Bug 667488 - Cannot recreate numsubordinates index with db2index
Summary: Cannot recreate numsubordinates index with db2index
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: 389
Classification: Retired
Component: Database - Indexes/Searches
Version: 1.2.7
Hardware: Unspecified
OS: Unspecified
low
medium
Target Milestone: ---
Assignee: Noriko Hosoi
QA Contact: Viktor Ashirov
URL:
Whiteboard:
Depends On:
Blocks: 639035
TreeView+ depends on / blocked
 
Reported: 2011-01-05 18:38 UTC by Orion Poplawski
Modified: 2015-12-07 17:11 UTC (History)
1 user (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2015-12-07 17:11:27 UTC
Embargoed:


Attachments (Terms of Use)
error log of ns-slapd db2index numsubordinates (66.52 KB, application/x-gzip)
2011-01-05 22:13 UTC, Orion Poplawski
no flags Details
git patch file (master) (2.08 KB, patch)
2011-01-07 21:44 UTC, Noriko Hosoi
nhosoi: review?
Details | Diff

Description Orion Poplawski 2011-01-05 18:38:56 UTC
Description of problem:

I'm seeing problems where filters such as numSubordinates>=1 (as used by the console to determine leaf-nodes) don't return the proper list.

numSubordinates appears to be indexed only for presence by default. 

I added an index for equality by adding nsIndexTypes: eq to:

cn=numsubordinates,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,dn=config
cn=numsubordinates,cn=index,cn=NetscapeRoot,cn=ldbm database,cn=plugins,dn=config
cn=numsubordinates,cn=default indexes,cn=config,cn=ldbm database,cn=plugins,dn=config

I triggered an index rebuild by adding:

dn: cn=db2index_2011_1_5_11_21_50, cn=index, cn=tasks, cn=config
changetype: add
objectclass: top
objectclass: extensibleObject
cn: db2index_2011_1_5_11_21_50
nsInstance: userRoot
nsIndexAttribute: numsubordinates:eq

Saw in the error log:

[05/Jan/2011:11:30:26 -0700] - userRoot: Indexing attribute: numsubordinates
[05/Jan/2011:11:30:27 -0700] - userRoot: Finished indexing.

But now my numSubordinates>=1 search comes up empty.  Interestingly, numSubordinates>4 doesn't work either, but in this case it returns all, even those with numSubordinates <= 4.

Restarting the slapd process didn't help.

Version-Release number of selected component (if applicable):
389-ds-base-1.2.7.5-1.el5

Comment 1 Orion Poplawski 2011-01-05 21:40:36 UTC
db2index -n userRoot -t numsubordinates (which runs ns-slapd db2index) fails to create the index as well.

I now have no numsuboridinates.db4 file at all and can't seem to recreate it.

Comment 2 Orion Poplawski 2011-01-05 22:13:09 UTC
Created attachment 471953 [details]
error log of ns-slapd db2index numsubordinates

This is the slapd error log.  Has output of several attempts of run db2index{,.pl}, as well as one db2index run with -d 262143 set.  Not sure there is much useful there though.  End of the run shows:

[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> entryrdn_lookup_dn
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- entryrdn_lookup_dn
[05/Jan/2011:15:04:49 -0700] ldbm2index - entryrdn_lookup_dn returned: cn=seismo,ou=auto.data4g,dc=cora,dc=nwra,dc=com, and set to dn cache
[05/Jan/2011:15:04:49 -0700] - slapi_str2entry_ext: flags=0x400, dn="cn=seismo,ou=auto.data4g,dc=cora,dc=nwra,dc=com", entry="rdn: cn=seismo
objectClass: automount
objectClass:..."
[05/Jan/2011:15:04:49 -0700] - => str2entry_dupcheck
[05/Jan/2011:15:04:49 -0700] - <= str2entry_dupcheck 0x9b82cc8 "cn=seismo,ou=auto.data4g,dc=cora,dc=nwra,dc=com"
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> entryrdn_index_read
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> _entryrdn_index_read
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> _entryrdn_new_rdn_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- _entryrdn_new_rdn_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> _entryrdn_get_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- _entryrdn_get_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> _entryrdn_new_rdn_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- _entryrdn_new_rdn_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> _entryrdn_get_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- _entryrdn_get_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> _entryrdn_new_rdn_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- _entryrdn_new_rdn_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - --> _entryrdn_get_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- _entryrdn_get_elem
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- _entryrdn_index_read
[05/Jan/2011:15:04:49 -0700] entryrdn-index - <-- entryrdn_index_read
[05/Jan/2011:15:04:49 -0700] - removing entire attribute hassubordinates
[05/Jan/2011:15:04:49 -0700] - removing entire attribute numsubordinates
[05/Jan/2011:15:04:49 -0700] - userRoot: Finished indexing.
[05/Jan/2011:15:04:49 -0700] - -> attrcrypt_cleanup_private
[05/Jan/2011:15:04:49 -0700] - <- attrcrypt_cleanup_private
[05/Jan/2011:15:04:49 -0700] - All database threads now stopped
[05/Jan/2011:15:04:49 -0700] - -> attrcrypt_cleanup_private
[05/Jan/2011:15:04:49 -0700] - <- attrcrypt_cleanup_private
[05/Jan/2011:15:04:49 -0700] - -> attrcrypt_cleanup_private
[05/Jan/2011:15:04:49 -0700] - <- attrcrypt_cleanup_private
[05/Jan/2011:15:04:49 -0700] - <= ldbm_back_ldbm2index

Not sure why the "removing entire attribute messages".

From an earlier strace, it does appear to try to access the database:

32449 stat64("/var/lib/dirsrv/slapd-cora/db/userRoot/numsubordinates.db4", 0xbf9c8ff0) = -1 ENOENT (No such file or directory)
32449 stat64("/var/lib/dirsrv/slapd-cora/db/userRoot/numsubordinates.db4", 0xbf9c8ff0) = -1 ENOENT (No such file or directory)
32449 stat64("/var/lib/dirsrv/slapd-cora/db/userRoot/numsubordinates.db4", 0xbf9c9060) = -1 ENOENT (No such file or directory)

but it doesn't attempt to create it.

Comment 3 Orion Poplawski 2011-01-06 16:37:39 UTC
It appears that "numsubordinates" is not being found in the slapi_entry_*_attr() list in ldbm_back_ldbm2index and so the index is never updated.  What creates that list?

Comment 4 Orion Poplawski 2011-01-06 16:53:30 UTC
Is this because numsubordinates is a "computed" attribute and not in the database values?

Comment 5 Orion Poplawski 2011-01-06 18:31:55 UTC
It appears that these attributes are deleted in add_op_attrs() called just before the indexes are updated:

    /* Get rid of attributes you're not allowed to specify yourself */
    slapi_entry_delete_values( ep->ep_entry, hassubordinates, NULL );
    slapi_entry_delete_values( ep->ep_entry, numsubordinates, NULL );

I'm guessing here that the numsubordinates line should be removed.

Comment 6 Orion Poplawski 2011-01-06 19:20:55 UTC
I removed that line and ran db2index.pl.  numsubordinates index file was re-created fine and now has presence and equality indexes:

dbscan -f /var/lib/dirsrv/slapd-cora/db/userRoot/numsubordinates.db4 -r -s
+                                       
        1 3 4 90 97 102 186 211 215 240 265 294 
=3                                      
        211 
=4                                      
        97 
=8                                      
        1 90 
=21                                     
        186 215 240 265 
=27                                     
        3 
=54                                     
        294 
=88                                     
        102 
=89                                     
        4 
Presence index keys: 12
Equality index keys: 12

Next step I guess is to remove the equality index and make sure the searches work again.

Comment 7 Orion Poplawski 2011-01-06 21:58:56 UTC
Removed equality index:

# dbscan -f /var/lib/dirsrv/slapd-cora/db/userRoot/numsubordinates.db4 -r -s
+                                       
        1 3 4 90 97 102 186 211 215 240 265 294 

After index rebuild searches appear to work okay.  So I guess in the original issue, the index was just corrupt?

Comment 8 Noriko Hosoi 2011-01-07 21:44:11 UTC
Created attachment 472302 [details]
git patch file (master)

Description: Special thanks to Orion Poplawski(orion.com)
for his in-depth analysis on the bug.  As he figured out, a helper
function add_op_attrs called from the reindex API ldbm_back_ldbm2index
removes the numsubordinates attribute-value pair from entries to
be reindexed, which makes reindexing numsubordinates fail.

The helper function add_op_attrs adds operational attributes parentid,
entryid and entrydn to entries as well as removes numsubordinates
from them before the entries are reindexed/imported. The add and
remove are necessary for the import, but not for the reindex since
these to-be-added operational attributes are already in entries
in the primary database id2entry.  And numsubordinates is necessary
when the attribute is reindexed.

This patch updates ldbm_back_ldbm2index (ldif2ldbm.c) not to call
add_op_attrs.

Comment 10 Noriko Hosoi 2011-01-07 22:10:08 UTC
Steps to verify:

0. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out

1-1. stop the server
1-2. $ /usr/lib[64]/dirsrv/slapd-ID/db2index -n <backend> -t numsubordinates
1-3. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.1
1-4. $ diff /tmp/numsubordinates.out /tmp/numsubordinates.out.1
     echo $?
     0

2-1. start the server
2-2. $ /usr/lib[64]/dirsrv/slapd-ID/db2index.pl -D 'cn=directory manager' -w <password> -n <backend> -t numsubordinates
2-3. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.2
(Note: You may want to restart the server before running dbscan.  Otherwise, you may need to wait at least for 60 sec. to make sure the contents of the db is flushed to the file.)
2-4. $ diff /tmp/numsubordinates.out /tmp/numsubordinates.out.2
     echo $?
     0

3-1. add equality index to numsubordinates
     $ ldapmodify ...
     dn: cn=numsubordinates,cn=index,cn=<backend>,cn=ldbm database,cn=plugins,cn=config
     changetype: modify
     add: nsIndexType
     nsIndexType: eq

     modifying entry cn=numsubordinates,cn=index,cn=<backend>,cn=ldbm database,cn=plugins,cn=config
3-2. $ /usr/lib[64]/dirsrv/slapd-ID/db2index.pl -D 'cn=directory manager' -w <password> -n <backend> -t numsubordinates
3-3. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.3
3-4. verify the equality index is added.  E.g.,
     =5                                      1
     1

Comment 12 Noriko Hosoi 2011-01-08 00:25:27 UTC
Pushed to master.

$ git merge work
Updating 186137e..573b529
Fast-forward
 ldap/servers/slapd/back-ldbm/ldif2ldbm.c |   12 ------------
 1 files changed, 0 insertions(+), 12 deletions(-)
$ git push
Counting objects: 13, done.
Delta compression using up to 4 threads.
Compressing objects: 100% (7/7), done.
Writing objects: 100% (7/7), 1.05 KiB, done.
Total 7 (delta 5), reused 0 (delta 0)
To ssh://git.fedorahosted.org/git/389/ds.git
   186137e..573b529  master -> master

Comment 13 Amita Sharma 2011-07-29 10:25:01 UTC
0. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out

1-1. stop the server
1-2. $ /usr/lib/dirsrv/slapd-testvm1/db2index -n exampledb -t numsubordinates

[root@rhel61 slapd-rhel61]# ./db2index -n userRoot -t numsubordinates

[29/Jul/2011:15:42:18 +051800] - exampledb: Indexed 98000 entries (97%).
[29/Jul/2011:15:42:18 +051800] - exampledb: Indexed 99000 entries (98%).
[29/Jul/2011:15:42:18 +051800] - exampledb: Indexed 100000 entries (99%).
[29/Jul/2011:15:42:18 +051800] - exampledb: Finished indexing.
[29/Jul/2011:15:42:18 +051800] - All database threads now stopped

1-3. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.1

1-4. $ diff /tmp/numsubordinates.out /tmp/numsubordinates.out.1
     echo $?
     0
[root@testvm slapd-testvm1]# dbscan -f /var/lib/dirsrv/slapd-testvm1/db/exampledb/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.1
[root@testvm slapd-testvm1]# diff /tmp/numsubordinates.out /tmp/numsubordinates.out.1
[root@testvm slapd-testvm1]#  echo $?
0

2-1. start the server

2-2. $ /usr/lib64/dirsrv/slapd-ID/db2index.pl -D 'cn=directory manager' -w <password> -n <backend> -t numsubordinates

[root@testvm slapd-testvm1]# /usr/lib64/dirsrv/slapd-testvm1/db2index.pl -D 'cn=directory manager' -w Secret123 -n exampledb -t numsubordinates
adding new entry "cn=db2index_2011_7_29_15_44_34, cn=index, cn=tasks, cn=config"

2-3. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.2
(Note: You may want to restart the server before running dbscan.  Otherwise,
you may need to wait at least for 60 sec. to make sure the contents of the db
is flushed to the file.)
2-4. $ diff /tmp/numsubordinates.out /tmp/numsubordinates.out.2
     echo $?
     0

[root@testvm slapd-testvm1]# dbscan -f /var/lib/dirsrv/slapd-testvm1/db/exampledb/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.2
[root@testvm slapd-testvm1]# diff /tmp/numsubordinates.out /tmp/numsubordinates.out.2
[root@testvm slapd-testvm1]# echo $?
0


3-1. add equality index to numsubordinates
     $ ldapmodify ...
     dn: cn=numsubordinates,cn=index,cn=exampledb,cn=exampledb,cn=ldbm database,cn=plugins,cn=config
     changetype: modify
     add: nsIndexType
     nsIndexType: eq


3-2. $ /usr/lib64/dirsrv/slapd-ID/db2index.pl -D 'cn=directory manager' -w <password> -n <backend> -t numsubordinates
3-3. $ dbscan -f /var/lib/dirsrv/slapd-ID/db/<backend>/numsubordinates.db4 -n -r > /tmp/numsubordinates.out.3
3-4. verify the equality index is added.  E.g.,
     =5                                      1
     1
[root@testvm slapd-testvm1]#  diff /tmp/numsubordinates.out /tmp/numsubordinates.out.3
2a3,16
> =1                                      1
> 	2 
> =8                                      1
> 	1 
> =19904                                  1
> 	9 
> =19926                                  1
> 	6 
> =19973                                  1
> 	7 
> =20078                                  1
> 	8 
> =20120                                  1
> 	10 

hence VERIFIED?

Comment 14 Noriko Hosoi 2011-07-29 15:51:17 UTC
> hence VERIFIED?

Yes.  All the steps look good.  Thanks, Amita!

Comment 15 Amita Sharma 2011-08-01 10:46:18 UTC
based on comment#14, marking this bug as VERIFIED. Thanks to you Noriko :)


Note You need to log in before you can comment on or make changes to this bug.