[Dovecot] 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-----
On Mon, 25 Jun 2007, Robert Schetterer wrote:
Hi Julian, i might fail ,but it looks like that there are problems on the clients side with idle http://wiki.dovecot.org/Clients
Thanks, that is a useful link. I don't see Apple Mail listed there, but that's not to say that there aren't any issues.
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 )
Not sure what problems you had with it. Apple Mail hasn't been much of a problem for me other than a few minor annoying behaviors. Of course, I haven't been looking at it from the server's point of view until now. The problem I described appears to be on Dovecot's end, though.
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..
On Wed, 2007-06-27 at 14:46 +0300, Timo Sirainen wrote:
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..
Looks like the connection should have been disconnected. Fixed: http://hg.dovecot.org/dovecot-1.0/rev/111275296af5
On Wed, 27 Jun 2007, Timo Sirainen wrote:
On Wed, 2007-06-27 at 14:46 +0300, Timo Sirainen wrote:
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..
Looks like the connection should have been disconnected. Fixed: http://hg.dovecot.org/dovecot-1.0/rev/111275296af5
Looks like this has fixed the problem. I've been connected using IDLE mode for most of the day here, and I haven't seen it get into a situation where it stops sending notifications.
In addition, it does indeed disconnect after about 30 minutes -- something that I vaguely noticed it wasn't doing before. Now that I think about it, the original problem started happening after about 30 minutes into the session. Guess this makes sense as it is all related.
Thanks very much for the fix!
participants (5)
-
Jef Driesen
-
Julian Cowley
-
Julian Cowley
-
Robert Schetterer
-
Timo Sirainen