OpenSSL: in server, detect TCP RST from client after QUIT under SSL,
authorJeremy Harris <jgh146exb@wizmail.org>
Thu, 23 Jul 2020 15:32:29 +0000 (16:32 +0100)
committerJeremy Harris <jgh146exb@wizmail.org>
Fri, 24 Jul 2020 14:00:57 +0000 (15:00 +0100)
  and log different message (under new log_selector)

doc/doc-txt/experimental-spec.txt
src/src/acl.c
src/src/globals.c
src/src/globals.h
src/src/macros.h
src/src/smtp_in.c
src/src/tls-openssl.c

index 68366a4a944bcf5f15d7f241b6b51a45af8b4ddf..e4a9301c312bf424f2cde3db4d79452cf6abd117 100644 (file)
@@ -666,6 +666,20 @@ and a whitespace-separated port number must be given.
 
 
 
+
+Logging protocol unusual states
+---------------------------------------------------------------
+An extra log_selector, "protocol_detail" has been added in the default build.
+The name may change in future, hence the Experimenal status.
+
+Currrently the only effect is to enable logging, under OpenSSL,
+of a TCP RST received directly after a QUIT (in server mode).
+
+Outlook is consistently doing this; not waiting for the SMTP response
+to its QUIT, not properly closing the TLS session and not properly closing
+the TCP connection.  Previously this resulted is an error from SSL_write
+being logged.
+
 --------------------------------------------------------------
 End of file
 --------------------------------------------------------------
index 185a39d5da84e2c66dc2f2f7ee1b8d108cf97183..934112c3138d9f69cefbabdca10b244dc663fa45 100644 (file)
@@ -1944,7 +1944,8 @@ if (quota)
       {
       if (!*user_msgptr && *log_msgptr)
         *user_msgptr = string_sprintf("Rejected after %s: %s",
-           smtp_names[smtp_connection_had[smtp_ch_index-1]], *log_msgptr);
+           smtp_names[smtp_connection_had[SMTP_HBUFF_PREV(smtp_ch_index)]],
+           *log_msgptr);
       if (rc == DEFER) f.acl_temp_details = TRUE;
       }
     }
