Bug 1298966

Summary:	[RFE] Extend Smart Card support
Product:	Red Hat Enterprise Linux 7	Reporter:	Petr Vobornik <pvoborni>
Component:	ipa	Assignee:	IPA Maintainers <ipa-maint>
Status:	CLOSED ERRATA	QA Contact:	Namita Soman <nsoman>
Severity:	medium	Docs Contact:	Marc Muehlfeld <mmuehlfe>
Priority:	high
Version:	7.2	CC:	ipa-maint, jcholast, ksiddiqu, mbasti, rcritten, rpattath, sbose
Target Milestone:	rc	Keywords:	FutureFeature
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	ipa-4.4.0-1.el7	Doc Type:	Enhancement
Doc Text:	IdM now supports smart card authentication for AD users This update extends smart card support in Identity Management (IdM). Users from a trusted Active Directory (AD) can now authenticate using a smart card both remotely using "ssh" as well as locally. The following methods are supported for local authentication: * Text console * Graphical console, such as the Gnome Display Manager (GDM) * Local authentication services, like "su" or "sudo" Note that IdM only supports the above-mentioned local authentication services and "ssh" for smart card authentication. Other services, such as FTP, are not supported. The smart card certificate for AD users can be stored directly in AD, or in an IdM override object for the AD user. For details, see https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Linux/7/html-single/Windows_Integration_Guide/index.html#smart-cards	Story Points:	---
Clone Of:
Clones:	1351248 (view as bug list)		Environment:
Last Closed:	2016-11-04 05:49:47 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:
Bug Depends On:
Bug Blocks:	1292074, 1296125, 1313485, 1351248

Description Petr Vobornik 2016-01-15 14:36:46 UTC

Support for mapping CAC identity certificates was added to IdM in 7.2 (bug 1072383 and bug 1202724). It is limited to certificates stored in user entries in IdM server.

This is a proposal to support smart cards also for AD users(in indirect AD trust scenario) where the certificate is stored is in IdM server.

Note: additional use cases are still a subject of discussion

Comment 1 Petr Vobornik 2016-01-15 14:40:45 UTC

See https://fedorahosted.org/freeipa/ticket/4955 for more details.

Comment 4 Petr Vobornik 2016-01-15 16:09:36 UTC

Upstream ticket:
https://fedorahosted.org/freeipa/ticket/4955

Comment 5 Jan Cholasta 2016-05-06 05:11:11 UTC

Fixed upstream
master:
https://fedorahosted.org/freeipa/changeset/6adf86378108cdf8b0825277431419a5e803aeb5

Comment 6 Petr Vobornik 2016-06-02 13:20:14 UTC

Upstream ticket:
https://fedorahosted.org/freeipa/ticket/5926

Comment 7 Petr Vobornik 2016-06-07 11:12:45 UTC

Web UI part - ticket 5926 is still missing.

Comment 8 Petr Vobornik 2016-06-29 14:47:21 UTC

webui part finished

master:
* aaf65e9c56c75d78d1c1f7dcefdb52dd3ddc419a Add certificate widget to ID override user details page.

Comment 9 Martin Bašti 2016-07-01 08:21:38 UTC

master:
https://fedorahosted.org/freeipa/changeset/a635135ba3caa6359c38f305d7982925ef3de50b

Comment 13 Roshni 2016-09-11 16:25:05 UTC

Seeing authentication failure when a smartcard has a cert issued by AD CA. Seeing the following in p11_child log

