Timo Sirainen wrote: > On to, 2010-06-03 at 09:14 -0600, markham breitbach wrote: > >> Jun 02 16:54:06 pop3-login: Info: Login: user=<bobs>, method=PLAIN, >> rip=199.247.84.12, lip=64.247.129.4 >> Jun 02 16:54:06 POP3([email protected]): Info: Loading modules from >> directory: /usr/local/lib/dovecot/pop3 >> > > Is the above correct? Login shows the username as "bobs", but pop3 sees > it as bob_sm...@domain? I think that means the passdb lookup did change > the username, but a later userdb probably changes it back.. > > Yes, that's correct. >> After much searching for anything different between these records, some >> tcpdumps showed that the problem occured when LDAP returned the >> attributes in a different order than they are requested in. >> > > There shouldn't be any ordering-dependent code.. > By changing the order that the objects were requested in the dovecot-ldap.conf I was able to get dovecot to ask for the attributes in the order that they are returned bt the LDAP server, so I think my initail assumption was flawed and it doesn't appear to be related to a difference between the order of the request and the order of the response. Also, by changing the pass_attrs line in dovecot-ldap.conf to:
pass_attrs = uid=user It looks like dovecot throws a pre-fretch error and then does another query to get the missing parameters. -----snip------ Jun 04 14:22:38 auth(default): Info: prefetch(bobs,192.168.84.12): passdb didn't return userdb entries, trying the next userdb Jun 04 14:22:38 auth(default): Info: ldap(bobs,192.168.84.12): user search: base=dc=2,dc=ssi scope=subtree filter=(&(objectClass=posixAccount)(uid=bobs)) fields=mailQuota,uidNumber,gidNumber ---------- I guess I still need to do some more testing and make sure that solves my problem, but it still looks like there might be a problem with the prefetch. > Logs about broken login with auth_debug=yes might show something useful. > > Here is the log with auth_debug=yes and the unmodified pass_attrs config. Jun 04 10:31:30 auth(default): Info: new auth connection: pid=26207 Jun 04 10:31:49 auth(default): Info: client in: AUTH 1 PLAIN service=pop3 lip=172.16.129.4 rip=192.168.84.12 lport=110 rport=54955 resp=<hidden> Jun 04 10:31:49 auth(default): Info: ldap([email protected],192.168.84.12): bind search: base=dc=example,dc=tld filter=(&(accountstatus=active)(emailaccountStatus=active)(|([email protected])([email protected]))) Jun 04 10:31:49 auth(default): Info: auth([email protected],192.168.84.12): username changed [email protected] -> bobs Jun 04 10:31:49 auth(default): Info: ldap(bobs,192.168.84.12): result: gidNumber(userdb_gid)=2000 uid(user)=bobs uidNumber(userdb_uid)=38538 homeDirectory(userdb_home)=/nonexistent Jun 04 10:31:49 auth(default): Info: client out: OK 1 user=bobs Jun 04 10:31:49 auth(default): Info: master in: REQUEST 6 26187 1 Jun 04 10:31:49 auth(default): Info: prefetch(bobs,192.168.84.12): success Jun 04 10:31:49 auth(default): Info: master out: USER 6 [email protected] gid=2000 uid=38538 home=/nonexistent Jun 04 10:31:49 pop3-login: Info: Login: user=<bobs>, method=PLAIN, rip=192.168.84.12, lip=172.16.129.4 Jun 04 10:31:49 POP3([email protected]): Info: Loading modules from directory: /usr/local/lib/dovecot/pop3 Jun 04 10:31:49 POP3([email protected]): Info: Module loaded: /usr/local/lib/dovecot/pop3/lib10_quota_plugin.so Jun 04 10:31:49 POP3([email protected]): Info: Effective uid=38538, gid=2000, home=/nonexistent Jun 04 10:31:49 POP3([email protected]): Info: Quota root: name=User quota backend=maildir args= Jun 04 10:31:49 POP3([email protected]): Info: Quota rule: root=User quota mailbox=* bytes=524288000 messages=0 Jun 04 10:31:49 POP3([email protected]): Info: Quota rule: root=User quota mailbox=Trash bytes=52428800 messages=0 Jun 04 10:31:49 POP3([email protected]): Info: Quota rule: root=User quota mailbox=Deleted Messages bytes=52428800 messages=0 Jun 04 10:31:49 POP3([email protected]): Info: maildir: data=/var/mail/[email protected] Jun 04 10:31:49 POP3([email protected]): Info: maildir++: root=/var/mail/[email protected], index=, control=, inbox=/var/mail/[email protected] Jun 04 10:31:49 POP3([email protected]): Info: Namespace : Using permissions from /var/mail/[email protected]: mode=0700 gid=-1 Timo Sirainen wrote: > On to, 2010-06-03 at 09:14 -0600, markham breitbach wrote: > >> Jun 02 16:54:06 pop3-login: Info: Login: user=<bobs>, method=PLAIN, >> rip=199.247.84.12, lip=64.247.129.4 >> Jun 02 16:54:06 POP3([email protected]): Info: Loading modules from >> directory: /usr/local/lib/dovecot/pop3 >> > > Is the above correct? Login shows the username as "bobs", but pop3 sees > it as bob_sm...@domain? I think that means the passdb lookup did change > the username, but a later userdb probably changes it back.. > > >> After much searching for anything different between these records, some >> tcpdumps showed that the problem occured when LDAP returned the >> attributes in a different order than they are requested in. >> > > There shouldn't be any ordering-dependent code.. > > Logs about broken login with auth_debug=yes might show something useful. > >
