Re: sendmail Broken Pipe Error

From: Willy Offermans <Willy_at_Offermans.Rompen.nl>
Date: Wed, 26 Mar 2014 12:17:49 +0100
Hello John-Mark Gurney,

On Tue, Mar 25, 2014 at 09:43:16AM -0700, John-Mark Gurney wrote:
> Willy Offermans wrote this message on Tue, Mar 25, 2014 at 11:39 +0100:
> > I found the following command, that generates some more informative output,
> > I hope.
> > 
> > root_at_MyServer:/home/MyName # sendmail -q -v
> > 
> > Running /var/spool/mqueue/s2ODs1hH016114 (sequence 1 of 2)
> > <MyFriend_at_MyFriendsDomainName>... Connecting to Smarhost.com via relay...
> > 220 CPSMTPM-CMT109.MyProvider.com MyProvider.com Tue, 25 Mar 2014 10:45:21
> > +0100 
> > >>> EHLO MyServer.MyDomain.com
> > 250-CPSMTPM-CMT109.MyProvider.com Hello [77.170.60.162]
> > 250-TURN
> > 250-SIZE 15744000
> > 250-ETRN
> > 250-PIPELINING
> > 250-DSN
> > 250-ENHANCEDSTATUSCODES
> > 250-8bitmime
> > 250-CHUNKING
> > 250-VRFY
> > 250 OK
> > >>> MAIL From:<MyName_at_MyRewrittenDomainName> SIZE=1254972
> > 250 2.1.0 MyName_at_MyRewrittenDomainName....Sender OK
> > >>> RCPT To:<MyFriend_at_MyFriendsDomainName>
> > >>> DATA
> > 250 2.1.5 MyFriend_at_MyFriendsDomainName 
> > 354 Start mail input; end with <CRLF>.<CRLF>
> > timeout writing message to Smarhost.com: Broken pipe
> > <MyFriend_at_MyFriendsDomainName>... Deferred
> > 
> > If I copy the *s2ODs1hH016114 files to MySecondServer and run 
> > sendmail -q -v once more, I got the following:
> > 
> > Running /var/spool/mqueue/s2ODs1hH016114 (sequence 1 of 1)
> > <MyFriend_at_MyFriendsDomainName>... Connecting to Smarhost.com via relay...
> > 220 CPSMTPM-cmt107.MyProvider.com MyProvider.com Tue, 25 Mar 2014 10:57:56
> > +0100 
> > >>> EHLO MySecondServer.MyRewrittenDomainName
> > 250-CPSMTPM-cmt107.MyProvider.com Hello [77.170.60.162]
> > 250-TURN
> > 250-SIZE 15744000
> > 250-ETRN
> > 250-PIPELINING
> > 250-DSN
> > 250-ENHANCEDSTATUSCODES
> > 250-8bitmime
> > 250-CHUNKING
> > 250-VRFY
> > 250 OK
> > >>> MAIL From:<MyName_at_MyRewrittenDomainName> SIZE=1254972
> > 250 2.1.0 MyName_at_MyRewrittenDomainName....Sender OK
> > >>> RCPT To:<MyFriend_at_MyFriendsDomainName>
> > >>> DATA
> > 250 2.1.5 MyFriend_at_MyFriendsDomainName 
> > 354 Start mail input; end with <CRLF>.<CRLF>
> > >>> .
> > 250 2.6.0  <20140324135355.GC6581_at_vpn.MyDomain.com> Queued mail for delivery
> > <MyFriend_at_MyFriendsDomainName>... Sent ( <20140324135355.GC6581_at_vpn.MyDomain.com>
> > Queued mail for delivery)
> > Closing connection to Smarhost.com
> > >>> QUIT
> > 221 2.0.0 CPSMTPM-cmt107.MyProvider.com Service closing transmission
> > channel
> > 
> > The test shows me that the problem is not on the MyProvider side.
> > 
> > The sendmail.cf files on the two server are identical, except the names of the 
> > servers and some comments.
> > 
> > The sendmail versions are different and the FreeBSD versions are different:
> > MyServer:
> > Sendmail Version 8.14.7
> > FreeBSD 10.0-STABLE
> > 
> > MySecondServer:
> > Sendmail Version 8.14.5
> > FreeBSD 9.0-RELEASE-p4
> > 
> > It is also important to note that above can only be observed for some
> > e-mails, not all. Thus some mails will be sent from MyServer, some are not!
> > 
> > If I make a tcpdump during the connection between sendmail and smarthost
> > concerning s2ODs1hH016114, I got the following:
> > 
> > 11:24:23.301300 IP MyServer.MyDomain.com.49165 > DNSMyProvider.domain: 32794+ [1au] MX? Smarhost.com. (43)
> > 11:24:23.320078 IP DNSMyProvider.domain > MyServer.MyDomain.com.49165: 32794 1/1/1 CNAME CNameMyProvider. (125)
> > 11:24:23.321592 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [S], seq 2245424203, win 65535, options [mss 1448,nop,wscale 6,sackOK,TS val 318826742 ecr 0], length 0
> > 11:24:23.339171 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [S.], seq 2238169153, ack 2245424204, win 8192, options [mss 1452], length 0
> > 11:24:23.339221 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], ack 1, win 65535, length 0
> > 11:24:23.355143 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [P.], seq 1:84, ack 1, win 65160, length 83
> > 11:24:23.355254 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [P.], seq 1:24, ack 84, win 65535, length 23
> > 11:24:23.370795 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [P.], seq 84:276, ack 24, win 65137, length 192
> > 11:24:23.371025 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [P.], seq 24:76, ack 276, win 65535, length 52
> > 11:24:23.392751 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [P.], seq 276:326, ack 76, win 65085, length 50
> > 11:24:23.393010 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [P.], seq 76:119, ack 326, win 65535, length 43
> > 11:24:23.414297 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [P.], seq 326:364, ack 119, win 65042, length 38
> > 11:24:23.520345 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], ack 364, win 65535, length 0
> > 11:24:23.535218 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [P.], seq 364:410, ack 119, win 65042, length 46
> > 11:24:23.769098 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 119:1567, ack 410, win 65535, length 1448
> > 11:24:23.769108 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 119:1567, ack 410, win 65535, length 1448
> > 11:24:23.811918 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 1567, win 65160, length 0
> > 11:24:24.077092 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 1567:3015, ack 410, win 65535, length 1448
> > 11:24:24.077101 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 1567:3015, ack 410, win 65535, length 1448
> > 11:24:24.119910 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 3015, win 65160, length 0
> > 11:24:24.451090 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 3015:4463, ack 410, win 65535, length 1448
> > 11:24:24.451100 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 3015:4463, ack 410, win 65535, length 1448
> > 11:24:24.493910 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 4463, win 65160, length 0
> > 11:24:24.957099 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 4463:5911, ack 410, win 65535, length 1448
> > 11:24:24.957110 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 4463:5911, ack 410, win 65535, length 1448
> > 11:24:24.999924 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 5911, win 65160, length 0
> > 11:24:25.727077 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 5911:7359, ack 410, win 65535, length 1448
> > 11:24:25.727085 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 5911:7359, ack 410, win 65535, length 1448
> > 11:24:25.769595 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 7359, win 65160, length 0
> > 11:24:26.929090 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 7359:8807, ack 410, win 65535, length 1448
> > 11:24:26.929099 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 7359:8807, ack 410, win 65535, length 1448
> > 11:24:26.972062 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 8807, win 65160, length 0
> > 11:24:29.100086 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 8807:10255, ack 410, win 65535, length 1448
> > 11:24:29.100093 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 8807:10255, ack 410, win 65535, length 1448
> > 11:24:29.142755 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 10255, win 65160, length 0
> > 11:24:33.205088 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 10255:11703, ack 410, win 65535, length 1448
> > 11:24:33.205100 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 10255:11703, ack 410, win 65535, length 1448
> > 11:24:33.247458 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 11703, win 65160, length 0
> > 11:24:41.127081 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 11703:13151, ack 410, win 65535, length 1448
> > 11:24:41.127091 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 11703:13151, ack 410, win 65535, length 1448
> > 11:24:41.169601 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 13151, win 65160, length 0
> > 11:24:56.729079 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 13151:14599, ack 410, win 65535, length 1448
> > 11:24:56.729086 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 13151:14599, ack 410, win 65535, length 1448
> > 11:24:56.771445 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 14599, win 65160, length 0
> > 11:25:12.331083 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 14599:16047, ack 410, win 65535, length 1448
> > 11:25:12.331094 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 14599:16047, ack 410, win 65535, length 1448
> > 11:25:12.373602 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 16047, win 65160, length 0
> > 11:25:27.933084 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 16047:17495, ack 410, win 65535, length 1448
> > 11:25:27.933095 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [.], seq 16047:17495, ack 410, win 65535, length 1448
> 
> The one odd thing I notice is that there doesn't seem to be a non-MTU
> sized frame to end the transmission...  The chances of that happeneing
> are slim...  1/1448 in fact...  Could this be an issue w/ FreeBSD not
> sending out the last frame after ack?  With out knowing what the last
> packet contains, it's hard to say...
> 
> > 11:25:27.975453 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 17495, win 65160, length 0
> > 11:25:43.535093 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [R.], seq 20391, ack 410, win 65535, length 0
> > 11:25:43.549940 IP ActualSmarthost.com.smtp > MyServer.MyDomain.com.51274: Flags [.], ack 17495, win 65160, length 0
> > 11:25:43.550002 IP MyServer.MyDomain.com.51274 > ActualSmarthost.com.smtp: Flags [R], seq 2245441698, win 0, length 0
> > 
> > I'm not an expert in tcpdump. Can anyone make sense out of the messages?
> 
> If you dumped the contents, using -s 0 -X, and look at that last packet
> you should see 0d 0a 2e 0d 0a at the end..  which is CR/LF/./CR/LF.. If
> you don't see that, then for some reason sendmail/FreeBSD isn't telling
> the server that it's done sending which would prevent the receiving
> side from ack'ing the email causing the timeout...
> 
> -- 
>   John-Mark Gurney				Voice: +1 415 225 5579
> 
>      "All that I will do, has been done, All that I have, has not."
> _______________________________________________
> freebsd-current_at_freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-current
> To unsubscribe, send any mail to "freebsd-current-unsubscribe_at_freebsd.org"

