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
(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
** Affects: samba (Ubuntu)
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Ubuntu
Server Team, which is subscribed to samba in Ubuntu.
https://bugs.launchpad.net/bugs/1310919
Title:
pam_winbind krb5_ccache_type=FILE stopped working after 14.04 upgrade
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/samba/+bug/1310919/+subscriptions
--
Ubuntu-server-bugs mailing list
Ubuntu-server-bugs@lists.ubuntu.com
Modify settings or unsubscribe at:
https://lists.ubuntu.com/mailman/listinfo/ubuntu-server-bugs
