On 06/03/11 15:39, Steve Perrault wrote:
> Running Sendmail 5.2a-1
>
> My mail sessions to one mail server (a Barracuda firewall) are dying if
> there is a large attachment
>
> I've turned on tcp_read and tcp_write logging. This is the log at the
> end of the session. Looks like SM is happily sending MIME-encoded data
> then something stops after 108s
>
> Have I stopped sending, or have they stopped receiving?
>
> ( lots of lines )
> 1 16:01:24.00:Info:-1300952144: tcp_write: [100]
> THMdzR7s7pAT\m\j37Z9xX21prMVVFJyTnIrxn9nDwknhfwZbxxxqhKgsB9BXqsOqMgwgzxWHL7zdjeDSibWoazHbL5U\m\jRy2AKbZa
>
> 1 16:01:24.00:Info:-1300952144: tcp_write: [100]
> rvjywycdzWBLflMyDknocV594x/aq+D3gjVv+Ee1vx/p0V7k7rRLpWkUjqCAa1Sk9uho\m\j63Jq3Y9avtSkkQt2XrisW+v7qfKxRk
>
> 1 16:03:12.00:Info:-1300952144: tcp_check_open got pullhup event on
> socket (Err Code Zero)
> 1 16:03:12.00:Info:-1300952144: tcp: Slow write 108 (108) seconds,
> 48046/63998 bytes sent
> 1 16:03:12.00:Info:-1300952144: Only wrote 48046/63998 bytes in that
> packet 1008802, retry 0, upto 0
> 1 16:03:12.00:Info:-1300952144: Only wrote 0/15952 bytes in that packet
> 1008802, upto=48046, in 109 seconds
> 1 16:03:12.00:Info:-1300952144: send_body failed (to=216.8.160.21
> TCPWrite failed 0/15952, tot=1008802 upto=48046 109 sec Connection was
> closed. writeopencheck)
> 1 16:03:12.00:Info:-1300952144: send: finished sending a message retry
> all (to=216.8.160.21 TCPWrite failed 0/15952, tot=1008802 upto=48046 109
> sec Connection was closed. writeopencheck)
> 1 16:03:12.00:Info:-1300952144: send: [177780956] going to set msg_later
> 1 [177780956]
> 1 16:03:12.00:Info:-1300952144: msg: log_reason [177780956] Later:
> 216.8.135.82 HIDDEN@ul@mnsi.net> <jbodchon@ventraplastics.com> 0
> "to=216.8.160.21 TCPWrite failed 0/15952, tot=1008802 upto=48046 109 sec
> Connection was closed. writeopencheck"
> 1 16:03:12.00:Info:-1300952144: q[177780956] send out->QUIT
> 1 16:03:12.00:Info:-1300952144: send: not open [177780956]
> 1 16:03:12.00:Info:-1300952144: Send_finish called from =
> HIDDEN@ul@mnsi.net>
> 1 16:03:12.00:Info:-1300952144: Send_finish, reque = 0
> 1 16:03:12.00:Info:-1300952144: msg_fque_todisk qnum=177780956 inmem was
> already false
> 1 16:03:12.00:Info:-1300952144: msg: rewriting msg file
> 1 16:03:12.00:Info:-1300952144: msg_open
> (/usr/local/surgemail/work/56/q177780956.idx_new)
> 1 16:03:12.00:Info:-1300952144: que_write q=177780956 idx_written 1
> 1 16:03:12.00:Info:-1300952144: msg_reque last qnum=177780956 busy=0
> 1 16:03:12.00:Info:-1300952144: send_thread, send_finish
> 1 16:03:12.00:Info:-1300952144: mlink_slow: Took 109 seconds
> 1 16:03:12.00:Info:-1300952144: online_mlink_tell_remove
>
> Who threw the pullhup event? My Surgemail server or the TCP session on
> the other end?
>
>

Is your server or their's behind a NAT that is dropping the sessions 
after ~100 seconds?  Thus breaking the TCP connection between the servers.

Lyle Giese
LCR Computer Services, Inc.