Hello,
I've a strange behavior while using index objectClass for searching.
In my slapd.conf I have defined the index in the database section:
index objectClass eq
Other indexes follows in the config. All of them working fine.
If I search via ldapsearch like:
ldapsearch -x -h localhost -w password -D"cn=admin,ou=root" -b"ou=root" "(objectclass=Guest)"
I can find following Message in the syslog (loglevel -1):
Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_equality_candidates (objectClass) Sep 1 14:02:52 LDAP01 slapd[17856]: => key_read Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_index_read: failed (-30989) Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_equality_candidates: id=0, first=0, last=0 Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_filter_candidates: id=0 first=0 last=0 Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_filter_candidates Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_equality_candidates (objectClass) Sep 1 14:02:52 LDAP01 slapd[17856]: => key_read Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_index_read 355545 candidates Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_equality_candidates: id=-1, first=228, last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_filter_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_list_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_filter_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_list_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_filter_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]: bdb_search_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]: => test_filter Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]: <= test_filter 5 Sep 1 14:02:52 LDAP01 slapd[17856]: bdb_search: 112277 does not match filter Sep 1 14:02:52 LDAP01 slapd[17856]: entry_decode: "cn=Aaa,cn=Bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]: <= entry_decode(cn=Aaa,cn=Bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_dn2id("cn=aaa,cn=bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]: <= bdb_dn2id: got id=0x1b696 Sep 1 14:02:52 LDAP01 slapd[17856]: => test_filter Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856] ... all other entires following...
As result, the entires are found, but not in the index and the search takes a very long time.
After this, I have rebuild the complete database via slapcat/slapadd, rebuild the index via slapindex for objetClass, but nothing helped.
In tried the test above on: * OpenSuSE 11.1 and openLDAP 2.4.21 and 2.4.23 (linked against libdb-4.5) * OpenSuSE 11.0 and openLDAP 2.4.9 (linked against libdb-4.5) * Debian Lenny and openLDAP 2.4.11 (linked against libdb-4.2)
with different databases and a search against a objectClass.
If I try another index (not objectClass) from the slapd.conf the index works, example:
ldapsearch -x -h localhost -w password -D"cn=admin,ou=root" -b"ou=root" "(mypk=1234-234)"
Sep 1 14:03:44 LDAP01 slapd[17856]: => bdb_equality_candidates (mypk) Sep 1 14:03:44 LDAP01 slapd[17856]: => key_read Sep 1 14:03:44 LDAP01 slapd[17856]: <= bdb_index_read 1 candidates Sep 1 14:03:44 LDAP01 slapd[17856]: <= bdb_equality_candidates: id=1, first=112838, last=112838 Sep 1 14:03:44 LDAP01 slapd[17856]: <= bdb_filter_candidates: id=1 first=112838 last=112838 Sep 1 14:03:44 LDAP01 slapd[17856]: <= bdb_list_candidates: id=1 first=112838 last=112838 Sep 1 14:03:44 LDAP01 slapd[17856]: <= bdb_filter_candidates: id=1 first=112838 last=112838 Sep 1 14:03:44 LDAP01 slapd[17856]: <= bdb_list_candidates: id=1 first=112838 last=112838 Sep 1 14:03:44 LDAP01 slapd[17856]: <= bdb_filter_candidates: id=1 first=112838 last=112838 Sep 1 14:03:44 LDAP01 slapd[17856]: bdb_search_candidates: id=1 first=112838 last=112838 Sep 1 14:03:44 LDAP01 slapd[17856]: => test_filter Sep 1 14:03:44 LDAP01 slapd[17856]: EQUALITY Sep 1 14:03:44 LDAP01 slapd[17856]: <= test_filter 6 Sep 1 14:03:44 LDAP01 slapd[17856]: => send_search_entry: conn 1002 dn="cn=Fff,cn=Eee,... Sep 1 14:03:44 LDAP01 slapd[17856]: <= send_search_entry: conn 1002 exit. Sep 1 14:03:44 LDAP01 slapd[17856]: send_ldap_result: conn=1002 op=1 p=3 Sep 1 14:03:44 LDAP01 slapd[17856]: send_ldap_response: msgid=2 tag=101 err=0 Sep 1 14:03:44 LDAP01 slapd[17856]: connection_get(12): got connid=1002 Sep 1 14:03:44 LDAP01 slapd[17856]: connection_read(12): checking for input on id=1002 Sep 1 14:03:44 LDAP01 slapd[17856]: op tag 0x42, time 1283342624 Sep 1 14:03:44 LDAP01 slapd[17856]: conn=1002 op=2 do_unbind Sep 1 14:03:44 LDAP01 slapd[17856]: connection_close: conn=1002 sd=12
Why does only the objectClass index not work?
The only difference I can see, is that all other indexes are based on "normal" attributes. I don't know, if it is necessary, but for objectClass I can't find a attribute definition in the schema. In the core.schema is the attribute definition for objectClass deactivated (aka #)...
Here is the Config from the LDAP-Server:
# Schema and objectClass definitions include /etc/openldap/schema/core.schema include /etc/openldap/schema/cosine.schema include /etc/openldap/schema/inetorgperson.schema include /etc/openldap/schema/yast.schema include /etc/openldap/schema/rfc2307bis.schema include /etc/openldap/schema/my_ldap_attribute.schema include /etc/openldap/schema/my_ldap.schema
pidfile /var/run/slapd/slapd.pid argsfile /var/run/slapd/slapd.args
modulepath /usr/lib/ldap moduleload back_bdb
sizelimit -1 timelimit 300 disallow bind_anon
gentlehup on tool-threads 1
####################################################################### # bdb database definitions ####################################################################### database bdb suffix "ou=root" rootdn "cn=root,ou=root"
checkpoint 4096 15 rootpw password directory /var/lib/ldap
dbnosync
# Indices to maintain index objectClass,entryUUID,entryCSN eq index mypk,myusername pres,eq index myproperty,mylanguage eq index cn eq,sub
Kindly regards Tim Stone
tim stone wrote:
Hello,
I've a strange behavior while using index objectClass for searching.
In my slapd.conf I have defined the index in the database section:
index objectClass eq
Other indexes follows in the config. All of them working fine.
If I search via ldapsearch like:
ldapsearch -x -h localhost -w password -D"cn=admin,ou=root" -b"ou=root" "(objectclass=Guest)"
I can find following Message in the syslog (loglevel -1):
Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_equality_candidates (objectClass) Sep 1 14:02:52 LDAP01 slapd[17856]: => key_read Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_index_read: failed (-30989) Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_equality_candidates: id=0, first=0, last=0 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=0 first=0 last=0 Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_filter_candidates Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_equality_candidates (objectClass) Sep 1 14:02:52 LDAP01 slapd[17856]: => key_read Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_index_read 355545 candidates Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_equality_candidates: id=-1, first=228, last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_list_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_list_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]: bdb_search_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]: => test_filter Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]:<= test_filter 5 Sep 1 14:02:52 LDAP01 slapd[17856]: bdb_search: 112277 does not match filter Sep 1 14:02:52 LDAP01 slapd[17856]: entry_decode: "cn=Aaa,cn=Bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]:<= entry_decode(cn=Aaa,cn=Bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_dn2id("cn=aaa,cn=bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_dn2id: got id=0x1b696 Sep 1 14:02:52 LDAP01 slapd[17856]: => test_filter Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856] ... all other entires following...
As result, the entires are found, but not in the index and the search takes a very long time.
The index is working as designed, it's just filled with a lot of false matches which have to be explicitly tested against the filter to be weeded out. The objectclass index provided 355545 candidates in the range of 228 thru 355772. Some other search term provided (355755-112277) candidates, leaving the range from 112277 thru 355755 needing to be tested. If this search takes too long, then you need a larger entry cache.
Hello,
Sorry, I made a mistake (during sanitize) in my posting. Ldapsearch is looking/starting the search dirctly (-b) in the Container DN with 88000 entires. Only this Container (searchbase) has the objectClass Guest.
So the request is look like:
ldapsearch -x -h localhost -w password -D"cn=admin,ou=root"-b"cn=Bbb,ou=root" "(objectclass=Guest)"
Because of the long time for searching today I moved (ldapmodify -f , moddn) all 88000 entires in an other location (from cn=Bbb,ou=root to cn=Ccc,ou=root)
Example: dn: cn=Aaa,cn=Bbb,ou=root changetype: moddn newrdn: cn=Aaa deleteoldrdn: 1 newSuperior: cn=Ccc,ou=root
and tried the ldapsearch again. The Container "old" is now empty like expected. The result from the displaying immediately (because the container has the objectclass Guest), but the search is continuing and takes a "long" time too.
In the logfile now I can see following error messages from the slapd:
Sep 9 16:25:20 LDAP02 slapd[26832]: bdb_search: 112279 scope not okay Sep 9 16:25:20 LDAP02 slapd[26832]: bdb_search: 112280 scope not okay . . Sep 9 16:25:20 LDAP02 slapd[26832]: bdb_search: 113276 scope not okay Sep 9 16:25:20 LDAP02 slapd[26832]: bdb_search: 113277 scope not okay
Sep 9 16:25:20 LDAP02 slapd[26832]: entry_decode: "cn=Xxx,cn=Ccc,ou=root" Sep 9 16:25:20 LDAP02 slapd[26832]: <= entry_decode(cn=Xxx,cn=Ccc,ou=root) Sep 9 16:25:20 LDAP02 slapd[26832]: bdb_search: 113278 scope not okay . . Sep 9 16:25:29 LDAP02 slapd[26832]: entry_decode: "cn=Zzz,cn=Ccc,ou=root" Sep 9 16:25:29 LDAP02 slapd[26832]: <= entry_decode(cn=Zzz,cn=Ccc,ou=root) Sep 9 16:25:29 LDAP02 slapd[26832]: bdb_search: 154297 scope not okay
Sep 9 16:25:29 LDAP02 slapd[26832]: entry_decode: "cn=Kkk,ou=abc...,... , ou=root" Sep 9 16:25:29 LDAP02 slapd[26832]: <= entry_decode(cn=Kkk,ou=abc...,... , ou=root) Sep 9 16:25:29 LDAP02 slapd[26832]: bdb_search: 154298 scope not okay . . Sep 9 16:26:16 LDAP02 slapd[26832]: entry_decode: "cn=123,ou=xvz...,... , ou=root" Sep 9 16:26:16 LDAP02 slapd[26832]: <= entry_decode(cn=123,ou=xvz...,... , ou=root) Sep 9 16:26:16 LDAP02 slapd[26832]: bdb_search: 355754 scope not okay
I found following Posting in the mailing List with the same message. http://www.openldap.org/lists/openldap-bugs/200410/msg00001.html
What is going wrong?
Thanks Tim
2010/9/9 Howard Chu hyc@symas.com:
tim stone wrote:
Hello,
I've a strange behavior while using index objectClass for searching.
In my slapd.conf I have defined the index in the database section:
index objectClass eq
Other indexes follows in the config. All of them working fine.
If I search via ldapsearch like:
ldapsearch -x -h localhost -w password -D"cn=admin,ou=root" -b"ou=root" "(objectclass=Guest)"
I can find following Message in the syslog (loglevel -1):
Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_equality_candidates (objectClass) Sep 1 14:02:52 LDAP01 slapd[17856]: => key_read Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_index_read: failed (-30989) Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_equality_candidates: id=0, first=0, last=0 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=0 first=0 last=0 Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_filter_candidates Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_equality_candidates (objectClass) Sep 1 14:02:52 LDAP01 slapd[17856]: => key_read Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_index_read 355545 candidates Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_equality_candidates: id=-1, first=228, last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_list_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=-1 first=228 last=355772 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_list_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_filter_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]: bdb_search_candidates: id=-1 first=112277 last=355755 Sep 1 14:02:52 LDAP01 slapd[17856]: => test_filter Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856]:<= test_filter 5 Sep 1 14:02:52 LDAP01 slapd[17856]: bdb_search: 112277 does not match filter Sep 1 14:02:52 LDAP01 slapd[17856]: entry_decode: "cn=Aaa,cn=Bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]:<= entry_decode(cn=Aaa,cn=Bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]: => bdb_dn2id("cn=aaa,cn=bbb,... Sep 1 14:02:52 LDAP01 slapd[17856]:<= bdb_dn2id: got id=0x1b696 Sep 1 14:02:52 LDAP01 slapd[17856]: => test_filter Sep 1 14:02:52 LDAP01 slapd[17856]: EQUALITY Sep 1 14:02:52 LDAP01 slapd[17856] ... all other entires following...
As result, the entires are found, but not in the index and the search takes a very long time.
The index is working as designed, it's just filled with a lot of false matches which have to be explicitly tested against the filter to be weeded out. The objectclass index provided 355545 candidates in the range of 228 thru 355772. Some other search term provided (355755-112277) candidates, leaving the range from 112277 thru 355755 needing to be tested. If this search takes too long, then you need a larger entry cache.
-- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/
The index is working as designed, it's just filled with a lot of false matches which have to be explicitly tested against the filter to be weeded out. The objectclass index provided 355545 candidates in the range of 228 thru 355772. Some other search term provided (355755-112277) candidates, leaving the range from 112277 thru 355755 needing to be tested. If this search takes too long, then you need a larger entry cache.
I tried to increase the cachesize and idlcachesize to 100000 and restarted the slapd, but it did not help.
Tim
--On Friday, September 10, 2010 8:25 AM +0200 tim stone timstone10001@googlemail.com wrote:
The index is working as designed, it's just filled with a lot of false matches which have to be explicitly tested against the filter to be weeded out. The objectclass index provided 355545 candidates in the range of 228 thru 355772. Some other search term provided (355755-112277) candidates, leaving the range from 112277 thru 355755 needing to be tested. If this search takes too long, then you need a larger entry cache.
I tried to increase the cachesize and idlcachesize to 100000 and restarted the slapd, but it did not help.
If you are using back-hdb, and using a subtree as the base (which it looked like you were doing), the first time through the search will be very slow while the cache is filled. That's a long-standing issue with back-hdb. Subsequent searches are substantially faster.
--Quanah
--
Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration
The index is working as designed, it's just filled with a lot of false matches which have to be explicitly tested against the filter to be weeded out. The objectclass index provided 355545 candidates in the range of 228 thru 355772. Some other search term provided (355755-112277) candidates, leaving the range from 112277 thru 355755 needing to be tested. If this search takes too long, then you need a larger entry cache.
Hello Howard,
but why is the index filled with a lot of false matches?
In one of my DN (Container) are 88000 entires. I placed my search there (searchBase). Only the Container itself has the searched objectClass, but all entires in this container will be examined too, because the index returned this all. Should the index for objectClass not only give back this _one_ (and not 355545) Candidate, because I placed my search there? Do I misunderstood this?
Thanks Tim
tim stone wrote:
The index is working as designed, it's just filled with a lot of false matches which have to be explicitly tested against the filter to be weeded out. The objectclass index provided 355545 candidates in the range of 228 thru 355772. Some other search term provided (355755-112277) candidates, leaving the range from 112277 thru 355755 needing to be tested. If this search takes too long, then you need a larger entry cache.
Hello Howard,
but why is the index filled with a lot of false matches?
In one of my DN (Container) are 88000 entires. I placed my search there (searchBase). Only the Container itself has the searched objectClass, but all entires in this container will be examined too, because the index returned this all. Should the index for objectClass not only give back this _one_ (and not 355545) Candidate, because I placed my search there? Do I misunderstood this?
An index is only a hint, it is not definitive. It is generated from a short hash of the relevant attribute values. It's always possible to have hash collisions, where multiple values hash to the same index.
Hello Howard,
but why is the index filled with a lot of false matches?
In one of my DN (Container) are 88000 entires. I placed my search there (searchBase). Only the Container itself has the searched objectClass, but all entires in this container will be examined too, because the index returned this all. Should the index for objectClass not only give back this _one_ (and not 355545) Candidate, because I placed my search there? Do I misunderstood this?
An index is only a hint, it is not definitive. It is generated from a short hash of the relevant attribute values. It's always possible to have hash collisions, where multiple values hash to the same index.
Can I check/recover this, that this problem with the index is a result of hash collisions?
Thank in advance, Tim
openldap-technical@openldap.org
-
Howard Chu -
Quanah Gibson-Mount -
tim stone