dovecot - May 2012 - dovecot/auth killed with signal 6

I've had this working for over a month now with no problems. Then I
suffered a power outage today, and now dovecot/auth dies as soon as I start
dovecot. I've spent the past three hours searching google, but can't
find
even a hint at what's wrong with my server. As far as I can tell, this is
the only thing that has failed after bringing the server back up when power
was restored. Can anyone help me figure out what is wrong?

The maillog records:
May  9 20:27:37 box dovecot: auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May  9 20:27:37 box dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libauthdb_ldap.so
May  9 20:27:37 box dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_mysql.so
May  9 20:27:37 box dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_pgsql.so
May  9 20:27:37 box dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_sqlite.so
May  9 20:27:37 box dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libmech_gssapi.so
May  9 20:27:37 box dovecot: auth: Panic: io_add(0x1) called twice fd=13,
callback=0x3016833290 -> 0x3016836cd0
May  9 20:27:37 box dovecot: auth: Error: Raw backtrace:
/usr/lib64/dovecot/libdovecot.so.0() [0x301683ca6a] ->
/usr/lib64/dovecot/libdovecot.so.0() [0x301683ca
b6] -> /usr/lib64/dovecot/libdovecot.so.0() [0x3016816dba] ->
/usr/lib64/dovecot/libdovecot.so.0(ioloop_iolist_add+0x7f) [0x301684872f]
-> /usr/lib64/dovecot/li
bdovecot.so.0(io_loop_handle_add+0x39) [0x3016849149] ->
/usr/lib64/dovecot/libdovecot.so.0(io_add+0xa3) [0x3016848593] ->
/usr/lib64/dovecot/libdovecot.so.0(ma
ster_service_io_listeners_add+0x68) [0x3016835b88] ->
/usr/lib64/dovecot/libdovecot.so.0(master_service_init_finish+0x192)
[0x30168363c2] -> dovecot/auth(main+0
x207) [0x415567] -> /lib64/libc.so.6(__libc_start_main+0xfd) [0x3016c1ecdd]
-> dovecot/auth() [0x409aa9]
May  9 20:27:37 box dovecot: master: Error: service(auth): child 25615
killed with signal 6 (core dumped)
May  9 20:27:37 box dovecot: master: Error: service(auth): command startup
failed, throttling

