Bug 1940517

Summary:	[RFE] Health and Support Analyzer: Add sssctl sub-command to select and display a single request from the logs
Product:	Red Hat Enterprise Linux 9	Reporter:	jstephen
Component:	sssd	Assignee:	jstephen
Status:	CLOSED ERRATA	QA Contact:	shridhar <sgadekar>
Severity:	medium	Docs Contact:
Priority:	medium
Version:	9.0	CC:	aboscatt, atikhono, dlavu, grajaiya, jhrozek, lslebodn, mzidek, pbrezina, sgoveas, tscherf
Target Milestone:	beta	Keywords:	FutureFeature, Triaged
Target Release:	---
Hardware:	All
OS:	Linux
Whiteboard:	sync-to-jira
Fixed In Version:	sssd-2.6.2-1.el9	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2022-05-17 16:00:30 UTC	Type:	Enhancement
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:	2011224
Bug Blocks:

Description jstephen 2021-03-18 15:12:22 UTC

To be able to understand why an individual request to SSSD fails or returns some unexpected results it would be good to have a way how this request can be tracked through the different SSSD components.

 To avoid to collect data from the logs manually sssctl should display the requests for a given frontend/type recorded in the log and allow to show the logs recorded for a given request from the frontend and backened logs (if the request hit the backend).

Comment 8 Alexey Tikhonov 2021-08-02 13:04:38 UTC

Alas, patches were not merged upstream yet.

Comment 10 Alexey Tikhonov 2021-10-25 10:22:17 UTC

Pushed PR: https://github.com/SSSD/sssd/pull/5712

* `master`
    * 097feb329c77f4d693beec05343baa4385b0d62b - SSSCTL: Add analyze command
    * 82e051e1f15060554ecacc07107c82675369e0bb - TOOLS: Add sss_analyze utility
    * 26086212a986f1485e0e52771d7aa9c31c92d8a7 - Responder: Log client uid that started a request
    * 3343b5a8111368c03ed36b965995fc255cd8530d - DP: Log offline warning for REQ_TRACE tracking

Comment 13 Alexey Tikhonov 2021-12-08 20:24:44 UTC

Additional upstream PR: https://github.com/SSSD/sssd/pull/5913

Comment 14 Alexey Tikhonov 2021-12-16 12:48:13 UTC

Pushed PR: https://github.com/SSSD/sssd/pull/5913

* `master`
    * 3ef7952e6a4b44c39a329d0f6c976e4dbc3c8785 - Analyzer: Remove python-click dependency

Comment 18 shridhar 2022-01-19 06:46:30 UTC

[root@ci-vm-10-0-138-134 tmp.uicIyk8MSW]# rpm -q sssd-tools
sssd-tools-2.6.2-1.el9.x86_64


[root@ci-vm-10-0-138-134 tmp.uicIyk8MSW]# cat /etc/sssd/sssd.conf 

[sssd]
domains = ad.baseos.qe
config_file_version = 2
services = nss, pam

[domain/ad.baseos.qe]
default_shell = /bin/bash
krb5_store_password_if_offline = True
cache_credentials = True
krb5_realm = AD.BASEOS.QE
realmd_tags = manages-system joined-with-adcli 
id_provider = ad
ldap_sasl_authid = CI-VM-10-0-138-$
fallback_homedir = /home/%u@%d
ad_domain = ad.baseos.qe
use_fully_qualified_names = True
ldap_id_mapping = True
access_provider = ad
ad_server = sec-ad1.ad.baseos.qe
debug_level = 9

[nss]
debug_level = 9

[pam]
debug_level = 9

[root@ci-vm-10-0-138-134 tmp.uicIyk8MSW]# id administrator.qe
uid=1366200500(administrator.qe) gid=1366200513(domain users.qe) groups=1366200513(domain users.qe),1366200520(group policy creator owners.qe),1366200519(enterprise admins.qe),1366200512(domain admins.qe),1366200518(schema admins.qe),1366200572(denied rodc password replication group.qe)

[root@ci-vm-10-0-138-134 tmp.uicIyk8MSW]# id amy-admin.qe
uid=1366201107(amy-admin.qe) gid=1366200513(domain users.qe) groups=1366200513(domain users.qe),1366200512(domain admins.qe),1366236880(sudo-grp.qe),1366236870(nonposix.qe),1366200572(denied rodc password replication group.qe)

.
.