(Sun Sep 11 12:16:34 2016) [[sssd[p11_child[4078]]]] [main] (0x0400): p11_child started.
(Sun Sep 11 12:16:34 2016) [[sssd[p11_child[4078]]]] [main] (0x2000): Running in [auth] mode.
(Sun Sep 11 12:16:34 2016) [[sssd[p11_child[4078]]]] [main] (0x2000): Running with effective IDs: [0][0].
(Sun Sep 11 12:16:34 2016) [[sssd[p11_child[4078]]]] [main] (0x2000): Running with real IDs [0][0].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Default Module List:
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): common name: [NSS Internal PKCS #11 Module].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): dll name: [(null)].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): common name: [opensc module].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): dll name: [/usr/lib64/opensc-pkcs11.so].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Dead Module List:
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): DB Module List:
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): common name: [NSS Internal Module].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): dll name: [(null)].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Description [NSS User Private Key and Certificate Services                   Mozilla Foundation              ] Manufacturer [Mozilla Foundation              ] flags [1].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Description [NSS Internal Cryptographic Services                             Mozilla Foundation              ] Manufacturer [Mozilla Foundation              ] flags [1].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Description [OMNIKEY AG CardMan 3021 00 00                                   OpenSC (www.opensc-project.org) ] Manufacturer [OpenSC (www.opensc-project.org) ] flags [7].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Found [OpenSC Card (scuser1] in slot [OMNIKEY AG CardMan 3021 00 00][1] of module [2].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Token is NOT friendly.
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Login required.
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): found cert[OpenSC Card (scuser1:Certificate][CN=smartcard user1,CN=Users,DC=ipaad2012,DC=test]
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): Filtered certificates:
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x4000): found cert[OpenSC Card (scuser1:Certificate][CN=smartcard user1,CN=Users,DC=ipaad2012,DC=test]
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [do_work] (0x0040): VFY_VerifyData failed [-8182].
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [main] (0x0040): do_work failed.
(Sun Sep 11 12:16:35 2016) [[sssd[p11_child[4078]]]] [main] (0x0020): p11_child failed!


When the cert on the smartcard is issued by an external CA, su and gdm login were successful but ssh was failing. log messages

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [get_client_cred] (0x4000): Client creds: euid[1000] egid[1000] pid[18753].
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [accept_fd_handler] (0x0400): Client connected!
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Received client version [0].
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Offered version [0].
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ssh_cmd_parse_request] (0x0400): Requested domain [<ALL>]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_ssh_cmd_get_host_pubkeys] (0x0400): Requesting SSH host public keys for [localhost][] from [<ALL>]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_issue_request] (0x0400): Issuing request for [0x7f7c37260650:localhost]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_get_ssh_host_msg] (0x0400): Creating SSH host request for [ipa1sc0817.test][0][localhost][-]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_add_timeout] (0x2000): 0x7f7c38361740
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_internal_get_send] (0x0400): Entering request [0x7f7c37260650:localhost]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_remove_timeout] (0x2000): 0x7f7c38361740
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_dispatch] (0x4000): dbus conn: 0x7f7c38353740
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 22 error message: Invalid argument
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ssh_host_pubkeys_search_dp_callback] (0x0040): Unable to get information from Data Provider
Error: 3, 22, Invalid argument
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ssh_host_pubkeys_search_next] (0x0400): Requesting SSH host public keys for [localhost]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f7c3835ff70

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f7c383cc0e0

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x7f7c3835ff70 "ltdb_callback"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x7f7c383cc0e0 "ltdb_timeout"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x7f7c3835ff70 "ltdb_callback"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sysdb_search_ssh_hosts] (0x0400): No such host
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ssh_host_pubkeys_search] (0x0040): No matching domain found for [localhost], fail!
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f7c3836b4a0

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f7c3836b560

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x7f7c3836b4a0 "ltdb_callback"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x7f7c3836b560 "ltdb_timeout"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x7f7c3836b4a0 "ltdb_callback"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sysdb_search_ssh_hosts] (0x0400): No such host
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/pubconf/.known_hosts.FOqLeS]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/pubconf/.known_hosts.FOqLeS]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7f7c37260650:localhost]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [client_recv] (0x0200): Client disconnected!
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [client_close_fn] (0x2000): Terminated client [0x7f7c3835e880][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [get_client_cred] (0x4000): Client creds: euid[99] egid[99] pid[18758].
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c383b6ad0][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [accept_fd_handler] (0x0400): Client connected!
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c383b6ad0][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Received client version [0].
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Offered version [0].
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c383b6ad0][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c383b6ad0][20]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ssh_cmd_parse_request] (0x0400): Requested domain [<ALL>]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ssh_cmd_parse_request] (0x0400): Parsing name [scuser1][<ALL>]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_parse_name_for_domains] (0x0200): name 'scuser1' matched expression for domain 'ipaad2012.test', user is scuser1
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_ssh_cmd_get_user_pubkeys] (0x0400): Requesting SSH user public keys for [scuser1] from [ipaad2012.test]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_issue_request] (0x0400): Issuing request for [0x7f7c37268c10:1:scuser1@ipaad2012.test]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_get_account_msg] (0x0400): Creating request for [ipaad2012.test][0x1][BE_REQ_USER][1][name=scuser1:-]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_add_timeout] (0x2000): 0x7f7c38357f40
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_internal_get_send] (0x0400): Entering request [0x7f7c37268c10:1:scuser1@ipaad2012.test]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_remove_timeout] (0x2000): 0x7f7c38357f40
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_dispatch] (0x4000): dbus conn: 0x7f7c38353740
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ssh_user_pubkeys_search_next] (0x0400): Requesting SSH user public keys for [scuser1]
(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f7c38359bb0

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f7c38359c70

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x7f7c38359bb0 "ltdb_callback"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x7f7c38359c70 "ltdb_timeout"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x7f7c38359bb0 "ltdb_callback"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f7c383af420

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f7c383595a0

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x7f7c383af420 "ltdb_callback"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x7f7c383595a0 "ltdb_timeout"

(Fri Sep  9 12:56:53 2016) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x7f7c383af420 "ltdb_callback"

(Fri Sep  9 12:56:57 2016) [sssd[ssh]] [cert_to_ssh_key] (0x0020): CERT_VerifyCertificateNow failed [-8179].
(Fri Sep  9 12:56:57 2016) [sssd[ssh]] [get_valid_certs_keys] (0x0040): cert_to_ssh_key failed, ignoring.
(Fri Sep  9 12:56:57 2016) [sssd[ssh]] [decode_and_add_base64_data] (0x4000): Mssing element, nothing to do.
(Fri Sep  9 12:56:57 2016) [sssd[ssh]] [decode_and_add_base64_data] (0x4000): Mssing element, nothing to do.
(Fri Sep  9 12:56:57 2016) [sssd[ssh]] [decode_and_add_base64_data] (0x4000): Mssing element, nothing to do.
(Fri Sep  9 12:56:57 2016) [sssd[ssh]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7f7c37268c10:1:scuser1@ipaad2012.test]
(Fri Sep  9 12:56:57 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c383b6ad0][20]
(Fri Sep  9 12:56:58 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c383b6ad0][20]
(Fri Sep  9 12:56:58 2016) [sssd[ssh]] [client_recv] (0x0200): Client disconnected!
(Fri Sep  9 12:56:58 2016) [sssd[ssh]] [client_close_fn] (0x2000): Terminated client [0x7f7c383b6ad0][20]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [get_client_cred] (0x4000): Client creds: euid[99] egid[99] pid[18772].
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [accept_fd_handler] (0x0400): Client connected!
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Received client version [0].
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Offered version [0].
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ssh_cmd_parse_request] (0x0400): Requested domain [<ALL>]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ssh_cmd_parse_request] (0x0400): Parsing name [scuser1][<ALL>]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_parse_name_for_domains] (0x0200): name 'scuser1' matched expression for domain 'ipaad2012.test', user is scuser1
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_ssh_cmd_get_user_pubkeys] (0x0400): Requesting SSH user public keys for [scuser1] from [ipaad2012.test]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_dp_issue_request] (0x0400): Issuing request for [0x7f7c37268c10:1:scuser1@ipaad2012.test]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_dp_get_account_msg] (0x0400): Creating request for [ipaad2012.test][0x1][BE_REQ_USER][1][name=scuser1:-]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sbus_add_timeout] (0x2000): 0x7f7c38361480
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_dp_internal_get_send] (0x0400): Entering request [0x7f7c37268c10:1:scuser1@ipaad2012.test]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sbus_remove_timeout] (0x2000): 0x7f7c38361480
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sbus_dispatch] (0x4000): dbus conn: 0x7f7c38353740
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ssh_user_pubkeys_search_next] (0x0400): Requesting SSH user public keys for [scuser1]
(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f7c38359c70

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f7c3836b4a0

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x7f7c38359c70 "ltdb_callback"

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x7f7c3836b4a0 "ltdb_timeout"

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x7f7c38359c70 "ltdb_callback"

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f7c3838c5f0

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f7c383b7a40

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Running timer event 0x7f7c3838c5f0 "ltdb_callback"

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Destroying timer event 0x7f7c383b7a40 "ltdb_timeout"

(Fri Sep  9 12:57:00 2016) [sssd[ssh]] [ldb] (0x4000): Ending timer event 0x7f7c3838c5f0 "ltdb_callback"

(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [cert_to_ssh_key] (0x0020): CERT_VerifyCertificateNow failed [-8179].
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [get_valid_certs_keys] (0x0040): cert_to_ssh_key failed, ignoring.
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [decode_and_add_base64_data] (0x4000): Mssing element, nothing to do.
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [decode_and_add_base64_data] (0x4000): Mssing element, nothing to do.
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [decode_and_add_base64_data] (0x4000): Mssing element, nothing to do.
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7f7c37268c10:1:scuser1@ipaad2012.test]
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f7c3835e880][20]
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [client_recv] (0x0200): Client disconnected!
(Fri Sep  9 12:57:05 2016) [sssd[ssh]] [client_close_fn] (0x2000): Terminated client [0x7f7c3835e880][20]

