RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1962550 - sss_pac_make_request fails on systems joined to Active Directory.
Summary: sss_pac_make_request fails on systems joined to Active Directory.
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: sssd
Version: 8.4
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: beta
: ---
Assignee: Sumit Bose
QA Contact: Dan Lavu
URL:
Whiteboard: sync-to-jira
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-05-20 09:16 UTC by Arya Rajendran
Modified: 2021-11-10 09:11 UTC (History)
11 users (show)

Fixed In Version: sssd-2.5.1-1.el8
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-11-09 19:47:29 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
tar ball with a test build (9.88 MB, application/gzip)
2021-05-21 09:45 UTC, Sumit Bose 		no flags Details
View All


Links
System ID Private Priority Status Summary Last Updated
Github SSSD sssd issues 5650 0 None open sss_pac_make_request fails on systems joined to Active Directory. 2021-05-25 08:45:09 UTC
Red Hat Product Errata RHBA-2021:4435 0 None None None 2021-11-09 19:47:44 UTC

Description Arya Rajendran 2021-05-20 09:16:34 UTC 
Description of problem:

PAC failures are observed in krb5_child.log logs even after adding pac responder in sssd.conf.
~~~
(2021-05-12  7:50:54): [krb5_child[105403]] [sss_send_pac] (0x0040): sss_pac_make_request failed [-1][14].
(2021-05-12  7:50:54): [krb5_child[105403]] [validate_tgt] (0x0040): sss_send_pac failed, group membership for user with principal [USER\@EXAMPLE.COM] might not be correct.
~~~

Version-Release number of selected component (if applicable):
Rhel 7.9
sssd-1.16.5-10.el7_9.7.x86_64

How reproducible:
Always in the customer environment

Actual results:

sss_pac_make_request fails

Expected results:

Succesful sss_pac_make_request

Additional info:

- keytab principal key matches with the kvno value returned from AD.

- Cleared sssd cache

- Logs: 

sssd.log:
(2021-05-12  7:50:35): [sssd] [client_registration] (0x0100): Received ID registration: (pac,1)
(2021-05-12  7:50:35): [sssd] [mark_service_as_started] (0x0200): Marking pac as started.

krb5_child.log:

(2021-05-12  7:50:54): [krb5_child[105403]] [sss_send_pac] (0x0040): sss_pac_make_request failed [-1][14].
(2021-05-12  7:50:54): [krb5_child[105403]] [validate_tgt] (0x0040): sss_send_pac failed, group membership for user with principal [USER\@EXAMPLE.COM] might not be correct.

sssd_example.com.log:

(2021-05-12  7:50:54): [be[example.com]] [check_if_pac_is_available] (0x4000): No PAC available.

sssd_pac.log:

(2021-05-12  7:50:54): [pac] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[105403].
(2021-05-12  7:50:54): [pac] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x560a951a7af0][18]
(2021-05-12  7:50:54): [pac] [accept_fd_handler] (0x0400): Client connected!
(2021-05-12  7:50:54): [pac] [sss_cmd_get_version] (0x0200): Received client version [1].
(2021-05-12  7:50:54): [pac] [sss_cmd_get_version] (0x0200): Offered version [1].
(2021-05-12  7:50:54): [pac] [client_recv] (0x0400): Invalid data from client, closing connection!
(2021-05-12  7:50:54): [pac] [client_close_fn] (0x2000): Terminated client [0x560a951a7af0][18]
(2021-05-12  7:50:54): [pac] [get_client_cred] (0x4000): Client creds: euid[2768] egid[13620000] pid[105403].
(2021-05-12  7:50:54): [pac] [accept_fd_handler] (0x0020): Access denied for uid [2768]
Comment 5 Sumit Bose 2021-05-20 10:53:50 UTC 
Hi,

so far I was not able to reproduce the issue. Can you ask to run

    strace -ff -o /tmp/sssd_be.trace -s 4096 -p $(pidof sssd_be)

as root in a terminal and try to authenticate from a different terminal. After the authentication attempt please stop strace with CRTL-C and attach the /tmp/sssd_be.trace* file (there should be more than one).

