[Dovecot] Wrong message information reported shortly after delivery

[Ron Avriel]

Hi,

If an IMAP fetch is issued some "short" time after a message was delivered
with dovecot deliver then dovecot reports wrong (zero) values
for that new message. Afterward, it reports the information OK.

This causes problems to our IMAP client.
The problem is easily reproduced with a large message on a slow machine.
I'm using dovecot 1.0.10

Here's a sample trace:

1 uid fetch 1:* fast
* 1 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:20:50 +0200" RFC822.SIZE 3378380 UID 1)
* 2 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:21:40 +0200" RFC822.SIZE 3378380 UID 2)
* 3 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:23:38 +0200" RFC822.SIZE 3378380 UID 3)
* 4 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:40:06 +0200" RFC822.SIZE 3378380 UID 4)
1 OK Fetch completed.

######## Here dovecot reports a new message (5) arrived ########
1 uid fetch 1:* fast
* 1 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:20:50 +0200" RFC822.SIZE 3378380 UID 1)
* 2 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:21:40 +0200" RFC822.SIZE 3378380 UID 2)
* 3 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:23:38 +0200" RFC822.SIZE 3378380 UID 3)
* 4 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:40:06 +0200" RFC822.SIZE 3378380 UID 4)
* 5 EXISTS
* 5 RECENT
1 OK Fetch completed.

######## This is where dovecot reports wrong information about message 5 ########
1 uid fetch 1:* fast
* 1 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:20:50 +0200" RFC822.SIZE 3378380 UID 1)
* 2 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:21:40 +0200" RFC822.SIZE 3378380 UID 2)
* 3 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:23:38 +0200" RFC822.SIZE 3378380 UID 3)
* 4 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:40:06 +0200" RFC822.SIZE 3378380 UID 4)
* 5 FETCH (FLAGS (\Recent) INTERNALDATE "01-Jan-1970 00:00:00 +0000" RFC822.SIZE 0 UID 5)
1 OK Fetch completed.

######## The same wrong information is repeated ########
1 uid fetch 1:* fast
* 1 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:20:50 +0200" RFC822.SIZE 3378380 UID 1)
* 2 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:21:40 +0200" RFC822.SIZE 3378380 UID 2)
* 3 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:23:38 +0200" RFC822.SIZE 3378380 UID 3)
* 4 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:40:06 +0200" RFC822.SIZE 3378380 UID 4)
* 5 FETCH (FLAGS (\Recent) INTERNALDATE "01-Jan-1970 00:00:00 +0000" RFC822.SIZE 0 UID 5)
1 OK Fetch completed.

######## The same wrong information is repeated several times ########
1 uid fetch 1:* fast
* 1 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:20:50 +0200" RFC822.SIZE 3378380 UID 1)
* 2 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:21:40 +0200" RFC822.SIZE 3378380 UID 2)
* 3 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:23:38 +0200" RFC822.SIZE 3378380 UID 3)
* 4 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:40:06 +0200" RFC822.SIZE 3378380 UID 4)
* 5 FETCH (FLAGS (\Recent) INTERNALDATE "01-Jan-1970 00:00:00 +0000" RFC822.SIZE 0 UID 5)
1 OK Fetch completed.

######## Trace truncated here ########

######## Finally, correct information is reported ########
1 uid fetch 1:* fast
* 1 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:20:50 +0200" RFC822.SIZE 3378380 UID 1)
* 2 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:21:40 +0200" RFC822.SIZE 3378380 UID 2)
* 3 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:23:38 +0200" RFC822.SIZE 3378380 UID 3)
* 4 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:40:06 +0200" RFC822.SIZE 3378380 UID 4)
* 5 FETCH (FLAGS (\Recent) INTERNALDATE "06-Mar-2008 17:41:07 +0200" RFC822.SIZE 3378380 UID 5)


dovecot -n:
# 1.0.10: /etc/dovecot.conf
log_timestamp: “%Y-%m-%d %H:%M:%S ”
protocols: imap
listen: *:143
ssl_disable: yes
login_dir: /var/run/dovecot/login
login_executable: /usr/libexec/dovecot/imap-login
login_process_per_connection: no
first_valid_uid: 150
last_valid_uid: 150
dotlock_use_excl: yes
fsync_disable: yes
maildir_copy_with_hardlinks: yes
maildir_copy_preserve_filename: yes
mail_plugins: quota imap_quota
auth default:
  mechanisms: plain login
  user: nobody
  master_user_separator: *
  passdb:
    driver: sql
    args: /etc/dovecot-sql.conf
  passdb:
    driver: passwd-file
    args: /etc/dovecot.masterusers
    master: yes
  userdb:
    driver: prefetch
  userdb:
    driver: sql
    args: /etc/dovecot-sql.conf
  socket:
    type: listen
    client:
      path: /var/spool/postfix/private/auth
      mode: 432
      user: postfix
      group: postfix
    master:
      path: /var/run/dovecot/auth-master
      mode: 432
      user: vmail
      group: mail
plugin:
  quota: maildir:storage=1024


Thanks,
Ron





      ____________________________________________________________________________________
Never miss a thing.  Make Yahoo your home page. 
http://www.yahoo.com/r/hs