A core dump was produced.  The backtrace shows:
# gdb /usr/libexec/dovecot/auth coredump
Core was generated by `dovecot/auth'.
Program terminated with signal 6, Aborted.
#0  0x0000003016c32885 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install
dovecot-2.0.9-2.el6_1.1.x86_64
(gdb) bt full
#0  0x0000003016c32885 in raise () from /lib64/libc.so.6
#1  0x0000003016c34065 in abort () from /lib64/libc.so.6
#2  0x000000301683ca78 in ?? () from /usr/lib64/dovecot/libdovecot.so.0
#3  0x000000301683cab6 in ?? () from /usr/lib64/dovecot/libdovecot.so.0
#4  0x0000003016816dba in i_panic () from /usr/lib64/dovecot/libdovecot.so.0
#5  0x000000301684872f in ioloop_iolist_add () from
/usr/lib64/dovecot/libdovecot.so.0
#6  0x0000003016849149 in io_loop_handle_add () from
/usr/lib64/dovecot/libdovecot.so.0
#7  0x0000003016848593 in io_add () from /usr/lib64/dovecot/libdovecot.so.0
#8  0x0000003016835b88 in master_service_io_listeners_add () from
/usr/lib64/dovecot/libdovecot.so.0
#9  0x00000030168363c2 in master_service_init_finish () from
/usr/lib64/dovecot/libdovecot.so.0
#10 0x0000000000415567 in main ()

This is running on CentOS 6.2
# rpm -q dovecot
dovecot-2.0.9-2.el6_1.1.x86_64

# dovecot --version
2.0.9

# dovecot -n
# 2.0.9: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.32-220.13.1.el6.x86_64 x86_64 CentOS release 6.2 (Final)
auth_debug = yes
auth_mechanisms = plain login
auth_verbose = yes
listen = *
mail_debug = yes
mail_location = mbox:~/mail:INBOX=/var/mail/%u
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
mbox_write_locks = fcntl
passdb {
  driver = pam
}
plugin {
  sieve = ~/.dovecot.sieve
  sieve_dir = ~/sieve
}
service auth {
  inet_listener {
    port = 12345
  }
  unix_listener /var/spool/postfix/private/auth {
    mode = 0666
  }
  user = $default_internal_user
}
ssl_cert = </etc/pki/dovecot/certs/dovecot.pem
ssl_key = </etc/pki/dovecot/private/dovecot.pem
userdb {
  driver = passwd
}

Okay, I figured out about installing debuginfo for a better backtrace, so
here it is:

#0  0x0000003016c32885 in raise (sig=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:64
        resultvar = 0
        pid = 2598
        selftid = 2598
#1  0x0000003016c34065 in abort () at abort.c:92
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x1, sa_sigaction 0x1},
sa_mask = {__val = {206536311181, 35954576, 35955280, 0,
206536165913, 4281703, 206536010617,
              206158430224, 140734171103856, 140734171103648, 7, 7,
35807776, 0, 16992, 6717507389398987896}}, sa_flags = 1768709983,
sa_restorer = 0}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x000000301683ca78 in default_fatal_finish (type=<value optimized
out>,
status=0) at failures.c:187
        backtrace = 0x2226220 "/usr/lib64/dovecot/libdovecot.so.0()
[0x301683ca6a] -> /usr/lib64/dovecot/libdovecot.so.0() [0x301683cab6] ->
/usr/lib64/dovecot/libdovecot.so.0() [0x3016816dba] ->
/usr/lib64/dovecot/libdovecot.so.0("...
#3  0x000000301683cab6 in i_internal_fatal_handler (ctx=0x7fff3a46c2e0,
format=<value optimized out>, args=<value optimized out>) at
failures.c:645
        status = 0
#4  0x0000003016816dba in i_panic (format=0xa26 <Address 0xa26 out of
bounds>) at failures.c:259
        ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0}
        args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area
0x7fff3a46c3b0, reg_save_area = 0x7fff3a46c2f0}}
#5  0x000000301684872f in ioloop_iolist_add (list=<value optimized out>,
io=<value optimized out>) at ioloop-iolist.c:26
        i = <value optimized out>
        idx = <value optimized out>
#6  0x0000003016849149 in io_loop_handle_add (io=0x224a250) at
ioloop-epoll.c:104
        ctx = 0x2243b20
        list = 0x2249558
        event = {events = 1, data = {ptr = 0x16836cd000000000, fd = 0, u32
= 0, u64 = 1622259931392507904}}
        op = <value optimized out>
        first = <value optimized out>
#7  0x0000003016848593 in io_add (fd=13, condition=IO_READ,
callback=0x3016836cd0 <master_service_listen>, context=0x2249f90) at
ioloop.c:54
        io = 0x224a250
        __FUNCTION__ = "io_add"
#8  0x0000003016835b88 in master_service_io_listeners_add
(service=0x222e4d0) at master-service.c:777
        l = 0x2249f90
        i = <value optimized out>
#9  0x00000030168363c2 in master_service_init_finish (service=0x222e4d0) at
master-service.c:385
        st = {st_dev = 8, st_ino = 15492, st_nlink = 1, st_mode = 4480,
st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 0, st_blksize 4096,
st_blocks = 0, st_atim = {
            tv_sec = 1336599449, tv_nsec = 793902156}, st_mtim = {tv_sec
1336599449, tv_nsec = 793902156}, st_ctim = {tv_sec = 1336599449, tv_nsec
793902156}, __unused = {0, 0,
            0}}
        value = <value optimized out>
        count = 4096
        __FUNCTION__ = "master_service_init_finish"
#10 0x0000000000415567 in main (argc=1, argv=0x222e370) at main.c:293
        c = <value optimized out>

On Wed, 2012-05-09 at 20:38 -0400, Edward Burr wrote:
> May  9 20:27:37 box dovecot: auth: Panic: io_add(0x1) called twice fd=13,
> callback=0x3016833290 -> 0x3016836cd0
Could you do:

gdb /usr/libexec/dovecot/auth coredump
x 0x3016833290
x 0x3016836cd0
> I finally got it working by commenting out the configuration under service
> auth {
> #  inet_listener {
> #    port = 12345
> #  }
> 
> which I had in there for SASL with postfix, and which WAS working before
> the power outage.
I guess there might be some bug in v2.0.9 related to this.