Callout: wait for response to QUIT before closing
authorJeremy Harris <jgh146exb@wizmail.org>
Tue, 15 Nov 2016 14:32:40 +0000 (14:32 +0000)
committerJeremy Harris <jgh146exb@wizmail.org>
Tue, 15 Nov 2016 14:32:40 +0000 (14:32 +0000)
src/src/smtp_out.c
src/src/verify.c
test/stderr/0227
test/stderr/0376
test/stderr/0398
test/stderr/0432
test/stderr/0462
test/stderr/5403
test/stderr/5410
test/stderr/5420
test/stderr/5840

index 0c655e2..3154c97 100644 (file)
@@ -536,7 +536,7 @@ Arguments:
   buffer    where to put the response
   size      the size of the buffer
   okdigit   the expected first digit of the response
-  timeout   the timeout to use
+  timeout   the timeout to use, in seconds
 
 Returns:    TRUE if a valid, non-error response was received; else FALSE
 */
index aa7988c..9652a39 100644 (file)
@@ -39,7 +39,7 @@ static tree_node *dnsbl_cache = NULL;
 #define MT_NOT 1
 #define MT_ALL 2
 
-static uschar cutthrough_response(char, uschar **);
+static uschar cutthrough_response(char, uschar **, int);
 
 
 
@@ -462,7 +462,7 @@ can do it there for the non-rcpt-verify case.  For this we keep an addresscount.
                transport_rcpt_address(addr,
                  (addr->transport == NULL)? FALSE :
                   addr->transport->rcpt_include_affixes)) >= 0 &&
-             cutthrough_response('2', &resp) == '2';
+             cutthrough_response('2', &resp, CUTTHROUGH_DATA_TIMEOUT) == '2';
 
            /* This would go horribly wrong if a callout fail was ignored by ACL.
            We punt by abandoning cutthrough on a reject, like the
@@ -1304,8 +1304,14 @@ can do it there for the non-rcpt-verify case.  For this we keep an addresscount.
       if (options & vopt_callout_recipsender)
         cancel_cutthrough_connection("not usable for cutthrough");
       if (send_quit)
+       {
        (void) smtp_write_command(&outblock, FALSE, "QUIT\r\n");
 
+       /* Wait a short time for response, and discard it */
+       smtp_read_response(&inblock, responsebuffer, sizeof(responsebuffer),
+         '2', 1);
+       }
+
 #ifdef SUPPORT_TLS
       tls_close(FALSE, TRUE);
 #endif
@@ -1523,7 +1529,7 @@ return cutthrough_puts(US"\r\n", 2);
 
 /* Get and check response from cutthrough target */
 static uschar
-cutthrough_response(char expect, uschar ** copy)
+cutthrough_response(char expect, uschar ** copy, int timeout)
 {
 smtp_inblock inblock;
 uschar inbuffer[4096];
@@ -1535,7 +1541,7 @@ inblock.ptr = inbuffer;
 inblock.ptrend = inbuffer;
 inblock.sock = cutthrough.fd;
 /* this relies on (inblock.sock == tls_out.active) */
-if(!smtp_read_response(&inblock, responsebuffer, sizeof(responsebuffer), expect, CUTTHROUGH_DATA_TIMEOUT))
+if(!smtp_read_response(&inblock, responsebuffer, sizeof(responsebuffer), expect, timeout))
   cancel_cutthrough_connection("target timeout on read");
 
 if(copy != NULL)
@@ -1564,7 +1570,7 @@ cutthrough_puts(US"DATA\r\n", 6);
 cutthrough_flush_send();
 
 /* Assume nothing buffered.  If it was it gets ignored. */
-return cutthrough_response('3', NULL) == '3';
+return cutthrough_response('3', NULL, CUTTHROUGH_DATA_TIMEOUT) == '3';
 }
 
 
@@ -1626,7 +1632,9 @@ if(cutthrough.fd >= 0)
   HDEBUG(D_transport|D_acl|D_v) debug_printf("  SMTP>> QUIT\n");
   _cutthrough_puts(US"QUIT\r\n", 6);   /* avoid recursion */
   _cutthrough_flush_send();
