Garret Huntress
2007-Feb-27 19:13 UTC
[Dovecot] Dovecot rc23 and rc24 freeze after authentication
I had our production systems running on rc23, however we ran into problems when the server was under heavy load. Eventually, the server would begin to freeze all imap connection after authentication (according to the logs). A user would connect, authentication would succeed, and then the connection would sit until timing out. No error logs were produced. Upgrading to rc24 did not resolve the issue, but reverting to rc22 has. -Garret -- Garret W. Huntress System Administrator / System Developer Geophysical Laboratory Carnegie Institution of Washington 5251 Broad Branch Road, NW Washington, DC 20015 Email: ghuntress at ciw.edu Phone: (202)-478-8973 AIM: Garret Huntress ? -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://dovecot.org/pipermail/dovecot/attachments/20070227/aa2ba44d/attachment-0004.html> -------------- next part -------------- A non-text attachment was scrubbed... Name: Garret Huntress.vcf Type: text/directory Size: 18045 bytes Desc: not available URL: <http://dovecot.org/pipermail/dovecot/attachments/20070227/aa2ba44d/attachment-0002.bin> -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://dovecot.org/pipermail/dovecot/attachments/20070227/aa2ba44d/attachment-0005.html>
Charles Marcus
2007-Feb-27 20:15 UTC
[Dovecot] Dovecot rc23 and rc24 freeze after authentication
Garret Huntress wrote:> I had our production systems running on rc23, however we ran into > problems when the server was under heavy load. Eventually, the server > would begin to freeze all imap connection after authentication > (according to the logs). A user would connect, authentication would > succeed, and then the connection would sit until timing out. No error > logs were produced. Upgrading to rc24 did not resolve the issue, but > reverting to rc22 has.Ok, give me a sec.... <grunt> <grunt> Dang - sorry, my crystall ball just isn't working... so, it may be just a leetle bit helpful if you provided some details... I'm thinking maybe some dovecot -n output, actual logs (well, you did say you had looked at them), platform, etc... -- Best regards, Charles
Garret Huntress
2007-Feb-28 04:56 UTC
[Dovecot] Dovecot rc23 and rc24 freeze after authentication
Machine: Quad 2GHz Opterons, 8GB Mem OS: Fedora Core 5 (Linux mail1.ciw.edu 2.6.17-1.2187_FC5 #1 SMP Mon Sep 11 01:16:59 EDT 2006 x86_64 x86_64 x86_64 GNU/Linux) Output from dovecot -n (now in rc22): # /etc/dovecot.conf base_dir: /srv/Apps/dovecot/ log_path: /var/log/dovecot/dovecot.log protocols: imap imaps pop3s ssl_ca_file: /etc/pki/tls/certs/ciw.edu-ca_cert.pem ssl_cert_file: /etc/pki/tls/certs/mail.ciw.edu-cert.pem ssl_key_file: /etc/pki/tls/private/mail.ciw.edu-key.pem login_dir: /srv/Apps/dovecot/login login_executable(default): /usr/libexec/dovecot/imap-login login_executable(imap): /usr/libexec/dovecot/imap-login login_executable(pop3): /usr/libexec/dovecot/pop3-login login_max_processes_count: 1024 default_mail_env: maildir:%h/Maildir mail_location: maildir:%h/Maildir mail_executable(default): /usr/libexec/dovecot/imap mail_executable(imap): /usr/libexec/dovecot/imap mail_executable(pop3): /usr/libexec/dovecot/pop3 mail_plugins: acl mail_plugin_dir(default): /usr/lib64/dovecot/imap mail_plugin_dir(imap): /usr/lib64/dovecot/imap mail_plugin_dir(pop3): /usr/lib64/dovecot/pop3 imap_client_workarounds(default): delay-newmail outlook-idle imap_client_workarounds(imap): delay-newmail outlook-idle imap_client_workarounds(pop3): outlook-idle pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh namespace: type: private separator: / location: maildir:%h/Maildir inbox: yes namespace: type: private separator: / prefix: CIW Archived/ location: maildir:%h/Mailarchive namespace: type: public separator: / prefix: CIW Groups/ location: maildir:/srv/Export/Groups:CONTROL=%h/Maildir/public- subscriptions:INDEX=%h/Maildir/public-index auth default: passdb: driver: pam args: session=yes dovecot userdb: driver: passwd cat of /etc/pam.d/dovecot #%PAM-1.0 auth required pam_nologin.so auth include od-auth account include od-auth session include od-auth cat of /etc/pam.d/od-auth #%PAM-1.0 auth required pam_env.so auth sufficient pam_krb5.so auth required pam_deny.so account required pam_ldap.so session optional pam_mkhomedir.so skel=/etc/skel umask=077 session required pam_limits.so session required pam_krb5.so session required pam_ldap.so Logs from when it occurred (usernames modified) dovecot: Feb 26 11:50:15 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:50:16 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:50:16 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:50:16 Info: imap-login: Disconnected: rip=10.1.1.254, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:50:16 Info: IMAP(user2): Disconnected: Logged out dovecot: Feb 26 11:50:16 Info: imap-login: Login: user=<user3>, method=PLAIN, rip=10.1.20.232, lip=10.1.248.31, TLS dovecot: Feb 26 11:50:17 Info: imap-login: Login: user=<user4>, method=PLAIN, rip=10.1.20.253, lip=10.1.248.31, TLS dovecot: Feb 26 11:50:17 Info: imap-login: Disconnected: rip=10.1.20.233, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:50:19 Info: imap-login: Login: user=<user5>, method=PLAIN, rip=4.21.98.3, lip=10.1.248.31, TLS dovecot: Feb 26 11:50:20 Info: imap-login: Disconnected: Shutting down: method=PLAIN, rip=10.1.15.194, lip=10.1.248.31, TLS dovecot: Feb 26 11:50:21 Info: imap-login: Login: user=<user1>, method=PLAIN, rip=10.1.1.254, lip=10.1.248.31, TLS dovecot: Feb 26 11:50:45 Info: IMAP(user6): Disconnected: Logged out dovecot: Feb 26 11:50:46 Info: imap-login: Login: user=<user1>, method=PLAIN, rip=10.1.1.254, lip=10.1.248.31, TLS dovecot: Feb 26 11:50:53 Info: IMAP(user7): Disconnected: Logged out dovecot: Feb 26 11:50:53 Info: imap-login: Disconnected: rip=10.1.15.170, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:50:54 Info: imap-login: Login: user=<user1>, method=PLAIN, rip=10.1.1.254, lip=10.1.248.31, TLS dovecot: Feb 26 11:50:57 Info: IMAP(user3): Disconnected: Logged out dovecot: Feb 26 11:50:57 Info: imap-login: Login: user=<user8>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:50:57 Info: IMAP(user8): Disconnected dovecot: Feb 26 11:50:58 Info: imap-login: Login: user=<user9>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:50:58 Info: IMAP(user9): Disconnected dovecot: Feb 26 11:50:59 Info: imap-login: Login: user=<user10>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:50:59 Info: IMAP(user10): Disconnected dovecot: Feb 26 11:51:00 Info: imap-login: Login: user=<user11>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:00 Info: IMAP(user11): Disconnected dovecot: Feb 26 11:51:01 Info: imap-login: Login: user=<user12>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:01 Info: IMAP(user12): Disconnected dovecot: Feb 26 11:51:02 Info: imap-login: Login: user=<user13>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:02 Info: IMAP(user13): Disconnected dovecot: Feb 26 11:51:03 Info: imap-login: Login: user=<user14>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:03 Info: IMAP(user14): Disconnected dovecot: Feb 26 11:51:04 Info: imap-login: Login: user=<user15>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:04 Info: IMAP(user15): Disconnected dovecot: Feb 26 11:51:05 Info: imap-login: Login: user=<user16>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:05 Info: IMAP(user16): Disconnected dovecot: Feb 26 11:51:06 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:06 Info: IMAP(user17): Disconnected: Logged out dovecot: Feb 26 11:51:07 Info: imap-login: Login: user=<user16>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:08 Info: imap-login: Login: user=<user9>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:08 Info: IMAP(user9): Disconnected dovecot: Feb 26 11:51:09 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:09 Info: IMAP(user17): Disconnected: Logged out dovecot: Feb 26 11:51:10 Info: IMAP(user18): Disconnected: Logged out dovecot: Feb 26 11:51:10 Info: imap-login: Login: user=<user10>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:10 Info: imap-login: Login: user=<user8>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:10 Info: IMAP(user8): Disconnected: Logged out dovecot: Feb 26 11:51:11 Info: IMAP(user10): Disconnected: Logged out dovecot: Feb 26 11:51:11 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:11 Info: imap-login: Login: user=<user19>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:11 Info: IMAP(user19): Disconnected: Logged out dovecot: Feb 26 11:51:12 Info: IMAP(user17): Disconnected dovecot: Feb 26 11:51:12 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:12 Info: imap-login: Login: user=<user9>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:12 Info: IMAP(user17): Disconnected: Logged out dovecot: Feb 26 11:51:13 Info: imap-login: Login: user=<user19>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:13 Info: imap-login: Login: user=<user8>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:14 Info: IMAP(user19): Disconnected: Logged out dovecot: Feb 26 11:51:14 Info: IMAP(user8): Disconnected: Logged out dovecot: Feb 26 11:51:14 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:14 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:15 Info: IMAP(user17): Disconnected: Logged out dovecot: Feb 26 11:51:15 Info: IMAP(user17): Disconnected dovecot: Feb 26 11:51:15 Info: imap-login: Login: user=<user19>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:15 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:15 Info: IMAP(user17): Disconnected dovecot: Feb 26 11:51:16 Info: IMAP(user19): Disconnected: Logged out dovecot: Feb 26 11:51:16 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:16 Info: imap-login: Login: user=<user15>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:16 Info: IMAP(user17): Disconnected dovecot: Feb 26 11:51:16 Info: IMAP(user15): Disconnected: Logged out dovecot: Feb 26 11:51:17 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:17 Info: IMAP(user17): Disconnected dovecot: Feb 26 11:51:21 Info: imap-login: Login: user=<user12>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:21 Info: IMAP(user12): Disconnected: Logged out dovecot: Feb 26 11:51:21 Info: imap-login: Login: user=<user17>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:21 Info: IMAP(user17): Disconnected: Logged out dovecot: Feb 26 11:51:22 Info: imap-login: Login: user=<user12>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:22 Info: IMAP(user12): Disconnected: Logged out dovecot: Feb 26 11:51:22 Info: imap-login: Login: user=<user12>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:23 Info: IMAP(user12): Disconnected: Logged out dovecot: Feb 26 11:51:31 Info: imap-login: Login: user=<user15>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:31 Info: IMAP(user15): Disconnected: Logged out dovecot: Feb 26 11:51:31 Info: imap-login: Login: user=<user15>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:31 Info: IMAP(user15): Disconnected: Logged out dovecot: Feb 26 11:51:53 Info: imap-login: Login: user=<user20>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:51:54 Info: IMAP(user20): Disconnected: Logged out dovecot: Feb 26 11:51:59 Info: imap-login: Login: user=<user1>, method=PLAIN, rip=10.1.1.254, lip=10.1.248.31, TLS dovecot: Feb 26 11:52:01 Info: imap-login: Login: user=<user21>, method=PLAIN, rip=129.49.95.41, lip=10.1.248.31, TLS dovecot: Feb 26 11:53:07 Info: IMAP(user16): Disconnected dovecot: Feb 26 11:53:08 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:53:08 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:53:08 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:53:08 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:53:08 Info: imap-login: Disconnected: rip=10.1.20.233, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:53:08 Info: imap-login: Disconnected: rip=10.1.1.254, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:53:08 Info: imap-login: Disconnected: rip=10.1.15.170, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:53:08 Info: imap-login: Login: user=<user21>, method=PLAIN, rip=129.49.95.41, lip=10.1.248.31, TLS dovecot: Feb 26 11:53:09 Info: imap-login: Login: user=<user22>, method=PLAIN, rip=10.1.15.187, lip=10.1.248.31, TLS dovecot: Feb 26 11:53:09 Info: imap-login: Login: user=<user23>, method=PLAIN, rip=10.1.15.170, lip=10.1.248.31, TLS dovecot: Feb 26 11:53:10 Info: imap-login: Login: user=<user24>, method=PLAIN, rip=68.8.68.149, lip=10.1.248.31, TLS dovecot: Feb 26 11:53:12 Info: IMAP(user9): Disconnected dovecot: Feb 26 11:53:29 Info: IMAP(user25): Disconnected: Logged out dovecot: Feb 26 11:53:29 Info: imap-login: Login: user=<user26>, method=PLAIN, rip=216.9.249.213, lip=10.1.248.31, TLS dovecot: Feb 26 11:53:30 Info: IMAP(user26): Disconnected: Logged out dovecot: Feb 26 11:53:31 Info: imap-login: Login: user=<user24>, method=PLAIN, rip=68.8.68.149, lip=10.1.248.31, TLS dovecot: Feb 26 11:54:40 Info: IMAP(user27): Disconnected: Logged out dovecot: Feb 26 11:54:40 Info: IMAP(user27): Disconnected: Logged out dovecot: Feb 26 11:54:41 Info: imap-login: Disconnected: rip=10.1.15.156, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:54:41 Info: imap-login: Disconnected: rip=10.1.15.170, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:54:42 Info: imap-login: Login: user=<user28>, method=PLAIN, rip=10.1.2.21, lip=10.1.248.31, TLS dovecot: Feb 26 11:54:43 Info: imap-login: Disconnected: Shutting down: rip=10.1.15.207, lip=10.1.248.31, TLS dovecot: Feb 26 11:54:44 Info: imap-login: Login: user=<user22>, method=PLAIN, rip=10.1.15.187, lip=10.1.248.31, TLS dovecot: Feb 26 11:54:44 Info: IMAP(user22): Disconnected: Logged out dovecot: Feb 26 11:54:45 Info: imap-login: Login: user=<user29>, method=PLAIN, rip=10.1.15.147, lip=10.1.248.31, TLS dovecot: Feb 26 11:55:42 Info: IMAP(user28): Disconnected: Logged out dovecot: Feb 26 11:55:42 Info: IMAP(user28): Disconnected: Logged out dovecot: Feb 26 11:55:42 Info: IMAP(user28): Disconnected: Logged out dovecot: Feb 26 11:55:43 Info: IMAP(user28): Disconnected: Logged out dovecot: Feb 26 11:55:43 Info: IMAP(user28): Disconnected: Logged out dovecot: Feb 26 11:55:43 Info: imap-login: Disconnected: rip=10.1.20.232, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:55:43 Info: imap-login: Disconnected: rip=10.1.2.21, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:55:43 Info: imap-login: Login: user=<user29>, method=PLAIN, rip=10.1.15.147, lip=10.1.248.31, TLS dovecot: Feb 26 11:55:43 Info: imap-login: Login: user=<user6>, method=PLAIN, rip=10.1.20.128, lip=10.1.248.31, TLS dovecot: Feb 26 11:55:43 Info: imap-login: Login: user=<user16>, method=PLAIN, rip=10.1.15.207, lip=10.1.248.31, TLS dovecot: Feb 26 11:55:44 Info: imap-login: Login: user=<user29>, method=PLAIN, rip=10.1.15.147, lip=10.1.248.31, TLS dovecot: Feb 26 11:55:44 Info: imap-login: Disconnected: rip=10.1.20.233, lip=10.1.248.31, TLS dovecot: Feb 26 11:55:45 Info: imap-login: Login: user=<user18>, method=PLAIN, rip=10.1.15.142, lip=10.1.248.31, TLS dovecot: Feb 26 11:56:45 Info: IMAP(user29): Disconnected: Logged out dovecot: Feb 26 11:56:45 Info: IMAP(user29): Disconnected: Logged out dovecot: Feb 26 11:56:45 Info: IMAP(user29): Disconnected: Logged out dovecot: Feb 26 11:56:45 Info: imap-login: Disconnected: rip=10.1.15.147, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:56:45 Info: imap-login: Login: user=<user1>, method=PLAIN, rip=10.1.1.254, lip=10.1.248.31, TLS dovecot: Feb 26 11:56:45 Info: imap-login: Login: user=<user18>, method=PLAIN, rip=10.1.15.142, lip=10.1.248.31, TLS dovecot: Feb 26 11:56:45 Info: IMAP(user18): Disconnected: Logged out dovecot: Feb 26 11:56:46 Info: imap-login: Disconnected: rip=10.1.2.21, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:56:46 Info: imap-login: Disconnected: rip=10.1.2.21, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:56:47 Info: IMAP(user30): Disconnected for inactivity dovecot: Feb 26 11:56:47 Info: imap-login: Disconnected: rip=10.1.2.21, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:56:47 Info: imap-login: Disconnected: rip=10.1.2.21, lip=10.1.248.31, TLS handshake dovecot: Feb 26 11:56:48 Info: imap-login: Login: user=<user31>, method=PLAIN, rip=160.111.107.74, lip=10.1.248.31, TLS dovecot: Feb 26 11:56:48 Info: imap-login: Login: user=<user1>, method=PLAIN, rip=10.1.1.254, lip=10.1.248.31, TLS dovecot: Feb 26 11:56:48 Info: imap-login: Login: user=<user32>, method=PLAIN, rip=10.1.15.139, lip=10.1.248.31, TLS dovecot: Feb 26 11:56:52 Info: IMAP(user1): Disconnected: Logged out dovecot: Feb 26 11:56:53 Info: imap-login: Login: user=<user28>, method=PLAIN, rip=10.1.2.21, lip=10.1.248.31, TLS dovecot: Feb 26 11:57:04 Info: IMAP(user28): Disconnected: Logged out dovecot: Feb 26 11:57:04 Info: imap-login: Login: user=<user12>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:57:04 Info: IMAP(user12): Disconnected dovecot: Feb 26 11:57:05 Info: imap-login: Login: user=<user33>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:57:05 Info: IMAP(user33): Disconnected dovecot: Feb 26 11:57:06 Info: imap-login: Login: user=<user16>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:57:06 Info: IMAP(user16): Disconnected dovecot: Feb 26 11:57:07 Info: imap-login: Login: user=<user34>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured dovecot: Feb 26 11:57:07 Info: IMAP(user34): Disconnected dovecot: Feb 26 11:57:09 Info: imap-login: Login: user=<user35>, method=PLAIN, rip=10.1.15.136, lip=10.1.248.31, TLS dovecot: Feb 26 11:57:21 Warning: Killed with signal 15 dovecot: Feb 26 11:57:21 Info: Dovecot v1.0.rc23 starting upuser1