Logging: support +outgoing_port on defer lines and per-host error lines
authorJeremy Harris <jgh146exb@wizmail.org>
Tue, 10 Nov 2015 23:12:26 +0000 (23:12 +0000)
committerJeremy Harris <jgh146exb@wizmail.org>
Thu, 12 Nov 2015 18:01:33 +0000 (18:01 +0000)
src/src/deliver.c
src/src/transports/smtp.c
test/confs/2010
test/confs/2110
test/log/0211
test/log/2010
test/log/2110
test/scripts/0000-Basic/0211
test/stdout/0211

index f3ae2208a85be40e10e63524dc63c3a52cd9ba54..e1f4e0e293cb69a24a0be0e750f1eb298b4c0ab9 100644 (file)
@@ -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);
index eae54764b2da7d820fddf9982d3e33f13e5c2f9c..59afe42aa84229b636eb96a97769007d7c209248 100644 (file)
@@ -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. */
index 8aede594a4a951b0c1ea3e27e85b5f8d8a388f7c..34383c25a59b938f13a3ed2a854eab277ebabb43 100644 (file)
@@ -14,6 +14,8 @@ gecos_name = CALLER_NAME
 
 # ----- Main settings -----
 
+log_selector = +outgoing_port
+
 acl_smtp_rcpt = accept
 
 queue_only
index 2bd3ed65684a4aca9ff684fb383fd031fbea42df..db6864863901eae85ebde81959d1e4b185828d5d 100644 (file)
@@ -13,6 +13,8 @@ gecos_name = CALLER_NAME
 
 # ----- Main settings -----
 
+log_selector = +outgoing_port
+
 acl_smtp_rcpt = accept
 
 queue_only
index 35da72e04539fc517be3423be2b5c034949bbd4d..9a5824674f72939a1252f8164fe5577196798c88 100644 (file)
@@ -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=<CALLER@test.ex> 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=<CALLER@test.ex> 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=<CALLER@test.ex> 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
index 9857a5604a47bd5ac2bcaf7c5a987176489a7a27..f5cde396b846a7c987df4ec2985a1970a7d7ef50 100644 (file)
@@ -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
index 660275c5ea12735d327f1b9ac5bfff585371c825..296365763bb502806cfd4452f0605d26633e4cad 100644 (file)
@@ -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
index 2775d20ef6f6ad94ff269368e6978a6a36214c76..f8750d2e84e55413e62c06b111faa57457d67a36 100644 (file)
@@ -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
index 446203b4fd0ccc8c2b4b42552a32e898a508c879..ebe8246b0d9fee1a95576831ed59cc17cc9ce6b2 100644 (file)
@@ -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