Logging: add I= element to transport-defer lines. Bug 2675

diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index d62ceafd73c5047de20d559ed24fa03cf719c115..34b36ca9ffd67bcf58a928db4514c5865b5e0fcd 100644 (file)
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -38668,6 +38668,7 @@ routing email addresses, but it does apply to &"byname"& lookups.
 client's ident port times out.
 .next
 .cindex "log" "incoming interface"
 client's ident port times out.
 .next
 .cindex "log" "incoming interface"

+.cindex "log" "outgoing interface"

 .cindex "log" "local interface"
 .cindex "log" "local address and port"
 .cindex "TCP/IP" "logging local address and port"
 .cindex "log" "local interface"
 .cindex "log" "local address and port"
 .cindex "TCP/IP" "logging local address and port"


@@ -38676,7 +38677,10 @@ client's ident port times out.
 to the &"<="& line as an IP address in square brackets, tagged by I= and
 followed by a colon and the port number. The local interface and port are also
 added to other SMTP log lines, for example, &"SMTP connection from"&, to
 to the &"<="& line as an IP address in square brackets, tagged by I= and
 followed by a colon and the port number. The local interface and port are also
 added to other SMTP log lines, for example, &"SMTP connection from"&, to

-rejection lines, and (despite the name) to outgoing &"=>"& and &"->"& lines.
+rejection lines, and (despite the name) to outgoing
+.new
+&"=>"&, &"->"&, &"=="& and &"**"& lines.
+.wen

 The latter can be disabled by turning off the &%outgoing_interface%& option.
 .next
 .cindex log "incoming proxy address"
 The latter can be disabled by turning off the &%outgoing_interface%& option.
 .next
 .cindex log "incoming proxy address"

diff --git a/doc/doc-txt/ChangeLog b/doc/doc-txt/ChangeLog
index d56454ccc1a1cb9b5564b52545a967622db9f71a..16098d50e88c09563e5e136f6a8496a1cc13bcf6 100644 (file)
--- a/doc/doc-txt/ChangeLog
+++ b/doc/doc-txt/ChangeLog
@@ -140,6 +140,10 @@ JH/28 Fix spurious logging of select error.  Some platforms, notably FreeBSD,
       a bug in the error-handling.  This was benign apart from the log
       messages.
 
       a bug in the error-handling.  This was benign apart from the log
       messages.
 

+JH/29 Bug 2675: add outgoing-interface I= element to deferred "==" log lines,
+      for consistency with delivered "=>" and failed "**" lines.  While we're
+      there, handle PRX and TFO.
+

 
 Exim version 4.94
 -----------------
 
 Exim version 4.94
 -----------------

diff --git a/src/src/deliver.c b/src/src/deliver.c
index 9c4c1a746d9ee0c829cd1f3175f7c9ad2a583975..4e6f08f898b91173a93e1a3480579253e173b4b5 100644 (file)
--- a/src/src/deliver.c
+++ b/src/src/deliver.c
@@ -1325,20 +1325,10 @@ else if (driver_kind)
 g = string_fmt_append(g, " defer (%d)", addr->basic_errno);
 
 if (addr->basic_errno > 0)
 g = string_fmt_append(g, " defer (%d)", addr->basic_errno);
 
 if (addr->basic_errno > 0)

-  g = string_append(g, 2, US": ",
-    US strerror(addr->basic_errno));
+  g = string_append(g, 2, US": ", US strerror(addr->basic_errno));

 
 if (addr->host_used)
 
 if (addr->host_used)

-  {
-  g = string_append(g, 5,
-                   US" H=", addr->host_used->name,
-                   US" [",  addr->host_used->address, US"]");
-  if (LOGGING(outgoing_port))
-    {
-    int port = addr->host_used->port;
-    g = string_fmt_append(g, ":%d", port == PORT_NONE ? 25 : port);
-    }
-  }
+  g = d_hostlog(g, addr);

 
 if (LOGGING(deliver_time))
   g = string_append(g, 2, US" DT=", string_timediff(&addr->delivery_time));
 
 if (LOGGING(deliver_time))
   g = string_append(g, 2, US" DT=", string_timediff(&addr->delivery_time));

