fetchmail-users

[fetchmail-users] Bug in imap_idle() with mail servers not supporting "idle"

[Brendan L. <bre...@ai...>]

I've run across what I believe to be a bug in imap_idle() on servers not 
supporting the IDLE extension.  There is code in imap_idle() that tries 
to simulate and idle() call with frequent NOOP calls:

    624     } else {  /* no idle support, fake it */
    625         /* when faking an idle, we can't assume the server will
    626          * send us the new messages out of the blue (RFC2060);
    627          * this timeout is potentially the delay before we notice
    628          * new mail (can be small since NOOP checking is cheap) */
    629         mytimeout = 28;
    630         ok = gen_transact(sock, "NOOP");
    631         /* if there's an error (not likely) or we just found 
mail (stage
    632          * has changed, timeout has also been restored), we're 
done */
    633         if (ok != 0 || stage != STAGE_IDLE)
    634             return(ok);
    635
    636         /* wait (briefly) for an unsolicited status update */
    637         ok = imap_ok(sock, NULL);
    638         /* again, this is new mail or an error */
    639         if (ok != PS_IDLETIMEOUT)
    640             return(ok);
    641     }

This code works fine until a notification of new mail is received (a "* 
1 EXISTS" message is received).  At this point normally one is in the 
"imap_ok()" routine called from line 637, and this correctly receives 
the notification message and parses it, updating the "count" variable.  
However it does not the return to imap_idle() routine, but instead 
reissues a recv call having set a much longer (300s) timeout and after 
the 300s have expired it then returns an error causing fetchmail to drop 
the IMAP connection (a main point of this idle code was to keep the 
connection open for subsequent message retrieval).  Net result is that 
delivery of mail is delayed by 5 minutes and the server connection is 
dropped and reestablished each time a wait for mail occurs.

The problem seems to be caused by the loop condition in imap_ok():

    151         }
    152     } while
    153         (tag[0] != '\0' && strncmp(buf, tag, strlen(tag)));
    154

This assumes that tag[0] will be set to '\0' if one is not waiting for a 
tagged response.  In this case the code should not be waiting for a 
tagged response (it is waiting for an unsolicited notification).  
However the 'tag' global character array is set by the gen_transact() at 
line 630 and is not cleared before the call to imap_ok() at line 637.

The fix is a very simple one-line change to imap_idle (2 lines with 
comments):

    630         ok = gen_transact(sock, "NOOP");
    631         /* if there's an error (not likely) or we just found 
mail (stage
    632          * has changed, timeout has also been restored), we're 
done */
    633         if (ok != 0 || stage != STAGE_IDLE)
    634             return(ok);
    635
+   636         /* clear tag so imap_ok does not expect tagged response */
+   637         tag[0]='\0';
    638         /* wait (briefly) for an unsolicited status update */
    639         ok = imap_ok(sock, NULL);

A second, more minor problem is that getting a "* RECENT" notification 
does not break a caller out of the imap_idle's imap_ok() call.  This 
causes an extra 28second wait after being notified about a message 
before it is actually received.

Diffs for the complete set of changes against 6.3.2 are attached to this 
email.

I have seen this in fetchmail 6.2.5 and 6.3.2 on linux platforms, but 
this problem should be generic to all platforms.

Re: [fetchmail-users] Bug in imap_idle() with mail servers not supporting "idle"

[Matthias A. <mat...@gm...>]

Brendan Lynch <bre...@ai...> writes:

> This code works fine until a notification of new mail is received (a "*
> 1 EXISTS" message is received).  At this point normally one is in the
> "imap_ok()" routine called from line 637, and this correctly receives
> the notification message and parses it, updating the "count" variable.
> However it does not the return to imap_idle() routine, but instead
> reissues a recv call having set a much longer (300s) timeout and after
> the 300s have expired it then returns an error causing fetchmail to drop
> the IMAP connection (a main point of this idle code was to keep the
> connection open for subsequent message retrieval).  Net result is that
> delivery of mail is delayed by 5 minutes and the server connection is
> dropped and reestablished each time a wait for mail occurs.
>
> The problem seems to be caused by the loop condition in imap_ok():
>
>    151         }
>    152     } while
>    153         (tag[0] != '\0' && strncmp(buf, tag, strlen(tag)));
>    154
>
> This assumes that tag[0] will be set to '\0' if one is not waiting for a
> tagged response.  In this case the code should not be waiting for a
> tagged response (it is waiting for an unsolicited notification).
> However the 'tag' global character array is set by the gen_transact() at
> line 630 and is not cleared before the call to imap_ok() at line 637.

This is correct, an IMAP client is supposed to parse untagged responses
until a tagged response is received. Trying with Dovecot and hacking
fetchmail a bit so it doesn't recognize RECENT and uses the NOOP
emulation code yields:

...
fetchmail: IMAP> A0010 NOOP
fetchmail: IMAP< A0010 OK NOOP completed.
fetchmail: IMAP> A0011 NOOP
fetchmail: IMAP< * 1 EXISTS
fetchmail: IMAP< * 1 RECENT
fetchmail: IMAP< A0011 OK NOOP completed.
fetchmail: IMAP> A0012 NOOP
...