bye,
Sumit
Comment 13 Sumit Bose 2021-05-20 15:30:09 UTC 
(In reply to Arya Rajendran from comment #11)
> (In reply to Sumit Bose from comment #5)
> > Hi,
> > 
> > so far I was not able to reproduce the issue. Can you ask to run
> > 
> >     strace -ff -o /tmp/sssd_be.trace -s 4096 -p $(pidof sssd_be)
> > 
> > as root in a terminal and try to authenticate from a different terminal.
> > After the authentication attempt please stop strace with CRTL-C and attach
> > the /tmp/sssd_be.trace* file (there should be more than one).
> > 
> > bye,
> > Sumit
> 
> Hi, 
> 
> They have shared strace with "-s 1" as strace captured user password. So the
> content of the inputs/outputs is truncated. 

Hi,

I really need the i/o data to understand why the PAC responder says "[client_recv] (0x0400): Invalid data from client, closing connection!".

Would it be possible to run

    strace -ff -o /tmp/sssd_be.trace -s 4096 -p $(pidof sssd_pac)

and do a login test? The PAC responder does not handle the password.

bye,
Sumit

> Thanks
Comment 15 Sumit Bose 2021-05-21 09:45:42 UTC 
Created attachment 1785480 [details]
tar ball with a test build

Hi,

please find attached a tar ball with a test build which should fix the issue. Please let me know if it works.

bye,
Sumit
Comment 18 Sumit Bose 2021-05-25 08:43:20 UTC 
Upstream ticket:
https://github.com/SSSD/sssd/issues/5650
Comment 21 Pavel Březina 2021-06-04 07:11:01 UTC 
Pushed PR: https://github.com/SSSD/sssd/pull/5664

* `sssd-1-16`
    * afa7d965a62f7dfc9f9912aaec7ad3d905a32381 - responder/common/responder_packet: remove SSS_GSSAPI_SEC_CTX
    * 1cbfca01505733bb689d9f8e0e8c1ded7187b7ae - pac: allow larger PACs
    * 6b3671dbcfcc8d4e522bbc2a6d9c6d0bb6325fe3 - responder/common/responder_packet: reduce duplication of code that handles larger-than-normal packets
    * 17b041538ced0e95f6e98f112c261889998965f9 - responder/common/responder_packet: handle large service tickets
    * 2d136dc6820b6a6c7cf3adf57853b5bb3839aa5a - responder/common/responder_packet: get packet length only once
Comment 24 Alexey Tikhonov 2021-06-04 11:10:32 UTC 
Pushed PR: https://github.com/SSSD/sssd/pull/5652

* `master`
    * b75ef442dd23f30d879e2876bbc19d13da1a62b8 - pac: allow larger PACs
Comment 27 Dan Lavu 2021-06-15 00:26:41 UTC 
Tested and verified against sssd-2.5.1-1.el8.x86_64

sssd.conf
---------------------------------------------
[sssd]
debug_level = 9
domains = domain.com
config_file_version = 2
services = nss, pam, pac

[domain/domain.com]
debug_level = 9
ad_domain = domain.com
krb5_realm = DOMAIN.COM
realmd_tags = manages-system joined-with-adcli 
cache_credentials = True
id_provider = ad
krb5_store_password_if_offline = True
default_shell = /bin/bash
ldap_id_mapping = True
use_fully_qualified_names = True
fallback_homedir = /home/%u@%d
access_provider = ad
allowed_uids = root,administrator


[pac]
debug_level = 9


sssd.log
---------------------------------------------
(2021-06-14 20:22:49): [sssd] [sbus_senders_lookup] (0x2000): Looking for identity of sender [sssd.pac]
(2021-06-14 20:22:49): [sssd] [sbus_dispatch] (0x4000): Dispatching.
(2021-06-14 20:22:49): [sssd] [sbus_method_handler] (0x2000): Received D-Bus method org.freedesktop.DBus.GetConnectionUnixUser on /org/freedesktop/DBus
(2021-06-14 20:22:49): [sssd] [sbus_issue_request_done] (0x0400): org.freedesktop.DBus.GetConnectionUnixUser: Success
(2021-06-14 20:22:49): [sssd] [sbus_dispatch] (0x4000): Dispatching.
(2021-06-14 20:22:49): [sssd] [sbus_senders_lookup] (0x2000): Looking for identity of sender [sssd.pac]
(2021-06-14 20:22:49): [sssd] [sbus_senders_add] (0x2000): Inserting identity of sender [sssd.pac]: 0
(2021-06-14 20:22:49): [sssd] [monitor_sbus_RegisterService] (0x0100): Received ID registration: (pac,1)
(2021-06-14 20:22:49): [sssd] [mark_service_as_started] (0x0200): Marking pac as started.


krb5_child.log 
---------------------------------------------
(2021-06-14 20:23:03): [krb5_child[2946]] [validate_tgt] (0x0400): TGT verified using key for [RHEL85$@DOMAIN.COM].
(2021-06-14 20:23:03): [krb5_child[2946]] [sss_child_krb5_trace_cb] (0x4000): [2946] 1623716583.602990: Retrieving Administrator -> RHEL85$@DOMAIN.COM from MEMORY:rd_req2 with result: 0/Success

(2021-06-14 20:23:03): [krb5_child[2946]] [sss_child_krb5_trace_cb] (0x4000): [2946] 1623716583.602991: Retrieving RHEL85$@DOMAIN.COM from MEMORY:/etc/krb5.keytab (vno 3, enctype aes256-cts) with result: 0/Success

(2021-06-14 20:23:03): [krb5_child[2946]] [sss_send_pac] (0x0400): PAC responder contacted. It might take a bit of time in case the cache is not up to date.
(2021-06-14 20:23:03): [krb5_child[2946]] [sss_child_krb5_trace_cb] (0x4000): [2946] 1623716583.602992: Destroying ccache MEMORY:rd_req2


sssd_pac.log
---------------------------------------------
(2021-06-14 20:23:03): [pac] [get_client_cred] (0x4000): Client [0x55e33729bb70][23] creds: euid[0] egid[0] pid[2946] cmd_line['/usr/libexec/sssd/krb5_child'].
(2021-06-14 20:23:03): [pac] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x55e33729bb70][23]
(2021-06-14 20:23:03): [pac] [accept_fd_handler] (0x0400): Client [CID #1][cmd /usr/libexec/sssd/krb5_child][0x55e33729bb70][23] connected!
(2021-06-14 20:23:03): [pac] [sss_cmd_get_version] (0x0200): Received client version [1].
(2021-06-14 20:23:03): [pac] [sss_cmd_get_version] (0x0200): Offered version [1].
(2021-06-14 20:23:03): [pac] [sss_domain_get_state] (0x1000): Domain implicit_files is Active
(2021-06-14 20:23:03): [pac] [sss_domain_get_state] (0x1000): Domain domain.com is Active
(2021-06-14 20:23:03): [pac] [sss_domain_get_state] (0x1000): Domain domain.com is Active
(2021-06-14 20:23:03): [pac] [cache_req_set_plugin] (0x2000): CR #0: Setting "Object by SID" plugin
(2021-06-14 20:23:03): [pac] [cache_req_send] (0x0400): CR #0: REQ_TRACE: New request [CID #1] 'Object by SID'
(2021-06-14 20:23:03): [pac] [cache_req_object_by_sid_well_known] (0x4000): CR #0: SID [S-1-5-21-1852701752-3115886509-69707877-500] is not a Well-Known SID.
(2021-06-14 20:23:03): [pac] [cache_req_select_domains] (0x0400): CR #0: Performing a single domain search
(2021-06-14 20:23:03): [pac] [sss_domain_get_state] (0x1000): Domain implicit_files is Active
(2021-06-14 20:23:03): [pac] [sss_domain_get_state] (0x1000): Domain domain.com is Active
(2021-06-14 20:23:03): [pac] [cache_req_search_domains] (0x0400): CR #0: Search will check the cache and check the data provider
(2021-06-14 20:23:03): [pac] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.com type POSIX is valid
(2021-06-14 20:23:03): [pac] [cache_req_set_domain] (0x0400): CR #0: Using domain [domain.com]
(2021-06-14 20:23:03): [pac] [cache_req_search_send] (0x0400): CR #0: Looking up SID:S-1-5-21-1852701752-3115886509-69707877-500
(2021-06-14 20:23:03): [pac] [cache_req_search_ncache] (0x0400): CR #0: Checking negative cache for [SID:S-1-5-21-1852701752-3115886509-69707877-500]
(2021-06-14 20:23:03): [pac] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/SID/S-1-5-21-1852701752-3115886509-69707877-500]
(2021-06-14 20:23:03): [pac] [cache_req_search_ncache] (0x0400): CR #0: [SID:S-1-5-21-1852701752-3115886509-69707877-500] is not present in negative cache
(2021-06-14 20:23:03): [pac] [cache_req_search_cache] (0x0400): CR #0: Looking up [SID:S-1-5-21-1852701752-3115886509-69707877-500] in cache
(2021-06-14 20:23:03): [pac] [cache_req_search_send] (0x0400): CR #0: Returning [SID:S-1-5-21-1852701752-3115886509-69707877-500] from cache
(2021-06-14 20:23:03): [pac] [cache_req_search_ncache_filter] (0x0400): CR #0: This request type does not support filtering result by negative cache
(2021-06-14 20:23:03): [pac] [cache_req_create_and_add_result] (0x0400): CR #0: Found 1 entries in domain domain.com
(2021-06-14 20:23:03): [pac] [cache_req_done] (0x0400): CR #0: Finished: Success
(2021-06-14 20:23:03): [pac] [sysdb_ldb_msg_difference] (0x2000): Added attr [pacBlob] to entry [name=Administrator,cn=users,cn=domain.com,cn=sysdb]
(2021-06-14 20:23:03): [pac] [sysdb_set_entry_attr] (0x0200): Entry [name=Administrator,cn=users,cn=domain.com,cn=sysdb] has set [cache, ts_cache] attrs.
(2021-06-14 20:23:04): [pac] [client_recv] (0x0200): Client disconnected!
Comment 37 errata-xmlrpc 2021-11-09 19:47:29 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-2021:4435
Note You need to log in before you can comment on or make changes to this bug.