sendmail Broken Pipe Error

[Willy Offermans]

Dear FreeBSD friends,

Lately I have setup a new FreeBSD server with 10.0-STABLE. Most of it went
smoothly. However I have an issue with sendmail. Some of the mails can be
sent out correctly, some of them stay in /var/spool/mqueue/. The provided
error messages are in the latter case:

Mar 24 14:16:01 MyServer sm-mta[11725]: s2ODCWT4011717: SYSERR(root): timeout writing message to MyProvider.com: Broken pipe
Mar 24 14:16:01 MyServer sm-mta[11725]: s2ODCWT4011717: to=<SomeA...@example.com>, delay=00:03:29, xdelay=00:03:26, mailer=relay, pri=1284849, relay=MyProvider.com [XXX.XXX.XXX.XXX], dsn=4.0.0, stat=Deferred

I'm using Version 8.14.7
All was fine when I was using Version 8.14.5.

Since there is a timeout error, I like to know what sendmail is writing to
MyProvider.com

Is there a way to debug sendmail to disclose the message written to
MyProvider.com and the response from MyProvider.com. I'm pretty sure that
there lays the solution to my problem.

Any help is highly appreciated.

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

Wiel

*************************************
W.K. Offermans
_______________________________________________
freebsd...@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-curre...@freebsd.org"

[John-Mark Gurney]

Willy Offermans wrote this message on Mon, Mar 24, 2014 at 14:36 +0100:
> Dear FreeBSD friends,
>
> Lately I have setup a new FreeBSD server with 10.0-STABLE. Most of it went
> smoothly. However I have an issue with sendmail. Some of the mails can be
> sent out correctly, some of them stay in /var/spool/mqueue/. The provided
> error messages are in the latter case:
>
> Mar 24 14:16:01 MyServer sm-mta[11725]: s2ODCWT4011717: SYSERR(root): timeout writing message to MyProvider.com: Broken pipe
> Mar 24 14:16:01 MyServer sm-mta[11725]: s2ODCWT4011717: to=<SomeA...@example.com>, delay=00:03:29, xdelay=00:03:26, mailer=relay, pri=1284849, relay=MyProvider.com [XXX.XXX.XXX.XXX], dsn=4.0.0, stat=Deferred
>
> I'm using Version 8.14.7
> All was fine when I was using Version 8.14.5.
>
> Since there is a timeout error, I like to know what sendmail is writing to
> MyProvider.com
>
> Is there a way to debug sendmail to disclose the message written to
> MyProvider.com and the response from MyProvider.com. I'm pretty sure that
> there lays the solution to my problem.
>
> Any help is highly appreciated.

You could use tcpflow to capture the flows for myprovider.com and look
at them...

Though you are seeing a timeout, so it sounds like myprovider.com isn't
reading your message in a timely fasion..

--
John-Mark Gurney Voice: +1 415 225 5579

"All that I will do, has been done, All that I have, has not."

[Claus Assmann]

On Mon, Mar 24, 2014, Willy Offermans wrote:

> Mar 24 14:16:01 MyServer sm-mta[11725]: s2ODCWT4011717: SYSERR(root): timeout writing message to MyProvider.com: Broken pipe
> Mar 24 14:16:01 MyServer sm-mta[11725]: s2ODCWT4011717: to=<SomeA...@example.com>, delay=00:03:29, xdelay=00:03:26, mailer=relay, pri=1284849, relay=MyProvider.com [XXX.XXX.XXX.XXX], dsn=4.0.0, stat=Deferred

> Since there is a timeout error, I like to know what sendmail is writing to
> MyProvider.com

The mail message (DATA) -- as the log entry states.

> Is there a way to debug sendmail to disclose the message written to
> MyProvider.com and the response from MyProvider.com. I'm pretty sure that

There's no response...
check out s2ODCWT4011717 in your mail queue.

[Willy Offermans]

Dear Claus and FreeBSD friends,

This sounds very reasonable, but for your better understanding the
following: My old FreeBSD server is still running as well. This server runs
sendmail 8.14.5 and does not show these errors. So I'm puzzled what the
problem might be.

--
Met vriendelijke groeten,
With kind regards,
Mit freundlichen Gruessen,

Willy

*************************************
W.K. Offermans

[Willy Offermans]

Dear FreeBSD friends,

I found the following command, that generates some more informative output,
I hope.

root@MyServer:/home/MyName # sendmail -q -v