[root@ci-vm-10-0-138-134 tmp.uicIyk8MSW]# sssctl analyze request list
2022-01-19  1:37:26: [uid 0] CID #1: id
2022-01-19  1:37:41: [uid 0] CID #2: id
2022-01-19  1:37:55: [uid 0] CID #3: ssh
2022-01-19  1:38:03: [uid 0] CID #4: sshd: administrator.qe
2022-01-19  1:38:09: [uid 0] CID #5: (systemd)
2022-01-19  1:38:30: [uid 0] CID #6: getent
2022-01-19  1:38:46: [uid 0] CID #7: getent
[root@ci-vm-10-0-138-134 tmp.uicIyk8MSW]# sssctl analyze request show 1
(2022-01-19  1:37:26): [nss] [accept_fd_handler] (0x0400): [CID#1] Client [cmd id][uid 0][0x55fe0a4393a0][21] connected!
(2022-01-19  1:37:26): [nss] [sss_cmd_get_version] (0x0200): [CID#1] Received client version [1].
(2022-01-19  1:37:26): [nss] [sss_cmd_get_version] (0x0200): [CID#1] Offered version [1].
(2022-01-19  1:37:26): [nss] [nss_getby_name] (0x0400): [CID#1] Input name: administrator.qe
(2022-01-19  1:37:26): [nss] [cache_req_set_plugin] (0x2000): [CID#1] CR #0: Setting "User by name" plugin
(2022-01-19  1:37:26): [nss] [cache_req_send] (0x0400): [CID#1] CR #0: REQ_TRACE: New request [CID #1] 'User by name'
(2022-01-19  1:37:26): [nss] [cache_req_send] (0x0400): [CID#1] CR #0: REQ_TRACE: New request [CID #1] 'User by name'
(2022-01-19  1:37:26): [nss] [cache_req_process_input] (0x0400): [CID#1] CR #0: Parsing input name [administrator.qe]
(2022-01-19  1:37:26): [nss] [sss_parse_name_for_domains] (0x0200): [CID#1] name 'administrator.qe' matched expression for domain 'ad.baseos.qe', user is administrator
(2022-01-19  1:37:26): [nss] [nss_get_object_send] (0x0400): [CID#1] Client [0x55fe0a4393a0][21]: sent cache request #0
(2022-01-19  1:37:26): [nss] [cache_req_set_name] (0x0400): [CID#1] CR #0: Setting name [administrator]
(2022-01-19  1:37:26): [nss] [cache_req_select_domains] (0x0400): [CID#1] CR #0: Performing a single domain search

[....]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_ldb_msg_difference] (0x2000): [RID#9] Added attr [member] to entry [name=Denied RODC Password Replication Group.qe,cn=groups,cn=ad.baseos.qe,cn=sysdb]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_set_entry_attr] (0x0200): [RID#9] Entry [name=Denied RODC Password Replication Group.qe,cn=groups,cn=ad.baseos.qe,cn=sysdb] has set [cache, ts_cache] attrs.
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_store_group] (0x0400): [RID#9] Group "Denied RODC Password Replication Group.qe" has been stored
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_groups] (0x4000): [RID#9] Group 0 members processed!
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sss_domain_get_state] (0x1000): [RID#9] Domain ad.baseos.qe is Active
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_get_primary_name] (0x0400): [RID#9] Processing object Domain Controllers
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_grpmem] (0x0400): [RID#9] Processing group Domain Controllers.qe
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_cache_search_users] (0x2000): [RID#9] Search users with filter: (&(objectCategory=user)(gidNumber=1366200516))
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_cache_search_users] (0x2000): [RID#9] No such entry
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_grpmem] (0x0400): [RID#9] No members for group [Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_remove_attrs] (0x2000): [RID#9] Removing attribute [member] from [Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_remove_attrs] (0x2000): [RID#9] Removing attribute [orig_member] from [Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_remove_attrs] (0x2000): [RID#9] Removing attribute [ghost] from [Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_store_group] (0x1000): [RID#9] The group record of Domain Controllers.qe did not change, only updated the timestamp cache
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_groups] (0x4000): [RID#9] Group 1 members processed!
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sss_domain_get_state] (0x1000): [RID#9] Domain ad.baseos.qe is Active
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_get_primary_name] (0x0400): [RID#9] Processing object Read-only Domain Controllers
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_grpmem] (0x0400): [RID#9] Processing group Read-only Domain Controllers.qe
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_cache_search_users] (0x2000): [RID#9] Search users with filter: (&(objectCategory=user)(gidNumber=1366200521))
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_cache_search_users] (0x2000): [RID#9] No such entry
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_grpmem] (0x0400): [RID#9] No members for group [Read-only Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_remove_attrs] (0x2000): [RID#9] Removing attribute [member] from [Read-only Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_remove_attrs] (0x2000): [RID#9] Removing attribute [orig_member] from [Read-only Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_remove_attrs] (0x2000): [RID#9] Removing attribute [ghost] from [Read-only Domain Controllers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_store_group] (0x1000): [RID#9] The group record of Read-only Domain Controllers.qe did not change, only updated the timestamp cache
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_groups] (0x4000): [RID#9] Group 2 members processed!
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sss_domain_get_state] (0x1000): [RID#9] Domain ad.baseos.qe is Active
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_get_primary_name] (0x0400): [RID#9] Processing object Cert Publishers
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_grpmem] (0x0400): [RID#9] Processing group Cert Publishers.qe
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_cache_search_users] (0x2000): [RID#9] Search users with filter: (&(objectCategory=user)(gidNumber=1366200517))
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_cache_search_users] (0x2000): [RID#9] No such entry
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_grpmem] (0x0400): [RID#9] Adding member users to group [Cert Publishers.qe]
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_set_entry_attr] (0x0200): [RID#9] Entry [name=Cert Publishers.qe,cn=groups,cn=ad.baseos.qe,cn=sysdb] has set [ts_cache] attrs.
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sysdb_store_group] (0x0400): [RID#9] Group "Cert Publishers.qe" has been stored
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_save_groups] (0x4000): [RID#9] Group 3 members processed!
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_nested_done] (0x2000): [RID#9] No external members, done
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_id_op_destroy] (0x4000): [RID#9] releasing operation connection
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [sdap_id_op_done] (0x4000): [RID#9] releasing operation connection
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [dp_req_done] (0x0400): [RID#9] DP Request [Account #9]: Request handler finished [0]: Success
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [_dp_req_recv] (0x0400): [RID#9] DP Request [Account #9]: Receiving request data.
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [dp_req_destructor] (0x0400): [RID#9] DP Request [Account #9]: Request removed.
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [dp_req_destructor] (0x0400): [RID#9] Number of active DP request: 0
(2022-01-19  1:37:30): [be[ad.baseos.qe]] [dp_req_reply_std] (0x1000): [RID#9] DP Request [Account #9]: Returning [Success]: 0,0,Success
[root@ci-vm-10-0-138-134 tmp.uicIyk8MSW]# 


marking verified

Comment 24 errata-xmlrpc 2022-05-17 16:00:30 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 (new packages: sssd), 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-2022:4015