Log local IP on delivery log line, under the incoming_interface log selector. Bug 507

10 files changed, 101 insertions, 21 deletions

diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index f7bebc866..d78797fb7 100644
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -34943,8 +34943,8 @@ selection marked by asterisks:
 &`*etrn                       `&  ETRN commands
 &`*host_lookup_failed         `&  as it says
 &` ident_timeout              `&  timeout for ident connection
-&` incoming_interface         `&  incoming interface on <= lines
-&` incoming_port              `&  incoming port on <= lines
+&` incoming_interface         `&  local interface on <= and => lines
+&` incoming_port              `&  remote port on <= lines
 &`*lost_incoming_connection   `&  as it says (includes timeouts)
 &` outgoing_port              `&  add remote port to => lines
 &`*queue_run                  `&  start and end queue runs
@@ -35063,12 +35063,16 @@ routing email addresses, but it does apply to &"byname"& lookups.
 client's ident port times out.
 .next
 .cindex "log" "incoming interface"
+.cindex "log" "local interface"
+.cindex "log" "local address and port"
+.cindex "TCP/IP" "logging local address and port"
 .cindex "interface" "logging"
 &%incoming_interface%&: The interface on which a message was received is added
 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"&, and to
-rejection lines.
+added to other SMTP log lines, for example &"SMTP connection from"& and to
+rejection lines
+and (despite the name) the local interface is added to &"=>"& lines..
 .next
 .cindex "log" "incoming remote port"
 .cindex "port" "logging remote"
diff --git a/doc/doc-txt/ChangeLog b/doc/doc-txt/ChangeLog
index f333752d7..eeefef71c 100644
--- a/doc/doc-txt/ChangeLog
+++ b/doc/doc-txt/ChangeLog
@@ -41,6 +41,9 @@ JH/09 A timeout of 2 minutes is now applied to all malware scanner types by
 
 JH/10 The smtp_receive_timeout main option is now expanded before use.
 
+JH/11 The incoming_interface log option now also enables logging of the
+      local interface on delivery outgoing connections.
+
 
 
 Exim version 4.85
diff --git a/src/src/deliver.c b/src/src/deliver.c
index a0c48d652..afbadca6a 100644
--- a/src/src/deliver.c
+++ b/src/src/deliver.c
@@ -817,6 +817,10 @@ else
   s = string_append(s, &size, &ptr, 2, US"> ", log_address);
   }
 
+if (log_extra_selector & LX_incoming_interface  &&  sending_ip_address)
+  s = string_append(s, &size, &ptr, 3, US" I=[", sending_ip_address, US"]");
+  /* for the port:  string_sprintf("%d", sending_port) */
+
 if ((log_extra_selector & LX_sender_on_delivery) != 0  ||  msg)
   s = string_append(s, &size, &ptr, 3, US" F=<", sender_address, US">");
 
@@ -3219,6 +3223,14 @@ while (!done)
     addr = addr->next;
     break;
 
