URL: https://github.com/SSSD/sssd/pull/5712 Title: #5712: Health and Support Analyzer - Add request log parsing utility
justin-stephenson commented: """ > Some issues I have noticed testing more use cases: > > 1. Login attempts with a bad password, log tracking is not really helpful > to identify this: > > > ``` > # sssctl analyze request --cid=1 --pam > <snip> > ... > <snip> > (2021-07-28 14:48:20): [be[ad.vm]] [unlink_dbg] (0x2000): [RID#11] File > already removed: [/var/lib/sss/pubconf/.krb5info_dummy_YlLWP4] > (2021-07-28 14:48:20): [be[ad.vm]] [sss_domain_get_state] (0x1000): [RID#11] > Domain ad.vm is Active > (2021-07-28 14:48:20): [be[ad.vm]] [child_handler_setup] (0x2000): [RID#11] > Setting up signal handler up for pid [369475] > (2021-07-28 14:48:20): [be[ad.vm]] [child_handler_setup] (0x2000): [RID#11] > Signal handler set up for pid [369475] > (2021-07-28 14:48:20): [be[ad.vm]] [write_pipe_handler] (0x0400): [RID#11] > All data has been sent! > (2021-07-28 14:48:20): [be[ad.vm]] [read_pipe_handler] (0x0400): [RID#11] EOF > received, client finished > (2021-07-28 14:48:20): [be[ad.vm]] [check_wait_queue] (0x1000): [RID#11] Wait > queue for user [vagr...@ad.vm] is empty. > (2021-07-28 14:48:20): [be[ad.vm]] [krb5_auth_queue_done] (0x1000): [RID#11] > krb5_auth_queue request [0x15c9da0] done. > (2021-07-28 14:48:20): [be[ad.vm]] [dp_req_done] (0x0400): [RID#11] DP > Request [PAM Authenticate #11]: Request handler finished [0]: Success > (2021-07-28 14:48:20): [be[ad.vm]] [_dp_req_recv] (0x0400): [RID#11] DP > Request [PAM Authenticate #11]: Receiving request data. > (2021-07-28 14:48:20): [be[ad.vm]] [dp_req_destructor] (0x0400): [RID#11] DP > Request [PAM Authenticate #11]: Request removed. > (2021-07-28 14:48:20): [be[ad.vm]] [dp_req_destructor] (0x0400): [RID#11] > Number of active DP request: 0 > (2021-07-28 14:48:20): [be[ad.vm]] [dp_method_enabled] (0x0400): [RID#11] > Target selinux is not configured > (2021-07-28 14:48:20): [be[ad.vm]] [child_sig_handler] (0x1000): [RID#11] > Waiting for child [369475]. > (2021-07-28 14:48:20): [be[ad.vm]] [child_sig_handler] (0x0100): [RID#11] > child [369475] finished successfully. > ``` > > -- The actual errors are in the krb5_child log > > ``` > (2021-07-28 14:48:20): [krb5_child[369475]] [tgt_req_child] (0x1000): > Attempting to get a TGT > (2021-07-28 14:48:20): [krb5_child[369475]] [get_and_save_tgt] (0x0400): > Attempting kinit for realm [AD.VM] > (2021-07-28 14:48:20): [krb5_child[369475]] > [sss_krb5_get_init_creds_password] (0x0020): 1647: > [-1765328360][Preauthentication failed] > (2021-07-28 14:48:20): [krb5_child[369475]] [k5c_send_data] (0x0200): > Received error code 1432158222 > (2021-07-28 14:48:20): [krb5_child[369475]] [pack_response_packet] (0x2000): > response packet size: [4] > ``` > > -- Or in the journal > > ``` > Jul 28 14:48:20 master.client.vm sshd[369464]: pam_sss(sshd:auth): > authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=::1 > user=vagr...@ad.vm > Jul 28 14:48:20 master.client.vm sshd[369464]: pam_sss(sshd:auth): received > for user vagr...@ad.vm: 7 (Authentication failure) > Jul 28 14:48:21 master.client.vm sshd[369464]: Failed password for > vagr...@ad.vm from ::1 port 58940 ssh2 > Jul 28 14:48:20 master.client.vm krb5_child[369475]: Preauthentication failed > ``` We agreed on the logging call that this can be addressed later > > 1. If the SSSD backend is offline (down backend server), failed `id > username` command does not indicate this > > > ``` > # sssctl analyze request --list > ldb: unable to dlopen /usr/lib64/ldb/modules/ldb/memberof.la : > /usr/lib64/ldb/modules/ldb/memberof.la: invalid ELF header > ******** Listing nss client requests ******** > (2021-07-28 14:39:56: CID #1: id > - User by name > - administra...@ad.vm > # sssctl analyze request --cid=1 > ldb: unable to dlopen /usr/lib64/ldb/modules/ldb/memberof.la : > /usr/lib64/ldb/modules/ldb/memberof.la: invalid ELF header > ******** Checking nss responder for Client ID 1 ******* > (2021-07-28 14:39:56): [nss] [cache_req_send] (0x0400): CR #0: REQ_TRACE: New > request [CID #1] 'User by name' > ********* Checking Backend for Client ID 1 ******** > (2021-07-28 14:39:56): [be[ad.vm]] [dp_attach_req] (0x0400): [RID#2] DP > Request [Account #2]: REQ_TRACE: New request. [sssd.nss CID #1] Flags > [0x0001]. > (2021-07-28 14:39:56): [be[ad.vm]] [dp_attach_req] (0x0400): [RID#2] Number > of active DP request: 1 > (2021-07-28 14:39:56): [be[ad.vm]] [sss_domain_get_state] (0x1000): [RID#2] > Domain ad.vm is Active > (2021-07-28 14:39:56): [be[ad.vm]] [dp_attach_req] (0x0400): [RID#3] DP > Request [Account #3]: REQ_TRACE: New request. [sssd.nss CID #1] Flags > [0x0001]. > (2021-07-28 14:39:56): [be[ad.vm]] [dp_attach_req] (0x0400): [RID#3] Number > of active DP request: 1 > (2021-07-28 14:39:56): [be[ad.vm]] [sss_domain_get_state] (0x1000): [RID#3] > Domain ad.vm is Active > ``` > > -- This is because the tool is grepping for the tevent chain ID numbers, but > the offline log message does not include the tevent request ID > > ``` > (2021-07-28 14:35:05): [be[ad.vm]] [sbus_issue_request_done] (0x0040): > sssd.dataprovider.getAccountInfo: Error [1432158212]: SSSD is offline > ``` I added commit `DP: Log offline warning for REQ_TRACE tracking` which address this issue, thanks to Sumit's suggestion. > > 1. If the SSSD backend is offline (down backend server), SSH attempts do > not show up in the --list --pam, as the actual user lookup part failed. This > might be a bad user experience issue. No fix for this, but it may be acceptable. > > 2. Due to the nature of how files provider requests originate, and the > lack of tevent chain ID RID messages in the files provider, the parsing tool > will be pretty much useless for files provider request tracking. I think this > is an acceptable limitation. We agreed on the logging call that the files provider is not a use case we need to handle with the parsing tool. """ See the full comment at https://github.com/SSSD/sssd/pull/5712#issuecomment-892739954
_______________________________________________ sssd-devel mailing list -- sssd-devel@lists.fedorahosted.org To unsubscribe send an email to sssd-devel-le...@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-devel@lists.fedorahosted.org Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