diff --git a/test/confs/0179 b/test/confs/0179
index f18ab32e56d9eae7ae2b50749112596a8dba349b..4efe92f948af6d682065c9b775fc7bab0b9f5634 100644 (file)
--- a/test/confs/0179
+++ b/test/confs/0179
@@ -8,7 +8,7 @@ primary_hostname = myhost.test.ex
 
 queue_run_in_order
 # incoming_interface is used here to get the _outgoing_ local port
 
 queue_run_in_order
 # incoming_interface is used here to get the _outgoing_ local port

-log_selector = +outgoing_port +incoming_interface
+log_selector = +outgoing_port +incoming_interface +received_recipients

 
 
 # ----- Routers -----
 
 
 # ----- Routers -----


@@ -20,6 +20,7 @@ all:
   route_list = * 127.0.0.1 byname
   self = send
   transport = smtp
   route_list = * 127.0.0.1 byname
   self = send
   transport = smtp

+  errors_to = ""

   no_more
 
 
   no_more
 
 

diff --git a/test/log/0179 b/test/log/0179
index de05f6462d8104853f029d8a0cb0e390912b1a05..614fea64045b8fe645e2a7bd059ebc07bb6a018c 100644 (file)
--- a/test/log/0179
+++ b/test/log/0179
@@ -1,8 +1,18 @@
-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 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for userx@domain.com
+1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for abcd@domain.com

 1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1]:PORT_S I=[127.0.0.1]:ppppp C="250 OK"
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
 1999-03-02 09:44:33 10HmaY-0005vi-00 => abcd@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1]:PORT_S I=[127.0.0.1]:ppppp* C="250 OK"
 1999-03-02 09:44:33 10HmaY-0005vi-00 Completed
 1999-03-02 09:44:33 End queue run: pid=pppp -qqf
 1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1]:PORT_S I=[127.0.0.1]:ppppp C="250 OK"
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
 1999-03-02 09:44:33 10HmaY-0005vi-00 => abcd@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1]:PORT_S I=[127.0.0.1]:ppppp* C="250 OK"
 1999-03-02 09:44:33 10HmaY-0005vi-00 Completed
 1999-03-02 09:44:33 End queue run: pid=pppp -qqf

+1999-03-02 09:44:33 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for userz@domain.com
+1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
+1999-03-02 09:44:33 10HmaZ-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: SMTP error from remote mail server after MAIL FROM:<>: 450 not right now, sorry
+1999-03-02 09:44:33 10HmaZ-0005vi-00 == userz@domain.com R=all T=smtp defer (-45) H=127.0.0.1 [127.0.0.1]:PORT_S I=[127.0.0.1]:ppppp: SMTP error from remote mail server after MAIL FROM:<>: 450 not right now, sorry
+1999-03-02 09:44:33 End queue run: pid=pppp -qqf
+1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
+1999-03-02 09:44:33 10HmaZ-0005vi-00 ** userz@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1]:PORT_S I=[127.0.0.1]:ppppp: SMTP error from remote mail server after RCPT TO:<userz@domain.com>: 550 Recipient refused
+1999-03-02 09:44:33 10HmaZ-0005vi-00 userz@domain.com: error ignored
+1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed
+1999-03-02 09:44:33 End queue run: pid=pppp -qqf

diff --git a/test/log/2010 b/test/log/2010
index 5116b354ea0b59b2a8716340ff6545dd0c046a15..2295e686045367ee50742265ca656655fd381ca7 100644 (file)
--- a/test/log/2010
+++ b/test/log/2010
@@ -6,7 +6,7 @@
 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]:1111: a TLS session is required, but the server did not offer TLS support
 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]: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 R=client T=send_to_server defer (-38) H=127.0.0.1 [127.0.0.1]:PORT_D: 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
 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/2037 b/test/log/2037
