Bug 997580

Summary: ssh login does not work winbind and 'kerberos method = system keytab'
Product: Red Hat Enterprise Linux 7 Reporter: Patrik Kis <pkis>
Component: realmdAssignee: Stef Walter <stefw>
Status: CLOSED CURRENTRELEASE QA Contact: Patrik Kis <pkis>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.0CC: dspurek, gdeschner, pkis, sengork, stefw
Target Milestone: rcKeywords: Regression
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: realmd-0.14.6-1.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-06-13 11:08:35 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Patrik Kis 2013-08-15 16:20:47 UTC
Description of problem:
After upgrading from realmd-0.14.2-3.el7 to realmd-0.14.3-1.el7 ssh stopped working for AD users. This happened only when the join was via winbind and also the AD server is configured with IPv6. Disabling IPv6 on the client does not helped.

Version-Release number of selected component (if applicable):
realmd-0.14.3-1.el7

How reproducible:
always

Steps to Reproduce:
1. Configure an AD with IPv6
2. On the client:

[root@rhel72 ~]# echo Pass2012! | realm -v join --user=Amy-admin --client-software=winbind --membership-software=samba ad.baseos.qe
 * Resolving: _ldap._tcp.ad.baseos.qe
 * Performing LDAP DSE lookup on: 10.34.37.22
 * Successfully discovered: ad.baseos.qe
Password for Amy-admin: 
 * Required files: /usr/libexec/oddjob/mkhomedir, /usr/sbin/oddjobd, /usr/bin/wbinfo, /usr/sbin/winbindd, /usr/bin/net
 * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.JO9P1W -U Amy-admin ads join ad.baseos.qe
Enter Amy-admin's password:
DNS update failed: NT_STATUS_INVALID_PARAMETER
Using short domain name -- AD
Joined 'RHEL72' to dns domain 'ad.baseos.qe'
No DNS domain configured for rhel72. Unable to perform DNS Update.
 * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.JO9P1W -U Amy-admin ads keytab create
Enter Amy-admin's password:
 * /usr/bin/systemctl enable winbind.service
ln -s '/usr/lib/systemd/system/winbind.service' '/etc/systemd/system/multi-user.target.wants/winbind.service'
 * /usr/bin/systemctl restart winbind.service
 * /usr/bin/sh -c /usr/sbin/authconfig --update --enablewinbind --enablewinbindauth --enablemkhomedir --nostart && /usr/bin/systemctl enable oddjobd.service
 * Successfully enrolled machine in realm
[root@rhel72 ~]# 
[root@rhel72 ~]# 
[root@rhel72 ~]# 
[root@rhel72 ~]# ssh amy.qe.0.1
amy.qe.0.1's password: 
Permission denied, please try again.
amy.qe.0.1's password: 
Permission denied, please try again.
amy.qe.0.1's password: 
Permission denied (publickey,gssapi-keyex,gssapi-with-mic,password).
[root@rhel72 ~]# 

