Bug 39267 - postfix smtpd authentication timeout when using dovecot-sasl
postfix smtpd authentication timeout when using dovecot-sasl
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: Mail - Dovecot
UCS 4.0
Other Linux
: P5 normal (vote)
: UCS 4.0-3-errata
Assigned To: Sönke Schwardt-Krummrich
Daniel Tröder
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2015-08-26 15:11 CEST by Sönke Schwardt-Krummrich
Modified: 2015-08-27 18:14 CEST (History)
1 user (show)

See Also:
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:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Sönke Schwardt-Krummrich univentionstaff 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 univentionstaff 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 univentionstaff 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 univentionstaff 2015-08-27 18:14:25 CEST
<http://errata.univention.de/ucs/4.0/291.html>