[Dovecot] dovecot 1.1alpha6 deliver+quota bugs

[Andrew Garner]

I was playing around with dovecot-1.1 and maildir++ quotas, and ran
into a reproducible error with indexing.    This only seems to be a
problem for new maildirs.   If I send a message without the quota
plugin on, and  "seed" the index/control files, future deliveries with
the quota plugin seem to succeed without errors.


Version: 1.1alpha6
OS: Debian etch/x86 (ext3 filesystem)


# dovecot -n
# 1.1.alpha6: /etc/dovecot/dovecot.conf
login_dir: /var/run/dovecot/login
login_executable: /usr/lib/dovecot/imap-login
mail_location: maildir:~/Maildir
mail_debug: yes
mmap_disable: yes
lock_method: dotlock
mail_executable: /usr/lib/dovecot/gdbhelper /usr/lib/dovecot/imap
mail_plugins: quota imap_quota
auth default:
  verbose: yes
  debug: yes
  debug_passwords: yes
  passdb:
    driver: sql
    args: /etc/dovecot/dovecot-sql.conf
  userdb:
    driver: sql
    args: /etc/dovecot/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: 384
      user: vmail
      group: vmail
plugin:
  quota: maildir
  quota_rule: *:storage=102400

Here's the deliver-log from a "fresh" Maildir (just ~/Maildir/{cur,new,tmp}):

deliver(example at example.com): Sep 21 18:39:48 Info: Loading modules
from directory: /usr/lib/dovecot/modules/lda
deliver(example at example.com): Sep 21 18:39:48 Info: Module loaded:
/usr/lib/dovecot/modules/lda/lib10_quota_plugin.so
deliver(example at example.com): Sep 21 18:39:48 Info: auth input:
example at example.com
deliver(example at example.com): Sep 21 18:39:48 Info: auth input:
home=/home/vmail/domains/example.com/example
deliver(example at example.com): Sep 21 18:39:48 Info: auth input: uid=1014
deliver(example at example.com): Sep 21 18:39:48 Info: auth input: gid=1014
deliver(example at example.com): Sep 21 18:39:48 Info: Quota rule: root=
mailbox= storage=102400kB messages=0
deliver(example at example.com): Sep 21 18:39:48 Info: maildir:
data=/home/vmail/domains/example.com/example/Maildir
deliver(example at example.com): Sep 21 18:39:48 Info: maildir++:
root=/home/vmail/domains/example.com/example/Maildir, index=,
control=, inbox=/home/vmail/domains/example.com/ex
ample/Maildir
deliver(example at example.com): Sep 21 18:39:48 Error: uid_validity
mismatch in file
/home/vmail/domains/example.com/example/Maildir/dovecot.list.index.uidmap:
1190399988 != 0
deliver(example at example.com): Sep 21 18:39:48 Error: Corrupted mailbox
list index file
/home/vmail/domains/example.com/example/Maildir/dovecot.list.index.uidmap:
dir_size is s
maller than record count
deliver(example at example.com): Sep 21 18:39:48 Error: Internal quota
calculation error
deliver(example at example.com): Sep 21 18:39:48 Info:
msgid=<1989.0003.0000 at server011>: save failed to INBOX: Internal error
occurred. Refer to server log for more information.
[2007-09-21 18:39:48]

Turning off the quota plugin will allow the delivery to succeed:

deliver(example at example.com): Sep 21 18:42:08 Info: auth input:
example at example.com
deliver(example at example.com): Sep 21 18:42:08 Info: auth input:
home=/home/vmail/domains/example.com/example
deliver(example at example.com): Sep 21 18:42:08 Info: auth input: uid=1014
deliver(example at example.com): Sep 21 18:42:08 Info: auth input: gid=1014
deliver(example at example.com): Sep 21 18:42:08 Info: maildir:
data=/home/vmail/domains/example.com/example/Maildir
deliver(example at example.com): Sep 21 18:42:08 Info: maildir++:
root=/home/vmail/domains/example.com/example/Maildir, index=,
control=, inbox=/home/vmail/domains/example.com/ex
ample/Maildir
deliver(example at example.com): Sep 21 18:42:08 Info:
msgid=<1989.0003.0000 at server011>: saved mail to INBOX

Turning quota back on has a temporary complaint about uidvalidity:

