Issue 4443 - Internal unindexed searches in syncrepl/retro changelog

Bug Description:

When a non-system index is added to a backend it is
disabled until the database is initialized or reindexed.
So in the case of the retro changelog the changenumber index
is alway disabled by default since it is never initialized.
This leads to unexpected unindexed searches of the retro
changelog.

Fix Description:

If an index has "nsSystemIndex" set to "true" then enable it
immediately.

relates:  #4443

Reviewed by: spichugi & tbordaz(Thanks!!)

dirsrvtests/tests/suites/retrocl/basic_test.py

@@ -8,7 +8,6 @@
 
 import logging
 import ldap
-import time
 import pytest
 from lib389.topologies import topology_st
 from lib389.plugins import RetroChangelogPlugin
@@ -18,7 +17,8 @@
 from lib389.cli_base import FakeArgs, connect_instance, disconnect_instance
 from lib389.cli_base.dsrc import dsrc_arg_concat
 from lib389.cli_conf.plugins.retrochangelog import retrochangelog_add
-from lib389.idm.user import UserAccount, UserAccounts, nsUserAccounts
+from lib389.idm.user import UserAccount, UserAccounts
+from lib389._mapped_object import DSLdapObjects
 
 pytestmark = pytest.mark.tier1
 
@@ -77,7 +77,7 @@ def test_retrocl_exclude_attr_add(topology_st):
 
     log.info('Adding user1')
     try:
