mån 2007-11-12 klockan 23:17 +0000 skrev quanah@zimbra.com:

--On Monday, November 12, 2007 7:02 AM +0000 hyc@symas.com wrote:

...

Dan.Oscarsson@tietoenator.com wrote:

...

Full_Name: Dan Oscarsson Version: 2.3.32 OS: SLES 10 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (193.15.240.60)

Also, Just some general data on what it is you are doing that is a bit more explanative. For example, what does your tree layout look like? A single root with 20,000+ subtrees off of the root? A root with 10 subtrees, with thousands of subtrees off of those? How are you doing these modrdn's? Why, exactly? Anything that can help us to possibly come up with a progamatic generation of dummy data.

The tree is based on a company organisation structure, branching at each organisational level util you get to a person. So the root has only a few subtrees, and each subtree only a few (say 1-30) subtrees. Most entries will probably a subtree for a unit with the persons beloning to that unit. People will always be leafs but an entry may contain both people and subtrees as children.

I have triggered the bug when doing major reorganisation of people. Then very many of the people are moved around to a new place in the tree. Many to newly created subtrees.

I have now used 2.3.38 compiled myself so I can add tracing to the code if needed. Running a move of people, with logging set to any, and then running my simple check program, the search at a subtree that goes wrong (entries are missing) is logged as: filter: (&(objectClass=enterprisePerson)(ba=telecom & media)(bu=telecom solutions)) 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: search_candidates: base="bu=telecom solutions,ba=telecom & media,cn=organisation,o=xx" (0x0000513a) scope=2 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => hdb_dn2idl("bu=telecom solutions,ba=telecom & media,cn=organisation,o=xx") 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_filter_candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: AND 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_list_candidates 0xa0 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_filter_candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: OR 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_list_candidates 0xa1 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_filter_candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: EQUALITY 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_equality_candidates (objectClass) 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => key_read 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: bdb_idl_fetch_key: [b49d1940] 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_index_read: failed (-30989) 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_equality_candidates: id=0, first=0, last=0 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_filter_candidates: id=0 first=0 last=0 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_filter_candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: AND 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_list_candidates 0xa0 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_filter_candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: EQUALITY 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_equality_candidates (objectClass) 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => key_read 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: bdb_idl_fetch_key: [a98323a6] 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_index_read 20569 candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_equality_candidates: id=20569, first=1483, last=26650 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_filter_candidates: id=20569 first=1483 last=26650 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_filter_candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: EQUALITY 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_equality_candidates (ba) 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => key_read 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: bdb_idl_fetch_key: [410ca247] 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_index_read 6991 candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_equality_candidates: id=6991, first=15620, last=26644 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_filter_candidates: id=6991 first=15620 last=26644 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_filter_candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: EQUALITY 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => bdb_equality_candidates (bu) 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: => key_read 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: bdb_idl_fetch_key: [8b819570] 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_index_read 2195 candidates 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_equality_candidates: id=2195, first=30, last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_filter_candidates: id=2195 first=30 last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_list_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_filter_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_list_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_filter_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_list_candidates: id=2130 first=20813 last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: <= bdb_filter_candidates: id=2130 first=20813 last=26614 2007-11-13 15.19.05 ra [local4.debug] slapd[27292]: bdb_search_candidates: id=2130 first=20813 last=26614

Stopping and starting the server. The check now works. The above search is logged the same except for the last part:

2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: bdb_idl_fetch_key: [8b819570] 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_index_read 2195 candidates 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_equality_candidates: id=2195, first=30, last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_filter_candidates: id=2195 first=30 last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_list_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_filter_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_list_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_filter_candidates: id=2144 first=20813 last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_list_candidates: id=2141 first=20813 last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: <= bdb_filter_candidates: id=2141 first=20813 last=26614 2007-11-13 15.19.41 ra [local4.debug] slapd[27460]: bdb_search_candidates: id=2141 first=20813 last=26614

In both above cases, with the same filter but search base set to o=xx witch is the database prefix, it works as it should. In this case the entries that were missing above is found.

I do not know it this might give you some clue to what the problem is.

Any suggestions on what I should look for or any suitable place in the code where I could add debug logging, would be nice.

The logs get very large when running with logging set to any.

Dan