From: Jeremy Harris Date: Tue, 8 Aug 2023 22:33:41 +0000 (+0100) Subject: Logging: connection_id X-Git-Tag: exim-4.97-RC0~39 X-Git-Url: https://git.exim.org/exim.git/commitdiff_plain/4e871f9b28dff4cacfd012aede1d092cc8cfbd36 Logging: connection_id --- diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt index cf670ba07..1a4e3f8da 100644 --- a/doc/doc-docbook/spec.xfpt +++ b/doc/doc-docbook/spec.xfpt @@ -38967,6 +38967,7 @@ the following table: .display &`A `& authenticator name (and optional id and sender) &`C `& SMTP confirmation on delivery +&`Ci `& connection identifier &` `& command list for &"no mail in SMTP session"& &`CV `& certificate verification status &`D `& duration of &"no mail in SMTP session"& @@ -39069,6 +39070,7 @@ selection marked by asterisks: .irow &`address_rewrite`&   "address rewriting" .irow &`all_parents`&   "all parents in => lines" .irow &`arguments`&   "command line arguments" +.irow &`connection_id`&   "connection identifier" .irow &`connection_reject`& * "connection rejections" .irow &`delay_delivery`& * "immediate delivery delayed" .irow &`deliver_time`&   "time taken to attempt delivery" @@ -39164,6 +39166,14 @@ because the arguments are checked before the configuration file is read. The only way to log such cases is to interpose a script such as &_util/logargs.sh_& between the caller and Exim. .next +.cindex "log" "connection identifier" +.new +&%connection_identifier%&: An identifier for the accepted connection is added to +connection start and end lines and to message accept lines. +The identifier is tagged by Ci=. +The value is PID-based, so will reset on reboot and will wrap. +.wen +.next .cindex "log" "connection rejections" &%connection_reject%&: A log entry is written whenever an incoming SMTP connection is rejected, for whatever reason. diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff index 3c96da6f8..25a8ae689 100644 --- a/doc/doc-txt/NewStuff +++ b/doc/doc-txt/NewStuff @@ -35,6 +35,8 @@ Version 4.97 13. Variable $recipients_list, a properly-quoted exim list. + 14. A log_selector for an incoming connection ID. + Version 4.96 ------------ diff --git a/src/src/daemon.c b/src/src/daemon.c index f6867b882..028626c0e 100644 --- a/src/src/daemon.c +++ b/src/src/daemon.c @@ -181,7 +181,7 @@ Returns: nothing */ static void -handle_smtp_call(struct pollfd *fd_polls, int listen_socket_count, +handle_smtp_call(struct pollfd * fd_polls, int listen_socket_count, int accept_socket, struct sockaddr *accepted) { pid_t pid; @@ -360,31 +360,8 @@ if (max_for_this_host > 0 && smtp_accept_count >= max_for_this_host) } } -/* OK, the connection count checks have been passed. Before we can fork the -accepting process, we must first log the connection if requested. This logging -used to happen in the subprocess, but doing that means that the value of -smtp_accept_count can be out of step by the time it is logged. So we have to do -the logging here and accept the performance cost. Note that smtp_accept_count -hasn't yet been incremented to take account of this connection. - -In order to minimize the cost (because this is going to happen for every -connection), do a preliminary selector test here. This saves ploughing through -the generalized logging code each time when the selector is false. If the -selector is set, check whether the host is on the list for logging. If not, -arrange to unset the selector in the subprocess. */ - -if (LOGGING(smtp_connection)) - { - uschar *list = hosts_connection_nolog; - memset(sender_host_cache, 0, sizeof(sender_host_cache)); - if (list && verify_check_host(&list) == OK) - save_log_selector &= ~L_smtp_connection; - else - log_write(L_smtp_connection, LOG_MAIN, "SMTP connection from %Y " - "(TCP/IP connection count = %d)", whofrom, smtp_accept_count + 1); - } - -/* Now we can fork the accepting process; do a lookup tidy, just in case any +/* OK, the connection count checks have been passed. +Now we can fork the accepting process; do a lookup tidy, just in case any expansion above did a lookup. */ search_tidyup(); @@ -404,6 +381,33 @@ if (pid == 0) #endif smtp_accept_count++; /* So that it includes this process */ + connection_id = getpid(); + + /* Log the connection if requested. + In order to minimize the cost (because this is going to happen for every + connection), do a preliminary selector test here. This saves ploughing through + the generalized logging code each time when the selector is false. If the + selector is set, check whether the host is on the list for logging. If not, + arrange to unset the selector in the subprocess. + + jgh 2023/08/08 :- moved this logging in from the parent process, just + pre-fork. There was a claim back from 2004 that smtp_accept_count could have + become out-of-date by the time the child could log it, and I can't see how + that could happen. */ + + if (LOGGING(smtp_connection)) + { + uschar * list = hosts_connection_nolog; + memset(sender_host_cache, 0, sizeof(sender_host_cache)); + if (list && verify_check_host(&list) == OK) + save_log_selector &= ~L_smtp_connection; + else if (LOGGING(connection_id)) + log_write(L_smtp_connection, LOG_MAIN, "SMTP connection from %Y " + "Ci=%lu (TCP/IP connection count = %d)", whofrom, connection_id, smtp_accept_count); + else + log_write(L_smtp_connection, LOG_MAIN, "SMTP connection from %Y " + "(TCP/IP connection count = %d)", whofrom, smtp_accept_count); + } /* If the listen backlog was over the monitoring level, log it. */ diff --git a/src/src/exim.c b/src/src/exim.c index 94061f97d..c44c7cb1b 100644 --- a/src/src/exim.c +++ b/src/src/exim.c @@ -5418,6 +5418,7 @@ if (host_checking) "**** This is not for real!\n\n", sender_host_address); + connection_id = getpid(); memset(sender_host_cache, 0, sizeof(sender_host_cache)); if (verify_check_host(&hosts_connection_nolog) == OK) { @@ -5606,6 +5607,7 @@ because a log line has already been written for all its failure exists (usually "connection refused: ") and writing another one is unnecessary clutter. */ +connection_id = getpid(); if (smtp_input) { smtp_in = stdin; diff --git a/src/src/globals.c b/src/src/globals.c index 9f4053937..56d192781 100644 --- a/src/src/globals.c +++ b/src/src/globals.c @@ -737,6 +737,7 @@ uid_t config_uid = CONFIGURE_OWNER; uid_t config_uid = 0; #endif +ulong connection_id = 0L; int connection_max_messages= -1; uschar *continue_proxy_cipher = NULL; BOOL continue_proxy_dane = FALSE; @@ -1089,6 +1090,7 @@ bit_table log_options[] = { /* must be in alphabetical order, BIT_TABLE(L, all), BIT_TABLE(L, all_parents), BIT_TABLE(L, arguments), + BIT_TABLE(L, connection_id), BIT_TABLE(L, connection_reject), BIT_TABLE(L, delay_delivery), BIT_TABLE(L, deliver_time), diff --git a/src/src/globals.h b/src/src/globals.h index 3a5513382..2458066dd 100644 --- a/src/src/globals.h +++ b/src/src/globals.h @@ -432,6 +432,7 @@ extern gstring *client_cmd_log; /* debug log of client cmds & responses * extern int clmacro_count; /* Number of command line macros */ extern uschar *clmacros[]; /* Copy of them, for re-exec */ extern BOOL commandline_checks_require_admin; /* belt and braces for insecure setups */ +extern ulong connection_id; /* per-daemon connection number */ extern int connection_max_messages;/* Max down one SMTP connection */ extern FILE *config_file; /* Configuration file */ extern const uschar *config_filename; /* Configuration file name */ diff --git a/src/src/host.c b/src/src/host.c index e274673a0..3e5a88660 100644 --- a/src/src/host.c +++ b/src/src/host.c @@ -628,6 +628,8 @@ else if (sender_ident) g = string_fmt_append(g, " U=%s", sender_ident); } +if (LOGGING(connection_id)) + g = string_fmt_append(g, " Ci=%lu", connection_id); gstring_release_unused(g); return string_from_gstring(g); } diff --git a/src/src/macros.h b/src/src/macros.h index 941c4f00c..47d75044b 100644 --- a/src/src/macros.h +++ b/src/src/macros.h @@ -466,6 +466,7 @@ enum logbit { Li_8bitmime = BITWORDSIZE, Li_acl_warn_skipped, Li_arguments, + Li_connection_id, Li_deliver_time, Li_delivery_size, Li_dkim, diff --git a/src/src/receive.c b/src/src/receive.c index 4271561d7..14038f2ec 100644 --- a/src/src/receive.c +++ b/src/src/receive.c @@ -1156,7 +1156,7 @@ Returns: the SMTP response */ static uschar * -handle_lost_connection(uschar *s) +handle_lost_connection(uschar * s) { log_write(L_lost_incoming_connection | L_smtp_connection, LOG_MAIN, "%s lost while reading message data%s", smtp_get_connection_info(), s); @@ -1379,6 +1379,8 @@ if (f.tcp_in_fastopen && !f.tcp_in_fastopen_logged) } if (sender_ident) g = string_append(g, 2, US" U=", sender_ident); +if (LOGGING(connection_id)) + g = string_fmt_append(g, " Ci=%lu", connection_id); if (received_protocol) g = string_append(g, 2, US" P=", received_protocol); if (LOGGING(pipelining) && f.smtp_in_pipelining_advertised) diff --git a/src/src/smtp_in.c b/src/src/smtp_in.c index 765d33bf4..18cde79b1 100644 --- a/src/src/smtp_in.c +++ b/src/src/smtp_in.c @@ -1342,21 +1342,29 @@ smtp_get_connection_info(void) { const uschar * hostname = sender_fullhost ? sender_fullhost : sender_host_address; +gstring * g = string_catn(NULL, US"SMTP connection", 15); + +if (LOGGING(connection_id)) + g = string_fmt_append(g, " Ci=%lu", connection_id); +g = string_catn(g, US" from ", 6); if (host_checking) - return string_sprintf("SMTP connection from %s", hostname); + g = string_cat(g, hostname); + +else if (f.sender_host_unknown || f.sender_host_notsocket) + g = string_cat(g, sender_ident); -if (f.sender_host_unknown || f.sender_host_notsocket) - return string_sprintf("SMTP connection from %s", sender_ident); +else if (f.is_inetd) + g = string_append(g, 2, hostname, US" (via inetd)"); -if (f.is_inetd) - return string_sprintf("SMTP connection from %s (via inetd)", hostname); +else if (LOGGING(incoming_interface) && interface_address) + g = string_fmt_append(g, "%s I=[%s]:%d", hostname, interface_address, interface_port); -if (LOGGING(incoming_interface) && interface_address) - return string_sprintf("SMTP connection from %s I=[%s]:%d", hostname, - interface_address, interface_port); +else + g = string_cat(g, hostname); -return string_sprintf("SMTP connection from %s", hostname); +gstring_release_unused(g); +return string_from_gstring(g); } diff --git a/test/confs/0230 b/test/confs/0230 index ecce42295..41bfa8697 100644 --- a/test/confs/0230 +++ b/test/confs/0230 @@ -13,7 +13,7 @@ acl_smtp_rcpt = check_recipient log_selector = \ +incoming_port \ +incoming_interface \ - +smtp_connection + +smtp_connection +connection_id queue_only queue_run_in_order diff --git a/test/confs/0552 b/test/confs/0552 index 153185561..ec138b931 100644 --- a/test/confs/0552 +++ b/test/confs/0552 @@ -14,6 +14,7 @@ acl_smtp_connect = check_connect acl_smtp_rcpt = check_rcpt queue_only +log_selector = +connection_id +received_recipients # ----- ACL ----- diff --git a/test/confs/0632 b/test/confs/0632 index 55592bf3b..fcabe86ee 100644 --- a/test/confs/0632 +++ b/test/confs/0632 @@ -4,6 +4,7 @@ primary_hostname = myhost.test.ex queue_only +log_selector = +received_recipients +connection_id # ----- Main settings ----- diff --git a/test/confs/0900 b/test/confs/0900 index 53d06b149..2d53eff1a 100644 --- a/test/confs/0900 +++ b/test/confs/0900 @@ -39,9 +39,9 @@ queue_only smtp_receive_timeout = 2s .ifdef _HAVE_DKIM -log_selector = +received_recipients +millisec +dkim_verbose +log_selector = +received_recipients +connection_id +millisec +dkim_verbose .else -log_selector = +received_recipients +millisec +log_selector = +received_recipients +connection_id +millisec .endif .ifdef _HAVE_TLS diff --git a/test/log/0230 b/test/log/0230 index f4e766a8b..db3ee7adb 100644 --- a/test/log/0230 +++ b/test/log/0230 @@ -1,7 +1,7 @@ -1999-03-02 09:44:33 SMTP connection from root -1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= x@y.x H=(test) [V4NET.9.8.7]:1111 U=root P=smtp S=sss -1999-03-02 09:44:33 SMTP connection from root D=qqs closed by QUIT -1999-03-02 09:44:33 Start queue run: pid=p1234 -qf +1999-03-02 09:44:33 SMTP connection Ci=p1234 from root +1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= x@y.x H=(test) [V4NET.9.8.7]:1111 U=root Ci=p1234 P=smtp S=sss +1999-03-02 09:44:33 SMTP connection Ci=p1234 from root D=qqs closed by QUIT +1999-03-02 09:44:33 Start queue run: pid=p1235 -qf 1999-03-02 09:44:33 10HmaY-000000005vi-0000 => x R=server T=local_delivery 1999-03-02 09:44:33 10HmaY-000000005vi-0000 Completed 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => x R=server T=local_delivery @@ -10,27 +10,27 @@ 1999-03-02 09:44:33 10HmbA-000000005vi-0000 Completed 1999-03-02 09:44:33 10HmaX-000000005vi-0000 => x R=server T=local_delivery 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed -1999-03-02 09:44:33 End queue run: pid=p1234 -qf -1999-03-02 09:44:33 SMTP connection from root -1999-03-02 09:44:33 10HmbB-000000005vi-0000 <= x@y.x H=(test) [V4NET.9.8.7]:1112 U=root P=smtp S=sss -1999-03-02 09:44:33 SMTP connection from root D=qqs closed by QUIT -1999-03-02 09:44:33 Start queue run: pid=p1235 -qf +1999-03-02 09:44:33 End queue run: pid=p1235 -qf +1999-03-02 09:44:33 SMTP connection Ci=p1236 from root +1999-03-02 09:44:33 10HmbB-000000005vi-0000 <= x@y.x H=(test) [V4NET.9.8.7]:1112 U=root Ci=p1236 P=smtp S=sss +1999-03-02 09:44:33 SMTP connection Ci=p1236 from root D=qqs closed by QUIT +1999-03-02 09:44:33 Start queue run: pid=p1237 -qf 1999-03-02 09:44:33 10HmbB-000000005vi-0000 => x@test.ex R=to_server T=remote H=127.0.0.1 [127.0.0.1] I=[127.0.0.1] C="250 OK id=10HmbC-000000005vi-0000" 1999-03-02 09:44:33 10HmbB-000000005vi-0000 Completed -1999-03-02 09:44:33 End queue run: pid=p1235 -qf +1999-03-02 09:44:33 End queue run: pid=p1237 -qf ******** SERVER ******** -1999-03-02 09:44:33 exim x.yz daemon started: pid=p1236, no queue runs, listening for SMTP on port PORT_D -1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:PORT_D (TCP/IP connection count = 1) -1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= x@y.x H=(test) [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:PORT_D P=smtp S=sss -1999-03-02 09:44:33 SMTP connection from (test) [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:PORT_D D=qqs closed by QUIT -1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1114 I=[127.0.0.1]:PORT_D (TCP/IP connection count = 1) -1999-03-02 09:44:33 10HmaZ-000000005vi-0000 <= x@y.x H=(test) [127.0.0.1]:1114 I=[127.0.0.1]:PORT_D P=smtp S=sss -1999-03-02 09:44:33 SMTP connection from (test) [127.0.0.1]:1114 I=[127.0.0.1]:PORT_D D=qqs closed by QUIT -1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:PORT_D (TCP/IP connection count = 1) -1999-03-02 09:44:33 10HmbA-000000005vi-0000 <= x@y.x H=(rhubarb) [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:PORT_D P=smtp S=sss -1999-03-02 09:44:33 SMTP connection from (rhubarb) [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:PORT_D D=qqs closed by QUIT -1999-03-02 09:44:33 exim x.yz daemon started: pid=p1237, no queue runs, listening for SMTP on port PORT_D -1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D (TCP/IP connection count = 1) -1999-03-02 09:44:33 10HmbC-000000005vi-0000 <= x@y.x H=localhost (myhost.test.ex) [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D P=esmtp S=sss -1999-03-02 09:44:33 SMTP connection from localhost (myhost.test.ex) [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D D=qqs closed by QUIT +1999-03-02 09:44:33 exim x.yz daemon started: pid=p1238, no queue runs, listening for SMTP on port PORT_D +1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:PORT_D Ci=p1239 (TCP/IP connection count = 1) +1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= x@y.x H=(test) [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:PORT_D Ci=p1239 P=smtp S=sss +1999-03-02 09:44:33 SMTP connection Ci=p1239 from (test) [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:PORT_D D=qqs closed by QUIT +1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1114 I=[127.0.0.1]:PORT_D Ci=p1240 (TCP/IP connection count = 1) +1999-03-02 09:44:33 10HmaZ-000000005vi-0000 <= x@y.x H=(test) [127.0.0.1]:1114 I=[127.0.0.1]:PORT_D Ci=p1240 P=smtp S=sss +1999-03-02 09:44:33 SMTP connection Ci=p1240 from (test) [127.0.0.1]:1114 I=[127.0.0.1]:PORT_D D=qqs closed by QUIT +1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:PORT_D Ci=p1241 (TCP/IP connection count = 1) +1999-03-02 09:44:33 10HmbA-000000005vi-0000 <= x@y.x H=(rhubarb) [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:PORT_D Ci=p1241 P=smtp S=sss +1999-03-02 09:44:33 SMTP connection Ci=p1241 from (rhubarb) [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:PORT_D D=qqs closed by QUIT +1999-03-02 09:44:33 exim x.yz daemon started: pid=p1242, no queue runs, listening for SMTP on port PORT_D +1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D Ci=p1243 (TCP/IP connection count = 1) +1999-03-02 09:44:33 10HmbC-000000005vi-0000 <= x@y.x H=localhost (myhost.test.ex) [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D Ci=p1243 P=esmtp S=sss +1999-03-02 09:44:33 SMTP connection Ci=p1243 from localhost (myhost.test.ex) [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D D=qqs closed by QUIT diff --git a/test/log/0552 b/test/log/0552 index ebd7c94a0..a023023d3 100644 --- a/test/log/0552 +++ b/test/log/0552 @@ -1,20 +1,20 @@ 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Accept non-SMTP -1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER P=local S=sss -1999-03-02 09:44:33 Start queue run: pid=p1234 -qf +1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@myhost.test.ex U=CALLER Ci=p1234 P=local S=sss for userx1@test.ex userx2@test.ex userx3@test.ex +1999-03-02 09:44:33 Start queue run: pid=p1235 -qf 1999-03-02 09:44:33 10HmaX-000000005vi-0000 H=127.0.0.1 [127.0.0.1]: SMTP timeout after pipelined MAIL FROM: SIZE=ssss: Connection timed out 1999-03-02 09:44:33 10HmaX-000000005vi-0000 == userx1@test.ex R=r1 T=t1 defer (dd): Connection timed out H=127.0.0.1 [127.0.0.1]: SMTP timeout after pipelined MAIL FROM: SIZE=ssss 1999-03-02 09:44:33 10HmaX-000000005vi-0000 == userx2@test.ex R=r1 T=t1 defer (dd): Connection timed out H=127.0.0.1 [127.0.0.1]: SMTP timeout after pipelined MAIL FROM: SIZE=ssss 1999-03-02 09:44:33 10HmaX-000000005vi-0000 == userx3@test.ex R=r1 T=t1 defer (dd): Connection timed out H=127.0.0.1 [127.0.0.1]: SMTP timeout after pipelined MAIL FROM: SIZE=ssss -1999-03-02 09:44:33 End queue run: pid=p1234 -qf -1999-03-02 09:44:33 Start queue run: pid=p1235 -qf +1999-03-02 09:44:33 End queue run: pid=p1235 -qf +1999-03-02 09:44:33 Start queue run: pid=p1236 -qf 1999-03-02 09:44:33 10HmaX-000000005vi-0000 => userx1@test.ex R=r1 T=t1 H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmaY-000000005vi-0000" 1999-03-02 09:44:33 10HmaX-000000005vi-0000 -> userx2@test.ex R=r1 T=t1 H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmaY-000000005vi-0000" 1999-03-02 09:44:33 10HmaX-000000005vi-0000 -> userx3@test.ex R=r1 T=t1 H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmaY-000000005vi-0000" 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed -1999-03-02 09:44:33 End queue run: pid=p1235 -qf +1999-03-02 09:44:33 End queue run: pid=p1236 -qf ******** SERVER ******** -1999-03-02 09:44:33 exim x.yz daemon started: pid=p1236, no queue runs, listening for SMTP on port PORT_D -1999-03-02 09:44:33 SMTP connection from localhost (myhost.test.ex) [127.0.0.1] lost while reading message data (header) 1999-03-02 09:44:33 exim x.yz daemon started: pid=p1237, no queue runs, listening for SMTP on port PORT_D -1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@myhost.test.ex H=localhost (myhost.test.ex) [127.0.0.1] P=esmtp S=sss id=E10HmaX-000000005vi-0000@myhost.test.ex +1999-03-02 09:44:33 SMTP connection Ci=p1238 from localhost (myhost.test.ex) [127.0.0.1] lost while reading message data (header) +1999-03-02 09:44:33 exim x.yz daemon started: pid=p1239, no queue runs, listening for SMTP on port PORT_D +1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@myhost.test.ex H=localhost (myhost.test.ex) [127.0.0.1] Ci=p1240 P=esmtp S=sss id=E10HmaX-000000005vi-0000@myhost.test.ex for userx1@test.ex userx2@test.ex userx3@test.ex diff --git a/test/log/0632 b/test/log/0632 index bbe0f0f18..b2ac59dd8 100644 --- a/test/log/0632 +++ b/test/log/0632 @@ -1,5 +1,5 @@ ******** SERVER ******** 1999-03-02 09:44:33 exim x.yz daemon started: pid=p1234, no queue runs, listening for SMTP on port PORT_D -1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@test.ex H=(test.ex) [127.0.0.1] P=smtp S=sss -1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@test.ex H=(test.ex) [127.0.0.1] P=smtp S=sss +1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= CALLER@test.ex H=(test.ex) [127.0.0.1] Ci=p1235 P=smtp S=sss for dest_1@test.ex +1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= CALLER@test.ex H=(test.ex) [127.0.0.1] Ci=p1236 P=smtp S=sss for dest_2@test.ex diff --git a/test/log/0900 b/test/log/0900 index 7c0ff0d06..c3e2bb8e7 100644 --- a/test/log/0900 +++ b/test/log/0900 @@ -1,18 +1,18 @@ ******** SERVER ******** -2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1234, no queue runs, listening for SMTP on port PORT_D -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex -2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex -2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= some_ne@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex -2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1236, no queue runs, listening for SMTP on port PORT_D +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] Ci=p1237 P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] Ci=p1238 P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] Ci=p1238 P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= some_ne@some.domain H=(tester) [127.0.0.1] Ci=p1239 P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] Ci=p1239 P=esmtp K S=sss for CALLER@test.ex 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 SMTP data timeout (message abandoned) on connection from (tester) [127.0.0.1] F= D=q.qqqs -2017-07-30 18:51:05.712 SMTP connection from (tester) [127.0.0.1] lost while reading message data -2017-07-30 18:51:05.712 SMTP connection from (tester) [127.0.0.1] lost while reading message data -2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex -2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] F= rejected RCPT : relay not permitted -2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] F= rejected RCPT : relay not permitted -2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] F= rejected RCPT : relay not permitted -2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 <= some6ne@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 SMTP connection Ci=p1240 from (tester) [127.0.0.1] lost while reading message data +2017-07-30 18:51:05.712 SMTP connection Ci=p1241 from (tester) [127.0.0.1] lost while reading message data +2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] Ci=p1242 P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] Ci=p1234 F= rejected RCPT : relay not permitted +2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] Ci=p1235 F= rejected RCPT : relay not permitted +2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] Ci=p1235 F= rejected RCPT : relay not permitted +2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 <= some6ne@some.domain H=(tester) [127.0.0.1] Ci=p1243 P=esmtp K S=sss for CALLER@test.ex 2017-07-30 18:51:05.712 rejected from H=(tester) [127.0.0.1]: Non-CRLF-terminated header, under CHUNKING: message abandoned -2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] P=esmtp K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] Ci=p1244 P=esmtp K S=sss for CALLER@test.ex diff --git a/test/log/0904 b/test/log/0904 index 930ee7dac..af82b56bd 100644 --- a/test/log/0904 +++ b/test/log/0904 @@ -1,44 +1,44 @@ -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for a@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@source.dom U=root Ci=p1234 P=local-bsmtp S=sss for a@test.ex 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK" 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for b@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= sender@source.dom U=root Ci=p1235 P=local-bsmtp S=sss for b@test.ex 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 H=127.0.0.1 [127.0.0.1]: SMTP timeout after end of data (ddd bytes written): Connection timed out 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 == b@test.ex R=to_server T=remote_smtp defer (dd): Connection timed out H=127.0.0.1 [127.0.0.1]: SMTP timeout after end of data (ddd bytes written) -2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for c@test.ex +2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@source.dom U=root Ci=p1236 P=local-bsmtp S=sss for c@test.ex 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => c@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK" 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for d@test.ex +2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= sender@source.dom U=root Ci=p1237 P=local-bsmtp S=sss for d@test.ex 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 ** d@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after end of data: 500 oops 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 d@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for e@test.ex +2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= sender@source.dom U=root Ci=p1238 P=local-bsmtp S=sss for e@test.ex 2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after end of data: 400 not right now 2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 == e@test.ex R=to_server T=remote_smtp defer (-46) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after end of data: 400 not right now -2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for ebad@test.ex +2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 <= sender@source.dom U=root Ci=p1239 P=local-bsmtp S=sss for ebad@test.ex 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 ** ebad@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:: 550 sorry, no 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 ebad@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for p@test.ex +2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 <= sender@source.dom U=root Ci=p1240 P=local-bsmtp S=sss for p@test.ex 2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 => p@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK bdat" 2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for r@test.ex +2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 <= sender@source.dom U=root Ci=p1241 P=local-bsmtp S=sss for r@test.ex 2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 => r@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK bdat" 2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for s@test.ex +2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 <= sender@source.dom U=root Ci=p1242 P=local-bsmtp S=sss for s@test.ex 2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 ** s@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined end of data: 550 unacceptable mail-from 2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 s@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for s1@test.ex +2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 <= sender@source.dom U=root Ci=p1243 P=local-bsmtp S=sss for s1@test.ex 2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined end of data: 450 greylisted mail-from 2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 == s1@test.ex R=to_server T=remote_smtp defer (-45) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined end of data: 450 greylisted mail-from -2017-07-30 18:51:05.712 10HmbH-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for t@test.ex +2017-07-30 18:51:05.712 10HmbH-000000005vi-0000 <= sender@source.dom U=root Ci=p1244 P=local-bsmtp S=sss for t@test.ex 2017-07-30 18:51:05.712 10HmbH-000000005vi-0000 ** t@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:: 550 no such recipient 2017-07-30 18:51:05.712 10HmbH-000000005vi-0000 t@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbH-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbI-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for u@test.ex +2017-07-30 18:51:05.712 10HmbI-000000005vi-0000 <= sender@source.dom U=root Ci=p1245 P=local-bsmtp S=sss for u@test.ex 2017-07-30 18:51:05.712 10HmbI-000000005vi-0000 ** u@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined end of data: 500 oops bdat 2017-07-30 18:51:05.712 10HmbI-000000005vi-0000 u@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbI-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbJ-000000005vi-0000 <= sender@source.dom U=root P=local-bsmtp S=sss for v@test.ex +2017-07-30 18:51:05.712 10HmbJ-000000005vi-0000 <= sender@source.dom U=root Ci=p1246 P=local-bsmtp S=sss for v@test.ex 2017-07-30 18:51:05.712 10HmbJ-000000005vi-0000 H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined end of data: 400 not right now bdat 2017-07-30 18:51:05.712 10HmbJ-000000005vi-0000 == v@test.ex R=to_server T=remote_smtp defer (-46) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined end of data: 400 not right now bdat diff --git a/test/log/0905 b/test/log/0905 index 225f6511d..693401145 100644 --- a/test/log/0905 +++ b/test/log/0905 @@ -1,37 +1,37 @@ -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for a@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@dom U=root Ci=p1234 P=local-bsmtp S=sss for a@test.ex 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK bdat" 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for d@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= sender@dom U=root Ci=p1235 P=local-bsmtp S=sss for d@test.ex 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 ** d@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after sending data block: 500 oops bdat-nonlast 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 d@test.ex: error ignored 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for p@test.ex +2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@dom U=root Ci=p1236 P=local-bsmtp S=sss for p@test.ex 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => p@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK bdat" 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for s@test.ex +2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= sender@dom U=root Ci=p1237 P=local-bsmtp S=sss for s@test.ex 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 ** s@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined sending data block: 550 unacceptable mail-from 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 s@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for t@test.ex +2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= sender@dom U=root Ci=p1238 P=local-bsmtp S=sss for t@test.ex 2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 ** t@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:: 550 no such recipient 2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 t@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for t1@test.ex t2@test.ex +2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 <= sender@dom U=root Ci=p1239 P=local-bsmtp S=sss for t1@test.ex t2@test.ex 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 ** t1@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:: 550 no such recipient 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 => t2@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK bdat" 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 t1@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for u@test.ex +2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 <= sender@dom U=root Ci=p1240 P=local-bsmtp S=sss for u@test.ex 2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 ** u@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined sending data block: 500 oops nonlast bdat 2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 u@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbD-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for v@test.ex +2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 <= sender@dom U=root Ci=p1241 P=local-bsmtp S=sss for v@test.ex 2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 ** v@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after end of data: 500 oops bdat 2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 v@test.ex: error ignored 2017-07-30 18:51:05.712 10HmbE-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for u@test.ex +2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 <= sender@dom U=root Ci=p1242 P=local-bsmtp S=sss for u@test.ex 2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined sending data block: 400 oops nonlast bdat 2017-07-30 18:51:05.712 10HmbF-000000005vi-0000 == u@test.ex R=to_server T=remote_smtp defer (-46) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after pipelined sending data block: 400 oops nonlast bdat -2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for p@test.ex +2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 <= sender@dom U=root Ci=p1243 P=local-bsmtp S=sss for p@test.ex 2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 => p@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] K C="250 OK bdat" 2017-07-30 18:51:05.712 10HmbG-000000005vi-0000 Completed diff --git a/test/log/1114 b/test/log/1114 index 814c50965..1229ea23e 100644 --- a/test/log/1114 +++ b/test/log/1114 @@ -1,5 +1,5 @@ ******** SERVER ******** 2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1234, no queue runs, listening for SMTP on port PORT_D -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= someone@some.domain H=(rhu.barb) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss for CALLER@test.ex -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= someone@some.domain H=(rhu.barb) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= someone@some.domain H=(rhu.barb) [127.0.0.1] Ci=p1235 P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss for CALLER@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= someone@some.domain H=(rhu.barb) [127.0.0.1] Ci=p1236 P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss for CALLER@test.ex diff --git a/test/log/1165 b/test/log/1165 index 23fc454c8..cd66fb6be 100644 --- a/test/log/1165 +++ b/test/log/1165 @@ -1,19 +1,19 @@ -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= this-user@testhost.test.ex U=this-user P=local S=sss for other-user@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= this-user@testhost.test.ex U=this-user Ci=p1234 P=local S=sss for other-user@test.ex 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => other-user@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 3nn byte chunk, total 3nn\\n250 OK id=10HmaY-000000005vi-0000" 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 removed by CALLER 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= this-user@testhost.test.ex U=this-user P=local S=sss for first-user@test.ex -2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= this-user@testhost.test.ex U=this-user P=local S=sss for second-user@test.ex -2017-07-30 18:51:05.712 Start queue run: pid=p1234 -qq +2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= this-user@testhost.test.ex U=this-user Ci=p1235 P=local S=sss for first-user@test.ex +2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= this-user@testhost.test.ex U=this-user Ci=p1236 P=local S=sss for second-user@test.ex +2017-07-30 18:51:05.712 Start queue run: pid=p1237 -qq 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => first-user@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 3nn byte chunk, total 3nn\\n250 OK id=10HmbB-000000005vi-0000" 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 Completed 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 => second-user@test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1]* X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K C="250- 3nn byte chunk, total 3nn\\n250 OK id=10HmbC-000000005vi-0000" 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 Completed -2017-07-30 18:51:05.712 End queue run: pid=p1234 -qq +2017-07-30 18:51:05.712 End queue run: pid=p1237 -qq ******** SERVER ******** -2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1235, no queue runs, listening for SMTP on port PORT_S -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmaX-000000005vi-0000@testhost.test.ex for other-user@test.ex -2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmaZ-000000005vi-0000@testhost.test.ex for first-user@test.ex -2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmbA-000000005vi-0000@testhost.test.ex for second-user@test.ex +2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1238, no queue runs, listening for SMTP on port PORT_S +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] Ci=p1239 P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmaX-000000005vi-0000@testhost.test.ex for other-user@test.ex +2017-07-30 18:51:05.712 10HmbB-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] Ci=p1240 P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmaZ-000000005vi-0000@testhost.test.ex for first-user@test.ex +2017-07-30 18:51:05.712 10HmbC-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] Ci=p1240 P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmbA-000000005vi-0000@testhost.test.ex for second-user@test.ex diff --git a/test/log/4511 b/test/log/4511 index 53350ed02..b45c16fbb 100644 --- a/test/log/4511 +++ b/test/log/4511 @@ -1,13 +1,13 @@ -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@testhost.test.ex U=sender P=local S=sss for a@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1234 P=local S=sss for a@test.ex 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000" 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@testhost.test.ex U=sender P=local S=sss for b@test.ex +2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1235 P=local S=sss for b@test.ex 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] K C="250- 8nn byte chunk, total 8nn\\n250 OK id=10HmbA-000000005vi-0000" 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 Completed ******** SERVER ******** -2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1234, no queue runs, listening for SMTP on port PORT_S +2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1236, no queue runs, listening for SMTP on port PORT_S 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtp K S=sss DKIM=test.ex id=E10HmaX-000000005vi-0000@testhost.test.ex for a@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] Ci=p1237 P=esmtp K S=sss DKIM=test.ex id=E10HmaX-000000005vi-0000@testhost.test.ex for a@test.ex 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtp K S=sss DKIM=test.ex id=E10HmaZ-000000005vi-0000@testhost.test.ex for b@test.ex +2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] Ci=p1238 P=esmtp K S=sss DKIM=test.ex id=E10HmaZ-000000005vi-0000@testhost.test.ex for b@test.ex diff --git a/test/log/4512 b/test/log/4512 index 4ccc961da..9f7e1655c 100644 --- a/test/log/4512 +++ b/test/log/4512 @@ -2,6 +2,6 @@ ******** SERVER ******** 2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1234, no queue runs, listening for SMTP on port PORT_S 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 DKIM: d=test.ex s=sel c=simple/simple a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] P=esmtp K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] Ci=p1235 P=esmtp K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 DKIM: d=test.ex s=sel c=simple/simple a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] P=esmtp K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] Ci=p1236 P=esmtp K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex diff --git a/test/log/4531 b/test/log/4531 index d2d24d580..bd642b51f 100644 --- a/test/log/4531 +++ b/test/log/4531 @@ -1,13 +1,13 @@ -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@testhost.test.ex U=sender P=local S=sss for a@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1234 P=local S=sss for a@test.ex 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => a@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 6nn byte chunk, total 6nn\\n250 OK id=10HmaY-000000005vi-0000" 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed -2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@testhost.test.ex U=sender P=local S=sss for b@test.ex +2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 <= sender@testhost.test.ex U=sender Ci=p1235 P=local S=sss for b@test.ex 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 => b@test.ex R=to_server T=remote_smtp_dkim H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes K C="250- 8nn byte chunk, total 8nn\\n250 OK id=10HmbA-000000005vi-0000" 2017-07-30 18:51:05.712 10HmaZ-000000005vi-0000 Completed ******** SERVER ******** -2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1234, no queue runs, listening for SMTP on port PORT_S +2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1236, no queue runs, listening for SMTP on port PORT_S 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=E10HmaX-000000005vi-0000@testhost.test.ex for a@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] Ci=p1237 P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=E10HmaX-000000005vi-0000@testhost.test.ex for a@test.ex 2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 DKIM: d=test.ex s=sel c=relaxed/relaxed a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=E10HmaZ-000000005vi-0000@testhost.test.ex for b@test.ex +2017-07-30 18:51:05.712 10HmbA-000000005vi-0000 <= <> H=localhost (testhost.test.ex) [127.0.0.1] Ci=p1238 P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=E10HmaZ-000000005vi-0000@testhost.test.ex for b@test.ex diff --git a/test/log/4532 b/test/log/4532 index 8aaf3c52f..ff8544395 100644 --- a/test/log/4532 +++ b/test/log/4532 @@ -2,6 +2,6 @@ ******** SERVER ******** 2017-07-30 18:51:05.712 exim x.yz daemon started: pid=p1234, no queue runs, listening for SMTP on port PORT_S 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 DKIM: d=test.ex s=sel c=simple/simple a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] P=smtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] Ci=p1235 P=smtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex 2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 DKIM: d=test.ex s=sel c=simple/simple a=rsa-sha256 b=1024 [verification succeeded] -2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] P=smtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex +2017-07-30 18:51:05.712 10HmaY-000000005vi-0000 <= CALLER@bloggs.com H=(xxx) [127.0.0.1] Ci=p1236 P=smtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss DKIM=test.ex id=qwerty1234@disco-zombie.net for a@test.ex diff --git a/test/log/5590 b/test/log/5590 index ce8c421dc..7f31ace78 100644 --- a/test/log/5590 +++ b/test/log/5590 @@ -4,4 +4,4 @@ 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 PRDR R= refusal 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 PRDR R= acceptance 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 PRDR R= refusal -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] P=esmtp PRDR K S=sss for bad1@test.ex good@test.ex bad2@test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= someone@some.domain H=(tester) [127.0.0.1] Ci=p1235 P=esmtp PRDR K S=sss for bad1@test.ex good@test.ex bad2@test.ex diff --git a/test/log/5591 b/test/log/5591 index 83c25bf69..92b6d8007 100644 --- a/test/log/5591 +++ b/test/log/5591 @@ -1,4 +1,4 @@ -2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@dom U=root P=local-bsmtp S=sss for usery@testhost.test.ex userz@testhost.test.ex +2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 <= sender@dom U=root Ci=p1234 P=local-bsmtp S=sss for usery@testhost.test.ex userz@testhost.test.ex 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 => usery@testhost.test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] PRDR K C="250 first rcpt was good\\n250 OK, overall" 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 -> userz@testhost.test.ex R=to_server T=remote_smtp H=127.0.0.1 [127.0.0.1] PRDR K C="250 second rcpt was good\\n250 OK, overall" 2017-07-30 18:51:05.712 10HmaX-000000005vi-0000 Completed diff --git a/test/msglog/0230.10HmbC-000000005vi-0000 b/test/msglog/0230.10HmbC-000000005vi-0000 index 6708b1451..6de0895be 100644 --- a/test/msglog/0230.10HmbC-000000005vi-0000 +++ b/test/msglog/0230.10HmbC-000000005vi-0000 @@ -1 +1 @@ -1999-03-02 09:44:33 Received from x@y.x H=localhost (myhost.test.ex) [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D P=esmtp S=sss +1999-03-02 09:44:33 Received from x@y.x H=localhost (myhost.test.ex) [127.0.0.1]:1116 I=[127.0.0.1]:PORT_D Ci=p1243 P=esmtp S=sss diff --git a/test/rejectlog/0900 b/test/rejectlog/0900 index e39b7c588..b69a83d6b 100644 --- a/test/rejectlog/0900 +++ b/test/rejectlog/0900 @@ -1,8 +1,8 @@ ******** SERVER ******** -2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] F= rejected RCPT : relay not permitted -2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] F= rejected RCPT : relay not permitted -2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] F= rejected RCPT : relay not permitted +2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] Ci=p1234 F= rejected RCPT : relay not permitted +2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] Ci=p1235 F= rejected RCPT : relay not permitted +2017-07-30 18:51:05.712 H=(tester) [127.0.0.1] Ci=p1235 F= rejected RCPT : relay not permitted 2017-07-30 18:51:05.712 rejected from H=(tester) [127.0.0.1]: Non-CRLF-terminated header, under CHUNKING: message abandoned Envelope-from: Envelope-to: diff --git a/test/runtest b/test/runtest index ae2d929fd..74c53e229 100755 --- a/test/runtest +++ b/test/runtest @@ -765,6 +765,7 @@ RESET_AFTER_EXTRA_LINE_READ: s/\bgid=\d+/gid=gggg/; s/\begid=\d+/egid=gggg/; s/\b(?:pid=|pid\s|PID:\s|Process\s|child\s)\K(\d+)/new_value($1, "p%s", \$next_pid)/gxe; + s/ Ci=\K(\d+)/new_value($1, "p%s", \$next_pid)/gxe; s/\buid=\d+/uid=uuuu/; s/\beuid=\d+/euid=uuuu/; s/set_process_info:\s+\d+/set_process_info: pppp/; diff --git a/test/stderr/0230 b/test/stderr/0230 index e046d9022..804b96ce4 100644 --- a/test/stderr/0230 +++ b/test/stderr/0230 @@ -1,5 +1,5 @@ >>> host in hosts_connection_nolog? no (option unset) -LOG: SMTP connection from [192.168.1.2]:1117 +LOG: SMTP connection Ci=p1244 from [192.168.1.2]:1117 >>> host in host_lookup? no (option unset) >>> host in host_reject_connection? no (option unset) >>> host in sender_unqualified_hosts? no (option unset) @@ -7,6 +7,6 @@ LOG: SMTP connection from [192.168.1.2]:1117 >>> host in helo_verify_hosts? no (option unset) >>> host in helo_try_verify_hosts? no (option unset) >>> host in helo_accept_junk_hosts? no (option unset) -LOG: SMTP connection from [192.168.1.2]:1117 D=qqs closed by QUIT +LOG: SMTP connection Ci=p1244 from [192.168.1.2]:1117 D=qqs closed by QUIT ******** SERVER ******** diff --git a/test/stderr/0609 b/test/stderr/0609 index 8e99a3f7e..2ea697f69 100644 --- a/test/stderr/0609 +++ b/test/stderr/0609 @@ -15,8 +15,8 @@ LOG: MAIN daemon running with uid=EXIM_UID gid=EXIM_GID euid=EXIM_UID egid=EXIM_GID Listening... Connection request from 127.0.0.1 port sssss -LOG: smtp_connection MAIN - SMTP connection from [127.0.0.1] (TCP/IP connection count = 1) +p1235 LOG: smtp_connection MAIN +p1235 SMTP connection from [127.0.0.1] (TCP/IP connection count = 1) p1235 Process p1235 is handling incoming connection from [127.0.0.1] p1235 Process p1235 is ready for new message p1235 using ACL "delay4_accept" @@ -35,8 +35,8 @@ child p1235 ended: status=0x0 0 SMTP accept processes now running Listening... Connection request from 127.0.0.1 port sssss -LOG: smtp_connection MAIN - SMTP connection from [127.0.0.1] (TCP/IP connection count = 1) +p1236 LOG: smtp_connection MAIN +p1236 SMTP connection from [127.0.0.1] (TCP/IP connection count = 1) p1236 Process p1236 is handling incoming connection from [127.0.0.1] p1236 Process p1236 is ready for new message p1236 using ACL "delay4_accept" diff --git a/test/stderr/0632 b/test/stderr/0632 index 0103f0b2c..66928e2e8 100644 --- a/test/stderr/0632 +++ b/test/stderr/0632 @@ -476,11 +476,11 @@ p1235 ╭considering: ${tod_full} p1235 ├──expanding: ${tod_full} p1235 ╰─────result: Tue, 2 Mar 1999 09:44:33 +0000 LOG: MAIN - <= CALLER@test.ex H=(test.ex) [127.0.0.1] P=smtp S=sss + <= CALLER@test.ex H=(test.ex) [127.0.0.1] Ci=p1235 P=smtp S=sss search_tidyup called Process p1235 is ready for new message LOG: smtp_connection MAIN - SMTP connection from (test.ex) [127.0.0.1] D=qqs closed by QUIT + SMTP connection Ci=p1235 from (test.ex) [127.0.0.1] D=qqs closed by QUIT p1234 1 SMTP accept process running p1234 Listening... p1234 daemon_notification (from unknown addr) @@ -930,11 +930,11 @@ p1236 ╭considering: ${tod_full} p1236 ├──expanding: ${tod_full} p1236 ╰─────result: Tue, 2 Mar 1999 09:44:33 +0000 LOG: MAIN - <= CALLER@test.ex H=(test.ex) [127.0.0.1] P=smtp S=sss + <= CALLER@test.ex H=(test.ex) [127.0.0.1] Ci=p1236 P=smtp S=sss search_tidyup called Process p1236 is ready for new message LOG: smtp_connection MAIN - SMTP connection from (test.ex) [127.0.0.1] D=qqs closed by QUIT + SMTP connection Ci=p1236 from (test.ex) [127.0.0.1] D=qqs closed by QUIT p1234 1 SMTP accept process running p1234 Listening... search_tidyup called