Timeout Leak

Luciano Mannucci luciano at vespaperitivo.it
Thu Mar 16 18:25:41 EET 2017


On Thu, 16 Mar 2017 13:48:27 +0200
Aki Tuomi <aki.tuomi at dovecot.fi> wrote:

> These are always worth looking into. Please do post, also any auth debug
> logs are welcome.
Ok.

Theese the logfile lines:

Mar 14 18:06:12 master: Warning: Killed with signal 15 (by pid=7390 uid=0 code=kill)
Mar 14 18:06:20 auth: Error: net_connect_unix(auth-worker) failed: Connection refused
Mar 14 18:06:42 auth: Warning: Timeout leak: 0x805e480 (auth-request-handler.c:550)
Mar 14 18:06:42 auth: Warning: Timeout leak: 0x805e480 (auth-request-handler.c:550)
Mar 14 18:06:42 auth: Warning: Timeout leak: 0x805e480 (auth-request-handler.c:550)

Here is the logfile.info of the relevant minute (a bit longish, passwors censored :)...

Mar 14 18:06:01 pop3(l.radice_dls): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/7415, size=950442332
Mar 14 18:06:01 auth: Debug: auth client connected (pid=7375)
Mar 14 18:06:01 auth: Debug: client in: AUTH	3	LOGIN	service=smtp	nologin	lip=212.45.144.70	rip=89.248.171.132
Mar 14 18:06:01 auth: Debug: client passdb out: CONT	3	VXNlcm5hbWU6
Mar 14 18:06:01 auth: Debug: client in: CONT	3	XXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:01 auth: Debug: client passdb out: CONT	3	UGFzc3dvcmQ6
Mar 14 18:06:01 auth: Debug: client in: CONT	3	XXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:01 auth-worker(6538): Debug: pam(admin at bilink.net,89.248.171.132): lookup service=dovecot
Mar 14 18:06:01 auth-worker(6538): Debug: pam(admin at bilink.net,89.248.171.132): #1/1 style=1 msg=Password: 
Mar 14 18:06:02 auth: Debug: auth client connected (pid=7377)
Mar 14 18:06:02 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=zgbC17NKLOvAqAvR	lip=192.168.134.44	rip=192.168.11.209lport=110	rport=60204
Mar 14 18:06:02 auth: Debug: client passdb out: CONT	1	
Mar 14 18:06:02 auth: Debug: client in: CONT	1	XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:02 auth-worker(7121): Debug: pam(m.castrechini_mms,192.168.11.209,<zgbC17NKLOvAqAvR>): lookup service=dovecot
Mar 14 18:06:02 auth-worker(7121): Debug: pam(m.castrechini_mms,192.168.11.209,<zgbC17NKLOvAqAvR>): #1/1 style=1 msg=Password: 
Mar 14 18:06:02 auth: Debug: client passdb out: OK	1	user=m.castrechini_mms	
Mar 14 18:06:03 auth: Debug: master in: REQUEST	2912419841	7377	1	e4d4a4c42ae38c0214a0def0bb0f0915	session_pid=7378
Mar 14 18:06:03 auth: Debug: passwd(m.castrechini_mms,192.168.11.209,<zgbC17NKLOvAqAvR>): userdb cache hit: system_groups_user=m.castrechini_mms	uid=3002	gid=111	home=/home/m.castrechini_mms
Mar 14 18:06:03 auth: Debug: master userdb out: USER	2912419841	m.castrechini_mms	system_groups_user=m.castrechini_mms	uid=3002	gid=111	home=/home/m.castrechini_mms
Mar 14 18:06:03 pop3-login: Info: Login: user=<m.castrechini_mms>, method=PLAIN, rip=192.168.11.209, lip=192.168.134.44, mpid=7378, session=<zgbC17NKLOvAqAvR>
Mar 14 18:06:03 pop3(m.castrechini_mms): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:03 auth-worker(6538): Info: pam(admin at bilink.net,89.248.171.132): unknown user
Mar 14 18:06:05 auth: Debug: client passdb out: FAIL	3	user=admin at bilink.net
Mar 14 18:06:06 auth: Debug: auth client connected (pid=7380)
Mar 14 18:06:06 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=khD317NKD+PAqAtY	lip=192.168.134.44	rip=192.168.11.88	lport=110	rport=58127	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:06 auth-worker(6538): Debug: pam(a.zurlo_mms,192.168.11.88,<khD317NKD+PAqAtY>): lookup service=dovecot
Mar 14 18:06:06 auth-worker(6538): Debug: pam(a.zurlo_mms,192.168.11.88,<khD317NKD+PAqAtY>): #1/1 style=1 msg=Password: 
Mar 14 18:06:06 auth: Debug: client passdb out: OK	1	user=a.zurlo_mms	
Mar 14 18:06:06 auth: Debug: master in: REQUEST	3493330945	7380	1	e4c2a1b6ab1b7ede85f4fd8611a960c8	session_pid=7382
Mar 14 18:06:06 auth: Debug: passwd(a.zurlo_mms,192.168.11.88,<khD317NKD+PAqAtY>): userdb cache hit: system_groups_user=a.zurlo_mms	uid=3005	gid=111	home=/home/a.zurlo_mms
Mar 14 18:06:06 auth: Debug: master userdb out: USER	3493330945	a.zurlo_mms	system_groups_user=a.zurlo_mms	uid=3005	gid=111	home=/home/a.zurlo_mms
Mar 14 18:06:06 pop3-login: Info: Login: user=<a.zurlo_mms>, method=PLAIN, rip=192.168.11.88, lip=192.168.134.44, mpid=7382, session=<khD317NKD+PAqAtY>
Mar 14 18:06:06 pop3(a.zurlo_mms): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:06 auth: Debug: auth client connected (pid=7383)
Mar 14 18:06:06 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=KP/817NKEuPAqAtY	lip=192.168.134.44	rip=192.168.11.88	lport=110	rport=58130	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:06 auth-worker(6538): Debug: pam(controllovideorobot_mms,192.168.11.88,<KP/817NKEuPAqAtY>): lookup service=dovecot
Mar 14 18:06:06 auth-worker(6538): Debug: pam(controllovideorobot_mms,192.168.11.88,<KP/817NKEuPAqAtY>): #1/1 style=1 msg=Password: 
Mar 14 18:06:06 auth: Debug: client passdb out: OK	1	user=controllovideorobot_mms	
Mar 14 18:06:06 auth: Debug: master in: REQUEST	1922301953	7383	1	233822ae3d04cb50fb2e019e50750e2e	session_pid=7384
Mar 14 18:06:06 auth: Debug: passwd(controllovideorobot_mms,192.168.11.88,<KP/817NKEuPAqAtY>): userdb cache hit: system_groups_user=controllovideorobot_mmsuid=3008	gid=111	home=/home/controllovideorobot_mms
Mar 14 18:06:06 auth: Debug: master userdb out: USER	1922301953	controllovideorobot_mms	system_groups_user=controllovideorobot_mms	uid=3008	gid=111	home=/home/controllovideorobot_mms
Mar 14 18:06:06 pop3-login: Info: Login: user=<controllovideorobot_mms>, method=PLAIN, rip=192.168.11.88, lip=192.168.134.44, mpid=7384, session=<KP/817NKEuPAqAtY>
Mar 14 18:06:06 pop3(controllovideorobot_mms): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:08 imap(info_eml): Info: Logged out in=557 out=45291
Mar 14 18:06:08 imap(info_eml): Info: Logged out in=91 out=801
Mar 14 18:06:12 imap(mau_mct): Info: Server shutting down. in=1273 out=27116
Mar 14 18:06:12 imap(mau_mct): Info: Server shutting down. in=296 out=3481
Mar 14 18:06:12 imap(mau_mct): Info: Server shutting down. in=528 out=1528
Mar 14 18:06:12 imap(mau_mct): Info: Server shutting down. in=1090 out=24607
Mar 14 18:06:12 imap(mau_mct): Info: Server shutting down. in=568 out=10682
Mar 14 18:06:12 imap(milena): Info: Server shutting down. in=87414 out=316725
Mar 14 18:06:12 imap(mau_mct): Info: Server shutting down. in=1005 out=49462
Mar 14 18:06:12 imap(alessandro.lucchini_pds): Info: Server shutting down. in=1512 out=3937
Mar 14 18:06:12 imap(studiofrasi): Info: Server shutting down. in=144 out=1263
Mar 14 18:06:12 imap(mau_mct): Info: Server shutting down. in=519 out=1483
Mar 14 18:06:12 imap(alessandro.lucchini_pds): Info: Server shutting down. in=382 out=1808
Mar 14 18:06:12 imap(presidente_pfp): Info: Server shutting down. in=1367 out=4035
Mar 14 18:06:12 imap(presidente_pfp): Info: Server shutting down. in=1455 out=2839
Mar 14 18:06:12 imap(presidente_pfp): Info: Server shutting down. in=997 out=2359
Mar 14 18:06:13 pop3(enricoarienti_cpx): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/224, size=31522996
Mar 14 18:06:15 auth: Debug: client in: AUTH	3	LOGIN	service=smtp	nologin	lip=212.45.144.44	rip=93.174.95.34
Mar 14 18:06:15 auth: Debug: client passdb out: CONT	3	VXNlcm5hbWU6
Mar 14 18:06:15 auth: Debug: client in: CONT	3	XXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:15 auth: Debug: client passdb out: CONT	3	UGFzc3dvcmQ6
Mar 14 18:06:15 auth: Debug: client in: CONT	3	XXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:20 imap(presidente_pfp): Info: Server shutting down. in=7841 out=38312
Mar 14 18:06:20 auth: Debug: client in: AUTH	7	LOGIN	service=smtp	nologin	lip=212.45.144.44	rip=94.102.58.20
Mar 14 18:06:20 auth: Debug: client passdb out: CONT	7	VXNlcm5hbWU6
Mar 14 18:06:20 auth: Debug: client in: CONT	7	XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:20 auth: Debug: client passdb out: CONT	7	UGFzc3dvcmQ6
Mar 14 18:06:20 auth: Debug: client in: CONT	7	XXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:25 master: Info: Dovecot v2.2.28 (bed8434) starting up for pop3, imap
Mar 14 18:06:27 auth: Debug: Loading modules from directory: /usr/lib/dovecot/auth
Mar 14 18:06:27 auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat
Mar 14 18:06:27 auth: Debug: auth client connected (pid=7425)
Mar 14 18:06:28 auth: Debug: auth client connected (pid=7427)
Mar 14 18:06:28 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=u35A2bNKZNYC5OBN	lip=212.45.144.44	rip=2.228.224.77	lport=110	rport=54884	resp=XXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:28 auth-worker(7428): Debug: Loading modules from directory: /usr/lib/dovecot/auth
Mar 14 18:06:28 auth-worker(7428): Debug: pam(info_mpw,2.228.224.77,<u35A2bNKZNYC5OBN>): lookup service=dovecot
Mar 14 18:06:28 auth-worker(7428): Debug: pam(info_mpw,2.228.224.77,<u35A2bNKZNYC5OBN>): #1/1 style=1 msg=Password: 
Mar 14 18:06:28 auth: Debug: client passdb out: OK	1	user=info_mpw	
Mar 14 18:06:28 auth: Debug: master in: REQUEST	1603010561	7427	1	91eec6a77f3c053d100bfd66724d2bf8	session_pid=7429
Mar 14 18:06:28 auth: Debug: passwd(info_mpw,2.228.224.77,<u35A2bNKZNYC5OBN>): userdb cache miss
Mar 14 18:06:28 auth-worker(7428): Debug: passwd(info_mpw,2.228.224.77,<u35A2bNKZNYC5OBN>): lookup
Mar 14 18:06:28 auth: Debug: master userdb out: USER	1603010561	info_mpw	system_groups_user=info_mpw	uid=2766	gid=111	home=/home/info_mpw
Mar 14 18:06:28 pop3-login: Info: Login: user=<info_mpw>, method=PLAIN, rip=2.228.224.77, lip=212.45.144.44, mpid=7429, session=<u35A2bNKZNYC5OBN>
Mar 14 18:06:28 pop3(info_mpw): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/156, size=21305074
Mar 14 18:06:28 auth: Debug: auth client connected (pid=7430)
Mar 14 18:06:28 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=mRpC2bNKZtYC5OBN	lip=212.45.144.44	rip=2.228.224.77	lport=110	rport=54886	resp=XXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:28 auth-worker(7428): Debug: pam(info_auv,2.228.224.77,<mRpC2bNKZtYC5OBN>): lookup service=dovecot
Mar 14 18:06:28 auth-worker(7428): Debug: pam(info_auv,2.228.224.77,<mRpC2bNKZtYC5OBN>): #1/1 style=1 msg=Password: 
Mar 14 18:06:28 auth: Debug: client passdb out: OK	1	user=info_auv	
Mar 14 18:06:28 auth: Debug: master in: REQUEST	3943038977	7430	1	2c8b6c326334aca7e7cb662f218ff917	session_pid=7431
Mar 14 18:06:28 auth: Debug: passwd(info_auv,2.228.224.77,<mRpC2bNKZtYC5OBN>): userdb cache miss
Mar 14 18:06:28 auth-worker(7428): Debug: passwd(info_auv,2.228.224.77,<mRpC2bNKZtYC5OBN>): lookup
Mar 14 18:06:28 auth: Debug: master userdb out: USER	3943038977	info_auv	system_groups_user=info_auv	uid=2719	gid=111	home=/home/info_auv
Mar 14 18:06:28 pop3-login: Info: Login: user=<info_auv>, method=PLAIN, rip=2.228.224.77, lip=212.45.144.44, mpid=7431, session=<mRpC2bNKZtYC5OBN>
Mar 14 18:06:28 pop3(info_auv): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/21, size=1691958
Mar 14 18:06:28 auth: Debug: client in: AUTH	1	PLAIN	service=imap	session=3sNC2bNKP602zbWH	lip=212.45.144.44	rip=54.205.181.135lport=143	rport=44351	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:28 auth-worker(7428): Debug: pam(presidente_pfp,54.205.181.135,<3sNC2bNKP602zbWH>): lookup service=dovecot
Mar 14 18:06:28 auth-worker(7428): Debug: pam(presidente_pfp,54.205.181.135,<3sNC2bNKP602zbWH>): #1/1 style=1 msg=Password: 
Mar 14 18:06:28 auth: Debug: client passdb out: OK	1	user=presidente_pfp	
Mar 14 18:06:28 auth: Debug: master in: REQUEST	1901068289	7425	1	5fe7716d8d250abfdf4ff45a3305cfe6	session_pid=7433	request_auth_token
Mar 14 18:06:28 auth: Debug: passwd(presidente_pfp,54.205.181.135,<3sNC2bNKP602zbWH>): userdb cache miss
Mar 14 18:06:28 auth-worker(7428): Debug: passwd(presidente_pfp,54.205.181.135,<3sNC2bNKP602zbWH>): lookup
Mar 14 18:06:28 auth: Debug: master userdb out: USER	1901068289	presidente_pfp	system_groups_user=presidente_pfp	uid=2343	gid=111	home=/home/presidente_pfp	auth_token=ecf98b41fdd6c8455c79daec0e131d886ec24a4d
Mar 14 18:06:28 imap-login: Info: Login: user=<presidente_pfp>, method=PLAIN, rip=54.205.181.135, lip=212.45.144.44, mpid=7433, session=<3sNC2bNKP602zbWH>
Mar 14 18:06:28 auth: Debug: client in: AUTH	4	LOGIN	service=smtp	nologin	lip=212.45.144.44	rip=93.174.93.18
Mar 14 18:06:28 auth: Debug: client passdb out: CONT	4	VXNlcm5hbWU6
Mar 14 18:06:28 auth: Debug: client in: CONT	4	XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:28 auth: Debug: client passdb out: CONT	4	UGFzc3dvcmQ6
Mar 14 18:06:28 auth: Debug: client in: CONT	4	XXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:32 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=RguE2bNKqMJf8bzq	lip=212.45.144.70	rip=95.241.188.234lport=110	rport=49832	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:33 auth: Debug: auth client connected (pid=7436)
Mar 14 18:06:33 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=4XKV2bNKan/AqKeg	lip=192.168.134.44	rip=192.168.167.160lport=110	rport=32618
Mar 14 18:06:33 auth: Debug: client passdb out: CONT	1	
Mar 14 18:06:33 auth: Debug: client in: CONT	1	XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:33 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<4XKV2bNKan/AqKeg>): lookup service=dovecot
Mar 14 18:06:33 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<4XKV2bNKan/AqKeg>): #1/1 style=1 msg=Password: 
Mar 14 18:06:33 auth: Debug: client passdb out: OK	1	user=dabbene_mct	
Mar 14 18:06:33 auth: Debug: master in: REQUEST	2830106625	7436	1	99d57dabac099af0f5f1a719a38325d7	session_pid=7437
Mar 14 18:06:33 auth: Debug: passwd(dabbene_mct,192.168.167.160,<4XKV2bNKan/AqKeg>): userdb cache miss
Mar 14 18:06:33 auth-worker(7428): Debug: passwd(dabbene_mct,192.168.167.160,<4XKV2bNKan/AqKeg>): lookup
Mar 14 18:06:33 auth: Debug: master userdb out: USER	2830106625	dabbene_mct	system_groups_user=dabbene_mct	uid=3384	gid=111	home=/home/dabbene_mct
Mar 14 18:06:33 pop3-login: Info: Login: user=<dabbene_mct>, method=PLAIN, rip=192.168.167.160, lip=192.168.134.44, mpid=7437, session=<4XKV2bNKan/AqKeg>
Mar 14 18:06:33 pop3(dabbene_mct): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/9450, size=1755467592
Mar 14 18:06:34 auth: Debug: auth client connected (pid=7438)
Mar 14 18:06:34 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=qASe2bNKbH/AqKeg	lip=192.168.134.44	rip=192.168.167.160lport=110	rport=32620
Mar 14 18:06:34 auth: Debug: client passdb out: CONT	1	
Mar 14 18:06:34 auth: Debug: client in: CONT	1	XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:34 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<qASe2bNKbH/AqKeg>): lookup service=dovecot
Mar 14 18:06:34 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<qASe2bNKbH/AqKeg>): #1/1 style=1 msg=Password: 
Mar 14 18:06:34 auth: Debug: client passdb out: OK	1	user=dabbene_mct	
Mar 14 18:06:34 auth: Debug: master in: REQUEST	770310145	7438	1	a8d9f74f6a53257915bd79f7efd1123a	session_pid=7439
Mar 14 18:06:34 auth: Debug: passwd(dabbene_mct,192.168.167.160,<qASe2bNKbH/AqKeg>): userdb cache hit: system_groups_user=dabbene_mct	uid=3384	gid=111	home=/home/dabbene_mct
Mar 14 18:06:34 auth: Debug: master userdb out: USER	770310145	dabbene_mct	system_groups_user=dabbene_mct	uid=3384	gid=111	home=/home/dabbene_mct
Mar 14 18:06:34 pop3-login: Info: Login: user=<dabbene_mct>, method=PLAIN, rip=192.168.167.160, lip=192.168.134.44, mpid=7439, session=<qASe2bNKbH/AqKeg>
Mar 14 18:06:34 pop3(dabbene_mct): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/9450, size=1755467592
Mar 14 18:06:34 auth: Debug: auth client connected (pid=7440)
Mar 14 18:06:34 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=Jgqk2bNKbn/AqKeg	lip=192.168.134.44	rip=192.168.167.160lport=110	rport=32622
Mar 14 18:06:34 auth: Debug: client passdb out: CONT	1	
Mar 14 18:06:34 auth: Debug: client in: CONT	1	XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:34 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<Jgqk2bNKbn/AqKeg>): lookup service=dovecot
Mar 14 18:06:34 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<Jgqk2bNKbn/AqKeg>): #1/1 style=1 msg=Password: 
Mar 14 18:06:34 auth: Debug: client passdb out: OK	1	user=dabbene_mct	
Mar 14 18:06:34 auth: Debug: master in: REQUEST	380239873	7440	1	65ec4289d0817fac99e77a6748b572b0	session_pid=7441
Mar 14 18:06:34 auth: Debug: passwd(dabbene_mct,192.168.167.160,<Jgqk2bNKbn/AqKeg>): userdb cache hit: system_groups_user=dabbene_mct	uid=3384	gid=111	home=/home/dabbene_mct
Mar 14 18:06:34 auth: Debug: master userdb out: USER	380239873	dabbene_mct	system_groups_user=dabbene_mct	uid=3384	gid=111	home=/home/dabbene_mct
Mar 14 18:06:34 pop3-login: Info: Login: user=<dabbene_mct>, method=PLAIN, rip=192.168.167.160, lip=192.168.134.44, mpid=7441, session=<Jgqk2bNKbn/AqKeg>
Mar 14 18:06:34 pop3(dabbene_mct): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/9450, size=1755467592
Mar 14 18:06:34 auth: Debug: auth client connected (pid=7443)
Mar 14 18:06:34 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=N3yq2bNKcH/AqKeg	lip=192.168.134.44	rip=192.168.167.160lport=110	rport=32624
Mar 14 18:06:34 auth: Debug: client passdb out: CONT	1	
Mar 14 18:06:34 auth: Debug: client in: CONT	1	XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:34 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<N3yq2bNKcH/AqKeg>): lookup service=dovecot
Mar 14 18:06:34 auth-worker(7428): Debug: pam(dabbene_mct,192.168.167.160,<N3yq2bNKcH/AqKeg>): #1/1 style=1 msg=Password: 
Mar 14 18:06:34 auth: Debug: client passdb out: OK	1	user=dabbene_mct	
Mar 14 18:06:34 auth: Debug: master in: REQUEST	3907125249	7443	1	5e61646a95e7b3f57680a997a6e857db	session_pid=7444
Mar 14 18:06:34 auth: Debug: passwd(dabbene_mct,192.168.167.160,<N3yq2bNKcH/AqKeg>): userdb cache hit: system_groups_user=dabbene_mct	uid=3384	gid=111	home=/home/dabbene_mct
Mar 14 18:06:34 auth: Debug: master userdb out: USER	3907125249	dabbene_mct	system_groups_user=dabbene_mct	uid=3384	gid=111	home=/home/dabbene_mct
Mar 14 18:06:34 pop3-login: Info: Login: user=<dabbene_mct>, method=PLAIN, rip=192.168.167.160, lip=192.168.134.44, mpid=7444, session=<N3yq2bNKcH/AqKeg>
Mar 14 18:06:35 pop3(dabbene_mct): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/9450, size=1755467592
Mar 14 18:06:36 auth: Debug: auth client connected (pid=7445)
Mar 14 18:06:36 auth: Debug: client in: AUTH	1	PLAIN	service=imap	secured	no-penalty	session=pKbC2bNKvcrAqIYQ	lip=192.168.134.44rip=192.168.134.16	lport=143	rport=51901	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:36 auth-worker(7428): Debug: pam(pteros_gan,192.168.134.16,<pKbC2bNKvcrAqIYQ>): lookup service=dovecot
Mar 14 18:06:36 auth-worker(7428): Debug: pam(pteros_gan,192.168.134.16,<pKbC2bNKvcrAqIYQ>): #1/1 style=1 msg=Password: 
Mar 14 18:06:36 auth: Debug: client passdb out: OK	1	user=pteros_gan	
Mar 14 18:06:36 auth: Debug: master in: REQUEST	2847801345	7445	1	7cdbea1c357d06b96e9440d1cf0a5aae	session_pid=7446	request_auth_token
Mar 14 18:06:36 auth: Debug: passwd(pteros_gan,192.168.134.16,<pKbC2bNKvcrAqIYQ>): userdb cache miss
Mar 14 18:06:36 auth-worker(7428): Debug: passwd(pteros_gan,192.168.134.16,<pKbC2bNKvcrAqIYQ>): lookup
Mar 14 18:06:36 auth: Debug: master userdb out: USER	2847801345	pteros_gan	system_groups_user=pteros_gan	uid=3264	gid=111	home=/home/pteros_gan	auth_token=e8801f4334e57f578eba11e501062d2a221a76ec
Mar 14 18:06:36 imap-login: Info: Login: user=<pteros_gan>, method=PLAIN, rip=192.168.134.16, lip=192.168.134.44, mpid=7446, secured, session=<pKbC2bNKvcrAqIYQ>
Mar 14 18:06:37 imap(pteros_gan): Info: Logged out in=92 out=993
Mar 14 18:06:41 auth: Debug: auth client connected (pid=7449)
Mar 14 18:06:41 auth: Debug: client in: AUTH	1	PLAIN	service=imap	session=HkkJ2rNKJs5dISSB	lip=212.45.144.44	rip=93.33.36.129	lport=143	rport=52774	resp=XXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:41 auth-worker(7428): Debug: pam(milena,93.33.36.129,<HkkJ2rNKJs5dISSB>): lookup service=dovecot
Mar 14 18:06:41 auth-worker(7428): Debug: pam(milena,93.33.36.129,<HkkJ2rNKJs5dISSB>): #1/1 style=1 msg=Password: 
Mar 14 18:06:41 auth: Debug: client passdb out: OK	1	user=milena	
Mar 14 18:06:41 auth: Debug: master in: REQUEST	2300051457	7449	1	1c19961e792ebed350ce962c74eca78a	session_pid=7451	request_auth_token
Mar 14 18:06:41 auth: Debug: passwd(milena,93.33.36.129,<HkkJ2rNKJs5dISSB>): userdb cache miss
Mar 14 18:06:41 auth-worker(7428): Debug: passwd(milena,93.33.36.129,<HkkJ2rNKJs5dISSB>): lookup
Mar 14 18:06:41 auth: Debug: master userdb out: USER	2300051457	milena	system_groups_user=milena	uid=2049	gid=111	home=/home/milena	auth_token=e3057d97e713495f979aad9b9d74454e1a8aa532
Mar 14 18:06:41 imap-login: Info: Login: user=<milena>, method=PLAIN, rip=93.33.36.129, lip=212.45.144.44, mpid=7451, session=<HkkJ2rNKJs5dISSB>
Mar 14 18:06:42 pop3(carnevali): Info: Server shutting down. top=0/0, retr=0/0, del=0/1407, size=134075183
Mar 14 18:06:42 pop3(board_cwl): Info: Server shutting down. top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:42 pop3-login: Info: Disconnected: Shutting down (disconnected while authenticating, waited 10 secs): user=<>, method=PLAIN, rip=95.241.188.234, lip=212.45.144.70, session=<RguE2bNKqMJf8bzq>
Mar 14 18:06:42 auth: Debug: client in: CANCEL	1
Mar 14 18:06:47 auth: Debug: auth client connected (pid=7452)
Mar 14 18:06:47 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=bE5l2rNKoPVf8bzq	lip=212.45.144.70	rip=95.241.188.234lport=110	rport=62880	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX(previous base64 data may contain sensitive data)
Mar 14 18:06:47 auth-worker(7428): Debug: pam(m.ceriani_dls,95.241.188.234,<bE5l2rNKoPVf8bzq>): lookup service=dovecot
Mar 14 18:06:47 auth-worker(7428): Debug: pam(m.ceriani_dls,95.241.188.234,<bE5l2rNKoPVf8bzq>): #1/1 style=1 msg=Password: 
Mar 14 18:06:47 auth: Debug: client passdb out: OK	1	user=m.ceriani_dls	
Mar 14 18:06:47 auth: Debug: master in: REQUEST	4273209345	7452	1	bdc6b6e0ff022b2b36b73145f7c8e49f	session_pid=7453
Mar 14 18:06:47 auth: Debug: passwd(m.ceriani_dls,95.241.188.234,<bE5l2rNKoPVf8bzq>): userdb cache miss
Mar 14 18:06:47 auth-worker(7428): Debug: passwd(m.ceriani_dls,95.241.188.234,<bE5l2rNKoPVf8bzq>): lookup
Mar 14 18:06:47 auth: Debug: master userdb out: USER	4273209345	m.ceriani_dls	system_groups_user=m.ceriani_dls	uid=3370	gid=111	home=/home/m.ceriani_dls
Mar 14 18:06:47 pop3-login: Info: Login: user=<m.ceriani_dls>, method=PLAIN, rip=95.241.188.234, lip=212.45.144.70, mpid=7453, session=<bE5l2rNKoPVf8bzq>
Mar 14 18:06:47 pop3(m.ceriani_dls): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:51 auth: Debug: auth client connected (pid=7458)
Mar 14 18:06:51 auth: Debug: auth client connected (pid=7459)
Mar 14 18:06:51 auth: Debug: auth client connected (pid=7460)
Mar 14 18:06:51 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=Cg+l2rNKyMJPGI56	lip=212.45.144.44	rip=79.24.142.122	lport=110	rport=49864	resp=XXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:51 auth-worker(7428): Debug: pam(lombardi,79.24.142.122,<Cg+l2rNKyMJPGI56>): lookup service=dovecot
Mar 14 18:06:51 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=PBal2rNKme9PGI56	lip=212.45.144.44	rip=79.24.142.122	lport=110	rport=61337	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:51 auth-worker(7428): Debug: pam(lombardi,79.24.142.122,<Cg+l2rNKyMJPGI56>): #1/1 style=1 msg=Password: 
Mar 14 18:06:51 auth: Debug: client passdb out: OK	1	user=lombardi	
Mar 14 18:06:51 auth: Debug: master in: REQUEST	3172204545	7458	1	a5455141079bfe1cd3f6ab39db6a79b5	session_pid=7462
Mar 14 18:06:51 auth: Debug: passwd(lombardi,79.24.142.122,<Cg+l2rNKyMJPGI56>): userdb cache miss
Mar 14 18:06:51 auth-worker(7428): Debug: passwd(lombardi,79.24.142.122,<Cg+l2rNKyMJPGI56>): lookup
Mar 14 18:06:51 auth: Debug: master userdb out: USER	3172204545	lombardi	system_groups_user=lombardi	uid=1637	gid=111	home=/home/lombardi
Mar 14 18:06:51 pop3-login: Info: Login: user=<lombardi>, method=PLAIN, rip=79.24.142.122, lip=212.45.144.44, mpid=7462, session=<Cg+l2rNKyMJPGI56>
Mar 14 18:06:51 auth-worker(7461): Debug: Loading modules from directory: /usr/lib/dovecot/auth
Mar 14 18:06:51 auth-worker(7461): Debug: pam(mara.lombardi_pds,79.24.142.122,<PBal2rNKme9PGI56>): lookup service=dovecot
Mar 14 18:06:51 auth-worker(7461): Debug: pam(mara.lombardi_pds,79.24.142.122,<PBal2rNKme9PGI56>): #1/1 style=1 msg=Password: 
Mar 14 18:06:51 auth: Debug: client passdb out: OK	1	user=mara.lombardi_pds	
Mar 14 18:06:51 auth: Debug: master in: REQUEST	799670273	7459	1	0137c0af693e392e968a6539a56c0150	session_pid=7463
Mar 14 18:06:51 auth: Debug: passwd(mara.lombardi_pds,79.24.142.122,<PBal2rNKme9PGI56>): userdb cache miss
Mar 14 18:06:51 auth-worker(7428): Debug: passwd(mara.lombardi_pds,79.24.142.122,<PBal2rNKme9PGI56>): lookup
Mar 14 18:06:51 auth: Debug: master userdb out: USER	799670273	mara.lombardi_pds	system_groups_user=mara.lombardi_pds	uid=2498	gid=111	home=/home/mara.lombardi_pds
Mar 14 18:06:51 pop3-login: Info: Login: user=<mara.lombardi_pds>, method=PLAIN, rip=79.24.142.122, lip=212.45.144.44, mpid=7463, session=<PBal2rNKme9PGI56>
Mar 14 18:06:51 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=Mv6l2rNKJMtPGI56	lip=212.45.144.44	rip=79.24.142.122	lport=110	rport=52004	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXus base64 data may contain sensitive data)
Mar 14 18:06:51 auth-worker(7428): Debug: pam(clmara_mrc,79.24.142.122,<Mv6l2rNKJMtPGI56>): lookup service=dovecot
Mar 14 18:06:51 auth-worker(7428): Debug: pam(clmara_mrc,79.24.142.122,<Mv6l2rNKJMtPGI56>): #1/1 style=1 msg=Password: 
Mar 14 18:06:51 auth: Debug: client passdb out: OK	1	user=clmara_mrc	
Mar 14 18:06:51 auth: Debug: master in: REQUEST	1579548673	7460	1	29fc24ff3e462806e1633496ff00838c	session_pid=7464
Mar 14 18:06:51 auth: Debug: passwd(clmara_mrc,79.24.142.122,<Mv6l2rNKJMtPGI56>): userdb cache miss
Mar 14 18:06:51 auth-worker(7428): Debug: passwd(clmara_mrc,79.24.142.122,<Mv6l2rNKJMtPGI56>): lookup
Mar 14 18:06:51 auth: Debug: master userdb out: USER	1579548673	clmara_mrc	system_groups_user=clmara_mrc	uid=2429	gid=111	home=/home/clmara_mrc
Mar 14 18:06:51 pop3-login: Info: Login: user=<clmara_mrc>, method=PLAIN, rip=79.24.142.122, lip=212.45.144.44, mpid=7464, session=<Mv6l2rNKJMtPGI56>
Mar 14 18:06:51 pop3(lombardi): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:51 pop3(mara.lombardi_pds): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:51 pop3(clmara_mrc): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0
Mar 14 18:06:56 auth: Debug: auth client connected (pid=7467)
Mar 14 18:06:57 auth: Debug: client in: AUTH	1	PLAIN	service=imap	secured	session=O00C27NKqfqXQs+K	lip=212.45.144.44	rip=151.66.207.138	lport=993	rport=64169	local_name=baobab.bilink.net	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:57 auth-worker(7428): Debug: pam(gloria_mct,151.66.207.138,<O00C27NKqfqXQs+K>): lookup service=dovecot
Mar 14 18:06:57 auth-worker(7428): Debug: pam(gloria_mct,151.66.207.138,<O00C27NKqfqXQs+K>): #1/1 style=1 msg=Password: 
Mar 14 18:06:57 auth: Debug: client passdb out: OK	1	user=gloria_mct	
Mar 14 18:06:57 auth: Debug: master in: REQUEST	1863581697	7467	1	5de654b8e8dc647f0f1caadf293acb0d	session_pid=7470	request_auth_token
Mar 14 18:06:57 auth: Debug: passwd(gloria_mct,151.66.207.138,<O00C27NKqfqXQs+K>): userdb cache miss
Mar 14 18:06:57 auth-worker(7428): Debug: passwd(gloria_mct,151.66.207.138,<O00C27NKqfqXQs+K>): lookup
Mar 14 18:06:57 auth: Debug: master userdb out: USER	1863581697	gloria_mct	system_groups_user=gloria_mct	uid=2052	gid=111	home=/home/gloria_mct	auth_token=965428ab0cd3e9840929cb145aa4b695cf7102f4
Mar 14 18:06:57 imap-login: Info: Login: user=<gloria_mct>, method=PLAIN, rip=151.66.207.138, lip=212.45.144.44, mpid=7470, TLS, session=<O00C27NKqfqXQs+K>
Mar 14 18:06:58 auth: Debug: auth client connected (pid=7471)
Mar 14 18:06:58 auth: Debug: client in: AUTH	1	PLAIN	service=pop3	session=WXwT27NKY41KfVKS	lip=212.45.144.44	rip=74.125.82.146	lport=110	rport=36195	resp=XXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:58 auth-worker(7428): Debug: pam(rod_mcs,74.125.82.146,<WXwT27NKY41KfVKS>): lookup service=dovecot
Mar 14 18:06:58 auth-worker(7428): Debug: pam(rod_mcs,74.125.82.146,<WXwT27NKY41KfVKS>): #1/1 style=1 msg=Password: 
Mar 14 18:06:58 auth: Debug: client passdb out: OK	1	user=rod_mcs	
Mar 14 18:06:58 auth: Debug: master in: REQUEST	1814953985	7471	1	31068e449668e6b779966eb3d0913b90	session_pid=7472
Mar 14 18:06:58 auth: Debug: passwd(rod_mcs,74.125.82.146,<WXwT27NKY41KfVKS>): userdb cache miss
Mar 14 18:06:58 auth-worker(7428): Debug: passwd(rod_mcs,74.125.82.146,<WXwT27NKY41KfVKS>): lookup
Mar 14 18:06:58 auth: Debug: master userdb out: USER	1814953985	rod_mcs	system_groups_user=rod_mcs	uid=3478	gid=111	home=/home/rod_mcs
Mar 14 18:06:58 pop3-login: Info: Login: user=<rod_mcs>, method=PLAIN, rip=74.125.82.146, lip=212.45.144.44, mpid=7472, session=<WXwT27NKY41KfVKS>
Mar 14 18:06:59 auth: Debug: auth client connected (pid=7473)
Mar 14 18:06:59 auth: Debug: client in: AUTH	1	PLAIN	service=imap	secured	session=3r0e27NK4dWXQs+K	lip=212.45.144.44	rip=151.66.207.138	lport=993	rport=54753	local_name=baobab.bilink.net	resp=XXXXXXXXXXXXXXXXXXXXXXXXXXXX (previous base64 data may contain sensitive data)
Mar 14 18:06:59 auth-worker(7428): Debug: pam(gloria_mct,151.66.207.138,<3r0e27NK4dWXQs+K>): lookup service=dovecot
Mar 14 18:06:59 auth-worker(7428): Debug: pam(gloria_mct,151.66.207.138,<3r0e27NK4dWXQs+K>): #1/1 style=1 msg=Password: 
Mar 14 18:06:59 auth: Debug: client passdb out: OK	1	user=gloria_mct	
Mar 14 18:06:59 auth: Debug: master in: REQUEST	776994817	7473	1	a5fc0b1823093916d7af6bccfe478d0b	session_pid=7474	request_auth_token
Mar 14 18:06:59 auth: Debug: passwd(gloria_mct,151.66.207.138,<3r0e27NK4dWXQs+K>): userdb cache hit: system_groups_user=gloria_mct	uid=2052	gid=111	home=/home/gloria_mct
Mar 14 18:06:59 auth: Debug: master userdb out: USER	776994817	gloria_mct	system_groups_user=gloria_mct	uid=2052	gid=111	home=/home/gloria_mct	auth_token=4abadc259a1dd45540394cbdefe390a198bcbd80
Mar 14 18:06:59 imap-login: Info: Login: user=<gloria_mct>, method=PLAIN, rip=151.66.207.138, lip=212.45.144.44, mpid=7474, TLS, session=<3r0e27NK4dWXQs+K>
Mar 14 18:06:59 pop3(rod_mcs): Info: Disconnected: Logged out top=0/0, retr=0/0, del=0/334, size=78892358



