Logging: mark continued-TLS connection deliveries with "X-*"
authorJeremy Harris <jgh146exb@wizmail.org>
Tue, 14 Mar 2017 16:38:41 +0000 (16:38 +0000)
committerJeremy Harris <jgh146exb@wizmail.org>
Wed, 15 Mar 2017 22:33:06 +0000 (22:33 +0000)
doc/doc-docbook/spec.xfpt
doc/doc-txt/ChangeLog
src/src/deliver.c
test/log/2013
test/log/2113
test/stderr/2013
test/stderr/2113

index be93cf67075ebd93f4493b621ecd1c49f2a216a2..91dacb7bb8f239421c496cfe5b073cf77a9c47bd 100644 (file)
@@ -35769,9 +35769,10 @@ down a single SMTP connection, an asterisk follows the IP address in the log
 lines for the second and subsequent messages.
 .new
 When two or more messages are delivered down a single TLS connection, the
 lines for the second and subsequent messages.
 .new
 When two or more messages are delivered down a single TLS connection, the
-TLS-related information logged for the first message delivered
-(which may not be the earliest line in the log)
+DNS and TLS-related information logged for the first message delivered
 will not be present in the log lines for the second and subsequent messages.
 will not be present in the log lines for the second and subsequent messages.
+A TLS-marker indication of &'X=*'& is added to the log line instead of
+cipher information.
 .wen
 
 .cindex "delivery" "cutthrough; logging"
 .wen
 
 .cindex "delivery" "cutthrough; logging"
@@ -35900,7 +35901,7 @@ the following table:
 &`T   `&        on &`<=`& lines: message subject (topic)
 &`    `&        on &`=>`& &`**`& and &`==`& lines: transport name
 &`U   `&        local user or RFC 1413 identity
 &`T   `&        on &`<=`& lines: message subject (topic)
 &`    `&        on &`=>`& &`**`& and &`==`& lines: transport name
 &`U   `&        local user or RFC 1413 identity
-&`X   `&        TLS cipher suite
+&`X   `&        TLS cipher suite, or TLS usage mark
 .endd
 
 
 .endd
 
 
index 5b5dcbd7f7c37bc77cb4b5b2228301c98891c2c9..f43475ba37e1db30542277ed03fa01ae22440212 100644 (file)
@@ -24,7 +24,8 @@ JH/03 Rework the transport continued-connection mechanism: when TLS is active,
       the passed-on TCP connection.  Instead, proxy the child (and any
       subsequent ones) for TLS via a unix-domain socket channel.  Logging is
       affected: the continued delivery log lines do not have any DNSSEC, TLS
       the passed-on TCP connection.  Instead, proxy the child (and any
       subsequent ones) for TLS via a unix-domain socket channel.  Logging is
       affected: the continued delivery log lines do not have any DNSSEC, TLS
-      cipher, Certificate or OCSP information.
+      cipher, Certificate or OCSP information. A "continued-TLS" marker is
+      added instead of the cipher information: "X=*".
 
 JH/04 Shorten the log line for daemon startup by collapsing adjacent sets of
       identical IP addresses on different listening ports.  Will also affect
 
 JH/04 Shorten the log line for daemon startup by collapsing adjacent sets of
       identical IP addresses on different listening ports.  Will also affect
index cb4616e6cd24143a3934e9c9792c02e41c86aefe..7743d37c3eb77ec59b1f798e74c21d73bb7d9d34 100644 (file)
@@ -3396,7 +3396,7 @@ while (!done)
 
     /* Cut out any "delete" items on the list. */
 
 
     /* Cut out any "delete" items on the list. */
 