3. Here are some more logs:
Aug 15 18:19:22 rhel72 realmd[2915]: client using service: :1.70
Aug 15 18:19:22 rhel72 realmd[2915]: holding daemon: :1.70
Aug 15 18:19:22 rhel72 realmd[2915]: Using 'r2308.2983' operation for method 'Discover' invocation on 'org.freedesktop.realmd.Provider' interface
Aug 15 18:19:22 rhel72 realmd[2915]: Registered cancellable for operation 'r2308.2983'
Aug 15 18:19:22 rhel72 realmd[2915]:  * Resolving: _ldap._tcp.ad.baseos.qe
Aug 15 18:19:22 rhel72 realmd[2915]:  * Resolving: _ldap._tcp.ad.baseos.qe
Aug 15 18:19:23 rhel72 realmd[2915]:  * Performing LDAP DSE lookup on: 10.34.37.22
Aug 15 18:19:23 rhel72 realmd[2915]:  * Performing LDAP DSE lookup on: 10.34.37.22
Aug 15 18:19:23 rhel72 realmd[2915]: Searching  for (objectClass=*)
Aug 15 18:19:23 rhel72 realmd[2915]: Got defaultNamingContext: DC=ad,DC=baseos,DC=qe
Aug 15 18:19:23 rhel72 realmd[2915]: Sending TCP Netlogon request
Aug 15 18:19:23 rhel72 realmd[2915]: Received TCP Netlogon response
Aug 15 18:19:23 rhel72 realmd[2915]:  * Successfully discovered: ad.baseos.qe
Aug 15 18:19:23 rhel72 realmd[2915]:  * Successfully discovered: ad.baseos.qe
Aug 15 18:19:23 rhel72 realmd[2915]: Using 'r2308.2983' operation for method 'Join' invocation on 'org.freedesktop.realmd.KerberosMembership' interface
Aug 15 18:19:23 rhel72 realmd[2915]: holding daemon: current-invocation
Aug 15 18:19:23 rhel72 realmd[2915]:  * Required files: /usr/libexec/oddjob/mkhomedir, /usr/sbin/oddjobd, /usr/bin/wbinfo, /usr/sbin/winbindd, /usr/bin/net
Aug 15 18:19:23 rhel72 realmd[2915]:  * Required files: /usr/libexec/oddjob/mkhomedir, /usr/sbin/oddjobd, /usr/bin/wbinfo, /usr/sbin/winbindd, /usr/bin/net
Aug 15 18:19:23 rhel72 realmd[2915]:  * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.FXSU1W -U Amy-admin ads join ad.baseos.qe
Aug 15 18:19:23 rhel72 realmd[2915]:  * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.FXSU1W -U Amy-admin ads join ad.baseos.qe
Aug 15 18:19:23 rhel72 realmd[2915]: process started: 2986
Aug 15 18:19:23 rhel72 realmd[2915]: PackageKit: notify::connected
Aug 15 18:19:23 rhel72 realmd[2915]: Enter Amy-admin's password:
Aug 15 18:19:23 rhel72 realmd[2915]: Enter Amy-admin's password:
Aug 15 18:19:25 rhel72 realmd[2915]: DNS update failed: NT_STATUS_INVALID_PARAMETER
Aug 15 18:19:25 rhel72 realmd[2915]: DNS update failed: NT_STATUS_INVALID_PARAMETER
Aug 15 18:19:25 rhel72 realmd[2915]: Using short domain name -- AD
Aug 15 18:19:25 rhel72 realmd[2915]: Using short domain name -- AD
Aug 15 18:19:25 rhel72 realmd[2915]: Joined 'RHEL72' to dns domain 'ad.baseos.qe'
Aug 15 18:19:25 rhel72 realmd[2915]: Joined 'RHEL72' to dns domain 'ad.baseos.qe'
Aug 15 18:19:25 rhel72 realmd[2915]: No DNS domain configured for rhel72. Unable to perform DNS Update.
Aug 15 18:19:25 rhel72 realmd[2915]: No DNS domain configured for rhel72. Unable to perform DNS Update.
Aug 15 18:19:25 rhel72 realmd[2915]: process exited: 2986
Aug 15 18:19:25 rhel72 realmd[2915]:  * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.FXSU1W -U Amy-admin ads keytab create
Aug 15 18:19:25 rhel72 realmd[2915]:  * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.FXSU1W -U Amy-admin ads keytab create
Aug 15 18:19:25 rhel72 realmd[2915]: process started: 2987
Aug 15 18:19:25 rhel72 realmd[2915]: Enter Amy-admin's password:
Aug 15 18:19:25 rhel72 realmd[2915]: Enter Amy-admin's password:
Aug 15 18:19:27 rhel72 realmd[2915]: process exited: 2987
Aug 15 18:19:27 rhel72 realmd[2915]:  * /usr/bin/systemctl enable winbind.service
Aug 15 18:19:27 rhel72 realmd[2915]:  * /usr/bin/systemctl enable winbind.service
Aug 15 18:19:27 rhel72 realmd[2915]: process started: 2988
Aug 15 18:19:27 rhel72 realmd[2915]: ln -s '/usr/lib/systemd/system/winbind.service' '/etc/systemd/system/multi-user.target.wants/winbind.service'
Aug 15 18:19:27 rhel72 realmd[2915]: ln -s '/usr/lib/systemd/system/winbind.service' '/etc/systemd/system/multi-user.target.wants/winbind.service'
Aug 15 18:19:27 rhel72 systemd[1]: Reloading.
Aug 15 18:19:27 rhel72 LVM: Activation generator successfully completed.
Aug 15 18:19:27 rhel72 realmd[2915]: process exited: 2988
Aug 15 18:19:27 rhel72 realmd[2915]:  * /usr/bin/systemctl restart winbind.service
Aug 15 18:19:27 rhel72 realmd[2915]:  * /usr/bin/systemctl restart winbind.service
Aug 15 18:19:27 rhel72 realmd[2915]: process started: 2996
Aug 15 18:19:27 rhel72 systemd[1]: Starting Samba Winbind Daemon...
Aug 15 18:19:27 rhel72 systemd[1]: PID file /run/winbindd.pid not readable (yet?) after start.
Aug 15 18:19:27 rhel72 systemd[1]: Started Samba Winbind Daemon.
Aug 15 18:19:27 rhel72 realmd[2915]: process exited: 2996
Aug 15 18:19:27 rhel72 realmd[2915]:  * /usr/bin/sh -c /usr/sbin/authconfig --update --enablewinbind --enablewinbindauth --enablemkhomedir --nostart && /usr/bin/systemctl enable oddjobd.service
Aug 15 18:19:27 rhel72 realmd[2915]:  * /usr/bin/sh -c /usr/sbin/authconfig --update --enablewinbind --enablewinbindauth --enablemkhomedir --nostart && /usr/bin/systemctl enable oddjobd.service
Aug 15 18:19:27 rhel72 realmd[2915]: process started: 2999
Aug 15 18:19:28 rhel72 systemd[1]: Reloading.
Aug 15 18:19:28 rhel72 LVM: Activation generator successfully completed.
Aug 15 18:19:28 rhel72 systemd[1]: Reloading.
Aug 15 18:19:28 rhel72 LVM: Activation generator successfully completed.
Aug 15 18:19:28 rhel72 systemd[1]: Reloading.
Aug 15 18:19:28 rhel72 LVM: Activation generator successfully completed.
Aug 15 18:19:28 rhel72 systemd[1]: Reloading.
Aug 15 18:19:28 rhel72 LVM: Activation generator successfully completed.
Aug 15 18:19:28 rhel72 realmd[2915]: process exited: 2999
Aug 15 18:19:28 rhel72 realmd[2915]:  * Successfully enrolled machine in realm
Aug 15 18:19:28 rhel72 realmd[2915]:  * Successfully enrolled machine in realm
Aug 15 18:19:28 rhel72 realmd[2915]: released daemon: current-invocation
Aug 15 18:19:28 rhel72 realmd[2915]: client gone away: :1.70
Aug 15 18:19:28 rhel72 realmd[2915]: released daemon: :1.70
Aug 15 18:19:34 rhel72 sshd[3063]: error: Could not load host key: /etc/ssh/ssh_host_ecdsa_key
Aug 15 18:19:41 rhel72 sshd[3063]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=localhost  user=amy.qe
Aug 15 18:19:41 rhel72 sshd[3063]: pam_winbind(sshd:auth): getting password (0x00000390)
Aug 15 18:19:41 rhel72 sshd[3063]: pam_winbind(sshd:auth): pam_get_item returned a password
Aug 15 18:19:41 rhel72 sshd[3063]: pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_AUTH_ERR (7), NTSTATUS: NT_STATUS_LOGON_FAILURE, Error message was: Logon failure
Aug 15 18:19:41 rhel72 sshd[3063]: pam_winbind(sshd:auth): user 'AD.BASEOS.QE\amy' denied access (incorrect password or invalid membership)
Aug 15 18:19:43 rhel72 sshd[3063]: Failed password for amy.qe from 127.0.0.1 port 52903 ssh2
Aug 15 18:19:57 rhel72 sshd[3063]: pam_winbind(sshd:auth): getting password (0x00000390)
Aug 15 18:19:57 rhel72 sshd[3063]: pam_winbind(sshd:auth): pam_get_item returned a password
Aug 15 18:19:58 rhel72 sshd[3063]: pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_AUTH_ERR (7), NTSTATUS: NT_STATUS_LOGON_FAILURE, Error message was: Logon failure
Aug 15 18:19:58 rhel72 sshd[3063]: pam_winbind(sshd:auth): user 'AD.BASEOS.QE\amy' denied access (incorrect password or invalid membership)
Aug 15 18:20:00 rhel72 sshd[3063]: Failed password for amy.qe from 127.0.0.1 port 52903 ssh2
Aug 15 18:20:04 rhel72 sshd[3063]: pam_winbind(sshd:auth): getting password (0x00000390)
Aug 15 18:20:04 rhel72 sshd[3063]: pam_winbind(sshd:auth): pam_get_item returned a password
Aug 15 18:20:04 rhel72 sshd[3063]: pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_AUTH_ERR (7), NTSTATUS: NT_STATUS_LOGON_FAILURE, Error message was: Logon failure
Aug 15 18:20:04 rhel72 sshd[3063]: pam_winbind(sshd:auth): user 'AD.BASEOS.QE\amy' denied access (incorrect password or invalid membership)
Aug 15 18:20:07 rhel72 sshd[3063]: Failed password for amy.qe from 127.0.0.1 port 52903 ssh2
Aug 15 18:20:07 rhel72 sshd[3063]: Connection closed by 127.0.0.1 [preauth]
Aug 15 18:20:07 rhel72 sshd[3063]: PAM 2 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=localhost  user=amy.qe

