Issue with a bug with imap-login
Grant Keller
grant.keller at sonic.com
Sat Mar 31 00:52:51 EEST 2018
Hello,
Currently working on migrating our existing directors from 2.1.13 to
2.2.10. In 2.2.10 when issuing the logout command on an unauthenticated
connection, the connection is closed before the server sends the BYE
line to the client. The new version works as expected with a non-secure
connection. I will include the strace output from the imap-login process
that shows the connection closing before the message can be sent.
# 2.2.10: /etc/dovecot/dovecot.conf
# OS: Linux 3.10.0-693.21.1.el7.x86_64 x86_64 CentOS Linux release 7.4.1708 (Core)
auth_master_user_separator = *
auth_username_format = %Ln
auth_verbose = yes
default_client_limit = 20000
director_mail_servers = removed
director_servers = c.director.imapd.sonic.net d.director.imapd.sonic.net
disable_plaintext_auth = no
doveadm_port = 1842
login_trusted_networks = removed
mbox_write_locks = fcntl
passdb {
args = /etc/dovecot/master-users
driver = passwd-file
master = yes
pass = yes
}
passdb {
args = proxy=y nopassword=y
driver = static
}
service anvil {
client_limit = 40103
}
service auth {
client_limit = 41704
}
service director {
fifo_listener login/proxy-notify {
mode = 0666
}
inet_listener {
port = 9321
}
unix_listener login/director {
mode = 0666
}
}
service imap-login {
executable = imap-login director
process_limit = 20000
process_min_avail = 1
}
service imap {
process_limit = 20480
}
service pop3-login {
executable = pop3-login director
process_limit = 20000
process_min_avail = 32
}
ssl_ca = </etc/dovecot/ssl/gd_bundle.crt
ssl_cert = </etc/dovecot/ssl/imap.sonic.net.crt
ssl_cipher_list = ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-DSS-AES128-GCM-SHA256:kEDH+AESGCM:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA:ECDHE-ECDSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-DSS-AES256-SHA:DHE-RSA-AES256-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:AES:CAMELLIA:DES-CBC3-SHA:!aNULL:!eNULL:!EXPORT:!DES:!RC4:!MD5:!PSK:!aECDH:!EDH-DSS-DES-CBC3-SHA:!EDH-RSA-DES-CBC3-SHA:!KRB5-DES-CBC3-SHA
ssl_key = </etc/dovecot/ssl/imap.sonic.net.key
ssl_parameters_regenerate = 1 days
ssl_protocols = !SSLv2 !SSLv3
syslog_facility = local0
protocol imap {
imap_max_line_length = 128 k
ssl_ca = </etc/dovecot/ssl/gd_bundle.crt
ssl_cert = </etc/dovecot/ssl/imap.sonic.net.crt
ssl_key = </etc/dovecot/ssl/imap.sonic.net.key
}
protocol pop3 {
ssl_ca = </etc/dovecot/ssl/pop.sonic.net.ca-bundle
ssl_cert = </etc/dovecot/ssl/pop.sonic.net.crt
ssl_key = </etc/dovecot/ssl/pop.sonic.net.key
}
STRACE:
263563 epoll_wait(14<anon_inode:[eventpoll]>, [{EPOLLIN, {u32=2772983280, u64=94500643429872}}], 8, -1) = 1
263563 accept(9<TCP:[0.0.0.0:993]>, {sa_family=AF_INET, sin_port=htons(39552), sin_addr=inet_addr("64.142.18.25")}, [16]) = 18<TCP:[64.142.111.79:993->64.142.18.25:39552]>
263563 fcntl(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, F_GETFL) = 0x2 (flags O_RDWR)
263563 fcntl(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, F_SETFL, O_RDWR|O_NONBLOCK) = 0
263563 write(5<pipe:[1445541]>, "\213\5\4\0\223\16\0\0\0\0\0\0", 12) = 12
263563 write(2<pipe:[1445512]>, "\1\010263563 ip=64.142.18.25\n", 25) = 25
263563 getsockname(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, {sa_family=AF_INET, sin_port=htons(993), sin_addr=inet_addr("64.142.111.79")}, [16]) = 0
263563 socket(AF_LOCAL, SOCK_STREAM, 0) = 19<UNIX:[1458853]>
263563 fcntl(19<UNIX:[1458853]>, F_GETFL) = 0x2 (flags O_RDWR)
263563 fcntl(19<UNIX:[1458853]>, F_SETFL, O_RDWR|O_NONBLOCK) = 0
263563 connect(19<UNIX:[1458853]>, {sa_family=AF_LOCAL, sun_path="ssl-params"}, 110) = 0
263563 fcntl(19<UNIX:[1458853]>, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
263563 fcntl(19<UNIX:[1458853]>, F_SETFL, O_RDWR) = 0
263563 read(19<UNIX:[1458853]>, "\0\2\0\0", 4) = 4
263563 read(19<UNIX:[1458853]>, "H\0\0\0", 4) = 4
263563 read(19<UNIX:[1458853]>, "0F\2A\0\246@\4\253O,\222\10\300\237\334\240>\331\270\24K\261w\300\16\0076\230\2039\1"..., 72) = 72
263563 read(19<UNIX:[1458853]>, "\0\4\0\0", 4) = 4
263563 read(19<UNIX:[1458853]>, "\212\0\0\0", 4) = 4
263563 read(19<UNIX:[1458853]>, "0\201\207\2\201\201\0\213:7H\"\251}6d\371}\212\312\276\177p!\10\26\1[\241\265\254\216"..., 138) = 138
263563 read(19<UNIX:[1458853]>, "\0\0\0\0", 4) = 4
263563 read(19<UNIX:[1458853]>, "", 1) = 0
263563 close(19<UNIX:[1458853]>) = 0
263563 socketpair(AF_LOCAL, SOCK_STREAM, 0, [19<UNIX:[1401333->1401334]>, 20<UNIX:[1401334->1401333]>]) = 0
263563 fcntl(19<UNIX:[1401333->1401334]>, F_GETFL) = 0x2 (flags O_RDWR)
263563 fcntl(19<UNIX:[1401333->1401334]>, F_SETFL, O_RDWR|O_NONBLOCK) = 0
263563 fcntl(20<UNIX:[1401334->1401333]>, F_GETFL) = 0x2 (flags O_RDWR)
263563 fcntl(20<UNIX:[1401334->1401333]>, F_SETFL, O_RDWR|O_NONBLOCK) = 0
263563 fcntl(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
263563 fcntl(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, F_SETFL, O_RDWR|O_NONBLOCK) = 0
263563 fstat(20<UNIX:[1401334->1401333]>, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
263563 lseek(20<UNIX:[1401334->1401333]>, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek)
263563 getsockname(20<UNIX:[1401334->1401333]>, {sa_family=AF_LOCAL, NULL}, [2]) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_ADD, 20<UNIX:[1401334->1401333]>, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=2773038880, u64=94500643485472}}) = 0
263563 write(20<UNIX:[1401334->1401333]>, "* OK [CAPABILITY IMAP4rev1 LITER"..., 103) = 103
263563 brk(NULL) = 0x55f2a549d000
263563 brk(0x55f2a54c2000) = 0x55f2a54c2000
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\26\3\1\0\253\1\0\0\247\3\3", 11) = 11
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\205\224\354\263zY\200p\240T\21\377\276\224\251(\343\255x\277\273.\223\304\"<R\222\16\3538s"..., 165) = 165
263563 write(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\26\3\3\0=\2\0\0009\3\0033\336\314\231\205\305\330\206M\361qQ\240\272\225\317^\331Ysc"..., 4096) = 4096
263563 write(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "http://ocsp.usertrust.com0\r\6\t*\206H"..., 680) = 680
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, 0x55f2a5498db3, 5) = -1 EAGAIN (Resource temporarily unavailable)
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_ADD, 18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=2773128976, u64=94500643575568}}) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 7<TCP:[0.0.0.0:143]>, 0x7ffcd4f4f270) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 8<TCPv6:[:::143]>, 0x7ffcd4f4f270) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 9<TCP:[0.0.0.0:993]>, 0x7ffcd4f4f270) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 10<TCPv6:[:::993]>, 0x7ffcd4f4f270) = 0
263563 close(7<TCP:[0.0.0.0:143]>) = 0
263563 close(8<TCPv6:[:::143]>) = 0
263563 close(9<TCP:[0.0.0.0:993]>) = 0
263563 close(10<TCPv6:[:::993]>) = 0
263563 epoll_wait(14<anon_inode:[eventpoll]>, [{EPOLLIN, {u32=2773128976, u64=94500643575568}}], 10, 179981) = 1
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\26\3\3\0f", 5) = 5
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\20\0\0ba\4:tZW\323_&\31\205\274\254\242\246\203\342\324O\350\36\206uX\36@/\r"..., 102) = 102
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\24\3\3\0\1", 5) = 5
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\1", 1) = 1
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\26\3\3\0(", 5) = 5
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\224\204\216\367\254\217z\253$S\325\242F\t\256<'vz\3\355\37\fmz\204\261li\307\23\225"..., 40) = 40
263563 write(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\26\3\3\0\252\4\0\0\246\0\0\1,\0\240q/\300C\32\250\251\253I>\177\205A\3\331&\\"..., 226) = 226
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_ADD, 19<UNIX:[1401333->1401334]>, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=2773039024, u64=94500643485616}}) = 0
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, 0x55f2a5498db3, 5) = -1 EAGAIN (Resource temporarily unavailable)
263563 epoll_wait(14<anon_inode:[eventpoll]>, [{EPOLLIN, {u32=2773039024, u64=94500643485616}}], 10, 179974) = 1
263563 read(19<UNIX:[1401333->1401334]>, "* OK [CAPABILITY IMAP4rev1 LITER"..., 1024) = 103
263563 setsockopt(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, SOL_TCP, TCP_CORK, [1], 4) = 0
263563 write(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\27\3\3\0\177[\202'O\267-\354\\\301@\225\301\363YeQ\213\341\204!x\347\314\305\327\16\366"..., 132) = 132
263563 read(19<UNIX:[1401333->1401334]>, 0x55f2a5492a54, 1024) = -1 EAGAIN (Resource temporarily unavailable)
263563 setsockopt(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, SOL_TCP, TCP_CORK, [0], 4) = 0
263563 epoll_wait(14<anon_inode:[eventpoll]>, [{EPOLLIN, {u32=2773128976, u64=94500643575568}}], 10, 179973) = 1
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\27\3\3\0!", 5) = 5
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\224\204\216\367\254\217z\254\366W\2765\27\22l\277\262\v\217f\323\254i\272\214\364\264#q\254n\323"..., 33) = 33
263563 sendto(19<UNIX:[1401333->1401334]>, "? logout\n", 9, 0, NULL, 0) = 9
263563 read(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, 0x55f2a5498db3, 5) = -1 EAGAIN (Resource temporarily unavailable)
263563 epoll_wait(14<anon_inode:[eventpoll]>, [{EPOLLIN, {u32=2773038880, u64=94500643485472}}], 10, 177320) = 1
263563 read(20<UNIX:[1401334->1401333]>, "? logout\n", 863) = 9
263563 write(2<pipe:[1445512]>, "\1\010263563 prefix=imap-login: \n", 29) = 29
263563 write(2<pipe:[1445512]>, "\1\002263563 Aborted login (no auth "..., 131) = 131
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, 0x7ffcd4f4f2d0) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 19<UNIX:[1401333->1401334]>, 0x7ffcd4f4f2d0) = 0
263563 write(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>, "\25\3\3\0\32[\202'O\267-\354]\221\344\235?\351'\270g\262\2-\31\216V\236\364\314\253", 31) = 31
263563 close(18<TCP:[64.142.111.79:993->64.142.18.25:39552]>) = 0
263563 close(19<UNIX:[1401333->1401334]>) = 0
263563 setsockopt(20<UNIX:[1401334->1401333]>, SOL_TCP, TCP_CORK, [1], 4) = -1 EOPNOTSUPP (Operation not supported)
263563 write(20<UNIX:[1401334->1401333]>, "* BYE Logging out\r\n? OK Logout c"..., 43) = -1 EPIPE (Broken pipe)
263563 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=263563, si_uid=994} ---
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 20<UNIX:[1401334->1401333]>, 0x7ffcd4f4f2e0) = 0
263563 close(20<UNIX:[1401334->1401333]>) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 17<UNIX:[1347141->1423948]>, 0x7ffcd4f4f280) = 0
263563 close(17<UNIX:[1347141->1423948]>) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 13<UNIX:[1347139->1250858]>, 0x7ffcd4f4f400) = 0
263563 close(13<UNIX:[1347139->1250858]>) = 0
263563 close(11<UNIX:[1347138->1449033]>) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 6<pipe:[1445521]>, 0x7ffcd4f4f420) = 0
263563 epoll_ctl(14<anon_inode:[eventpoll]>, EPOLL_CTL_DEL, 15<pipe:[1347140]>, 0x7ffcd4f4f3f0) = 0
263563 close(15<pipe:[1347140]>) = 0
263563 close(16<pipe:[1347140]>) = 0
263563 close(14<anon_inode:[eventpoll]>) = 0
263563 exit_group(0) = ?
263563 +++ exited with 0 +++
Grant Keller
System Operations
grant.keller at sonic.com
More information about the dovecot
mailing list