timeout after DATA ( 0 bytes )

[Giuseppe De Nicolo']

Hello all,

Lately one of my users reported to me that he was missing some
message that he was waiting didn't get into his mailbox , so I went I
checked and this is what I found out :

http://pastebin.com/HPmaGqaJ

I 've decided to contact the support staff of the sender MTA and
ask them for their log\support and this is their side log ( is not the
same conversation since they sent me just a snippet ) :

http://pastebin.com/qUFcVY1j


Now they told me that since their MTA was on round-robin DNS
Greylisting could be the issue so I went on and whitelisted their MTA ,
to no avail I might add , so I decide to fire up a TCP dump and this is
I think my problem :

http://pastebin.com/PKaGQ0ty


I ve tried so far to check the MTU but it seems correct , I tried
disabling TCP offloading , but nothing seems to change , I would like to
stress the fact that this issue is happening only whith their MTA ,
nonetheless I would like to be sure it is not something related on my
side.. following my main and master conf
Best Regards

main.cf
alias_maps = hash:/etc/postfix/aliases
bounce_queue_lifetime = 8h
config_directory = /etc/postfix
content_filter = amavis-scan:[127.0.0.1]:10024
disable_vrfy_command = yes
maximal_queue_lifetime = 8h
message_size_limit = 20480000
mydestination =
myhostname = smtp.oapointgroup.it
mynetworks = 127.0.0.0/8, 172.17.0.4/32, 172.17.0.5/32 172.17.0.11/32,
212.19.117.109/32
myorigin = $mydomain
newaliases_path = /usr/bin/newaliases
postscreen_access_list =
permit_mynetworks,cidr:/etc/postfix/postscreen/postscreen_access.cidr
postscreen_dnsbl_action = enforce
postscreen_dnsbl_reply_map = texthash:/etc/postfix/postscreen/dnsbl_reply
postscreen_dnsbl_sites = zen.spamhaus.org*2 bl.spamcom.net*1
b.barracudacentral.org*1
postscreen_dnsbl_threshold = 2
postscreen_greet_action = enforce
queue_directory = /var/spool/postfix
readme_directory = no
relay_domains = /etc/postfix/relay_domains
relay_recipient_maps = hash:/etc/postfix/relay_recipients
sendmail_path = /usr/sbin/sendmail
setgid_group = postdrop
smtp_tls_CAfile = /etc/postfix/sslkey/oagroup/ca-bundle.pem
smtp_tls_CApath = /etc/postfix/sslkey/oagroup/
smtp_tls_loglevel = 1
smtp_tls_note_starttls_offer = yes
smtp_use_tls = yes
smtpd_banner = $myhostname ESMTP $mail_name
smtpd_client_restrictions =
permit_mynetworks,permit_sasl_authenticated,reject_unknown_recipient_domain,reject_unauth_destination
smtpd_recipient_restrictions = permit_mynetworks,check_policy_service
inet:127.0.0.1:60000,permit_sasl_authenticated,reject_unauth_destination,
smtpd_tls_ask_ccert = yes
smtpd_tls_cert_file = /etc/postfix/sslkey/oagroup/smtp.oapointgroup.it.crt
smtpd_tls_key_file = /etc/postfix/sslkey/oagroup/oagroup.key
smtpd_tls_loglevel = 1
smtpd_tls_security_level = may
smtpd_use_tls = yes
soft_bounce = yes
transport_maps = hash:/etc/postfix/transport

master.cf

#
# Postfix master process configuration file. For details on the format
# of the file, see the master(5) manual page (command: "man 5 master").
#
# Do not forget to execute "postfix reload" after editing this file.
#
# ==========================================================================
# service type private unpriv chroot wakeup maxproc command + args
# (yes) (yes) (yes) (never) (100)
# ==========================================================================
smtp inet n - n - - smtpd
smtp inet n - n - 1 postscreen
smtpd pass - - n - - smtpd
dnsblog unix - - n - 0 dnsblog
tlsproxy unix - - n - 0 tlsproxy
pickup fifo n - n 60 1 pickup
cleanup unix n - n - 0 cleanup
qmgr fifo n - n 300 1 qmgr
#qmgr fifo n - n 300 1 oqmgr
tlsmgr unix - - n 1000? 1 tlsmgr
rewrite unix - - n - - trivial-rewrite
bounce unix - - n - 0 bounce
defer unix - - n - 0 bounce
trace unix - - n - 0 bounce
verify unix - - n - 1 verify
flush unix n - n 1000? 0 flush
proxymap unix - - n - - proxymap
proxywrite unix - - n - 1 proxymap
smtp unix - - n - - smtp
relay unix - - n - - smtp
showq unix n - n - - showq
error unix - - n - - error
retry unix - - n - - error
discard unix - - n - - discard
local unix - n n - - local
virtual unix - n n - - virtual
lmtp unix - - n - - lmtp
anvil unix - - n - 1 anvil
scache unix - - n - 1 scache

#
# ====================================================================
# ====================================================================
# AMAVISD CONTENT FILTER
# ====================================================================
# =====================================================================
# service type private unpriv chroot wakeup maxproc command + args
# (yes) (yes) (yes) (never) (100)
# =====================================================================
amavis-scan unix - - n - 2 lmtp
-o lmtp_data_done_timeout=1200
-o lmtp_send_xforward_command=yes
-o lmtp_tls_note_starttls_offer=no

127.0.0.1:10025 inet n - n - - smtpd
-o content_filter=
-o smtpd_delay_reject=no
-o smtpd_client_restrictions=permit_mynetworks,reject
-o smtpd_helo_restrictions=
-o smtpd_sender_restrictions=
-o smtpd_recipient_restrictions=permit_mynetworks,reject
-o smtpd_data_restrictions=reject_unauth_pipelining
-o smtpd_end_of_data_restrictions=
-o smtpd_restriction_classes=
-o mynetworks=127.0.0.0/8
-o smtpd_error_sleep_time=0
-o smtpd_soft_error_limit=1001
-o smtpd_hard_error_limit=1000
-o smtpd_client_connection_count_limit=0
-o smtpd_client_connection_rate_limit=0
-o
receive_override_options=no_header_body_checks,no_unknown_recipient_checks,no_milters
-o local_header_rewrite_clients=
-o smtpd_milters=
-o local_recipient_maps=
-o relay_recipient_maps=

127.0.0.1:2345 inet n - n -
- smtpd
-o content_filter=amavisfeed:[127.0.0.1]:10028
-o smtpd_client_restrictions=permit_mynetworks,reject
-o mynetworks=127.0.0.0/8

[Wietse Venema]

Giuseppe De Nicolo':

> 136.233724 212.19.117.109 217.72.32.234 SMTP 131 S:
> 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with <CR><LF>.<CR><LF>
> 136.441076 212.19.117.109 217.72.32.234 SMTP 131 [TCP
> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
> <CR><LF>.<CR><LF>
> 136.468072 212.19.117.109 217.72.32.234 SMTP 131 [TCP
> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
> <CR><LF>.<CR><LF>
> ..SNIP...
> 377.007113 212.19.117.109 217.72.32.234 SMTP 131 [TCP
> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
> <CR><LF>.<CR><LF>
> 436.284965 212.19.117.109 217.72.32.234 SMTP 122 S:
> 421 4.4.2 smtp.oapointgroup.it Error: timeout exceeded

Somewhere between sender and receiver is a network with a smaller
MTU, and the sender is not receiving the ICMP "fragmentation needed"
messages. Only small packets are coming through.

Wietse

[Giuseppe De Nicolo']

Hello Wietse,

Thank you very much for your answer , though at this point I am
unsure of what other step to undertake to further debug the issue , I
tried a tracepath ( attached below ) and a ping though I dubt I could
see such a problem there , anyway I get this is definitely not a postfix
issue so although I am somewhat relieved , now I ll have to find other
means by wich debug this issue.

Best Regards

root@smtp:~# tracepath eugene.interplanet.it
1: smtp.oapointgroup.it 0.060ms pmtu
1500
1: 172.18.0.1 0.515ms
1: 172.18.0.1 0.468ms
2: gateway.leonet.it 1.745ms
3: 151.5.151.73 8.014ms asymm 4
4: FICI-B01-Ge2-0.71.wind.it 7.977ms
5: 151.6.0.250 14.248ms asymm 7
6: MISG-B01-Ge10-1.wind.it 13.520ms
7: 4te2-2.mivivxmr01.retelit.it 33.879ms asymm 8
8: te1-1.mivivxmr01.retelit.it 23.255ms asymm 7
9: 217.19.148.178 27.206ms asymm 8
10: no reply
11: no reply
12: eugene.interplanet.it 36.876ms reached
Resume: pmtu 1500 hops 12 back 53

root@smtp:~# ping -M do -s 1472 eugene.interplanet.it
PING eugene.interplanet.it (217.72.32.249) 1472(1500) bytes of data.
1480 bytes from eugene.interplanet.it (217.72.32.249): icmp_req=1 ttl=53
time=27.3 ms
1480 bytes from eugene.interplanet.it (217.72.32.249): icmp_req=2 ttl=53
time=27.2 ms
1480 bytes from eugene.interplanet.it (217.72.32.249): icmp_req=3 ttl=53
time=26.8 ms

[Wietse Venema]

Giuseppe De Nicolo':

> On 09/18/2014 05:40 PM, Wietse Venema wrote:
> > Giuseppe De Nicolo':
> >

> >> 136.231890 217.72.32.234 212.19.117.109 SMTP 227 C:
> >> MAIL FROM:<giampaolo...@bertoliniassociati.it> SIZE=2857 |
> >> RCPT TO:<Giulio.D...@oapointgroup.it>
> >> ORCPT=rfc822;Giulio.D...@oapointgroup.it | DATA

> >> 136.233724 212.19.117.109 217.72.32.234 SMTP 131 S:
> >> 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with <CR><LF>.<CR><LF>
> >> 136.441076 212.19.117.109 217.72.32.234 SMTP 131 [TCP
> >> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
> >> <CR><LF>.<CR><LF>

There is another possibility.

The SMTP client sends MAIL FROM/RCPT TO/DATA as one request
(SMTP command pipelining, RFC 2920), that's why Postfix replies
with 250/250/354 as one response.

It is possible that there is a device in the path that tries to
read SMTP conversation and that drops packets it does not understand.
Stuff like that tends to be built into a network firewall.

In that case, see what happens when you configure

# postconf -e 'smtpd_discard_ehlo_keywords=pipelining'
# postfix reload

If that solves the problem then you can make this selective per
client IP address with smtpd_discard_ehlo_keyword_address_maps.

Wietse

[Wietse Venema]

Wietse Venema:

> Giuseppe De Nicolo':
> > On 09/18/2014 05:40 PM, Wietse Venema wrote:
> > > Giuseppe De Nicolo':
> > >
> > >> 136.231890 217.72.32.234 212.19.117.109 SMTP 227 C:
> > >> MAIL FROM:<giampaolo...@bertoliniassociati.it> SIZE=2857 |
> > >> RCPT TO:<Giulio.D...@oapointgroup.it>
> > >> ORCPT=rfc822;Giulio.D...@oapointgroup.it | DATA
> > >> 136.233724 212.19.117.109 217.72.32.234 SMTP 131 S:
> > >> 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with <CR><LF>.<CR><LF>
> > >> 136.441076 212.19.117.109 217.72.32.234 SMTP 131 [TCP
> > >> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
> > >> <CR><LF>.<CR><LF>
>
> There is another possibility.
>
> The SMTP client sends MAIL FROM/RCPT TO/DATA as one request
> (SMTP command pipelining, RFC 2920), that's why Postfix replies
> with 250/250/354 as one response.
>
> It is possible that there is a device in the path that tries to
> read SMTP conversation and that drops packets it does not understand.
> Stuff like that tends to be built into a network firewall.

Or worse, the device sees the MAIL FROM part and ignores the rest,
then the device sees the first 250 part and ignores the rest. Then
the remote SMTP client starts sending the message but the device
is still waiting for RCPT TO commands, so it drops everything it
does not expect.

> In that case, see what happens when you configure
>
> # postconf -e 'smtpd_discard_ehlo_keywords=pipelining'
> # postfix reload
>
> If that solves the problem then you can make this selective per
> client IP address with smtpd_discard_ehlo_keyword_address_maps.

That would still solve the problem if it is due to a device
that does not understand RFC 2920 command pipelining.

Wietse

[Giuseppe De Nicolo']

On 09/18/2014 05:40 PM, Wietse Venema wrote:
> Giuseppe De Nicolo':
>

>> 136.233724 212.19.117.109 217.72.32.234 SMTP 131 S:
>> 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with <CR><LF>.<CR><LF>
>> 136.441076 212.19.117.109 217.72.32.234 SMTP 131 [TCP
>> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
>> <CR><LF>.<CR><LF>

>> 136.468072 212.19.117.109 217.72.32.234 SMTP 131 [TCP

>> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
>> <CR><LF>.<CR><LF>

>> ..SNIP...
>> 377.007113 212.19.117.109 217.72.32.234 SMTP 131 [TCP

>> Retransmission] S: 250 2.1.0 Ok | 250 2.1.5 Ok | 354 End data with
>> <CR><LF>.<CR><LF>

>> 436.284965 212.19.117.109 217.72.32.234 SMTP 122 S:
>> 421 4.4.2 smtp.oapointgroup.it Error: timeout exceeded
> Somewhere between sender and receiver is a network with a smaller
> MTU, and the sender is not receiving the ICMP "fragmentation needed"
> messages. Only small packets are coming through.
>
> Wietse
>

Just to give a follow up the problem was resolved on their part using a
mangle firewall rule to clear the DF bit or so they say , anyway my
problem is solved

Thanks