[Dovecot] Bug report - crash on group lookup

Peter Meier peter.meier at immerda.ch
Fri May 25 19:52:32 EEST 2012 

Hi

I was doing some migration from a 1.2 installation to a 2.1. While
testing my new installation dovecot crashed at two test-cases constantly
with with a "Panic: Trying to allocate 0 bytes" message.

Both times it was because I was using a wrong group (or none) in my config.

The output I got by dovecot was not that helpful. I only figured it out,
that it has something to do with the group by looking at the code, to
figure out where the stacktrace I got could come from.

Unfortunately, I don't remember one of the examples anymore that
correctly (except that it was also a group configuration related issue).
The other example, was that I was testing the quota warning scripts:

Normal delivery worked fine, but as soon as dovecot should send a quota
warning, after the mail got already delivered, I received said panic.
For the MTA the mail delivery failed (-> bounce), although the LDA
already delivered the mail, but failed in post processing (sending the
quota warning).

My fix was to add:

  unix_listener quota-warning {
    group = mail
    mode = 0660
  }

to the quota warning service. The LDA process has an own user per
mailbox and the mail group.
It looks to me as it would panic by looking up the user of the lda
process, but that's pure guess.

Attached is a debug output and the configuration that triggered the problem.

I see two problems:

1. Don't panic while "looking" up a group
2. Give a meaningful error messages.

If you have any further questions, please let me know.

~pete


==> /var/log/dovecot/debug.log <==
May 25 12:19:50 lda: Debug: Loading modules from directory: /usr/lib/dovecot
May 25 12:19:50 lda: Debug: Module loaded:
/usr/lib/dovecot/lib10_quota_plugin.so
May 25 12:19:50 lda: Debug: Module loaded:
/usr/lib/dovecot/lib90_sieve_plugin.so
May 25 12:19:50 lda: Debug: auth input: dovecot at example.com
home=/var/mail/dovecot at example.com uid=41407 gid=12 quota_rule=*:storage=1M
May 25 12:19:50 lda: Debug: Added userdb setting:
plugin/quota_rule=*:storage=1M
May 25 12:19:50 lda(dovecot at example.com): Debug: Effective uid=41407,
gid=12, home=/var/mail/dovecot at example.com
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota root: name=User
quota backend=maildir args=
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota rule: root=User
quota mailbox=* bytes=1048576 messages=0
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota rule: root=User
quota mailbox=INBOX.Trash bytes=+104857 (10%) messages=0
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota warning:
bytes=996147 (95%) messages=0 reverse=no command=quota-warning 95
dovecot at example.co,
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota warning:
bytes=838860 (80%) messages=0 reverse=no command=quota-warning 80
dovecot at example.com
May 25 12:19:50 lda(dovecot at example.com): Debug: Namespace inbox:
type=private, prefix=INBOX., sep=, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:/var/mail/dovecot at example.com
May 25 12:19:50 lda(dovecot at example.com): Debug: maildir++:
root=/var/mail/dovecot at example.com/mail, index=, control=,
inbox=/var/mail/dovecot at example.com/mail, alt=
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota root: name=User
quota backend=maildir args=
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota rule: root=User
quota mailbox=* bytes=0 messages=0
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota rule: root=User
quota mailbox=INBOX.Trash bytes=0 (10%) messages=0
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota warning: bytes=0
(95%) messages=0 reverse=no command=quota-warning 95 raw mail ur
May 25 12:19:50 lda(dovecot at example.com): Debug: Quota warning: bytes=0
(80%) messages=0 reverse=no command=quota-warning 80 raw mail ur
May 25 12:19:50 lda(dovecot at example.com): Debug: none: root=, index=,
control=, inbox=, alt=
May 25 12:19:50 lda(dovecot at example.com): Debug: Destination address:
dovecot at example.com (source: -a parameter)
May 25 12:19:50 lda(dovecot at example.com): Debug: sieve: user's script
path /var/mail/dovecot at example.com/dovecot.sieve doesn't exist
(usinglobal script path in stead)
May 25 12:19:50 lda(dovecot at example.com): Debug: sieve: using sieve path
for user's script: /var/lib/dovecot-sieve/default.sieve
May 25 12:19:50 lda(dovecot at example.com): Debug: sieve: opening script
/var/lib/dovecot-sieve/default.sieve
May 25 12:19:50 lda(dovecot at example.com): Debug: sieve: script binary
/var/lib/dovecot-sieve/default.svbin successfully loaded
May 25 12:19:50 lda(dovecot at example.com): Debug: sieve: binary save: not
saving binary /var/lib/dovecot-sieve/default.svbin, because its already
stored
May 25 12:19:50 lda(dovecot at example.com): Debug: sieve: executing script
from /var/lib/dovecot-sieve/default.svbin
May 25 12:19:51 lda(dovecot at example.com): Debug: quota: Executing
warning: quota-warning 80 dovecot at example.com

