Re: [exim] 2 hours delay (gnutls_handshake): timed out: deli…

Top Page
Delete this message
Reply to this message
Author: tt-admin
Date:  
To: exim-users
Subject: Re: [exim] 2 hours delay (gnutls_handshake): timed out: delivering unencrypted to
exiwhat says: waiting for a remote delivery subprocess to finish

started a new strace with longer lines (-s 256) and date column.

I will try to contact the remote administrator, but my hopes for a trace
from their side are low (Symantec Messaging Gateway, i suppose without root
access).

--
Marc

-----Ursprüngliche Nachricht-----
Von: Exim-users [mailto:exim-users-bounces+tt-admin=intranett.de@exim.org]
Im Auftrag von Evgeniy Berdnikov via Exim-users
Gesendet: Mittwoch, 30. März 2022 19:56
An: exim-users@???
Betreff: Re: [exim] 2 hours delay (gnutls_handshake): timed out: delivering
unencrypted to

On Wed, Mar 30, 2022 at 02:53:45PM +0200, tt-admin via Exim-users wrote:
> Continuation of the strace;
>
> 6649  select(8, [7], NULL, NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
> 6671  <... recvfrom resumed> 0x56352d0bd71b, 324, 0, NULL, NULL) = -1
> ECONNRESET (Connection reset by peer)
> 6671  alarm(0)                          = 0
> 6671  sendmsg(7, {msg_name=NULL, msg_namelen=0,
> msg_iov=[{iov_base="\25\3\3\0\2\2Z", iov_len=7}], msg_iovlen=1,
> msg_controllen=0, msg_flags=0}, 0) = -1 EPIPE (Broken pipe)
> 6671  --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=6671,
> si_uid=111} ---


Diring TLS exchange server sent RST, client got ECONNRESET and tried to
send TLS closing packet (it's my guess what "\25\3\3\0\2\2Z" means),
so client got EPIPE because connection has been deleted by kernel on RST.

The question is why server has dropped connection. Probably this connection
was timed out -- on the server's side, not on the client's one.
Traffic dump from both ends could make this situation clean.

> 6671  openat(AT_FDCWD, "/var/log/exim4/mainlog",
> O_WRONLY|O_CREAT|O_APPEND|O_NONBLOCK, 0640) = 5
> 6671  fcntl(5, F_GETFD)                 = 0
> 6671  fcntl(5, F_SETFD, FD_CLOEXEC)     = 0
> 6671  fcntl(5, F_GETFL)                 = 0x8c01 (flags
> O_WRONLY|O_APPEND|O_NONBLOCK|O_LARGEFILE)
> 6671  fcntl(5, F_SETFL, O_WRONLY|O_APPEND|O_LARGEFILE) = 0
> 6671  fstat(5, {st_mode=S_IFREG|0640, st_size=15402412, ...}) = 0
> 6671  write(5, "2022-03-30 12:25:33.594 [6671] 1"..., 187) = 187


You have better to increase strace display length with -s.., or post
full log line here.

> 6671  socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 7
> 6671  setsockopt(7, SOL_TCP, TCP_NODELAY, [1], 4) = 0
> 6671  alarm(300)                        = 0

>
> Then the unencrypted smtp connections starts and the mesage is delivered
> unencrypted.


I could imagine one reason for such server's behaviour: presence of some
statefull firewall behind server, which scans SMTP packets and drops
packets with "suspicious" patterns. If it drop some TLS packet from client,
it would also drop all its copies on retransmissions, so TLS session
become disrupted and tcp connection dies on timeout.

However, in this scenario messages should not wait in queue for hours,
they should be delivered in plain SMTP just after first TLS timeout.
--
Eugene Berdnikov

--
## 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/