-    for (rp = &(addr->retries); (r = *rp); rp = &r->next)
+    for (rp = &addr->retries; (r = *rp); rp = &r->next)
       if (Ustrcmp(r->key, ptr+1) == 0)           /* Found item with same key */
         {
         if ((r->flags & rf_delete) == 0) break;  /* It was not "delete" */
       if (Ustrcmp(r->key, ptr+1) == 0)           /* Found item with same key */
         {
         if ((r->flags & rf_delete) == 0) break;  /* It was not "delete" */
@@ -3408,7 +3408,7 @@ while (!done)
     /* We want to add a delete item only if there is no non-delete item;
     however we still have to step ptr through the data. */
 
     /* We want to add a delete item only if there is no non-delete item;
     however we still have to step ptr through the data. */
 
-    if (!r || (*ptr & rf_delete) == 0)
+    if (!r || !(*ptr & rf_delete))
       {
       r = store_get(sizeof(retry_item));
       r->next = addr->retries;
       {
       r = store_get(sizeof(retry_item));
       r->next = addr->retries;
@@ -3458,36 +3458,34 @@ while (!done)
     switch (subid)
       {
       case '1':
     switch (subid)
       {
       case '1':
-      addr->cipher = NULL;
-      addr->peerdn = NULL;
-
-      if (*ptr)
-       addr->cipher = string_copy(ptr);
-      while (*ptr++);
-      if (*ptr)
-       addr->peerdn = string_copy(ptr);
-      break;
+       addr->cipher = NULL;
+       addr->peerdn = NULL;
+
+       if (*ptr)
+         addr->cipher = string_copy(ptr);
+       while (*ptr++);
+       if (*ptr)
+         addr->peerdn = string_copy(ptr);
+       break;
 
       case '2':
 
       case '2':
-      if (*ptr)
-       (void) tls_import_cert(ptr, &addr->peercert);
-      else
-       addr->peercert = NULL;
-      break;
+       if (*ptr)
+         (void) tls_import_cert(ptr, &addr->peercert);
+       else
+         addr->peercert = NULL;
+       break;
 
       case '3':
 
       case '3':
-      if (*ptr)
-       (void) tls_import_cert(ptr, &addr->ourcert);
-      else
-       addr->ourcert = NULL;
-      break;
+       if (*ptr)
+         (void) tls_import_cert(ptr, &addr->ourcert);
+       else
+         addr->ourcert = NULL;
+       break;
 
 # ifndef DISABLE_OCSP
       case '4':
 
 # ifndef DISABLE_OCSP
       case '4':
-      addr->ocsp = OCSP_NOT_REQ;
-      if (*ptr)
-       addr->ocsp = *ptr - '0';
-      break;
+       addr->ocsp = *ptr ? *ptr - '0' : OCSP_NOT_REQ;
+       break;
 # endif
       }
     while (*ptr++);
 # endif
       }
     while (*ptr++);
@@ -4713,13 +4711,13 @@ for (delivery_count = 0; addr_remote; delivery_count++)
         if (!addr->peerdn)
          *ptr++ = 0;
        else
         if (!addr->peerdn)
          *ptr++ = 0;
        else
-          {
-          ptr += sprintf(CS ptr, "%.512s", addr->peerdn);
-          ptr++;
-          }
+          ptr += sprintf(CS ptr, "%.512s", addr->peerdn) + 1;
 
         rmt_dlv_checked_write(fd, 'X', '1', big_buffer, ptr - big_buffer);
         }
 
         rmt_dlv_checked_write(fd, 'X', '1', big_buffer, ptr - big_buffer);
         }
+      else if (continue_proxy)         /* known TLS, but no cipher info */
+        rmt_dlv_checked_write(fd, 'X', '1', US"*\0", 3);
+
       if (addr->peercert)
        {
         ptr = big_buffer;
       if (addr->peercert)
        {
         ptr = big_buffer;
index 79bc3f6122c187bf5f50e199282329e5d85e5071..ad78743ec15523c670ba85189ca2cba05d6ffb3e 100644 (file)
@@ -4,9 +4,9 @@
 1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] X=TLS1.x:xxxxRSA_AES_256_CBC_SHAnnn:256 CV=no DN="C=UK,O=The Exim Maintainers,OU=Test Suite,CN=Phil Pennock" C="250 OK id=10HmbA-0005vi-00"
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
 1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] X=TLS1.x:xxxxRSA_AES_256_CBC_SHAnnn:256 CV=no DN="C=UK,O=The Exim Maintainers,OU=Test Suite,CN=Phil Pennock" C="250 OK id=10HmbA-0005vi-00"
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
-1999-03-02 09:44:33 10HmaZ-0005vi-00 => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbB-0005vi-00"
+1999-03-02 09:44:33 10HmaZ-0005vi-00 => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbB-0005vi-00"
 1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed
 1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed
-1999-03-02 09:44:33 10HmaY-0005vi-00 => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbC-0005vi-00"
+1999-03-02 09:44:33 10HmaY-0005vi-00 => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbC-0005vi-00"
 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 10HmaY-0005vi-00 Completed
 1999-03-02 09:44:33 End queue run: pid=pppp -qqf
 
index 08b08cc84beca1b14b48376cd7568323f701fc5a..88eafe9b3d690ce7a50c4e80ab39f3a326d64b63 100644 (file)
@@ -4,9 +4,9 @@
 1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] X=TLSv1:AES256-SHA:256 CV=no DN="/C=UK/O=The Exim Maintainers/OU=Test Suite/CN=Phil Pennock" C="250 OK id=10HmbA-0005vi-00"
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
 1999-03-02 09:44:33 Start queue run: pid=pppp -qqf
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] X=TLSv1:AES256-SHA:256 CV=no DN="/C=UK/O=The Exim Maintainers/OU=Test Suite/CN=Phil Pennock" C="250 OK id=10HmbA-0005vi-00"
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
-1999-03-02 09:44:33 10HmaZ-0005vi-00 => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbB-0005vi-00"
+1999-03-02 09:44:33 10HmaZ-0005vi-00 => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbB-0005vi-00"
 1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed
 1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed
-1999-03-02 09:44:33 10HmaY-0005vi-00 => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbC-0005vi-00"
+1999-03-02 09:44:33 10HmaY-0005vi-00 => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbC-0005vi-00"
 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 10HmaY-0005vi-00 Completed
 1999-03-02 09:44:33 End queue run: pid=pppp -qqf
 
index 60b23885fd2922f6fbed034f7729b311821cdd54..c183664d6ab6d5c99bda97dd83adb96097c5bdbe 100644 (file)
@@ -49,7 +49,7 @@ cmd buf flush ddd bytes
   SMTP<< 250 OK id=10HmbB-0005vi-00
   SMTP(close)>>
 LOG: MAIN
   SMTP<< 250 OK id=10HmbB-0005vi-00
   SMTP(close)>>
 LOG: MAIN
-  => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbB-0005vi-00"
+  => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbB-0005vi-00"
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
@@ -70,7 +70,7 @@ cmd buf flush ddd bytes
   SMTP(close)>>
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
   SMTP(close)>>
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
-  => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbC-0005vi-00"
+  => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbC-0005vi-00"
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
index 55cfc39dd4a1cf2c882f135b2fa205dd92eca223..ae0044b99674ce699997a66c0284ce9cb5d55760 100644 (file)
@@ -49,7 +49,7 @@ cmd buf flush ddd bytes
   SMTP<< 250 OK id=10HmbB-0005vi-00
   SMTP(close)>>
 LOG: MAIN
   SMTP<< 250 OK id=10HmbB-0005vi-00
   SMTP(close)>>
 LOG: MAIN
-  => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbB-0005vi-00"
+  => userz@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbB-0005vi-00"
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
@@ -70,7 +70,7 @@ cmd buf flush ddd bytes
   SMTP(close)>>
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
   SMTP(close)>>
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
-  => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* C="250 OK id=10HmbC-0005vi-00"
+  => usery@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1]* X=* CV=no C="250 OK id=10HmbC-0005vi-00"
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
 LOG: MAIN
   Completed
 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>