URL: https://github.com/SSSD/sssd/pull/203 Author: justin-stephenson Title: #203: IPA: Enhance debug logging for ipa s2n operations Action: opened
PR body: """ Troubleshooting IPA client issues during AD Trust user and group resolution can be a difficult task requiring review of IPA client and IPA server SSSD logs during the full timeframe of a lookup request. If groups go missing on the client or client operations timeout with no obvious error then it is difficult to understand which requests to the IPA server are failing. Often times, client-side ipa_s2n functions will fail with a generic `s2n exop request failed` and the SSSD server-side logs are very busy for large AD environments.
This PR is intended to help assist in log analysis and troubleshooting efforts by adding more useful information in the IPA client logs to help narrow down the focus for searching SSSD failures on the server.
- Before patch:
``` [root@ipa-client-f25 ~]# id sssduser@ad.jstephen
[root@ipa-client-f25 ~]# grep 'ipa_s2n' /var/log/sssd/sssd_idm.jstephen.log (Thu Mar 16 15:49:43 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:49:43 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 17 (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 18 (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x4000): Found original AD upn [sssduser@AD.JSTEPHEN]. (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x2000): Updating memberships for sssduser@ad.jstephen (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 19 (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x0400): Processing group secondarygroup@ad.jstephen (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 20 (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x0400): Processing group domain users@ad.jstephen (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 21 (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:49:44 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x0400): Processing group parentofprimarygroup@ad.jstephen (Thu Mar 16 15:49:45 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x4000): Found original AD upn [sssduser@AD.JSTEPHEN]. (Thu Mar 16 15:49:45 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x2000): Updating memberships for sssduser@ad.jstephen
```
- After patch ``` [root@ipa-client-f25 ~]# id sssduser@ad.jstephen
[root@ipa-client-f25 ~]# grep 'ipa_s2n' /var/log/sssd/sssd_idm.jstephen.log (Thu Mar 16 15:59:39 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [3] for trust user [sssduser] to IPA server (Thu Mar 16 15:59:39 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:59:39 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 17 (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_user_done] (0x0400): Received [4] groups in group list from IPA Server (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_user_done] (0x0400): [sssduser@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_user_done] (0x0400): [secondarygroup@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_user_done] (0x0400): [domain users@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_user_done] (0x0400): [parentofprimarygroup@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_step] (0x0400): Sending request_type: [3] for group [sssduser@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 18 (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_next] (0x0400): Received [sssduser@ad.jstephen] attributes from IPA server. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x4000): Found original AD upn [sssduser@AD.JSTEPHEN]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x2000): Updating memberships for sssduser@ad.jstephen (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_step] (0x0400): Sending request_type: [3] for group [secondarygroup@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 19 (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_next] (0x0400): Received [secondarygroup@ad.jstephen] attributes from IPA server. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x0400): Processing group secondarygroup@ad.jstephen (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_step] (0x0400): Sending request_type: [3] for group [domain users@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 20 (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_next] (0x0400): Received [domain users@ad.jstephen] attributes from IPA server. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x0400): Processing group domain users@ad.jstephen (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_step] (0x0400): Sending request_type: [3] for group [parentofprimarygroup@ad.jstephen]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 21 (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_get_list_next] (0x0400): Received [parentofprimarygroup@ad.jstephen] attributes from IPA server. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x0400): Processing group parentofprimarygroup@ad.jstephen (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x4000): Found original AD upn [sssduser@AD.JSTEPHEN]. (Thu Mar 16 15:59:40 2017) [sssd[be[idm.jstephen]]] [ipa_s2n_save_objects] (0x2000): Updating memberships for sssduser@ad.jstephen ```
"""
To pull the PR as Git branch: git remote add ghsssd https://github.com/SSSD/sssd git fetch ghsssd pull/203/head:pr203 git checkout pr203
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
centos-ci commented: """ Can one of the admins verify this patch? """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-287174614
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
centos-ci commented: """ Can one of the admins verify this patch? """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-287174617
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
sumit-bose commented: """ ok to test """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-287178642
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
sumit-bose commented: """ Thank you for the patch. What do you think about adding a translation call like be_reg2str() to not only show the request by number? """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-287308360
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
justin-stephenson commented: """ Agreed, I think that will be more useful. I will update this PR to implement this. """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-287468395
URL: https://github.com/SSSD/sssd/pull/203 Author: justin-stephenson Title: #203: IPA: Enhance debug logging for ipa s2n operations Action: synchronized
To pull the PR as Git branch: git remote add ghsssd https://github.com/SSSD/sssd git fetch ghsssd pull/203/head:pr203 git checkout pr203
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
justin-stephenson commented: """ PR updated, sorry I wasn't sure what the proper place to add the `ipa_s2n_reqtype2str` function. I am happy to move it elsewhere if needed. """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-287837141
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
justin-stephenson commented: """ PR updated, sorry I wasn't sure what the proper place to add the `ipa_s2n_reqtype2str` function. I am happy to move it elsewhere if needed. """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-287837141
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
sumit-bose commented: """ Besides the review comments the patch looks good and is working as expected. """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-288387346
URL: https://github.com/SSSD/sssd/pull/203 Author: justin-stephenson Title: #203: IPA: Enhance debug logging for ipa s2n operations Action: synchronized
To pull the PR as Git branch: git remote add ghsssd https://github.com/SSSD/sssd git fetch ghsssd pull/203/head:pr203 git checkout pr203
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
justin-stephenson commented: """ Thank you Sumit and Lukas for the review, changes made as requested. """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-288452106
URL: https://github.com/SSSD/sssd/pull/203 Author: justin-stephenson Title: #203: IPA: Enhance debug logging for ipa s2n operations Action: synchronized
To pull the PR as Git branch: git remote add ghsssd https://github.com/SSSD/sssd git fetch ghsssd pull/203/head:pr203 git checkout pr203
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
justin-stephenson commented: """ PR updated, thanks again for the quick feedback. """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-288692791
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
sumit-bose commented: """ Thank you, ACK """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-288756475
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
Label: +Accepted
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
jhrozek commented: """ * master: * cd83aead3c9799ac05d8f8977dbb92bbd399c6d5 * a04bef313508c423ed06cc54805a3b8106ab90cd """
See the full comment at https://github.com/SSSD/sssd/pull/203#issuecomment-288776660
URL: https://github.com/SSSD/sssd/pull/203 Author: justin-stephenson Title: #203: IPA: Enhance debug logging for ipa s2n operations Action: closed
To pull the PR as Git branch: git remote add ghsssd https://github.com/SSSD/sssd git fetch ghsssd pull/203/head:pr203 git checkout pr203
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
Label: +Pushed
URL: https://github.com/SSSD/sssd/pull/203 Title: #203: IPA: Enhance debug logging for ipa s2n operations
Label: -Accepted
sssd-devel@lists.fedorahosted.org
-
centos-ci -
jhrozek
-
justin-stephenson
-
sumit-bose