On Thu, 2011-11-03 at 10:07 +1000, GOLLSCHEWSKY, Tim wrote:
> > So I'm pretty much out of ideas now. I was hoping trac
#1006 would fix my issue (very slow login times:
https://fedorahosted.org/pipermail/sssd-devel/2011-September/007000.html) but it
hasn't made any difference.
> >
> > Just a normal log in with my user id (which is a member of 149 groups) takes:
38.20s
>
> It is an SSH login? If so, you might be interested in
>
https://fedorahosted.org/sssd/ticket/1063
Yes it's ssh logins. That looks like a good enhancement but it's the initial
intigroups that takes a long time.
As you can see here by the timestamps. The groups have many members and it takes a long
time to iterate them all:
# /apps/sssd-1.5.14/sbin/sssd -c /etc/sssd/sssd.conf -i 2>&1 | grep 'toring
info for group'
(Thu Nov 3 10:02:12 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:12 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxange
(Thu Nov 3 10:02:12 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:12 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxlemr
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:13 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:14 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:15 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:18 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:18 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:18 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:18 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxb2
(Thu Nov 3 10:02:19 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxx002
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:20 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:21 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxx001
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:22 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:23 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:24 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:25 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:25 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:25 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:25 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:26 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:26 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:26 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:26 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:26 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:26 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:29 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:30 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:30 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:30 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:30 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:30 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:30 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:30 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:31 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:32 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:32 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:32 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:32 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:32 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:32 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:33 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:33 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:33 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxra
(Thu Nov 3 10:02:33 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:33 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:33 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:33 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxu
(Thu Nov 3 10:02:34 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:34 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:34 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:34 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:34 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxu
(Thu Nov 3 10:02:34 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:34 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxi
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxx002
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxt
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:35 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxx003
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxdef
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:36 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:37 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:37 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:37 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:37 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:37 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:37 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:38 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxp
(Thu Nov 3 10:02:38 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
(Thu Nov 3 10:02:38 2011) [sssd[be[XXX.XXX.XXX]]] [sdap_save_group] (6): Storing info
for group xxxxd
This is still very concerning. We need to profile the sdap_save_group()
routine and try to figure out where all the time is being wasted.
There's no reason I can think of that this should be taking more than
two or three seconds.