index 3291debab9ef387b264bd69a7db73151cdb999eb..abe4b3ebd9327d79c31e9e9658067a76db169160 100644 (file)
--- a/test/log/2037
+++ b/test/log/2037
@@ -1,7 +1,7 @@
 1999-03-02 09:44:33 U=CALLER F=<> temporarily rejected RCPT <rcpt_defer@test.ex>: Could not complete recipient verify callout: 127.0.0.1 [127.0.0.1] : SMTP error from remote mail server after RCPT TO:<rcpt_defer@test.ex>: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local-smtp S=sss for data_defer@test.ex
 1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 U=CALLER F=<> temporarily rejected RCPT <rcpt_defer@test.ex>: Could not complete recipient verify callout: 127.0.0.1 [127.0.0.1] : SMTP error from remote mail server after RCPT TO:<rcpt_defer@test.ex>: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local-smtp S=sss for data_defer@test.ex
 1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later

-1999-03-02 09:44:33 10HmaY-0005vi-00 == data_defer@test.ex R=client T=t1 defer (-46) H=127.0.0.1 [127.0.0.1]:1111: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later
+1999-03-02 09:44:33 10HmaY-0005vi-00 == data_defer@test.ex R=client T=t1 defer (-46) H=127.0.0.1 [127.0.0.1]:PORT_D: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later

 
 ******** SERVER ********
 1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
 
 ******** SERVER ********
 1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D

diff --git a/test/log/2110 b/test/log/2110
index ef00023df8ecf0c5b96a655e9e889764d76996fa..315dc244aaead0332181a3a6dc2d37a367c4e9fd 100644 (file)
--- a/test/log/2110
+++ b/test/log/2110
@@ -8,7 +8,7 @@
 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]:1111: a TLS session is required, but the server did not offer TLS support
 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]: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 R=client T=send_to_server defer (-38) H=127.0.0.1 [127.0.0.1]:PORT_D: 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
 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/2137 b/test/log/2137
index 3291debab9ef387b264bd69a7db73151cdb999eb..abe4b3ebd9327d79c31e9e9658067a76db169160 100644 (file)
--- a/test/log/2137
+++ b/test/log/2137
@@ -1,7 +1,7 @@
 1999-03-02 09:44:33 U=CALLER F=<> temporarily rejected RCPT <rcpt_defer@test.ex>: Could not complete recipient verify callout: 127.0.0.1 [127.0.0.1] : SMTP error from remote mail server after RCPT TO:<rcpt_defer@test.ex>: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local-smtp S=sss for data_defer@test.ex
 1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 U=CALLER F=<> temporarily rejected RCPT <rcpt_defer@test.ex>: Could not complete recipient verify callout: 127.0.0.1 [127.0.0.1] : SMTP error from remote mail server after RCPT TO:<rcpt_defer@test.ex>: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local-smtp S=sss for data_defer@test.ex
 1999-03-02 09:44:33 10HmaY-0005vi-00 H=127.0.0.1 [127.0.0.1]:1111: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later

-1999-03-02 09:44:33 10HmaY-0005vi-00 == data_defer@test.ex R=client T=t1 defer (-46) H=127.0.0.1 [127.0.0.1]:1111: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later
+1999-03-02 09:44:33 10HmaY-0005vi-00 == data_defer@test.ex R=client T=t1 defer (-46) H=127.0.0.1 [127.0.0.1]:PORT_D: SMTP error from remote mail server after end of data: 451 Temporary local problem - please try later

 
 ******** SERVER ********
 1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
 
 ******** SERVER ********
 1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D