deliver(example at example.com): Sep 21 18:44:17 Info: Loading modules
from directory: /usr/lib/dovecot/modules/lda
deliver(example at example.com): Sep 21 18:44:17 Info: Module loaded:
/usr/lib/dovecot/modules/lda/lib10_quota_plugin.so
deliver(example at example.com): Sep 21 18:44:17 Info: auth input:
example at example.com
deliver(example at example.com): Sep 21 18:44:17 Info: auth input:
home=/home/vmail/domains/example.com/example
deliver(example at example.com): Sep 21 18:44:17 Info: auth input: uid=1014
deliver(example at example.com): Sep 21 18:44:17 Info: auth input: gid=1014
deliver(example at example.com): Sep 21 18:44:17 Info: Quota rule: root=
mailbox= storage=102400kB messages=0
deliver(example at example.com): Sep 21 18:44:17 Info: maildir:
data=/home/vmail/domains/example.com/example/Maildir
deliver(example at example.com): Sep 21 18:44:17 Info: maildir++:
root=/home/vmail/domains/example.com/example/Maildir, index=,
control=, inbox=/home/vmail/domains/example.com/ex
ample/Maildir
deliver(example at example.com): Sep 21 18:44:17 Error: uid_validity
mismatch in file
/home/vmail/domains/example.com/example/Maildir/dovecot.list.index.uidmap:
1190400128 != 119
0400088
deliver(example at example.com): Sep 21 18:44:17 Warning:
/home/vmail/domains/example.com/example/Maildir/dovecot.list.index:
Desync: uid_validity changed 1190400088 -> 119040012
8
deliver(example at example.com): Sep 21 18:44:17 Info:
msgid=<1e2f.0003.0000 at server011>: saved mail to INBOX

But then it's pretty happy:

deliver(example at example.com): Sep 21 18:45:36 Info: Loading modules
from directory: /usr/lib/dovecot/modules/lda
deliver(example at example.com): Sep 21 18:45:36 Info: Module loaded:
/usr/lib/dovecot/modules/lda/lib10_quota_plugin.so
deliver(example at example.com): Sep 21 18:45:36 Info: auth input:
example at example.com
deliver(example at example.com): Sep 21 18:45:36 Info: auth input:
home=/home/vmail/domains/example.com/example
deliver(example at example.com): Sep 21 18:45:36 Info: auth input: uid=1014
deliver(example at example.com): Sep 21 18:45:36 Info: auth input: gid=1014
deliver(example at example.com): Sep 21 18:45:36 Info: Quota rule:
root=mailbox= storage=102400kB messages=0
deliver(example at example.com): Sep 21 18:45:36 Info: maildir:
data=/home/vmail/domains/example.com/example/Maildir
deliver(example at example.com): Sep 21 18:45:36 Info: maildir++:
root=/home/vmail/domains/example.com/example/Maildir, index=,
control=, inbox=/home/vmail/domains/example.com/example/Maildir
deliver(example at example.com): Sep 21 18:45:36 Info:
msgid=<1e42.0003.0000 at server011>: saved mail to INBOX

But once I hit the quota limit, I get an assertion failure:

deliver(example at example.com): Sep 21 18:57:12 Info: Loading modules
from directory: /usr/lib/dovecot/modules/lda
deliver(example at example.com): Sep 21 18:57:12 Info: Module loaded:
/usr/lib/dovecot/modules/lda/lib10_quota_plugin.so
deliver(example at example.com): Sep 21 18:57:12 Info: auth input:
example at example.com
deliver(example at example.com): Sep 21 18:57:12 Info: auth input:
home=/home/vmail/domains/example.com/example
deliver(example at example.com): Sep 21 18:57:12 Info: auth input: uid=1014
deliver(example at example.com): Sep 21 18:57:12 Info: auth input: gid=1014
deliver(example at example.com): Sep 21 18:57:12 Info: Quota rule: root=
mailbox= storage=102400kB messages=0
deliver(example at example.com): Sep 21 18:57:12 Info: maildir:
data=/home/vmail/domains/example.com/example/Maildir
deliver(example at example.com): Sep 21 18:57:12 Info: maildir++:
root=/home/vmail/domains/example.com/example/Maildir, index=,
control=, inbox=/home/vmail/domains/example.com/example/Maildir
deliver(example at example.com): Sep 21 18:57:13 Info:
msgid=<1ed0.0003.0000 at server011>: save failed to INBOX: Quota exceeded
deliver(example at example.com): Sep 21 18:57:13 Info:
msgid=<1ed0.0003.0000 at server011>: Rejected: Quota exceeded
deliver(example at example.com): Sep 21 18:57:13 Panic: file
index-mail-headers.c: line 590 (index_mail_get_raw_headers): assertion
failed: (ret != -1)
deliver(example at example.com): Sep 21 18:57:13 Error: Raw backtrace:
/usr/lib/dovecot/deliver [0x80d3165] ->
/usr/lib/dovecot/deliver(i_fatal+0) [0x80d33ac] -> /usr/lib/dovecot
/deliver [0x8091eb1] ->
/usr/lib/dovecot/deliver(index_mail_get_first_header+0x2b) [0x8092258]
-> /usr/lib/dovecot/deliver(mail_get_first_header+0x30) [0x80be839] ->
/usr/lib/
dovecot/deliver(deliver_get_return_address+0x23) [0x8058f9a] ->
/usr/lib/dovecot/deliver(mail_send_rejection+0x36) [0x805b428] ->
/usr/lib/dovecot/deliver(main+0xb53) [0x805a9eb] ->
/lib/tls/i686/cmov/libc.so.6(__libc_start_main+0xc8) [0xb7e40ea8] ->
/usr/lib/dovecot/deliver [0x8058241]