[SSSD] No negative cache with sssd_nss

Stephen Gallagher sgallagh at redhat.com
Fri Jun 29 16:38:04 UTC 2012


On Fri, 2012-06-29 at 18:27 +0200, Jan Engelhardt wrote:
> On Wednesday 2012-06-27 16:40, Stephen Gallagher wrote:
> >> >
> >> >So if you wanted to test our latest nightlies with this program, I think
> >> >you'd find it responding much faster.
> >> 
> >> Yes, I do. But for a different reason: 1.8.93 does not retrive
> >> any groups whatsoever from LDAP anymore. What broke there?
> >> (`getent groups someldapgroup` yields no output anymore.)
> >> 
> >> I skimmed over the changelog earlier and noticed that there
> >> was some change with respect to groups (ignored when no "name"
> >> attribute, was it?) The LDAP entry for (an empty group) looks like
> >> 
> >> # clients, groups, woven
> >> dn: cn=clients,ou=groups,o=woven
> >> objectClass: groupOfNames
> >> objectClass: posixGroup
> >> cn: clients
> >> gidNumber: 100000
> >> member: cn=clients,ou=groups,o=woven
> >> 
> >> and was previously properly returned in sssd-1.8.3.
> >
> >Hmm, that's very concerning. Can you get debug logs of that? (Obviously,
> >nightlies tend to be in flux, but I hadn't seen anything go this wrong
> >lately...)
> >
> sssd -d 99 -i &
> v-sfac:/etc/sssd # id jengelh
> [sssd[nss]] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[28212].
> [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1d64b80][17]
> [sssd[nss]] [accept_fd_handler] (0x0400): Client connected!
> [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1d64b80][17]
> [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1].
> [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1].
> [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1d64b80][17]
> [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1d64b80][17]
> [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'jengelh' matched without domain, user is jengelh
> [sssd[nss]] [nss_cmd_initgroups] (0x0100): Requesting info for [jengelh] from [<ALL>]
> [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request for [0x42dd60:domains at LDAP]
> [sssd[nss]] [sss_dp_get_domains_msg] (0x0400): Sending get domains request for [LDAP][not forced][]
> [sssd[nss]] [sbus_add_timeout] (0x2000): 0x1d68810
> [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering request [0x42dd60:domains at LDAP]
> [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 8E5260
> [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
> [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [getDomains]
> [sssd[be[LDAP]]] [be_get_subdomains] (0x0400): Got get subdomains [not forced][]
> [sssd[be[LDAP]]] [be_get_subdomains] (0x0100): Undefined backend target.
> [sssd[be[LDAP]]] [be_get_subdomains] (0x1000): Request processed. Returned 3,19,Subdomains back end target is not configured
> [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x1d68810
> [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn: 1D66ED0
> [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching.
> [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 19 error message: Subdomains back end target is not configured
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x1d7e380
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x1d7e430
> [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x1d7e430 "ltdb_timeout"
> [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x1d7e380 "ltdb_callback"
> [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'jengelh' matched without domain, user is jengelh
> [sssd[nss]] [nss_cmd_initgroups_cb] (0x0400): Requesting info for [jengelh] from [<ALL>]
> [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/LDAP/jengelh]
> [sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting info for [jengelh at LDAP]
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x1d7f350
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x1d7dfe0
> [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x1d7dfe0 "ltdb_timeout"
> [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x1d7f350 "ltdb_callback"
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x1d67c10
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x1d65bc0
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x1d84c20
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x1d84cd0
> [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x1d65bc0 "ltdb_timeout"
> [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x1d67c10 "ltdb_callback"
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x1d65bc0
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x1d85050
> [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x1d84cd0 "ltdb_timeout"
> [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x1d84c20 "ltdb_callback"
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x1d86100
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x1d85c60
> [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x1d85050 "ltdb_timeout"
> [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x1d65bc0 "ltdb_callback"
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x1d65bc0
> [sssd[nss]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x1d85470
> [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x1d85c60 "ltdb_timeout"
> [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x1d86100 "ltdb_callback"
> [sssd[nss]] [ldb] (0x4000): tevent: Destroying timer event 0x1d85470 "ltdb_timeout"
> [sssd[nss]] [ldb] (0x4000): tevent: Ending timer event 0x1d65bc0 "ltdb_callback"
> [sssd[nss]] [check_cache] (0x0400): Cached entry is valid, returning..
> [sssd[nss]] [nss_cmd_initgroups_search] (0x0400): Initgroups for [jengelh at LDAP] completed
> [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x42dd60:domains at LDAP]
> [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1d64b80][17]
> 
> uid=25121(jengelh) gid=100(users) groups=100(users),33(video),399,56485,31327,27072
> 
> [sssd[nss]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1d64b80][17]
> [sssd[nss]] [client_recv] (0x0200): Client disconnected!
> [sssd[nss]] [client_destructor] (0x2000): Terminated client [0x1d64b80][17]
> (Fri Jun 29 12:23:09 2012) [sssd] [services_startup_timeout] (0x0400): Handling timeout
> 
> v-sfac:/etc/sssd # getent group 31327
> v-sfac:/etc/sssd #


That's not a large enough section of the logs (also, please use
attachments, rather than pasting into the body of the email). You only
see the initgroups() call, which is working just fine. It's returning
all of the correct GIDs to which you belong.

Where it's subsequently failing is apparently while trying to do
'getgrgid(31327)'. Can you please show us the logs of that attempt?
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 198 bytes
Desc: This is a digitally signed message part
URL: <https://lists.fedorahosted.org/pipermail/sssd-devel/attachments/20120629/0489fa53/attachment.sig>


More information about the sssd-devel mailing list