So it waits for the tagged NOOP response, and this is a requirement so
it actually picks up both the EXISTS and the RECENT responses of working
servers. Servers that do not respond with a tagged response to a NOOP
command are broken.

> The fix is a very simple one-line change to imap_idle (2 lines with
> comments):
>
>    630         ok = gen_transact(sock, "NOOP");
>    631         /* if there's an error (not likely) or we just found mail
> (stage
>    632          * has changed, timeout has also been restored), we're
> done */
>    633         if (ok != 0 || stage != STAGE_IDLE)
>    634             return(ok);
>    635
> +   636         /* clear tag so imap_ok does not expect tagged response */
> +   637         tag[0]='\0';
>    638         /* wait (briefly) for an unsolicited status update */
>    639         ok = imap_ok(sock, NULL);

So this patch would sort of break the IMAP client because it would jump
out of the loop before having read the reply. This requires more
thought. Casper Gripenberg reported a similar problem, so perhaps some
common upstream server software is the culprit (and he suggested a
different fix, I'll have a look at that too).

What software is your upstream server running?

Can I see a "fetchmail -Nvvv --nosyslog" trace of a failing IMAP session
with NOOP emulation?

> A second, more minor problem is that getting a "* RECENT" notification
> does not break a caller out of the imap_idle's imap_ok() call.  This
> causes an extra 28second wait after being notified about a message
> before it is actually received.
>
> Diffs for the complete set of changes against 6.3.2 are attached to this
> email.
>
> I have seen this in fetchmail 6.2.5 and 6.3.2 on linux platforms, but
> this problem should be generic to all platforms.
> diff -Naur fetchmail-6.3.2/imap.c fetchmail-6.3.2a/imap.c
> --- fetchmail-6.3.2/imap.c  2006-01-20 10:38:45.000000000 +0000
> +++ fetchmail-6.3.2a/imap.c 2006-02-23 23:54:52.000000000 +0000
> @@ -116,6 +116,17 @@
>         {
>         recentcount_ok = 1;
>         recentcount = atoi(buf+2);
> +       /*
> +        * Kluge to handle IDLE simulation. If we are in STAGE_IDLE and
> +        * we are simulating (has_idle unset) we need to alert calling
> +        * imap_idle() to the fact that we have received a new "recent"
> +        * alert in order to break the imap_idle() out of its wait.
> +        */
> +       if (!has_idle && stage == STAGE_IDLE)
> +       {
> +           mytimeout = saved_timeout;
> +           stage = STAGE_FETCH;
> +       }
>         }
>         else if (strstr(buf, " EXPUNGE"))
>         {

This looks acceptable.

How can a server mark a new message "RECENT" without also sending an
"EXISTS"? I'm inclined to consider such behavior broken. I'm willing to
apply this nonetheless as I don't think it would hurt anyone.

-- 
Matthias Andree

[fetchmail-users] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Sunil S. <sh...@bo...>]

Quoting from Matthias Andree's mail on Mon, Feb 27, 2006:
> Brendan Lynch <bre...@ai...> writes:
> Can I see a "fetchmail -Nvvv --nosyslog" trace of a failing IMAP session
> with NOOP emulation?
> 
> > A second, more minor problem is that getting a "* RECENT" notification
> > does not break a caller out of the imap_idle's imap_ok() call.  This
> > causes an extra 28second wait after being notified about a message
> > before it is actually received.
> >
> > Diffs for the complete set of changes against 6.3.2 are attached to this
> > email.
> >
> > I have seen this in fetchmail 6.2.5 and 6.3.2 on linux platforms, but
> > this problem should be generic to all platforms.
> > diff -Naur fetchmail-6.3.2/imap.c fetchmail-6.3.2a/imap.c
> > --- fetchmail-6.3.2/imap.c  2006-01-20 10:38:45.000000000 +0000
> > +++ fetchmail-6.3.2a/imap.c 2006-02-23 23:54:52.000000000 +0000
> > @@ -116,6 +116,17 @@
> >         {
> >         recentcount_ok = 1;
> >         recentcount = atoi(buf+2);
> > +       /*
> > +        * Kluge to handle IDLE simulation. If we are in STAGE_IDLE and
> > +        * we are simulating (has_idle unset) we need to alert calling
> > +        * imap_idle() to the fact that we have received a new "recent"
> > +        * alert in order to break the imap_idle() out of its wait.
> > +        */
> > +       if (!has_idle && stage == STAGE_IDLE)
> > +       {
> > +           mytimeout = saved_timeout;
> > +           stage = STAGE_FETCH;
> > +       }
> >         }
> >         else if (strstr(buf, " EXPUNGE"))
> >         {
> 
> This looks acceptable.
> 
> How can a server mark a new message "RECENT" without also sending an
> "EXISTS"? I'm inclined to consider such behavior broken. I'm willing to
> apply this nonetheless as I don't think it would hurt anyone.

I think, it would still be advisable to first get the output of
"fetchmail -Nvv --nosyslog" before accepting the patch. It is possible
that the problem lies elsewhere.

-- 
Sunil Shetye.

[fetchmail-users] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Sunil S. <sh...@bo...>]

I think this issue is similar to the one reported by Casper
Gripenberg. Could you try this patch and report if it works for you?

=========================================================================
Index: fetchmail/imap.c
===================================================================
--- fetchmail/imap.c	(revision 4696)
+++ fetchmail/imap.c	(working copy)
@@ -633,11 +633,12 @@
 	if (ok != 0 || stage != STAGE_IDLE)
 	    return(ok);
 
-	/* wait (briefly) for an unsolicited status update */
-	ok = imap_ok(sock, NULL);
-	/* again, this is new mail or an error */
-	if (ok != PS_IDLETIMEOUT)
-	    return(ok);
+	/* we used to wait for an unsolicited status update here with
+	 * imap_ok(). However, since no command has actually been
+	 * sent, there is no "tag" which can be used for comparison.
+	 * Just sleep instead */
+	set_timeout(0);
+	sleep(mytimeout);
     }
 
     /* restore normal timeout value */
