Re: sendmail Broken Pipe Error

From: Rick Macklem <rmacklem_at_uoguelph.ca>
Date: Fri, 28 Mar 2014 18:25:23 -0400 (EDT)
John-Mark Gurney wrote:
> Willy Offermans wrote this message on Thu, Mar 27, 2014 at 15:46
> +0100:
> > Hello John-Mark and FreeBSD friends,
> > 
> > On Wed, Mar 26, 2014 at 04:04:27PM -0700, John-Mark Gurney wrote:
> > > Willy Offermans wrote this message on Wed, Mar 26, 2014 at 18:22
> > > +0100:
> > > > Hello John-Mark and FreeBSD friends,
> > > > 
> > > > On Wed, Mar 26, 2014 at 09:20:35AM -0700, John-Mark Gurney
> > > > wrote:
> > > > > Willy Offermans wrote this message on Wed, Mar 26, 2014 at
> > > > > 12:17 +0100:
> > > > > > 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'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...
> > > > > > 
> > > > > > 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
> > > > > 
> > > > > It should look something like:
> > > > > 09:18:34.723280 IP jmgmac.funkthat.com.64724 >
> > > > > h2.funkthat.com.ssh: Flags [.], ack 177, win 33280, options
> > > > > [nop,nop,TS val 1854905469 ecr 3482476972], length 0
> > > > >         0x0000:  4510 0034 d7ac 4000 4006 e1af c0a8 0003
> > > > >          E..4.._at_._at_.......
> > > > >         0x0010:  c0a8 0004 fcd4 0016 7e48 238e d872 43dc
> > > > >          ........~H#..rC.
> > > > >         0x0020:  8010 8200 7c08 0000 0101 080a 6e8f 9c7d
> > > > >          ....|.......n..}
> > > > >         0x0030:  cf92 61ac
> > > > >                                        ..a.
> > > > > 
> > > > > Notice the hex output...  I didn't see any of that in your
> > > > > output...
> > > > > The last packet I was talking about is the last one that had
> > > > > length
> > > > > 1448 that your server sent...
> > > > 
> > > > I sent two e-mails consecutively: the first without an
> > > > attachment, the
> > > > second with attachment. I dumped tcp of the NIC for port smtp.
> > > > I got the
> > > > following:
> > > > 
> > > > 
> > > > 12:20:55.988622 IP MyServer.com.37191 > Smarthost.com.smtp:
> > > > Flags [P.], seq 18943:19104, ack 412, win 65535, length 161
> > > >         0x0000:  4500 00c9 eebd 4000 4006 0000 c0a8 0004
> > > >          E....._at_._at_.......
> > > >         0x0010:  d54b 3f0d 9147 0019 4ea0 36dd 15a7 38a0
> > > >          .K?..G..N.6...8.
> > > >         0x0020:  5018 ffff 4481 0000 2020 2020 2020 2020
> > > >          P...D...........
> > > >         0x0030:  2020 2020 2020 2020 2020 2020 2020 2020
> > > >          ................
> > > >         0x0040:  2020 2020 2020 2020 2020 2020 2020 205c
> > > >          ...............\
> > > >         0x0050:  2f20 205c 205e 0d0a 2020 2020 2020 2020
> > > >          /..\.^..........
> > > >         0x0060:  2020 2020 2020 2020 2020 2020 2020 2020
> > > >          ................
> > > >         0x0070:  2020 2020 2020 2020 2020 2020 2020 2020
> > > >          ................
> > > >         0x0080:  2020 202e 5c2e 5f2f 5f29 0d0a 0d0a 2020
> > > >          ....\._/_)......
> > > >         0x0090:  2020 2020 2020 2020 2020 2020 2020 2020
> > > >          ................
> > > >         0x00a0:  2020 2020 2020 2020 2020 2020 2020 2020
> > > >          ................
> > > >         0x00b0:  2020 2020 2077 7777 2e46 7265 6542 5344
> > > >          .....www.FreeBSD
> > > >         0x00c0:  2e6f 7267 0d0a 2e0d 0a
> > > >                           .org.....
> > > > 
> > > > As predicted by John-Mark, the first ended with "0d0a 2e0d 0a".
> > > > However it
> > > > was not the last packet with length 1448. I hope that this will
> > > > not spoil
> > > > the party. Is the Flag [P.] more indicative? It looks like to
> > > > me, but I'm
> > > > just learning.
> > > > 
> > > > Anyway the second mail ended with:
> > > > 
> > > > 12:22:17.960896 IP MyServer.com.37191 > Smarthost.com.smtp:
> > > > Flags [.], seq 35127:36575, ack 638, win 65535, length 1448
> > > >         0x0000:  4500 05d0 fe9d 4000 4006 0000 c0a8 0004
> > > >          E....._at_._at_.......
> > > > <snip>
> > > > </snip>
> > > >         0x0560:  5670 6876 4a67 5a5a 5a50 4b2f 4b78 3774
> > > >          VphvJgZZZPK/Kx7t
> > > >         0x0570:  382f 4230 594f 6b78 3449 0d0a 4a76 6551
> > > >          8/B0YOkx4I..JveQ
> > > >         0x0580:  2b6e 7765 5647 2f33 6e79 6231 6133 496f
> > > >          +nweVG/3nyb1a3Io
> > > >         0x0590:  5474 554f 4d61 4374 696b 714b 436b 4959
> > > >          TtUOMaCtikqKCkIY
> > > >         0x05a0:  704a 7668 3055 416d 6c33 4754 4f4c 6455
> > > >          pJvh0UAml3GTOLdU
> > > >         0x05b0:  774b 4145 7151 5741 7841 4141 5a66 7647
> > > >          wKAEqQWAxAAAZfvG
> > > >         0x05c0:  706b 6c36 0d0a 7a4e 6234 745a 6633 5a6c
> > > >          pkl6..zNb4tZf3Zl
> > > > 
> > > > Being packet with length 1448 and sent from my side. The code
> > > > "0d0a 2e0d
> > > > 0a" is missing. Immediately thereafter the following packets:
> > > 
> > > We clearly haven't gotten the last mime-boundary, we are still in
> > > the
> > > base64 encoded data of the attachment...
> > > 
> > > > 12:22:18.003557 IP Smarthost.com.smtp > MyServer.com.37191:
> > > > Flags [.], ack 36575, win 65160, length 0
> > > >         0x0000:  4500 0028 11fb 4000 7a06 19d0 d54b 3f0d
> > > >          E..(.._at_.z....K?.
> > > >         0x0010:  c0a8 0004 0019 9147 15a7 3982 4ea0 7bbd
> > > >          .......G..9.N.{.
> > > >         0x0020:  5010 fe88 315f 0000 0000 0000 0000
> > > >               P...1_........
> > > 
> > > The remote acking that it got your last packet...
> > > 
> > > > 12:22:37.665889 IP MyServer.com.37191 > Smarthost.com.smtp:
> > > > Flags [R.], seq 39471, ack 638, win 65535, length 0
> > > >         0x0000:  4500 0028 492c 4000 4006 0000 c0a8 0004
> > > >          E..(I,_at_._at_.......
> > > >         0x0010:  d54b 3f0d 9147 0019 4ea0 870d 15a7 3982
> > > >          .K?..G..N.....9.
> > > >         0x0020:  5014 ffff 2494 0000
> > > >                              P...$...
> > > 
> > > Local host closing down the connection because of time out...
> > > 
> > > > 12:22:37.680857 IP Smarthost.com.smtp > MyServer.com.37191:
> > > > Flags [.], ack 36575, win 65160, length 0
> > > >         0x0000:  4500 0028 0584 0000 f906 e746 d54b 3f0d
> > > >          E..(.......F.K?.
> > > >         0x0010:  c0a8 0004 0019 9147 15a7 3982 4ea0 7bbd
> > > >          .......G..9.N.{.
> > > >         0x0020:  5010 fe88 315f 0000 0000 0000 0000
> > > >               P...1_........
> > > > 12:22:37.680920 IP MyServer.com.37191 > Smarthost.com.smtp:
> > > > Flags [R], seq 1319140285, win 0, length 0
> > > >         0x0000:  4500 0028 4935 4000 4006 0000 c0a8 0004
> > > >          E..(I5_at_._at_.......
> > > >         0x0010:  d54b 3f0d 9147 0019 4ea0 7bbd 0000 0000
> > > >          .K?..G..N.{.....
> > > >         0x0020:  5004 0000 7f1d 0000
> > > >                              P.......
> > > > 
> > > > It looks like Smarthost.com asks for more, but there is not
> > > > more to sent.
> > > > The final packet seems to be absent. I cannot look for the
> > > > closing remark
> > > > "www.FreeBSD.org", since there is the attachment at the end of
> > > > the second
> > > > mail. Is there any connection between the encoded attachment in
> > > > the second
> > > > mail and the output of tcpdump?
> > > > 
> > > > Am I the only one noticing this error? I can hardly believe
> > > > this.
> > > > 
> > > > Is there a way to force the insertion of <CRLF>.<CRLF>?
> > > 
> > > So, this is more looking like a kernel problem where the last
> > > packet(s)
> > > aren't being sent out...  Could you possibly catch the output of
> > > netstat -anfinet of the connection between the last packet and
> > > the
> > > reset?  It'll be interesting to see if there is data in the
> > > send-q
> > > for the connection (third column)...  If it's zero, that seems to
> > > imply
> > > that the server process hasn't sent all the data necessary...
> > >  Then
> > > the next bit of investigation would be to run ktrace on the
> > > sendmail
> > > process and make sure that it writes all the correct data to the
> > > socket...
> > > 
> > > Do you know what OS the remote side is running?  You could use
> > > nmap
> > > to try to figure it out, as it could be a TCP stack interaction
> > > issue..
> > 
> > netstat -anfinet gave:
> > 
> > tcp4       0  33304 MyServerIP.35395      SmarthostIP.25
> > ESTABLISHED
> > 
> > So there is still data to be sent, if I interpret correctly. What
> > is next
> > to be investigated?
> 
> Yeh, if there is data in the send-q (per above) and you aren't seeing
> any more packets, someone on -net with some TCP clue should help you
> debug this...
> 
> Also, did you figure out what the OS is of the other end?  Knowing
> that will also help them...
> 
> For -net's reference, the opening syns look like:
> 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
> 
You could try disabling TSO on the bge net interface(s). They are among
the ones that only handle 32 transmit segments for TSO and this can cause
problems for NFS (and a tester reported iSCSI).

Also, at a glance, if_bge.c uses a mix of m_collapse() and m_defrag().
{ m_collapse() has lower overhead, but is less likely to compact the
  TSO segment into 32 mbufs }

You can read this thread for the story of the NFS case:
  http://docs.FreeBSD.org/cgi/mid.cgi?1850411724.1687820.1395621539316.JavaMail.root

Good luck with it, rick

> --
>   John-Mark Gurney				Voice: +1 415 225 5579
> 
>      "All that I will do, has been done, All that I have, has not."
> _______________________________________________
> freebsd-net_at_freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-net
> To unsubscribe, send any mail to
> "freebsd-net-unsubscribe_at_freebsd.org"
> 
Received on Fri Mar 28 2014 - 21:25:31 UTC

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