dovecot - Oct 2010 - 2.0.5 masteruser problem with uncached users

a "masteruser" login fails:

Oct  8 15:12:54 postamt dovecot: auth: Debug:
auth(masteruser,141.42.206.38,master): Master user lookup for login:
nonworkinguser
Oct  8 15:12:54 postamt dovecot: auth: passdb(masteruser,141.42.206.38,master):
Master user logging in as nonworkinguser
Oct  8 15:12:54 postamt dovecot: auth: Debug:
cache(nonworkinguser,141.42.206.38): expired
Oct  8 15:12:54 postamt dovecot: auth: Debug: pam(nonworkinguser,141.42.206.38):
lookup service=dovecot
Oct  8 15:12:54 postamt dovecot: auth: Debug: pam(nonworkinguser,141.42.206.38):
#1/1 style=1 msg=Password:
Oct  8 15:12:56 postamt dovecot: auth: pam(nonworkinguser,141.42.206.38):
pam_authenticate() failed: Authentication failure (password mismatch?) (given
password: correct_masteruserpassword)
Oct  8 15:12:58 postamt dovecot: auth: Debug: client out:
FAIL^I48226^Iuser=nonworkinguser^Iauthz
Oct  8 15:12:58 postamt dovecot: imap-login: Disconnected (auth failed, 1
attempts): user=<nonworkinguser>, method=PLAIN, rip=141.42.206.38,
lip=141.42.206.36, mpid=0

but with the same setup, a masteruser for another user succeeded:

Oct  8 13:44:31 postamt dovecot: auth: Debug: auth(masteruser,127.0.0.1,master):
Master user lookup for login: workinguser
Oct  8 13:44:31 postamt dovecot: auth: passdb(masteruser,127.0.0.1,master):
Master user logging in as workinguser
Oct  8 13:44:31 postamt dovecot: auth: Debug: cache(workinguser,127.0.0.1): hit:
{SHA1}fJcDCzIZnqwatTFXqU/Vgf5kwlo=^Iuser=workinguser^Iuser=workinguser
Oct  8 13:44:31 postamt dovecot: auth: Debug: client out:
OK^I3685^Iuser=workinguser
Oct  8 13:44:32 postamt dovecot: auth: Debug: master out:
USER^I1^Iworkinguser^Isystem_groups_user=workinguser^Iuid=47077^Igid=100^Ihome=/home/d/w/workinguser^Imaster_user=masteruser
Oct  8 13:44:32 postamt dovecot: imap-login: Login: user=<workinguser>,
method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=28224, secured

So why does the masteruser login for an UNCACHED user fail?

auth_debug = yes
auth_debug_passwords = yes
auth_mechanisms = plain login
disable_plaintext_auth = no
auth_master_user_separator = *

# fuer user*masteruser logins
passdb {
  args = /usr/dovecot-2/etc/dovecot/dovecot.masteruser
  driver = passwd-file
  master = yes
  pass = yes
}
	
# Authorisierung via PAM, /etc/pam.d/dovecot
auth_cache_size = 64 M
passdb {
  driver = pam
  args = cache_key=%u
}
	    
# User via passwd
  userdb {
  driver = passwd
}
	      
-- 
Ralf Hildebrandt
  Gesch?ftsbereich IT | Abteilung Netzwerk
  Charit? - Universit?tsmedizin Berlin
  Campus Benjamin Franklin
  Hindenburgdamm 30 | D-12203 Berlin
  Tel. +49 30 450 570 155 | Fax: +49 30 450 570 962
  ralf.hildebrandt at charite.de | http://www.charite.de

* Ralf Hildebrandt <Ralf.Hildebrandt at
charite.de>:
> a "masteruser" login fails:
> 
> Oct  8 15:12:54 postamt dovecot: auth: Debug:
auth(masteruser,141.42.206.38,master): Master user lookup for login:
nonworkinguser
> Oct  8 15:12:54 postamt dovecot: auth:
passdb(masteruser,141.42.206.38,master): Master user logging in as
nonworkinguser
> Oct  8 15:12:54 postamt dovecot: auth: Debug:
cache(nonworkinguser,141.42.206.38): expired
> Oct  8 15:12:54 postamt dovecot: auth: Debug:
pam(nonworkinguser,141.42.206.38): lookup service=dovecot
> Oct  8 15:12:54 postamt dovecot: auth: Debug:
pam(nonworkinguser,141.42.206.38): #1/1 style=1 msg=Password:
> Oct  8 15:12:56 postamt dovecot: auth: pam(nonworkinguser,141.42.206.38):
pam_authenticate() failed: Authentication failure (password mismatch?) (given
password: correct_masteruserpassword)
> Oct  8 15:12:58 postamt dovecot: auth: Debug: client out:
FAIL^I48226^Iuser=nonworkinguser^Iauthz
> Oct  8 15:12:58 postamt dovecot: imap-login: Disconnected (auth failed, 1
attempts): user=<nonworkinguser>, method=PLAIN, rip=141.42.206.38,
lip=141.42.206.36, mpid=0
> 
> but with the same setup, a masteruser for another user succeeded:
> 
> Oct  8 13:44:31 postamt dovecot: auth: Debug:
auth(masteruser,127.0.0.1,master): Master user lookup for login: workinguser
> Oct  8 13:44:31 postamt dovecot: auth: passdb(masteruser,127.0.0.1,master):
Master user logging in as workinguser
> Oct  8 13:44:31 postamt dovecot: auth: Debug: cache(workinguser,127.0.0.1):
hit: {SHA1}fJcDCzIZnqwatTFXqU/Vgf5kwlo=^Iuser=workinguser^Iuser=workinguser
> Oct  8 13:44:31 postamt dovecot: auth: Debug: client out:
OK^I3685^Iuser=workinguser
> Oct  8 13:44:32 postamt dovecot: auth: Debug: master out:
USER^I1^Iworkinguser^Isystem_groups_user=workinguser^Iuid=47077^Igid=100^Ihome=/home/d/w/workinguser^Imaster_user=masteruser
> Oct  8 13:44:32 postamt dovecot: imap-login: Login:
user=<workinguser>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1,
mpid=28224, secured
> 
> So why does the masteruser login for an UNCACHED user fail?
Right now I'm having a hard time migrating my users because the
masteruser login fails. Anybody?

-- 
Ralf Hildebrandt
  Gesch?ftsbereich IT | Abteilung Netzwerk
  Charit? - Universit?tsmedizin Berlin
  Campus Benjamin Franklin
  Hindenburgdamm 30 | D-12203 Berlin
  Tel. +49 30 450 570 155 | Fax: +49 30 450 570 962
  ralf.hildebrandt at charite.de | http://www.charite.de

On Fri, 2010-10-08 at 15:38 +0200, Ralf Hildebrandt wrote:
> # fuer user*masteruser logins
> passdb {
>   args = /usr/dovecot-2/etc/dovecot/dovecot.masteruser
>   driver = passwd-file
>   master = yes
>   pass = yes
You can't use pass=yes with passdb pam. From wiki:

"You should also add the pass=yes setting to the master passdb if
possible. It means that Dovecot verifies that the login user really
exists before allowing the master user to log in. Without the setting if
a nonexistent login username is given, depending on the configuration,
it could either return an internal login error (the userdb lookup
failed) or create a whole new user (with eg. static userdb). pass=yes
doesn't work with PAM or LDAP with auth_bind=yes, because both of them
require knowing the user's password."

But .. yeah, maybe a fallback should be to do a userdb lookup instead.
Or change it to a pass=yes|no|userdb setting.