-  /* No wait for response */
+
+  /* Wait a short time for response, and discard it */
+  cutthrough_response('2', NULL, 1);
 
   #ifdef SUPPORT_TLS
   tls_close(FALSE, TRUE);
@@ -1668,7 +1676,7 @@ if(  !cutthrough_puts(US".", 1)
   )
   return cutthrough.addr.message;
 
-res = cutthrough_response('2', &cutthrough.addr.message);
+res = cutthrough_response('2', &cutthrough.addr.message, CUTTHROUGH_DATA_TIMEOUT);
 for (addr = &cutthrough.addr; addr; addr = addr->next)
   {
   addr->message = cutthrough.addr.message;
index 016b9a3..d676f05 100644 (file)
@@ -9,6 +9,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<ok@localhost>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: smtp_connection MAIN
   SMTP connection from root closed by QUIT
@@ -27,6 +28,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<bad@localhost>
   SMTP<< 550 Unknown user
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.1] U=root sender verify fail for <bad@localhost>: response to "RCPT TO:<bad@localhost>" from 127.0.0.1 [127.0.0.1] was: 550 Unknown user
@@ -45,6 +47,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<uncheckable@localhost1>
   SMTP<< 450 Temporary error
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.1] U=root sender verify defer for <uncheckable@localhost1>: response to "RCPT TO:<uncheckable@localhost1>" from 127.0.0.1 [127.0.0.1] was: 450 Temporary error
@@ -61,6 +64,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> MAIL FROM:<>
   SMTP<< 550 Error for <>
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.1] U=root sender verify fail for <uncheckable2@localhost1>: response to "MAIL FROM:<>" from 127.0.0.1 [127.0.0.1] was: 550 Error for <>
@@ -78,6 +82,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP<< 550-Multiline error for <>
          550 Here's the second line
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.1] U=root sender verify fail for <uncheckable@localhost1>: response to "MAIL FROM:<>" from 127.0.0.1 [127.0.0.1] was: 550-Multiline error for <>\n550 Here's the second line
@@ -96,6 +101,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<z@remote.domain>
   SMTP<< 550 Recipient not liked
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.3] U=root F=<uncheckable@localhost1> rejected RCPT <z@remote.domain>: response to "RCPT TO:<z@remote.domain>" from 127.0.0.1 [127.0.0.1] was: 550 Recipient not liked
@@ -113,6 +119,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP<< 550-Recipient not liked on two lines
          550 Here's the second
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.3] U=root F=<uncheckable@localhost1> rejected RCPT <z@remote.domain>: response to "RCPT TO:<z@remote.domain>" from 127.0.0.1 [127.0.0.1] was: 550-Recipient not liked on two lines\n550 Here's the second
@@ -137,6 +144,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<abcd@x.y.z>
   SMTP<< 550 Not liked
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.4] U=root F=<uncheckable@localhost1> rejected after DATA: there is no valid sender in any header line
@@ -153,6 +161,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<abcd@x.y.z>
   SMTP<< 550 Not liked
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.4] U=root F=<uncheckable@localhost1> rejected after DATA: there is no valid sender in any header line
@@ -176,6 +185,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@localhost1>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.5] U=root F=<ok@localhost1> rejected RCPT <z@remote.domain>: relay not permitted
@@ -199,6 +209,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@localhost1>
   SMTP<< 550 Don't like postmaster
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.5] U=root sender verify fail for <ok@localhost1>: response to "RCPT TO:<postmaster@localhost1>" from 127.0.0.1 [127.0.0.1] was: 550 Don't like postmaster
@@ -219,6 +230,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<ok@localhost1>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: smtp_connection MAIN
   SMTP connection from root closed by QUIT