@@ -4542,7 +4543,8 @@ switch (where)
     /* Drop cutthrough conns, and drop heldopen verify conns if
     the previous was not DATA */
     {
-    uschar prev = smtp_connection_had[smtp_ch_index-2];
+    uschar prev =
+      smtp_connection_had[SMTP_HBUFF_PREV(SMTP_HBUFF_PREV(smtp_ch_index))];
     BOOL dropverify = !(prev == SCH_DATA || prev == SCH_BDAT);
 
     cancel_cutthrough_connection(dropverify, US"quit or conndrop");
index 654c39b4fbc50689becd2d0730365eef546c9ef9..a5df06d98d645e4a276f285baf26a6da4699b7c5 100644 (file)
@@ -307,6 +307,7 @@ struct global_flags f =
 #endif
        .smtp_in_pipelining_advertised = FALSE,
        .smtp_in_pipelining_used = FALSE,
+       .smtp_in_quit           = FALSE,
        .spool_file_wireformat  = FALSE,
        .submission_mode        = FALSE,
        .suppress_local_fixups  = FALSE,
@@ -1073,6 +1074,7 @@ bit_table log_options[]        = { /* must be in alphabetical order,
   BIT_TABLE(L, outgoing_port),
   BIT_TABLE(L, pid),
   BIT_TABLE(L, pipelining),
+  BIT_TABLE(L, protocol_detail),
 #if defined(SUPPORT_PROXY) || defined(SUPPORT_SOCKS)
   BIT_TABLE(L, proxy),
 #endif
@@ -1464,6 +1466,8 @@ uschar *smtp_etrn_command      = NULL;
 int     smtp_max_synprot_errors= 3;
 int     smtp_max_unknown_commands = 3;
 uschar *smtp_notquit_reason    = NULL;
+unsigned smtp_peer_options     = 0;
+unsigned smtp_peer_options_wrap= 0;
 uschar *smtp_ratelimit_hosts   = NULL;
 uschar *smtp_ratelimit_mail    = NULL;
 uschar *smtp_ratelimit_rcpt    = NULL;
@@ -1479,8 +1483,6 @@ int     smtp_rlr_base          = 0;
 double  smtp_rlr_factor        = 0.0;
 int     smtp_rlr_limit         = 0;
 int     smtp_rlr_threshold     = INT_MAX;
-unsigned smtp_peer_options     = 0;
-unsigned smtp_peer_options_wrap= 0;
 #ifdef SUPPORT_I18N
 uschar *smtputf8_advertise_hosts = US"*";      /* overridden under test-harness */
 #endif
index 0c85c11501976d9e53d2cab033425d857906cbc8..ea326959df70006ed8902b3d8868a1f15ba5eace 100644 (file)
@@ -269,6 +269,7 @@ extern struct global_flags {
 #endif
  BOOL   smtp_in_pipelining_advertised  :1; /* server advertised PIPELINING */
  BOOL   smtp_in_pipelining_used                :1; /* server noted client using PIPELINING */
+ BOOL   smtp_in_quit                   :1; /* server noted QUIT command */
  BOOL   spool_file_wireformat          :1; /* current -D file has CRLF rather than NL */
  BOOL   submission_mode                        :1; /* Can be forced from ACL */
  BOOL   suppress_local_fixups          :1; /* Can be forced from ACL */
index b5221c7ecbbc20016b4975a3414b713f4b241b0f..4c5279f0a0731c8d0bc45957d83e9c0dd1457b5c 100644 (file)
@@ -148,6 +148,7 @@ enough to hold all the headers from a normal kind of message. */
 /* The size of the circular buffer that remembers recent SMTP commands */
 
 #define SMTP_HBUFF_SIZE 20
+#define SMTP_HBUFF_PREV(n)     ((n) ? (n)-1 : SMTP_HBUFF_SIZE-1)
 
 /* The initial size of a big buffer for use in various places. It gets put
 into big_buffer_size and in some circumstances increased. It should be at least
@@ -480,6 +481,7 @@ enum logbit {
   Li_outgoing_port,
   Li_pid,
   Li_pipelining,
+  Li_protocol_detail,
   Li_proxy,
   Li_queue_time,
   Li_queue_time_overall,
index ef3964f5c6720d385107f289a410c8f38336c4d0..3325d54c67e89e0d5bd4950e058dc715f3fc9f7c 100644 (file)
@@ -1733,6 +1733,7 @@ for (;;) switch(smtp_read_command(FALSE, GETC_BUFFER_UNLIMITED))
     return;
 
   case QUIT_CMD:
+    f.smtp_in_quit = TRUE;
     smtp_printf("221 %s closing connection\r\n", FALSE, smtp_active_hostname);
     mac_smtp_fflush();
     return;
@@ -2349,8 +2350,9 @@ while (done <= 0)
       break;
 
 
-    case EOF_CMD:
     case QUIT_CMD:
+      f.smtp_in_quit = TRUE;
+    case EOF_CMD:
       done = 2;
       break;
 
@@ -3835,14 +3837,13 @@ static void
 smtp_quit_handler(uschar ** user_msgp, uschar ** log_msgp)
 {
 HAD(SCH_QUIT);
+f.smtp_in_quit = TRUE;
 incomplete_transaction_log(US"QUIT");
-if (acl_smtp_quit)
-  {
-  int rc = acl_check(ACL_WHERE_QUIT, NULL, acl_smtp_quit, user_msgp, log_msgp);
-  if (rc == ERROR)
+if (  acl_smtp_quit
+   && acl_check(ACL_WHERE_QUIT, NULL, acl_smtp_quit, user_msgp, log_msgp)
+       == ERROR)
     log_write(0, LOG_MAIN|LOG_PANIC, "ACL for QUIT returned ERROR: %s",
       *log_msgp);
-  }
 
 #ifdef TCP_CORK
 (void) setsockopt(fileno(smtp_out), IPPROTO_TCP, TCP_CORK, US &on, sizeof(on));
@@ -5284,10 +5285,10 @@ while (done <= 0)
          }
        if (f.smtp_in_pipelining_advertised && last_was_rcpt)
          smtp_printf("503 Valid RCPT command must precede %s\r\n", FALSE,
-           smtp_names[smtp_connection_had[smtp_ch_index-1]]);
+           smtp_names[smtp_connection_had[SMTP_HBUFF_PREV(smtp_ch_index)]]);
        else
          done = synprot_error(L_smtp_protocol_error, 503, NULL,
-           smtp_connection_had[smtp_ch_index-1] == SCH_DATA
+           smtp_connection_had[SMTP_HBUFF_PREV(smtp_ch_index)] == SCH_DATA
            ? US"valid RCPT command must precede DATA"
            : US"valid RCPT command must precede BDAT");
 
@@ -5551,6 +5552,7 @@ while (done <= 0)
        some sense is perhaps "right". */
 
        case QUIT_CMD:
+         f.smtp_in_quit = TRUE;
          user_msg = NULL;
          if (  acl_smtp_quit
             && ((rc = acl_check(ACL_WHERE_QUIT, NULL, acl_smtp_quit, &user_msg,
index 50384cbd565e3bb2dd9694c407954b059649f2ba..64f60b7e4c86e09380afea24a3597ceadf709f7f 100644 (file)
@@ -3673,7 +3673,7 @@ context for the stashed information. */
 a store reset there, so use POOL_PERM. */
 /* + if CHUNKING, cmds EHLO,MAIL,RCPT(s),BDAT */
 
-if ((more || corked))
+if (more || corked)
   {
   if (!len) buff = US &error;  /* dummy just so that string_catn is ok */
 
@@ -3722,9 +3722,16 @@ for (int left = len; left > 0;)
       return -1;
 
     case SSL_ERROR_SYSCALL:
-      log_write(0, LOG_MAIN, "SSL_write: (from %s) syscall: %s",
-       sender_fullhost ? sender_fullhost : US"<unknown>",
-       strerror(errno));
+      if (ct_ctx || errno != ECONNRESET || !f.smtp_in_quit)
+       log_write(0, LOG_MAIN, "SSL_write: (from %s) syscall: %s",
+         sender_fullhost ? sender_fullhost : US"<unknown>",
+         strerror(errno));
+      else if (LOGGING(protocol_detail))
+       log_write(0, LOG_MAIN, "[%s] after QUIT, client reset TCP before"
+         " SMTP response and TLS close\n", sender_host_address);
+      else
+       DEBUG(D_tls) debug_printf("[%s] SSL_write: after QUIT,"
+         " client reset TCP before TLS close\n", sender_host_address);
       return -1;
 
     default: