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@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@av.loc Jan 7 19:43:09 f42252se postfix/qmgr[14561]: 9A86C30007C: from=avadmin@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@av.loc Jan 7 19:43:11 f42252se postfix/cleanup[14631]: BE0AC30007F: message-id=50EB173B.5090109@av.loc Jan 7 19:43:11 f42252se postfix/qmgr[14561]: BE0AC30007F: from=avadmin@av.loc, size=1534, nrcpt=1 (queue active) Jan 7 19:43:11 f42252se postfix/pipe[14632]: 9A86C30007C: to=redmine@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@averlon.loc#011service=lda Jan 7 19:43:11 f42252se dovecot: auth: Debug: ldap(redmine@averlon.loc): pass search: base=ou=user,dc=averlon,dc=loc scope=onelevel filter=(&(objectClass=posixAccount)(uid=redmine@averlon.loc)) fields=uid,userPassword Jan 7 19:43:11 f42252se dovecot: auth: ldap(redmine@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@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@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@av.loc#011service=lda Jan 7 19:43:11 f42252se dovecot: auth: Debug: ldap(avadmin@av.loc): pass search: base=ou=user,dc=averlon,dc=loc scope=onelevel filter=(&(objectClass=posixAccount)(uid=avadmin@av.loc)) fields=uid,userPassword Jan 7 19:43:11 f42252se dovecot: auth: ldap(avadmin@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@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