dovecot-debug.log

gistfile1.txt

==> /var/log/dovecot-debug.log <==
Dec 04 18:09:32 auth: Debug: client in: AUTH    14      PLAIN   service=imap    secured session=3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB       lip=::1 rip=::1 lport=143       rport=52264     resp=<hidden>
Dec 04 18:09:32 auth: Debug: pam([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Performing passdb lookup
Dec 04 18:09:32 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<27>: Handling PASSV request
Dec 04 18:09:32 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<27>: pam([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Performing passdb lookup
Dec 04 18:09:32 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<27>: pam([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): lookup service=dovecot
Dec 04 18:09:32 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<27>: pam([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): #1/1 style=1 msg=Password: 
///**** Here there are 2 secondo of delay!!! 
Dec 04 18:09:34 auth: Debug: pam([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Finished passdb lookup
Dec 04 18:09:34 auth: Debug: sql([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Performing passdb lookup
Dec 04 18:09:34 auth: Debug: sql([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): cache hit: <hidden> [email protected]
Dec 04 18:09:34 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<27>: pam([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Finished passdb lookup
Dec 04 18:09:34 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<27>: Finished: user_unknown
Dec 04 18:09:34 auth: Debug: sql([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Finished passdb lookup
Dec 04 18:09:34 auth: Debug: auth([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Auth request finished
Dec 04 18:09:34 auth: Debug: client passdb out: OK      14      [email protected]
Dec 04 18:09:34 auth: Debug: master in: REQUEST 1909456897      9534    14      4ee0e7e7c134a28ff1765817f9eab62f      session_pid=9793 request_auth_token
Dec 04 18:09:34 auth: Debug: passwd([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Performing userdb lookup
Dec 04 18:09:34 auth: Debug: passwd([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): userdb cache miss
Dec 04 18:09:34 auth: Debug: passwd([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Finished userdb lookup
Dec 04 18:09:34 auth: Debug: sql([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Performing userdb lookup
Dec 04 18:09:34 auth: Debug: sql([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): userdb cache hit: home=/var/mail/vmail/felics.club/admin/  uid=501 gid=501 quota_rule=*:bytes=0
Dec 04 18:09:34 auth: Debug: sql([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Finished userdb lookup
Dec 04 18:09:34 auth: Debug: master userdb out: USER    1909456897      [email protected]       home=/var/mail/vmail/felics.club/admin/        uid=501 gid=501 quota_rule=*:bytes=0    auth_mech=PLAIN auth_token=3208852fa1a7070d2b1c7f3b2110b2e811ea66b1
Dec 04 18:09:34 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<28>: Handling USER request
Dec 04 18:09:34 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<28>: passwd([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Performing userdb lookup
Dec 04 18:09:34 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<28>: passwd([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): lookup
Dec 04 18:09:34 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<28>: passwd([email protected],::1,<3esMBbMLKMwAAAAAAAAAAAAAAAAAAAAB>): Finished userdb lookup
Dec 04 18:09:34 auth-worker(9537): Debug: conn unix:auth-worker (pid=9536,uid=102): auth-worker<28>: Finished: user_unknown