==> /var/log/dovecot/deliver-errors.log <==
May 25 12:19:51 lda(dovecot at example.com): Panic: Trying to allocate 0 bytes
May 25 12:19:51 lda(dovecot at example.com): Error: Raw backtrace:
/usr/lib/dovecot/libdovecot.so.0 [0xbd4e70] -> /usr/lib/dovecot/libdoveco
t.so.0(default_fatal_handler+0x43) [0xbd4f63] ->
/usr/lib/dovecot/libdovecot.so.0 [0xbd4784] ->
/usr/lib/dovecot/libdovecot.so.0 [0xbd
241d] -> /usr/lib/dovecot/libdovecot.so.0(t_malloc0+0x29) [0xbd2619] ->
/usr/lib/dovecot/libdovecot.so.0(restrict_get_groups_list+0x43
) [0xbef183] -> /usr/lib/dovecot/libdovecot.so.0 [0xbd2b39] ->
/usr/lib/dovecot/libdovecot.so.0 [0xbd2dd2] -> /usr/lib/dovecot/libdove
cot.so.0 [0xbd34c6] ->
/usr/lib/dovecot/lib10_quota_plugin.so(quota_transaction_commit+0x5ff)
[0xeeeaff] -> /usr/lib/dovecot/lib10_quo
ta_plugin.so [0xef3f6c] ->
/usr/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_commit_get_changes+0x42)
[0xc922d2] -> /usr/li
b/dovecot/libdovecot-storage.so.0(mailbox_transaction_commit+0x33)
[0xc92323] -> /usr/lib/dovecot/libdovecot-sieve.so.0 [0xd4cfa4] ->
/usr/lib/dovecot/libdovecot-sieve.so.0 [0xd44821] ->
/usr/lib/dovecot/libdovecot-sieve.so.0(sieve_result_execute+0x2d1)
[0xd44b41] ->
/usr/lib/dovecot/libdovecot-sieve.so.0(sieve_execute+0x69) [0xd550f9] ->
/usr/lib/dovecot/lib90_sieve_plugin.so [0x11211c] -> /usr/lib
/dovecot/libdovecot-lda.so.0(mail_deliver+0x4c) [0x843e1c] ->
/usr/libexec/dovecot/deliver(main+0x725) [0x804a185] -> /lib/i686/nosegn
eg/libc.so.6(__libc_start_main+0xdc) [0x65ce9c] ->
/usr/libexec/dovecot/deliver [0x80498c1]


== config
# dovecot -n
# 2.1.6: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.18-238.el5xen i686 CentOS release 5.8 (Final) xfs
debug_log_path = /var/log/dovecot/debug.log
dict {
  expire = sqlite:/etc/dovecot/dovecot-expire.conf.ext
}
disable_plaintext_auth = no
first_valid_gid = 12
first_valid_uid = 40001
info_log_path = /var/log/dovecot/infos.log
lda_mailbox_autocreate = yes
log_path = /var/log/dovecot/error.log
mail_debug = yes
mail_location = maildir:/var/mail/%u/mail
maildir_very_dirty_syncs = yes
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope
encoded-character vacation subaddress comparator-i;ascii-numeric relational
regex imap4flags copy include variables body enotify environment mailbox
date ihave
mbox_write_locks = fcntl
namespace inbox {
  inbox = yes
  location =
  mailbox Drafts {
    special_use = \Drafts
  }
  mailbox Junk {
    special_use = \Junk
  }
  mailbox Sent {
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  prefix = INBOX.
}
passdb {
  args = /usr/libexec/dovecot/checkpassword-bcrypt/checkpassword-bcrypt.rb
  driver = checkpassword
}
plugin {
  expire = INBOX.Trash 14 INBOX.Trash/* 14 INBOX.Spam 14 INBOX.spam 14
INBOX.Papierkorb 14 INBOX.Papierkorb/* 14 INBOX.Junk 14
  expire_dict = proxy::expire
  quota = maildir:User quota
  quota_rule = *:storage=0
  quota_rule2 = INBOX.Trash:storage=+10%%
  quota_warning = storage=95%% quota-warning 95 %u
  quota_warning2 = storage=80%% quota-warning 80 %u
  sieve = ~/dovecot.sieve
  sieve_default = /var/lib/dovecot-sieve/default.sieve
  sieve_dir = ~/sieve
  sieve_global_dir = /var/lib/dovecot-sieve/global/
}
postmaster_address = postmaster at example.com
protocols = imap pop3 sieve
service managesieve-login {
  inet_listener sieve {
    port = 4190
  }
  inet_listener sieve_deprecated {
    port = 2000
  }
}
service quota-warning {
  executable = script /usr/libexec/dovecot/quota-warning.sh
}
ssl_cert = </etc/certs/server.crt
ssl_cipher_list = HIGH:MEDIUM:!aNULL:!SSLv2:@STRENGTH
ssl_key = </etc/certs/server.key
userdb {
  driver = prefetch
}
userdb {
  args = /usr/libexec/dovecot/checkpassword-bcrypt/checkpassword-bcrypt.rb
  driver = checkpassword
}
version_ignore = yes
protocol lda {
  info_log_path = /var/log/dovecot/deliver.log
  log_path = /var/log/dovecot/deliver-errors.log
  mail_plugins = sieve quota
}
protocol imap {
  imap_client_workarounds = delay-newmail tb-extra-mailbox-sep
  mail_max_userip_connections = 30
  mail_plugins = expire quota imap_quota
}
protocol pop3 {
  mail_plugins = expire quota
}

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 262 bytes
Desc: OpenPGP digital signature
URL: <http://dovecot.org/pipermail/dovecot/attachments/20120525/83078db1/attachment-0002.bin>

More information about the dovecot mailing list