Comment 11 Stef Walter 2013-09-02 17:00:38 UTC
Cannot reproduce. Or maybe I'm missing the failure you're pointing to. I've updated realmd to the latest version (also tried the procedure before updating) and then run through the steps:

0 [root@rhel7 ~ ]# yum update realmd
Loaded plugins: auto-update-debuginfo, product-id, subscription-manager
This system is not registered to Red Hat Subscription Management. You can use subscription-manager to register.
Resolving Dependencies
--> Running transaction check
---> Package realmd.x86_64 0:0.14.2-3.el7 will be updated
---> Package realmd.x86_64 0:0.14.5-1.el7 will be an update
--> Finished Dependency Resolution

Dependencies Resolved

================================================================================
 Package          Arch             Version                Repository       Size
================================================================================
Updating:
 realmd           x86_64           0.14.5-1.el7           rhel7           229 k

Transaction Summary
================================================================================
Upgrade  1 Package

Total download size: 229 k
Is this ok [y/d/N]: y
Downloading packages:
No Presto metadata available for rhel7
realmd-0.14.5-1.el7.x86_64.rpm                             | 229 kB   00:00     
Running transaction check
Running transaction test
Transaction test succeeded
Running transaction
Warning: RPMDB altered outside of yum.
  Updating   : realmd-0.14.5-1.el7.x86_64                                   1/2 
  Cleanup    : realmd-0.14.2-3.el7.x86_64                                   2/2 
  Verifying  : realmd-0.14.5-1.el7.x86_64                                   1/2 
  Verifying  : realmd-0.14.2-3.el7.x86_64                                   2/2 