=========================================================================

-- 
Sunil Shetye.

[fetchmail-users] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Brendan L. <bre...@ai...>]

I have been in communication with Casper; see my response to Matthias 
earlier in this thread.

Brendan

sh...@bo... wrote:

>I think this issue is similar to the one reported by Casper
>Gripenberg. Could you try this patch and report if it works for you?
>
>=========================================================================
>Index: fetchmail/imap.c
>===================================================================
>--- fetchmail/imap.c    (revision 4696)
>+++ fetchmail/imap.c    (working copy)
>@@ -633,11 +633,12 @@
>    if (ok != 0 || stage != STAGE_IDLE)
>        return(ok);
> 
>-   /* wait (briefly) for an unsolicited status update */
>-   ok = imap_ok(sock, NULL);
>-   /* again, this is new mail or an error */
>-   if (ok != PS_IDLETIMEOUT)
>-       return(ok);
>+   /* we used to wait for an unsolicited status update here with
>+    * imap_ok(). However, since no command has actually been
>+    * sent, there is no "tag" which can be used for comparison.
>+    * Just sleep instead */
>+   set_timeout(0);
>+   sleep(mytimeout);
>     }
> 
>     /* restore normal timeout value */
>=========================================================================
>
>  
>

Re: [fetchmail-users] Bug in imap_idle() with mail servers not supporting "idle"

[Brendan L. <bre...@ai...>]

I've seen the problem with a couple of upstream servers: I'll get you 
the id of my current server when I get home.

However I believe the servers is behaving correctly according to the 
IMAP spec: I have attached an explanation of the secondary problem I am 
seeing (extra 28 s wait) that I sent to Casper; let me know if you need 
more info.

I've put comments to your comments below.

Brendan

mat...@gm... wrote:

>Brendan Lynch <bre...@ai...> writes:
>
>  
>
>>This code works fine until a notification of new mail is received (a "*
>>1 EXISTS" message is received).  At this point normally one is in the
>>"imap_ok()" routine called from line 637, and this correctly receives
>>the notification message and parses it, updating the "count" variable.
>>However it does not the return to imap_idle() routine, but instead
>>reissues a recv call having set a much longer (300s) timeout and after
>>the 300s have expired it then returns an error causing fetchmail to drop
>>the IMAP connection (a main point of this idle code was to keep the
>>connection open for subsequent message retrieval).  Net result is that
>>delivery of mail is delayed by 5 minutes and the server connection is
>>dropped and reestablished each time a wait for mail occurs.
>>
>>The problem seems to be caused by the loop condition in imap_ok():
>>
>>   151         }
>>   152     } while
>>   153         (tag[0] != '\0' && strncmp(buf, tag, strlen(tag)));
>>   154
>>
>>This assumes that tag[0] will be set to '\0' if one is not waiting for a
>>tagged response.  In this case the code should not be waiting for a
>>tagged response (it is waiting for an unsolicited notification).
>>However the 'tag' global character array is set by the gen_transact() at
>>line 630 and is not cleared before the call to imap_ok() at line 637.
>>    
>>
>
>This is correct, an IMAP client is supposed to parse untagged responses
>until a tagged response is received. Trying with Dovecot and hacking
>fetchmail a bit so it doesn't recognize RECENT and uses the NOOP
>emulation code yields:
>
>...
>fetchmail: IMAP> A0010 NOOP
>fetchmail: IMAP< A0010 OK NOOP completed.
>fetchmail: IMAP> A0011 NOOP
>fetchmail: IMAP< * 1 EXISTS
>fetchmail: IMAP< * 1 RECENT
>fetchmail: IMAP< A0011 OK NOOP completed.
>fetchmail: IMAP> A0012 NOOP
>...
>
>So it waits for the tagged NOOP response, and this is a requirement so
>it actually picks up both the EXISTS and the RECENT responses of working
>servers. Servers that do not respond with a tagged response to a NOOP
>command are broken.
>  
>
See my explanation to Casper. 

