Mark,
I have experienced the same... seems to happen one every 2-3 weeks and I
think it depends on which actual server in Google's cluster you get
connected to.
Google's implementation of SMTP seems to be very poor at reporting
actual problems, rather it either accepts delivery (and presumably
discards it) or hangs like you have experienced.
Mike
On 10/08/2022 01:02, Marc MERLIN via Exim-users wrote:
> This started about a week ago, exim 4.94.2 on debian.
>
> I tried disabling chunking ( hosts_try_chunking = ) and it didn't help
>
> Some Emails to gmail get here, some don't. It seems content dependent. It could be as if gmail
> is actually teergrubbing me :)
>
> Connecting to gmail-smtp-in.l.google.com [2607:f8b0:4023:c0d::1a]:25 ... failed: Cannot assign requested address
> LOG: MAIN
> H=gmail-smtp-in.l.google.com [2607:f8b0:4023:c0d::1a] Cannot assign requested address
> Connecting to gmail-smtp-in.l.google.com [142.251.2.27]:25 ... TFO mode sendto, no data: EINPROGRESS
> connected
> TCP_FASTOPEN tcpi_unacked 2
> SMTP<< 220 mx.google.com ESMTP l193-20020a6391ca000000b0041b8f2bd530si11447438pge.217 - gsmtp
> SMTP>> EHLO mail1.merlins.org
> SMTP<< 250-mx.google.com at your service, [209.81.13.136]
> 250-SIZE 157286400
> 250-8BITMIME
> 250-STARTTLS
> 250-ENHANCEDSTATUSCODES
> 250-PIPELINING
> 250-CHUNKING
> 250 SMTPUTF8
> SMTP>> STARTTLS
> SMTP<< 220 2.0.0 Ready to start TLS
> SMTP>> EHLO mail1.merlins.org
> SMTP<< 250-mx.google.com at your service, [209.81.13.136]
> 250-SIZE 157286400
> 250-8BITMIME
> 250-ENHANCEDSTATUSCODES
> 250-PIPELINING
> 250-CHUNKING
> 250 SMTPUTF8
> SMTP>> MAIL FROM:<foo> SIZE=111056
> SMTP>> RCPT TO:<merlin@???>
> will write message using CHUNKING
> SMTP>> BDAT 4562
> SMTP<< 250 2.1.0 OK l193-20020a6391ca000000b0041b8f2bd530si11447438pge.217 - gsmtp
> SMTP<< 250 2.1.5 OK l193-20020a6391ca000000b0041b8f2bd530si11447438pge.217 - gsmtp
> SMTP<< 250 2.0.0 OK l193-20020a6391ca000000b0041b8f2bd530si11447438pge.217 - gsmtp
> SMTP>> BDAT 105345 LAST
> <hangs here>
>
>
> nnecting to gmail-smtp-in.l.google.com [142.251.2.27]:25 ... TFO mode sendto, no data: EINPROGRESS
> connected
> TCP_FASTOPEN tcpi_unacked 2
> SMTP<< 220 mx.google.com ESMTP n23-20020a170902969700b0016ef3d9ed6bsi14752543plp.530 - gsmtp
> SMTP>> EHLO mail1.merlins.org
> SMTP<< 250-mx.google.com at your service, [209.81.13.136]
> 250-SIZE 157286400
> 250-8BITMIME
> 250-STARTTLS
> 250-ENHANCEDSTATUSCODES
> 250-PIPELINING
> 250-CHUNKING
> 250 SMTPUTF8
> SMTP>> STARTTLS
> SMTP<< 220 2.0.0 Ready to start TLS
> SMTP>> EHLO mail1.merlins.org
> SMTP<< 250-mx.google.com at your service, [209.81.13.136]
> 250-SIZE 157286400
> 250-8BITMIME
> 250-ENHANCEDSTATUSCODES
> 250-PIPELINING
> 250-CHUNKING
> 250 SMTPUTF8
> SMTP>> MAIL FROM:<foo> SIZE=111056
> SMTP>> RCPT TO:<merlin@???>
> SMTP>> DATA
> SMTP<< 250 2.1.0 OK n23-20020a170902969700b0016ef3d9ed6bsi14752543plp.530 - gsmtp
> SMTP<< 250 2.1.5 OK n23-20020a170902969700b0016ef3d9ed6bsi14752543plp.530 - gsmtp
> SMTP<< 354 Go ahead n23-20020a170902969700b0016ef3d9ed6bsi14752543plp.530 - gsmtp
> SMTP>> writing message and terminating "."
> <hangs here>
>
> -d+all shows
> 16:52:41 5682 Calling gnutls_record_recv(session=0x5594689d08e0, buffer=0x5594689e5ae0, len=4096)
> 16:52:41 5682 read response data: size=72
> 16:52:41 5682 SMTP<< 250 2.1.0 OK 30-20020a17090a035e00b001f57a54c7aasi385374pjf.69 - gsmtp
> 16:52:41 5682 sync_responses expect rcpt
> 16:52:41 5682 Calling gnutls_record_recv(session=0x5594689d08e0, buffer=0x5594689e5ae0, len=4096)
> 16:52:41 5682 read response data: size=72
> 16:52:41 5682 SMTP<< 250 2.1.5 OK 30-20020a17090a035e00b001f57a54c7aasi385374pjf.69 - gsmtp
> 16:52:41 5682 look for one response for BDAT
> 16:52:41 5682 Calling gnutls_record_recv(session=0x5594689d08e0, buffer=0x5594689e5ae0, len=4096)
> 16:52:41 5682 read response data: size=72
> 16:52:41 5682 SMTP<< 250 2.0.0 OK 30-20020a17090a035e00b001f57a54c7aasi385374pjf.69 - gsmtp
> 16:52:41 5682 SMTP>> BDAT 105345 LAST
> 16:52:41 5682 cmd buf flush 18 bytes (more expected)
> 16:52:41 5682 gnutls_record_cork(session=0x5594689d08e0)
> 16:52:41 5682 tls_write(0x5594689e6ae0, 18, more)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594689e6ae0, left=18)
> 16:52:41 5682 outbytes=18
> 16:52:41 5682 cannot use sendfile for body: spoolfile not wireformat
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 gnutls_record_uncork(session=0x5594689d08e0)
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutl_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 flushing headers buffer
> 16:52:41 5682 writing data block fd=7 size=8191 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 8191)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=8191)
> 16:52:41 5682 outbytes=8191
> 16:52:41 5682 writing data block fd=7 size=7053 timeout=300
> 16:52:41 5682 tls_write(0x5594688fabf0, 7053)
> 16:52:41 5682 gnutls_record_send(session=0x5594689d08e0, buffer=0x5594688fabf0, left=7053)
> 16:52:41 5682 outbytes=7053
> <hangs here>
>
