Bug 1871288

Summary: krb5_child denies ssh users when pki device detected [rhel-7.9.z]
Product: Red Hat Enterprise Linux 7 Reporter: Karl Grindley <g63it>
Component: sssdAssignee: Sumit Bose <sbose>
Status: CLOSED ERRATA QA Contact: Scott Poore <spoore>
Severity: high Docs Contact:
Priority: unspecified    
Version: 7.8CC: atikhono, grajaiya, jhrozek, jreznik, lslebodn, mzidek, pbrezina, sbose, sgoveas, spoore, thalman, tscherf
Target Milestone: rcKeywords: ZStream
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard: sync-to-jira qetodo
Fixed In Version: sssd-1.16.5-10.el7_9.6 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-12-15 11:22:17 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 Karl Grindley 2020-08-21 23:45:18 UTC
Description of problem:
When a PKI smartcard device is inserted, and a DIFFERENT user attempts to ssh with a password, krb5_child will attempt to perform a PKINIT using the smartcard credential instead of using the password token passed in from the pam stack. this fails the auth stack and user is denied.

disabling pcscd.socket allows the user to login without issue. (but smartcard auth no longer works)

I might suggest a simple fix - add an option to pam_sss such as nop11 in the password-auth-ac stack?  Also, this doesn't appear to be a problem on RHEL8, so perhaps a missing fix to the 1.16 branch?

Version-Release number of selected component (if applicable):
python-sssdconfig.noarch  1.16.4-37.el7_8.4
sssd.x86_64               1.16.4-37.el7_8.4
sssd-ad.x86_64            1.16.4-37.el7_8.4
sssd-client.x86_64        1.16.4-37.el7_8.4
sssd-common.x86_64        1.16.4-37.el7_8.4
sssd-common-pac.x86_64    1.16.4-37.el7_8.4
sssd-dbus.x86_64          1.16.4-37.el7_8.4
sssd-ipa.x86_64           1.16.4-37.el7_8.4
sssd-kcm.x86_64           1.16.4-37.el7_8.4
sssd-krb5.x86_64          1.16.4-37.el7_8.4
sssd-krb5-common.x86_64   1.16.4-37.el7_8.4
sssd-ldap.x86_64          1.16.4-37.el7_8.4
sssd-proxy.x86_64         1.16.4-37.el7_8.4
sssd-tools.x86_64         1.16.4-37.el7_8.4

(note, we are running the patched version with the the certmap backport, but are applied to this version)

How reproducible:
every time

Steps to Reproduce:
1. setup sssd as the pki provider (not pam_pkcs11) and enable pki support
2. verify PKI authentication works via GDM
3. attempt to ssh in using another directory user account

Actual results:
User is not granted access.  Following is logged.

Aug 21 19:33:53 rhel7-system [sssd[krb5_child[727]]][727]: Pre-authentication failed: Preauthentication failed
Aug 21 19:33:54 rhel7-system [sssd[krb5_child[730]]][730]: Pre-authentication failed: Preauthentication failed
Aug 21 19:33:54 rhel7-system [sssd[krb5_child[730]]][730]: Pre-authentication failed: Preauthentication failed
Aug 21 19:33:54 rhel7-system [sssd[krb5_child[730]]][730]: Pre-authentication failed: Preauthentication failed
Aug 21 19:33:54 rhel7-system sshd[719]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=remotesystem.example.com user=ssh_user
Aug 21 19:33:54 rhel7-system sshd[719]: pam_sss(sshd:auth): received for user ssh_user: 17 (Failure setting user credentials)
Aug 21 19:33:56 rhel7-system sshd[719]: Failed password for ssh_user from 192.168.1.100 port 58970 ssh2


Expected results:
Ssh user should be allowed to log in.

Additional info:

the following is reported using sssd debug logging. (anonymized)
==> krb5_child.log <==
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [main] (0x0400): krb5_child started.
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [unpack_buffer] (0x1000): total buffer size: [115]
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [unpack_buffer] (0x0100): cmd [241] uid [966406121] gid [966400513] validate [true] enterprise principal [true] offline [false] UPN [ssh_user]
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [KCM:] keytab: [/etc/krb5.keytab]
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [check_use_fast] (0x0100): Not using FAST.
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [switch_creds] (0x0200): Switch user to [966406121][966400513].
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [switch_creds] (0x0200): Switch user to [0][0].
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [KCM:] and is  active and TGT is  valid.
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [become_user] (0x0200): Trying to become user [966406121][966400513].
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [main] (0x2000): Running as [966406121][966400513].
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [k5c_setup] (0x2000): Running as [966406121][966400513].
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [set_lifetime_options] (0x0100): Renewable lifetime is set to [30d]
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [set_lifetime_options] (0x0100): Lifetime is set to [24h]
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true]
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [main] (0x0400): Will perform online auth
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [tgt_req_child] (0x1000): Attempting to get a TGT
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [EXAMPLE.COM]
(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711589: Getting initial credentials for ssh_user\@EXAMPLE.COM

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711591: Sending unauthenticated request

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711592: Sending request (213 bytes) to EXAMPLE.COM

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711593: Initiating TCP connection to stream 192.168.1.10:88

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711594: Sending TCP request to stream 192.168.1.10:88

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711595: Received answer (193 bytes) from stream 192.168.1.10:88

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711596: Terminating TCP connection to stream 192.168.1.10:88

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711597: Response was from master KDC

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711598: Received error from KDC: -1765328359/Additional pre-authentication required

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711601: Preauthenticating using KDC method data

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711602: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)