diff --git a/test/runtest b/test/runtest
index d4e469b9f941686eedb2635b573b50955843d76d..b5ace4ee3322a7f9c8b9fe18221d85f1c40a365d 100755 (executable)
--- a/test/runtest
+++ b/test/runtest
@@ -780,7 +780,7 @@ RESET_AFTER_EXTRA_LINE_READ:
 
   # This handles "connection from" and the like, when the port is given
   if (!/listening for SMTP on/ && !/Connecting to/ && !/=>/ && !/->/
 
   # This handles "connection from" and the like, when the port is given
   if (!/listening for SMTP on/ && !/Connecting to/ && !/=>/ && !/->/

-      && !/\*>/ && !/Connection refused/)
+      && !/\*>/&& !/==/  && !/\*\*/ && !/Connection refused/ && !/in response to/)

     {
     s/\[([a-z\d:]+|\d+(?:\.\d+){3})\]:(\d+)/"[".$1."]:".new_value($2,"%s",\$next_port)/ie;
     }
     {
     s/\[([a-z\d:]+|\d+(?:\.\d+){3})\]:(\d+)/"[".$1."]:".new_value($2,"%s",\$next_port)/ie;
     }

diff --git a/test/scripts/0000-Basic/0179 b/test/scripts/0000-Basic/0179
index 932cc11feb803e74b66054a689df41675a16ea2b..6a7b2253b7f12ce6f49fd7dfbcd99cf1545bd341 100644 (file)
--- a/test/scripts/0000-Basic/0179
+++ b/test/scripts/0000-Basic/0179
@@ -33,3 +33,38 @@ QUIT
 ****
 exim -odi -qqf
 ****
 ****
 exim -odi -qqf
 ****

+#
+# Defer from receiving host
+exim -odq userz@domain.com
+.
+****
+server PORT_S
+220 ESMTP
+EHLO
+250-OK
+250 HELP
+MAIL FROM:
+450 not right now, sorry
+QUIT
+250 OK
+****
+exim -odi -qqf
+****
+#
+# Deny from receiving host
+server PORT_S
+220 ESMTP
+EHLO
+250-OK
+250 HELP
+MAIL FROM:
+250 Sender OK
+RCPT TO:
+550 Recipient refused
+QUIT
+250 OK
+****
+exim -odi -qqf
+****
+#
+no_msglog_check

diff --git a/test/stdout/0179 b/test/stdout/0179
index 9013698dfed2c43e2509ad3c9cff6d7d108c5244..c8db946208147d57cb2199111425708da619e16d 100644 (file)
--- a/test/stdout/0179
+++ b/test/stdout/0179
@@ -6,7 +6,7 @@ Connection request from [127.0.0.1]
 EHLO myhost.test.ex
 250-OK
 250 HELP
 EHLO myhost.test.ex
 250-OK
 250 HELP

-MAIL FROM:<CALLER@myhost.test.ex>
+MAIL FROM:<>

 250 Sender OK
 RCPT TO:<userx@domain.com>
 250 Recipient OK
 250 Sender OK
 RCPT TO:<userx@domain.com>
 250 Recipient OK


@@ -22,7 +22,7 @@ Date: Tue, 2 Mar 1999 09:44:33 +0000
 
 .
 250 OK
 
 .
 250 OK

-MAIL FROM:<CALLER@myhost.test.ex>
+MAIL FROM:<>

 250 Sender OK
 RCPT TO:<abcd@domain.com>
 250 Recipient OK
 250 Sender OK
 RCPT TO:<abcd@domain.com>
 250 Recipient OK


@@ -41,3 +41,27 @@ Date: Tue, 2 Mar 1999 09:44:33 +0000
 QUIT
 250 OK
 End of script
 QUIT
 250 OK
 End of script

+Listening on port 1224 ... 
+Connection request from [127.0.0.1]
+220 ESMTP
+EHLO myhost.test.ex
+250-OK
+250 HELP
+MAIL FROM:<>
+450 not right now, sorry
+QUIT
+250 OK
+End of script
+Listening on port 1224 ... 
+Connection request from [127.0.0.1]
+220 ESMTP
+EHLO myhost.test.ex
+250-OK
+250 HELP
+MAIL FROM:<>
+250 Sender OK
+RCPT TO:<userz@domain.com>
+550 Recipient refused
+QUIT
+250 OK
+End of script