thr3ads.net - dovecot - [Dovecot] unknown users [Jan 2013]

If this information is useful, please help other people find it:
Share via:

Averlon

2013-Jan-07 19:00 UTC

[Dovecot] unknown users

Hi,
can anyone tell me where these "unknown users" come from.

As far as I see the fact, dovecot is asked by postfix to look for the
password of the recipient-user (why ever).

+++
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: initializing the
server-side TLS engine
Jan  7 19:43:09 f42252se postfix/tlsmgr[14627]: open smtpd TLS cache
btree:/var/lib/postfix/smtpd_scache
Jan  7 19:43:09 f42252se postfix/tlsmgr[14627]: tlsmgr_cache_run_event:
start TLS smtpd session cache cleanup
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: connect from
f42252ud.averlon.loc[192.168.110.165]
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: setting up TLS connection
from f42252ud.averlon.loc[192.168.110.165]
Jan  7 19:43:09 f42252se postfix/smtpd[14625]:
f42252ud.averlon.loc[192.168.110.165]: TLS cipher list
"aNULL:-aNULL:ALL:+RC4:@STRENGTH"
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:before/accept
initialization
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 read
client hello A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
server hello A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
certificate A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
key exchange A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
server done A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 flush data
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 read
client key exchange A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 read
finished A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
session ticket A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
change cipher spec A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
finished A
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 flush data
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: Anonymous TLS connection
established from f42252ud.averlon.loc[192.168.110.165]: TLSv1 with
cipher ECDHE-RSA-AES256-SHA (256/256 bits)
Jan  7 19:43:09 f42252se dovecot: auth: Debug: Loading modules from
directory: /usr/lib/dovecot/modules/auth
Jan  7 19:43:09 f42252se dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libauthdb_ldap.so
Jan  7 19:43:09 f42252se dovecot: auth: Debug: auth client connected
(pid=14625)
Jan  7 19:43:09 f42252se dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=smtp#011nologin#011lip=192.168.110.150#011rip=192.168.110.165#011secured#011resp=<hidden>
Jan  7 19:43:09 f42252se dovecot: auth: Debug:
ldap(avadmin,192.168.110.165): pass search:
base=ou=user,dc=averlon,dc=loc scope=onelevel
filter=(&(objectClass=posixAccount)(uid=avadmin)) fields=uid,userPassword
Jan  7 19:43:09 f42252se dovecot: auth: Debug:
ldap(avadmin,192.168.110.165): result: uid(user)=avadmin
userPassword(password)=<hidden>
Jan  7 19:43:09 f42252se dovecot: auth: Debug: client out:
OK#0111#011user=avadmin
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: 9A86C30007C:
client=f42252ud.averlon.loc[192.168.110.165], sasl_method=PLAIN,
sasl_username=avadmin
Jan  7 19:43:09 f42252se postfix/cleanup[14631]: 9A86C30007C:
message-id=<50EB173B.5090109 at av.loc>
Jan  7 19:43:09 f42252se postfix/qmgr[14561]: 9A86C30007C:
from=<avadmin at av.loc>, size=1227, nrcpt=1 (queue active)
Jan  7 19:43:09 f42252se postfix/smtpd[14625]: disconnect from
f42252ud.averlon.loc[192.168.110.165]
Jan  7 19:43:11 f42252se postfix/pickup[14560]: BE0AC30007F: uid=5002
from=<avadmin at av.loc>
Jan  7 19:43:11 f42252se postfix/cleanup[14631]: BE0AC30007F:
message-id=<50EB173B.5090109 at av.loc>
Jan  7 19:43:11 f42252se postfix/qmgr[14561]: BE0AC30007F:
from=<avadmin at av.loc>, size=1534, nrcpt=1 (queue active)
Jan  7 19:43:11 f42252se postfix/pipe[14632]: 9A86C30007C:
to=<redmine at averlon.loc>, relay=spamassassin, delay=2.2,
delays=0.05/0/0/2.1, dsn=2.0.0, status=sent (delivered via spamassassin
service)
Jan  7 19:43:11 f42252se postfix/qmgr[14561]: 9A86C30007C: removed
Jan  7 19:43:11 f42252se dovecot: auth: Debug: master in:
USER#0111#011redmine at averlon.loc#011service=lda
Jan  7 19:43:11 f42252se dovecot: auth: Debug:
ldap(redmine at averlon.loc): pass search: base=ou=user,dc=averlon,dc=loc
scope=onelevel
filter=(&(objectClass=posixAccount)(uid=redmine at averlon.loc))
fields=uid,userPassword
Jan  7 19:43:11 f42252se dovecot: auth: ldap(redmine at averlon.loc):
*unknown user*
Jan  7 19:43:11 f42252se dovecot: auth: Debug: master out: NOTFOUND#0111
Jan  7 19:43:11 f42252se postfix/pipe[14637]: BE0AC30007F:
to=<redmine at averlon.loc>, relay=dovecot, delay=0.02, delays=0/0/0/0.01,
dsn=5.1.1, status=bounced (user unknown)
Jan  7 19:43:11 f42252se postfix/cleanup[14631]: C279030007E:
message-id=<20130107184311.C279030007E at mail.av.loc>
Jan  7 19:43:11 f42252se postfix/qmgr[14561]: C279030007E: from=<>,
size=3182, nrcpt=1 (queue active)
Jan  7 19:43:11 f42252se postfix/bounce[14639]: BE0AC30007F: sender
non-delivery notification: C279030007E
Jan  7 19:43:11 f42252se postfix/qmgr[14561]: BE0AC30007F: removed
Jan  7 19:43:11 f42252se dovecot: auth: Debug: master in:
USER#0111#011avadmin at av.loc#011service=lda
Jan  7 19:43:11 f42252se dovecot: auth: Debug: ldap(avadmin at av.loc):
pass search: base=ou=user,dc=averlon,dc=loc scope=onelevel
filter=(&(objectClass=posixAccount)(uid=avadmin at av.loc))
fields=uid,userPassword
Jan  7 19:43:11 f42252se dovecot: auth: ldap(avadmin at av.loc): *unknown user*
Jan  7 19:43:11 f42252se dovecot: auth: Debug: master out: NOTFOUND#0111
Jan  7 19:43:11 f42252se postfix/pipe[14637]: C279030007E:
to=<avadmin at av.loc>, relay=dovecot, delay=0.01, delays=0/0/0/0.01,
dsn=5.1.1, status=bounced (user unknown)
Jan  7 19:43:11 f42252se postfix/qmgr[14561]: C279030007E: removed
Jan  7 19:43:21 f42252se dovecot: auth: Debug: auth client connected
(pid=14644)
Jan  7 19:43:21 f42252se dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=pop3#011secured#011lip=192.168.110.150#011rip=192.168.110.165#011lport=995#011rport=43070
Jan  7 19:43:21 f42252se dovecot: auth: Debug: client out: CONT#0111#011
Jan  7 19:43:21 f42252se dovecot: auth: Debug: client in: CONT<hidden>
Jan  7 19:43:21 f42252se dovecot: auth: Debug:
ldap(qx42252006,192.168.110.165): pass search:
base=ou=user,dc=averlon,dc=loc scope=onelevel
filter=(&(objectClass=posixAccount)(uid=qx42252006)) fields=uid,userPassword
Jan  7 19:43:21 f42252se dovecot: auth: Debug:
ldap(qx42252006,192.168.110.165): result: uid(user)=qx42252006
userPassword(password)=<hidden>
Jan  7 19:43:21 f42252se dovecot: auth: Debug: client out:
OK#0111#011user=qx42252006
Jan  7 19:43:21 f42252se dovecot: auth: Debug: master in:
REQUEST#0113145334785#01114644#0111#0115f6241afb0ff05d6b901a9a1edd65840
Jan  7 19:43:21 f42252se dovecot: auth: Debug: master out:
USER#0113145334785#011qx42252006#011uid=5000#011gid=5000#011home=/home/vmail/qx42252006
Jan  7 19:43:21 f42252se dovecot: pop3-login: Login: user=<qx42252006>,
method=PLAIN, rip=192.168.110.165, lip=192.168.110.150, mpid=14646, TLS
Jan  7 19:43:21 f42252se dovecot: pop3(qx42252006): Disconnected: Logged
out top=0/0, retr=0/0, del=0/0, size=0
Jan  7 19:43:27 f42252se dovecot: auth: Debug: auth client connected
(pid=14649)
Jan  7 19:43:28 f42252se dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=pop3#011secured#011lip=192.168.110.150#011rip=192.168.110.165#011lport=995#011rport=43071
Jan  7 19:43:28 f42252se dovecot: auth: Debug: client out: CONT#0111#011
Jan  7 19:43:28 f42252se dovecot: auth: Debug: client in: CONT<hidden>
Jan  7 19:43:28 f42252se dovecot: auth: Debug:
ldap(avadmin,192.168.110.165): pass search:
base=ou=user,dc=averlon,dc=loc scope=onelevel
filter=(&(objectClass=posixAccount)(uid=avadmin)) fields=uid,userPassword
Jan  7 19:43:28 f42252se dovecot: auth: Debug:
ldap(avadmin,192.168.110.165): result: uid(user)=avadmin
userPassword(password)=<hidden>
Jan  7 19:43:28 f42252se dovecot: auth: Debug: client out:
OK#0111#011user=avadmin
Jan  7 19:43:28 f42252se dovecot: auth: Debug: master in:
REQUEST#0113661234177#01114649#0111#011abd1ac9fcd3ced2d9b01e090f3703ac0
Jan  7 19:43:28 f42252se dovecot: auth: Debug: master out:
USER#0113661234177#011avadmin#011uid=5000#011gid=5000#011home=/home/vmail/avadmin
Jan  7 19:43:28 f42252se dovecot: pop3-login: Login: user=<avadmin>,
method=PLAIN, rip=192.168.110.165, lip=192.168.110.150, mpid=14650, TLS
Jan  7 19:43:28 f42252se dovecot: pop3(avadmin): Disconnected: Logged
out top=0/0, retr=0/0, del=0/2, size=4872
Jan  7 19:44:31 f42252se dovecot: auth: Debug: auth client connected
(pid=14694)
Jan  7 19:44:31 f42252se dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=pop3#011secured#011lip=192.168.110.150#011rip=192.168.110.165#011lport=995#011rport=43073
Jan  7 19:44:31 f42252se dovecot: auth: Debug: client out: CONT#0111#011
Jan  7 19:44:31 f42252se dovecot: auth: Debug: client in: CONT<hidden>
Jan  7 19:44:31 f42252se dovecot: auth: Debug:
ldap(qx42252008,192.168.110.165): pass search:
base=ou=user,dc=averlon,dc=loc scope=onelevel
filter=(&(objectClass=posixAccount)(uid=qx42252008)) fields=uid,userPassword
Jan  7 19:44:31 f42252se dovecot: auth: Debug:
ldap(qx42252008,192.168.110.165): result: uid(user)=qx42252008
userPassword(password)=<hidden>
Jan  7 19:44:31 f42252se dovecot: auth: Debug: client out:
OK#0111#011user=qx42252008
Jan  7 19:44:31 f42252se dovecot: auth: Debug: master in:
REQUEST#011251920385#01114694#0111#011db7eed58edf0149fd176446b57c20a33
Jan  7 19:44:31 f42252se dovecot: auth: Debug: master out:
USER#011251920385#011qx42252008#011uid=5000#011gid=5000#011home=/home/vmail/qx42252008
Jan  7 19:44:31 f42252se dovecot: pop3-login: Login: user=<qx42252008>,
method=PLAIN, rip=192.168.110.165, lip=192.168.110.150, mpid=14698, TLS

