From b7b71e2da754f950229cbc34d55e34e1314de301 Mon Sep 17 00:00:00 2001
From: Thierry Bordaz <tbordaz@redhat.com>
Date: Fri, 19 Jan 2018 17:50:59 +0100
Subject: [PATCH] Ticket 49540 - Indexing task is reported finished too early
regarding the backend status
Bug Description:
If a task complete successfully, its status is updated before the backend
can receive update.
Fix Description:
postpone the task status update after backend is reenabled
https://pagure.io/389-ds-base/issue/49540
Reviewed by: Ludwig Krispenz
Platforms tested: F26
Flag Day: no
Doc impact: no
---
dirsrvtests/tests/tickets/ticket49540_test.py | 135 ++++++++++++++++++++++++++
ldap/servers/slapd/back-ldbm/ldif2ldbm.c | 16 +--
2 files changed, 145 insertions(+), 6 deletions(-)
create mode 100644 dirsrvtests/tests/tickets/ticket49540_test.py
diff --git a/dirsrvtests/tests/tickets/ticket49540_test.py b/dirsrvtests/tests/tickets/ticket49540_test.py
new file mode 100644
index 000000000..1fbfde2c5
--- /dev/null
+++ b/dirsrvtests/tests/tickets/ticket49540_test.py
@@ -0,0 +1,135 @@
+import logging
+import pytest
+import os
+import ldap
+import time
+import re
+from lib389._constants import *
+from lib389.tasks import *
+from lib389.topologies import topology_st as topo
+from lib389.idm.user import UserAccount, UserAccounts, TEST_USER_PROPERTIES
+from lib389 import Entry
+
+
+
+DEBUGGING = os.getenv("DEBUGGING", default=False)
+if DEBUGGING:
+ logging.getLogger(__name__).setLevel(logging.DEBUG)
+else:
+ logging.getLogger(__name__).setLevel(logging.INFO)
+log = logging.getLogger(__name__)
+
+HOMEDIRECTORY_INDEX = 'cn=homeDirectory,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config'
+HOMEDIRECTORY_CN = "homedirectory"
+MATCHINGRULE = 'nsMatchingRule'
+USER_CN = 'user_'
+
+def create_index_entry(topo):
+ log.info("\n\nindex homeDirectory")
+ try:
+ ent = topo.getEntry(HOMEDIRECTORY_INDEX, ldap.SCOPE_BASE)
+ except ldap.NO_SUCH_OBJECT:
+ topo.add_s(Entry((HOMEDIRECTORY_INDEX, {
+ 'objectclass': "top nsIndex".split(),
+ 'cn': HOMEDIRECTORY_CN,
+ 'nsSystemIndex': 'false',
+ MATCHINGRULE: ['caseIgnoreIA5Match', 'caseExactIA5Match' ],
+ 'nsIndexType': ['eq', 'sub', 'pres']})))
+
+
+def provision_users(topo):
+ test_users = []
+ homeValue = b'x' * (32 * 1024) # just to slow down indexing
+ for i in range(100):
+ CN = '%s%d' % (USER_CN, i)
+ users = UserAccounts(topo, SUFFIX)
+ user_props = TEST_USER_PROPERTIES.copy()
+ user_props.update({'uid': CN, 'cn': CN, 'sn': '_%s' % CN, HOMEDIRECTORY_CN: homeValue})
+ testuser = users.create(properties=user_props)
+ test_users.append(testuser)
+ return test_users
+
+def start_start_status(server):
+ args = {TASK_WAIT: False}
+ indexTask = Tasks(server)
+ indexTask.reindex(suffix=SUFFIX, attrname='homeDirectory', args=args)
+ return indexTask
+
+def check_task_status(server, indexTask, test_entry):
+ finish_pattern = re.compile(".*Finished indexing.*")
+ mod = [(ldap.MOD_REPLACE, 'sn', b'foo')]
+ for i in range(10):
+ log.info("check_task_status =========> %d th loop" % i)
+ try:
+ ent = server.getEntry(indexTask.dn, ldap.SCOPE_BASE)
+ if ent.hasAttr('nsTaskStatus'):
+ value = str(ent.getValue('nsTaskStatus'))
+ finish = finish_pattern.search(value)
+ log.info("%s ---> %s" % (indexTask.dn, value))
+ else:
+ finish = None
+ log.info("%s ---> NO STATUS" % (indexTask.dn))
+
+ if not finish:
+ # This is not yet finished try an update
+ try:
+ server.modify_s(test_entry, mod)
+
+ # weird, may be indexing just complete
+ ent = server.getEntry(indexTask.dn, ldap.SCOPE_BASE, ['nsTaskStatus'])
+ assert (ent.hasAttr('nsTaskStatus') and regex.search(ent.getValue('nsTaskStatus')))
+ log.info("Okay, it just finished so the MOD was successful")
+ except ldap.UNWILLING_TO_PERFORM:
+ log.info("=========> Great it was expected in the middle of index")
+ else:
+ # The update should be successful
+ server.modify_s(test_entry, mod)
+
+ except ldap.NO_SUCH_OBJECT:
+ log.info("%s: no found" % (indexTask.dn))
+
+ time.sleep(1)
+
+def test_ticket49540(topo):
+ """Specify a test case purpose or name here
+
+ :id: 1df16d5a-1b92-46b7-8435-876b87545748
+ :setup: Standalone Instance
+ :steps:
+ 1. Create homeDirectory index (especially with substring)
+ 2. Creates 100 users with large homeDirectory value => long to index
+ 3. Start an indexing task WITHOUT waiting for its completion
+ 4. Monitor that until task.status = 'Finish', any update -> UNWILLING to perform
+ :expectedresults:
+ 1. Index configuration succeeds
+ 2. users entry are successfully created
+ 3. Indexing task is started
+ 4. If the task.status does not contain 'Finished indexing', any update should return UNWILLING_TO_PERFORM
+ When it contains 'Finished indexing', updates should be successful
+ """
+
+ server = topo.standalone
+ create_index_entry(server)
+ test_users = provision_users(server)
+
+ indexTask = start_start_status(server)
+ check_task_status(server, indexTask, test_users[0].dn)
+
+ # If you need any test suite initialization,
+ # please, write additional fixture for that (including finalizer).
+ # Topology for suites are predefined in lib389/topologies.py.
+
+ # If you need host, port or any other data about instance,
+ # Please, use the instance object attributes for that (for example, topo.ms["master1"].serverid)
+
+ if DEBUGGING:
+ # Add debugging steps(if any)...
+ pass
+
+
+if __name__ == '__main__':
+ # Run isolated
+ # -s for DEBUG mode
+ CURRENT_FILE = os.path.realpath(__file__)
+ pytest.main(["-s", CURRENT_FILE])
+
diff --git a/ldap/servers/slapd/back-ldbm/ldif2ldbm.c b/ldap/servers/slapd/back-ldbm/ldif2ldbm.c
index 6d897edc7..6527a477c 100644
--- a/ldap/servers/slapd/back-ldbm/ldif2ldbm.c
+++ b/ldap/servers/slapd/back-ldbm/ldif2ldbm.c
@@ -2533,12 +2533,7 @@ ldbm_back_ldbm2index(Slapi_PBlock *pb)
vlvIndex_go_online(pvlv[vlvidx], be);
}
- if (task) {
- slapi_task_log_status(task, "%s: Finished indexing.",
- inst->inst_name);
- slapi_task_log_notice(task, "%s: Finished indexing.",
- inst->inst_name);
- }
+ /* if it was a task, its status will be updated later after backend is ready for update */
slapi_log_err(SLAPI_LOG_INFO, "ldbm_back_ldbm2index", "%s: Finished indexing.\n",
inst->inst_name);
return_value = 0; /* success */
@@ -2562,6 +2557,15 @@ err_min:
dblayer_release_id2entry( be, db ); /* nope */
instance_set_not_busy(inst);
+ if (return_value == 0) {
+ if (task) {
+ slapi_task_log_status(task, "%s: Finished indexing.",
+ inst->inst_name);
+ slapi_task_log_notice(task, "%s: Finished indexing.",
+ inst->inst_name);
+ }
+ }
+
if (run_from_cmdline) {
if (0 != dblayer_flush(li)) {
slapi_log_err(SLAPI_LOG_ERR,
--
2.13.6