Comment 14 Petr Vobornik 2016-09-12 07:40:38 UTC

Most likely an issue in a other component then IPA, e.g. SSSD.

Comment 15 Sumit Bose 2016-09-12 08:01:45 UTC

Yes, it makes more sense to report this issues in a SSSD related ticket, e.g. https://bugzilla.redhat.com/show_bug.cgi?id=1290378 .

Roshni, can you copy the logs to #1290378 and switch this ticket back to QA because this ticket is for the IPA server side which only includes adding and removing certificates to the id-overrides, which is unrelated to the issue you see.

Comment 16 Petr Vobornik 2016-09-13 15:09:45 UTC

Moving the state back according to comment 15.

Comment 17 Roshni 2016-09-18 20:54:56 UTC

[root@dhcp129-34 ~]# rpm -qi ipa-client
Name        : ipa-client
Version     : 4.4.0
Release     : 12.el7
Architecture: x86_64
Install Date: Sun 18 Sep 2016 12:54:23 PM EDT
Group       : System Environment/Base
Size        : 367167
License     : GPLv3+
Signature   : (none)
Source RPM  : ipa-4.4.0-12.el7.src.rpm
Build Date  : Fri 16 Sep 2016 05:23:17 AM EDT
Build Host  : x86-037.build.eng.bos.redhat.com
Relocations : (not relocatable)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
Vendor      : Red Hat, Inc.
URL         : http://www.freeipa.org/
Summary     : IPA authentication for use on clients

[root@dhcp129-34 ~]# rpm -qi sssd
Name        : sssd
Version     : 1.14.0
Release     : 42.el7
Architecture: x86_64
Install Date: Sun 18 Sep 2016 12:54:23 PM EDT
Group       : Applications/System
Size        : 35147
License     : GPLv3+
Signature   : (none)
Source RPM  : sssd-1.14.0-42.el7.src.rpm
Build Date  : Fri 16 Sep 2016 09:48:09 AM EDT
Build Host  : x86-039.build.eng.bos.redhat.com
Relocations : (not relocatable)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
Vendor      : Red Hat, Inc.
URL         : http://fedorahosted.org/sssd/
Summary     : System Security Services Daemon

Tested login using gdm, su and ssh when certificates on the card has certs associated with AD users. Smartcard authentication directly to AD server is successful. Smartcard authentication is successful when ipa has the override users for the AD users.

Comment 19 errata-xmlrpc 2016-11-04 05:49:47 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, 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://rhn.redhat.com/errata/RHBA-2016-2404.html