+++
Tell me what you need as additional info.

Thanks for help
-- 
Signatur Averlon info

 

Mit freundlichen Gr??en / Kind Regards

Karl-Heinz Fischbach

 

Skype: khfischbach
jabber: averlon at jabber.org
Blog: averlon.posterous.com

Signatur:
Diese e-mail ist unter Umst?nden signiert. Die Signatur entspricht dem
Deutschen Signaturgesetz und entsprechenden europ?ischen Regelungen.
Important Note:
This e-mail may contain trade secrets or privileged, undisclosed or
otherwise confidential information. If you have received this e-mail in
error, you are hereby notified that any review, copying or distribution
of it is strictly prohibited. Please inform us immediately and destroy
the original transmittal.

       
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 3887 bytes
Desc: S/MIME Kryptografische Unterschrift
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20130107/706f00bb/attachment-0004.bin>

Charles Marcus

2013-Jan-07 20:15 UTC

head link

[Dovecot] unknown users

Please TURN OFF verbose logging in postfix. Verbose logs are almost 
never needed, and only make debugging much harder.

On 2013-01-07 2:00 PM, Averlon <c38sgzkz at averlon.net>
wrote:> Hi,
> can anyone tell me where these "unknown users" come from.
>
> As far as I see the fact, dovecot is asked by postfix to look for the
> password of the recipient-user (why ever).
>
> +++
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: initializing the
> server-side TLS engine
> Jan  7 19:43:09 f42252se postfix/tlsmgr[14627]: open smtpd TLS cache
> btree:/var/lib/postfix/smtpd_scache
> Jan  7 19:43:09 f42252se postfix/tlsmgr[14627]: tlsmgr_cache_run_event:
> start TLS smtpd session cache cleanup
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: connect from
> f42252ud.averlon.loc[192.168.110.165]
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: setting up TLS connection
> from f42252ud.averlon.loc[192.168.110.165]
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]:
> f42252ud.averlon.loc[192.168.110.165]: TLS cipher list
> "aNULL:-aNULL:ALL:+RC4:@STRENGTH"
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:before/accept
> initialization
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 read
> client hello A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
> server hello A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
> certificate A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
> key exchange A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
> server done A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 flush data
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 read
> client key exchange A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 read
> finished A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
> session ticket A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
> change cipher spec A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 write
> finished A
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: SSL_accept:SSLv3 flush data
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: Anonymous TLS connection
> established from f42252ud.averlon.loc[192.168.110.165]: TLSv1 with
> cipher ECDHE-RSA-AES256-SHA (256/256 bits)
> Jan  7 19:43:09 f42252se dovecot: auth: Debug: Loading modules from
> directory: /usr/lib/dovecot/modules/auth
> Jan  7 19:43:09 f42252se dovecot: auth: Debug: Module loaded:
> /usr/lib/dovecot/modules/auth/libauthdb_ldap.so
> Jan  7 19:43:09 f42252se dovecot: auth: Debug: auth client connected
> (pid=14625)
> Jan  7 19:43:09 f42252se dovecot: auth: Debug: client in:
>
AUTH#0111#011PLAIN#011service=smtp#011nologin#011lip=192.168.110.150#011rip=192.168.110.165#011secured#011resp=<hidden>
> Jan  7 19:43:09 f42252se dovecot: auth: Debug:
> ldap(avadmin,192.168.110.165): pass search:
> base=ou=user,dc=averlon,dc=loc scope=onelevel
> filter=(&(objectClass=posixAccount)(uid=avadmin))
fields=uid,userPassword
> Jan  7 19:43:09 f42252se dovecot: auth: Debug:
> ldap(avadmin,192.168.110.165): result: uid(user)=avadmin
> userPassword(password)=<hidden>
> Jan  7 19:43:09 f42252se dovecot: auth: Debug: client out:
> OK#0111#011user=avadmin
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: 9A86C30007C:
> client=f42252ud.averlon.loc[192.168.110.165], sasl_method=PLAIN,
> sasl_username=avadmin
> Jan  7 19:43:09 f42252se postfix/cleanup[14631]: 9A86C30007C:
> message-id=<50EB173B.5090109 at av.loc>
> Jan  7 19:43:09 f42252se postfix/qmgr[14561]: 9A86C30007C:
> from=<avadmin at av.loc>, size=1227, nrcpt=1 (queue active)
> Jan  7 19:43:09 f42252se postfix/smtpd[14625]: disconnect from
> f42252ud.averlon.loc[192.168.110.165]
> Jan  7 19:43:11 f42252se postfix/pickup[14560]: BE0AC30007F: uid=5002
> from=<avadmin at av.loc>
> Jan  7 19:43:11 f42252se postfix/cleanup[14631]: BE0AC30007F:
> message-id=<50EB173B.5090109 at av.loc>
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: BE0AC30007F:
> from=<avadmin at av.loc>, size=1534, nrcpt=1 (queue active)
> Jan  7 19:43:11 f42252se postfix/pipe[14632]: 9A86C30007C:
> to=<redmine at averlon.loc>, relay=spamassassin, delay=2.2,
> delays=0.05/0/0/2.1, dsn=2.0.0, status=sent (delivered via spamassassin
> service)
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: 9A86C30007C: removed
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master in:
> USER#0111#011redmine at averlon.loc#011service=lda
> Jan  7 19:43:11 f42252se dovecot: auth: Debug:
> ldap(redmine at averlon.loc): pass search: base=ou=user,dc=averlon,dc=loc
> scope=onelevel
> filter=(&(objectClass=posixAccount)(uid=redmine at averlon.loc))
> fields=uid,userPassword
> Jan  7 19:43:11 f42252se dovecot: auth: ldap(redmine at averlon.loc):
> *unknown user*
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master out: NOTFOUND#0111
> Jan  7 19:43:11 f42252se postfix/pipe[14637]: BE0AC30007F:
> to=<redmine at averlon.loc>, relay=dovecot, delay=0.02,
delays=0/0/0/0.01,
> dsn=5.1.1, status=bounced (user unknown)
> Jan  7 19:43:11 f42252se postfix/cleanup[14631]: C279030007E:
> message-id=<20130107184311.C279030007E at mail.av.loc>
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: C279030007E: from=<>,
> size=3182, nrcpt=1 (queue active)
> Jan  7 19:43:11 f42252se postfix/bounce[14639]: BE0AC30007F: sender
> non-delivery notification: C279030007E
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: BE0AC30007F: removed
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master in:
> USER#0111#011avadmin at av.loc#011service=lda
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: ldap(avadmin at av.loc):
> pass search: base=ou=user,dc=averlon,dc=loc scope=onelevel
> filter=(&(objectClass=posixAccount)(uid=avadmin at av.loc))
> fields=uid,userPassword
> Jan  7 19:43:11 f42252se dovecot: auth: ldap(avadmin at av.loc): *unknown
user*
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master out: NOTFOUND#0111
> Jan  7 19:43:11 f42252se postfix/pipe[14637]: C279030007E:
> to=<avadmin at av.loc>, relay=dovecot, delay=0.01, delays=0/0/0/0.01,
> dsn=5.1.1, status=bounced (user unknown)
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: C279030007E: removed
> Jan  7 19:43:21 f42252se dovecot: auth: Debug: auth client connected
> (pid=14644)
> Jan  7 19:43:21 f42252se dovecot: auth: Debug: client in:
>
AUTH#0111#011PLAIN#011service=pop3#011secured#011lip=192.168.110.150#011rip=192.168.110.165#011lport=995#011rport=43070
> Jan  7 19:43:21 f42252se dovecot: auth: Debug: client out: CONT#0111#011
> Jan  7 19:43:21 f42252se dovecot: auth: Debug: client in:
CONT<hidden>
> Jan  7 19:43:21 f42252se dovecot: auth: Debug:
> ldap(qx42252006,192.168.110.165): pass search:
> base=ou=user,dc=averlon,dc=loc scope=onelevel
> filter=(&(objectClass=posixAccount)(uid=qx42252006))
fields=uid,userPassword
> Jan  7 19:43:21 f42252se dovecot: auth: Debug:
> ldap(qx42252006,192.168.110.165): result: uid(user)=qx42252006
> userPassword(password)=<hidden>
> Jan  7 19:43:21 f42252se dovecot: auth: Debug: client out:
> OK#0111#011user=qx42252006
> Jan  7 19:43:21 f42252se dovecot: auth: Debug: master in:
> REQUEST#0113145334785#01114644#0111#0115f6241afb0ff05d6b901a9a1edd65840
> Jan  7 19:43:21 f42252se dovecot: auth: Debug: master out:
>
USER#0113145334785#011qx42252006#011uid=5000#011gid=5000#011home=/home/vmail/qx42252006
> Jan  7 19:43:21 f42252se dovecot: pop3-login: Login:
user=<qx42252006>,
> method=PLAIN, rip=192.168.110.165, lip=192.168.110.150, mpid=14646, TLS
> Jan  7 19:43:21 f42252se dovecot: pop3(qx42252006): Disconnected: Logged
> out top=0/0, retr=0/0, del=0/0, size=0
> Jan  7 19:43:27 f42252se dovecot: auth: Debug: auth client connected
> (pid=14649)
> Jan  7 19:43:28 f42252se dovecot: auth: Debug: client in:
>
AUTH#0111#011PLAIN#011service=pop3#011secured#011lip=192.168.110.150#011rip=192.168.110.165#011lport=995#011rport=43071
> Jan  7 19:43:28 f42252se dovecot: auth: Debug: client out: CONT#0111#011
> Jan  7 19:43:28 f42252se dovecot: auth: Debug: client in:
CONT<hidden>
> Jan  7 19:43:28 f42252se dovecot: auth: Debug:
> ldap(avadmin,192.168.110.165): pass search:
> base=ou=user,dc=averlon,dc=loc scope=onelevel
> filter=(&(objectClass=posixAccount)(uid=avadmin))
fields=uid,userPassword
> Jan  7 19:43:28 f42252se dovecot: auth: Debug:
> ldap(avadmin,192.168.110.165): result: uid(user)=avadmin
> userPassword(password)=<hidden>
> Jan  7 19:43:28 f42252se dovecot: auth: Debug: client out:
> OK#0111#011user=avadmin
> Jan  7 19:43:28 f42252se dovecot: auth: Debug: master in:
> REQUEST#0113661234177#01114649#0111#011abd1ac9fcd3ced2d9b01e090f3703ac0
> Jan  7 19:43:28 f42252se dovecot: auth: Debug: master out:
>
USER#0113661234177#011avadmin#011uid=5000#011gid=5000#011home=/home/vmail/avadmin
> Jan  7 19:43:28 f42252se dovecot: pop3-login: Login: user=<avadmin>,
> method=PLAIN, rip=192.168.110.165, lip=192.168.110.150, mpid=14650, TLS
> Jan  7 19:43:28 f42252se dovecot: pop3(avadmin): Disconnected: Logged
> out top=0/0, retr=0/0, del=0/2, size=4872
> Jan  7 19:44:31 f42252se dovecot: auth: Debug: auth client connected
> (pid=14694)
> Jan  7 19:44:31 f42252se dovecot: auth: Debug: client in:
>
AUTH#0111#011PLAIN#011service=pop3#011secured#011lip=192.168.110.150#011rip=192.168.110.165#011lport=995#011rport=43073
> Jan  7 19:44:31 f42252se dovecot: auth: Debug: client out: CONT#0111#011
> Jan  7 19:44:31 f42252se dovecot: auth: Debug: client in:
CONT<hidden>
> Jan  7 19:44:31 f42252se dovecot: auth: Debug:
> ldap(qx42252008,192.168.110.165): pass search:
> base=ou=user,dc=averlon,dc=loc scope=onelevel
> filter=(&(objectClass=posixAccount)(uid=qx42252008))
fields=uid,userPassword
> Jan  7 19:44:31 f42252se dovecot: auth: Debug:
> ldap(qx42252008,192.168.110.165): result: uid(user)=qx42252008
> userPassword(password)=<hidden>
> Jan  7 19:44:31 f42252se dovecot: auth: Debug: client out:
> OK#0111#011user=qx42252008
> Jan  7 19:44:31 f42252se dovecot: auth: Debug: master in:
> REQUEST#011251920385#01114694#0111#011db7eed58edf0149fd176446b57c20a33
> Jan  7 19:44:31 f42252se dovecot: auth: Debug: master out:
>
USER#011251920385#011qx42252008#011uid=5000#011gid=5000#011home=/home/vmail/qx42252008
> Jan  7 19:44:31 f42252se dovecot: pop3-login: Login:
user=<qx42252008>,
> method=PLAIN, rip=192.168.110.165, lip=192.168.110.150, mpid=14698, TLS
>
> +++
> Tell me what you need as additional info.
>
> Thanks for help

