Activity log for bug #1310919

Date Who What changed Old value New value Message
2014-04-22 05:32:03 styro bug added bug
2014-04-23 15:58:20 msaxl attachment added krb5_kt_start_seq.diff https://bugs.launchpad.net/ubuntu/+source/samba/+bug/1310919/+attachment/4094414/+files/krb5_kt_start_seq.diff
2014-04-23 16:13:18 Launchpad Janitor samba (Ubuntu): status New Confirmed
2014-04-23 16:27:02 Ubuntu Foundations Team Bug Bot tags patch
2014-04-23 16:27:10 Ubuntu Foundations Team Bug Bot bug added subscriber Ubuntu Review Team
2014-04-23 16:32:30 msaxl bug watch added https://bugzilla.samba.org/show_bug.cgi?id=10490
2014-04-28 15:40:37 Brian Murray samba (Ubuntu): assignee Canonical Server Team (canonical-server)
2014-04-28 17:27:35 Brian Murray tags patch patch regression-release
2014-04-28 17:37:06 Serge Hallyn samba (Ubuntu): importance Undecided High
2014-04-29 21:07:03 Serge Hallyn nominated for series Ubuntu Trusty
2014-04-29 21:07:03 Serge Hallyn bug task added samba (Ubuntu Trusty)
2014-04-29 21:07:03 Serge Hallyn nominated for series Ubuntu Utopic
2014-04-29 21:07:03 Serge Hallyn bug task added samba (Ubuntu Utopic)
2014-04-30 08:21:48 Launchpad Janitor samba (Ubuntu Utopic): status Confirmed Fix Released
2014-04-30 14:41:41 Serge Hallyn description Ubuntu version: 14.04 AMD64 samba, winbind, libpam-winbind version: 2:4.1.6+dfsg-1ubuntu2 After upgrading to 14.04 from 13.10 I couldn't log in with any Active Directory accounts. After checking that Winbind itself worked (eg wbinfo and getent still worked properly) and plain old Kerberos kinit still worked fine, it seemed like it had to be a PAM problem. This is from /var/log/auth.log after enabling debug and debug_state on pam_winbind and trying to log in via ssh (local logins had the same problem both via the console and lightdm) Apr 22 16:21:23 ben sshd[10932]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=client.example.com user=anton Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] ENTER: pam_sm_authenticate (flags: 0x0001) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f30e9cbf250) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_USER) = "anton" (0x7f30e9cc1f80) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_TTY) = "ssh" (0x7f30e9cdb0d0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7f30e9cdb0b0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_AUTHTOK) = 0x7f30e9cd8ef0 Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_CONV) = 0x7f30e9cd8ed0 Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): getting password (0x00001389) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): pam_get_item returned a password Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): Verify user 'anton' Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): PAM config: krb5_ccache_type 'FILE' Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): enabling krb5 login flag Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): enabling cached login flag Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): enabling request for a FILE krb5 ccache Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_SYSTEM_ERR (4), NTSTATUS: NT_STATUS_C ONNECTION_DISCONNECTED, Error message was: NT_STATUS_CONNECTION_DISCONNECTED Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): internal module error (retval = PAM_SYSTEM_ERR(4), user = 'anton') Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] LEAVE: pam_sm_authenticate returning 4 (PAM_SYSTEM_ERR) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f30e9cbf250) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_USER) = "anton" (0x7f30e9cc1f80) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_TTY) = "ssh" (0x7f30e9cdb0d0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7f30e9cdb0b0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_AUTHTOK) = 0x7f30e9cd8ef0 Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_CONV) = 0x7f30e9cd8ed0 Apr 22 16:21:25 ben sshd[10932]: Failed password for anton from 192.168.20.100 port 58950 ssh2 Apr 22 16:21:27 ben sshd[10932]: Connection closed by 192.168.20.100 [preauth] After seeing that the line before the first error was about request a FILE krb5 ccache, I successfully tried with a different credential cache type (krb5_ccache_type=KEYRING) for pam_winbind in /etc/pam.d/common-auth: Apr 22 16:23:34 ben sshd[10946]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=client.example.com user=anton Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] ENTER: pam_sm_authenticate (flags: 0x0001) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b1610aa0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_AUTHTOK) = 0x7ff5b1627ed0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b1627eb0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): getting password (0x00001389) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): pam_get_item returned a password Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): Verify user 'anton' Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): PAM config: krb5_ccache_type 'KEYRING' Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): enabling krb5 login flag Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): enabling cached login flag Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): enabling request for a KEYRING krb5 ccache Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): request wbcLogonUser succeeded Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): user 'anton' granted access Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): Returned user was 'anton' Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] LEAVE: pam_sm_authenticate returning 0 (PAM_SUCCESS) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_AUTHTOK) = 0x7ff5b1627ed0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b1627eb0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10946]: Accepted password for anton from 192.168.20.100 port 58955 ssh2 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] ENTER: pam_sm_setcred (flags: 0x0002) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b162cea0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): PAM_ESTABLISH_CRED not implemented Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b162cea0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10946]: pam_unix(sshd:session): session opened for user anton by (uid=0) Apr 22 16:23:34 ben systemd-logind[855]: Removed session 3. Apr 22 16:23:34 ben systemd-logind[855]: New session 4 of user anton. Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] ENTER: pam_sm_setcred (flags: 0x0002) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b160f040 Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): PAM_ESTABLISH_CRED not implemented Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b160f040 Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) It would fail again if changed back to krb5_ccache_type=FILE which is still the default setting as far as I can tell. Also kinit could successfully create a FILE ccache. And (I don't know if this is relevant) even with a KEYRING ccache, klist would still show the standard FILE ccache path. contents of /usr/share/pam-configs/winbind Name: Winbind NT/Active Directory authentication Default: yes Priority: 192 Auth-Type: Primary Auth: [success=end default=ignore] pam_winbind.so krb5_auth krb5_ccache_type=KEYRING cached_login try_first_pass Auth-Initial: [success=end default=ignore] pam_winbind.so krb5_auth krb5_ccache_type=KEYRING cached_login Account-Type: Primary Account: [success=end new_authtok_reqd=done default=ignore] pam_winbind.so Password-Type: Primary Password: [success=end default=ignore] pam_winbind.so use_authtok try_first_pass Password-Initial: [success=end default=ignore] pam_winbind.so Session-Type: Additional Session: optional pam_winbind.so contents of /etc/pam.d/common-auth: # here are the per-package modules (the "Primary" block) auth [success=2 default=ignore] pam_unix.so nullok_secure auth [success=1 default=ignore] pam_winbind.so krb5_auth krb5_ccache_type=KEYRING cached_login try_first_pass # here's the fallback if no module succeeds auth requisite pam_deny.so # prime the stack with a positive return value if there isn't one already; # this avoids us returning an error just because nothing sets a success code # since the modules above will each just jump around auth required pam_permit.so # and here are more per-package modules (the "Additional" block) auth optional pam_cap.so # end of pam-auth-update config testparm service definition: [global] workgroup = EXAMPLE realm = EXAMPLE.COM security = ADS kerberos method = secrets and keytab log file = /var/log/samba/%m max log size = 50 printcap name = cups local master = No template homedir = /home/%U template shell = /bin/bash winbind enum users = Yes winbind enum groups = Yes winbind use default domain = Yes winbind nss info = rfc2307 winbind refresh tickets = Yes winbind offline logon = Yes idmap config EXAMPLE:range = 10000 - 19999 idmap config EXAMPLE:schema_mode = rfc2307 idmap config EXAMPLE:default = yes idmap config EXAMPLE:readonly = yes idmap config EXAMPLE:backend = ad idmap config * : range = 50000 - 50999 idmap config * : backend = tdb ============================================ Impact: pam-winbind stops working, preventing AD logins Regression potential: This patch is not accepted upstream so could for instance be introducing a memory leak in failure paths. Test case: login using pam-winbind ============================================ Ubuntu version: 14.04 AMD64 samba, winbind, libpam-winbind version: 2:4.1.6+dfsg-1ubuntu2 After upgrading to 14.04 from 13.10 I couldn't log in with any Active Directory accounts. After checking that Winbind itself worked (eg wbinfo and getent still worked properly) and plain old Kerberos kinit still worked fine, it seemed like it had to be a PAM problem. This is from /var/log/auth.log after enabling debug and debug_state on pam_winbind and trying to log in via ssh (local logins had the same problem both via the console and lightdm) Apr 22 16:21:23 ben sshd[10932]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=client.example.com user=anton Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] ENTER: pam_sm_authenticate (flags: 0x0001) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f30e9cbf250) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_USER) = "anton" (0x7f30e9cc1f80) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_TTY) = "ssh" (0x7f30e9cdb0d0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7f30e9cdb0b0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_AUTHTOK) = 0x7f30e9cd8ef0 Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_CONV) = 0x7f30e9cd8ed0 Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): getting password (0x00001389) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): pam_get_item returned a password Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): Verify user 'anton' Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): PAM config: krb5_ccache_type 'FILE' Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): enabling krb5 login flag Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): enabling cached login flag Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): enabling request for a FILE krb5 ccache Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_SYSTEM_ERR (4), NTSTATUS: NT_STATUS_C ONNECTION_DISCONNECTED, Error message was: NT_STATUS_CONNECTION_DISCONNECTED Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): internal module error (retval = PAM_SYSTEM_ERR(4), user = 'anton') Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] LEAVE: pam_sm_authenticate returning 4 (PAM_SYSTEM_ERR) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f30e9cbf250) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_USER) = "anton" (0x7f30e9cc1f80) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_TTY) = "ssh" (0x7f30e9cdb0d0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7f30e9cdb0b0) Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_AUTHTOK) = 0x7f30e9cd8ef0 Apr 22 16:21:23 ben sshd[10932]: pam_winbind(sshd:auth): [pamh: 0x7f30e9cca190] STATE: ITEM(PAM_CONV) = 0x7f30e9cd8ed0 Apr 22 16:21:25 ben sshd[10932]: Failed password for anton from 192.168.20.100 port 58950 ssh2 Apr 22 16:21:27 ben sshd[10932]: Connection closed by 192.168.20.100 [preauth] After seeing that the line before the first error was about request a FILE krb5 ccache, I successfully tried with a different credential cache type (krb5_ccache_type=KEYRING) for pam_winbind in /etc/pam.d/common-auth: Apr 22 16:23:34 ben sshd[10946]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=client.example.com user=anton Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] ENTER: pam_sm_authenticate (flags: 0x0001) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b1610aa0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_AUTHTOK) = 0x7ff5b1627ed0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b1627eb0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): getting password (0x00001389) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): pam_get_item returned a password Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): Verify user 'anton' Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): PAM config: krb5_ccache_type 'KEYRING' Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): enabling krb5 login flag Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): enabling cached login flag Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): enabling request for a KEYRING krb5 ccache Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): request wbcLogonUser succeeded Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): user 'anton' granted access Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): Returned user was 'anton' Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] LEAVE: pam_sm_authenticate returning 0 (PAM_SUCCESS) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_AUTHTOK) = 0x7ff5b1627ed0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b1627eb0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:auth): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10946]: Accepted password for anton from 192.168.20.100 port 58955 ssh2 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] ENTER: pam_sm_setcred (flags: 0x0002) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b162cea0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): PAM_ESTABLISH_CRED not implemented Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b162cea0 Apr 22 16:23:34 ben sshd[10946]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10946]: pam_unix(sshd:session): session opened for user anton by (uid=0) Apr 22 16:23:34 ben systemd-logind[855]: Removed session 3. Apr 22 16:23:34 ben systemd-logind[855]: New session 4 of user anton. Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] ENTER: pam_sm_setcred (flags: 0x0002) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b160f040 Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): PAM_ESTABLISH_CRED not implemented Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7ff5b160e080) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_USER) = "anton" (0x7ff5b162c7d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_TTY) = "ssh" (0x7ff5b162a0f0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_RHOST) = "client.example.com" (0x7ff5b162a0d0) Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: ITEM(PAM_CONV) = 0x7ff5b160f040 Apr 22 16:23:34 ben sshd[10984]: pam_winbind(sshd:setcred): [pamh: 0x7ff5b1619110] STATE: DATA(PAM_WINBIND_LOGONSERVER) = "ADDC" (0x7ff5b162c410) It would fail again if changed back to krb5_ccache_type=FILE which is still the default setting as far as I can tell. Also kinit could successfully create a FILE ccache. And (I don't know if this is relevant) even with a KEYRING ccache, klist would still show the standard FILE ccache path. contents of /usr/share/pam-configs/winbind Name: Winbind NT/Active Directory authentication Default: yes Priority: 192 Auth-Type: Primary Auth:         [success=end default=ignore] pam_winbind.so krb5_auth krb5_ccache_type=KEYRING cached_login try_first_pass Auth-Initial:         [success=end default=ignore] pam_winbind.so krb5_auth krb5_ccache_type=KEYRING cached_login Account-Type: Primary Account:         [success=end new_authtok_reqd=done default=ignore] pam_winbind.so Password-Type: Primary Password:         [success=end default=ignore] pam_winbind.so use_authtok try_first_pass Password-Initial:         [success=end default=ignore] pam_winbind.so Session-Type: Additional Session:         optional pam_winbind.so contents of /etc/pam.d/common-auth: # here are the per-package modules (the "Primary" block) auth [success=2 default=ignore] pam_unix.so nullok_secure auth [success=1 default=ignore] pam_winbind.so krb5_auth krb5_ccache_type=KEYRING cached_login try_first_pass # here's the fallback if no module succeeds auth requisite pam_deny.so # prime the stack with a positive return value if there isn't one already; # this avoids us returning an error just because nothing sets a success code # since the modules above will each just jump around auth required pam_permit.so # and here are more per-package modules (the "Additional" block) auth optional pam_cap.so # end of pam-auth-update config testparm service definition: [global]  workgroup = EXAMPLE  realm = EXAMPLE.COM  security = ADS  kerberos method = secrets and keytab  log file = /var/log/samba/%m  max log size = 50  printcap name = cups  local master = No  template homedir = /home/%U  template shell = /bin/bash  winbind enum users = Yes  winbind enum groups = Yes  winbind use default domain = Yes  winbind nss info = rfc2307  winbind refresh tickets = Yes  winbind offline logon = Yes  idmap config EXAMPLE:range = 10000 - 19999  idmap config EXAMPLE:schema_mode = rfc2307  idmap config EXAMPLE:default = yes  idmap config EXAMPLE:readonly = yes  idmap config EXAMPLE:backend = ad  idmap config * : range = 50000 - 50999  idmap config * : backend = tdb
2014-04-30 14:41:50 Serge Hallyn bug added subscriber Ubuntu Stable Release Updates Team
2014-04-30 14:41:54 Serge Hallyn samba (Ubuntu Trusty): importance Undecided High
2014-04-30 14:41:57 Serge Hallyn samba (Ubuntu Trusty): status New Confirmed
2014-05-01 21:07:22 Brian Murray bug task added samba
2014-05-01 21:12:30 Brian Murray samba (Ubuntu Trusty): status Confirmed Fix Committed
2014-05-01 21:12:34 Brian Murray bug added subscriber SRU Verification
2014-05-01 21:12:42 Brian Murray tags patch regression-release patch regression-release verification-needed
2014-05-01 21:31:20 Bug Watch Updater samba: status Unknown Confirmed
2014-05-01 21:31:20 Bug Watch Updater samba: importance Unknown Medium
2014-05-05 04:39:34 styro tags patch regression-release verification-needed patch regression-release verification-done
2014-05-12 05:17:20 Launchpad Janitor samba (Ubuntu Trusty): status Fix Committed Fix Released
2014-05-12 05:17:30 Scott Kitterman removed subscriber Ubuntu Stable Release Updates Team
2014-09-10 19:53:38 Serge Hallyn samba (Ubuntu Utopic): status Fix Released Incomplete
2014-09-11 16:56:19 Serge Hallyn samba (Ubuntu Utopic): status Incomplete Triaged
2014-09-11 19:13:10 Launchpad Janitor samba (Ubuntu Utopic): status Triaged Fix Released