On Fri, Aug 9, 2013 at 9:42 AM, Lukas Slebodnik <lslebodn@redhat.com> wrote:

And then try to get some information about problematic group.
getent group -s sss 1596003661

Output from that command:

USER@smarty:~$ getent group -s sss 1596003661
certificate service dcom access:*:1596003661:

Performed again with another phantom group:

USER@smarty:/etc/puppet/modules/sssd$ getent group -s sss 1596003662
users:*:1596003662:aspnet

I've got debug output but it contains some relatively private information (first and last names, usernames, possibly other directory information). It's also rather large (11K lines). Could I share this offlist if necessary?

As it is, here are some relevant lines. In this case, the reported bad group was 1596003663.

==> sssd_nss.log <==
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x9656278
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn: 964B150
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for [1596003206@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9655fe0
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9648240
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x9648240 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x9655fe0 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0400): Returning info for gid [1596003206@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/GROUP/TESTDOMAIN/drupal_admin]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/TESTDOMAIN/testuser]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x807bb20:2:1596003206@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/GID/1596003663]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for [1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9648298
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9656a70
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x9656a70 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x9648298 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request for [0x807bb20:2:1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request for [TESTDOMAIN][4098][1][idnumber=1596003663]
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x96579e8
(Fri Aug 9 10:46:01 2013) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering request [0x807bb20:2:1596003663@TESTDOMAIN]
==> sssd_TESTDOMAIN.log <==
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: sh[0x9543678], connected[1], ops[(nil)], ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sbus_dispatch] (0x4000): dbus conn: 95379C0
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [be_get_account_info] (0x0100): Got request for [4098][1][idnumber=1596003663]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [DC=TESTDOMAIN,DC=local]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectSID=S-1-5-21-1779125721-235263668-3792523542-3663)(objectclass=group)(name=*))][DC=TESTDOMAIN,DC=local].
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [member]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 104
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300], ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300], ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300], ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: sh[0x9543678], connected[1], ops[0x958c300], ldap[0x9537030]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 0 results.
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9550388
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9658190
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Destroying timer event 0x9658190 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Ending timer event 0x9550388 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x95562b0
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9556310
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x95f5ac8
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x95507e0
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Destroying timer event 0x9556310 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Ending timer event 0x95562b0 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x95ea5e8
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x95c6c58
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Destroying timer event 0x95507e0 "ltdb_timeout"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Ending timer event 0x95f5ac8 "ltdb_callback"
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x95c6d60
(Fri Aug 9 10:46:01 2013) [sssd[be[TESTDOMAIN]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x95e9b20
etc...
<output ommitted>
==> sssd_nss.log <==
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x96579e8
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn: 964B150
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching.
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0100): Requesting info for [1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x965a8f0
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x96575c0
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x96575c0 "ltdb_timeout"
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x965a8f0 "ltdb_callback"
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0040): No matching domain found for [1596003663], fail!
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x807bb20:2:1596003663@TESTDOMAIN]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x9658678][23]
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
(Fri Aug 9 10:46:02 2013) [sssd[nss]] [client_destructor] (0x2000): Terminated client [0x9658678][23]
==> sssd_TESTDOMAIN.log <==
(Fri Aug 9 10:46:02 2013) [sssd[be[TESTDOMAIN]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success
(Fri Aug 9 10:46:02 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: sh[0x9543678], connected[1], ops[(nil)], ldap[0x9537030]
(Fri Aug 9 10:46:02 2013) [sssd[be[TESTDOMAIN]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!

Thanks.

-Chris