From ac881e2749754fbe167b5f38784dd85b088571cf Mon Sep 17 00:00:00 2001 From: Tony Finch Date: Thu, 13 Aug 2015 15:16:51 +0100 Subject: [PATCH] Improve the consistency of logging incoming and outgoing interfaces. The I= interface field on outgoing lines is now after the H= remote host field, same as incoming lines. There is a separate outgoing_interface log selector which allows you to disable the outgoing I= field. (slight massaging by JH) --- doc/doc-docbook/spec.xfpt | 34 +++++++++++++--- doc/doc-txt/ChangeLog | 6 +++ src/src/deliver.c | 86 +++++++++++++++++++++++++++------------ src/src/globals.c | 2 + src/src/log.c | 4 +- src/src/macros.h | 3 +- test/log/0230 | 2 +- 7 files changed, 102 insertions(+), 35 deletions(-) diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt index 69a810c0c..d2b6043d6 100644 --- a/doc/doc-docbook/spec.xfpt +++ b/doc/doc-docbook/spec.xfpt @@ -35313,6 +35313,9 @@ selection marked by asterisks: &` incoming_interface `& local interface on <= and => lines &` incoming_port `& remote port on <= lines &`*lost_incoming_connection `& as it says (includes timeouts) +.new +&` outgoing_interface `& local interface on => lines +.wen &` outgoing_port `& add remote port to => lines &`*queue_run `& start and end queue runs &` queue_time `& time on queue for one recipient @@ -35438,9 +35441,11 @@ client's ident port times out. &%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 -and (despite the name) the local interface is added to &"=>"& lines.. +added to other SMTP log lines, for example &"SMTP connection from"&, to +rejection lines, and (despite the name) to outgoing &"=>"& and &"->"& lines. +.new +The latter can be disabled by turning off the &%outgoing_interface%& option. +.wen .next .cindex "log" "incoming remote port" .cindex "port" "logging remote" @@ -35458,13 +35463,30 @@ important with the widening use of NAT (see RFC 2505). &%lost_incoming_connection%&: A log line is written when an incoming SMTP connection is unexpectedly dropped. .next +.cindex "log" "outgoing interface" +.cindex "log" "local interface" +.cindex "log" "local address and port" +.cindex "TCP/IP" "logging local address and port" +.cindex "interface" "logging" +.new +&%outgoing_interface%&: If &%incoming_interface%& is turned on, then the +interface on which a message was sent is added to delivery lines as an I= tag +followed by IP address in square brackets. You can disable this by turning +off the &%outgoing_interface%& option. +.wen +.next .cindex "log" "outgoing remote port" .cindex "port" "logging outgoint remote" .cindex "TCP/IP" "logging ougtoing remote port" &%outgoing_port%&: The remote port number is added to delivery log lines (those -containing => tags) following the IP address. This option is not included in -the default setting, because for most ordinary configurations, the remote port -number is always 25 (the SMTP port). +containing => tags) following the IP address. +.new +The local port is also added if &%incoming_interface%& and +&%outgoing_interface%& are both enabled. +.wen +This option is not included in the default setting, because for most ordinary +configurations, the remote port number is always 25 (the SMTP port), and the +local port is a random ephemeral port. .next .cindex "log" "process ids in" .cindex "pid (process id)" "in log lines" diff --git a/doc/doc-txt/ChangeLog b/doc/doc-txt/ChangeLog index c3904dab9..0ec296470 100644 --- a/doc/doc-txt/ChangeLog +++ b/doc/doc-txt/ChangeLog @@ -12,6 +12,12 @@ JH/01 Bug 1664: Disable OCSP for GnuTLS library versions at/before 3.3.16 TF/01 Code cleanup: Overhaul the debug_selector and log_selector machinery to support variable-length bit vectors. No functional change. +TF/02 Improve the consistency of logging incoming and outgoing interfaces. + The I= interface field on outgoing lines is now after the H= remote + host field, same as incoming lines. There is a separate + outgoing_interface log selector which allows you to disable the + outgoing I= field. + Exim version 4.86 ----------------- diff --git a/src/src/deliver.c b/src/src/deliver.c index c796de040..0e7cea31d 100644 --- a/src/src/deliver.c +++ b/src/src/deliver.c @@ -676,39 +676,78 @@ while (addr->parent != NULL) +/************************************************* +* Delivery logging support functions * +*************************************************/ + +/* The LOGGING() checks in d_log_interface() are complicated for backwards +compatibility. When outgoing interface logging was originally added, it was +conditional on just incoming_interface (which is off by default). The +outgoing_interface option is on by default to preserve this behaviour, but +you can enable incoming_interface and disable outgoing_interface to get I= +fields on incoming lines only. + +Arguments: + s The log line buffer + sizep Pointer to the buffer size + ptrp Pointer to current index into buffer + addr The address to be logged + +Returns: New value for s +*/ static uschar * -d_hostlog(uschar * s, int * sizep, int * ptrp, address_item * addr) +d_log_interface(uschar *s, int *sizep, int *ptrp) { - s = string_append(s, sizep, ptrp, 5, US" H=", addr->host_used->name, - US" [", addr->host_used->address, US"]"); +if (LOGGING(incoming_interface) && LOGGING(outgoing_interface) + && sending_ip_address != NULL) + { + s = string_append(s, sizep, ptrp, 2, US" I=[", sending_ip_address); if (LOGGING(outgoing_port)) - s = string_append(s, sizep, ptrp, 2, US":", string_sprintf("%d", - addr->host_used->port)); - return s; + s = string_append(s, sizep, ptrp, 2, US"]:", + string_sprintf("%d", sending_port)); + else + s = string_cat(s, sizep, ptrp, "]", 1); + } +return s; } + + +static uschar * +d_hostlog(uschar *s, int *sizep, int *ptrp, address_item *addr) +{ +s = string_append(s, sizep, ptrp, 5, US" H=", addr->host_used->name, + US" [", addr->host_used->address, US"]"); +if (LOGGING(outgoing_port)) + s = string_append(s, sizep, ptrp, 2, US":", string_sprintf("%d", + addr->host_used->port)); +return d_log_interface(s, sizep, ptrp); +} + + + #ifdef SUPPORT_TLS static uschar * d_tlslog(uschar * s, int * sizep, int * ptrp, address_item * addr) { - if (LOGGING(tls_cipher) && addr->cipher != NULL) - s = string_append(s, sizep, ptrp, 2, US" X=", addr->cipher); - if (LOGGING(tls_certificate_verified) && addr->cipher != NULL) - s = string_append(s, sizep, ptrp, 2, US" CV=", - testflag(addr, af_cert_verified) - ? +if (LOGGING(tls_cipher) && addr->cipher != NULL) + s = string_append(s, sizep, ptrp, 2, US" X=", addr->cipher); +if (LOGGING(tls_certificate_verified) && addr->cipher != NULL) + s = string_append(s, sizep, ptrp, 2, US" CV=", + testflag(addr, af_cert_verified) + ? #ifdef EXPERIMENTAL_DANE - testflag(addr, af_dane_verified) - ? "dane" - : + testflag(addr, af_dane_verified) + ? "dane" + : #endif - "yes" - : "no"); - if (LOGGING(tls_peerdn) && addr->peerdn != NULL) - s = string_append(s, sizep, ptrp, 3, US" DN=\"", - string_printing(addr->peerdn), US"\""); - return s; + "yes" + : "no"); +if (LOGGING(tls_peerdn) && addr->peerdn != NULL) + s = string_append(s, sizep, ptrp, 3, US" DN=\"", + string_printing(addr->peerdn), US"\""); +return s; } #endif @@ -816,10 +855,6 @@ else s = string_append(s, &size, &ptr, 2, US"> ", log_address); } -if (LOGGING(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 (LOGGING(sender_on_delivery) || msg) s = string_append(s, &size, &ptr, 3, US" F=<", #ifdef EXPERIMENTAL_INTERNATIONAL @@ -862,6 +897,7 @@ if (addr->transport->info->local) { if (addr->host_list) s = string_append(s, &size, &ptr, 2, US" H=", addr->host_list->name); + s = d_log_interface(s, &size, &ptr); if (addr->shadow_message != NULL) s = string_cat(s, &size, &ptr, addr->shadow_message, Ustrlen(addr->shadow_message)); diff --git a/src/src/globals.c b/src/src/globals.c index 1344b5aed..4188b4d84 100644 --- a/src/src/globals.c +++ b/src/src/globals.c @@ -827,6 +827,7 @@ int log_default[] = { /* for initializing log_selector */ Li_etrn, Li_host_lookup_failed, Li_lost_incoming_connection, + Li_outgoing_interface, /* see d_log_interface in deliver.c */ Li_queue_run, Li_rejected_header, Li_retry_defer, @@ -863,6 +864,7 @@ bit_table log_options[] = { /* must be in alphabetical order */ BIT_TABLE(L, incoming_interface), BIT_TABLE(L, incoming_port), BIT_TABLE(L, lost_incoming_connection), + BIT_TABLE(L, outgoing_interface), BIT_TABLE(L, outgoing_port), BIT_TABLE(L, pid), #ifdef EXPERIMENTAL_PROXY diff --git a/src/src/log.c b/src/src/log.c index b2d1fcfc1..558c000d7 100644 --- a/src/src/log.c +++ b/src/src/log.c @@ -753,8 +753,8 @@ DEBUG(D_any|D_v) for (i = 0; i < log_options_count; i++) { - unsigned int bit = log_options[i].bit; - if (bit < BITWORDSIZE && selector == BIT(bit)) + unsigned int bitnum = log_options[i].bit; + if (bitnum < BITWORDSIZE && selector == BIT(bitnum)) { *ptr++ = ' '; Ustrcpy(ptr, log_options[i].name); diff --git a/src/src/macros.h b/src/src/macros.h index d63025ec2..0ce24f8cb 100644 --- a/src/src/macros.h +++ b/src/src/macros.h @@ -474,8 +474,9 @@ enum { Li_8bitmime, Li_smtp_mailauth, Li_proxy, + Li_outgoing_interface, - log_selector_size = BITWORD(Li_proxy) + 1 + log_selector_size = BITWORD(Li_outgoing_interface) + 1 }; #define LOGGING(opt) BIT_TEST(log_selector, log_selector_size, Li_##opt) diff --git a/test/log/0230 b/test/log/0230 index de9d5a55e..723ac066c 100644 --- a/test/log/0230 +++ b/test/log/0230 @@ -15,7 +15,7 @@ 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 => x@test.ex R=to_server T=remote H=127.0.0.1 [127.0.0.1] I=[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 -- 2.25.1