Bug 39267

Summary:	postfix smtpd authentication timeout when using dovecot-sasl
Product:	UCS	Reporter:	Sönke Schwardt-Krummrich <schwardt>
Component:	Mail - Dovecot	Assignee:	Sönke Schwardt-Krummrich <schwardt>
Status:	CLOSED FIXED	QA Contact:	Daniel Tröder <troeder>
Severity:	normal
Priority:	P5	CC:	walkenhorst
Version:	UCS 4.0
Target Milestone:	UCS 4.0-3-errata
Hardware:	Other
OS:	Linux
What kind of report is it?:	---	What type of bug is this?:	---
Who will be affected by this bug?:	---	How will those affected feel about the bug?:	---
User Pain:		Enterprise Customer affected?:
School Customer affected?:		ISV affected?:
Waiting Support:		Flags outvoted (downgraded) after PO Review:
Ticket number:		Bug group (optional):
Max CVSS v3 score:

Description Sönke Schwardt-Krummrich

2015-08-26 15:11:14 CEST

At least during QA (and possibly in jenkins tests) the authentication against postfix smtpd was randomly rejected.

Debugging revealed several problems:
- postfix only waits up to 10 seconds for authentication (currently there is no 
  known way to increase the timeout)
- pam_ldap.so was never used within the pam stack "dovecot"; instead pam_krb5
  was used for authentication at took more than 6 seconds because only the 
  master of the 3-server-environment was running and the kdc was determined via 
  DNS SRV lookups (and choose an offline server).
- pam_ldap.so was never used because auf the argument "use_first_pass". 
  pam_univentionmailcyrus.so somehow does not provide a password for pam_ldap 
  so the latter one failed.


==> /var/log/mail.log <==
Aug 26 00:21:54 master40 postfix/smtpd[11980]: connect from unknown[1.2.3.4]
 
==> /var/log/dovecot.log <==
Aug 26 00:21:54 master40 dovecot: auth: Debug: auth client connected (pid=0)
Aug 26 00:21:54 master40 dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=smtp#011nologin#011lip=10.200.18.40#011rip=1.2.3.4#011secured#011resp=AHlhd2FpNHYwem5AbnN0eC5sb2NhbAB1bml2ZW50aW9u (previous base64 data may contain sensitive data)
Aug 26 00:21:54 master40 dovecot: auth: Debug: pam(yawai4v0zn@nstx.local,1.2.3.4): cache miss
Aug 26 00:21:54 master40 dovecot: auth-worker(11984): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Aug 26 00:21:54 master40 dovecot: auth-worker(11984): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Aug 26 00:21:54 master40 dovecot: auth-worker(11984): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libauthdb_ldap.so
Aug 26 00:21:54 master40 dovecot: auth-worker(11984): Debug: passwd-file /etc/dovecot/master-users: Read 1 users in 0 secs
Aug 26 00:21:54 master40 dovecot: auth-worker(11984): Debug: pam(yawai4v0zn@nstx.local,1.2.3.4): lookup service=dovecot
 
==> /var/log/auth.log <==
Aug 26 00:21:54 master40 PAM-univentionmailcyrus[11984]: continuing as user a0p011z5wm
 
==> /var/log/dovecot.log <==
Aug 26 00:21:55 master40 dovecot: auth-worker(11984): Debug: pam(yawai4v0zn@nstx.local,1.2.3.4): #1/1 style=1 msg=Password:
 
==> /var/log/mail.log <==
Aug 26 00:22:04 master40 postfix/smtpd[11980]: warning: unknown[1.2.3.4]: SASL PLAIN authentication failed: Connection lost to authentication server
Aug 26 00:22:04 master40 postfix/smtpd[11980]: lost connection after AUTH from unknown[1.2.3.4]
Aug 26 00:22:04 master40 postfix/smtpd[11980]: disconnect from unknown[1.2.3.4]
 
==> /var/log/dovecot.log <==
Aug 26 00:22:07 master40 dovecot: auth-worker(11984): pam(yawai4v0zn@nstx.local,1.2.3.4): unknown user (given password: univention)
 
==> /var/log/auth.log <==
Aug 26 00:22:07 master40 auth[11984]: pam_krb5(dovecot:auth): authentication failure; logname=a0p011z5wm uid=0 euid=0 tty=dovecot ruser=yawai4v0zn@nstx.local rhost=1.2.3.4
 
==> /var/log/dovecot.log <==
Aug 26 00:22:09 master40 dovecot: auth: Debug: client passdb out: FAIL#0111#011user=yawai4v0zn@nstx.local#011

Comment 1 Sönke Schwardt-Krummrich

2015-08-26 16:19:31 CEST

After removing 'use_first_pass' the auth attempt took less than a second. pam_ldap worked again.

Fixed in UCS 4.0-3:

2015-08-26-univention-mail-dovecot.yaml:
r63269 | Bug #39267: updated yaml
r63266 | Bug #39267: added YAML for univention-mail-dovecot

univention-mail-dovecot (1.0.0-4):
r63267 | Bug #39267: bumped version
r63265 | Bug #39267: removed 'use_first_pass' from pam_ldap in PAM stack 'dovecot'

Also fixed in UCS 4.1-0:

univention-mail-dovecot (1.0.0-4):
r63268 | Bug #39267: bumped version
r63260 | Bug #39267: removed 'use_first_pass' from pam_ldap in PAM stack 'dovecot'

Package has been built in scope errata4.0-3.

Comment 2 Daniel Tröder

2015-08-27 13:21:06 CEST

OK: code change
OK: changelog
OK: YAML
OK: merged to 4.1
OK: manual test
OK: automatic tests using "ucs-test -E dangerous -s mail" on jenkins AWS VM (failed test are unrelated)

Comment 3 Janek Walkenhorst

2015-08-27 18:14:25 CEST

<http://errata.univention.de/ucs/4.0/291.html>