On 16/02/2022 08:08, Martin Waschbüsch via Exim-users wrote:
07:45:34.638 57451 sync_responses expect rcpt for recipi...@recipientdomain.tld 07:45:34.638 57451 SMTP<< 550 5.1.1 <xn--recipient-...@recipientdomain.tld>: Recipient address rejected: User unknown
far end rejected RCPT. We had pipelined MAIL, RCPT, BDAT, on a TLS conn.
07:45:34.638 57451 look for one response for BDAT 07:45:34.638 57451 SMTP<< 554 5.5.1 Error: no valid recipients
follow-on reject for the BDAT, reasonable given the RCPT situation
07:45:34.638 57451 ok=0 send_quit=1 send_rset=1 continue_more=0 yield=0 first_address is NULL
we think we're done with this message, and with the connection
07:45:34.638 57451 SMTP+> QUIT
set up the QUIT command
07:45:34.638 57451 cmd buf flush 6 bytes (more expected) 07:45:34.638 57451 tls_write(0x8011111a0, 6, more) 07:45:34.638 57451 tls_write((nil), 0) 07:45:34.638 57451 SSL_write(0x801600000, 0x801050768, 6) 07:45:34.638 57451 outbytes=6 error=0 07:45:34.638 57451 SMTP(TLS shutdown)>>
pipeline it with our side's TLS close notification
07:45:34.638 57451 SSL3 alert write:warning:close notify 07:45:34.638 57451 SMTP(shutdown)>>
Tell the socket we'll send no more data; this results in a TCP FIN send (leaving the TCP conn in "half-closed" state; the peer could still send data - and in fact ought to: an SMTP response to the QUIT within the TLS session, followed by a TLS shutdown)
07:45:34.643 57451 Calling SSL_read(0x801600000, 0x8011101a0, 4096) 07:45:34.643 57451 read response data: size=15 07:45:34.643 57451 SMTP<< 221 2.0.0 Bye
Peer sent the response for QUIT, as expected
07:45:34.643 57451 Calling SSL_read(0x801600000, 0x8011101a0, 4096) 07:45:35.700 57451 tls_close(): shutting down TLS (with response-wait) 07:45:35.700 57451 tls_write((nil), 0)
waiting for the TLS close...
07:46:33.400 57448 polling subprocess pipes
(note the PID difference) This is the parent of the transport process, waiting for status from there
07:47:33.420 57448 polling subprocess pipes 07:48:33.450 57448 polling subprocess pipes 07:49:33.520 57448 polling subprocess pipes 07:50:33.530 57448 polling subprocess pipes 07:51:33.550 57448 polling subprocess pipes 07:52:33.650 57448 polling subprocess pipes 07:53:33.730 57448 polling subprocess pipes 07:54:33.750 57448 polling subprocess pipes 07:55:33.830 57448 polling subprocess pipes 07:56:33.930 57448 polling subprocess pipes 07:57:33.950 57448 polling subprocess pipes
mmm, 10+ minutes elapsed - and 57448 has neither timed out nor noticed that 57451 died. Or sent status, but then it should have said *somthing* more. I wonder if it crashed (as seen in one previous event) and 57448 didn't see it? Aha. there was a recent for affecting FreeBSD which might be relevant: https://bugs.exim.org/show_bug.cgi?id=2831 From https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=259822 I suspect that The FreeBSD project has not picked up that fix (and possibly also other more-recent ones). The workaround for that particular issue was to periodically restart the daemon. A SIGHUP suffices. Preferable would be to incorporate fixes in the Exim you are running. Of course, that bug might not be the one you're hitting, but it's a possible. -- Cheers, Jeremy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-users ## Exim details at http://www.exim.org/ ## Please use the Wiki with this list - http://wiki.exim.org/