And Here is my doveconf -n:

# 2.2.28 (bed8434): /usr/local/etc/dovecot/dovecot.conf
# Pigeonhole version 0.4.17 (e179378)
# OS: Linux 3.0.101-105-pae i686 openSUSE 11.4 (i586) ext3
auth_cache_size = 3 k
auth_debug = yes
auth_debug_passwords = yes
auth_mechanisms = plain login
auth_verbose = yes
default_client_limit = 1249
default_vsz_limit = 712 M
disable_plaintext_auth = no
first_valid_gid = 0
first_valid_uid = 100
info_log_path = /var/log/dovecot/logfile.info
listen = *
log_path = /var/log/dovecot/logfile
login_greeting = Dovecot at Baobab ready.
login_trusted_networks = 127.0.0.0/8 212.45.144.0/24 192.168.134.0/24
mail_location = mbox:/var/spool/mailboxes/%u:INBOX=/var/spool/mail/%u:DIRNAME=mbox:INDEX=/var/dovecot_indexes/%u
maildir_copy_with_hardlinks = no
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate mime foreverypart extracttext
mbox_lock_timeout = 443 secs
namespace {
  inbox = yes
  location = 
  prefix = 
  separator = .
  type = private
}
passdb {
  driver = pam
}
plugin {
  mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
  mail_log_fields = uid box msgid size
}
protocols = pop3 imap
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
  user = root
}
service imap-login {
  inet_listener imaps {
    address = *
  }
  process_limit = 512
}
service pop3-login {
  chroot = 
  executable = pop3-login -D
  inet_listener pop3s {
    address = *
  }
  process_limit = 512
}
ssl_ca = </etc/ssl/ca.crt
ssl_cert = </etc/ssl/certs/dovecot.pem
ssl_key =  # hidden, use -P to show it
userdb {
  driver = passwd
}
version_ignore = yes
protocol imap {
  imap_client_workarounds = delay-newmail
  mail_plugins = mail_log notify
}
protocol pop3 {
  pop3_client_workarounds = outlook-no-nuls oe-ns-eoh
  pop3_enable_last = yes
}
protocol lda {
  info_log_path = /var/log/dovecot/lda.log
  log_path = /var/log/dovecot/lda-errors.log
  postmaster_address = postmaster at mcs.it
}

Cheers,

Luciano.
-- 
 /"\                         /Via A. Salaino, 7 - 20144 Milano (Italy)
 \ /  ASCII RIBBON CAMPAIGN / PHONE : +39 2 485781 FAX: +39 2 48578250
  X   AGAINST HTML MAIL    /  E-MAIL: posthamster at sublink.sublink.ORG
 / \  AND POSTINGS        /   WWW: http://www.lesassaie.IT/


More information about the dovecot mailing list