[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: Very slow ldapserach



Hi,

It was long weekend with Easter holiday so...

To answer Mattes, and Ulrich first, I will do as suggested by you.

But something new first. If I have tried to add less data to database and then I have conducted the search. Till some point it works and then fails. It looks like when database is filed with more than some amount of data it stops to send data back.

To be sure that my build is not the culprit I have installed in parallel on similar server Ubuntu 14.04 with their slapd package (I know, it is not good but just for this test...) and this happened when I have tried this:

ldapsearch -h 10.14.252.104 -p 389 -D cn=admin,dc=spr -w password -s sub -a always -b dc=SPR objectClass=*

My build on centos 6.6 chrashed with this message:

5523ac18 >>> slap_listener(ldap:///)
5523ac18 connection_get(11): got connid=1001
5523ac18 connection_read(11): checking for input on id=1001
ber_get_next
ber_get_next: tag 0x30 len 34 contents:
5523ac18 op tag 0x60, time 1428401176
ber_get_next
5523ac18 conn=1001 op=0 do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt (m}) ber:
5523ac18 >>> dnPrettyNormal: <cn=admin,dc=spr>
5523ac18 <<< dnPrettyNormal: <cn=admin,dc=spr>, <cn=admin,dc=spr>
5523ac18 do_bind: version=3 dn="cn=admin,dc=spr" method=128
5523ac18 do_bind: v3 bind: "cn=admin,dc=spr" to "cn=admin,dc=spr"
5523ac18 send_ldap_result: conn=1001 op=0 p=3
5523ac18 send_ldap_response: msgid=1 tag=97 err=0
ber_flush2: 14 bytes to sd 11
5523ac18 connection_get(11): got connid=1001
5523ac18 connection_read(11): checking for input on id=1001
ber_get_next
ber_get_next: tag 0x30 len 43 contents:
5523ac18 op tag 0x63, time 1428401176
ber_get_next
5523ac18 conn=1001 op=1 do_search
ber_scanf fmt ({miiiib) ber:
5523ac18 >>> dnPrettyNormal: <dc=SPR>
5523ac18 <<< dnPrettyNormal: <dc=SPR>, <dc=spr>
ber_scanf fmt (m) ber:
ber_scanf fmt ({M}}) ber:
5523ac18 => mdb_search
5523ac18 mdb_dn2entry("dc=spr")
5523ac18 => mdb_dn2id("dc=spr")
5523ac18 <= mdb_dn2id: got id=0x1
5523ac18 => mdb_entry_decode:
5523ac18 <= mdb_entry_decode
5523ac18 search_candidates: base="dc=spr" (0x00000001) scope=2
5523ac18 => mdb_equality_candidates (objectClass)
5523ac18 => key_read
5523ac18 <= mdb_index_read 10000000 candidates
5523ac18 <= mdb_equality_candidates: id=-1, first=16, last=10000015
Segmentation fault


On Ubuntu 14.04 passed through but no result:

Apr  7 12:51:36 spr2 slapd[8432]: conn=1001 op=1 SRCH base="dc=SPR" scope=2 deref=3 filter="(objectClass=*)"
Apr  7 12:51:36 spr2 slapd[8432]: => mdb_search
Apr  7 12:51:36 spr2 slapd[8432]: mdb_dn2entry("dc=spr")
Apr  7 12:51:36 spr2 slapd[8432]: => mdb_dn2id("dc=spr")
Apr  7 12:51:36 spr2 slapd[8432]: <= mdb_dn2id: got id=0x1
Apr  7 12:51:36 spr2 slapd[8432]: => mdb_entry_decode:
Apr  7 12:51:36 spr2 slapd[8432]: <= mdb_entry_decode
Apr  7 12:51:36 spr2 slapd[8432]: => access_allowed: search access to "dc=SPR" "entry" requested
Apr  7 12:51:36 spr2 slapd[8432]: <= root access granted
Apr  7 12:51:36 spr2 slapd[8432]: => access_allowed: search access granted by manage(=mwrscxd)
Apr  7 12:51:36 spr2 slapd[8432]: search_candidates: base="dc=spr" (0x00000001) scope=2
Apr  7 12:51:36 spr2 slapd[8432]: => mdb_filter_candidates
Apr  7 12:51:36 spr2 slapd[8432]: #011EQUALITY
Apr  7 12:51:36 spr2 slapd[8432]: => mdb_equality_candidates (objectClass)
Apr  7 12:51:36 spr2 slapd[8432]: => key_read
Apr  7 12:51:36 spr2 slapd[8432]: mdb_idl_fetch_key: [01872a84]
Apr  7 12:51:36 spr2 slapd[8432]: <= mdb_index_read 294110 candidates
Apr  7 12:51:36 spr2 slapd[8432]: <= mdb_equality_candidates: id=-1, first=16, last=294125
Apr  7 12:51:36 spr2 slapd[8432]: <= mdb_filter_candidates: id=-1 first=16 last=294125
Apr  7 12:51:36 spr2 slapd[8432]: mdb_search_candidates: failed (rc=-30798)
Apr  7 12:51:36 spr2 slapd[8432]: mdb_search: no candidates
Apr  7 12:51:36 spr2 slapd[8432]: send_ldap_result: conn=1001 op=1 p=3
Apr  7 12:51:36 spr2 slapd[8432]: send_ldap_result: err=0 matched="" text=""
Apr  7 12:51:36 spr2 slapd[8432]: send_ldap_response: msgid=2 tag=101 err=0
Apr  7 12:51:36 spr2 slapd[8432]: conn=1001 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text=
Apr  7 12:51:36 spr2 slapd[8432]: daemon: activity on 1 descriptor
Apr  7 12:51:36 spr2 slapd[8432]: daemon: activity on:
Apr  7 12:51:36 spr2 slapd[8432]:  13r


For test I have cut data from 2 mil lines to 300000 lines and database is now just 841 M in size (was 2,1 G)

root@spr2:/var/log# du -hs /var/lib/ldap/*
841M    /var/lib/ldap/data.mdb
4.0K    /var/lib/ldap/lock.mdb


And data is accessible:

----cut-----
# search result
search: 2
result: 0 Success

# numResponses: 22076
# numEntries: 22075

It looks like this is happening again:

http://www.openldap.org/lists/openldap-technical/201304/msg00198.html


Br

Sasa