Updated:
  realmd.x86_64 0:0.14.5-1.el7                                                  

Complete!
0 [root@rhel7 ~ ]# echo Pass2012! | realm -v join --user=Amy-admin --client-software=winbind --membership-software=samba ad.baseos.qe
 * Resolving: _ldap._tcp.ad.baseos.qe
 * Performing LDAP DSE lookup on: 10.34.37.22
 * Performing LDAP DSE lookup on: 2620:52:0:2223:1dfe:a8ea:f0d8:380c
 * Performing LDAP DSE lookup on: 2620:52:0:2223::1:1
 ! Can't contact LDAP server
 ! Can't contact LDAP server
 * Successfully discovered: ad.baseos.qe
Password for Amy-admin: 
 * Required files: /usr/libexec/oddjob/mkhomedir, /usr/sbin/oddjobd, /usr/bin/wbinfo, /usr/sbin/winbindd, /usr/bin/net
 * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.2TSS2W -U Amy-admin ads join ad.baseos.qe
Enter Amy-admin's password:
DNS update failed: NT_STATUS_IO_TIMEOUT
Using short domain name -- AD
Joined 'RHEL7' to dns domain 'ad.baseos.qe'
 * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.2TSS2W -U Amy-admin ads keytab create
Enter Amy-admin's password:
 * /usr/bin/systemctl enable winbind.service
ln -s '/usr/lib/systemd/system/winbind.service' '/etc/systemd/system/multi-user.target.wants/winbind.service'
 * /usr/bin/systemctl restart winbind.service
 * /usr/bin/sh -c /usr/sbin/authconfig --update --enablewinbind --enablewinbindauth --enablemkhomedir --nostart && /usr/bin/systemctl enable oddjobd.service
 * Successfully enrolled machine in realm
0 [root@rhel7 ~ ]# realm leave^C
130 [root@rhel7 ~ ]# realm list
ad.baseos.qe
  type: kerberos
  realm-name: AD.BASEOS.QE
  domain-name: ad.baseos.qe
  configured: kerberos-member
  server-software: active-directory
  client-software: winbind
  required-package: oddjob-mkhomedir
  required-package: oddjob
  required-package: samba-winbind-clients
  required-package: samba-winbind
  required-package: samba-common
  login-formats: AD\%U
  login-policy: allow-any-login
