Here are some more runs of nested_group_perf.stp.
Running fc25 workstation, kernel 4.8.8-300.fc25.x86_64, gnome desktop.
############################################################################################ Noticed a small issue with the system tap script ############################################################################################ nested_group_perf.stp
When missing a package it suggests using yum rather than dnf.
e.g.
“use: yum install kernel-devel-4.8.8-300.fc25.x86_64”
############################################################################################ Modifications to /etc/sssd/sssd.conf: dyndns_update = True ############################################################################################ real 1m23.424s user 0m0.006s sys 0m0.013s
[root@fc25-vm systemtap]# stap nested_group_perf.stp ^CTime spent in group sssd_be searches: 18543 Time spent in sdap_nested_group_send/recv: 12793 ms (ratio: 68.99%) Time spent in zero-level sysdb transactions: 4894 ms (ratio: 26.39%)
Breakdown of sdap_nested_group req (total: 12793 ms) sdap_nested_group_process req: 10973 sdap_nested_group_process_split req: 502 sdap_nested_group_check_cache: 459 sdap_nested_group_sysdb_search_users: 226 sdap_nested_group_sysdb_search_groups: 213 ldap request breakdown of total 22629 sdap_nested_group_deref req: 7462 sdap_deref_search_send req 12399 processing deref results: 534 sdap_nested_group_lookup_user req: 4611 sdap_nested_group_lookup_group req: 791 Time spent refreshing unknown members: 4828
Breakdown of results processing (total 4894) Time spent populating nested members: 1581 Time spent searching ldb while populating nested members: 1372 Time spent saving nested members: 2829 Time spent writing to the ldb: 470 ms
############################################################################################ Same user, ran sss_cache -UG, but perhaps some organizational information is still cached?
Not sure what else accounts for the time difference. ############################################################################################ real 0m49.898s user 0m0.004s sys 0m0.007s
[root@fc25-vm systemtap]# stap nested_group_perf.stp ^CTime spent in group sssd_be searches: 16000 Time spent in sdap_nested_group_send/recv: 7629 ms (ratio: 47.68%) Time spent in zero-level sysdb transactions: 1770 ms (ratio: 11.06%)
Breakdown of sdap_nested_group req (total: 7629 ms) sdap_nested_group_process req: 5971 sdap_nested_group_process_split req: 302 sdap_nested_group_check_cache: 281 sdap_nested_group_sysdb_search_users: 150 sdap_nested_group_sysdb_search_groups: 120 ldap request breakdown of total 21757 sdap_nested_group_deref req: 3708 sdap_deref_search_send req 14555 processing deref results: 36 sdap_nested_group_lookup_user req: 3243 sdap_nested_group_lookup_group req: 583 Time spent refreshing unknown members: 3376
Breakdown of results processing (total 1770) Time spent populating nested members: 302 Time spent searching ldb while populating nested members: 268 Time spent saving nested members: 1236 Time spent writing to the ldb: 212 ms
############################################################################################ Different user than before. ############################################################################################ real 0m41.878s user 0m0.004s sys 0m0.003s
[root@fc25-vm systemtap]# stap nested_group_perf.stp ^CTime spent in group sssd_be searches: 16000 Time spent in sdap_nested_group_send/recv: 7629 ms (ratio: 47.68%) Time spent in zero-level sysdb transactions: 1770 ms (ratio: 11.06%)
Breakdown of sdap_nested_group req (total: 7629 ms) sdap_nested_group_process req: 5971 sdap_nested_group_process_split req: 302 sdap_nested_group_check_cache: 281 sdap_nested_group_sysdb_search_users: 150 sdap_nested_group_sysdb_search_groups: 120 ldap request breakdown of total 21757 sdap_nested_group_deref req: 3708 sdap_deref_search_send req 14555 processing deref results: 36 sdap_nested_group_lookup_user req: 3243 sdap_nested_group_lookup_group req: 583 Time spent refreshing unknown members: 3376
Breakdown of results processing (total 1770) Time spent populating nested members: 302 Time spent searching ldb while populating nested members: 268 Time spent saving nested members: 1236 Time spent writing to the ldb: 212 ms
[root@fc25-vm systemtap]# stap nested_group_perf.stp ^CTime spent in group sssd_be searches: 6862 Time spent in sdap_nested_group_send/recv: 5495 ms (ratio: 80.07%) Time spent in zero-level sysdb transactions: 1133 ms (ratio: 16.51%)
Breakdown of sdap_nested_group req (total: 5495 ms) sdap_nested_group_process req: 4024 sdap_nested_group_process_split req: 182 sdap_nested_group_check_cache: 158 sdap_nested_group_sysdb_search_users: 49 sdap_nested_group_sysdb_search_groups: 90 ldap request breakdown of total 18417 sdap_nested_group_deref req: 2900 sdap_deref_search_send req 14437 processing deref results: 46 sdap_nested_group_lookup_user req: 1687 sdap_nested_group_lookup_group req: 482 Time spent refreshing unknown members: 1811
Breakdown of results processing (total 1133) Time spent populating nested members: 88 Time spent searching ldb while populating nested members: 63 Time spent saving nested members: 910 Time spent writing to the ldb: 77 ms
############################################################################################ ^C[root@fc25-vm systemtap]# stap nested_group_perf.stp ^CTime spent in group sssd_be searches: 5021 Time spent in sdap_nested_group_send/recv: 10726 ms (ratio: 213.62%) Time spent in zero-level sysdb transactions: 368 ms (ratio: 7.32%)
Breakdown of sdap_nested_group req (total: 10726 ms) sdap_nested_group_process req: 1480525834936 sdap_nested_group_process_split req: 124 sdap_nested_group_check_cache: 51 sdap_nested_group_sysdb_search_users: 31 sdap_nested_group_sysdb_search_groups: 19 ldap request breakdown of total 22264 sdap_nested_group_deref req: 1480525833504 sdap_deref_search_send req 16770 processing deref results: 1480525825718 sdap_nested_group_lookup_user req: 2637 sdap_nested_group_lookup_group req: 110 Time spent refreshing unknown members: 2747
Breakdown of results processing (total 368) Time spent populating nested members: 4729 Time spent searching ldb while populating nested members: 3947 Time spent saving nested members: 221 Time spent writing to the ldb: 95 ms
############################################################################################
real 2m4.412s user 0m0.004s sys 0m0.005s
[root@fc25-vm systemtap]# stap nested_group_perf.stp ^C ^CTime spent in group sssd_be searches: 8083 Time spent in sdap_nested_group_send/recv: 36901 ms (ratio: 456.52%) Time spent in zero-level sysdb transactions: 2329 ms (ratio: 28.81%)
Breakdown of sdap_nested_group req (total: 36901 ms) sdap_nested_group_process req: 35943 sdap_nested_group_process_split req: 177 sdap_nested_group_check_cache: 146 sdap_nested_group_sysdb_search_users: 50 sdap_nested_group_sysdb_search_groups: 87 ldap request breakdown of total 29401 sdap_nested_group_deref req: 34914 sdap_deref_search_send req 26218 processing deref results: 25004 sdap_nested_group_lookup_user req: 1385 sdap_nested_group_lookup_group req: 340 Time spent refreshing unknown members: 1458
Breakdown of results processing (total 2329) Time spent populating nested members: 826 Time spent searching ldb while populating nested members: 590 Time spent saving nested members: 1786 Time spent writing to the ldb: 256 ms
############################################################################################ su - <domain user> ############################################################################################ [root@fc25-vm systemtap]# stap nested_group_perf.stp ^CTime spent in group sssd_be searches: 545 Time spent in sdap_nested_group_send/recv: 1480527569532 ms (ratio: 271656434776.51%) Time spent in zero-level sysdb transactions: 112 ms (ratio: 20.55%)
Breakdown of sdap_nested_group req (total: 1480527569532 ms) sdap_nested_group_process req: 1480527569440 sdap_nested_group_process_split req: 11 sdap_nested_group_check_cache: 11 sdap_nested_group_sysdb_search_users: 5 sdap_nested_group_sysdb_search_groups: 6 ldap request breakdown of total 451 sdap_nested_group_deref req: 1480527569424 sdap_deref_search_send req 192 processing deref results: 1480527569190 sdap_nested_group_lookup_user req: 114 sdap_nested_group_lookup_group req: 15 Time spent refreshing unknown members: 130
Breakdown of results processing (total 112) Time spent populating nested members: 649 Time spent searching ldb while populating nested members: 438 Time spent saving nested members: 58 Time spent writing to the ldb: 38 ms