I followed your suggestions. However I'm not able to distinguish the last
packet. Is there a way to find this with help of the Flags? The following
is the output of tcpdump -r /root/tmp/tcpdump -X | grep Flags

11:57:56.539788 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [S], seq 1001452351, win 65535, options [mss 1448,nop,wscale 6,sackOK,TS val 407239960 ecr 0], length 0
11:57:56.555262 IP Smarthost.com.smtp > MyServer.com.41115: Flags [S.], seq 1277075046, ack 1001452352, win 8192, options [mss 1452], length 0
11:57:56.555324 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], ack 1, win 65535, length 0
11:57:56.570648 IP Smarthost.com.smtp > MyServer.com.41115: Flags [P.], seq 1:84, ack 1, win 65160, length 83
11:57:56.570766 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [P.], seq 1:24, ack 84, win 65535, length 23
11:57:56.586467 IP Smarthost.com.smtp > MyServer.com.41115: Flags [P.], seq 84:276, ack 24, win 65137, length 192
11:57:56.586714 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [P.], seq 24:75, ack 276, win 65535, length 51
11:57:56.609793 IP Smarthost.com.smtp > MyServer.com.41115: Flags [P.], seq 276:326, ack 75, win 65086, length 50
11:57:56.610005 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [P.], seq 75:113, ack 326, win 65535, length 38
11:57:56.631140 IP Smarthost.com.smtp > MyServer.com.41115: Flags [P.], seq 326:359, ack 113, win 65048, length 33
11:57:56.737002 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], ack 359, win 65535, length 0
11:57:56.751874 IP Smarthost.com.smtp > MyServer.com.41115: Flags [P.], seq 359:405, ack 113, win 65048, length 46
11:57:56.986989 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 113:1561, ack 405, win 65535, length 1448
11:57:56.987000 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 113:1561, ack 405, win 65535, length 1448
11:57:57.029507 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 1561, win 65160, length 0
11:57:57.297003 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 1561:3009, ack 405, win 65535, length 1448
11:57:57.297013 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 1561:3009, ack 405, win 65535, length 1448
11:57:57.339976 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 3009, win 65160, length 0
11:57:57.675996 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 3009:4457, ack 405, win 65535, length 1448
11:57:57.676007 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 3009:4457, ack 405, win 65535, length 1448
11:57:57.718213 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 4457, win 65160, length 0
11:57:58.201067 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 4457:5905, ack 405, win 65535, length 1448
11:57:58.201076 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 4457:5905, ack 405, win 65535, length 1448
11:57:58.243285 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 5905, win 65160, length 0
11:57:59.010630 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 5905:7353, ack 405, win 65535, length 1448
11:57:59.010639 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 5905:7353, ack 405, win 65535, length 1448
11:57:59.053151 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 7353, win 65160, length 0
11:58:00.245068 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 7353:8801, ack 405, win 65535, length 1448
11:58:00.245077 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 7353:8801, ack 405, win 65535, length 1448
11:58:00.287443 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 8801, win 65160, length 0
11:58:02.419988 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 8801:10249, ack 405, win 65535, length 1448
11:58:02.419996 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 8801:10249, ack 405, win 65535, length 1448
11:58:02.462508 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 10249, win 65160, length 0
11:58:06.531992 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 10249:11697, ack 405, win 65535, length 1448
11:58:06.532004 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 10249:11697, ack 405, win 65535, length 1448
11:58:06.574362 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 11697, win 65160, length 0
11:58:14.453988 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 11697:13145, ack 405, win 65535, length 1448
11:58:14.454000 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 11697:13145, ack 405, win 65535, length 1448
11:58:14.496061 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 13145, win 65160, length 0
11:58:30.055988 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 13145:14593, ack 405, win 65535, length 1448
11:58:30.055997 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 13145:14593, ack 405, win 65535, length 1448
11:58:30.098510 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 14593, win 65160, length 0
11:58:45.657987 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 14593:16041, ack 405, win 65535, length 1448
11:58:45.657996 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 14593:16041, ack 405, win 65535, length 1448
11:58:45.700808 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 16041, win 65160, length 0
11:59:01.259990 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 16041:17489, ack 405, win 65535, length 1448
11:59:01.259999 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [.], seq 16041:17489, ack 405, win 65535, length 1448
11:59:01.302361 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 17489, win 65160, length 0
11:59:16.862003 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [R.], seq 20385, ack 405, win 65535, length 0
11:59:16.876967 IP Smarthost.com.smtp > MyServer.com.41115: Flags [.], ack 17489, win 65160, length 0
11:59:16.877022 IP MyServer.com.41115 > Smarthost.com.smtp: Flags [R], seq 1001469840, win 0, length 0

-- 
Met vriendelijke groeten,
With kind regards,
Mit freundlichen Gruessen,
De jrus wah,

Wiel

*************************************
 W.K. Offermans
e-mail: Willy_at_Offermans.Rompen.nl

                                       Powered by ....

                                            (__)
                                         \\\'',)
                                           \/  \ ^
                                           .\._/_)

                                       www.FreeBSD.org
Received on Wed Mar 26 2014 - 10:22:07 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:48 UTC