From 3dac3503087b6bae9e6e3d63a8214e8be65a145b Mon Sep 17 00:00:00 2001 From: Thierry Bordaz Date: Fri, 19 Jan 2018 17:50:59 +0100 Subject: [PATCH 05/10] 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 4347c1721..16b87ee6b 100644 --- a/ldap/servers/slapd/back-ldbm/ldif2ldbm.c +++ b/ldap/servers/slapd/back-ldbm/ldif2ldbm.c @@ -2562,12 +2562,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 */ @@ -2591,6 +2586,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) { dblayer_instance_close(be); if (0 != dblayer_close(li, DBLAYER_INDEX_MODE)) { -- 2.13.6