Bug 692331

Summary: Segfault on index update during full replication push on 1.2.7.5
Product: [Retired] 389 Reporter: Karsten Sperling <mail>
Component: Database - Indexes/SearchesAssignee: Rich Megginson <rmeggins>
Status: CLOSED CURRENTRELEASE QA Contact: Chandrasekar Kannan <ckannan>
Severity: unspecified Docs Contact:
Priority: high    
Version: 1.2.7CC: amsharma, benl, nkinder
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 693516 (view as bug list) Environment:
Last Closed: 2014-06-16 16:23:50 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 639035, 656390, 693516    
Attachments:
Description Flags
0001-Bug-692331-Segfault-on-index-update-during-full-repl.patch nkinder: review+

Description Karsten Sperling 2011-03-31 03:02:45 UTC
Description of problem:

Segfault on index update during full replication push to 1.2.7.5 on RHEL6 x86_64, replicating from 1.2.6 on RHEL 5.4 i386.

Version-Release number of selected component (if applicable):

1.2.7.5

How reproducible:

Index definition:
dn: cn=nzCoSkyReceiveMarketingNewsletter,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config
changetype: add
objectClass: top
objectClass: nsIndex
cn:nzCoSkyReceiveMarketingNewsletter
nsSystemIndex:false
nsIndexType:eq
nsMatchingRule: 2.16.840.1.113730.3.3.2.6.1

Attribute definition:
attributeTypes: (
  1.3.6.1.4.1.34217.1.1.1.2.6
  NAME 'nzCoSkyReceiveMarketingNewsLetter'
  DESC 'Whether the user opts to receive SKY TV news letters'
  EQUALITY booleanMatch
  ORDERING booleanMatch
  SYNTAX 1.3.6.1.4.1.1466.115.121.1.7
  SINGLE-VALUE
)

Steps to Reproduce:
1. Synchronize an entry that has a value for the nzCoSkyReceiveMarketingNewsLetter attribute

Additional info:

The indexer created via create_matchrule_indexer() -> or_filter_create() has a SLAPI_PLUGIN_MR_FILTER_INDEX_FN but no SLAPI_PLUGIN_MR_FILTER_INDEX_SV_FN. matchrule_values_to_keys_sv() then calls SLAPI_PLUGIN_MR_FILTER_INDEX_SV_FN resulting in the segfault.

This seems to relate to change http://git.fedorahosted.org/git/?p=389/ds.git;a=commitdiff;h=ca6e6538a65bc03f7b8e1c521b5d0ba6d7b82a9e to matchrule_values_to_keys_sv().

Stack trace etc:

Thread 1 (Thread 18697):
#0  0x0000000000000000 in ?? ()
No symbol table info available.
#1  0x00007f2a8173582d in matchrule_values_to_keys_sv (pb=0x7f2a18005850, input_values=0x7f2a48017400, output_values=0x7f2a397fac50) at ldap/servers/slapd/back-ldbm/matchrule.c:162
        mrINDEX = 0
#2  0x00007f2a8170f494 in index_addordel_values_ext_sv (be=<value optimized out>, type=<value optimized out>, vals=0x7f2a48017400, evals=<value optimized out>, id=9, flags=<value optimized out>,
    txn=0x0, idl_disposition=0x7f2a397fad8c, buffer_handle=0x0) at ldap/servers/slapd/back-ldbm/index.c:2003
        keys = 0x0
        officialOID = 0x20328f0 "2.16.840.1.113730.3.3.2.6.1"
        pb = 0x7f2a18005850
        oid = 0x2281590
        db = 0x7f2a18000a40
        ai = 0x22821a0
        err = <value optimized out>
        ivals = 0x0
        buf = "nzCoSkyReceiveMarketingNewsletter", '\000' <repeats 222 times>
        basetmp = 0x0
        basetype = <value optimized out>
#3  0x00007f2a8170cbad in import_worker (param=0x7f2a3c002ae0) at ldap/servers/slapd/back-ldbm/import-threads.c:2545
        ep = <value optimized out>
        svals = <value optimized out>
        attr = <value optimized out>
        info = 0x7f2a3c002ae0
        job = 0x7f2a480016b0
        inst = 0x21da780
        be = 0x2154ba0
        sleeptime = 200
        finished = <value optimized out>
        id = <value optimized out>
        ret = 0
        idl_disposition = 1
        vlv_index = 0x0
        substring_key_buffer = 0x0
        fi = 0x7f2a78588130
        attrlist_cursor = 0x7f2a48017450
#4  0x00007f2a88f64593 in ?? () from /lib64/libnspr4.so
No symbol table info available.
#5  0x00007f2a889077e1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#6  0x00007f2a8866253d in clone () from /lib64/libc.so.6
No symbol table info available.