The key point is that the imap_idle() code when 'faking' IDLE support 
calls imap_ok() (at line 637) without having issued any tagged command:

    625         /* when faking an idle, we can't assume the server will
    626          * send us the new messages out of the blue (RFC2060);
    627          * this timeout is potentially the delay before we notice
    628          * new mail (can be small since NOOP checking is cheap) */
    629         mytimeout = 28;
    630         ok = gen_transact(sock, "NOOP");
    631         /* if there's an error (not likely) or we just found 
mail (stage
    632          * has changed, timeout has also been restored), we're 
done */
    633         if (ok != 0 || stage != STAGE_IDLE)
    634             return(ok);
    635
    636         /* wait (briefly) for an unsolicited status update */
    637         ok = imap_ok(sock, NULL);
    638         /* again, this is new mail or an error */
    639         if (ok != PS_IDLETIMEOUT)
    640             return(ok);

Since there is no tagged command outstanding the server will not (and 
should not) ever send a tagged response.  If we set imap_ok to only 
return after a tagged response we are guaranteeing it will always only 
return after a timeout.

Worse, if the server does send an unsolicited EXISTS message during this 
(28s) imap_ok() wait, there is already-existing special-case code to 
handle an unsolicited EXITS message in imap_ok:

     93                 /*
     94                  * Nasty kluge to handle RFC2177 IDLE.  If we 
know we're idling
     95                  * we can't wait for the tag matching the IDLE; 
we have to tell the
     96                  * server the IDLE is finished by shipping back 
a DONE when we
     97                  * see an EXISTS.  Only after that will a tagged 
response be
     98                  * shipped.  The idling flag also gets cleared 
on a timeout.
     99                  */
    100                 if (stage == STAGE_IDLE)
    101                 {
    102                     /* If IDLE isn't supported, we were only 
sending NOOPs anyway. */
    103                     if (has_idle)
    104                     {
    105                         /* we do our own write and report here 
to disable tagging */
    106                         SockWrite(sock, "DONE\r\n", 6);
    107                         if (outlevel >= O_MONITOR)
    108                             report(stdout, "IMAP> DONE\n");
    109                     }
    110
    111                     mytimeout = saved_timeout;
    112                     stage = STAGE_FETCH;
    113                 }

The last 2 lines are executed even for the NOOP-emulated idle.  This 
causes us to  change the timeout to 5 minutes and set stage to 
STAGE_FETCH.  Then, if we are waiting for a tagged response, we loop 
around and wait for 5 minutes for a tagged response (which we will never 
see) and eventually return PS_SOCKET (since our wait times out and we 
are not in STAGE_IDLE) causing fetchmail to drop and reestablish the 
mail server connection.