0 [root@rhel7 ~ ]# ssh amy.qe.0.1
amy.qe.0.1's password: 
org.freedesktop.DBus.Error.ServiceUnknown: The name com.redhat.oddjob_mkhomedir was not provided by any .service files
Last login: Mon Sep  2 18:57:15 2013 from localhost
Could not chdir to home directory /home/AD/amy: No such file or directory
-bash-4.2$ logout
Connection to 127.0.0.1 closed.

Comment 12 Stef Walter 2013-09-02 17:01:22 UTC
Are you referring to this error?

org.freedesktop.DBus.Error.ServiceUnknown: The name com.redhat.oddjob_mkhomedir was not provided by any .service files

This does not prevent login. Is this worth filing a separate bug about? I thought we had fixed this issue, but perhaps oddjob repackaging brought it up again?

Comment 13 Patrik Kis 2013-09-03 12:02:54 UTC
(In reply to Stef Walter from comment #12)
> Are you referring to this error?
> 
> org.freedesktop.DBus.Error.ServiceUnknown: The name
> com.redhat.oddjob_mkhomedir was not provided by any .service files
> 
> This does not prevent login. Is this worth filing a separate bug about? I
> thought we had fixed this issue, but perhaps oddjob repackaging brought it
> up again?

No, the error is that the remote user is cannot login via ssh at all.

I found what caused that it worked for you. After the update realmd has to be restarted.

0 [root@rhel7 ~ ]# killall realmd
0 [root@rhel7 ~ ]# echo Pass2012! | realm -v join --user=Amy-admin --client-software=winbind --membership-software=samba ad.baseos.qe
 * Resolving: _ldap._tcp.ad.baseos.qe
 * Performing LDAP DSE lookup on: 10.34.37.22
 * Performing LDAP DSE lookup on: 2620:52:0:2223:1dfe:a8ea:f0d8:380c
 ! Can't contact LDAP server
 * Performing LDAP DSE lookup on: 2620:52:0:2223::1:1
 ! Can't contact LDAP server
 * Successfully discovered: ad.baseos.qe
Password for Amy-admin: 
 * Required files: /usr/libexec/oddjob/mkhomedir, /usr/sbin/oddjobd, /usr/bin/wbinfo, /usr/sbin/winbindd, /usr/bin/net
 * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.0Z2U2W -U Amy-admin ads join ad.baseos.qe
Enter Amy-admin's password:
DNS update failed: NT_STATUS_IO_TIMEOUT
Using short domain name -- AD
Joined 'RHEL7' to dns domain 'ad.baseos.qe'
 * LANG=C LOGNAME=root /usr/bin/net -s /var/cache/realmd/realmd-smb-conf.0Z2U2W -U Amy-admin ads keytab create
Enter Amy-admin's password:
 * /usr/bin/systemctl enable winbind.service
ln -s '/usr/lib/systemd/system/winbind.service' '/etc/systemd/system/multi-user.target.wants/winbind.service'
 * /usr/bin/systemctl restart winbind.service
 * /usr/bin/sh -c /usr/sbin/authconfig --update --enablewinbind --enablewinbindauth --enablemkhomedir --nostart && /usr/bin/systemctl enable oddjobd.service
 * Successfully enrolled machine in realm
0 [root@rhel7 ~ ]#  ssh amy.qe.0.1amy.qe.0.1's password: 
Permission denied, please try again.
amy.qe.0.1's password: 
Permission denied, please try again.
amy.qe.0.1's password: 
Permission denied (publickey,gssapi-keyex,gssapi-with-mic,password).
255 [root@rhel7 ~ ]#

Comment 14 Patrik Kis 2013-09-03 13:01:58 UTC
The problem can be triggered by realmd update to realmd-0.14.2-3.el7 but it has to be ensured that the realmd daemon is restarted so the new one is running. I managed to track down which changes caused the ssh login failures and it is most probably caused by changes from bug 985819.

The follwing lines were added to /etc/security/pam_winbind.conf after realmd upgrade and join.

#								#
# pam_winbind configuration file				# pam_winbind configuration file
#								#
# /etc/security/pam_winbind.conf				# /etc/security/pam_winbind.conf
#								#

[global]							[global]
cached_login = yes					      <
krb5_ccache_type = FILE					      <
krb5_auth = yes						      <

# turn on debugging						# turn on debugging
;debug = no							;debug = no

If they are commented out and winbind daemon restarted the ssh login starts working again.

What is still unclear to me is that the failure happens only with 2 of 3 test active directory servers I wasn't able to track down what causes the differences.

Comment 15 Patrik Kis 2013-09-03 15:00:34 UTC
Logs say while ssh as remote user this (with enabled debug in /etc/security/pam_winbind.conf):

Sep 03 16:26:53 rhel7.pkis.net sshd[19719]: error: Could not load host key: /etc/ssh/ssh_host_ecdsa_key
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=localhost  user=amy.qe
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] ENTER: pam_sm_authenticate (flags: 0x0001)
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f2ca3bca690)
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_USER) = "amy.qe" (0x7f2ca3bca6b0)
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_TTY) = "ssh" (0x7f2ca3bdabb0)
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_RHOST) = "localhost" (0x7f2ca3bdab90)
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_AUTHTOK) = 0x7f2ca3bdc460
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_CONV) = 0x7f2ca3bda330
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): getting password (0x00001391)
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): pam_get_item returned a password
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): Verify user 'AD.BASEOS.QE\amy'
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): CONFIG file: krb5_ccache_type 'FILE'
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): enabling krb5 login flag
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): enabling cached login flag
Sep 03 16:26:54 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): enabling request for a FILE krb5 ccache
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_AUTH_ERR (7), NTSTATUS: NT_STATUS_LOGON_FAILURE, Error message was: Logon failure
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): user 'AD.BASEOS.QE\amy' denied access (incorrect password or invalid membership)
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] LEAVE: pam_sm_authenticate returning 7 (PAM_AUTH_ERR)
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f2ca3bca690)
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_USER) = "amy.qe" (0x7f2ca3bca6b0)
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_TTY) = "ssh" (0x7f2ca3bdabb0)
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_RHOST) = "localhost" (0x7f2ca3bdab90)
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_AUTHTOK) = 0x7f2ca3bdc460
Sep 03 16:26:59 rhel7.pkis.net sshd[19719]: pam_winbind(sshd:auth): [pamh: 0x7f2ca3bca510] STATE: ITEM(PAM_CONV) = 0x7f2ca3bda330
Sep 03 16:27:00 rhel7.pkis.net sshd[19719]: Failed password for amy.qe from 127.0.0.1 port 50029 ssh2


