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
}