[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
FW: profiling
Has anyone spent any time profiling slapd to see where the CPU time goes?
I've been doing a bit of this; I've long believed that slapd is too
malloc/free happy and needs some more efficient data structure approaches.
Getting a decent profile is somewhat tricky. I think you can only get a
usable profile from a non-threaded binary, statically linked. Also, you must
force the slapd to run
in a single process, without going into the background, otherwise the
monitor snapshots are garbled by the forked process.
So far I've gotten a couple Add and Search profiles, but the add doesn't
work very well. I'm feeding in the nis_sample.ldif file from the tests
directory, and ldapadd sometimes gets an LDAP_SERVER_DOWN while loading
entries. It usually gets thru about 500 or 600 entries before it fails, but
the slapd itself is still active. This is very odd.
Anyway, I have some output from gprof if anyone is interested in seeing the
distribution of times and function calls for this limited data set.
Here are the top entries in the gprof output, if you're curious. This is for
adding
nis_sample.ldif from the tests/data directory, with some minor fixes to that
data file to get past schema problems and such. Looks like malloc time is
small in this case,
although since I don't have a profiled libc I don't know how much time is
lost there.
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls us/call us/call name
14.04 0.08 0.08 6427 12.45 12.45 idl_insert
8.77 0.13 0.05 9870 5.07 5.07 ldif_sput
5.26 0.16 0.03 115023 0.26 0.26 ber_memalloc
3.51 0.18 0.02 73959 0.27 0.27 lutil_debug
3.51 0.20 0.02 34164 0.59 0.88 avl_find
3.51 0.22 0.02 5516 3.63 8.68 ber_scanf
3.51 0.24 0.02 2725 7.34 7.34 ravl_insert
3.51 0.26 0.02 1072 18.66 469.02 do_add
3.51 0.28 0.02 1072 18.66 31.47 slap_mods_opattrs
1.75 0.29 0.01 86057 0.12 0.12 oc_index_name_cmp
1.75 0.30 0.01 75572 0.13 0.13
ldap_pvt_thread_mutex_unlo
ck
1.75 0.31 0.01 28046 0.36 0.36 ber_get_tag
1.75 0.32 0.01 15064 0.66 0.67 ber_write
1.75 0.33 0.01 13264 0.75 1.63 oc_find
1.75 0.34 0.01 12950 0.77 1.29 ber_bvdup
1.75 0.35 0.01 8740 1.14 1.14 lutil_HASHUpdate
1.75 0.36 0.01 8706 1.15 1.28 slap_get_time
1.75 0.37 0.01 7959 1.26 1.41 ber_next_element
1.75 0.38 0.01 7504 1.33 13.60 idl_insert_key
1.75 0.39 0.01 6631 1.51 1.51 ldbm_datum_free
1.75 0.40 0.01 6388 1.57 1.79 ldbm_cache_close
1.75 0.41 0.01 4595 2.18 3.05 ber_get_stringal
1.75 0.42 0.01 4275 2.34 3.49
cache_find_entry_ndn2id
1.75 0.43 0.01 2154 4.64 4.64 dn_validate
1.75 0.44 0.01 2152 4.65 5.32 ber_put_seqorset
1.75 0.45 0.01 1221 8.19 8.19 at_find_in_list
1.75 0.46 0.01 1163 8.60 8.60 UTF8StringValidate
1.75 0.47 0.01 1084 9.23 9.23 ber_getnint
1.75 0.48 0.01 1076 9.29 9.29 ber_get_option
1.75 0.49 0.01 1076 9.29 11.31 ber_put_int
1.75 0.50 0.01 1076 9.29 47.80 send_ldap_result
1.75 0.51 0.01 1072 9.33 328.13 ldbm_back_add
-- Howard Chu
Chief Architect, Symas Corp. Director, Highland Sun
http://www.symas.com http://highlandsun.com/hyc