Upgrade to 2.2.32 from 2.2.15 failed

Sat Nov 25 09:18:19 EET 2017

No, is that something that would make a difference between 2.2.15 and 2.2.32?

--Mark

On Fri, 24 Nov 2017 21:37:47 -0800 Gary <lists at lazygranch.com> wrote:

> Out of curiosity, do you do a !SSLv3 in the conf file? 
>
>
>   Original Message  
>> From: mfoley at ohprs.org
>> Sent: November 24, 2017 9:04 PM
>> To: dovecot at dovecot.org
>> Subject: Upgrade to 2.2.32 from 2.2.15 failed
>>
>> 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