[tpop3d-discuss] tpop3d[2209]: net_loop: timed out client

[Matthew Trent]

On Wednesday 10 December 2003 02:49 pm, Chris Lightfoot wrote:
> To me it looks like the client started reading the message
> at 17:11:12, and was timed out at 17:18:00.
>
> > Dec 10 17:18:01 gucio tpop3d[2209]: connections_post_select: client
> > [7]abakus(195.116.149.253): finished session for `abakus ' with mysql
> >
> > Dec 10 17:18:01 gucio tpop3d[2209]: connections_post_select: client
> > [7]abakus(195.116.149.253): disconnected; 64/719042 byte s read/written
> >
> > but only 719042 bytes written? Message was ~2MB and tpop3d wrote ,,sent
> > message''! Looks like some tpop3d bug.
>
> -- that's consistent with a client timeout during message
> transmission.

Ok, here's another timeout. This time the customer didn't get copies of the 
message, but the connection always died on a certain message (not quite 100k 
this time). We deleted a bunch of messages that were before it in the list, 
but it would always hang on this one message. The customer tried several 
times with us on the phone to download it. Client was Outlook Express I 
believe.

Dec 10 15:06:12 mail1 tpop3d[12906]: fork_child: [6]folger(69.10.200.188): 
began session for `folger' with mysql; child PID is 23813
Dec 10 15:06:12 mail1 tpop3d[23813]: maildir_new: scanned maildir /var/spool/
store/SERVERS/localaccess.com/folger (42 messages) in 0.047s
Dec 10 15:06:12 mail1 tpop3d[23813]: connection_sendresponse: client 
[6]folger(69.10.200.188): sent `+OK Welcome aboard! You have 42 messages.'
Dec 10 15:06:12 mail1 tpop3d[23813]: connection_parsecommand: client 
[6]folger(69.10.200.188): received `STAT'
Dec 10 15:06:12 mail1 tpop3d[23813]: connection_sendresponse: client 
[6]folger(69.10.200.188): sent `+OK 42 1736358'
Dec 10 15:06:12 mail1 tpop3d[23813]: connection_parsecommand: client 
[6]folger(69.10.200.188): received `LIST'
Dec 10 15:06:12 mail1 tpop3d[23813]: connection_sendresponse: client 
[6]folger(69.10.200.188): sent `+OK Scan list follows:'
Dec 10 15:06:12 mail1 tpop3d[23813]: do_list: client [6]folger(69.10.200.188): 
sent 43-line scan list
Dec 10 15:06:13 mail1 tpop3d[23813]: connection_parsecommand: client 
[6]folger(69.10.200.188): received `RETR 1'
Dec 10 15:06:13 mail1 tpop3d[23813]: do_retr: client [6]folger(69.10.200.188): 
sending message 1 (2526 bytes)
Dec 10 15:06:13 mail1 tpop3d[23813]: connection_sendresponse: client 
[6]folger(69.10.200.188): sent `+OK Message follows'
Dec 10 15:06:13 mail1 tpop3d[23813]: do_retr: client [6]folger(69.10.200.188): 
sent message 1
Dec 10 15:06:16 mail1 tpop3d[23813]: connection_parsecommand: client 
[6]folger(69.10.200.188): received `RETR 2'
Dec 10 15:06:16 mail1 tpop3d[23813]: do_retr: client [6]folger(69.10.200.188): 
sending message 2 (97545 bytes)
Dec 10 15:06:16 mail1 tpop3d[23813]: connection_sendresponse: client 
[6]folger(69.10.200.188): sent `+OK Message follows'
Dec 10 15:06:16 mail1 tpop3d[23813]: do_retr: client [6]folger(69.10.200.188): 
sent message 2
Dec 10 15:07:05 mail1 tpop3d[23813]: connection_sendresponse: client 
[6]folger(69.10.200.188): sent `-ERR Client has been idle for too long.'
Dec 10 15:07:05 mail1 tpop3d[23813]: net_loop: timed out client 
[6]folger(69.10.200.188)
Dec 10 15:07:05 mail1 tpop3d[23813]: connections_post_select: client 
[6]folger(69.10.200.188): finished session for `folger' with mysql
Dec 10 15:07:05 mail1 tpop3d[23813]: connections_post_select: client 
[6]folger(69.10.200.188): disconnected; 52/101546 bytes read/written

Looks like the total bytes is consistant will the full message (plus message 
#1) being sent. The interesting thing is this email is full of random 
characters. It kinda looks like a jpg file pasted raw into the message body. 
The headers look fine.

ftp://alderaan.localaccess.com/gibberish is the email in question. The other 
file in there ("email") is the big one with the mpg attachment I mentioned 
earlier.
-- 
Matt
Systems Administrator
Local Access Communications
360.330.5535