fetchmail-friends
[Top] [All Lists]

[fetchmail]BUG (?) fetchmail 6.2.5 hangs with 'idle' on OpenBSD

2006-02-19 09:08:33
I include here full gdb, -V, and -v -v output. Here's a description
of the problem:

I'm running 6.2.5 on OpenBSD 3.3 to an IMAP server with 'idle' in the 
config file. The server does not support the IDLE command, so fetchmail
does the NOOP stuff.

Everything works fine until fetchmail enters the NOOP loop
_AND_ it receives a new incoming mail notification. I.e. the
IMAP server says:

fetchmail: IMAP< * 1 EXISTS

..then fetchmail hangs..it won't continue until a 300 second
timeout passes, and after that it reports:

fetchmail: timeout after 300 seconds waiting for server pop.kolumbus.fi.
fetchmail: socket error while fetching from pop.kolumbus.fi

..and then the normal cycle starts again. 

Here's all the debug info:

----------------------------------------------------------------------

Configurarion options:
./configure --enable-NTLM --with-ssl --disable-nls

----------------------------------------------------------------------

Config file:

set postmaster "casper"
set bouncemail
set no spambounce
set properties ""
set daemon 200
poll pop.kolumbus.fi with proto IMAP port 143
  user 'ea5540' there with password 'xxxxxxx' is 'casper' here options no keep 
idle

----------------------------------------------------------------------

fetchmail -V

This is fetchmail release 6.2.5+NTLM+SSL
Fallback MDA: (none)
OpenBSD zoidberg.homeip.net 3.3 GENERIC_NOIPV6#0 i386
Taking options from command line and /home/casper/.fetchmailrc
Poll interval is 10 seconds
Idfile is /home/casper/.fetchids
Fetchmail will forward misaddressed multidrop messages to casper.
Options for retrieving from ea5540(_at_)pop(_dot_)kolumbus(_dot_)fi:
  True name of server is pop.kolumbus.fi.
  Protocol is IMAP (using port 143).
  All available authentication methods will be tried.
  Server nonresponse timeout is 300 seconds (default).
  Default mailbox selected.
  Only new messages will be retrieved (--all off).
  Fetched messages will not be kept on the server (--keep off).
  Old messages will not be flushed before message retrieval (--flush off).
  Rewrite of server-local addresses is enabled (--norewrite off).
  Carriage-return stripping is disabled (stripcr off).
  Carriage-return forcing is disabled (forcecr off).
  Interpretation of Content-Transfer-Encoding is enabled (pass8bits off).
  MIME decoding is disabled (mimedecode off).
  Idle after poll is enabled (idle on).
  Nonempty Status lines will be kept (dropstatus off)
  Delivered-To lines will be kept (dropdelivered off)
  Fetch message size limit is 100 (--fetchsizelimit 100).
  Do binary search of UIDs during 9 out of 10 polls (--fastuidl 10).
  Messages will be SMTP-forwarded to: localhost (default)
  Single-drop mode: 1 local name(s) recognized.
  No UIDs saved from this host.

------------------------------------------------------------------------
Running with -v -v + gdb session:

zoidberg [Sun 19 15:42] <~/tmp/fetchmail-6.2.5>: ./fetchmail -N -v -v

fetchmail: starting fetchmail 6.2.5 daemon
fetchmail: 6.2.5 querying pop.kolumbus.fi (protocol IMAP) at Sun, 19 Feb 2006 
15:44:02 +0200 (EET): poll started
fetchmail: IMAP< * OK IMAP4 server (InterMail vM.6.01.04.01 
201-2131-118-101-20041129) ready Sun, 19 Feb 2006 15:44:02 +0200 (EET)
fetchmail: IMAP> A0001 CAPABILITY
fetchmail: IMAP< * CAPABILITY IMAP4rev1 UIDPLUS NAMESPACE QUOTA
fetchmail: IMAP< A0001 OK CAPABILITY completed
fetchmail: Protocol identified as IMAP4 rev 1
fetchmail: will idle after poll
fetchmail: IMAP> A0002 LOGIN "ea5540" *
fetchmail: IMAP< A0002 OK LOGIN completed
fetchmail: selecting or re-polling default folder
fetchmail: IMAP> A0003 SELECT "INBOX"
fetchmail: IMAP< * 0 EXISTS
fetchmail: IMAP< * OK [UIDVALIDITY 1031331700] UIDs valid
fetchmail: IMAP< * OK [UIDNEXT 1000] Predicted next UID
fetchmail: IMAP< * FLAGS (\Answered \Flagged \Deleted \Draft \Seen)
fetchmail: IMAP< * OK [PERMANENTFLAGS (\* \Answered \Flagged \Deleted \Draft 
\Seen)] Permanent flags
fetchmail: IMAP< * 0 RECENT
fetchmail: IMAP< A0003 OK [READ-WRITE] SELECT completed
fetchmail: 0 messages waiting after first poll
fetchmail: IMAP> A0004 NOOP
fetchmail: IMAP< A0004 OK NOOP completed
fetchmail: IMAP> A0005 NOOP
fetchmail: IMAP< A0005 OK NOOP completed
fetchmail: IMAP> A0006 NOOP
fetchmail: IMAP< A0006 OK NOOP completed
fetchmail: IMAP> A0007 NOOP
fetchmail: IMAP< A0007 OK NOOP completed
fetchmail: IMAP< * 1 EXISTS

