I have setup dovecot to allow users to login using their email address
or uid and have found a strange behaviour when the user logs in using
the email address for a "username". I am using OpenLDAP for a backend
data store with a rather customized schema. This behaviour occurs for
both POP3 and IMAP logins. For some users it works as expected, but for
others the pass_attrs->user does not get mapped back to the uid, but
remains the mailLocalAddress (dovecot-ldap.conf is attached at the end
of this post).
Here is an excerpt from the logs for a working and a malfunctioning
user. In both cases the users were logged directly into the pop3 port
(ie. telnet <mailserver> 110) and used the fully qualified email address
as the user (ie. foo at ex.tld).
Jun 02 13:23:19 pop3-login: Info: Login: user=<foo>, method=PLAIN,
rip=64.247.129.10, lip=64.247.129.10, secured
Jun 02 13:23:19 POP3(foo): Info: Loading modules from directory:
/usr/local/lib/dovecot/pop3
Jun 02 13:23:19 POP3(foo): Info: Module loaded:
/usr/local/lib/dovecot/pop3/lib10_quota_plugin.so
Jun 02 13:23:19 POP3(foo): Info: Effective uid=14921, gid=2000,
home=/nonexistent
Jun 02 13:23:19 POP3(foo): Info: Quota root: name=User quota
backend=maildir argsJun 02 13:23:19 POP3(foo): Info: Quota rule: root=User quota
mailbox=*
bytes=0 messages=0
Jun 02 13:23:19 POP3(foo): Info: maildir: data=/var/mail/foo
Jun 02 13:23:19 POP3(foo): Info: maildir++: root=/var/mail/foo, index=,
control=, inbox=/var/mail/foo
Jun 02 13:23:19 POP3(foo): Info: Namespace : Using permissions from
/var/mail/foo: mode=0700 gid=-1
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(bob_smith at example.tld): Info: Loading modules from
directory: /usr/local/lib/dovecot/pop3
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: Module loaded:
/usr/local/lib/dovecot/pop3/lib10_quota_plugin.so
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: Effective uid=38538,
gid=2000, home=/nonexistent
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: Quota root: name=User
quota backend=maildir argsJun 02 16:54:06 POP3(bob_smith at example.tld): Info:
Quota rule: root=User
quota mailbox=* bytes=524288000 messages=0
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: Quota rule: root=User
quota mailbox=Trash bytes=52428800 messages=0
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: Quota rule: root=User
quota mailbox=Deleted Messages bytes=52428800 messages=0
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: maildir:
data=/var/mail/bob_smith at example.tld
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: maildir++:
root=/var/mail/bob_smith at example.tld, index=, control=,
inbox=/var/mail/bob_smith at example.tld
Jun 02 16:54:06 POP3(bob_smith at example.tld): Info: Namespace : Using
permissions from /var/mail/bob_smith at example.tld: mode=0700 gid=-1
Jun 02 16:54:10 POP3(bob_smith at example.tld): Info: Disconnected: Logged
out top=0/0, retr=0/0, del=0/0, size=0
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.
In this sample, you can see the request for
uid,homeDirectory,uidNumber,gidNumber,mailQuota and the values are
returned in the order gidNumber, uid, uidNumber, homeDirectory. There
is no mailQuota set for this user.
16:54:06.145597 IP mail.xxxxx.com.62929 > closest-ldap.ldap: P
14:261(247) ack 15 win 33304 <nop,nop,timestamp 1521221146 267819447>
0x0000: 4500 012b fd4d 4000 4006 b87a 40f7 8104 E..+.M at .@..z at ...
0x0010: 40f7 8112 f5d1 0185 41e1 8b7d 5aea 01d9 @.......A..}Z...
0x0020: 8018 8218 8522 0000 0101 080a 5aab fe1a ....."......Z...
0x0030: 0ff6 99b7 3081 f402 0120 6381 ee04 0b64 ....0.....c....d
0x0040: 633d 322c 6463 3d73 7369 0a01 020a 0100 c=2,dc=ssi......
0x0050: 0201 0002 0100 0101 00a0 8198 a317 040d ................
0x0060: 6163 636f 756e 7473 7461 7475 7304 0661 accountstatus..a
0x0070: 6374 6976 65a3 1c04 1265 6d61 696c 6163 ctive....emailac
0x0080: 636f 756e 7453 7461 7475 7304 0661 6374 countStatus..act
0x0090: 6976 65a1 5fa3 2704 0375 6964 0420 626f ive._.'..uid..bo
0x00a0: 625f 6d61 6364 6f6e 616c 6440 6772 6561 b_xxxxxxxxx at xxxx
0x00b0: 7473 6c61 7665 6865 6c69 2e63 6f6d a334 xxxxxxxxxx.com.4
0x00c0: 0410 6d61 696c 4c6f 6361 6c41 6464 7265 ..mailLocalAddre
0x00d0: 7373 0420 626f 625f 6d61 6364 6f6e 616c ss..bob_xxxxxxxx
0x00e0: 6440 6772 6561 7473 6c61 7665 6865 6c69 x at xxxxxxxxxxxxxx
0x00f0: 2e63 6f6d 3035 0403 7569 6404 0d68 6f6d .com05..uid..hom
0x0100: 6544 6972 6563 746f 7279 0409 7569 644e eDirectory..uidN
0x0110: 756d 6265 7204 0967 6964 4e75 6d62 6572 umber..gidNumber
0x0120: 0409 6d61 696c 5175 6f74 61 ..mailQuota
16:54:06.147464 IP closest-ldap.ldap > mail.xxxxx.com.62929: P
15:142(127) ack 261 win 32942 <nop,nop,timestamp 267819449 1521221146>
0x0000: 4500 00b3 bb91 4000 4006 faae 40f7 8112 E..... at .@... at ...
0x0010: 40f7 8104 0185 f5d1 5aea 01d9 41e1 8c74 @.......Z...A..t
0x0020: 8018 80ae b708 0000 0101 080a 0ff6 99b9 ................
0x0030: 5aab fe1a 307d 0201 2064 7804 1663 6e3d Z...0}...dx..cn 0x0040:
6773 6862 6f62 6d2c 6463 3d32 2c64 633d xxxbobx,dc=2,dc 0x0050: 7373 6930
5e30 1304 0967 6964 4e75 6d62 ssi0^0...gidNumb
0x0060: 6572 3106 0404 3230 3030 3010 0403 7569 er1...20000...ui
0x0070: 6431 0904 0767 7368 626f 626d 3014 0409 d1...xxxbobx0...
0x0080: 7569 644e 756d 6265 7231 0704 0533 3835 uidNumber1...385
0x0090: 3338 301f 040d 686f 6d65 4469 7265 6374 380...homeDirect
0x00a0: 6f72 7931 0e04 0c2f 6e6f 6e65 7869 7374 ory1.../nonexist
0x00b0: 656e 74 ent
I will spare you the packet dump, but in the cases where the login works
correctly, LDAP returns the values in the same order that they are
requested in. This behaviour has been found with both OpenLDAP: slapd
2.3.39 and OpenLDAP: slapd 2.4.17, and is consistent with standard LDAP
behaviour (ie, there is no guaranteed ordering in the LDAP database).
A brief look at the code, seems to indicate that the values are being
pulled from the LDAP return struct in a step-wise manner, which could
certainly put them out of sync with the request if it is assumed that
they will always be returned in the same order....This is just based on
a quick review of the code though, and not any detailed tracing.
Here is the obligatory dovecot -n:
# 1.2.11: /usr/local/etc/dovecot.conf
# OS: FreeBSD 6.4-RELEASE-p7 i386 nullfs
log_path: /var/log/dovecot.log
info_log_path: /var/log/dovecot-info.log
protocols: pop3 pop3s imap imaps
disable_plaintext_auth: no
login_dir: /usr/local/var/run/dovecot/login
login_executable(default): /usr/local/libexec/dovecot/imap-login
login_executable(imap): /usr/local/libexec/dovecot/imap-login
login_executable(pop3): /usr/local/libexec/dovecot/pop3-login
first_valid_uid: 0
mail_location: maildir:/var/mail/%u
mail_debug: yes
mail_executable(default): /usr/local/libexec/dovecot/imap
mail_executable(imap): /usr/local/libexec/dovecot/imap
mail_executable(pop3): /usr/local/libexec/dovecot/pop3
mail_plugins(default): quota imap_quota
mail_plugins(imap): quota imap_quota
mail_plugins(pop3): quota
mail_plugin_dir(default): /usr/local/lib/dovecot/imap
mail_plugin_dir(imap): /usr/local/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3
pop3_uidl_format(default): %08Xu%08Xv
pop3_uidl_format(imap): %08Xu%08Xv
pop3_uidl_format(pop3): %v.%u
lda:
postmaster_address: postmaster at ssimicro.com
mail_plugins: quota
log_path:
info_log_path:
auth default:
passdb:
driver: ldap
args: /usr/local/etc/dovecot-ldap.conf
userdb:
driver: prefetch
userdb:
driver: ldap
args: /usr/local/etc/dovecot-ldap.conf
userdb:
driver: passwd
socket:
type: listen
master:
path: /usr/local/var/run/dovecot/auth-master
mode: 384
user: dovecot
plugin:
quota: maildir:User quota
quota_rule: *:storage=500MB
quota_rule2: Trash:storage=50MB
quota_rule3: Deleted Messages:storage=50MB
home: /tmp/thome
and the dovecot-ldap.conf
hosts = closest-ldap
base = "dc=2,dc=ssi"
scope = subtree
auth_bind = yes
pass_attrs = uid=user,
homeDirectory=userdb_home,uidNumber=userdb_uid,gidNumber=userdb_gid,mailQuota=userdb_quota_rule=*:bytes=%$
user_attrs = mailQuota=quota_rule=*:bytes=%$, uidNumber=uid,gidNumber=gid
pass_filter
(&(accountstatus=active)(emailaccountStatus=active)(|(uid=%u)(mailLocalAddress=%u)))