and it seems that setting in  /etc/samba/smb.conf in [global] section:

 kerberos method = system keytab

does solve the problem.

I don't know if this is due to misconfigured samba or it should support something that it does not.

And I still do not understand why the ssh was working for one AD without any manual config change. And on top of that for 1 of 2 servers that was not working it starts work after some re-join and winbind restart without any config change. But for the 3rd one it can be forced only by the config change mentioned above. The only difference with this server is that it supports IPv6, but there may be other that does not come to my mind. Anyhow, it's a kind of mystery.

@ Stef, what you think? Is the config change above ok or winbind should work as it is?

Comment 17 Stef Walter 2013-09-06 13:49:58 UTC
Andreas, do you know off hand if winbind should work with 'kerberos method = system keytab' when user's are logging in via ssh? wbinfo returns valid info, but auth fails in pam_winbind with messages like this:

Sep  6 15:44:44 rhel7 sshd[4011]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=localhost  user=amy.qe
Sep  6 15:44:44 rhel7 sshd[4011]: pam_winbind(sshd:auth): getting password (0x00000390)
Sep  6 15:44:44 rhel7 sshd[4011]: pam_winbind(sshd:auth): pam_get_item returned a password
Sep  6 15:44:44 rhel7 sshd[4011]: pam_winbind(sshd:auth): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_AUTH_ERR (7), NTSTATUS: NT_STATUS_LOGON_FAILURE, Error message was: Logon failure
Sep  6 15:44:44 rhel7 sshd[4011]: pam_winbind(sshd:auth): user 'AD.BASEOS.QE\amy' denied access (incorrect password or invalid membership)
Permission denied, please try again.

Comment 18 Stef Walter 2013-09-06 13:53:44 UTC
Oh, whoops. I got that backward. The setting is missing :S My bad. This is a regression in realmd.

Comment 19 Stef Walter 2013-09-06 13:56:01 UTC
Patch upstream.

Comment 22 Ludek Smid 2014-06-13 11:08:35 UTC
This request was resolved in Red Hat Enterprise Linux 7.0.

Contact your manager or support representative in case you have further questions about the request.