From aeaf5db33f20a06399b8b15630cd2f5e9755e38a Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Sun, 18 Jan 2015 21:05:56 +0000 Subject: [PATCH] Log local IP on delivery log line, under the incoming_interface log selector. Bug 507 --- doc/doc-docbook/spec.xfpt | 12 ++++++++---- doc/doc-txt/ChangeLog | 3 +++ src/src/deliver.c | 24 ++++++++++++++++++++++++ test/confs/0230 | 11 +++++++++++ test/log/0230 | 29 ++++++++++++++++++++--------- test/mail/0230.x | 12 ++++++------ test/msglog/0230.10HmbC-0005vi-00 | 1 + test/scripts/0000-Basic/0230 | 20 ++++++++++++++++++++ test/stderr/0230 | 4 ++-- test/stdout/0230 | 6 ++++++ 10 files changed, 101 insertions(+), 21 deletions(-) create mode 100644 test/msglog/0230.10HmbC-0005vi-00 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 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 ) 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 ) 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 ) 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: +rcpt to: +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 -- 2.25.1