*** Reporter, please consider answering these questions, where appropriate ***
* What led up to the situation?
Fresh install of Dovecot IMAP server with SSL.
Fresh install of Sogo on a different instance from Dovecot server.
* What exactly did you do (or not do) that was effective (or ineffective)?
I add account to SOGo on a remote IMAP server that I could retrieve mails
from Desktop mail client.
* What was the outcome of this action?
Please see attached the log file.
* What outcome did you expect instead?
Connection to a remote IMAP server successfully.
*** End of the template - remove these template lines ***
—Log File
-- SOGo Log
Jul 13 06:49:38 sogod [4645]: <0x0x5643dd010430[NGImap4Client]> TLS started
successfully.
Jul 13 06:49:38 sogod [4645]: <0x0x5643dd010430[NGImap4Client]>
ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched
non-IMAP4 parsing exception UnexpectedEndOfStream: the parsed stream ended
unexpectedly
Jul 13 06:49:38 sogod [4645]: [ERROR]
<0x0x5643dd00e2f0[NGImap4ConnectionManager]> IMAP4 login failed:
Jul 13 06:49:38 sogod [4645]: <0x5643dccac200[SOGoMailAccount]:0> renewing
imap4 password
Jul 13 06:49:38 sogod [4645]: <0x0x5643dd034ef0[NGImap4Client]> TLS started
successfully.
Jul 13 06:49:38 sogod [4645]: <0x0x5643dd034ef0[NGImap4Client]>
ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched
non-IMAP4 parsing exception UnexpectedEndOfStream: the parsed stream ended
unexpectedly
Jul 13 06:49:38 sogod [4645]: [ERROR]
<0x0x5643dd00e2f0[NGImap4ConnectionManager]> IMAP4 login failed:
Jul 13 06:49:38 sogod [4645]: [ERROR] <0x5643dccac200[SOGoMailAccount]:0> Could
not connect IMAP4
Jul 13 06:49:38 sogod [4645]: 203.141.134.112 "GET /SOGo/so/mzch/Mail/0/view
HTTP/1.1" 200 17/0 0.168 - - 4M
Jul 13 06:49:38 sogod [4645]: <0x0x5643dcf5fda0[NGHttpRequest]> got 2 values
for cookie 'XSRF-TOKEN', using first only:
046eab9994feeb60b2bb8f1a867c3e5eec55ac9c,1561253855.lejy384sa9ro.KwYdIDKYPsvb60g
Jul 13 06:49:38 sogod [4645]: <0x0x5643dd04f1e0[NGImap4Client]> TLS started
successfully.
Jul 13 06:49:38 sogod [4645]: <0x0x5643dd04f1e0[NGImap4Client]>
ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched
non-IMAP4 parsing exception UnexpectedEndOfStream: the parsed stream ended
unexpectedly
Jul 13 06:49:38 sogod [4645]: [ERROR]
<0x0x5643dd00e2f0[NGImap4ConnectionManager]> IMAP4 login failed:
Jul 13 06:49:38 sogod [4645]: <0x5643dd046c10[SOGoMailAccount]:0> renewing
imap4 password
Jul 13 06:49:38 sogod [4645]: <0x0x5643dcff3950[NGImap4Client]> TLS started
successfully.
Jul 13 06:49:38 sogod [4645]: <0x0x5643dcff3950[NGImap4Client]>
ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched
non-IMAP4 parsing exception UnexpectedEndOfStream: the parsed stream ended
unexpectedly
Jul 13 06:49:38 sogod [4645]: [ERROR]
<0x0x5643dd00e2f0[NGImap4ConnectionManager]> IMAP4 login failed:
Jul 13 06:49:38 sogod [4645]: [ERROR] <0x5643dd046c10[SOGoMailAccount]:0> Could
not connect IMAP4
Jul 13 06:49:38 sogod [4645]: 203.141.134.112 "POST
/SOGo/so/mzch/Mail/unseenCount HTTP/1.1" 200 21/31 0.145 - - 0
-- Dovecot Log
Jul 12 23:49:38 n03 dovecot: auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Jul 12 23:49:38 n03 dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Jul 12 23:49:38 n03 dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Jul 12 23:49:38 n03 dovecot: auth: Debug: Read auth token secret from
/var/run/dovecot/auth-token-secret.dat
Jul 12 23:49:38 n03 dovecot: auth: Debug: auth client connected (pid=31797)
Jul 12 23:49:38 n03 dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=3PE/boqNIJ/AqM+K#011lip=192.168.207.22#011rip=192.168.207.138#011lport=143#011rport=40736#011ssl_cipher=TLS_AES_256_GCM_SHA384#011ssl_cipher_bits=256#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3#011resp=<hidden>
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug: Loading modules from
directory: /usr/lib/dovecot/modules/auth
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Jul 12 23:49:38 n03 dovecot: auth: Debug: auth client connected (pid=31801)
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<3PE/boqNIJ/AqM+K>): query: SELECT username
as user, password FROM mailbox WHERE username = 'm...@uixis.com' AND active =
'1'
Jul 12 23:49:38 n03 dovecot: auth: Debug: client passdb out:
OK#0111#011user=m...@uixis.com#011
Jul 12 23:49:38 n03 dovecot: auth: Debug: master in:
REQUEST#0111400766465#01131797#0111#0118232a486f12d97195f237ee1009552cb#011session_pid=31803#011request_auth_token
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<3PE/boqNIJ/AqM+K>): SELECT
concat('/var/mail/', maildir) as home, concat('*:bytes=', quota) as quota_rule,
998 as uid, 8 as gid FROM mailbox WHERE active = '1' AND username = (SELECT
goto FROM alias WHERE (address = 'm...@uixis.com' AND alias.active = '1') OR
(address = (SELECT concat('mzch', '@', target_domain) FROM alias_domain where
alias_domain = 'uixis.com' AND alias_domain.active = '1' ) ) )
Jul 12 23:49:38 n03 dovecot: auth: Debug: master userdb out:
USER#0111400766465#011m...@uixis.com#011home=/var/mail/uixis.com/mzch/#011quota_rule=*:bytes=15728640000#011uid=998#011gid=8#011auth_token=eaebbf07f001c23ad59b207de89eafef1a96db9f
Jul 12 23:49:38 n03 dovecot: imap-login: Login: user=<m...@uixis.com>,
method=PLAIN, rip=192.168.207.138, lip=192.168.207.22, mpid=31803, TLS,
session=<3PE/boqNIJ/AqM+K>
Jul 12 23:49:38 n03 dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=xApBboqNIp/AqM+K#011lip=192.168.207.22#011rip=192.168.207.138#011lport=143#011rport=40738#011ssl_cipher=TLS_AES_256_GCM_SHA384#011ssl_cipher_bits=256#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3#011resp=<hidden>
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<xApBboqNIp/AqM+K>): query: SELECT username
as user, password FROM mailbox WHERE username = 'm...@uixis.com' AND active =
'1'
Jul 12 23:49:38 n03 dovecot: auth: Debug: client passdb out:
OK#0111#011user=m...@uixis.com#011
Jul 12 23:49:38 n03 dovecot: imap(m...@uixis.com)<31803><3PE/boqNIJ/AqM+K>:
Connection closed (No commands sent) in=0 out=379 deleted=0 expunged=0
trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
Jul 12 23:49:38 n03 dovecot: auth: Debug: master in:
REQUEST#01111927553#01131801#0111#01154e4b116a9f698a21d0c757fa6c22780#011session_pid=31804#011request_auth_token
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<xApBboqNIp/AqM+K>): SELECT
concat('/var/mail/', maildir) as home, concat('*:bytes=', quota) as quota_rule,
998 as uid, 8 as gid FROM mailbox WHERE active = '1' AND username = (SELECT
goto FROM alias WHERE (address = 'm...@uixis.com' AND alias.active = '1') OR
(address = (SELECT concat('mzch', '@', target_domain) FROM alias_domain where
alias_domain = 'uixis.com' AND alias_domain.active = '1' ) ) )
Jul 12 23:49:38 n03 dovecot: auth: Debug: master userdb out:
USER#01111927553#011m...@uixis.com#011home=/var/mail/uixis.com/mzch/#011quota_rule=*:bytes=15728640000#011uid=998#011gid=8#011auth_token=e7a39fdb4cacb4a23770723458a67e356335f222
Jul 12 23:49:38 n03 dovecot: imap-login: Login: user=<m...@uixis.com>,
method=PLAIN, rip=192.168.207.138, lip=192.168.207.22, mpid=31804, TLS:
read(size=492) failed: Connection reset by peer, session=<xApBboqNIp/AqM+K>
Jul 12 23:49:38 n03 dovecot: imap(m...@uixis.com)<31804><xApBboqNIp/AqM+K>:
Connection closed (No commands sent) in=0 out=379 deleted=0 expunged=0
trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
Jul 12 23:49:38 n03 dovecot: auth: Debug: auth client connected (pid=31805)
Jul 12 23:49:38 n03 dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=HrREboqNJp/AqM+K#011lip=192.168.207.22#011rip=192.168.207.138#011lport=143#011rport=40742#011ssl_cipher=TLS_AES_256_GCM_SHA384#011ssl_cipher_bits=256#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3#011resp=<hidden>
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<HrREboqNJp/AqM+K>): query: SELECT username
as user, password FROM mailbox WHERE username = 'm...@uixis.com' AND active =
'1'
Jul 12 23:49:38 n03 dovecot: auth: Debug: client passdb out:
OK#0111#011user=m...@uixis.com#011
Jul 12 23:49:38 n03 dovecot: auth: Debug: master in:
REQUEST#0113533045761#01131805#0111#011976c2beed8c25e6f7981c031a6af73e8#011session_pid=31807#011request_auth_token
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<HrREboqNJp/AqM+K>): SELECT
concat('/var/mail/', maildir) as home, concat('*:bytes=', quota) as quota_rule,
998 as uid, 8 as gid FROM mailbox WHERE active = '1' AND username = (SELECT
goto FROM alias WHERE (address = 'm...@uixis.com' AND alias.active = '1') OR
(address = (SELECT concat('mzch', '@', target_domain) FROM alias_domain where
alias_domain = 'uixis.com' AND alias_domain.active = '1' ) ) )
Jul 12 23:49:38 n03 dovecot: auth: Debug: master userdb out:
USER#0113533045761#011m...@uixis.com#011home=/var/mail/uixis.com/mzch/#011quota_rule=*:bytes=15728640000#011uid=998#011gid=8#011auth_token=d80e776ce564abf3387668cfb3eb267f3fba06d8
Jul 12 23:49:38 n03 dovecot: imap-login: Login: user=<m...@uixis.com>,
method=PLAIN, rip=192.168.207.138, lip=192.168.207.22, mpid=31807, TLS,
session=<HrREboqNJp/AqM+K>
Jul 12 23:49:38 n03 dovecot: auth: Debug: auth client connected (pid=31808)
Jul 12 23:49:38 n03 dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=Gr5FboqNKJ/AqM+K#011lip=192.168.207.22#011rip=192.168.207.138#011lport=143#011rport=40744#011ssl_cipher=TLS_AES_256_GCM_SHA384#011ssl_cipher_bits=256#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3#011resp=<hidden>
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<Gr5FboqNKJ/AqM+K>): query: SELECT username
as user, password FROM mailbox WHERE username = 'm...@uixis.com' AND active =
'1'
Jul 12 23:49:38 n03 dovecot: auth: Debug: client passdb out:
OK#0111#011user=m...@uixis.com#011
Jul 12 23:49:38 n03 dovecot: imap(m...@uixis.com)<31807><HrREboqNJp/AqM+K>:
Connection closed (No commands sent) in=0 out=379 deleted=0 expunged=0
trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
Jul 12 23:49:38 n03 dovecot: auth: Debug: master in:
REQUEST#0113184525313#01131808#0111#01144e7963d05404dcd882b19fd3ed3d66a#011session_pid=31810#011request_auth_token
Jul 12 23:49:38 n03 dovecot: auth-worker(31800): Debug:
sql(m...@uixis.com,192.168.207.138,<Gr5FboqNKJ/AqM+K>): SELECT
concat('/var/mail/', maildir) as home, concat('*:bytes=', quota) as quota_rule,
998 as uid, 8 as gid FROM mailbox WHERE active = '1' AND username = (SELECT
goto FROM alias WHERE (address = 'm...@uixis.com' AND alias.active = '1') OR
(address = (SELECT concat('mzch', '@', target_domain) FROM alias_domain where
alias_domain = 'uixis.com' AND alias_domain.active = '1' ) ) )
Jul 12 23:49:38 n03 dovecot: auth: Debug: master userdb out:
USER#0113184525313#011m...@uixis.com#011home=/var/mail/uixis.com/mzch/#011quota_rule=*:bytes=15728640000#011uid=998#011gid=8#011auth_token=36ffa7773d8357354c708e6df01793d2d22091fb
Jul 12 23:49:38 n03 dovecot: imap-login: Login: user=<m...@uixis.com>,
method=PLAIN, rip=192.168.207.138, lip=192.168.207.22, mpid=31810, TLS:
read(size=492) failed: Connection reset by peer, session=<Gr5FboqNKJ/AqM+K>
Jul 12 23:49:38 n03 dovecot: imap(m...@uixis.com)<31810><Gr5FboqNKJ/AqM+K>:
Connection closed (No commands sent) in=0 out=379 deleted=0 expunged=0
trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