@@ -233,6 +245,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<z@remote.lmtp>
   SMTP<< 550 Recipient not liked
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 LOG: MAIN REJECT
   H=[V4NET.0.0.3] U=root F=<uncheckable@localhost1> rejected RCPT <z@remote.lmtp>: response to "RCPT TO:<z@remote.lmtp>" from 127.0.0.1 [127.0.0.1] was: 550 Recipient not liked
index dd58a13..652477e 100644 (file)
@@ -21,6 +21,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<ok@localhost>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for localhost:
   result=1 postmaster=0 random=0
@@ -92,6 +93,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<bad@localhost>
   SMTP<< 550 REJECTED
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for localhost:
   result=1 postmaster=0 random=0
@@ -145,6 +147,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> MAIL FROM:<>
   SMTP<< 550 REJECT MAIL FROM
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for localhost:
   result=3 postmaster=0 random=0
@@ -205,6 +208,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@otherhost>
   SMTP<< 550 NOT OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost:
   result=1 postmaster=2 random=0
@@ -266,6 +270,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@otherhost2>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost2:
   result=1 postmaster=1 random=0
@@ -314,6 +319,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<myhost.test.ex-dddddddd-testing@otherhost3>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost3:
   result=1 postmaster=0 random=1
@@ -359,6 +365,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<myhost.test.ex-dddddddd-testing@otherhost4>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost4:
   result=1 postmaster=0 random=1
@@ -417,6 +424,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@otherhost41>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost41:
   result=1 postmaster=1 random=2
@@ -473,6 +481,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@otherhost21>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost21:
   result=1 postmaster=1 random=0
@@ -504,6 +513,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<ok2@otherhost21>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost21:
   result=1 postmaster=1 random=0
@@ -540,6 +550,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<ok@otherhost31>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost31:
   result=1 postmaster=0 random=2
@@ -571,6 +582,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<okok@otherhost31>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost31:
   result=1 postmaster=0 random=2
@@ -607,6 +619,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<okokok@otherhost31>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost31:
   result=1 postmaster=0 random=2
@@ -676,6 +689,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@otherhost52>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost52:
   result=1 postmaster=1 random=0
@@ -707,6 +721,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<abcd@x.y.z>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for x.y.z:
   result=1 postmaster=0 random=0
@@ -779,6 +794,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for otherhost9:
   result=1 postmaster=1 random=0
@@ -822,6 +838,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@test.ex>
   SMTP<< 250 OK
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for test.ex:
   result=1 postmaster=1 random=2
index 3e3994b..7489a19 100644 (file)
@@ -144,6 +144,7 @@ cmd buf flush ddd bytes
   SMTP<< 550 Unknown
   SMTP>> QUIT
 cmd buf flush ddd bytes
+  SMTP<< 250 OK
   SMTP(close)>>
 locking TESTSUITE/spool/db/callout.lockfile
 locked  TESTSUITE/spool/db/callout.lockfile
index 2fe0ca8..f819fb0 100644 (file)
@@ -105,6 +105,7 @@ cmd buf flush ddd bytes
   SMTP<< 250 OK
   SMTP>> QUIT
 cmd buf flush ddd bytes
+  SMTP<< 220 OK
   SMTP(close)>>
 locking TESTSUITE/spool/db/callout.lockfile
 locked  TESTSUITE/spool/db/callout.lockfile
@@ -270,6 +271,7 @@ MUNGED: ::1 will be omitted in what follows
 >>>   SMTP<< 250 OK
 >>>   SMTP>> QUIT
 >>> cmd buf flush 6 bytes
+>>>   SMTP<< 220 OK
 >>>   SMTP(close)>>
 >>> wrote callout cache domain record for b:
 >>>   result=1 postmaster=0 random=0
index 2041893..3db191c 100644 (file)
@@ -28,6 +28,7 @@ Cutthrough cancelled by presence of postmaster verify
   SMTP>> RCPT TO:<postmaster@localhost>
   SMTP<< 550 NO
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for localhost:
   result=1 postmaster=2 random=0