Running /var/spool/mqueue/s2ODs1hH016114 (sequence 1 of 2)
<MyFriend@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@MyRewrittenDomainName> SIZE=1254972
250 2.1.0 MyName@MyRewrittenDomainName....Sender OK
>>> RCPT To:<MyFriend@MyFriendsDomainName>
>>> DATA
250 2.1.5 MyFriend@MyFriendsDomainName
354 Start mail input; end with <CRLF>.<CRLF>
timeout writing message to Smarhost.com: Broken pipe
<MyFriend@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@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@MyRewrittenDomainName> SIZE=1254972
250 2.1.0 MyName@MyRewrittenDomainName....Sender OK
>>> RCPT To:<MyFriend@MyFriendsDomainName>
>>> DATA
250 2.1.5 MyFriend@MyFriendsDomainName
354 Start mail input; end with <CRLF>.<CRLF>
>>> .
250 2.6.0 <2014032413...@vpn.MyDomain.com> Queued mail for delivery
<MyFriend@MyFriendsDomainName>... Sent ( <2014032413...@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
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?

--
Met vriendelijke groeten,
With kind regards,
Mit freundlichen Gruessen,

De jrus wah,

Wiel

[John-Mark Gurney]

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."

[Willy Offermans]

Hallo FreeBSD friends,

As I said, I'm not an expert in tcpdump, but I will dump with -s 0 -X and
try to get a look to the packages. However I can already announce that the
error only occurs with e-mails __with__ attachments. E-mails without
attachments can pass through seemingly without an issue.

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

Wiel

*************************************
W.K. Offermans

Home: +31 45 544 49 44
Mobile: +31 681 15 87 68
Mobile: +49 1575 414 60 55
e-mail: Wi...@Offermans.Rompen.nl

Powered by ....

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

www.FreeBSD.org

[Willy Offermans]

Hello John-Mark Gurney,

On Tue, Mar 25, 2014 at 09:43:16AM -0700, John-Mark Gurney wrote:

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: Wi...@Offermans.Rompen.nl

Powered by ....

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

www.FreeBSD.org

[John-Mark Gurney]

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..@.@.......
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...

[Gregory Shapiro]

> > 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..@.@.......
> 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...

Willy mentioned that this only happened on mail with attachments. Could it be an MTU issue? Specifically, see:

http://www.sendmail.com/sm/open_source/tips/path_mtu/

[John-Mark Gurney]

Gregory Shapiro wrote this message on Wed, Mar 26, 2014 at 09:23 -0700:
> > > 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..@.@.......
> > 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...
>
> Willy mentioned that this only happened on mail with attachments. Could it be an MTU issue? Specifically, see:
>
> http://www.sendmail.com/sm/open_source/tips/path_mtu/

I don't see how it could be... If it is litterally only mail with
attachments and not large emails w/o attachments, then it's definately
not that issue.. He could just disable path_mtu on the server:
sysctl net.inet.tcp.path_mtu_discovery=0

to test this, but I'd be surprised if it allows email through, since
he's already getting 1448 byte packets through and acked before the
hang up occurs...

--
John-Mark Gurney Voice: +1 415 225 5579

"All that I will do, has been done, All that I have, has not."

[Willy Offermans]

Hello John-Mark and FreeBSD friends,

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.....@.@.......
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.....@.@.......
<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:

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..(..@.z....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.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,@.@.......
0x0010: d54b 3f0d 9147 0019 4ea0 870d 15a7 3982 .K?..G..N.....9.
0x0020: 5014 ffff 2494 0000 P...$...
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@.@.......
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>?

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

Wiel

*************************************
W.K. Offermans

Powered by ....

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

www.FreeBSD.org

[John-Mark Gurney]

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..(..@.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,@.@.......
> 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@.@.......
> 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..

[Willy Offermans]

Hello John-Mark and FreeBSD friends,

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?

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

Wiel

*************************************
W.K. Offermans

e-mail: Wi...@Offermans.Rompen.nl

Powered by ....

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

www.FreeBSD.org

[John-Mark Gurney]

> 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

[Willy Offermans]

Hello John-Mark and FreeBSD friends,

I did some more investigations and I found the following:

1) The error depends on the size of the e-mail not the presence or absence
of an attachment. I put rfc3028.txt into a test mail and try to sent it. It
got stuck in the mail server with eventually the same Broken pipe/time out
error as previously discussed.

2) I noticed a substantial increase in CPU usage of natd and dhcpd when the
e-mail is being processed by the mail server.

From top:

PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND

1235 root 1 93 0 28908K 2144K RUN 0 54:05 71.78% natd
1614 dhcpd 1 4 0 26784K 14936K RUN 0 29:24 38.77% dhcpd

The idle cpu load of these services is ca. 0.00%.

3) I experienced extremely slow copy processes with scp not related with
e-mail processing.