(gdb) info frame
Stack level 2, frame at 0x7f2a397facd0:
 rip = 0x7f2a8170f494 in index_addordel_values_ext_sv (ldap/servers/slapd/back-ldbm/index.c:2003); saved rip 0x7f2a8170cbad
 called by frame at 0x7f2a397fadd0, caller of frame at 0x7f2a397fa820
 source language c.
 Arglist at 0x7f2a397fa818, args: be=<value optimized out>, type=<value optimized out>, vals=0x7f2a48017400, evals=<value optimized out>, id=9, flags=<value optimized out>, txn=0x0,
    idl_disposition=0x7f2a397fad8c, buffer_handle=0x0
 Locals at 0x7f2a397fa818, Previous frame's sp is 0x7f2a397facd0
 Saved registers:
  rbx at 0x7f2a397fac98, rbp at 0x7f2a397faca0, r12 at 0x7f2a397faca8, r13 at 0x7f2a397facb0, r14 at 0x7f2a397facb8, r15 at 0x7f2a397facc0, rip at 0x7f2a397facc8
(gdb) info locals
keys = 0x0
officialOID = 0x20328f0 "2.16.840.1.113730.3.3.2.6.1"
pb = 0x7f2a18005850
oid = 0x2281590
db = 0x7f2a18000a40
ai = 0x22821a0
err = <value optimized out>
ivals = 0x0
buf = "nzCoSkyReceiveMarketingNewsletter", '\000' <repeats 222 times>
basetmp = 0x0
basetype = <value optimized out>
(gdb) print *pb
$10 = {pb_backend = 0x0, pb_conn = 0x0, pb_op = 0x0, pb_plugin = 0x202b710, pb_opreturn = 0, pb_object = 0x7f2a180009c0, pb_destroy_fn = 0x7f2a86349fd0 <op_indexer_destroy>, pb_requestor_isroot = 0,
  pb_config_fname = 0x0, pb_config_lineno = 0, pb_config_argc = 0, pb_config_argv = 0x0, pb_target_entry = 0x0, pb_existing_dn_entry = 0x0, pb_existing_uniqueid_entry = 0x0, pb_parent_entry = 0x0,
  pb_newparent_entry = 0x0, pb_pre_op_entry = 0x0, pb_post_op_entry = 0x0, pb_seq_type = 0, pb_seq_attrname = 0x0, pb_seq_val = 0x0, pb_ldif_file = 0x0, pb_removedupvals = 0, pb_db2index_attrs = 0x0,
  pb_ldif2db_noattrindexes = 0, pb_ldif_printkey = 0, pb_instance_name = 0x0, pb_task = 0x0, pb_task_flags = 0, pb_mr_filter_match_fn = 0, pb_mr_filter_index_fn = 0, pb_mr_filter_reset_fn = 0,
  pb_mr_index_fn = 0x7f2a86349ed0 <op_index_entry>, pb_mr_oid = 0x20328f0 "2.16.840.1.113730.3.3.2.6.1", pb_mr_type = 0x7f2a397fab30 "nzCoSkyReceiveMarketingNewsletter", pb_mr_value = 0x0,
  pb_mr_values = 0x7f2a48017400, pb_mr_keys = 0x0, pb_mr_filter_reusable = 0, pb_mr_query_operator = 0, pb_mr_usage = 1, pb_pwd_storage_scheme_user_passwd = 0x0, pb_pwd_storage_scheme_db_passwd = 0x0,
  pb_managedsait = 0, pb_internal_op_result = 0, pb_plugin_internal_search_op_entries = 0x0, pb_plugin_internal_search_op_referrals = 0x0, pb_plugin_identity = 0x0, pb_parent_txn = 0x0, pb_txn = 0x0,
  pb_dbsize = 0, pb_ldif_files = 0x0, pb_ldif_include = 0x0, pb_ldif_exclude = 0x0, pb_ldif_dump_replica = 0, pb_ldif_dump_uniqueid = 0, pb_ldif_generate_uniqueid = 0, pb_ldif_namespaceid = 0x0,
  pb_ldif_encrypt = 0, pb_operation_notes = 0, pb_slapd_argc = 0, pb_slapd_argv = 0x0, pb_slapd_configdir = 0x0, pb_ctrls_arg = 0x0, pb_dse_dont_add_write = 0, pb_dse_add_merge = 0,
  pb_dse_dont_check_dups = 0, pb_dse_is_primary_file = 0, pb_schema_flags = 0, pb_result_code = 0, pb_result_text = 0x0, pb_result_matched = 0x0, pb_nentries = 0, urls = 0x0, pb_import_entry = 0x0,
  pb_import_state = 0, pb_destroy_content = 0, pb_dse_reapply_mods = 0, pb_urp_naming_collision_dn = 0x0, pb_urp_tombstone_uniqueid = 0x0, pb_server_running = 0, pb_backend_count = 0, pb_pwpolicy_ctrl = 0,
  pb_vattr_context = 0x0, pb_substrlens = 0x0, pb_plugin_enabled = 0, pb_search_ctrls = 0x0, pb_mr_index_sv_fn = 0}

