Folks: I've been running Dovecot 2.0.7 on a Qmail / Vpopmail installation built on Debian Squeeze, with no problems for about a year. Dovecot is used for IMAP/S auth only. Dovecot is built from source. I just upgraded to 2.0.15 but it segfaults whenever an IMAP auth is attempted, regardless of the user who tries to login, whether by webmail (Roundmail) Android phone (K-9 Mail) or iPad (Roundmail) I downgraded to 2.0.13 but the segfault persisted. Re-installed 2.0.7 and that cleared it right up. Here's the pertinent details from 2.0.15. Anything else I can provide? root at XXX:/# uname -a Linux XXX 2.6.32-5-686 #1 SMP Wed Jan 12 04:01:41 UTC 2011 i686 GNU/Linux root at XXX:/# dovecot -n # 2.0.15: /usr/local/etc/dovecot/dovecot.conf # OS: Linux 2.6.32-5-686 i686 Debian 6.0.3 auth_debug = yes auth_debug_passwords = yes auth_verbose = yes auth_verbose_passwords = plain disable_plaintext_auth = no first_valid_uid = XXXX last_valid_uid = XXXX log_path = /var/log/dovecot.log mail_debug = yes passdb { driver = vpopmail } protocols = imap service imap-login { inet_listener imap { address = * port = 143 } inet_listener imaps { address = * port = 993 } process_limit = 128 vsz_limit = 64 M } ssl_cert = </etc/ssl/certs/dovecot.pem ssl_key = </etc/ssl/private/dovecot.pem userdb { driver = vpopmail } verbose_ssl = yes Here's a failed login transaction from /var/log/dovecot [snip -- 10 lines or so. The SSL handshake completes OK] Nov 15 14:08:43 auth: Debug: client in: AUTH 1 PLAIN service=imap secured lip=192.xxx.xxx.xxx rip=174.79.xxx.xxxlport=143 rport=55437 resp=XYXYXYXYXYXXYXYXYXYXYXYXYXYX=Nov 15 14:08:43 auth-worker: Debug: Loading modules from directory: /usr/local/lib/dovecot/auth Nov 15 14:08:43 auth-worker: Debug: vpopmail(user at mydomain.net,174.79.xxx.xxx): lookup user=user domain=domain.net Nov 15 14:08:43 auth: Debug: client out: OK 1 user=user at mydomain.net Nov 15 14:08:43 auth: Debug: master in: REQUEST 2710831105 686 1 XYXYXYXYXYXXYYXYXYX Nov 15 14:08:43 auth-worker: Debug: vpopmail(user at domain.net,174.79.xxx.xxx): lookup user=user domain=domain.net Nov 15 14:08:43 auth: Error: auth worker: Aborted request: Worker process died unexpectedly Nov 15 14:08:43 master: Error: service(auth-worker): child 690 killed with signal 11 (core dumped) Nov 15 14:08:43 auth: Debug: master out: FAIL 2710831105 Nov 15 14:08:43 imap: Error: Internal auth failure (client-pid=686 client-id=1) Nov 15 14:08:43 imap-login: Info: Internal login failure (pid=686 id=1) (auth failed, 1 attempts): user=<user at domain.net>, method=PLAIN, rip=174.79.xxx.xxx, lip=192.xxx.xxx.xxx, mpid=691, TLS Nov 15 14:08:43 imap-login: Warning: SSL alert: where=0x4008, ret=256: warning close notify [174.79.xxx.xxx] Nov 15 14:08:43 auth-worker: Debug: Loading modules from directory: /usr/local/lib/dovecot/auth I ought to mention that /usr/local/lib/dovecot/auth is empty. Here's the backtrace: root at XXX:/# gdb /usr/local/libexec/dovecot/auth /usr/local/var/run/dovecot/core GNU gdb (GDB) 7.0.1-debian [snip] Reading symbols from /usr/local/libexec/dovecot/auth...done. warning: Can't read pathname for load map: Input/output error. Reading symbols from /usr/local/lib/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/local/lib/dovecot/libdovecot.so.0 Reading symbols from /lib/i686/cmov/libcrypt.so.1...Reading symbols from /usr/lib/debug/lib/i686/cmov/libcrypt-2.11.2.so...done. (no debugging symbols found)...done. Loaded symbols for /lib/i686/cmov/libcrypt.so.1 Reading symbols from /home/vpopmail/lib/libvpopmail.so...(no debugging symbols found)...done. Loaded symbols for /home/vpopmail/lib/libvpopmail.so Reading symbols from /lib/i686/cmov/libdl.so.2...Reading symbols from /usr/lib/debug/lib/i686/cmov/libdl-2.11.2.so...done. (no debugging symbols found)...done. Loaded symbols for /lib/i686/cmov/libdl.so.2 Reading symbols from /lib/i686/cmov/librt.so.1...Reading symbols from /usr/lib/debug/lib/i686/cmov/librt-2.11.2.so...done. (no debugging symbols found)...done. Loaded symbols for /lib/i686/cmov/librt.so.1 Reading symbols from /lib/i686/cmov/libc.so.6...Reading symbols from /usr/lib/debug/lib/i686/cmov/libc-2.11.2.so...done. (no debugging symbols found)...done. Loaded symbols for /lib/i686/cmov/libc.so.6 Reading symbols from /lib/ld-linux.so.2...Reading symbols from /usr/lib/debug/lib/ld-2.11.2.so...done. (no debugging symbols found)...done. Loaded symbols for /lib/ld-linux.so.2 Reading symbols from /lib/i686/cmov/libpthread.so.0...Reading symbols from /usr/lib/debug/lib/i686/cmov/libpthread-2.11.2.so...done. (no debugging symbols found)...done. Loaded symbols for /lib/i686/cmov/libpthread.so.0 Reading symbols from /home/vpopmail/etc/vpopmail.authmodule...(no debugging symbols found)...done. Loaded symbols for /home/vpopmail/etc/vpopmail.authmodule Core was generated by `dovecot/auth -w'. Program terminated with signal 11, Segmentation fault. #0 0x00000000 in ?? () (gdb) bt full #0 0x00000000 in ?? () No symbol table info available. #1 0x08059890 in auth_worker_handle_user (client=0x82b34d0) at auth-worker-client.c:405 auth_request = 0x82b56e8 userdb_id = 1 #2 auth_worker_handle_line (client=0x82b34d0) at auth-worker-client.c:534 id = 2 #3 auth_worker_input (client=0x82b34d0) at auth-worker-client.c:614 _data_stack_cur_id = 3 line = <value optimized out> ret = 232 #4 0xb785f021 in io_loop_call_io (io=0x82b3688) at ioloop.c:384 ioloop = 0x82a6398 t_id = 2 #5 0xb78600d3 in io_loop_handler_run (ioloop=0x82a6398) at ioloop-epoll.c:213 ctx = 0x82b1f38 event = 0x82b1f78 list = 0x82b36b0 io = 0x829e2b0 tv = {tv_sec = 2147483, tv_usec = 0} msecs = 1 ret = 1 i = 0 j = 0 call = 192 #6 0xb785efa0 in io_loop_run (ioloop=0x82a6398) at ioloop.c:405 No locals. #7 0xb784abaa in master_service_run (service=0x82a62e8, callback=0x805c470 <worker_connected>) at master-service.c:481 No locals. #8 0x0805c828 in main (argc=2, argv=0x82a61c0) at main.c:298 c = <value optimized out> (gdb) --mhg
On Tue, 2011-11-15 at 14:31 -0500, Mark Goldey wrote: Could you do a bit more with gdb and this core:> #1 0x08059890 in auth_worker_handle_user (client=0x82b34d0) at > auth-worker-client.c:405 > auth_request = 0x82b56e8 > userdb_id = 1fr 1 p *auth_request->userdb->userdb p *auth_request->userdb->userdb->iface
Your message was discarded by mailman, probably because it was html-only. Anyway: On Wed, 2011-11-16 at 13:15 -0500, Mark Goldey wrote:> (gdb) p *auth_request->userdb->userdb->iface > $2 = {name = 0x807023e "vpopmail", preinit = 0x8065d60 > <vpopmail_preinit>, init = 0, deinit = 0, > lookup = 0x8066010 <vpopmail_lookup>, iterate_init = 0, iterate_next > = 0, iterate_deinit = 0}OK, so "auth_request->userdb->userdb->iface->lookup" should call vpopmail_lookup(), it's not NULL as this says:> > (gdb) bt full > > #0 0x00000000 in ?? ()So something's going strangely wrong. Maybe gcc optimizations cause this and the real problem happens later. Try compiling auth process with optimizations: - Remove -O2 from src/auth/Makefile - cd src/auth ; make clean ; make ; make install Is the backtrace different?
Sorry about the HTML. I removed the string "-O2" from the /auth Makefile and, for good measure, did make clean, make and make install for all of Dovecot. Still, it crashed when trying to log in via IMAP (webmail). Core dumped, here's the backtrace. [snip] Core was generated by `dovecot/auth -w'. Program terminated with signal 11, Segmentation fault. #0 0x00000000 in ?? () (gdb) bt full #0 0x00000000 in ?? () No symbol table info available. #1 0x0805b0c7 in auth_worker_handle_user (client=0x82754d0, id=2, args=0x82601c8) at auth-worker-client.c:405 auth_request = 0x82776e8 userdb_id = 1 #2 0x0805b630 in auth_worker_handle_line (client=0x82754d0, line=0x82757da "2\tUSER\t1\tuser=mgoldXX at goldey.net\tservice=imap\toriginal_username=mgoldXX at goldey.net\trequested_login_user\tlip=127.0.0.1\trip=127.0.0.1\tlport=143\trport=47574\tsecured=1\tsuccessful=1\tmech=PLAIN") at auth-worker-client.c:534 args = 0x82601c0 id = 2 ret = false #3 0x0805b890 in auth_worker_input (client=0x82754d0) at auth-worker-client.c:614 _data_stack_cur_id = 3 line = 0x82757da "2\tUSER\t1\tuser=mgoldXX at goldey.net\tservice=imap\toriginal_username=mgoldXX at goldey.net\trequested_login_user\tlip=127.0.0.1\trip=127.0.0.1\tlport=143\trport=47574\tsecured=1\tsuccessful=1\tmech=PLAIN" ret = 183 #4 0xb7726021 in io_loop_call_io (io=0x8275688) at ioloop.c:384 ioloop = 0x8268398 t_id = 2 #5 0xb77270d3 in io_loop_handler_run (ioloop=0x8268398) at ioloop-epoll.c:213 ctx = 0x8273f38 event = 0x8273f78 list = 0x82756b0 io = 0xbf80049f tv = {tv_sec = 2147483, tv_usec = 0} msecs = 1 ret = 1 i = 0 j = 0 call = 192 #6 0xb7725fa0 in io_loop_run (ioloop=0x8268398) at ioloop.c:405 No locals. #7 0xb7711baa in master_service_run (service=0x82682e8, callback=0x805e466 <worker_connected>) at master-service.c:481 No locals. #8 0x0805e7aa in main (argc=2, argv=0x82681c0) at main.c:298 c = -1 And, for good measure: (gdb) fr 1 #1 0x0805b0c7 in auth_worker_handle_user (client=0x82754d0, id=2, args=0x82601c8) at auth-worker-client.c:405 405 auth_request->userdb->userdb->iface-> (gdb) p *auth_request->userdb->userdb $1 = {args = 0x8268d10 "", cache_key = 0x0, blocking = true, id = 1, init_refcount = 1, iface = 0x807b320} (gdb) p *auth_request->userdb->userdb->iface $2 = {name = 0x8074f3d "vpopmail", preinit = 0x8069a27 <vpopmail_preinit>, init = 0, deinit = 0, lookup = 0x806975f <vpopmail_lookup>, iterate_init = 0, iterate_next 0, iterate_deinit = 0} This is all Greek to me, but I'm happy to do more troubleshooting. --mhg