>  
>
>>The fix is a very simple one-line change to imap_idle (2 lines with
>>comments):
>>
>>   630         ok = gen_transact(sock, "NOOP");
>>   631         /* if there's an error (not likely) or we just found mail
>>(stage
>>   632          * has changed, timeout has also been restored), we're
>>done */
>>   633         if (ok != 0 || stage != STAGE_IDLE)
>>   634             return(ok);
>>   635
>>+   636         /* clear tag so imap_ok does not expect tagged response */
>>+   637         tag[0]='\0';
>>   638         /* wait (briefly) for an unsolicited status update */
>>   639         ok = imap_ok(sock, NULL);
>>    
>>
>
>So this patch would sort of break the IMAP client because it would jump
>out of the loop before having read the reply. This requires more
>thought. Casper Gripenberg reported a similar problem, so perhaps some
>common upstream server software is the culprit (and he suggested a
>different fix, I'll have a look at that too).
>  
>

No, the client *is not* waiting for a reply; the reply was received and 
processed in the gen_transact() call at line 630; this deals with an 
imap_ok wait where no command has been issued.

>What software is your upstream server running?
>
>Can I see a "fetchmail -Nvvv --nosyslog" trace of a failing IMAP session
>with NOOP emulation?
>  
>

I'll set this up this evening and send you the trace and a timed strace 
(which is much more useful).  My mail to Caper includes an strace where 
the 'exit on unsolicited notification during imap_idle fix is in place, 
but the second 'RECENT' modification is not.

>  
>
>>A second, more minor problem is that getting a "* RECENT" notification
>>does not break a caller out of the imap_idle's imap_ok() call.  This
>>causes an extra 28second wait after being notified about a message
>>before it is actually received.
>>
>>Diffs for the complete set of changes against 6.3.2 are attached to this
>>email.
>>
>>I have seen this in fetchmail 6.2.5 and 6.3.2 on linux platforms, but
>>this problem should be generic to all platforms.
>>diff -Naur fetchmail-6.3.2/imap.c fetchmail-6.3.2a/imap.c
>>--- fetchmail-6.3.2/imap.c  2006-01-20 10:38:45.000000000 +0000
>>+++ fetchmail-6.3.2a/imap.c 2006-02-23 23:54:52.000000000 +0000
>>@@ -116,6 +116,17 @@
>>        {
>>        recentcount_ok = 1;
>>        recentcount = atoi(buf+2);
>>+       /*
>>+        * Kluge to handle IDLE simulation. If we are in STAGE_IDLE and
>>+        * we are simulating (has_idle unset) we need to alert calling
>>+        * imap_idle() to the fact that we have received a new "recent"
>>+        * alert in order to break the imap_idle() out of its wait.
>>+        */
>>+       if (!has_idle && stage == STAGE_IDLE)
>>+       {
>>+           mytimeout = saved_timeout;
>>+           stage = STAGE_FETCH;
>>+       }
>>        }
>>        else if (strstr(buf, " EXPUNGE"))
>>        {
>>    
>>
>
>This looks acceptable.
>
>How can a server mark a new message "RECENT" without also sending an
>"EXISTS"? I'm inclined to consider such behavior broken. I'm willing to
>apply this nonetheless as I don't think it would hurt anyone.
>
>  
>
It cannot, but the order it does them depends on the server; and also 
the server may send an EXISTS message without a RECENT message if a 
message is expunged.  the 'recentcount' is what is used to break us out 
of one of the loops; see my explanation to Casper.

Brendan

[fetchmail-users] [PATCH] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Sunil S. <sh...@bo...>]

Quoting from Brendan Lynch's mail on Thu, Mar 02, 2006:
> However I believe the servers is behaving correctly according to the 
> IMAP spec: I have attached an explanation of the secondary problem I am 
> seeing (extra 28 s wait) that I sent to Casper; let me know if you need 
> more info.

Yes, I have now read RFC 3501 section 5.3. This behaviour is correct.

> The key point is that the imap_idle() code when 'faking' IDLE support 
> calls imap_ok() (at line 637) without having issued any tagged command:

...

> Since there is no tagged command outstanding the server will not (and 
> should not) ever send a tagged response.  If we set imap_ok to only 
> return after a tagged response we are guaranteeing it will always only 
> return after a timeout.

...

> This again first does a gen_transact() which results in sending "A0130 
> NOOP" at 17:00:49.  A "RECENT" update is already on its way form the 
> server, so we receive it before the "A0130 NOOP completed" at 17:00:49.  
> In imap_ok() we first process the "* 1 RECENT" notification at line 117, 
> setting recentcount, then (since we ARE waiting a tag) loop and process 
> the NOOP ok.  we then return to gen_transact(), which in turn returns to 
> imap_idle().
> 
> Since setting "recentcount" does not also change the stage, we fail the 
> test at line 633 of imap_idle() and continue to do an extra imap_ok() 
> which sets a 28 second timer at 17:00:49 and does a recv() which times 
> out at 17:01:17.  We then return from imap_idle() to imap_getrange() 
> line 679.  At this point recentcount is set and we exit the "while 
> (recentcount == 0 && do_idle)" loop.
> 
> The wait between 17:00:49 and 17:01:17 was unnecessary, as already had 
> our RECENT notification.  The second part of my fix causes imap_ok() to 
> change the stage to STAGE_FETCH on receipt of a RECENT notification, 
> just as it already did on receipt of a EXISTS notification. This causes 
> the if condition "if (ok != 0 || stage != STAGE_IDLE)" to be met at line 
> 633 of imap_idle() so it immediately exits and does not do the extra 
> unneeded imap_ok() call.

Yes, you have diagnosed the problem correctly and your patch is also
correct. Based on your patch, I have prepared a new patch which does
not modify imap_ok(), but cleans up the code in imap_idle(). Could you
test this patch and see if this patch is acceptable to you? This patch
is identical to the patch I had sent to Casper Gripenberg, except that
comments relating to compliance with RFCs have been updated.

-- 
Sunil Shetye.

[fetchmail-users] Re: [PATCH] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Brendan L. <bre...@ai...>]

Your patch works too.  I cannot say the code is clearer than my fix, but 
you are no doubt a lot more familiar with this code than I am.  The key 
fix (beyond not waiting for a tagged response when no tagged command had 
been issued) in your fix is at line 595, where you do not attempt to 
enter the pseudo-idle wait if a RECENT message has been received 
(recentcount != 0).

Thanks,

Brendan

sh...@bo... wrote:

