On Fri, 2011-09-23 at 12:20 +1000, GOLLSCHEWSKY, Tim wrote:
Hi Dmitri, thanks for your response.
The bit I don't understand is: It does this even when I have "Enumerate" set to False. Isn't Enumerate = False supposed to stop it from downloading all the group memberships?
http://docs.redhat.com/docs/en-US/Red_Hat_Enterprise_Linux/6/html/Deployment...
Note I'm using an "ldap_filter" on just one group to control access to the box. So really for the initial login process it only needs to see the users that exist in one group. The only time I would expect it to look at other groups is when somebody types the "groups" command for example or does an "ls" in a directory.
This is not how it works. It does the resolution of the user and all his membership once user logs in. We do it once at the login as we do not know what applications and user would do. You know that you never call "groups" and want to offload the performance hit to it but we do not. This is why we can't have partial information. There were some performance issue like that that we noticed and tried to address recently. What version are you running and on what OS? Some of the recent 1.6 fixes might help.
I'm running RHEL6:
$ rpm -q sssd sssd-1.5.1-34.el6_1.3.x86_64
Also you might extend the cache timeouts significantly but then the changes made centrally would also be propagated with significant latency. I also wonder if winbind would be faster... Have you ever tried winbind?
Not for many years, but if this is preferable for large organisations I could give it a shot.
It will be interesting to compare its performance and sssd in your setup as we are bringing it as a back end to sssd soon.
If you can provide sanitized logs and info about how your data is structured (how many groups, nesting, etc) we would be able to see if this problem is something we already know about or something different.
At this point in time we have 145 groups in the "ldap_group_search_base", although this is growing all the time. Each group has about 10-200 members.
So it doesn't sound like a lot, but it takes around 30 seconds to enumerate all this information at login time.
Here's an example of the sanitised debug logs while it's doing the enumeration (heavily grep -v'd)
... (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(msSFU30PosixMember=CN=oggap,OU=xxx,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx)(objectclass=group)(cn=*)(gidNumber=*))][ou=xxx,ou=Right Groups,ou=Groups,dc=xxx,dc=xxx,dc=xxx]. (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_done] (6): Search result: Success(0), (null) (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_update_sysdb] (6): Processing group [oggap] (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Search groups with filter: (&(objectclass=group)(member=name=oggap,cn=groups,cn=XXX.XXX.XXX,cn=sysdb)) (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_update_sysdb] (6): Group [oggap] is not a direct member of any groups (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_step] (6): Looking up parent groups for group [CN=rmbad,OU=xxx,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx] (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(msSFU30PosixMember=CN=rmbad,OU=xxx,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx)(objectclass=group)(cn=*)(gidNumber=*))][ou=xxx,ou=Right Groups,ou=Groups,dc=xxx,dc=xxx,dc=xxx]. (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_done] (6): Search result: Success(0), (null) (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_update_sysdb] (6): Processing group [rmbad] (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Search groups with filter: (&(objectclass=group)(member=name=rmbad,cn=groups,cn=XXX.XXX.XXX,cn=sysdb)) (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_update_sysdb] (6): Group [rmbad] is not a direct member of any groups (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_step] (6): Looking up parent groups for group [CN=iswad,OU=xxx,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx] (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(msSFU30PosixMember=CN=iswad,OU=xxx,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx)(objectclass=group)(cn=*)(gidNumber=*))][ou=xxx,ou=Right Groups,ou=Groups,dc=xxx,dc=xxx,dc=xxx]. (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_done] (6): Search result: Success(0), (null) (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_update_sysdb] (6): Processing group [iswad] (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sysdb_search_groups] (6): Search groups with filter: (&(objectclass=group)(member=name=iswad,cn=groups,cn=XXX.XXX.XXX,cn=sysdb)) (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_update_sysdb] (6): Group [iswad] is not a direct member of any groups (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_step] (6): Saving incomplete group [voirp] to the sysdb (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [rfc2307bis_nested_groups_step] (6): Looking up parent groups for group [CN=voirp,OU=xxx,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx] (Fri Sep 23 08:58:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(msSFU30PosixMember=CN=voirp,OU=xxx,OU=Right Groups,OU=Groups,DC=xxx,DC=xxx,DC=xxx)(objectclass=group)(cn=*)(gidNumber=*))][ou=xxx,ou=Right Groups,ou=Groups,dc=xxx,dc=xxx,dc=xxx]. ...
This isn't enough information to say where the latency is occurring. Is the 30s passing while it's still iterating through "Looking up parent groups for group", or are you seeing it happen while the SSSD is saving the results to the cache? I'm guessing that the problem is likely happening during the latter. We're doing a lot of work right now for 1.6.2 with improving the cache performance, but I'd like to try and track this down to make sure our current enhancement plans will aid you.