PR#50027: Ticket 50026 - audit logs does not capture the operation where nsslapd-lookthroughlimit is modified - 389-ds-base

389-ds-base

#50027 Ticket 50026 - audit logs does not capture the operation where nsslapd-lookthroughlimit is modified

Closed 3 years ago by spichugi. Opened 5 years ago by tbordaz.

tbordaz/389-ds-base ticket_50026 into master

Ticket 50026 - audit logs does not capture the operation where nsslapd-lookthroughlimit is modified

Thierry Bordaz • 5 years ago

a1578a9

dirsrvtests/tests/suites/basic/basic_test.py

file modified

+51

		`@@ -1088,6 +1088,57 @@`
		`# Step 5`
		`assert not topology_st.standalone.searchErrorsLog('CRIT - list_candidates - NULL idl was recieved from filter_candidates_ext.')`

		`+ def audit_pattern_found(server, log_pattern):`
		`+ file_obj = open(server.ds_paths.audit_log, "r")`
		`+`
		`+ found = None`
		`+ # Use a while true iteration because 'for line in file: hit a`
		`+ log.info('Audit log contains')`
		`+ while True:`
		`+ line = file_obj.readline()`
		`+ log.info(line)`
		`+ found = log_pattern.search(line)`
		`+ if ((line == '') or (found)):`
		`+ break`
		`+`
		`+ return found`
		`+`
		`+ @pytest.mark.ds50026`
		`+ def test_ticketldbm_audit(topology_st):`
		`+ """When updating LDBM config attributes, those attributes/values are not listed`
		`+ in the audit log`
		`+`
		`+ :id: 5bf75c47-a283-430e-a65c-3c5fd8dbadb8`
		`+ :setup: Standalone Instance`
		`+ :steps:`
		`+ 1. Enable audit log`
		`+ 2. Update a set of config attrs in LDBM config`
		`+ 3. Disable audit log (to restore the default config)`
		`+ 4. Check that config attrs are listed in the audit log`
		`+ :expectedresults:`
		`+ 1. Should succeeds`
		`+ 2. Should succeeds`
		`+ 3. Should succeeds`
		`+ 4. Should succeeds`
		`+ """`
		`+ inst = topology_st[0]`
		`+`
		`+ inst.config.enable_log('audit')`
		`+`
		`+ #inst.ds_paths.audit_log`
		`+ attrs = ['nsslapd-lookthroughlimit', 'nsslapd-pagedidlistscanlimit', 'nsslapd-idlistscanlimit', 'nsslapd-db-locks']`
		`+ mods = []`
		`+ for attr in attrs:`
		`+ mods.append((ldap.MOD_REPLACE, attr, b'10001'))`
		`+ inst.modify_s(DN_CONFIG_LDBM, mods)`
		`+ inst.config.enable_log('audit')`
		`+`
		`+ for attr in attrs:`
		`+ log.info("Check %s is replaced in the audit log" % attr)`
		`+ regex = re.compile("^replace: %s" % attr)`
		`+ assert audit_pattern_found(inst, regex)`
		`+`
		`+`
		`if __name__ == '__main__':`
		`# Run isolated`
		`# -s for DEBUG mode`

ldap/servers/slapd/dse.c

file modified

		`@@ -1697,6 +1697,7 @@`
		`{`
		`int err; /House keeping stuff/`
		`LDAPMod *mods; /Used to apply the modifications*/`
		`+ LDAPMod *original_mods = NULL; / some mods can be removed by callback, save them for later logging */`
		`char errbuf = NULL; / To get error back */`
		`struct dse *pdse;`
		`Slapi_Entry *ec = NULL;`
		`@@ -1763,6 +1764,7 @@`
		`global_backend_lock_lock();`
		`global_lock_owned = PR_TRUE;`
		`}`
		`+ original_mods = copy_mods(mods);`

		`/* XXXmcs: should we expand objectclass values here?? */`
		`/* give the dse callbacks the first crack at the modify */`
		`@@ -1960,6 +1962,13 @@`
		`}`
		`}`
		`}`
		`+ /* time to restore original mods */`
		`+ if (original_mods) {`
		`+ LDAPMod **mods_from_callback;`
		`+ slapi_pblock_get(pb, SLAPI_MODIFY_MODS, &mods_from_callback);`
		`+ ldap_mods_free(mods_from_callback, 1 /* Free the Array and the Elements */);`
		`+ slapi_pblock_set(pb, SLAPI_MODIFY_MODS, original_mods);`
		`+ }`
		`if (global_lock_owned) {`
		`global_backend_lock_unlock();`
		`}`

tbordaz commented 5 years ago

Bug Description:
During a dse update (config, schema,..) the dse callback will process the mods
but can also modify them (SLAPI_MODIFY_MODS) leaving only ignored attributes.
A consequence is that later audit logging will only log the ignored attributes.

Fix Description:
Save a copy of the orignal mods before the dse callback and restore them
when dse callback completes.

https://pagure.io/389-ds-base/issue/50026

Reviewed by: ?

Platforms tested: F27

Flag Day: no

Doc impact: no

lkrispen commented 5 years ago

this will ensure we log the mods we receive in the audit log, but I have two remarks:

1) if mods can be removed and ignored we do not see this in the audit log, do we somewhere specify if it should log the received or the applied mods?

2) what about mods on "real" backends, we have the case where otp plugin can remove mods, are they seen in the audit log, if not should they be ? We should be consistent.

tbordaz commented 5 years ago

@lkrispen thanks for the review and sorry for my late answer. To be honest I found difficult to understand the logic of that part of code :(

1) audit logging records all the changes that are present in the mods after the postop. At this point it did not know which of them were received or not and even if they were applied or not. It just drop mod that have invalid MOD type.

For DSE update, the fix logs the received mods. It logs all the mods the dse backend (ldbm config) applied but if an other mod (not processed by dse backend) is later removed in the preop, it will log it.

Reading the code, I found it complex and error prone. For example I think that if a MOD fails after the dse_callback, the updates processed in dse_callback are not undone. So the ldbm config entry may not reflect what is configured in the database.

2) OTP plugin can removes mods (prevent counters going backward) before applying on the backend.
DSE preop removes mods that it actually applies on the backend (ldbm config) and ignores (i.e. leave) mods that it does not know how to handle (modifiersname, modifytimestamp...).
So mods logged by DSE were not consistent with the other backends as it did not log the mods it applied.

lkrispen commented 5 years ago

thanks for the explanation.

ack

rebased onto a1578a9

5 years ago

Pull-Request has been merged by tbordaz

5 years ago