>Quoting from Brendan Lynch's mail on Thu, Mar 02, 2006:
>  
>
>>However I believe the servers is behaving correctly according to the 
>>IMAP spec: I have attached an explanation of the secondary problem I am 
>>seeing (extra 28 s wait) that I sent to Casper; let me know if you need 
>>more info.
>>    
>>
>
>Yes, I have now read RFC 3501 section 5.3. This behaviour is correct.
>
>  
>
>>The key point is that the imap_idle() code when 'faking' IDLE support 
>>calls imap_ok() (at line 637) without having issued any tagged command:
>>    
>>
>
>...
>
>  
>
>>Since there is no tagged command outstanding the server will not (and 
>>should not) ever send a tagged response.  If we set imap_ok to only 
>>return after a tagged response we are guaranteeing it will always only 
>>return after a timeout.
>>    
>>
>
>...
>
>  
>
>>This again first does a gen_transact() which results in sending "A0130 
>>NOOP" at 17:00:49.  A "RECENT" update is already on its way form the 
>>server, so we receive it before the "A0130 NOOP completed" at 17:00:49.  
>>In imap_ok() we first process the "* 1 RECENT" notification at line 117, 
>>setting recentcount, then (since we ARE waiting a tag) loop and process 
>>the NOOP ok.  we then return to gen_transact(), which in turn returns to 
>>imap_idle().
>>
>>Since setting "recentcount" does not also change the stage, we fail the 
>>test at line 633 of imap_idle() and continue to do an extra imap_ok() 
>>which sets a 28 second timer at 17:00:49 and does a recv() which times 
>>out at 17:01:17.  We then return from imap_idle() to imap_getrange() 
>>line 679.  At this point recentcount is set and we exit the "while 
>>(recentcount == 0 && do_idle)" loop.
>>
>>The wait between 17:00:49 and 17:01:17 was unnecessary, as already had 
>>our RECENT notification.  The second part of my fix causes imap_ok() to 
>>change the stage to STAGE_FETCH on receipt of a RECENT notification, 
>>just as it already did on receipt of a EXISTS notification. This causes 
>>the if condition "if (ok != 0 || stage != STAGE_IDLE)" to be met at line 
>>633 of imap_idle() so it immediately exits and does not do the extra 
>>unneeded imap_ok() call.
>>    
>>
>
>Yes, you have diagnosed the problem correctly and your patch is also
>correct. Based on your patch, I have prepared a new patch which does
>not modify imap_ok(), but cleans up the code in imap_idle(). Could you
>test this patch and see if this patch is acceptable to you? This patch
>is identical to the patch I had sent to Casper Gripenberg, except that
>comments relating to compliance with RFCs have been updated.
>
>  
>
>------------------------------------------------------------------------
>
>Index: fetchmail-6.3/imap.c
>===================================================================
>--- fetchmail-6.3/imap.c   (revision 4705)
>+++ fetchmail-6.3/imap.c   (working copy)
>@@ -621,7 +621,6 @@
> {
>     int ok;
> 
>-    stage = STAGE_IDLE;
>     saved_timeout = mytimeout;
> 
>     if (has_idle) {
>@@ -629,6 +628,7 @@
>    * at least every 28 minutes:
>    * (the server may have an inactivity timeout) */
>   mytimeout = 1680; /* 28 min */
>+  stage = STAGE_IDLE;
>   /* enter IDLE mode */
>   ok = gen_transact(sock, "IDLE");
> 
>@@ -637,37 +637,43 @@
>       SockWrite(sock, "DONE\r\n", 6);
>       if (outlevel >= O_MONITOR)
>       report(stdout, "IMAP> DONE\n");
>-  } else
>-      /* not idle timeout */
>-      return ok;
>+      /* reset stage and timeout here: we are not idling any more */
>+      mytimeout = saved_timeout;
>+      stage = STAGE_FETCH;
>+      /* get OK IDLE message */
>+      ok = imap_ok(sock, NULL);
>+  }
>     } else {  /* no idle support, fake it */
>-  /* when faking an idle, we can't assume the server will
>-   * send us the new messages out of the blue (RFC2060);
>-   * this timeout is potentially the delay before we notice
>-   * new mail (can be small since NOOP checking is cheap) */
>-  mytimeout = 28;
>+  /* Note: stage and timeout have not been changed here as NOOP
>+   * does not idle */
>   ok = gen_transact(sock, "NOOP");
>-  /* if there's an error (not likely) or we just found mail (stage 
>-   * has changed, timeout has also been restored), we're done */
>-  if (ok != 0 || stage != STAGE_IDLE)
>-      return(ok);
> 
>-  /* wait (briefly) for an unsolicited status update */
>-  ok = imap_ok(sock, NULL);
>-  /* again, this is new mail or an error */
>-  if (ok != PS_IDLETIMEOUT)
>-      return(ok);
>+  /* no error, but no new mail either */
>+  if (ok == PS_SUCCESS && recentcount == 0)
>+  {
>+      /* There are some servers who do send new mail
>+       * notification out of the blue. This is in compliance
>+       * with RFC 2060 section 5.3. Wait for that with a low
>+       * timeout */
>+      mytimeout = 28;
>+      stage = STAGE_IDLE;
>+      /* We are waiting for notification; no tag needed */
>+      tag[0] = '\0';
>+      /* wait (briefly) for an unsolicited status update */
>+      ok = imap_ok(sock, NULL);
>+      if (ok == PS_IDLETIMEOUT) {
>+      /* no notification came; ok */
>+      ok = PS_SUCCESS;
>+      }
>+  }
>     }
> 
>     /* restore normal timeout value */
>+    set_timeout(0);
>     mytimeout = saved_timeout;
>     stage = STAGE_FETCH;
> 
>-    /* get OK IDLE message */
>-    if (has_idle)
>-        return imap_ok(sock, NULL);
>-
>-    return PS_SUCCESS;
>+    return(ok);
> }
> 
> static int imap_getrange(int sock, 
>  
>

Re: [fetchmail-users] [PATCH] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Matthias A. <mat...@gm...>]

I've committed the patch. One thing makes me wonder though:

fetchmail: IMAP> A0004 NOOP
fetchmail: IMAP< A0004 OK NOOP completed.
fetchmail: IMAP> A0005 NOOP
fetchmail: IMAP< * 1 EXISTS
fetchmail: IMAP< * 1 RECENT
fetchmail: IMAP< A0005 OK NOOP completed.
fetchmail: IMAP> A0006 EXPUNGE
fetchmail: IMAP< A0006 OK Expunge completed.

Why does fetchmail perform an EXPUNGE after NOOP?
Accident or intent?

