[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
Re: OpenLDAP profiling/performance
At 05:01 PM 1/3/01 -0500, Ben Collins wrote:
>I've been working with a 6000 entry user database. For awhile I was
>using OpenLDAP 1.2.11, which was working great, but to take advantage of
>some of the more advanced ACL's I switched the production box to using
>OpenLDAP 2.0.7. Big mistake.
While 2.0's ACLs are "more advanced", they are also "more expensive"
(even for a set of ACLs using only 1.2 features).
>Searches for things like "uid=foo" were taking about 30 seconds (this on
>a machine with 128megs of ram and a 450Mhz PIII, dedicated to just this
>LDAP server).
Sound like you don't have an equality index on uid.
>Note, this is running under Linux, kernel 2.2.x (not that
>it matters). Also note that the openldap 1.2.11 and 2.0.7 setup were
>pretty much identical. Both of them had indexes for these attrbiutes (in
>fact, almost all of the attributes were indexed).
you have, I assume, in both:
index uid eq
(note that 'default' has different semantics in 2.0)
>I then compiled two binaries, one is 1.2.11 and the other is 2.0.7,
>using -pg (profiling). The results were a little disturbing. Here's a
>look at 2.0.7, with indexes for a single search in the 6000 entry db with
>this filter "uid=bcollins":
>
> (# of times called)
> 0.00 0.04 0.00 1830352 0.00 0.00 ch_free
> 0.00 0.04 0.00 1286279 0.00 0.00 attr_index_name_cmp
> 0.00 0.04 0.00 1241312 0.00 0.00 ch_malloc
> ^^^^^^^
>
>Note how many times these functions are called. This is mainly from
>str2entry(), which is itself called by id2entry_rw(), and that is called
>by ldbm_back_search(). Now, ldbm_back_search() is called only once in
>this scenario, while id2entry_rw() and thus str2entry(), are called
>11124 times by ldbm_back_search().
This implies you don't have an equality index on uid.
(I note that 11124 str2entry calls seems odd give a 6000 entry
DB).
>Now, let's look at the highest called functions in the 1.2.11 profile:
>
> 0.00 0.00 0.00 3091 0.00 0.00 ldap_pvt_thread_mutex_init
> 0.00 0.00 0.00 2397 0.00 0.00 ch_strdup
> 0.00 0.00 0.00 1188 0.00 0.00 strtok_quote
> 0.00 0.00 0.00 1030 0.00 0.00 ldap_pvt_thread_cond_init
> ^^^^
>
>Quit a bit of difference. Also, the number of times that str2entry() and
>id2entry() are called is down to a measly 2 each!
indexing in action.
>One more point, I tried both of these with and without indexing. The
>1.2.11 without indexing is comparable to that of 2.0.7 (with or
>without). OpenLDAP 2.0.7 without indexing was the same as with
>(performance wise), however the profile looks slightly different, so
>something is being done differently. I suspect the index isn't being
>used though, atleast not optimally. I also tried the head branch, and
>got the same results.
I suspect the difference is that you have some index defined
for uid but not an equality index... and hence the difference
in behavior. Or the code could be broke...
>Kurt, any ideas on why this is happening? There looks like a lot of
>indirection has been added since openldap 1.2.x. A lot of chasing
>a single function call, iterates down 4 other consecutive functions.
The fun of attribute type subtyping....
>Also, the debugging functions are getting a high count. Now they might
>not being doing much, but the overhead in jumping from one function to
>another and then back, surely is causing some performance drop. I'm
>probably back to square one from before when I planned on rewriting the
>debug code. FYI, lutil_debug() was called 323237 times just for this
>search.
That's a separate issue.
>For a look at the complete gprof output:
>
>http://marcus.debian.net/~bmc/ldap/
>
>Ben
>
>--
> -----------=======-=-======-=========-----------=====------------=-=------
>/ Ben Collins -- ...on that fantastic voyage... -- Debian GNU/Linux \
>` bcollins@debian.org -- bcollins@openldap.org -- bcollins@linux.com '
> `---=========------=======-------------=-=-----=-===-======-------=--=---'