(gdb) print pb->pb_mr_index_sv_fn
$17 = (IFP) 0

(gdb) print *(pb->pb_mr_index_fn)
$16 = {int ()} 0x7f2a86349ed0 <op_index_entry>

(gdb) info line *0x7f2a86349ed0
Line 611 of "ldap/servers/plugins/collation/orfilter.c" starts at address 0x7f2a86349ed0 <op_index_entry> and ends at 0x7f2a86349eda <op_index_entry+10>.

Comment 1 Rich Megginson 2011-04-04 21:08:06 UTC
Created attachment 489855 [details]
0001-Bug-692331-Segfault-on-index-update-during-full-repl.patch

Comment 2 Rich Megginson 2011-04-05 01:41:16 UTC
To ssh://git.fedorahosted.org/git/389/ds.git
   27ff25d..466fced  master -> master
commit 62a7368e3aed00b44d9f1828b9235d0a2d7572cd
Author: Rich Megginson <rmeggins>
Date:   Wed Mar 30 20:00:27 2011 -0600
    Reviewed by: nkinder (Thanks!)
    Branch: master
    Fix Description: The collation plugin still uses the old style index key
    generation function that uses struct berval **.  If we don't find a new
    style index key function that uses Slapi_Value**, wrap the old function
    to convert Slapi_Value** to struct berval **
    The plugin_mr code keeps track of the Slapi_Value**.  The old style
    collation code keeps track of and deletes the struct berval** values.
    We store the output keys in the MR_KEYS pblock field and free them
    in the indexer destroyer code.  The new style mr indexer code sets
    MR_KEYS to NULL so the indexer destroyer code won't try to free them
    again.
    Steps to reproduce:
    1) find or create an attribute which has an ORDERING matching rule
    (and not via inheritance - that's another bug)
    2) add or change the index for the attribute to have an nsMatchingRule
    with one of the l10n matching rules defined by the collation plugin
    e.g. 2.16.840.1.113730.3.3.2.11.1 for en or en-US
    3) add an entry which has that attribute and a valid value
    4) do an import or re-index
    It crashes in matchrule_values_to_keys_sv because mrINDEX is NULL
    because the old style collation plugin indexer does not support
    Slapi_Values.
    Platforms tested: RHEL6 x86_64
    Flag Day: no
    Doc impact: no

Comment 3 Rich Megginson 2011-04-05 02:08:54 UTC
To ssh://git.fedorahosted.org/git/389/ds.git
   e2288d9..5c1cd5f  389-ds-base-1.2.8 -> 389-ds-base-1.2.8
commit e98229a602b3acfafd616afda743d268dae42ff2
Author: Rich Megginson <rmeggins>
Date:   Wed Mar 30 20:00:27 2011 -0600

Comment 4 Amita Sharma 2011-04-29 13:35:51 UTC
Hi Rich,

Got the error at step 2 only, Please check :

1) find or create an attribute which has an ORDERING matching rule
    (and not via inheritance - that's another bug)

ldapmodify -x -h localhost -p 1389 -D "cn=directory manager" -w Secret123 -v << EOF
dn: cn=schema
changetype: modify
add: attributetypes
attributeTypes: (1.3.6.1.4.1.34217.1.1.1.2.6 NAME 'nzCoSkyReceiveMarketingNewsLetter' DESC 'Whether the user opts to receive SKY TV news letters' EQUALITY booleanMatch ORDERING booleanMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.7 SINGLE-VALUE)

add attributeTypes:
	(1.3.6.1.4.1.34217.1.1.1.2.6 NAME 'nzCoSkyReceiveMarketingNewsLetter' DESC 'Whether the user opts to receive SKY TV news letters' EQUALITY booleanMatch ORDERING booleanMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.7 SINGLE-VALUE)
modifying entry "cn=schema"
modify complete

2) add or change the index for the attribute to have an nsMatchingRule
    with one of the l10n matching rules defined by the collation plugin
    e.g. 2.16.840.1.113730.3.3.2.11.1 for en or en-US