(Fri Aug 21 19:20:00 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052000.711603: Selected etype info: etype aes256-cts, salt "EXAMPLE.COMssh_user", params ""

(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_responder] (0x4000): Got question [pkinit].
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [answer_pkinit] (0x4000): [0] Identity [PKCS11:module_name=/usr/lib64/pkcs11/opensc-pkcs11.so:slotid=8:token=Other PKI User] flags [0].
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [answer_pkinit] (0x4000): Setting pkinit_prompting.
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL.
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_prompter] (0x4000): Prompt [0][(YUBI) Other PKI User    PIN].
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts.
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052001.144941: PKINIT client has no configured identity; giving up

(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052001.144942: Preauth module pkinit (16) (real) returned: -1765328360/Preauthentication failed

(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052001.144943: PKINIT client has no configured identity; giving up

(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052001.144944: Preauth module pkinit (14) (real) returned: -1765328360/Preauthentication failed

(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL.
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for ssh_user\@EXAMPLE.COM].
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts.
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_child_krb5_trace_cb] (0x4000): [32720] 1598052001.144945: Preauth module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read password

(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [sss_krb5_get_init_creds_password] (0x0020): 1627: [-1765328174][Pre-authentication failed: Preauthentication failed]
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [get_and_save_tgt] (0x0020): 1704: [-1765328174][Pre-authentication failed: Preauthentication failed]
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [map_krb5_error] (0x0020): 1817: [-1765328174][Pre-authentication failed: Preauthentication failed]
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [k5c_send_data] (0x0200): Received error code 1432158221
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [pack_response_packet] (0x2000): response packet size: [4]
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [k5c_send_data] (0x4000): Response sent.
(Fri Aug 21 19:20:01 2020) [[sssd[krb5_child[32720]]]] [main] (0x0400): krb5_child completed successfully

Comment 2 Sumit Bose 2020-08-24 09:25:18 UTC
Hi,

please check https://github.com/SSSD/sssd/issues/5290 for a discussion of the issue.

bye,
Sumit

Comment 3 Alexey Tikhonov 2020-08-25 10:34:13 UTC
Upstream PR: https://github.com/SSSD/sssd/pull/5294

Comment 6 Pavel Březina 2020-09-04 09:24:23 UTC
Pushed PR: https://github.com/SSSD/sssd/pull/5294

* `master`
    * bca413267f58395e22415edc662a7ba89fbe7b30 - krb5: only try pkinit with Smartcard credentials
* `sssd-1-16`
    * 277cd1fa71222f3bdf4d8b39d0bce7d07d0df07b - krb5: only try pkinit with Smartcard credentials

Comment 7 Alexey Tikhonov 2020-09-04 10:55:43 UTC
Hi Karl,

Having customer case backing up this request, might increase chances of fulfillment (i.e. actual inclusion of the patch into RHEL7).

Comment 8 Karl Grindley 2020-09-04 15:17:52 UTC
Case 02745114 opened as a premium/severity 2(high) since it's impacting user experience/workflow/denial of service.
https://access.redhat.com/support/cases/#/case/02745114

We're working around using our custom packages which include other fixes as well, but we can't be the only ones with this problem.

Comment 9 Alexey Tikhonov 2020-09-04 15:26:27 UTC
(In reply to Karl Grindley from comment #8)
> Case 02745114 opened 

Thank you.

Do you have `pkinit_identities` set in `/etc/krb5.conf`?

If "yes", could you please check if removing this setting helps to work around the issues?

Comment 24 Scott Poore 2020-11-30 18:22:48 UTC
Verified.

Version ::

sssd-1.16.5-10.el7_9.6

Results ::

First reproducing issue:

[root@rhel7-4 ~]# rpm -q sssd
sssd-1.16.5-10.el7.x86_64

[root@rhel7-4 ~]# grep pkinit_identities /etc/krb5.conf
  pkinit_identities = PKCS11:/usr/lib64/pkcs11/opensc-pkcs11.so

[root@rhel7-4 ~]# grep ldap_opt_timeout /etc/sssd/sssd.conf
ldap_opt_timeout = 60

[root@rhel7-4 ~]# systemctl stop sssd; rm -rf /var/lib/sss/{db,mc}/*; systemctl start sssd

[root@rhel7-4 ~]# su - ipauser1 -c 'su - ipauser1 -c whoami'
PIN for sctest (MyEID)
ipauser1

[root@rhel7-4 ~]# ssh ipauser2@localhost
Password:
Password:
Password:
^^^ failing to login with pkinit_identities set ^^^

Now with updated sssd:

[root@rhel7-4 ~]# yum update sssd -y
...

[root@rhel7-4 ~]# rpm -q sssd
sssd-1.16.5-10.el7_9.6.x86_64

[root@rhel7-4 ~]# systemctl stop sssd; rm -rf /var/lib/sss/{db,mc}/*; systemctl start sssd

[root@rhel7-4 ~]# su - ipauser1 -c 'su - ipauser1 -c whoami'
PIN for sctest (MyEID)
ipauser1

[root@rhel7-4 ~]# ssh ipauser2@localhost
Password: 
Last failed login: Mon Nov 30 12:12:36 CST 2020 from localhost on ssh:notty
There were 2 failed login attempts since the last successful login.
Last login: Mon Nov 30 08:24:07 2020 from localhost

-sh-4.2$ whoami
ipauser2

Comment 29 errata-xmlrpc 2020-12-15 11:22:17 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (sssd bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:5459

Comment 30 Red Hat Bugzilla 2023-09-14 06:06:35 UTC
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 1000 days