/192.168.7.184/ -/Client - Mozilla Thunderbird (latest version)/ *192.168.7.185* - *Server Dovecot 2.2.19*
# vim dovecot.log
Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be
used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be
used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 auth: Debug: auth client connected (pid=14842)
Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be
used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be
used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 auth: Debug: auth client connected (pid=14843)
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x10, ret=1: before/accept
initialization [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept
initialization [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
client hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
server hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key
exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
server done A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush
data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read
client certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read
client certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
client key exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
certificate verify A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
session ticket A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
change cipher spec A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush
data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation
finished successfully [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation
finished successfully [192.168.7.184]
Oct 04 15:17:45 auth: Debug: client in: AUTH 1 CRAM-MD5
service=imap secured session=Zt5gYkYhjQDAqAe4 lip=192.168.7.185
rip=192.168.7.184 lport=143 rport=59277
Oct 04 15:17:45 auth: Debug: client passdb out: CONT 1
PDU2NzIwMjE3OTU1MDYwMjguMTQ0Mzk2MTA2NUBzZXJ2Nz4=
Oct 04 15:17:45 auth: Debug: client in: CONT 1
c2VtZmx5QGZseTc3Ny5uZXQgNmY2Y2FiNTc3YjQ4ZTE1OGE4NzU4NzkwZjdkNzhmN2U=
(previous base64 data may contain sensitive data)
Oct 04 15:17:45 auth-worker(14845): Debug: Loading modules from directory:
/usr/local/lib/dovecot/auth
Oct 04 15:17:45 auth-worker(14845): Debug:
sql(simon@mydomain.lan,192.168.7.184): query: SELECT username as user,
password FROM mailbox WHERE username = 'simon@mydomain.lan' and active='1'
Oct 04 15:17:45 auth: Debug:
sql(simon@mydomain.lan,192.168.7.184,<Zt5gYkYhjQDAqAe4>): Credentials:
6df356c95df134db8c7ad557c31c752ed2ffcb7a9ff613748af3c43036a7370c
Oct 04 15:17:45 auth: Debug: client passdb out: OK 1
user=simon@mydomain.lan
Oct 04 15:17:45 auth: Debug: master in: REQUEST 3765567489 14836 1
982fc0b6f6ecf6098e257ccac0abbe3d session_pid=14846
request_auth_token
Oct 04 15:17:45 auth-worker(14845): Debug:
sql(simon@mydomain.lan,192.168.7.184): SELECT
'/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS home,
'maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS mail, 1983 AS
uid, 1983 AS gid, CONCAT('*:bytes=', domain.maxquota*1048576) AS quota_rule,
CONCAT('*:bytes=', mailbox.quota) AS quota2_rule FROM mailbox, domain WHERE
username = 'simon@mydomain.lan' AND mailbox.active = '1' AND domain.domain =
'mydomain.lan' AND domain.active = '1'
Oct 04 15:17:45 auth: Debug: master userdb out: USER 3765567489
simon@mydomain.lan
home=/var/spool/mail/mydomain.lan/simon@mydomain.lan
mail=maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan uid=1983
gid=1983 quota_rule=*:bytes=7516192768
quota2_rule=*:bytes=7516192768
auth_token=71e913f2c5640c009de725f121c5bf5a5aa31198
Oct 04 15:17:45 imap-login: Info: Login: user=simon@mydomain.lan,
method=CRAM-MD5, rip=192.168.7.184, lip=192.168.7.185, mpid=14846, TLS,
session=<Zt5gYkYhjQDAqAe4>
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x10, ret=1: before/accept
initialization [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept
initialization [192.168.7.184]
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Loading modules from
directory: /usr/local/lib/dovecot
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Module loaded:
/usr/local/lib/dovecot/lib10_quota_plugin.so
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Module loaded:
/usr/local/lib/dovecot/lib11_imap_quota_plugin.so
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Added userdb setting:
mail=maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Added userdb setting:
plugin/quota2_rule=*:bytes=7516192768
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Added userdb setting:
plugin/quota_rule=*:bytes=7516192768
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Effective uid=1983,
gid=1983, home=/var/spool/mail/mydomain.lan/simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota root:
name=domain_quota backend=dict args=mydomain.lan:proxy::sqldomainquota
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule:
root=domain_quota mailbox=* bytes=7516192768 messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota grace:
root=domain_quota bytes=751619276 (10%)
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota root: name=user_quota
backend=dict args=:proxy::sqluserquota
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule: root=user_quota
mailbox=* bytes=7516192768 messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule: root=user_quota
mailbox=Trash bytes=+1503238553 (20%) messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule: root=user_quota
mailbox=Junk bytes=+1503238553 (20%) messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning:
bytes=7516192768 (100%) messages=0 reverse=no command=quota-exceeded 100
simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning:
bytes=7140383129 (95%) messages=0 reverse=no command=quota-warning 95
simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning:
bytes=6764573491 (90%) messages=0 reverse=no command=quota-warning 90
simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning:
bytes=5637144576 (75%) messages=0 reverse=no command=quota-warning 75
simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota grace:
root=user_quota bytes=751619276 (10%)
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: dict quota:
user=mydomain.lan, uri=proxy::sqldomainquota, noenforcing=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: dict quota:
user=simon@mydomain.lan, uri=proxy::sqluserquota, noenforcing=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: maildir++:
root=/var/spool/mail/mydomain.lan/simon@mydomain.lan, index=, indexpvt=,
control=, inbox=/var/spool/mail/mydomain.lan/simon@mydomain.lan, alt=
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
client hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
server hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key
exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
server done A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush
data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read
client certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read
client certificate A [192.168.7.184]
Oct 04 15:17:45 dict: Error: sql dict: commit failed: Field 'description'
doesn't have a default value
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
client key exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
certificate verify A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read
finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
session ticket A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
change cipher spec A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write
finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush
data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation
finished successfully [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation
finished successfully [192.168.7.184]
Oct 04 15:17:45 auth: Debug: client in: AUTH 1 CRAM-MD5
service=imap secured session=gPtjYkYhjgDAqAe4 lip=192.168.7.185
rip=192.168.7.184 lport=143 rport=59278
Oct 04 15:17:45 auth: Debug: client passdb out: CONT 1
PDYwNDQwODUxNzAwMzE2NDEuMTQ0Mzk2MTA2NUBzZXJ2Nz4=
Oct 04 15:17:45 auth: Debug: client in: CONT 1
c2VtZmx5QGZseTc3Ny5uZXQgZTAzYzdjY2I3OGRmMDE1MmZmOTMzNTdmMzMyMmFmZmU=
(previous base64 data may contain sensitive data)
Oct 04 15:17:45 auth-worker(14845): Debug:
sql(simon@mydomain.lan,192.168.7.184): query: SELECT username as user,
password FROM mailbox WHERE username = 'simon@mydomain.lan' and active='1'
Oct 04 15:17:45 auth: Debug:
sql(simon@mydomain.lan,192.168.7.184,<gPtjYkYhjgDAqAe4>): Credentials:
6df356c95df134db8c7ad557c31c752ed2ffcb7a9ff613748af3c43036a7370c
Oct 04 15:17:45 auth: Debug: client passdb out: OK 1
user=simon@mydomain.lan
Oct 04 15:17:45 auth: Debug: master in: REQUEST 592969729 13563 1
eda35ea2307a82f2dec1b894530f1d09 session_pid=14849
request_auth_token
Oct 04 15:17:45 auth-worker(14845): Debug:
sql(simon@mydomain.lan,192.168.7.184): SELECT
'/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS home,
'maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS mail, 1983 AS
uid, 1983 AS gid, CONCAT('*:bytes=', domain.maxquota*1048576) AS quota_rule,
CONCAT('*:bytes=', mailbox.quota) AS quota2_rule FROM mailbox, domain WHERE
username = 'simon@mydomain.lan' AND mailbox.active = '1' AND domain.domain =
'mydomain.lan' AND domain.active = '1'
Oct 04 15:17:45 auth-worker(14845): Info:
sql(simon@mydomain.lan,192.168.7.184): unknown user
Oct 04 15:17:45 auth: Error:
sql(simon@mydomain.lan,192.168.7.184,<gPtjYkYhjgDAqAe4>): user not found
from userdb
Oct 04 15:17:45 auth: Debug: master userdb out: NOTFOUND 592969729
Oct 04 15:17:45 imap: Error: Authenticated user not found from userdb, auth
lookup id=592969729 (client-pid=13563 client-id=1)
Oct 04 15:17:45 imap-login: Info: Internal login failure (pid=13563 id=1)
(internal failure, 1 successful auths): user=simon@mydomain.lan,
method=CRAM-MD5, rip=192.168.7.184, lip=192.168.7.185, mpid=14849, TLS,
session=<gPtjYkYhjgDAqAe4>
Oct 04 15:17:45 imap-login: Debug: SSL alert: close notify [192.168.7.184]
Oct 04 15:17:52 imap(simon@mydomain.lan): Info: Disconnected: Logged out
in=184 out=1432
Oct 04 15:17:52 imap-login: Debug: SSL alert: close notify [192.168.7.184]
-= END of dovecot.log =-
-- View this message in context: http://dovecot.2317879.n4.nabble.com/More-information-about-Dovecot-2-2-x-qu... Sent from the Dovecot mailing list archive at Nabble.com.