+    /* Local interface address/port */
+    case 'I':
+    if (*ptr) sending_ip_address = string_copy(ptr);
+    while (*ptr++) ;
+    if (*ptr) sending_port = atoi(ptr);
+    while (*ptr++) ;
+    break;
+
     /* Z marks the logical end of the data. It is followed by '0' if
     continue_transport was NULL at the end of transporting, otherwise '1'.
     We need to know when it becomes NULL during a delivery down a passed SMTP
@@ -4430,6 +4442,18 @@ for (delivery_count = 0; addr_remote != NULL; delivery_count++)
       rmt_dlv_checked_write(fd, 'A', '0', big_buffer, ptr - big_buffer);
       }
 
+    /* Local interface address/port */
+    if (log_extra_selector & LX_incoming_interface  &&  sending_ip_address)
+      {
+      uschar * ptr = big_buffer;
+      sprintf(CS ptr, "%.128s", sending_ip_address);
+      while(*ptr++);
+      sprintf(CS ptr, "%d", sending_port);
+      while(*ptr++);
+
+      rmt_dlv_checked_write(fd, 'I', '0', big_buffer, ptr - big_buffer);
+      }
+
     /* Add termination flag, close the pipe, and that's it. The character
     after 'Z' indicates whether continue_transport is now NULL or not.
     A change from non-NULL to NULL indicates a problem with a continuing
diff --git a/test/confs/0230 b/test/confs/0230
index df25468ed..350a110a8 100644
--- a/test/confs/0230
+++ b/test/confs/0230
@@ -36,6 +36,14 @@ check_recipient:
 
 begin routers
 
+.ifdef RT
+to_server:
+  driver = manualroute
+  transport = remote
+  route_list = * 127.0.0.1
+  self = send
+.endif
+
 fail_remote_domains:
   driver = redirect
   domains = ! +local_domains
@@ -57,6 +65,9 @@ local_delivery:
   headers_add = Port: $sender_host_port
   user = CALLER
 
+remote:
+  driver = smtp
+  port = PORT_D
 
 # ----- Retry -----
 
diff --git a/test/log/0230 b/test/log/0230
index faee13556..de9d5a55e 100644
--- a/test/log/0230
+++ b/test/log/0230
@@ -11,15 +11,26 @@
 1999-03-02 09:44:33 10HmaX-0005vi-00 => x <x@test.ex> R=server T=local_delivery
 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 SMTP connection from root
+1999-03-02 09:44:33 10HmbB-0005vi-00 <= x@y.x H=[V4NET.9.8.7]:1112 U=root P=smtp S=sss
+1999-03-02 09:44:33 SMTP connection from root closed by QUIT
+1999-03-02 09:44:33 Start queue run: pid=pppp -qf
+1999-03-02 09:44:33 10HmbB-0005vi-00 => x@test.ex I=[127.0.0.1] R=to_server T=remote H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmbC-0005vi-00"
+1999-03-02 09:44:33 10HmbB-0005vi-00 Completed
+1999-03-02 09:44:33 End queue run: pid=pppp -qf
 
 ******** SERVER ********
 1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port 1225
-1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1112 I=[ip4.ip4.ip4.ip4]:1225 (TCP/IP connection count = 1)
-1999-03-02 09:44:33 10HmaY-0005vi-00 <= x@y.x H=[ip4.ip4.ip4.ip4]:1112 I=[ip4.ip4.ip4.ip4]:1225 P=smtp S=sss
-1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1112 I=[ip4.ip4.ip4.ip4]:1225 closed by QUIT
-1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1113 I=[127.0.0.1]:1225 (TCP/IP connection count = 1)
-1999-03-02 09:44:33 10HmaZ-0005vi-00 <= x@y.x H=[127.0.0.1]:1113 I=[127.0.0.1]:1225 P=smtp S=sss
-1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1113 I=[127.0.0.1]:1225 closed by QUIT
-1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1114 I=[ip4.ip4.ip4.ip4]:1225 (TCP/IP connection count = 1)
-1999-03-02 09:44:33 10HmbA-0005vi-00 <= x@y.x H=(rhubarb) [ip4.ip4.ip4.ip4]:1114 I=[ip4.ip4.ip4.ip4]:1225 P=smtp S=sss
-1999-03-02 09:44:33 SMTP connection from (rhubarb) [ip4.ip4.ip4.ip4]:1114 I=[ip4.ip4.ip4.ip4]:1225 closed by QUIT
+1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:1225 (TCP/IP connection count = 1)
+1999-03-02 09:44:33 10HmaY-0005vi-00 <= x@y.x H=[ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:1225 P=smtp S=sss
+1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1113 I=[ip4.ip4.ip4.ip4]:1225 closed by QUIT
+1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1114 I=[127.0.0.1]:1225 (TCP/IP connection count = 1)
+1999-03-02 09:44:33 10HmaZ-0005vi-00 <= x@y.x H=[127.0.0.1]:1114 I=[127.0.0.1]:1225 P=smtp S=sss
+1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1114 I=[127.0.0.1]:1225 closed by QUIT
+1999-03-02 09:44:33 SMTP connection from [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:1225 (TCP/IP connection count = 1)
+1999-03-02 09:44:33 10HmbA-0005vi-00 <= x@y.x H=(rhubarb) [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:1225 P=smtp S=sss
+1999-03-02 09:44:33 SMTP connection from (rhubarb) [ip4.ip4.ip4.ip4]:1115 I=[ip4.ip4.ip4.ip4]:1225 closed by QUIT
+1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port 1225
+1999-03-02 09:44:33 SMTP connection from [127.0.0.1]:1116 I=[127.0.0.1]:1225 (TCP/IP connection count = 1)
+1999-03-02 09:44:33 10HmbC-0005vi-00 <= x@y.x H=localhost (myhost.test.ex) [127.0.0.1]:1116 I=[127.0.0.1]:1225 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]:1225 closed by QUIT
diff --git a/test/mail/0230.x b/test/mail/0230.x
index a033d4264..6027b25e1 100644
--- a/test/mail/0230.x
+++ b/test/mail/0230.x
@@ -1,28 +1,28 @@
 From x@y.x Tue Mar 02 09:44:33 1999
-Received: from [ip4.ip4.ip4.ip4] (port=1112)
+Received: from [ip4.ip4.ip4.ip4] (port=1113)
 	by myhost.test.ex with smtp (Exim x.yz)
 	(envelope-from <x@y.x>)
 	id 10HmaY-0005vi-00
 	for x@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
-Port: 1112
+Port: 1113
 
 
 From x@y.x Tue Mar 02 09:44:33 1999
-Received: from [127.0.0.1] (port=1113)
+Received: from [127.0.0.1] (port=1114)
 	by myhost.test.ex with smtp (Exim x.yz)
 	(envelope-from <x@y.x>)
 	id 10HmaZ-0005vi-00
 	for x@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
-Port: 1113
+Port: 1114
 
 
 From x@y.x Tue Mar 02 09:44:33 1999
-Received: from [ip4.ip4.ip4.ip4] (port=1114 helo=rhubarb)
+Received: from [ip4.ip4.ip4.ip4] (port=1115 helo=rhubarb)
 	by myhost.test.ex with smtp (Exim x.yz)
 	(envelope-from <x@y.x>)
 	id 10HmbA-0005vi-00
 	for x@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
-Port: 1114
+Port: 1115
 
 
 From x@y.x Tue Mar 02 09:44:33 1999
diff --git a/test/msglog/0230.10HmbC-0005vi-00 b/test/msglog/0230.10HmbC-0005vi-00
new file mode 100644
index 000000000..6a3489d5e
--- /dev/null
+++ b/test/msglog/0230.10HmbC-0005vi-00
@@ -0,0 +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]:1225 P=esmtp S=sss
diff --git a/test/scripts/0000-Basic/0230 b/test/scripts/0000-Basic/0230
index 1bd97d670..b62e31355 100644
--- a/test/scripts/0000-Basic/0230
+++ b/test/scripts/0000-Basic/0230
@@ -60,3 +60,23 @@ exim -odi -qf
 exim -bh 192.168.1.2.99
 quit
 ****
+#
+#
+#
+#
+#
+exim -DSERVER=server -bd -oX PORT_D
+****
+sudo exim -DRT -bs -oMa V4NET.9.8.7.1225
+mail from:<x@y.x>
+rcpt to:<x@test.ex>
+data
+this is a message
+.
+quit
+****
+exim -DRT -odi -qf
+****
+#
+#
+killdaemon
diff --git a/test/stderr/0230 b/test/stderr/0230
index e45c5b44f..9017df8f2 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]:1115
+LOG: SMTP connection 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]:1115
 >>> 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]:1115 closed by QUIT
+LOG: SMTP connection from [192.168.1.2]:1117 closed by QUIT
 
 ******** SERVER ********
diff --git a/test/stdout/0230 b/test/stdout/0230
index d7d68d378..67e1ffec0 100644
--- a/test/stdout/0230
+++ b/test/stdout/0230
@@ -73,3 +73,9 @@ End of script
 
 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000

 221 myhost.test.ex closing connection

+220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000

+250 OK

+250 Accepted

+354 Enter message, ending with "." on a line by itself

+250 OK id=10HmbB-0005vi-00

+221 myhost.test.ex closing connection