I'm on Centos 7.2 and thought I'd try this to see how it works. Instead of
nice output I got and error. Have I done something wrong?
[root@linux systemtap]# stap id_perf.stp
ERROR: empty aggregate near identifier 'print' at id_perf.stp:68:5
Total run time of id was: 3 ms
Number of zero-level cache transactions: 0
Time spent in level-0 sysdb transactions: 0 ms
Time spent writing to LDB: 0 ms
Number of LDAP searches: 0
Time spent waiting for LDAP: 0 ms
LDAP searches breakdown:
Number of user requests: 0
Time spent in user requests: 0
Number of group requests: 0
Time spent in group requests: 0
Number of initgroups requests: 0
Time spent in initgroups requests: 0
Unaccounted time: 3 ms
sysdb transaction breakdown:
The most expensive transaction breakdown, per transaction:
WARNING: Number of errors: 1, skipped probes: 0
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run failed. [man error::pass5]
------
The most dangerous phrase in the language is, "We've always done it this
way."
- Grace Hopper
On 26 November 2016 at 10:05, <[email protected]> wrote:
> Sorry for the delay, the holidays managed to take up more of my spare time
> than anticipated.
>
> This was done on Fedora workstation 25. Overall sssd performance appears
> to be noticeably better than Ubuntu 16.04/16.10 and Fedora 24. Please let
> me know if I made any mistakes running these tests, or if I need to run
> additional tests.
>
> ############################################################
> ########################################
> This was my quick attempt at the USE method in order to rule out other
> causes of performance issues.
> ############################################################
> ########################################
> task: id <domain user>
>
> vmstat, pidstat, and top/htop are showing high amounts of CPU time being
> spent in user-space. Looks to be sssd_be.
>
> e.g. from pidstat
> 02:34:39 PM UID PID %usr %system %guest %CPU CPU
> Command
> 02:34:40 PM 0 12518 100.00 0.00 0.00 100.00 0
> sssd_be
>
>
> iostat is showing minimal I/O occurring, disks are mostly idle. Not
> seeing any errors or queuing.
>
> nicstat shows network interfaces never go above 60% utilization. No
> network errors reported. No queuing.
>
> free is not showing any serious memory pressure, no swapping is occurring.
>
> Unsure how to measure interconnects between subsystems. May use
> perf/systemtap.
>
> ############################################################
> ########################################
>
> These runs were of id <domainuser> and each was of a different user so as
> to hopefully avoid caching.
> Each time there were warnings of missing unwind data, is there a set of
> packages I need to install to resolve this?
>
> ############################################################
> ########################################
>
> [root@fc25-vm systemtap]# stap id_perf.stp
> WARNING: Missing unwind data for a module, rerun with 'stap -d
> /usr/lib64/libtevent.so.0.9.30'
> Total run time of id was: 91098 ms
> Number of zero-level cache transactions: 15
> Time spent in level-0 sysdb transactions: 324 ms
> Time spent writing to LDB: 93 ms
> Number of LDAP searches: 83
> Time spent waiting for LDAP: 1480105770919 ms
> LDAP searches breakdown:
> Number of user requests: 0
> Time spent in user requests: 0
>
> Number of group requests: 14
> Time spent in group requests: 1933
>
> Number of initgroups requests: 0
> Time spent in initgroups requests: 0
>
> Unaccounted time: -1480105680145 ms
> sysdb transaction breakdown:
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> 0x7f78b9781474 [libtevent.so.0.9.30+0x5474]
> avg:36 min: 36 max: 36 sum: 36
>
> 8 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> 0x7f78b9781474 [libtevent.so.0.9.30+0x5474]
> avg:21 min: 19 max: 28 sum: 171
>
> 4 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> 0x7f78b9781474 [libtevent.so.0.9.30+0x5474]
> avg:29 min: 21 max: 52 sum: 117
>
> The most expensive transaction breakdown, per transaction:
> value |-------------------------------------------------- count
> 0 |@@@ 3
> 50 |@ 1
> 100 | 0
> 150 | 0
>
> ############################################################
> ########################################
>
> [root@fc25-vm systemtap]# stap -d /usr/lib64/libtevent.so.0.9.30
> id_perf.stp
> WARNING: Missing unwind data for a module, rerun with 'stap -d
> /usr/libexec/sssd/sssd_be'
> Total run time of id was: 102614 ms
> Number of zero-level cache transactions: 34
> Time spent in level-0 sysdb transactions: 7789 ms
> Time spent writing to LDB: 519 ms
> Number of LDAP searches: 742
> Time spent waiting for LDAP: 51312 ms
> LDAP searches breakdown:
> Number of user requests: 1
> Time spent in user requests: 144
>
> Number of group requests: 30
> Time spent in group requests: 50523
>
> Number of initgroups requests: 1
> Time spent in initgroups requests: 465
>
> Unaccounted time: 43513 ms
> sysdb transaction breakdown:
> 2 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> 0x55a92ac7c677 [sssd_be+0x8
> avg:22 min: 22 max: 23 sum: 45
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
>
> avg:53 min: 53 max: 53 sum: 53
>
> 4 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> 0x55fcef0ca677 [sssd_be+0x8
> avg:22 min: 22 max: 23 sum: 90
>
> 2 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> 0x55a92ac7c677 [sssd_be+0x8
> avg:2635 min: 67 max: 5203 sum: 5270
>
> 2 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> 0x55fcef0ca677 [sssd_be+0x8677]
> avg:25 min: 25 max: 26 sum: 51
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libteve
> avg:1539 min: 1539 max: 1539 sum: 1539
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_ad_save_group_membership_with_idmapping+0x532 [libsss_ldap_common.so]
> sdap_ad_tokengroups_initgr_mapping_done+0x13b [libsss_ldap_common.so]
> sdap_get_ad_tokengroups_done+0x22f [libsss_ldap_common.so]
> generic_ext_search_handler.isra.4+0xe0 [libsss_ldap_common.so]
> sdap_get_generic_op_finished+0x5ba [libsss_ldap_common.so]
> sdap_process_result+0x71d [libsss_ldap_common.so]
> tevent_common_loop_timer_delay+0xd0 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x69 [li
> avg:60 min: 60 max: 60 sum: 60
>
> 14 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> 0x55fcef0ca677 [sssd_be+0x8
> avg:29 min: 20 max: 47 sum: 416
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_save_users+0x28a [libsss_ldap_common.so]
> sdap_get_users_done+0xd2 [libsss_ldap_common.so]
> sdap_search_user_process+0x25f [libsss_ldap_common.so]
> generic_ext_search_handler.isra.4+0xe0 [libsss_ldap_common.so]
> sdap_get_generic_op_finished+0x5ba [libsss_ldap_common.so]
> sdap_process_result+0x71d [libsss_ldap_common.so]
> tevent_common_loop_timer_delay+0xd0 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x69 [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent
> avg:116 min: 116 max: 116 sum: 116
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
>
> avg:83 min: 83 max: 83 sum: 83
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_get_initgr_user+0x216 [libsss_ldap_common.so]
> generic_ext_search_handler.isra.4+0xe0 [libsss_ldap_common.so]
> sdap_get_generic_op_finished+0x5ba [libsss_ldap_common.so]
> sdap_process_result+0x71d [libsss_ldap_common.so]
> tevent_common_loop_timer_delay+0xd0 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x69 [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so
> avg:6 min: 6 max: 6 sum: 6
>
> 2 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
>
> avg:30 min: 26 max: 34 sum: 60
>
> The most expensive transaction breakdown, per transaction:
> value |-------------------------------------------------- count
> 0 | 0
> 50 |@ 1
> 100 | 0
> 150 | 0
> ~
> 450 | 0
> 500 | 0
> >500 |@ 1
>
> ############################################################
> ########################################
>
> [root@fc25-vm systemtap]# stap -d /usr/lib64/libtevent.so.0.9.30 -d
> /usr/libexec/sssd/sssd_be id_perf.stp
> WARNING: Missing unwind data for a module, rerun with 'stap -d /usr/lib64/
> libc-2.24.so'
> Total run time of id was: 162710 ms
> Number of zero-level cache transactions: 32
> Time spent in level-0 sysdb transactions: 944 ms
> Time spent writing to LDB: 301 ms
> Number of LDAP searches: 141
> Time spent waiting for LDAP: 77244 ms
> LDAP searches breakdown:
> Number of user requests: 1
> Time spent in user requests: 136
>
> Number of group requests: 29
> Time spent in group requests: 3561
>
> Number of initgroups requests: 1
> Time spent in initgroups requests: 143
>
> Unaccounted time: 84522 ms
> sysdb transaction breakdown:
> 9 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> main+0x707 [sssd_be]
> 0x7f76
> avg:28 min: 22 max: 37 sum: 254
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_get_initgr_user+0x216 [libsss_ldap_common.so]
> generic_ext_search_handler.isra.4+0xe0 [libsss_ldap_common.so]
> sdap_get_generic_op_finished+0x5ba [libsss_ldap_common.so]
> sdap_process_result+0x71d [libsss_ldap_common.so]
> tevent_common_loop_timer_delay+0xd0 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x69 [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so
> avg:5 min: 5 max: 5 sum: 5
>
> 3 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> main+0x707 [sssd_be]
> 0x7f7675d86401 [libc-2.24.so+0x20401]
> avg:21 min: 21 max: 22 sum: 64
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> main+0x707 [sssd_be]
> 0x7fc1
> avg:35 min: 35 max: 35 sum: 35
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
>
> avg:42 min: 42 max: 42 sum: 42
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_ad_save_group_membership_with_idmapping+0x532 [libsss_ldap_common.so]
> sdap_ad_tokengroups_initgr_mapping_done+0x13b [libsss_ldap_common.so]
> sdap_get_ad_tokengroups_done+0x22f [libsss_ldap_common.so]
> generic_ext_search_handler.isra.4+0xe0 [libsss_ldap_common.so]
> sdap_get_generic_op_finished+0x5ba [libsss_ldap_common.so]
> sdap_process_result+0x71d [libsss_ldap_common.so]
> tevent_common_loop_timer_delay+0xd0 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x69 [li
> avg:86 min: 86 max: 86 sum: 86
>
> 2 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
>
> avg:31 min: 26 max: 36 sum: 62
>
> 2 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
>
> avg:25 min: 24 max: 26 sum: 50
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> main+0x707 [sssd_be]
> 0x7fc1
> avg:35 min: 35 max: 35 sum: 35
>
> 4 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x21e [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
> server_loop+0x13 [libsss_util.so]
> main+0x707 [sssd_be]
> 0x7f76
> avg:27 min: 21 max: 36 sum: 111
>
> 1 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_save_users+0x28a [libsss_ldap_common.so]
> sdap_get_users_done+0xd2 [libsss_ldap_common.so]
> sdap_search_user_process+0x25f [libsss_ldap_common.so]
> generic_ext_search_handler.isra.4+0xe0 [libsss_ldap_common.so]
> sdap_get_generic_op_finished+0x5ba [libsss_ldap_common.so]
> sdap_process_result+0x71d [libsss_ldap_common.so]
> tevent_common_loop_timer_delay+0xd0 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x69 [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent
> avg:114 min: 114 max: 114 sum: 114
>
> 3 hits of transaction sysdb_transaction_commit+0xa0 [libsss_util.so]
> sdap_nested_done+0x2d5 [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> sdap_nested_group_process_done+0x1fe [libsss_ldap_common.so]
> tevent_common_loop_immediate+0xd4 [libtevent.so.0.9.30]
> epoll_event_loop_once+0x5d [libtevent.so.0.9.30]
> std_event_loop_once+0x37 [libtevent.so.0.9.30]
> _tevent_loop_once+0x9d [libtevent.so.0.9.30]
> tevent_common_loop_wait+0x1b [libtevent.so.0.9.30]
> std_event_loop_wait+0x37 [libtevent.so.0.9.30]
>
> avg:28 min: 26 max: 33 sum: 86
>
> The most expensive transaction breakdown, per transaction:
> value |-------------------------------------------------- count
> 0 | 0
> 50 | 0
> 100 |@ 1
> 150 | 0
> 200 | 0
>
> ############################################################
> ########################################
> Caching appears to be taking effect here. Guessing I should clear the user
> cache, is there a best practice for that, rather than just clearing out the
> sss/db/ directory?
> ############################################################
> ########################################
> [root@fc25-vm systemtap]# stap nested_group_perf.stp
> ^CTime spent in group sssd_be searches: 2033
> Time spent in sdap_nested_group_send/recv: 1112 ms (ratio: 54.69%)
> Time spent in zero-level sysdb transactions: 699 ms (ratio: 34.38%)
>
> Breakdown of sdap_nested_group req (total: 1112 ms)
> sdap_nested_group_process req: 1111
> sdap_nested_group_process_split req: 11
> sdap_nested_group_check_cache: 11
> sdap_nested_group_sysdb_search_users: 6
> sdap_nested_group_sysdb_search_groups: 3
> ldap request breakdown of total 2144
> sdap_nested_group_deref req: 54
> sdap_deref_search_send req 54
> processing deref results: 0
> sdap_nested_group_lookup_user req: 979
> sdap_nested_group_lookup_group req: 66
> Time spent refreshing unknown members: 1045
>
> Breakdown of results processing (total 699)
> Time spent populating nested members: 3
> Time spent searching ldb while populating nested members: 3
> Time spent saving nested members: 330
> Time spent writing to the ldb: 226 ms
>
> ############################################################
> ########################################
> This user is from a completely different department, so it likely didn't
> hit the cache much.
> ############################################################
> ########################################
> [root@fc25-vm systemtap]# stap nested_group_perf.stp
> ^CTime spent in group sssd_be searches: 12502
> Time spent in sdap_nested_group_send/recv: 4642 ms (ratio: 37.13%)
> Time spent in zero-level sysdb transactions: 1099 ms (ratio: 8.79%)
>
> Breakdown of sdap_nested_group req (total: 4642 ms)
> sdap_nested_group_process req: 4971
> sdap_nested_group_process_split req: 53
> sdap_nested_group_check_cache: 51
> sdap_nested_group_sysdb_search_users: 17
> sdap_nested_group_sysdb_search_groups: 33
> ldap request breakdown of total 55789
> sdap_nested_group_deref req: 2908
> sdap_deref_search_send req 50266
> processing deref results: 2
> sdap_nested_group_lookup_user req: 2138
> sdap_nested_group_lookup_group req: 623
> Time spent refreshing unknown members: 2762
>
> Breakdown of results processing (total 1099)
> Time spent populating nested members: 29
> Time spent searching ldb while populating nested members:
> 23
> Time spent saving nested members: 635
> Time spent writing to the ldb: 303 ms
> _______________________________________________
> sssd-users mailing list -- [email protected]
> To unsubscribe send an email to [email protected]
>
_______________________________________________
sssd-users mailing list -- [email protected]
To unsubscribe send an email to [email protected]