@@ -71,6 +72,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<NOTok@elsewhere>
   SMTP<< 550 NO
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for elsewhere:
   result=1 postmaster=0 random=0
@@ -105,6 +107,7 @@ Connecting to 127.0.0.1 [127.0.0.1]:1224 ... connected
   SMTP>> RCPT TO:<NOTok2@elsewhere>
   SMTP<< 550 NO
   SMTP>> QUIT
+  SMTP<< 250 OK
   SMTP(close)>>
 wrote callout cache domain record for elsewhere:
   result=1 postmaster=0 random=0
index 065db11..8d6f97c 100644 (file)
@@ -89,6 +89,7 @@ MUNGED: ::1 will be omitted in what follows
 >>> accept: condition test succeeded in ACL "ar"
 >>> end of ACL "ar": ACCEPT
 >>>   SMTP>> QUIT
+>>>   SMTP<< 220 OK
 >>>   SMTP(close)>>
 >>> ----------- cutthrough shutdown (host-checking mode) ------------
 LOG: 10HmaY-0005vi-00 <= sender@myhost.test.ex H=(myhost.test.ex) [1.2.3.4] P=esmtp S=sss for verify@domain.com
index 5934476..cb1b31b 100644 (file)
@@ -233,6 +233,7 @@ considering: ${tod_full}
 LOG: MAIN
   >> userx@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1] X=TLSv1:AES256-SHA:256 CV=no C="250 OK id=10HmaY-0005vi-00"
   SMTP>> QUIT
+  SMTP<< 221 myhost.test.ex closing connection
   SMTP(close)>>
 ----------- cutthrough shutdown (delivered) ------------
 LOG: MAIN
@@ -444,6 +445,7 @@ considering: ${tod_full}
 LOG: MAIN
   >> usery@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmbA-0005vi-00"
   SMTP>> QUIT
+  SMTP<< 221 myhost.test.ex closing connection
   SMTP(close)>>
 ----------- cutthrough shutdown (delivered) ------------
 LOG: MAIN
@@ -655,6 +657,7 @@ considering: ${tod_full}
 LOG: MAIN
   >> usery@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmbC-0005vi-00"
   SMTP>> QUIT
+  SMTP<< 221 myhost.test.ex closing connection
   SMTP(close)>>
 ----------- cutthrough shutdown (delivered) ------------
 LOG: MAIN
index e6247ce..8ccf0fd 100644 (file)
@@ -232,6 +232,7 @@ considering: ${tod_full}
 LOG: MAIN
   >> userx@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:xxxxRSA_AES_256_CBC_SHAnnn:256 CV=no C="250 OK id=10HmaY-0005vi-00"
   SMTP>> QUIT
+  SMTP<< 221 myhost.test.ex closing connection
   SMTP(close)>>
 ----------- cutthrough shutdown (delivered) ------------
 LOG: MAIN
@@ -443,6 +444,7 @@ considering: ${tod_full}
 LOG: MAIN
   >> usery@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmbA-0005vi-00"
   SMTP>> QUIT
+  SMTP<< 221 myhost.test.ex closing connection
   SMTP(close)>>
 ----------- cutthrough shutdown (delivered) ------------
 LOG: MAIN
@@ -654,6 +656,7 @@ considering: ${tod_full}
 LOG: MAIN
   >> usery@domain.com R=all T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmbC-0005vi-00"
   SMTP>> QUIT
+  SMTP<< 221 myhost.test.ex closing connection
   SMTP(close)>>
 ----------- cutthrough shutdown (delivered) ------------
 LOG: MAIN
index d9d4e7a..97fdca6 100644 (file)
@@ -60,6 +60,7 @@ MUNGED: ::1 will be omitted in what follows
 >>>   SMTP<< 250 Accepted
 >>>   SMTP>> QUIT
 >>> cmd buf flush 6 bytes
+>>>   SMTP<< 221 myhost.test.ex closing connection
 >>>   SMTP(close)>>
 >>> wrote callout cache domain record for dane256ee.test.ex:
 >>>   result=1 postmaster=0 random=0