Issue 6304 - RFE when memberof is enabled, defer updates of members f…

…rom the update of the group (#6305)

Bug Description:
	When an update of a static group changes
	impacts a large portion of its members, memberof triggers
	a large number of internal updates on members.
	All the updates are done a same TXN that may hold
	sensitive DB pages and block others SRCH req
	waiting for those pages.
	In extreme condition, all workers are stuck on
	SRCH req waiting for the completion of the update.
	Then the server appears unresponsive.

Fix Description:
	The fix is to defer the update of the members.

	Memberof tests:
		- for the verification of the membership, if deferred update is set,
	then adds a delay before checking
			- automember_plugin/automember_test.py
			- automember_plugin/basic_test.py
			- memberof_plugin/memberof_include_scopes_test.py
			- plugins/acceptance_test.py
			- plugins/entryusn_test.py
			- plugins/memberof_test.py
			- lib389/plugins.py
		- original update (group) succeeds even if deferred updates fails (multiple TXN)
			- betxns/betxn_test.py
		- Check replication of memberof
			- memberof_plugin/memberof_deferred_repl_test.py
		- Check deferred update and shutdown
			- memberof_plugin/memberof_include_scopes_test.py

	Core implementation:

		- Make sure that direct update (not internal) wait for
		  deferred update before returning a result
			- back-ldbm/ldbm_add.c
			- back-ldbm/ldbm_delete.c
			- back-ldbm/ldbm_modify.c
			- back-ldbm/ldbm_modrdn.c

		- Implementation of the deferred update
			- memberof/memberof.h
			- memberof/memberof.c
			- memberof/memberof_config.c
			- slapd/pblock.c
			- slapd/pblock_v3.h
			- slapd/schema.c
			- slapd/slapi-plugin.h
	memberof_be_postop_init
		registers memberof_push_deferred_task that:
		push deferred update to deferred thread
			task taken from pblock (SLAPI_MEMBEROF_DEFERRED_TASK)
			push to the memberof config deferred_list

	deferred thread (deferred_thread_func)
		if 'memberOfNeedFixup: on' then run fixup task
		loop until shutdown
			fetch task (remove_deferred_task) from the memberof config deferred_list
			proceed with the task
		if it exits abruptly, it logs an alert and add 'memberOfNeedFixup: on' to the config

	memberof_postop_start
		if deferred update is configured then it creates a deferred_list in the config
		it spawn the deferred thread + CV

	Each postop_operation memberof_postop_modrdn, memberof_postop_del, memberof_postop_modify, memberof_postop_add
		if deferred update it allocates a task and add it in the pblock (SLAPI_MEMBEROF_DEFERRED_TASK)

Related: #6304

Reviewed by: Simon Pichugin (Thanks!!)

dirsrvtests/tests/suites/automember_plugin/automember_test.py

@@ -10,6 +10,7 @@
 import pytest
 import os
 import ldap
+import time
 from lib389.utils import ds_is_older
 from lib389._constants import *
 from lib389.plugins import AutoMembershipPlugin, AutoMembershipDefinition, AutoMembershipDefinitions, AutoMembershipRegexRule
@@ -172,6 +173,10 @@ def test_delete_default_group(automember_fixture, topo):
 
     from lib389.plugins import MemberOfPlugin
     memberof = MemberOfPlugin(topo.standalone)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        tries = 10 # to avoid any risk of transient failure
+    else:
+        tries = 1
     memberof.enable()
     topo.standalone.restart()
     topo.standalone.setLogLevel(65536)
@@ -182,8 +187,20 @@ def test_delete_default_group(automember_fixture, topo):
     try:
         assert group.is_member(user_1.dn)
         group.delete()
-        error_lines = topo.standalone.ds_error_log.match('.*auto-membership-plugin - automember_update_member_value - group .default or target. does not exist .%s.$' % group.dn)
-        assert (len(error_lines) == 1)
+        # Check there is the expected message
+        while tries > 0:
+            error_lines = topo.standalone.ds_error_log.match('.*auto-membership-plugin - automember_update_member_value - group .default or target. does not exist .%s.$' % group.dn)
+            nb_match = len(error_lines)
+            log.info("len(error_lines)=%d" % nb_match)
+            for i in error_lines:
+                log.info(" - %s" % i)
+            assert nb_match <= 1
+            if (nb_match == 1):
+                # we are done the test is successful
+                break
+            time.sleep(1)
+            tries -= 1
+        assert tries > 0
     finally:
         user_1.delete()
         topo.standalone.setLogLevel(0)
@@ -285,6 +302,10 @@ def test_delete_target_group(automember_fixture, topo):
 
     from lib389.plugins import MemberOfPlugin
     memberof = MemberOfPlugin(topo.standalone)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     memberof.enable()
 
     topo.standalone.restart()
@@ -300,6 +321,7 @@ def test_delete_target_group(automember_fixture, topo):
 
         # delete that target filter group
         group_regex.delete()
+        time.sleep(delay)
         error_lines = topo.standalone.ds_error_log.match('.*auto-membership-plugin - automember_update_member_value - group .default or target. does not exist .%s.$' % group_regex.dn)
         # one line for default group and one for target group
         assert (len(error_lines) == 1)

dirsrvtests/tests/suites/automember_plugin/basic_test.py

@@ -368,19 +368,23 @@ def test_ability_to_control_behavior_of_modifiers_name(topo, _create_all_entries
         7. Should success
     """
     instance1 = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance1)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     configure = Config(instance1)
     configure.replace('nsslapd-plugin-binddn-tracking', 'on')
     instance1.restart()
     assert configure.get_attr_val_utf8('nsslapd-plugin-binddn-tracking') == 'on'
     user = add_user(topo, "User_autoMembers_05", "ou=Employees,{}".format(TEST_BASE),
                     "19", "18", "Supervisor")
+    time.sleep(delay)
     # search the User DN name for the creatorsname in user entry
     assert user.get_attr_val_utf8('creatorsname') == 'cn=directory manager'
     # search the User DN name for the internalCreatorsname in user entry
     assert user.get_attr_val_utf8('internalCreatorsname') == \
            'cn=ldbm database,cn=plugins,cn=config'
-    # search the modifiersname in the user entry
-    assert user.get_attr_val_utf8('modifiersname') == 'cn=directory manager'
     # search the internalModifiersname in the user entry
     assert user.get_attr_val_utf8('internalModifiersname') == \
            'cn=MemberOf Plugin,cn=plugins,cn=config'
@@ -404,10 +408,18 @@ def test_posixaccount_objectclass_automemberdefaultgroup(topo, _create_all_entri
         2. Should success
     """
     test_id = "autoMembers_05"
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     default_group = "cn=TestDef1,CN=testuserGroups,{}".format(TEST_BASE)
     user = add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_TEST, "19", "18", "Supervisor")
+    time.sleep(delay)
     assert check_groups(topo, default_group, user.dn, "member")
     user.delete()
+    time.sleep(delay)
     with pytest.raises(AssertionError):
         assert check_groups(topo, default_group, user.dn, "member")
 
@@ -433,13 +445,22 @@ def test_duplicated_member_attributes_added_when_the_entry_is_re_created(topo, _
         6. Should success
     """
     test_id = "autoMembers_06"
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     default_group = "cn=TestDef1,CN=testuserGroups,{}".format(TEST_BASE)
     user = add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_TEST, "19", "16", "Supervisor")
+    time.sleep(delay)
     assert check_groups(topo, default_group, user.dn, "member")
     user.delete()
+    time.sleep(delay)
     with pytest.raises(AssertionError):
         assert check_groups(topo, default_group, user.dn, "member")
     user = add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_TEST, "19", "15", "Supervisor")
+    time.sleep(delay)
     assert check_groups(topo, default_group, user.dn, "member")
     user.delete()
 
@@ -461,13 +482,21 @@ def test_multi_valued_automemberdefaultgroup_for_hostgroups(topo, _create_all_en
         4. Should success
     """
     test_id = "autoMembers_07"
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     default_group1 = "cn=TestDef1,CN=testuserGroups,{}".format(TEST_BASE)
     default_group2 = "cn=TestDef2,CN=testuserGroups,{}".format(TEST_BASE)
     default_group3 = "cn=TestDef3,CN=testuserGroups,{}".format(TEST_BASE)
     user = add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_TEST, "19", "14", "TestEngr")
+    time.sleep(delay)
     for grp in [default_group1, default_group2, default_group3]:
         assert check_groups(topo, grp, user.dn, "member")
     user.delete()
+    time.sleep(delay)
     with pytest.raises(AssertionError):
         assert check_groups(topo, default_group1, user.dn, "member")
 
@@ -488,6 +517,12 @@ def test_plugin_creates_member_attributes_of_the_automemberdefaultgroup(topo, _c
         3. Should success
     """
     test_id = "autoMembers_08"
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     default_group1 = "cn=TestDef1,CN=testuserGroups,{}".format(TEST_BASE)
     default_group2 = "cn=TestDef5,CN=testuserGroups,{}".format(TEST_BASE)
     default_group3 = "cn=TestDef3,CN=testuserGroups,{}".format(TEST_BASE)
@@ -498,6 +533,7 @@ def test_plugin_creates_member_attributes_of_the_automemberdefaultgroup(topo, _c
                     "cn=TestDef4,CN=testuserGroups,{}".format(TEST_BASE),
                     "uid=User_{},{}".format(test_id, AUTO_MEM_SCOPE_TEST), "member")
     user = add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_TEST, "19", "14", "TestEngr")
+    time.sleep(delay)
     for grp in [default_group1, default_group2, default_group3]:
         assert check_groups(topo, grp, user.dn, "member")
     user.delete()
@@ -523,6 +559,11 @@ def test_multi_valued_automemberdefaultgroup_with_uniquemember(topo, _create_all
     """
     test_id = "autoMembers_09"
     instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     auto = AutoMembershipPlugin(topo.ms["supplier1"])
     # Modify automember config entry to use uniquemember: cn=testuserGroups,PLUGIN_AUTO
     AutoMembershipDefinition(
@@ -573,11 +614,18 @@ def test_invalid_automembergroupingattr_member(topo, _create_all_entries):
         5. Should success
     """
     test_id = "autoMembers_10"
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     default_group = "cn=TestDef1,CN=testuserGroups,{}".format(TEST_BASE)
     instance_of_group = Group(topo.ms["supplier1"], default_group)
     change_grp_objclass("groupOfUniqueNames", "member", instance_of_group)
     with pytest.raises(ldap.UNWILLING_TO_PERFORM):
         add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_TEST, "19", "20", "Invalid")
+    time.sleep(delay)
     with pytest.raises(AssertionError):
         assert check_groups(topo, default_group,
                             "uid=User_{},{}".format(test_id, AUTO_MEM_SCOPE_TEST), "member")
@@ -603,6 +651,14 @@ def test_valid_and_invalid_automembergroupingattr(topo, _create_all_entries):
         5. Should success
     """
     test_id = "autoMembers_11"
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        singleTXN = False
+        delay = 3
+    else:
+        singleTXN = True
+        delay = 0
     default_group_1 = "cn=TestDef1,CN=testuserGroups,{}".format(TEST_BASE)
     default_group_2 = "cn=TestDef2,CN=testuserGroups,{}".format(TEST_BASE)
     default_group_3 = "cn=TestDef3,CN=testuserGroups,{}".format(TEST_BASE)
@@ -614,6 +670,7 @@ def test_valid_and_invalid_automembergroupingattr(topo, _create_all_entries):
         change_grp_objclass("groupOfUniqueNames", "member", instance_of_group)
     with pytest.raises(ldap.UNWILLING_TO_PERFORM):
         add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_TEST, "19", "24", "MixUsers")
+    time.sleep(delay)
     for grp in [default_group_1, default_group_2, default_group_3]:
         assert not check_groups(topo, grp, "cn=User_{},{}".format(test_id,
                                                                   AUTO_MEM_SCOPE_TEST), "member")
@@ -640,8 +697,15 @@ def test_add_regular_expressions_for_user_groups_and_check_for_member_attribute_
         2. Should success
     """
     test_id = "autoMembers_12"
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     default_group = f'cn=SuffDef1,ou=userGroups,{BASE_SUFF}'
     user = add_user(topo, "User_{}".format(test_id), AUTO_MEM_SCOPE_BASE, "19", "0", "HR")
+    time.sleep(delay)
     assert check_groups(topo, default_group, user.dn, "member")
     assert number_memberof(topo, user.dn, 5)
     user.delete()
@@ -677,6 +741,13 @@ def test_matching_gid_role_inclusive_regular_expression(topo, _create_all_entrie
     user1 = add_user(topo, "User_{}".format(testid), AUTO_MEM_SCOPE_BASE, uid, gid, role)
     user2 = add_user(topo, "SecondUser_{}".format(testid), AUTO_MEM_SCOPE_BASE,
                      uid2, gid2, role)
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
+    time.sleep(delay)
     for user_dn in [user1.dn, user2.dn]:
         assert check_groups(topo, contract_grp, user_dn, "member")
     assert number_memberof(topo, user1.dn, 1)
@@ -716,9 +787,16 @@ def test_gid_and_role_inclusive_exclusive_regular_expression(topo, _create_all_e
         3. Should success
         4. Should success
     """
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     contract_grp = f'cn={c_grp},ou=userGroups,{BASE_SUFF}'
     default_group = f'cn={m_grp},ou=userGroups,{BASE_SUFF}'
     user = add_user(topo, "User_{}".format(testid), AUTO_MEM_SCOPE_BASE, uid, gid, role)
+    time.sleep(delay)
     with pytest.raises(AssertionError):
         assert check_groups(topo, contract_grp, user.dn, "member")
     check_groups(topo, default_group, user.dn, "member")
@@ -755,7 +833,14 @@ def test_managers_contractors_exclusive_regex_rules_member_uid(topo, _create_all
     """
     default_group1 = f'cn={c_grp},{SUBSUFFIX}'
     default_group2 = f'cn={m_grp},{SUBSUFFIX}'
+    instance = topo.ms["supplier1"]
+    memberof = MemberOfPlugin(instance)
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        delay = 3
+    else:
+        delay = 0
     user = add_user(topo, "User_{}".format(testid), AUTO_MEM_SCOPE_BASE, uid, gid, role)
+    time.sleep(delay)
     for group in [default_group1, default_group2]:
         assert check_groups(topo, group, user.dn, "memberuid")
     user.delete()

dirsrvtests/tests/suites/betxns/betxn_test.py

@@ -159,6 +159,10 @@ def test_betxn_memberof(topology_st):
     memberof = MemberOfPlugin(topology_st.standalone)
     memberof.enable()
     memberof.set_autoaddoc('referral')
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        singleTXN = False
+    else:
+        singleTXN = True
     topology_st.standalone.restart()
 
     groups = Groups(topology_st.standalone, DEFAULT_SUFFIX)
@@ -171,11 +175,17 @@ def test_betxn_memberof(topology_st):
         group2.remove('objectClass', 'nsMemberOf')
 
     # Add group2 to group1 - it should fail with objectclass violation
-    with pytest.raises(ldap.OBJECT_CLASS_VIOLATION):
+    if singleTXN:
+        with pytest.raises(ldap.OBJECT_CLASS_VIOLATION):
+            group1.add_member(group2.dn)
+
+        # verify entry cache reflects the current/correct state of group1
+        assert not group1.is_member(group2.dn)
+    else:
         group1.add_member(group2.dn)
 
-    # verify entry cache reflects the current/correct state of group1
-    assert not group1.is_member(group2.dn)
+        # verify entry cache reflects the current/correct state of group1
+        assert group1.is_member(group2.dn)
 
     # Done
     log.info('test_betxn_memberof: PASSED')
@@ -208,6 +218,10 @@ def test_betxn_modrdn_memberof_cache_corruption(topology_st):
     memberof.set_autoaddoc('nsContainer')  # Bad OC
     memberof.set('memberOfEntryScope', peoplebase)
     memberof.set('memberOfAllBackends', 'on')
+    if (memberof.get_memberofdeferredupdate() and memberof.get_memberofdeferredupdate().lower() == "on"):
+        singleTXN = False
+    else:
+        singleTXN = True
     topology_st.standalone.restart()
 
     groups = Groups(topology_st.standalone, DEFAULT_SUFFIX)
@@ -223,12 +237,16 @@ def test_betxn_modrdn_memberof_cache_corruption(topology_st):
 
     group.add_member(user.dn)
 
-    # Attempt modrdn that should fail, but the original entry should stay in the cache
-    with pytest.raises(ldap.OBJECT_CLASS_VIOLATION):
-        group.rename('cn=group_to_people', newsuperior=peoplebase)
+    if singleTXN:
+        # Attempt modrdn that should fail, but the original entry should stay in the cache
+        with pytest.raises(ldap.OBJECT_CLASS_VIOLATION):
+            group.rename('cn=group_to_people', newsuperior=peoplebase)
 
-    # Should fail, but not with NO_SUCH_OBJECT as the original entry should still be in the cache
-    with pytest.raises(ldap.OBJECT_CLASS_VIOLATION):
+        # Should fail, but not with NO_SUCH_OBJECT as the original entry should still be in the cache
+        with pytest.raises(ldap.OBJECT_CLASS_VIOLATION):
+            group.rename('cn=group_to_people', newsuperior=peoplebase)
+    else:
+        group.rename('cn=group_to_people', newsuperior=peoplebase)
         group.rename('cn=group_to_people', newsuperior=peoplebase)
 
     # Done