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

Serge Hallyn 1310919 at bugs.launchpad.net
Wed Apr 30 14:41:41 UTC 2014


** Description changed:

+ ============================================
+ 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:
- 
+ 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.
+ 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
+         [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
+         [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
+         [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
+         [success=end default=ignore]    pam_winbind.so use_authtok try_first_pass
  Password-Initial:
-         [success=end default=ignore]    pam_winbind.so
+         [success=end default=ignore]    pam_winbind.so
  Session-Type: Additional
  Session:
-         optional                        pam_winbind.so
- 
+         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
+  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

** Changed in: samba (Ubuntu Trusty)
   Importance: Undecided => High

** Changed in: samba (Ubuntu Trusty)
       Status: New => Confirmed

-- 
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



More information about the Ubuntu-server-bugs mailing list