Problem: Dovecot UserDB Cache Causing Incorrect Home Directory on Cached IMAP Logins

[fdavid]

Problem:

There is a bug in Dovecot’s userdb cache that can cause the wrong home directory to be used when accessing IMAP folders after the first login.

When accessing an IMAP folder for the first time (userdb cache miss), a username change is detected and applied correctly. On subsequent accesses (userdb cache hit), the username change is not applied, resulting in an incorrect home directory being used for the session.

---

Disclaimer: Fixed

This issu is fixed with Erratum 263. You have to update the System to UCS 5.2-3 first, before the Erratum will be available.

---

Steps to Enable Auth Logging

To diagnose the issue, enable detailed authentication logging:

ucr set mail/dovecot/logging/auth_debug=yes \
        mail/dovecot/logging/auth_verbose=yes \
        mail/dovecot/logging/mail_debug=yes \
        mail/dovecot/logging/auth_debug_passwords=yes
systemctl restart dovecot

Example Log Output

First access (userdb cache miss):

auth: Debug: client passdb out: OK    1   user=test2
auth: Debug: ldap(test2,10.205.2.33,<token>): userdb cache miss
auth: Debug: ldap(test2,10.205.2.33,<token>): user search: ...
auth: Debug: ldap(test2,10.205.2.33,<token>): result: uid=test2 ...
auth: Debug: ldap(test2,10.205.2.33,<token>): username changed test2 -> test2m@uni.dtr
imap-login: Login: user=<test2>, ...
imap(test2m@uni.dtr): Debug: Effective uid=125, gid=133, home=/var/spool/dovecot/private/uni.dtr/test2m

Second access on the same connection (userdb cache hit):

auth: Debug: client passdb out: OK    1   user=test2
auth: Debug: ldap(test2,10.205.2.33,<token>): userdb cache hit: uid=125    gid=133    system_groups_user=test2    quota_rule=*:bytes=0M
imap-login: Login: user=<test2>, ...
imap(test2): Debug: Effective uid=125, gid=133, home=/var/spool/dovecot/private//test2

Notice that the home directory is now incorrect because the cached userdb did not reflect the username change.

Correct behavior when the cache works properly:

auth: Debug: ldap(test2,10.205.2.33,<token>): userdb cache hit: uid=126    gid=132    system_groups_user=test2    quota_rule=*:bytes=0M    user=test2m@uni.dtr

Here, the cache correctly returns the updated user=test2m@uni.dtr.

Workaround

Disabling the userdb cache resolves the issue:

ucr set mail/dovecot/auth/cache_size=0
systemctl restart dovecot

Important

Once the issue is resolved, remember to disable authentication logging to avoid excessive log output:

ucr set mail/dovecot/logging/auth_debug=no \
        mail/dovecot/logging/auth_verbose=no \
        mail/dovecot/logging/mail_debug=no \
        mail/dovecot/logging/auth_debug_passwords=no
systemctl restart dovecot