Improve the consistency of logging incoming and outgoing interfaces.
authorTony Finch <dot@dotat.at>
Thu, 13 Aug 2015 14:16:51 +0000 (15:16 +0100)
committerJeremy Harris <jgh146exb@wizmail.org>
Fri, 14 Aug 2015 15:10:56 +0000 (16:10 +0100)
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
doc/doc-txt/ChangeLog
src/src/deliver.c
src/src/globals.c
src/src/log.c
src/src/macros.h
test/log/0230

index 69a810c0c5d7a8dfb3de88dde31c27ecdc58632c..d2b6043d669bce72e606c694040a43b9548003c9 100644 (file)
@@ -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"
index c3904dab9cc68d02417d38c0c0d30dad09e890d2..0ec296470d5d266a0f5fbde3bc98beb689f5dc26 100644 (file)
@@ -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
 -----------------
index c796de040229fd73061285305c4942dc4069a141..0e7cea31d3b96832c0e9bf23331a875bccd99c7f 100644 (file)
@@ -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));
index 1344b5aeda133b75a87688232632ce57f4dde5b7..4188b4d845974c4dadfb63f54e264f5ba91fe929 100644 (file)
@@ -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
index b2d1fcfc1c5280e06464db6589d7eb4fc502d445..558c000d73d61e63c3ae794999c87824863c8fe5 100644 (file)
@@ -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);
index d63025ec251a2a05290288036bec872675893561..0ce24f8cb1ae84d8bd58bf7c225b3c4f624c6a96 100644 (file)
@@ -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)
index de9d5a55e9835fb7637f1c17920dab79ad7d9084..723ac066ccb96032c1f1db67a9d59f2840c19510 100644 (file)
@@ -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