I have a problem. I have been running Dovecot 2.2.15 and I'd like to upgrade. My distro
(Slackware) has dovecot 2.2.32 available. I downloaded and installed that, but it didn't work.
No one was able to get messages from the dovecot server on their workstations. The following is
the entire dovecot log file from startup to the last message generated. No more messages went
into the logfile after line 76, even with clients trying to connect. The 174.233.134.88 IP is
from an external user connecting from his iPhone. The normal successful message from this user
are shown at bottom.
I'm suspecting something to do with line 18 where is says "Auth process broken." If anyone has
any insight I'd deeply appreciate it as I'd love to upgrade.
THX -- Mark
1 Nov 24 19:22:24 master: Info: Dovecot v2.2.32 (dfbe293d4) starting up for imap (core dumps disabled)
2 Nov 24 19:22:24 ssl-params: Info: Generating SSL parameters
3 Nov 24 19:22:26 ssl-params: Info: SSL parameters regeneration completed
4 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [174.233.134.88]
5 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [174.233.134.88]
6 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [174.233.134.88]
7 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [174.233.134.88]
8 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [174.233.134.88]
9 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [174.233.134.88]
10 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [174.233.134.88]
11 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [174.233.134.88]
12 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client certificate A [174.233.134.88]
13 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [174.233.134.88]
14 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [174.233.134.88]
15 Nov 24 19:23:02 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
16 Nov 24 19:23:02 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
17 Nov 24 19:23:02 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
18 Nov 24 19:23:02 imap-login: Info: Disconnected: Auth process broken (disconnected before auth was ready, waited 0 secs): user=<>, rip=174.233.134.88, lip=98.102.63.107, TLS handshaking, session=<idAcrMNe8xqu6YZY>
19 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [174.233.134.88]
20 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [174.233.134.88]
21 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [174.233.134.88]
22 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [174.233.134.88]
23 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [174.233.134.88]
24 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [174.233.134.88]
25 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [174.233.134.88]
26 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [174.233.134.88]
27 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client certificate A [174.233.134.88]
28 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [174.233.134.88]
29 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [174.233.134.88]
30 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [174.233.134.88]
31 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read certificate verify A [174.233.134.88]
32 Nov 24 19:23:02 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read finished A [174.233.134.88]
33 Nov 24 19:23:03 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [174.233.134.88]
34 Nov 24 19:23:03 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [174.233.134.88]
35 Nov 24 19:23:03 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [174.233.134.88]
36 Nov 24 19:23:03 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [174.233.134.88]
37 Nov 24 19:23:03 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [174.233.134.88]
38 Nov 24 19:23:03 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [174.233.134.88]
39 Nov 24 19:23:04 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
40 Nov 24 19:23:04 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
41 Nov 24 19:23:04 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
42 Nov 24 19:23:04 imap-login: Info: Disconnected: Auth process broken (disconnected before auth was ready, waited 2 secs): user=<>, rip=174.233.134.88, lip=98.102.63.107, TLS, session=<YGw7rMNe+Rqu6YZY>
43 Nov 24 19:23:04 imap-login: Debug: SSL alert: close notify [174.233.134.88]
44 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [174.233.134.88]
45 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [174.233.134.88]
46 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [174.233.134.88]
47 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [174.233.134.88]
48 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [174.233.134.88]
49 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [174.233.134.88]
50 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [174.233.134.88]
51 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [174.233.134.88]
52 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client certificate A [174.233.134.88]
53 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [174.233.134.88]
54 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [174.233.134.88]
55 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [174.233.134.88]
56 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read certificate verify A [174.233.134.88]
57 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read finished A [174.233.134.88]
58 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [174.233.134.88]
59 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [174.233.134.88]
60 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [174.233.134.88]
61 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [174.233.134.88]
62 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [174.233.134.88]
63 Nov 24 19:23:05 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [174.233.134.88]
64 Nov 24 19:23:08 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
65 Nov 24 19:23:08 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
66 Nov 24 19:23:08 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
67 Nov 24 19:23:08 imap-login: Info: Disconnected: Auth process broken (disconnected before auth was ready, waited 3 secs): user=<>, rip=174.233.134.88, lip=98.102.63.107, TLS, session=<7ZF4rMNe8hqu6YZY>
68 Nov 24 19:23:08 imap-login: Debug: SSL alert: close notify [174.233.134.88]
69 Nov 24 19:23:16 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
70 Nov 24 19:23:16 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
71 Nov 24 19:23:16 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
72 Nov 24 19:23:16 imap-login: Info: Disconnected: Auth process broken (disconnected before auth was ready, waited 0 secs): user=<>, rip=192.168.0.54, lip=192.168.0.2, session=<6bbyrMNeGM/AqAA2>
73 Nov 24 19:24:13 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
74 Nov 24 19:24:13 auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
75 Nov 24 19:24:13 auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
76 Nov 24 19:24:13 imap-login: Info: Disconnected: Auth process broken (disconnected before auth was ready, waited 0 secs): user=<>, rip=192.168.0.52, lip=192.168.0.2, session=<b75YsMNeb9nAqAA0>
Normal OK messages from dovecot 2.2.15:
Nov 24 23:50:49 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [174.233.134.88]
Nov 24 23:50:49 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [174.233.134.88]
Nov 24 23:50:49 auth: Debug: client in: AUTH 1 PLAIN service=imap secured session=vQnEacde6QCu6YZY lip=98.102.63.107 rip=174.233.134.88 lport=993 rport=6889 resp=AG0udGhlbQAhbXRfMTAxOQ== (previous base64 data may contain sensitive data)
Nov 24 23:50:49 auth-worker(17650): Debug: shadow(m.them,174.233.134.88): lookup
Nov 24 23:50:49 auth: Debug: client passdb out: OK 1 user=m.them
Finally, the 2.2.15 doveconf, which I used the same for 2.2.32:
> doveconf -n
# 2.2.15: /usr/local/etc/dovecot/dovecot.conf
# OS: Linux 4.4.88 x86_64 Slackware 14.2
auth_debug = yes
auth_debug_passwords = yes
auth_gssapi_hostname = $ALL
auth_krb5_keytab = /etc/dovecot/dovecot.keytab
auth_mechanisms = plain login gssapi
auth_use_winbind = yes
auth_username_format = %n
auth_verbose = yes
auth_verbose_passwords = plain
disable_plaintext_auth = no
info_log_path = /var/log/dovecot_info
mail_location = maildir:~/Maildir
passdb {
driver = shadow
}
protocols = imap
ssl_cert = </etc/ssl/certs/OHPRS/GoDaddy/Apache/2016-08-10/54e789087d419b6e.crt
ssl_key = </etc/ssl/certs/OHPRS/GoDaddy/mail.ohprs.org.key
userdb {
driver = passwd
}
verbose_ssl = yes