[Dovecot] dovecot 1.0-test69 io hangs
I've been testing test69 with pop3 (under Linux and with mbox). I began testing with a large inbox (11000 mails) and it seems the communication between dovecot and the mailclient (evolution) stalls after 1000-2000 messages transferred.
I've looked in to the (non-trivial) io functionality of dovecot. What I see is that io_loop_handler_run() in ioloop-poll.c does not signal any more data (and eventually the whole thing timeouts).
Evolution downloads the mailbox fine via qpopper.
I tried turning on rawlog: mail_executable = /usr/libexec/dovecot/rawlog /usr/libexec/dovecot/pop3
I cannot find any logfile.. I must be missing something.
Any help or ideas ?
Cheers, Jens
'This mail automatically becomes portable when carried.' Jens Låås Email: jens.laas@data.slu.se
Department of Computer Services, SLU Phone: +46 18 67 35 15
Vindbrovägen 1
P.O. Box 7079
S-750 07 Uppsala
SWEDEN Hi Jens,
You have to create a dovecot.rawlog directory in the user's home directory (or what dovecot thinks is that directory). That way you limit the logging to problematic users.
Regards Andrew
On Fri, 2005-05-13 at 09:07 +0200, Jens Laas wrote:
I've been testing test69 with pop3 (under Linux and with mbox). I began testing with a large inbox (11000 mails) and it seems the communication between dovecot and the mailclient (evolution) stalls after 1000-2000 messages transferred.
I've looked in to the (non-trivial) io functionality of dovecot. What I see is that io_loop_handler_run() in ioloop-poll.c does not signal any more data (and eventually the whole thing timeouts).
Evolution downloads the mailbox fine via qpopper.
I tried turning on rawlog: mail_executable = /usr/libexec/dovecot/rawlog /usr/libexec/dovecot/pop3
I cannot find any logfile.. I must be missing something.
Any help or ideas ?
Cheers, Jens
'This mail automatically becomes portable when carried.'
Jens Låås Email: jens.laas@data.slu.se Department of Computer Services, SLU Phone: +46 18 67 35 15 Vindbrovägen 1 P.O. Box 7079 S-750 07 Uppsala SWEDEN
-- Andrew Hutchings (A-Wing) Linux Guru - Netserve Consultants Ltd. - www.domaincity.co.uk Admin - North Wales Linux User Group - www.nwlug.org.uk BOFH excuse 58: high pressure system failure
(05.05.13 kl.08:41) Andrew Hucthings skrev följande till dovecot@dovecot.org:
Hi Jens,
You have to create a dovecot.rawlog directory in the user's home directory (or what dovecot thinks is that directory). That way you limit the logging to problematic users.
Thanks.
Its seems like this is a heisenbug. When I use rawlog the hang problem does not show itself. (Likewise it took longer to show when I patched in some extra logging, so the load of the machine/connection seems to be involved.)
Ill try to think of something else...
Cheers, Jens
Regards Andrew
On Fri, 2005-05-13 at 09:07 +0200, Jens Laas wrote:
I've been testing test69 with pop3 (under Linux and with mbox). I began testing with a large inbox (11000 mails) and it seems the communication between dovecot and the mailclient (evolution) stalls after 1000-2000 messages transferred.
I've looked in to the (non-trivial) io functionality of dovecot. What I see is that io_loop_handler_run() in ioloop-poll.c does not signal any more data (and eventually the whole thing timeouts).
Evolution downloads the mailbox fine via qpopper.
I tried turning on rawlog: mail_executable = /usr/libexec/dovecot/rawlog /usr/libexec/dovecot/pop3
I cannot find any logfile.. I must be missing something.
Any help or ideas ?
Cheers, Jens
'This mail automatically becomes portable when carried.'
Jens Låås Email: jens.laas@data.slu.se Department of Computer Services, SLU Phone: +46 18 67 35 15 Vindbrovägen 1 P.O. Box 7079 S-750 07 Uppsala SWEDEN
-- Andrew Hutchings (A-Wing) Linux Guru - Netserve Consultants Ltd. - www.domaincity.co.uk Admin - North Wales Linux User Group - www.nwlug.org.uk BOFH excuse 58: high pressure system failure
'This mail automatically becomes portable when carried.' Jens Låås Email: jens.laas@data.slu.se
Department of Computer Services, SLU Phone: +46 18 67 35 15
Vindbrovägen 1
P.O. Box 7079
S-750 07 Uppsala
SWEDEN (05.05.13 kl.12:36) Jens Laas skrev följande till Andrew Hucthings:
(05.05.13 kl.08:41) Andrew Hucthings skrev följande till dovecot@dovecot.org:
Hi Jens,
You have to create a dovecot.rawlog directory in the user's home directory (or what dovecot thinks is that directory). That way you limit the logging to problematic users.
Thanks.
Its seems like this is a heisenbug. When I use rawlog the hang problem does not show itself. (Likewise it took longer to show when I patched in some extra logging, so the load of the machine/connection seems to be involved.)
Ill try to think of something else...
Cheers, Jens
Ive implemented a lot of logging with i_info. It seems like input from client is disabled and never reenabled.
(The more logging I do the harder it seems to be to trigger the hang..)
Log: dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8185 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8186 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): client_send_line: disabling input wi:false dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8187 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): client_input: handled 3 cmds dovecot: May 13 13:49:39 Info: POP3(jenslt): client_output: enabling input dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8188 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8189 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8190 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): client_send_line: disabling input wi:false dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8191 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8192 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): RETR: fetch 8193 begin dovecot: May 13 13:49:39 Info: POP3(jenslt): client_input: handled 6 cmds dovecot: May 13 13:49:44 Info: POP3(jenslt): io_loop_handler_run: 4 sec timeout in poll(5999)
.. and here we are stuck
Ill attach the relevant patches for this kind of logging. They are all incremental patches on top of the nice logging patch previously posted here by .. someone i forgot.
The first attchment is the general logging patch. The rest are my debug patches.
Cheers, Jens
Regards Andrew
On Fri, 2005-05-13 at 09:07 +0200, Jens Laas wrote:
I've been testing test69 with pop3 (under Linux and with mbox). I began testing with a large inbox (11000 mails) and it seems the communication between dovecot and the mailclient (evolution) stalls after 1000-2000 messages transferred.
I've looked in to the (non-trivial) io functionality of dovecot. What I see is that io_loop_handler_run() in ioloop-poll.c does not signal any more data (and eventually the whole thing timeouts).
Evolution downloads the mailbox fine via qpopper.
I tried turning on rawlog: mail_executable = /usr/libexec/dovecot/rawlog /usr/libexec/dovecot/pop3
I cannot find any logfile.. I must be missing something.
Any help or ideas ?
Cheers, Jens
'This mail automatically becomes portable when carried.'
Jens Låås Email: jens.laas@data.slu.se Department of Computer Services, SLU Phone: +46 18 67 35 15 Vindbrovägen 1 P.O. Box 7079 S-750 07 Uppsala SWEDEN
-- Andrew Hutchings (A-Wing) Linux Guru - Netserve Consultants Ltd. - www.domaincity.co.uk Admin - North Wales Linux User Group - www.nwlug.org.uk BOFH excuse 58: high pressure system failure
'This mail automatically becomes portable when carried.'
Jens Låås Email: jens.laas@data.slu.se Department of Computer Services, SLU Phone: +46 18 67 35 15 Vindbrovägen 1 P.O. Box 7079 S-750 07 Uppsala SWEDEN
'This mail automatically becomes portable when carried.' Jens Låås Email: jens.laas@data.slu.se
Department of Computer Services, SLU Phone: +46 18 67 35 15
Vindbrovägen 1
P.O. Box 7079
S-750 07 Uppsala
SWEDEN On Fri, 2005-05-13 at 12:36 +0200, Jens Laas wrote:
Its seems like this is a heisenbug. When I use rawlog the hang problem does not show itself.
That's because then all the data from imap process's point of view is already sent (to rawlog process). Looks like with at least Linux kernel it can eat megabytes of data into kernel memory (I think? wonder how the memory limits go there..) before transmit buffer is full, if the socket destination is in the same computer.
(Likewise it took longer to show when I patched in some extra logging, so the load of the machine/connection seems to be involved.)
So the client will have more time to read the answer without making imap process's transmit buffer full.
I've been testing test69 with pop3 (under Linux and with mbox). I began testing with a large inbox (11000 mails) and it seems the communication between dovecot and the mailclient (evolution) stalls after 1000-2000 messages transferred.
Looks like I broke it in test69. This should fix it: Index: src/pop3/client.c =================================================================== RCS file: /var/lib/cvs/dovecot/src/pop3/client.c,v retrieving revision 1.51 diff -u -r1.51 client.c --- src/pop3/client.c 29 Apr 2005 11:42:38 -0000 1.51 +++ src/pop3/client.c 13 May 2005 13:03:20 -0000 @@ -345,8 +345,11 @@ client->last_output = ioloop_time; o_stream_cork(client->output); - if (client->cmd != NULL) + if (client->cmd != NULL) { client->cmd(client); + if (client->cmd != NULL) + o_stream_set_flush_pending(client->output, TRUE); + } o_stream_uncork(client->output); if (o_stream_get_buffer_used_size(client->output) <
participants (3)
-
Andrew Hucthings
-
Jens Laas
-
Timo Sirainen