[Bug 1310919] [NEW] pam_winbind krb5_ccache_type=FILE stopped working after 14.04 upgrade

2014-04-21 Thread styro
Public bug reported:

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 
(0x1389)
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): 

[Bug 1310919] [NEW] pam_winbind krb5_ccache_type=FILE stopped working after 14.04 upgrade

2014-04-21 Thread styro
Public bug reported:

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 
(0x1389)
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):