Greets,
I'm using dovecot 2.0.9 (also tried rolling back to 2.0.8 which does the same
- the output below is from 2.0.8), and this problem is imap specific. The following is a recurring problem with a specific user - as far as we can tell, other users are working just fine (there are thousands); but I bet there are others.
In a nutshell: User authenticates OK, then the imap process hangs.
It's almost as if something in the user's inbox is causing the problem, since if I clear all emails (and cache), then things work fine. The user will then receive emails OK for some random period (maybe a few days) and be able to read/write OK via imap, and the problem will re-occur.
The debug output shows nothing untoward:
auth: Debug: auth client connected (pid=20774)
auth: Debug: client in: AUTH 1 PLAIN service=imap secured
lip=127.0.0.1 rip=127.0.0.1 lport=144 rport=41641 resp=<hidden>
auth: Debug: shadow(username,127.0.0.1): lookup
auth: Debug: client out: OK 1 user=username
auth: Debug: master in: REQUEST 1938161665 20774 1
238230058d076a9af1cd4405244d33ba
auth: Debug: passwd(username,127.0.0.1): lookup
auth: Debug: master out: USER 1938161665 username
system_groups_user=username uid=17286 gid=300
home=/home/mailusers/username
imap-login: Info: Login: user=<username>, method=PLAIN, rip=127.0.0.1,
lip=127.0.0.1, mpid=20775, secured
imap(username): Debug: Effective uid=17286, gid=300,
home=/home/mailusers/username
imap(username): Debug: fs: root=/home/mailusers/username/., index=, control=,
inbox=/var/mail/username
Rawlog looks good:
IN: A002 CAPABILITY A003 NAMESPACE C64 EXAMINE "" A002 STATUS "INBOX" (MESSAGES UNSEEN RECENT) A003 SELECT "INBOX" A004 EXPUNGE A005 SELECT "INBOX" A006 EXPUNGE A007 UID SEARCH UNSEEN A008 UID FETCH 2533:2588 (FLAGS BODY.PEEK[HEADER.FIELDS (RECEIVED)])
OUT: ...
- 15 FETCH (UID 2536 FLAGS () BODY[HEADER.FIELDS (RECEIVED)] {944} ...
- 67 FETCH (UID 2588 FLAGS () BODY[HEADER.FIELDS (RECEIVED)] {945} ... A008 OK Fetch completed.
It's at this point that nothing happens for a short while and the user gets a blank screen.
I tried running it through gdb (ie, "Talk IMAP Directly" - as described at http://dovecot.org/bugreport.html), but that fails with "Cannot find user-level thread for LWP nnnn: generic error", which is probably specific to our old box/installation.
strace hangs with:
Process 6574 attached - interrupt to quit gettimeofday({1296472202, 318955}, NULL) = 0 gettimeofday({1296472202, 319073}, NULL) = 0 epoll_wait(0x8, 0x806c4f8, 0x6, 0x1b708d
gdb backtrace gives:
0xb7e2bff9 in epoll_wait () from /lib/tls/libc.so.6 (gdb) bt full #0 0xb7e2bff9 in epoll_wait () from /lib/tls/libc.so.6 No symbol table info available. #1 0xb7eed4eb in io_loop_handler_run (ioloop=0x806c390) at ioloop-epoll.c:181 ctx = (struct ioloop_handler_context *) 0x806c4b8 list = (struct io_list *) 0x8082850 io = (struct io_file *) 0x806c4f8 tv = {tv_sec = 1696, tv_usec = 510098} msecs = 8 ret = -1 i = 0 j = -1208929836 call = 8 #2 0xb7eec249 in io_loop_run (ioloop=0x806c390) at ioloop.c:404 No locals. #3 0xb7ed8e15 in master_service_run (service=0x806c2e0, callback=0xfffffffc) at master-service.c:484 No locals. #4 0x0805ee75 in main (argc=1, argv=0x806c1d8) at main.c:375 set_roots = {0x8061d80, 0x0} service_flags = 6 storage_service_flags = MAIL_STORAGE_SERVICE_FLAG_DISALLOW_ROOT postlogin_socket_path = 0x806c2e0 "\220�\006\bp�\006\b\200�\006\b\b" username = 0x0 c = -4 (gdb)
lsof shows:
COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME imap 6574 username cwd DIR 9,0 4096 30130787 /home2/home/mailusers/username imap 6574 username rtd DIR 3,1 4096 2 / imap 6574 username txt REG 9,0 941700 35836003 /home2/local/libexec/dovecot/imap imap 6574 username mem REG 0,0 0 [heap] (stat: No such file or directory) imap 6574 username mem REG 9,0 109568 30130578 /home2/home/mailusers/username/.imap/INBOX/dovecot.index.cache imap 6574 username mem REG 3,1 41351 13749135 /lib/tls/libnss_files-2.3.5.so imap 6574 username mem REG 3,1 41583 13749137 /lib/tls/libnss_nis-2.3.5.so imap 6574 username mem REG 3,1 92501 13749132 /lib/tls/libnsl-2.3.5.so imap 6574 username mem REG 3,1 35866 13749133 /lib/tls/libnss_compat-2.3.5.so imap 6574 username mem REG 3,1 87827 13749140 /lib/tls/libpthread-2.3.5.so imap 6574 username mem REG 3,1 1366940 13749126 /lib/tls/libc-2.3.5.so imap 6574 username mem REG 3,1 34582 13749142 /lib/tls/librt-2.3.5.so imap 6574 username mem REG 3,1 13120 13749129 /lib/tls/libdl-2.3.5.so imap 6574 username mem REG 9,0 17380 6897709 /home2/home/mailusers/username/.imap/INBOX/dovecot.index.log imap 6574 username mem REG 9,0 1980063 35835914 /home2/local/lib/dovecot/libdovecot.so.0.0.0 imap 6574 username mem REG 9,0 4911010 35835915 /home2/local/lib/dovecot/libdovecot-storage.so.0.0.0 imap 6574 username mem REG 3,1 27274 654816 /lib/libsafe.so.2.0.16 imap 6574 username mem REG 3,1 99790 654754 /lib/ld-2.3.5.so imap 6574 username 0w CHR 1,3 327760 /dev/null imap 6574 username 1w CHR 1,3 327760 /dev/null imap 6574 username 2w FIFO 0,5 1548069248 pipe imap 6574 username 3w FIFO 0,5 1548064788 pipe imap 6574 username 4r FIFO 0,5 1548414049 pipe imap 6574 username 5w FIFO 0,5 1548069260 pipe imap 6574 username 6u unix 0xe481b180 1548069218 /usr/local/var/run/dovecot/login/imap imap 6574 username 7w FIFO 0,5 1548414049 pipe imap 6574 username 8u 0000 0,6 0 9 unknown inode type imap 6574 username 9u REG 9,0 17380 6897709 /home2/home/mailusers/username/.imap/INBOX/dovecot.index.log imap 6574 username 10u IPv4 1548412828 TCP localhost:144->localhost:38067 (ESTABLISHED) imap 6574 username 11u REG 9,0 2632 30130623 /home2/home/mailusers/username/.imap/INBOX/dovecot.index imap 6574 username 12u REG 9,0 109568 30130578 /home2/home/mailusers/username/.imap/INBOX/dovecot.index.cache imap 6574 username 13u REG 9,0 10472498 9257043 /home2/var/spool/mail/username
Any pointers?
Thanks Henry
CONFIG:
auth_debug = yes auth_mechanisms = plain login default_login_user = nobody first_valid_uid = 200 listen = * log_path = /var/log/dovecot.log mail_debug = yes mail_location = mbox:~/.:INBOX=/var/mail/%u passdb { driver = shadow } protocols = imap service imap-login { inet_listener imap { port = 144 # 143 is for imap proxy } } ssl = no userdb { driver = passwd }