Here fetchmail hangs..nothing happens for 300 secs..it's totally
dead. Sending SIGHUP doesn't help. So I enter GDB on another terminal:

(gdb) attach 19362
Attaching to program `/home/casper/tmp/fetchmail-6.2.5/fetchmail', process 19362
Symbols already loaded for /usr/libexec/ld.so
Symbols already loaded for /usr/local/lib/libintl.so.1.1
Symbols already loaded for /usr/lib/libssl.so.7.0
Symbols already loaded for /usr/lib/libcrypto.so.9.0
Symbols already loaded for /usr/lib/libc.so.29.0
Symbols already loaded for /usr/local/lib/libiconv.so.3.0
0x401ce7af in recvfrom ()
(gdb) up
#1  0x401abeff in recv ()
(gdb) up
#2  0xaf83 in SockRead (sock=3, buf=0xcfbf6b6c "* 1 EXISTS", len=8192) at 
socket.c:625
625                 if ((n = fm_peek(sock, bp, len)) <= 0)

Looks like it hangs on the 'peek':

(gdb) list
620             {
621
622     #ifdef __BEOS__
623                 if ((n = fm_read(sock, bp, 1)) <= 0)
624     #else
625                 if ((n = fm_peek(sock, bp, len)) <= 0)
626     #endif
627                     return (-1);
628                 maxavailable = n;
629                 if ((newline = memchr(bp, '\n', n)) != NULL)
(gdb) up
#3  0x2373d in gen_recv (sock=3, buf=0xcfbf6b6c "* 1 EXISTS", size=8193) at 
transact.c:1504
1504        if (SockRead(sock, buf, size) == -1)
(gdb) list
1499    {
1500        int oldphase = phase;       /* we don't have to be re-entrant */
1501
1502        phase = SERVER_WAIT;
1503        set_timeout(mytimeout);
1504        if (SockRead(sock, buf, size) == -1)
1505        {
1506            set_timeout(0);
1507            phase = oldphase;
1508            if(isidletimeout())
(gdb) print mytimeout
$1 = 300
(gdb) detach
Detaching from program: /home/casper/tmp/fetchmail-6.2.5/fetchmail process 19362
(gdb)

Timeout is indeed 300...so I detach and wait to see what happens,
and sure enough after 300 seconds it wakes up:

fetchmail: timeout after 300 seconds waiting for server pop.kolumbus.fi.
fetchmail: socket error while fetching from pop.kolumbus.fi
fetchmail: 6.2.5 querying pop.kolumbus.fi (protocol IMAP) at Sun, 19 Feb 2006 
15:50:40 +0200 (EET): poll completed
fetchmail: Query status=2 (SOCKET)
fetchmail: Deleting fetchids file.
fetchmail: sleeping at Sun, 19 Feb 2006 15:50:40 +0200 (EET)
fetchmail: awakened at Sun, 19 Feb 2006 15:50:50 +0200 (EET)
fetchmail: 6.2.5 querying pop.kolumbus.fi (protocol IMAP) at Sun, 19 Feb 2006 
15:50:50 +0200 (EET): poll started
fetchmail: IMAP< * OK IMAP4 server (InterMail vM.6.01.04.01 
201-2131-118-101-20041129) ready Sun, 19 Feb 2006 15:50:50 +0200 (EET)
fetchmail: IMAP> A0001 CAPABILITY
fetchmail: IMAP< * CAPABILITY IMAP4rev1 UIDPLUS NAMESPACE QUOTA
...

..and the mail is finally delivered. This cycle continues ad infinitum..
It hangs every time a new mail is reported by the IMAP server, and
then continues after 300 secs :(

Any ideas what could be wrong?

Thanks.

Regards,
  Casper


_______________________________________________
Fetchmail-friends mailing list
Fetchmail-friends(_at_)lists(_dot_)ccil(_dot_)org
http://lists.ccil.org/cgi-bin/mailman/listinfo/fetchmail-friends