4) All other processes run smoothly to my notice and that makes it tricky
to discover.

5) I tried to figure out the OS on the Smarthost:

Nmap scan report for Smarthost.com (SmarthostIP)
Host is up (0.023s latency).
Not shown: 994 closed ports
PORT STATE SERVICE
25/tcp open smtp
135/tcp filtered msrpc
139/tcp filtered netbios-ssn
445/tcp filtered microsoft-ds
1720/tcp filtered H.323/Q.931
5555/tcp filtered freeciv

This looks like some kind of MS OS to me.

*)
So I get the feeling that the encountered problems are somehow
hardware related or related to my settings. Can someone suggest a good
description of my problem?

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

Wiel

*************************************
W.K. Offermans
e-mail: Wi...@Offermans.Rompen.nl

Powered by ....

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

www.FreeBSD.org

[Rick Macklem]

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."
> _______________________________________________

> freeb...@freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-net

> To unsubscribe, send any mail to

> "freebsd-net...@freebsd.org"

[Lucius Rizzo]

* Willy Offermans <Wi...@Offermans.Rompen.nl> [2014-03-24 14:36]:

> Dear FreeBSD friends,
>
> Lately I have setup a new FreeBSD server with 10.0-STABLE. Most of it went
> smoothly. However I have an issue with sendmail. Some of the mails can be
> sent out correctly, some of them stay in /var/spool/mqueue/. The provided
> error messages are in the latter case:
>
> Mar 24 14:16:01 MyServer sm-mta[11725]: s2ODCWT4011717: SYSERR(root): timeout
> writing message to MyProvider.com: Broken pipe Mar 24 14:16:01 MyServer
> sm-mta[11725]: s2ODCWT4011717: to=<SomeA...@example.com>, delay=00:03:29,
> xdelay=00:03:26, mailer=relay, pri=1284849, relay=MyProvider.com
> [XXX.XXX.XXX.XXX], dsn=4.0.0, stat=Deferred
>
> I'm using Version 8.14.7 All was fine when I was using Version 8.14.5.

Could be a number of things -- maybe even TLS? I am currently on 8.14.8 which
is the latest. I have a pretty complex setup including milters galore with zero
problems. Have you considered updating to the latest release? That might
help.

You can also try sending an email via debug in sendmail to MyProvider.com and
see if there is something going on or perhaps provide us with a few more
details..

--

| _o _ |_)o_ _ _
|_|_|(_||_|_> | \|/_/_(_) - Lucius.Tel
--------------------------------------
++ What the hell is it good for? ++
++ -- Robert Lloyd (engineer of the Advanced Computing Systems ++
++ Division of IBM), to colleagues who insisted that the ++
++ microprocessor was the wave of the future, c. 1968 ++

[Willy Offermans]

Hello Rick and FreeBSD friends,

Disabling ISO on the bge net interface did the trick. Thnx a lot Rick for
the hint.

How can I save this setting in the rc.conf file to disable TSO at startup?

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

Wiel

*************************************
W.K. Offermans
e-mail: Wi...@Offermans.Rompen.nl

Powered by ....

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

www.FreeBSD.org

[Kevin Oberman]

On Sun, Mar 30, 2014 at 12:44 PM, Allan Jude <fre...@allanjude.com> wrote:

> On 2014-03-30 15:31, Willy Offermans wrote:
> > Hello Rick and FreeBSD friends,
> >

> > How can I save this setting in the rc.conf file to disable TSO at
> startup?
> >
>

> add -tso to the ifconfig line:
>
> ifconfig_bge0="inet <ip address> netmask <subnet mask> -tso"
> --
> Allan Jude
>
>
I'd recommend that people stop using the long obsolete netmask form of
ifconfig, especially when making suggestions to others. CIDR notation is
about two decades old now.

ifconfig_bge0="inet <ip address/len> -tso"

--
R. Kevin Oberman, Network Engineer, Retired
E-mail: rkob...@gmail.com