-- 

Best regards,

Charles Marcus
I.T. Director
Media Brokers International, Inc.
678.514.6200 x224 | 678.514.6299 fax

/dev/rob0

2013-Jan-08 00:11 UTC

head link

[Dovecot] unknown users

On Mon, Jan 07, 2013 at 08:00:37PM +0100, Averlon wrote:> can anyone tell me where these "unknown users" come from.
> Jan 7 19:43:11 f42252se postfix/pipe[14632]: 9A86C30007C: 
> to=<redmine at averlon.loc>, relay=spamassassin, delay=2.2, 
> delays=0.05/0/0/2.1, dsn=2.0.0, status=sent (delivered via 
> spamassassin service)
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: 9A86C30007C: removed
The original message is successfully delivered to your content 
filter.
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master in:
> USER#0111#011redmine at averlon.loc#011service=lda
> Jan 7 19:43:11 f42252se dovecot: auth: Debug: 
> ldap(redmine at averlon.loc): pass search: 
> base=ou=user,dc=averlon,dc=loc scope=onelevel 
> filter=(&(objectClass=posixAccount)(uid=redmine at averlon.loc)) 
> fields=uid,userPassword
Here's one of your LDAP queries.
> Jan  7 19:43:11 f42252se dovecot: auth: ldap(redmine at averlon.loc):
> *unknown user*
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master out: NOTFOUND#0111
> Jan  7 19:43:11 f42252se postfix/pipe[14637]: BE0AC30007F:
> to=<redmine at averlon.loc>, relay=dovecot, delay=0.02,
delays=0/0/0/0.01,
> dsn=5.1.1, status=bounced (user unknown)
The content filter reinjects via sendmail(1), and the pipe(8) to the 
Dovecot LDA fails. Your LDAP query is not returning what you expect, 
or you're not querying for the right thing.
> Jan  7 19:43:11 f42252se postfix/cleanup[14631]: C279030007E:
> message-id=<20130107184311.C279030007E at mail.av.loc>
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: C279030007E: from=<>,
> size=3182, nrcpt=1 (queue active)
> Jan  7 19:43:11 f42252se postfix/bounce[14639]: BE0AC30007F: sender
> non-delivery notification: C279030007E
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: BE0AC30007F: removed
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master in:
> USER#0111#011avadmin at av.loc#011service=lda
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: ldap(avadmin at av.loc):
> pass search: base=ou=user,dc=averlon,dc=loc scope=onelevel
> filter=(&(objectClass=posixAccount)(uid=avadmin at av.loc))
> fields=uid,userPassword
There's another one of your queries, looking up the sender address 
for delivery of the bounce.
> Jan  7 19:43:11 f42252se dovecot: auth: ldap(avadmin at av.loc): *unknown
user*
> Jan  7 19:43:11 f42252se dovecot: auth: Debug: master out: NOTFOUND#0111
> Jan  7 19:43:11 f42252se postfix/pipe[14637]: C279030007E:
> to=<avadmin at av.loc>, relay=dovecot, delay=0.01, delays=0/0/0/0.01,
> dsn=5.1.1, status=bounced (user unknown)
> Jan  7 19:43:11 f42252se postfix/qmgr[14561]: C279030007E: removed
Same thing happens to the bounce. Being undeliverable, your mail is 
gone.
> +++
> Tell me what you need as additional info.
Turn off verbose logging in Postfix, as Charles pointed out. I guess 
it's only the TLS logging that you have made verbose.

Review the Dovecot wiki / wiki2 (you didn't say what version you are
using?) page on LDAP.
-- 
  http://rob0.nodns4.us/ -- system administration and consulting
  Offlist GMX mail is seen only if "/dev/rob0" is in the Subject:

Reasonably Related Threads

Search for more maybe matching threads

dovecot - Jan 2013 - unknown users

[Dovecot] unknown users

[Dovecot] unknown users

[Dovecot] unknown users

Reasonably Related Threads