-- 
Matthias Andree

[fetchmail-users] [PATCH-2] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Sunil S. <sh...@bo...>]

Quoting from Matthias Andree's mail on Fri, Mar 10, 2006:
> I've committed the patch. One thing makes me wonder though:
> 
> fetchmail: IMAP> A0004 NOOP
> fetchmail: IMAP< A0004 OK NOOP completed.
> fetchmail: IMAP> A0005 NOOP
> fetchmail: IMAP< * 1 EXISTS
> fetchmail: IMAP< * 1 RECENT
> fetchmail: IMAP< A0005 OK NOOP completed.
> fetchmail: IMAP> A0006 EXPUNGE
> fetchmail: IMAP< A0006 OK Expunge completed.
> 
> Why does fetchmail perform an EXPUNGE after NOOP?
> Accident or intent?

Looks like an accident.

The original intention is to do an EXPUNGE immediately after SELECT.
In this case, since no mails were found after SELECT, the EXPUNGE was
sent after the NOOP(s). This EXPUNGE after NOOP is pointless and
confusing. This patch should remove this.

======================================================================
Index: fetchmail-6.3/imap.c
===================================================================
--- fetchmail-6.3/imap.c	(revision 4730)
+++ fetchmail-6.3/imap.c	(working copy)
@@ -737,16 +737,6 @@
 				    "%d messages waiting after first poll\n",
 				    count), count);
 
-	/* no messages?  then we may need to idle until we get some */
-	while (count == 0 && do_idle) {
-	    ok = imap_idle(sock);
-	    if (ok)
-	    {
-		report(stderr, GT_("re-poll failed\n"));
-		return(ok);
-	    }
-	}
-
 	/*
 	 * We should have an expunge here to
 	 * a) avoid fetching deleted mails during 'fetchall'
@@ -765,6 +755,23 @@
 					"%d messages waiting after expunge\n",
 					count), count);
 	}
+
+	if (count == 0 && do_idle)
+	{
+	    /* no messages?  then we may need to idle until we get some */
+	    while (count == 0) {
+		ok = imap_idle(sock);
+		if (ok)
+		{
+		    report(stderr, GT_("re-poll failed\n"));
+		    return(ok);
+		}
+	    }
+	    if (outlevel >= O_DEBUG)
+		report(stdout, ngettext("%d message waiting after re-poll\n",
+					"%d messages waiting after re-poll\n",
+					count), count);
+	}
     }
 
     *countp = count;
======================================================================

-- 
Sunil Shetye.

Re: [fetchmail-users] [PATCH-2] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Matthias A. <mat...@gm...>]

Sunil Shetye <sh...@bo...> writes:

> Looks like an accident.
>
> The original intention is to do an EXPUNGE immediately after SELECT.
> In this case, since no mails were found after SELECT, the EXPUNGE was
> sent after the NOOP(s). This EXPUNGE after NOOP is pointless and
> confusing. This patch should remove this.

Thanks, merged.

-- 
Matthias Andree

Re: [fetchmail-users] [PATCH] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Brendan L. <bre...@ai...>]