[root@rheltest slapd-rheltest]# ldapmodify -a -D "cn=directory manager" -w Secret123 -p 1389 -h localhost << EOF
> dn: cn=nzCoSkyReceiveMarketingNewsletter,cn=index,cn=userRoot,cn=ldbm
> database,cn=plugins,cn=config
> changetype: add
> objectClass: top
> objectClass: nsIndex
> cn:nzCoSkyReceiveMarketingNewsletter
> nsSystemIndex:false
> nsIndexType:eq
> nsMatchingRule: 2.16.840.1.113730.3.3.2.6.1
> nsMatchingRule: 2.16.840.1.113730.3.3.2.11.1
> EOF
ldapmodify: invalid format (line 2) entry: "cn=nzCoSkyReceiveMarketingNewsletter,cn=index,cn=userRoot,cn=ldbm"
Segmentation fault (core dumped)

Comment 5 Amita Sharma 2011-05-02 14:28:49 UTC
1) find or create an attribute which has an ORDERING matching rule
    (and not via inheritance - that's another bug) - 

createTimestamp has ORDERING matching rule

2) add or change the index for the attribute to have an nsMatchingRule
    with one of the l10n matching rules defined by the collation plugin
    e.g. 2.16.840.1.113730.3.3.2.11.1 for en or en-US

ldapmodify -a -D "cn=directory manager" -w Secret123 -p 1390 -h localhost << EOF
dn: cn=createTimestamp,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config
changetype: add
objectClass: top
objectClass: nsIndex
cn:createTimestamp
nsSystemIndex:false
nsIndexType:eq
nsMatchingRule: 2.16.840.1.113730.3.3.2.11.1

3).add an entry which has that attribute and a valid value

ldapmodify -x -h localhost -p 1390 -D "cn=Directory Manager" -w Secret123 << EOF
dn: uid=amimash5,dc=example,dc=com
changetype: add
objectClass: top
objectClass: inetorgperson
objectClass: examplePerson
cn: kkktestkrbuser
sn: testkrbuser
userPassword: redhat
createTimestamp: ddmmyyy
EOF

4)  service dirsrv stop

5) [root@rhel61-ds90-amita ~]# /usr/lib64/dirsrv/slapd-rhel61-ds90-amita1/db2index
[02/May/2011:19:14:46 +051800] - check_and_set_import_cache: pagesize: 4096, pages: 255398, procpages: 49700
[02/May/2011:19:14:46 +051800] - WARNING: After allocating import cache 408636KB, the available memory is 612956KB, which is less than the soft limit 1048576KB. You may want to decrease the import cache size and rerun import.
[02/May/2011:19:14:46 +051800] - Import allocates 408636KB import cache.
[02/May/2011:19:14:46 +051800] - Backing up file 0 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/parentid.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 1 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/sn.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 2 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/entryrdn.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 3 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/objectclass.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 4 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/id2entry.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 5 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/DBVERSION)
[02/May/2011:19:14:46 +051800] - Backing up file 6 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/uid.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 7 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/createTimestamp.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 8 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/aci.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 9 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/cn.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 10 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/nsuniqueid.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 11 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/ancestorid.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 12 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/numsubordinates.db4)
[02/May/2011:19:14:46 +051800] - Backing up file 13 (/var/lib/dirsrv/slapd-rhel61-ds90-amita1/bak/reindex_2011_05_02_19_14_46/userRoot/uniquemember.db4)
[02/May/2011:19:14:46 +051800] upgrade DB - userRoot: Start upgradedb.
[02/May/2011:19:14:46 +051800] - WARNING: Import is running with nsslapd-db-private-import-mem on; No other process is allowed to access the database
[02/May/2011:19:14:46 +051800] - reindex userRoot: Index buffering enabled with bucket size 100
[02/May/2011:19:14:47 +051800] - reindex userRoot: Workers finished; cleaning up...
[02/May/2011:19:14:47 +051800] - reindex userRoot: Workers cleaned up.
[02/May/2011:19:14:47 +051800] - reindex userRoot: Cleaning up producer thread...
[02/May/2011:19:14:47 +051800] - reindex userRoot: Indexing complete.  Post-processing...
[02/May/2011:19:14:47 +051800] - reindex userRoot: Flushing caches...
[02/May/2011:19:14:47 +051800] - reindex userRoot: Closing files...
[02/May/2011:19:14:47 +051800] - All database threads now stopped
[02/May/2011:19:14:47 +051800] - reindex userRoot: Reindexing complete.  Processed 11 entries in 1 seconds. (11.00 entries/sec)
[02/May/2011:19:14:47 +051800] - All database threads now stopped

6) service dirsrv start

Working fine without any issue, marking as VERIFIED.

Comment 6 Rich Megginson 2014-06-16 13:37:43 UTC
should be marked CLOSED