From 1a47b633600e808a11d75551306a2bf8ebf87335 Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Tue, 10 Nov 2015 23:12:26 +0000 Subject: [PATCH] Logging: support +outgoing_port on defer lines and per-host error lines --- src/src/deliver.c | 8 ++++++++ src/src/transports/smtp.c | 23 +++++++++++------------ test/confs/2010 | 2 ++ test/confs/2110 | 2 ++ test/log/0211 | 9 +++++++++ test/log/2010 | 8 ++++---- test/log/2110 | 8 ++++---- test/scripts/0000-Basic/0211 | 19 +++++++++++++++++++ test/stdout/0211 | 4 ++++ 9 files changed, 63 insertions(+), 20 deletions(-) diff --git a/src/src/deliver.c b/src/src/deliver.c index f3ae2208a..e1f4e0e29 100644 --- a/src/src/deliver.c +++ b/src/src/deliver.c @@ -1288,9 +1288,17 @@ else if (result == DEFER || result == PANIC) US strerror(addr->basic_errno)); if (addr->host_used) + { s = string_append(s, &size, &ptr, 5, US" H=", addr->host_used->name, US" [", addr->host_used->address, US"]"); + if (LOGGING(outgoing_port)) + { + int port = addr->host_used->port; + s = string_append(s, &size, &ptr, 2, + US":", port == PORT_NONE ? US"25" : string_sprintf("%d", port)); + } + } if (addr->message) s = string_append(s, &size, &ptr, 2, US": ", addr->message); diff --git a/src/src/transports/smtp.c b/src/src/transports/smtp.c index eae54764b..59afe42aa 100644 --- a/src/src/transports/smtp.c +++ b/src/src/transports/smtp.c @@ -655,6 +655,9 @@ write_logs(address_item *addr, host_item *host) { uschar * message = string_sprintf("H=%s [%s]", host->name, host->address); +if (LOGGING(outgoing_port)) + message = string_sprintf("%s:%d", message, + host->port == PORT_NONE ? 25 : host->port); if (addr->message) { message = string_sprintf("%s: %s", message, addr->message); @@ -665,9 +668,6 @@ if (addr->message) } else { - if (LOGGING(outgoing_port)) - message = string_sprintf("%s:%d", message, - host->port == PORT_NONE ? 25 : host->port); log_write(0, LOG_MAIN, "%s %s", message, strerror(addr->basic_errno)); deliver_msglog("%s %s %s\n", tod_stamp(tod_log), message, strerror(addr->basic_errno)); @@ -3618,15 +3618,14 @@ for (cutoff_retry = 0; expired && host_item *h; DEBUG(D_transport) debug_printf("hosts_max_try limit reached with this host\n"); - for (h = host; h != NULL; h = h->next) - if (h->mx != host->mx) break; - if (h != NULL) - { - nexthost = h; - unexpired_hosts_tried--; - DEBUG(D_transport) debug_printf("however, a higher MX host exists " - "and will be tried\n"); - } + for (h = host; h; h = h->next) if (h->mx != host->mx) + { + nexthost = h; + unexpired_hosts_tried--; + DEBUG(D_transport) debug_printf("however, a higher MX host exists " + "and will be tried\n"); + break; + } } /* Attempt the delivery. */ diff --git a/test/confs/2010 b/test/confs/2010 index 8aede594a..34383c25a 100644 --- a/test/confs/2010 +++ b/test/confs/2010 @@ -14,6 +14,8 @@ gecos_name = CALLER_NAME # ----- Main settings ----- +log_selector = +outgoing_port + acl_smtp_rcpt = accept queue_only diff --git a/test/confs/2110 b/test/confs/2110 index 2bd3ed656..db6864863 100644 --- a/test/confs/2110 +++ b/test/confs/2110 @@ -13,6 +13,8 @@ gecos_name = CALLER_NAME # ----- Main settings ----- +log_selector = +outgoing_port + acl_smtp_rcpt = accept queue_only diff --git a/test/log/0211 b/test/log/0211 index 35da72e04..9a5824674 100644 --- a/test/log/0211 +++ b/test/log/0211 @@ -1,10 +1,18 @@ +1999-03-02 09:44:33 Test: temp-rej connect 1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@test.ex U=CALLER P=local S=sss 1999-03-02 09:44:33 10HmaX-0005vi-00 H=localhost4.test.ex [127.0.0.1]: SMTP error from remote mail server after initial connection: 450 I'm busy 1999-03-02 09:44:33 10HmaX-0005vi-00 == userx@domain1 R=others T=smtp defer (0) H=localhost4.test.ex [127.0.0.1]: SMTP error from remote mail server after initial connection: 450 I'm busy +1999-03-02 09:44:33 Test: temp-rej helo 1999-03-02 09:44:33 Start queue run: pid=pppp -qf 1999-03-02 09:44:33 10HmaX-0005vi-00 H=localhost4.test.ex [127.0.0.1]: SMTP error from remote mail server after HELO the.local.host.name: 450 I'm busy 1999-03-02 09:44:33 10HmaX-0005vi-00 == userx@domain1 R=others T=smtp defer (0) H=localhost4.test.ex [127.0.0.1]: SMTP error from remote mail server after HELO the.local.host.name: 450 I'm busy 1999-03-02 09:44:33 End queue run: pid=pppp -qf +1999-03-02 09:44:33 Test: drop conn after banner +1999-03-02 09:44:33 Start queue run: pid=pppp -qf +1999-03-02 09:44:33 10HmaX-0005vi-00 H=localhost4.test.ex [127.0.0.1]: Remote host closed connection in response to EHLO the.local.host.name +1999-03-02 09:44:33 10HmaX-0005vi-00 == userx@domain1 R=others T=smtp defer (-18) H=localhost4.test.ex [127.0.0.1]: Remote host closed connection in response to EHLO the.local.host.name +1999-03-02 09:44:33 End queue run: pid=pppp -qf +1999-03-02 09:44:33 Test: reject connect 1999-03-02 09:44:33 Start queue run: pid=pppp -qf 1999-03-02 09:44:33 10HmaX-0005vi-00 ** userx@domain1 F= R=others T=smtp H=localhost4.test.ex [127.0.0.1]: SMTP error from remote mail server after initial connection: 550 Go away 1999-03-02 09:44:33 10HmaY-0005vi-00 <= <> R=10HmaX-0005vi-00 U=EXIMUSER P=local S=sss @@ -12,6 +20,7 @@ 1999-03-02 09:44:33 10HmaY-0005vi-00 Completed 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed 1999-03-02 09:44:33 End queue run: pid=pppp -qf +1999-03-02 09:44:33 Test: reject helo 1999-03-02 09:44:33 10HmaZ-0005vi-00 <= CALLER@test.ex U=CALLER P=local S=sss 1999-03-02 09:44:33 10HmaZ-0005vi-00 ** userx@domain1 F= R=others T=smtp H=localhost4.test.ex [127.0.0.1]: SMTP error from remote mail server after HELO the.local.host.name: 550 Go away 1999-03-02 09:44:33 10HmaZ-0005vi-00 ** usery@domain2 F= R=others T=smtp H=localhost4.test.ex [127.0.0.1]: SMTP error from remote mail server after HELO the.local.host.name: 550 Go away diff --git a/test/log/2010 b/test/log/2010 index 9857a5604..f5cde396b 100644 --- a/test/log/2010 +++ b/test/log/2010 @@ -1,12 +1,12 @@ 1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss 1999-03-02 09:44:33 Start queue run: pid=pppp -qf -1999-03-02 09:44:33 10HmaX-0005vi-00 H=127.0.0.1 [127.0.0.1]: a TLS session is required, but the server did not offer TLS support -1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:xxxxRSA_AES_256_CBC_SHAnnn:256 CV=no C="250 OK id=10HmaY-0005vi-00" +1999-03-02 09:44:33 10HmaX-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: a TLS session is required, but the server did not offer TLS support +1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4]:1225 X=TLS1.x:xxxxRSA_AES_256_CBC_SHAnnn:256 CV=no C="250 OK id=10HmaY-0005vi-00" 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed 1999-03-02 09:44:33 End queue run: pid=pppp -qf 1999-03-02 09:44:33 Start queue run: pid=pppp -qf -1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]: a TLS session is required, but the server did not offer TLS support -1999-03-02 09:44:33 10HmaY-0005vi-00 == userx@test.ex R=client T=send_to_server defer (-38) H=127.0.0.1 [127.0.0.1]: a TLS session is required, but the server did not offer TLS support +1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: a TLS session is required, but the server did not offer TLS support +1999-03-02 09:44:33 10HmaY-0005vi-00 == userx@test.ex R=client T=send_to_server defer (-38) H=127.0.0.1 [127.0.0.1]:1111: a TLS session is required, but the server did not offer TLS support 1999-03-02 09:44:33 10HmaY-0005vi-00 ** userx@test.ex: retry timeout exceeded 1999-03-02 09:44:33 10HmaZ-0005vi-00 <= <> R=10HmaY-0005vi-00 U=EXIMUSER P=local S=sss 1999-03-02 09:44:33 10HmaY-0005vi-00 Completed diff --git a/test/log/2110 b/test/log/2110 index 660275c5e..296365763 100644 --- a/test/log/2110 +++ b/test/log/2110 @@ -1,14 +1,14 @@ 1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss 1999-03-02 09:44:33 Start queue run: pid=pppp -qf -1999-03-02 09:44:33 10HmaX-0005vi-00 H=127.0.0.1 [127.0.0.1]: a TLS session is required, but the server did not offer TLS support +1999-03-02 09:44:33 10HmaX-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: a TLS session is required, but the server did not offer TLS support 1999-03-02 09:44:33 10HmaX-0005vi-00 [ip4.ip4.ip4.ip4] SSL verify error: depth=0 error=self signed certificate cert=/C=UK/O=The Exim Maintainers/OU=Test Suite/CN=Phil Pennock 1999-03-02 09:44:33 10HmaX-0005vi-00 [ip4.ip4.ip4.ip4] SSL verify error: certificate name mismatch: "/C=UK/O=The Exim Maintainers/OU=Test Suite/CN=Phil Pennock" -1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLSv1:AES256-SHA:256 CV=no C="250 OK id=10HmaY-0005vi-00" +1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4]:1225 X=TLSv1:AES256-SHA:256 CV=no C="250 OK id=10HmaY-0005vi-00" 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed 1999-03-02 09:44:33 End queue run: pid=pppp -qf 1999-03-02 09:44:33 Start queue run: pid=pppp -qf -1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]: a TLS session is required, but the server did not offer TLS support -1999-03-02 09:44:33 10HmaY-0005vi-00 == userx@test.ex R=client T=send_to_server defer (-38) H=127.0.0.1 [127.0.0.1]: a TLS session is required, but the server did not offer TLS support +1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: a TLS session is required, but the server did not offer TLS support +1999-03-02 09:44:33 10HmaY-0005vi-00 == userx@test.ex R=client T=send_to_server defer (-38) H=127.0.0.1 [127.0.0.1]:1111: a TLS session is required, but the server did not offer TLS support 1999-03-02 09:44:33 10HmaY-0005vi-00 ** userx@test.ex: retry timeout exceeded 1999-03-02 09:44:33 10HmaZ-0005vi-00 <= <> R=10HmaY-0005vi-00 U=EXIMUSER P=local S=sss 1999-03-02 09:44:33 10HmaY-0005vi-00 Completed diff --git a/test/scripts/0000-Basic/0211 b/test/scripts/0000-Basic/0211 index 2775d20ef..f8750d2e8 100644 --- a/test/scripts/0000-Basic/0211 +++ b/test/scripts/0000-Basic/0211 @@ -2,6 +2,8 @@ need_ipv4 munge optional_dsn_info # +exim -z "Test: temp-rej connect" +**** server PORT_S 450 I'm busy QUIT @@ -10,6 +12,9 @@ QUIT exim -odi userx@domain1 Test message 1 **** +# +exim -z "Test: temp-rej helo" +**** server PORT_S 220 Connected OK EHLO @@ -21,6 +26,17 @@ QUIT **** exim -qf **** +# +exim -z "Test: drop conn after banner" +**** +server PORT_S +220 Connected OK +**** +exim -qf +**** +# +exim -z "Test: reject connect" +**** server PORT_S 550 Go away QUIT @@ -28,6 +44,9 @@ QUIT **** exim -qf **** +# +exim -z "Test: reject helo" +**** server PORT_S 220 Connected OK EHLO diff --git a/test/stdout/0211 b/test/stdout/0211 index 446203b4f..ebe8246b0 100644 --- a/test/stdout/0211 +++ b/test/stdout/0211 @@ -18,6 +18,10 @@ QUIT End of script Listening on port 1224 ... Connection request from [127.0.0.1] +220 Connected OK +End of script +Listening on port 1224 ... +Connection request from [127.0.0.1] 550 Go away QUIT 250 OK -- 2.30.2