-        user1 = users.create(properties={
+        users.create(properties={
             'sn': '1',
             'cn': 'user 1',
             'uid': 'user1',
@@ -92,17 +92,18 @@ def test_retrocl_exclude_attr_add(topology_st):
     except ldap.ALREADY_EXISTS:
         pass
     except ldap.LDAPError as e:
-        log.error("Failed to add user1")
+        log.error("Failed to add user1: " + str(e))
 
     log.info('Verify homePhone and carLicense attrs are in the changelog changestring')
     try:
-        cllist = st.search_s(RETROCL_SUFFIX, ldap.SCOPE_SUBTREE, '(targetDn=%s)' % USER1_DN)
+        retro_changelog_suffix = DSLdapObjects(st, basedn=RETROCL_SUFFIX)
+        cllist = retro_changelog_suffix.filter(f'(targetDn={USER1_DN})')
     except ldap.LDAPError as e:
-        log.fatal("Changelog search failed, error: " +str(e))
+        log.fatal("Changelog search failed, error: " + str(e))
         assert False
     assert len(cllist) > 0
-    if  cllist[0].hasAttr('changes'):
-        clstr = (cllist[0].getValue('changes')).decode()
+    if  cllist[0].present('changes'):
+        clstr = str(cllist[0].get_attr_vals_utf8('changes'))
         assert ATTR_HOMEPHONE in clstr
         assert ATTR_CARLICENSE in clstr
 
@@ -133,7 +134,7 @@ def test_retrocl_exclude_attr_add(topology_st):
 
     log.info('Adding user2')
     try:
-        user2 = users.create(properties={
+        users.create(properties={
             'sn': '2',
             'cn': 'user 2',
             'uid': 'user2',
@@ -148,18 +149,18 @@ def test_retrocl_exclude_attr_add(topology_st):
     except ldap.ALREADY_EXISTS:
         pass
     except ldap.LDAPError as e:
-        log.error("Failed to add user2")
+        log.error("Failed to add user2: " + str(e))
 
     log.info('Verify homePhone attr is not in the changelog changestring')
     try:
-        cllist = st.search_s(RETROCL_SUFFIX, ldap.SCOPE_SUBTREE, '(targetDn=%s)' % USER2_DN)
+        cllist = retro_changelog_suffix.filter(f'(targetDn={USER2_DN})')
         assert len(cllist) > 0
-        if  cllist[0].hasAttr('changes'):
-            clstr = (cllist[0].getValue('changes')).decode()
+        if  cllist[0].present('changes'):
+            clstr = str(cllist[0].get_attr_vals_utf8('changes'))
             assert ATTR_HOMEPHONE not in clstr
             assert ATTR_CARLICENSE in clstr
     except ldap.LDAPError as e:
-        log.fatal("Changelog search failed, error: " +str(e))
+        log.fatal("Changelog search failed, error: " + str(e))
         assert False
 
 #unstable or unstatus tests, skipped for now
@@ -222,19 +223,20 @@ def test_retrocl_exclude_attr_mod(topology_st):
             'homeDirectory': '/home/user1',
             'userpassword': USER_PW})
     except ldap.ALREADY_EXISTS:
-        pass
+        user1 = UserAccount(st, dn=USER1_DN)
     except ldap.LDAPError as e:
-        log.error("Failed to add user1")
+        log.error("Failed to add user1: " + str(e))
 
     log.info('Verify homePhone and carLicense attrs are in the changelog changestring')
     try:
-        cllist = st.search_s(RETROCL_SUFFIX, ldap.SCOPE_SUBTREE, '(targetDn=%s)' % USER1_DN)
+        retro_changelog_suffix = DSLdapObjects(st, basedn=RETROCL_SUFFIX)
+        cllist = retro_changelog_suffix.filter(f'(targetDn={USER1_DN})')
     except ldap.LDAPError as e:
-        log.fatal("Changelog search failed, error: " +str(e))
+        log.fatal("Changelog search failed, error: " + str(e))
         assert False
     assert len(cllist) > 0
-    if  cllist[0].hasAttr('changes'):
-        clstr = (cllist[0].getValue('changes')).decode()
+    if  cllist[0].present('changes'):
+        clstr = str(cllist[0].get_attr_vals_utf8('changes'))
         assert ATTR_HOMEPHONE in clstr
         assert ATTR_CARLICENSE in clstr
 
@@ -265,24 +267,25 @@ def test_retrocl_exclude_attr_mod(topology_st):
 
     log.info('Modify user1 carLicense attribute')
     try:
-        st.modify_s(USER1_DN, [(ldap.MOD_REPLACE, ATTR_CARLICENSE, b"123WX321")])
+        user1.replace(ATTR_CARLICENSE, "123WX321")
     except ldap.LDAPError as e:
         log.fatal('test_retrocl_exclude_attr_mod: Failed to update user1 attribute: error ' + e.message['desc'])
         assert False
 
     log.info('Verify carLicense attr is not in the changelog changestring')
     try:
-        cllist = st.search_s(RETROCL_SUFFIX, ldap.SCOPE_SUBTREE, '(targetDn=%s)' % USER1_DN)
+        cllist = retro_changelog_suffix.filter(f'(targetDn={USER1_DN})')
         assert len(cllist) > 0
         # There will be 2 entries in the changelog for this user, we are only
         #interested in the second one, the modify operation.
-        if  cllist[1].hasAttr('changes'):
-            clstr = (cllist[1].getValue('changes')).decode()
+        if  cllist[1].present('changes'):
+            clstr = str(cllist[1].get_attr_vals_utf8('changes'))
             assert ATTR_CARLICENSE not in clstr
     except ldap.LDAPError as e:
-        log.fatal("Changelog search failed, error: " +str(e))
+        log.fatal("Changelog search failed, error: " + str(e))
         assert False
 
+
 if __name__ == '__main__':
     # Run isolated
     # -s for DEBUG mode

dirsrvtests/tests/suites/retrocl/retrocl_indexing_test.py

@@ -0,0 +1,68 @@
+import logging
+import pytest
+import os
+from lib389._constants import RETROCL_SUFFIX, DEFAULT_SUFFIX
+from lib389.topologies import topology_st as topo
+from lib389.plugins import RetroChangelogPlugin
+from lib389.idm.user import UserAccounts
+from lib389._mapped_object import DSLdapObjects
+log = logging.getLogger(__name__)
+
+
+def test_indexing_is_online(topo):
+    """Test that the changenmumber index is online right after enabling the plugin
+
+    :id: 16f4c001-9e0c-4448-a2b3-08ac1e85d40f
+    :setup: Standalone Instance
+    :steps:
+        1. Enable retro cl
+        2. Perform some updates
+        3. Search for "(changenumber>=-1)", and it is not partially unindexed
+        4. Search for "(&(changenumber>=-1)(targetuniqueid=*))", and it is not partially unindexed
+    :expectedresults:
+        1. Success
+        2. Success
+        3. Success
+        4. Success
+    """
+
+    # Enable plugin
+    topo.standalone.config.set('nsslapd-accesslog-logbuffering',  'off')
+    plugin = RetroChangelogPlugin(topo.standalone)
+    plugin.enable()
+    topo.standalone.restart()
+
+    # Do a bunch of updates
+    users = UserAccounts(topo.standalone, DEFAULT_SUFFIX)
+    user_entry = users.create(properties={
+        'sn': '1',
+        'cn': 'user 1',
+        'uid': 'user1',
+        'uidNumber': '11',
+        'gidNumber': '111',
+        'givenname': 'user1',
+        'homePhone': '0861234567',
+        'carLicense': '131D16674',
+        'mail': 'user1@whereever.com',
+        'homeDirectory': '/home'
+    })
+    for count in range(0, 10):
+        user_entry.replace('mail', f'test{count}@test.com')
+
+    # Search the retro cl, and check for error messages
+    filter_simple = '(changenumber>=-1)'
+    filter_compound = '(&(changenumber>=-1)(targetuniqueid=*))'
+    retro_changelog_suffix = DSLdapObjects(topo.standalone, basedn=RETROCL_SUFFIX)
+    retro_changelog_suffix.filter(filter_simple)
+    assert not topo.standalone.searchAccessLog('Partially Unindexed Filter')
+
+    # Search the retro cl again with compound filter
+    retro_changelog_suffix.filter(filter_compound)
+    assert not topo.standalone.searchAccessLog('Partially Unindexed Filter')
+
+
+if __name__ == '__main__':
+    # Run isolated
+    # -s for DEBUG mode
+    CURRENT_FILE = os.path.realpath(__file__)
+    pytest.main(["-s", CURRENT_FILE])

ldap/servers/plugins/retrocl/retrocl_create.c

@@ -133,7 +133,7 @@ retrocl_create_be(const char *bedir)
     val.bv_len = strlen(val.bv_val);
     slapi_entry_add_values(e, "cn", vals);
 
-    val.bv_val = "false";
+    val.bv_val = "true"; /* enables the index */
     val.bv_len = strlen(val.bv_val);
     slapi_entry_add_values(e, "nssystemindex", vals);
 

ldap/servers/slapd/back-ldbm/ldbm_index_config.c

@@ -25,7 +25,7 @@ int ldbm_instance_index_config_delete_callback(Slapi_PBlock *pb, Slapi_Entry *en
 #define INDEXTYPE_NONE 1
 
 static int
-ldbm_index_parse_entry(ldbm_instance *inst, Slapi_Entry *e, const char *trace_string, char **index_name, char *err_buf)
+ldbm_index_parse_entry(ldbm_instance *inst, Slapi_Entry *e, const char *trace_string, char **index_name, PRBool *is_system_index, char *err_buf)
 {
     Slapi_Attr *attr;
     const struct berval *attrValue;
@@ -78,6 +78,15 @@ ldbm_index_parse_entry(ldbm_instance *inst, Slapi_Entry *e, const char *trace_st
         }
     }
 
+    *is_system_index = PR_FALSE;
+    if (0 == slapi_entry_attr_find(e, "nsSystemIndex", &attr)) {
+        slapi_attr_first_value(attr, &sval);
+        attrValue = slapi_value_get_berval(sval);
+        if (strcasecmp(attrValue->bv_val, "true") == 0) {
+            *is_system_index = PR_TRUE;
+        }
+    }
+
     /* ok the entry is good to process, pass it to attr_index_config */
     if (attr_index_config(inst->inst_be, (char *)trace_string, 0, e, 0, 0, err_buf)) {
         slapi_ch_free_string(index_name);
@@ -101,9 +110,10 @@ ldbm_index_init_entry_callback(Slapi_PBlock *pb __attribute__((unused)),
                                void *arg)
 {
     ldbm_instance *inst = (ldbm_instance *)arg;
+    PRBool is_system_index = PR_FALSE;
 
     returntext[0] = '\0';
-    *returncode = ldbm_index_parse_entry(inst, e, "from ldbm instance init", NULL, NULL);
+    *returncode = ldbm_index_parse_entry(inst, e, "from ldbm instance init", NULL, &is_system_index /* not used */, NULL);
     if (*returncode == LDAP_SUCCESS) {
         return SLAPI_DSE_CALLBACK_OK;
     } else {
@@ -126,17 +136,21 @@ ldbm_instance_index_config_add_callback(Slapi_PBlock *pb __attribute__((unused))
 {
     ldbm_instance *inst = (ldbm_instance *)arg;
     char *index_name = NULL;
+    PRBool is_system_index = PR_FALSE;
 
     returntext[0] = '\0';
-    *returncode = ldbm_index_parse_entry(inst, e, "from DSE add", &index_name, returntext);
+    *returncode = ldbm_index_parse_entry(inst, e, "from DSE add", &index_name, &is_system_index, returntext);
     if (*returncode == LDAP_SUCCESS) {
         struct attrinfo *ai = NULL;
         /* if the index is a "system" index, we assume it's being added by
          * by the server, and it's okay for the index to go online immediately.
          * if not, we set the index "offline" so it won't actually be used
          * until someone runs db2index on it.
+         * If caller wants to add an index that they want to be online
+         * immediately they can also set "nsSystemIndex" to "true" in the
+         * index config entry (e.g. is_system_index).
          */
-        if (!ldbm_attribute_always_indexed(index_name)) {
+        if (!is_system_index && !ldbm_attribute_always_indexed(index_name)) {
             ainfo_get(inst->inst_be, index_name, &ai);
             PR_ASSERT(ai != NULL);
             ai->ai_indexmask |= INDEX_OFFLINE;
@@ -386,13 +400,14 @@ ldbm_instance_index_config_enable_index(ldbm_instance *inst, Slapi_Entry *e)
     char *index_name = NULL;
     int rc = LDAP_SUCCESS;
     struct attrinfo *ai = NULL;
+    PRBool is_system_index = PR_FALSE;
 
     index_name = slapi_entry_attr_get_charptr(e, "cn");
     if (index_name) {
         ainfo_get(inst->inst_be, index_name, &ai);
     }
     if (!ai) {
-        rc = ldbm_index_parse_entry(inst, e, "from DSE add", &index_name, NULL);
+        rc = ldbm_index_parse_entry(inst, e, "from DSE add", &index_name, &is_system_index /* not used */, NULL);
     }
     if (rc == LDAP_SUCCESS) {
         /* Assume the caller knows if it is OK to go online immediately */

src/lib389/lib389/_mapped_object.py

@@ -148,6 +148,19 @@ def exists(self):
 
         return True
 
+    def search(self, scope="subtree", filter='objectclass=*'):
+        search_scope = ldap.SCOPE_SUBTREE
+        if scope == 'base':
+            search_scope = ldap.SCOPE_BASE
+        elif scope == 'one':
+            search_scope = ldap.SCOPE_ONE
+        elif scope == 'subtree':
+            search_scope = ldap.SCOPE_SUBTREE
+        return self._instance.search_ext_s(self._dn, search_scope, filter,
+                                           serverctrls=self._server_controls,
+                                           clientctrls=self._client_controls,
+                                           escapehatch='i am sure')
+
     def display(self, attrlist=['*']):
         """Get an entry but represent it as a string LDIF