Re: OpenLDAP Search bug?

["Kurt D. Zeilenga" <Kurt@OpenLDAP.org>]

A couple of things to try:

a) stop server, run slapindex, restart server
b) more logging... to determine what slapd is doing
   for those 4-5 seconds
c) try the latest release engineering version
   (OPENLDAP_REL_ENG_2_1 or OPENLDAP_REL_ENG_2) of
   OpenLDAP from CVS.

Kurt

At 09:13 AM 2002-09-06, Banzaitron wrote:
>I have done a little more research on this problem (found in the email
>below) and have found a few more interesting notes...
>
>I tried rebuilding the entire database with the following indices:
>index           ou,o            eq
>index           uid,myorgdn,myorgroot,myorgsn              eq
>index           objectclass             eq
>
>I am still seeing a 4 second delay in the middle of receiving search result
>data from the openldap, right before the last 14 bytes are sent (why is it
>always 14 bytes?).
>
>The interesting thing I found is when I move up one level in the tree and
>try the same query over ALL users, I receive about 50 times as many entries
>and the query is faster!!!  How could that possibly be?  Here are the two
>queries:
>
>This one searches below one user (which only has 10 entries below it) and
>takes about 4-5 seconds:
>
>conn=8 op=27 SRCH
>base="uid=6225183,ou=People,o=myorg,myorgroot=top,o=myorg.com" scope=1
>filter="(objectClass=myorgservice)"
>ber_flush: 629 bytes to sd 28
>ber_flush: 521 bytes to sd 28
>ber_flush: 543 bytes to sd 28
>ber_flush: 520 bytes to sd 28
>ber_flush: 524 bytes to sd 28
>ber_flush: 532 bytes to sd 28
>ber_flush: 534 bytes to sd 28
>ber_flush: 524 bytes to sd 28
>ber_flush: 559 bytes to sd 28
>ber_flush: 526 bytes to sd 28
>
><<4 second pause>>
>
>ber_flush: 14 bytes to sd 28
>conn=8 op=27 SEARCH RESULT tag=101 err=0 nentries=10 text=
>
>This next one has the same filter, but searches through ALL users (one level
>up in the tree) and runs instantaneously:
>
>conn=5 op=51 SRCH base="ou=People,o=myorg,myorgroot=top,o=myorg.com" scope=2
>filter="(objectClass=myorgservice)"
>ber_flush: 117 bytes to sd 11
>ber_flush: 129 bytes to sd 11
>ber_flush: 128 bytes to sd 11
>ber_flush: 145 bytes to sd 11
>ber_flush: 119 bytes to sd 11
>ber_flush: 123 bytes to sd 11
>...
><<ommited hundreds of similar lines>>
>...
>ber_flush: 14 bytes to sd 11
>conn=5 op=51 SEARCH RESULT tag=101 err=0 nentries=521 text=
>
>I can't see how this could be anything other than a bug in the search
>routines.  Has anyone else experienced this?  I can only reproduce it when
>searching by (objectclass=somevalue).  If I do (objectclass=*) it runs
>instantly and if I use a value for objectclass that doesn't exist, it is
>also instantaneous.  I have also tried the same query at other levels of the
>tree.  I only see this problem at this particular level, and then only when
>i search by objectclass.
>
>Please help me!!! I am about to pull out my hair!!
>
>Thanks,
>Andy Hofle
>
>----- Original Message -----
>From: "Banzaitron" <banzaitron@adelphia.net>
>To: <openldap-software@OpenLDAP.org>
>Sent: Thursday, September 05, 2002 10:20 AM
>Subject: Very strange search performance problem...
>
>
>> Hello,
>> I have finally gotten to the point of migrating our iPlanet directory to
>the
>> openldap (thanks to help from this list) and being able to run our
>> applications against the new LDAP.  I am seeing a very strange behavior
>with
>> searches.  For example, when I start a query, I see the following in the
>> LDAP log output:
>>
>> conn=2 op=50 SRCH
>> base="uid=6225183,ou=People,o=myorg,myorgroot=top,o=myorg.com" scope=1
>> filter="(objectClass=myorgservice)"
>> ber_flush: 629 bytes to sd 13
>> ber_flush: 521 bytes to sd 13
>> ber_flush: 543 bytes to sd 13
>> ber_flush: 520 bytes to sd 13
>> ber_flush: 524 bytes to sd 13
>> ber_flush: 532 bytes to sd 13
>> ber_flush: 534 bytes to sd 13
>> ber_flush: 524 bytes to sd 13
>> ber_flush: 559 bytes to sd 13
>> ber_flush: 526 bytes to sd 13
>>
>> ****3-4 second pause****   <-----------------------
>>
>> ber_flush: 14 bytes to sd 13
>> conn=2 op=50 SEARCH RESULT tag=101 err=0 nentries=10 text=
>>
>> There is ALWAYS a long delay before the last 14 bytes are flushed.
>> Obviously, this is causing poor application performance due to the large
>> number of queries of this type.  When I run the same query from a simple
>> LDAP browser, it does the same thing (long pause).  However, when I change
>> the filter from(objectClass=myorgservice) to (objectClass=*) it runs
>> instantly.  I assume this is some indexing problem, but I have an
>> objectClass index in my slapd.conf:
>>
>> # Indices to maintain
>> index   objectClass     eq
>>
>> Also, there are very few entries under this DN so even if it was an
>indexing
>> problem, I can't imagine why it would be taking so long to search the 5 or
>6
>> entries under that UID.  Any idea how I can improve this situation?  I'm a
>> little new to LDAP indices -- are there any others that I should
>definitely
>> have turned on by default?
>>
>> Thanks alot,
>> Andy Hofle
>>
>>