That seem to be intentional first-pass behaviour (i.e. not really the 
general Idle polling case).  Look at these lines from imap_getrange():

    732          * We should have an expunge here to
    733          * a) avoid fetching deleted mails during 'fetchall'
    734          * b) getting a wrong count of mails during 'no fetchall'
    735          */
    736         if (!check_only && !ctl->keep && count > 0)
    737         {
    738             ok = internal_expunge(sock);
    739             if (ok)

This generates the EXPUNGE you see.  However this only happens for the 
first message, since this is the "else" case of the if statement:

    672     if (pass > 1)
    673     {
    674         /* deleted mails have already been expunged by
    675          * end_mailbox_poll().

and will only be taken before the first message has been seen. After the 
first message has been seen no EXPUNGE is sent (and the comment suggests 
why the code does not do an EXPUNGE in this case).

A trace shows exactly this behaviour:

First time:

    18:00:55 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:00:55 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={28, 0}}, NULL) = 0
    18:00:55 recv(4, 0xbfea66fb, 8192, MSG_PEEK) = ? ERESTARTSYS (To be
    restarted)
    18:01:23 --- SIGALRM (Alarm clock) @ 0 (0) ---
    18:01:23 sigreturn()                    = ? (mask now [])
    18:01:23 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:01:23 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={0, 0}}, NULL) = 0
    18:01:23 write(4, "A0013 NOOP\r\n", 12) = 12
    18:01:23 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={300,
    0}}, NULL) = 0
    18:01:23 recv(4, "A0013 OK NOOP completed\r\n", 8192, MSG_PEEK) = 25
    18:01:23 read(4, "A0013 OK NOOP completed\r\n", 25) = 25
    18:01:23 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:01:23 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={28, 0}}, NULL) = 0
    18:01:23 recv(4, "* 1 EXISTS\r\n", 8192, MSG_PEEK) = 12
    18:01:47 read(4, "* 1 EXISTS\r\n", 12)  = 12
    18:01:47 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:01:47 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={0, 0}}, NULL) = 0
    18:01:47 write(4, "A0014 EXPUNGE\r\n", 15) = 15
    18:01:47 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={300,
    0}}, NULL) = 0
    18:01:47 recv(4, "* 1 RECENT\r\nA0014 OK EXPUNGE completed\r\n",
    8192, MSG_PEEK) = 40
    18:01:47 read(4, "* 1 RECENT\r\n", 12)  = 12
    18:01:47 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:01:47 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={300, 0}}, NULL) = 0
    18:01:47 recv(4, "A0014 OK EXPUNGE completed\r\n", 8192, MSG_PEEK) = 28
    18:01:47 read(4, "A0014 OK EXPUNGE completed\r\n", 28) = 2818:01:47
    setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
    18:01:47 write(4, "A0015 FETCH 1 RFC822.SIZE\r\n", 27) = 27
    18:01:47 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={300,
    0}}, NULL) = 0
    18:01:47 recv(4, "* 1 FETCH (RFC822.SIZE 7640)\r\n", 8192, MSG_PEEK)
    = 30

Later times:

    18:03:12 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={28,
    0}}, NULL) = 0
    18:03:12 recv(4, 0xbfea66fb, 8192, MSG_PEEK) = ? ERESTARTSYS (To be
    restarted)
    18:03:40 --- SIGALRM (Alarm clock) @ 0 (0) ---
    18:03:40 sigreturn()                    = ? (mask now [])
    18:03:40 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:03:40 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={0, 0}}, NULL) = 0 18:03:40 write(4, "A0024 NOOP\r\n", 12) = 12
    18:03:40 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={300,
    0}}, NULL) = 0
    18:03:40 recv(4, "A0024 OK NOOP completed\r\n", 8192, MSG_PEEK) = 25
    18:03:40 read(4, "A0024 OK NOOP completed\r\n", 25) = 25
    18:03:40 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:03:40 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={28, 0}}, NULL) = 0
    18:03:40 recv(4, "* 1 EXISTS\r\n", 8192, MSG_PEEK) = 12
    18:03:49 read(4, "* 1 EXISTS\r\n", 12)  = 12
    18:03:49 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:03:49 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={0, 0}}, NULL) = 018:03:49 write(4, "A0025 NOOP\r\n", 12) = 12
    18:03:49 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={300,
    0}}, NULL) = 0
    18:03:49 recv(4, "* 1 RECENT\r\nA0025 OK NOOP completed\r\n", 8192,
    MSG_PEEK) = 37
    18:03:49 read(4, "* 1 RECENT\r\n", 12)  = 12
    18:03:49 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:03:49 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={300, 0}}, NULL) = 0
    18:03:49 recv(4, "A0025 OK NOOP completed\r\n", 8192, MSG_PEEK) = 25
    18:03:49 read(4, "A0025 OK NOOP completed\r\n", 25) = 25
    18:03:49 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0,
    0}}, NULL) = 018:03:49 setitimer(ITIMER_REAL, {it_interval={0, 0},
    it_value={0, 0}}, NULL) = 018:03:49 write(4, "A0026 FETCH 1
    RFC822.SIZE\r\n", 27) = 27

After the first RECEIVE further RECEIVES are followed by a FETCH without 
intervening EXPUNGE.

Brendan

mat...@gm... wrote:

>I've committed the patch. One thing makes me wonder though:
>
>fetchmail: IMAP> A0004 NOOP
>fetchmail: IMAP< A0004 OK NOOP completed.
>fetchmail: IMAP> A0005 NOOP
>fetchmail: IMAP< * 1 EXISTS
>fetchmail: IMAP< * 1 RECENT
>fetchmail: IMAP< A0005 OK NOOP completed.
>fetchmail: IMAP> A0006 EXPUNGE
>fetchmail: IMAP< A0006 OK Expunge completed.
>
>Why does fetchmail perform an EXPUNGE after NOOP?
>Accident or intent?
>
>  
>

Re: [fetchmail-users] [PATCH] Re: Bug in imap_idle() with mail servers not supporting "idle"

[Matthias A. <mat...@gm...>]

Brendan Lynch <bre...@ai...> writes:

> That seem to be intentional first-pass behaviour (i.e. not really the general
> Idle polling case).  Look at these lines from imap_getrange():
>
>     732          * We should have an expunge here to
>     733          * a) avoid fetching deleted mails during 'fetchall'
>     734          * b) getting a wrong count of mails during 'no fetchall'
>     735          */
>     736         if (!check_only && !ctl->keep && count > 0)
>     737         {
>     738             ok = internal_expunge(sock);
>     739             if (ok)
>
> This generates the EXPUNGE you see.  However this only happens for the first
> message, since this is the "else" case of the if statement:
>
>     672     if (pass > 1)
>     673     {
>     674         /* deleted mails have already been expunged by
>     675          * end_mailbox_poll().
>
> and will only be taken before the first message has been seen. After the first
> message has been seen no EXPUNGE is sent (and the comment suggests why the
> code does not do an EXPUNGE in this case).

Well, yes, but I think it's pointless to run EXPUNGE in this particular
context. We might only expunge the deletions of another process, and
that's probably not what fetchmail should be doing.

I'll probably merge Sunil's patch tomorrow.

-- 
Matthias Andree