[Dovecot] unknown users

Charles Marcus CMarcus at Media-Brokers.com
Mon Jan 7 22:15:27 EET 2013


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




More information about the dovecot mailing list