dovecot - Jun 2007 - IMAP IDLE goes to sleep

First of all, let me say that I'm really impressed with Dovecot.
It is great.

Problem description
==================
Now I've got a possible bug I'd like to report.  I've been learning
about the IMAP protocol recently, and have started playing with the
IDLE command.  The problem is that Dovecot doesn't always notify the
client when there is new mail available.  While notifications work
for the most part, it seems that Dovecot occasionally gets itself
into a rut where it fails to notice any changes to the mailbox (new
messages, flag changes, etc.).  The problem usually becomes apparent
when there is more than one email client accessing the same mailbox.
In fact, this may be a requirement -- I only tested it once, but I
couldn't reproduce the problem when I had only one connection open
to the mailbox (which is in maildir format in my case).

An example is included below.  Any feedback on how to debug this
problem further would be appreciated.

An aside
=======
After I found out about the IDLE command, I looked for implementations.
I ran across this plug-in for Apple Mail (one of my favorite mail
clients):

http://www.rothwell.us/imapidle/index.html

The web page notes that Leopard's Apple Mail may support the IDLE
command natively, which is good news if true.  It would be really
cool if Dovecot's IDLE command can be made robust enough to make this
feature really come alive.

Example
======
This transcript is copied from an SSL connection directly to dovecot
using openssl s_client.  At the same time a separate client (Horde/IMP)
has the same mailbox open:

A0017 IDLE
+ idling
* 7927 FETCH (FLAGS (\Seen \Recent))
* 7927 FETCH (FLAGS (\Deleted \Seen \Recent))
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* 7940 EXISTS
* 22 RECENT
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* OK Still here
* 7941 EXISTS

[At some point after this, something happens (or doesn't happen) and
dovecot no longer notifies of new messages.  The other client is still
reading messages in the same mailbox and new mail is still arriving.]

* OK Still here
* OK Still here
* OK Still here
* OK Still here
* OK Still here

[The above message repeated another 30 times here.  Finally, IDLE
mode is terminated:]

* OK Still here
DONE
* 7941 EXPUNGE
A0017 OK Idle completed.

[Now a NOOP is issued to gather any more untagged responses, and
there's a deluge of responses, presumably all the stuff that happened
while dovecot was asleep.  Notice that the highest message is 7967
whereas the last one heard about was 7941.]

A0018 NOOP
* 7913 FETCH (FLAGS (\Deleted \Recent))
* 7914 FETCH (FLAGS (\Deleted))
* 7915 FETCH (FLAGS (\Deleted))
* 7916 FETCH (FLAGS (\Deleted))
* 7917 FETCH (FLAGS (\Deleted))
* 7918 FETCH (FLAGS (\Deleted))
* 7919 FETCH (FLAGS (\Deleted \Recent))
* 7920 FETCH (FLAGS (\Deleted \Recent))
* 7921 FETCH (FLAGS (\Deleted \Recent))
* 7922 FETCH (FLAGS (\Deleted \Seen))
* 7923 FETCH (FLAGS (\Deleted \Seen))
* 7925 FETCH (FLAGS (\Deleted \Seen))
* 7928 FETCH (FLAGS (\Deleted \Recent))
* 7967 EXISTS
* 30 RECENT
A0018 OK NOOP completed.

Configuration
============
Here are the specifications of the dovecot used in the above test:

version         dovecot 1.0.1
os              linux
distro          centos 4.5
fs              ext3
arch            x86_64
kernel          2.6.9-55.ELsmp
configure       --without inotify --with pam_stack --with forcequota2
cc              gcc (GCC) 3.4.6 20060404 (Red Hat 3.4.6-8)

In addition, I'm using the deliver LDA as the Postfix mailbox_command,
and am using the dovecot-sieve plugin (which is used to set customized
IMAP keywords).

dovecot -n:

# 1.0.1: /etc/dovecot.conf
ssl_cert_file: /usr/lib/courier-imap/share/imapd.pem
ssl_key_file: /usr/lib/courier-imap/share/imapd.pem
login_dir: /var/run/dovecot/login
login_executable(default): /usr/libexec/dovecot/imap-login
login_executable(imap): /usr/libexec/dovecot/imap-login
login_executable(pop3): /usr/libexec/dovecot/pop3-login
first_valid_uid: 100
mail_location: maildir:~/Maildir
maildir_copy_with_hardlinks: yes
mail_executable(default): /usr/libexec/dovecot/imap
mail_executable(imap): /usr/libexec/dovecot/imap
mail_executable(pop3): /usr/libexec/dovecot/pop3
mail_plugin_dir(default): /usr/lib64/dovecot/imap
mail_plugin_dir(imap): /usr/lib64/dovecot/imap
mail_plugin_dir(pop3): /usr/lib64/dovecot/pop3
namespace:
   type: private
   separator: /
   inbox: yes
auth default:
   default_realm: lava.net
   verbose: yes
   passdb:
     driver: sql
     args: /etc/dovecot-sql.conf
   userdb:
     driver: sql
     args: /etc/dovecot-sql.conf

ps. Good thing there's no POP IDLE command!

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Julian Cowley schrieb:
> First of all, let me say that I'm really impressed with Dovecot.
> It is great.
> 
> Problem description
> ==================> 
> Now I've got a possible bug I'd like to report.  I've been
learning
> about the IMAP protocol recently, and have started playing with the
> IDLE command.  The problem is that Dovecot doesn't always notify the
> client when there is new mail available.  While notifications work
> for the most part, it seems that Dovecot occasionally gets itself
> into a rut where it fails to notice any changes to the mailbox (new
> messages, flag changes, etc.).  The problem usually becomes apparent
> when there is more than one email client accessing the same mailbox.
> In fact, this may be a requirement -- I only tested it once, but I
> couldn't reproduce the problem when I had only one connection open
> to the mailbox (which is in maildir format in my case).
> 
> An example is included below.  Any feedback on how to debug this
> problem further would be appreciated.
> 
> An aside
> =======> 
> After I found out about the IDLE command, I looked for implementations.
> I ran across this plug-in for Apple Mail (one of my favorite mail
> clients):
> 
> http://www.rothwell.us/imapidle/index.html
> 
> The web page notes that Leopard's Apple Mail may support the IDLE
> command natively, which is good news if true.  It would be really
> cool if Dovecot's IDLE command can be made robust enough to make this
> feature really come alive.
> 
> Example
> ======> 
> This transcript is copied from an SSL connection directly to dovecot
> using openssl s_client.  At the same time a separate client (Horde/IMP)
> has the same mailbox open:
> 
> A0017 IDLE
> + idling
> * 7927 FETCH (FLAGS (\Seen \Recent))
> * 7927 FETCH (FLAGS (\Deleted \Seen \Recent))
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * 7940 EXISTS
> * 22 RECENT
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * 7941 EXISTS
> 
> [At some point after this, something happens (or doesn't happen) and
> dovecot no longer notifies of new messages.  The other client is still
> reading messages in the same mailbox and new mail is still arriving.]
> 
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> 
> [The above message repeated another 30 times here.  Finally, IDLE
> mode is terminated:]
> 
> * OK Still here
> DONE
> * 7941 EXPUNGE
> A0017 OK Idle completed.
> 
> [Now a NOOP is issued to gather any more untagged responses, and
> there's a deluge of responses, presumably all the stuff that happened
> while dovecot was asleep.  Notice that the highest message is 7967
> whereas the last one heard about was 7941.]
> 
> A0018 NOOP
> * 7913 FETCH (FLAGS (\Deleted \Recent))
> * 7914 FETCH (FLAGS (\Deleted))
> * 7915 FETCH (FLAGS (\Deleted))
> * 7916 FETCH (FLAGS (\Deleted))
> * 7917 FETCH (FLAGS (\Deleted))
> * 7918 FETCH (FLAGS (\Deleted))
> * 7919 FETCH (FLAGS (\Deleted \Recent))
> * 7920 FETCH (FLAGS (\Deleted \Recent))
> * 7921 FETCH (FLAGS (\Deleted \Recent))
> * 7922 FETCH (FLAGS (\Deleted \Seen))
> * 7923 FETCH (FLAGS (\Deleted \Seen))
> * 7925 FETCH (FLAGS (\Deleted \Seen))
> * 7928 FETCH (FLAGS (\Deleted \Recent))
> * 7967 EXISTS
> * 30 RECENT
> A0018 OK NOOP completed.
> 
> Configuration
> ============> 
> Here are the specifications of the dovecot used in the above test:
> 
> version         dovecot 1.0.1
> os              linux
> distro          centos 4.5
> fs              ext3
> arch            x86_64
> kernel          2.6.9-55.ELsmp
> configure       --without inotify --with pam_stack --with forcequota2
> cc              gcc (GCC) 3.4.6 20060404 (Red Hat 3.4.6-8)
> 
> In addition, I'm using the deliver LDA as the Postfix mailbox_command,
> and am using the dovecot-sieve plugin (which is used to set customized
> IMAP keywords).
> 
> dovecot -n:
> 
> # 1.0.1: /etc/dovecot.conf
> ssl_cert_file: /usr/lib/courier-imap/share/imapd.pem
> ssl_key_file: /usr/lib/courier-imap/share/imapd.pem
> login_dir: /var/run/dovecot/login
> login_executable(default): /usr/libexec/dovecot/imap-login
> login_executable(imap): /usr/libexec/dovecot/imap-login
> login_executable(pop3): /usr/libexec/dovecot/pop3-login
> first_valid_uid: 100
> mail_location: maildir:~/Maildir
> maildir_copy_with_hardlinks: yes
> mail_executable(default): /usr/libexec/dovecot/imap
> mail_executable(imap): /usr/libexec/dovecot/imap
> mail_executable(pop3): /usr/libexec/dovecot/pop3
> mail_plugin_dir(default): /usr/lib64/dovecot/imap
> mail_plugin_dir(imap): /usr/lib64/dovecot/imap
> mail_plugin_dir(pop3): /usr/lib64/dovecot/pop3
> namespace:
>   type: private
>   separator: /
>   inbox: yes
> auth default:
>   default_realm: lava.net
>   verbose: yes
>   passdb:
>     driver: sql
>     args: /etc/dovecot-sql.conf
>   userdb:
>     driver: sql
>     args: /etc/dovecot-sql.conf
> 
> ps. Good thing there's no POP IDLE command!
> 
Hi Julian,
i might fail ,but it looks like
that there are problems on the clients side with idle
http://wiki.dovecot.org/Clients
and depending to that , there are workarounds
however i wouldnt recommand apple mail with imap
anyway ,cause it is know for a long history of bugs with imap
courier, cyrus , dovecot
( i dont know if apple has fixed them over the time, but i had a really
bad time with some of my apple mail users in the past )

- --
Mit freundlichen Gruessen
Best Regards

Robert Schetterer

https://www.schetterer.org
Germany
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.5 (GNU/Linux)
Comment: Using GnuPG with SUSE - http://enigmail.mozdev.org

iD8DBQFGf5khfGH2AvR16oERAnkrAJ0cp7x2qhuOl+Eo7kotgUslXOeojQCePZhb
ixro5SzMaAD62GbLfrfG/3g=Hw/R
-----END PGP SIGNATURE-----

Julian Cowley wrote:
> configure       --without inotify
This might be the problem. Without inotify (or one of the other 
systems), dovecot has to poll the mailbox for changes once in a while. 
This means clients will receive updates only after each poll cycle, not 
instantly.

On Sun, 24 Jun 2007, Julian Cowley wrote:
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
>
> [The above message repeated another 30 times here.  Finally, IDLE
> mode is terminated:]
>
> * OK Still here
> DONE
> * 7941 EXPUNGE
> A0017 OK Idle completed.
I think I've found an additional data point on this problem.  Every
time I notice that there hasn't been update in some time, terminating
IDLE mode always results in an EXPUNGE message.  I don't know what is
doing an expunge on a single message (and I'm not doing an expunge in
any of my mail clients).  I can only assume this might have something
to do with Dovecot sieve addflag (this is just a guess), as all of the
messages I've seen so far listed as being expunged instantly reappear
with an explicit or implied EXISTS and have an IMAP flag on them.

Hope this helps.

[Please refer to my original message to see the entire protocol trace.]

ps. I haven't tried a kernel that has inotify yet, but I'll try that
next
and/or turning off any addflag statements in .dovecot.sieve.

On Sun, 2007-06-24 at 23:16 -1000, Julian Cowley wrote:
> * 7941 EXISTS
> 
> [At some point after this, something happens (or doesn't happen) and
> dovecot no longer notifies of new messages.  The other client is still
> reading messages in the same mailbox and new mail is still arriving.]
> 
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> * OK Still here
> 
> [The above message repeated another 30 times here.  Finally, IDLE
> mode is terminated:]
> 
> * OK Still here
> DONE
> * 7941 EXPUNGE
> A0017 OK Idle completed.
This is most likely because of outlook-idle workaround (enabled by
default). When you have been IDLEing for 29 minutes, Dovecot sends a
fake EXISTS reply and when DONE command is given, it sends EXPUNGE for
that fake EXISTS.

I don't understand why you have so many "OK Still here"
notifications
there though. They're sent 2 minutes apart from each others, but between
EXISTS/EXPUNGE there should be max. 1 minute. Wonder if there's a bug in
timeout handling code..

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20070627/b6ddca21/attachment-0002.bin>