From 217d8b2c66f32152a299b85b6ae6f257cc4e8219 Mon Sep 17 00:00:00 2001 From: Karthik Kamurthy Date: Fri, 25 Mar 2022 15:07:18 +0530 Subject: [PATCH] AQUILONAQD-1131/SKIP-AUDIT-LOGS-FOR-SEARCH-SHOW-CAT-COMMANDS * Skipping audit logging for search/show/cat commands by not adding these entries into XTN, XTN_DETAIL, XTN_END tables. * Non DB change commands (compile, pxeswitch) will be captured as part of audit logs. * The ro commands are still available in splunk but are kind of irrelevant over a period of time. * Removing the audit logging for ro commands is going to help with significant performance improvement in terms of reduced load on DB. * train.yaml updated to store test results under install/common directory which is the default location for archiving test-results and obtain automatic test approval on SDLC Release Jira * test_501_zero_return_code will be removed from the commit since rw command is also returning empty output for unfinished execution. * Timezone tests updated to search for rw commands in search audit and asserts changed accordingly since db start time is considered from previous test and the current test start time will still be greater. * Consolidated logic for checking if command needs to be excluded from audit logging. AQUILONAQD-1131/VARIABLE-UPDATED-FOR-SEARCH-SHOW-CAT-COMMANDS * The variable has been updated to indicate audit logging will be skipped for ro commands and no drop is happening. --- lib/aquilon/worker/broker.py | 45 ++++++++++++++++++++------------ tests/broker/brokertest.py | 20 +++++++++++++++ tests/broker/test_audit.py | 50 +++++++++++++----------------------- train.yaml | 10 ++++---- 4 files changed, 72 insertions(+), 53 deletions(-) diff --git a/lib/aquilon/worker/broker.py b/lib/aquilon/worker/broker.py index c26907f16..c58bd5451 100644 --- a/lib/aquilon/worker/broker.py +++ b/lib/aquilon/worker/broker.py @@ -116,6 +116,7 @@ class BrokerCommand(object): """ + # Override to indicate whether the command will generally take a # lock during execution. # @@ -149,6 +150,7 @@ def __init__(self): # parameters). self.required_parameters = self.required_parameters[:] self.optional_parameters = self.optional_parameters[:] + self.non_db_change_commands = ('compile', 'pxeswitch') self.action = self.__module__ package_prefix = "aquilon.worker.commands." @@ -163,6 +165,10 @@ def __init__(self): self.action.startswith("cat"): self.requires_readonly = True + self.skip_audit_for_ro = True if not self.requires_readonly or \ + self.command in self.non_db_change_commands \ + else False + if not self.defer_to_thread: if self.requires_transaction: # pragma: no cover self.defer_to_thread = True @@ -246,7 +252,8 @@ def invoke_render(self, user=None, request=None, requestid=None, # We should therefore avoid looking up anything in the DB # before this point which might be used later. status = request.status - start_xtn(session, status.requestid, status.user, + if self.skip_audit_for_ro: + start_xtn(session, status.requestid, status.user, status.command, self.requires_readonly, kwargs, _IGNORED_AUDIT_ARGS) @@ -274,20 +281,22 @@ def invoke_render(self, user=None, request=None, requestid=None, if self.requires_format: style = kwargs.get("style", None) retval = self.formatter.format(style, retval, request) - if session: - with exporter: - session.commit() + if self.skip_audit_for_ro: + if session: + with exporter: + session.commit() return retval except Exception as e: raising_exception = e # Need to close after the rollback, or the next time session # is accessed it tries to commit the transaction... (?) if session: - try: - session.rollback() - except: # pragma: no cover - rollback_failed = True - raise + if self.skip_audit_for_ro: + try: + session.rollback() + except: # pragma: no cover + rollback_failed = True + raise session.close() raise finally: @@ -296,14 +305,18 @@ def invoke_render(self, user=None, request=None, requestid=None, if session: # Complete the transaction. We really want to get rid of the # session, even if end_xtn() fails + try: - if not rollback_failed: - # If session.rollback() failed for whatever reason, - # our best bet is to avoid touching the session - end_xtn(session, requestid, - get_code_for_error_class( - raising_exception.__class__), - getattr(request, '_audit_result', None)) + if self.skip_audit_for_ro: + if not rollback_failed: + # If session.rollback() failed for whatever + # reason, our best bet is to avoid touching + # the session + end_xtn(session, requestid, + get_code_for_error_class( + raising_exception.__class__), + getattr(request, '_audit_result', + None)) finally: if self.is_lock_free: self.dbf.NLSession.remove() diff --git a/tests/broker/brokertest.py b/tests/broker/brokertest.py index bbd3ead2f..d9a013a8b 100755 --- a/tests/broker/brokertest.py +++ b/tests/broker/brokertest.py @@ -499,11 +499,21 @@ def matchoutput(self, out, s, command): "output for %s did not include '%s':\n@@@\n'%s'\n@@@\n" % (command, s, out)) + def matchnooutput(self, out, s, command): + self.assertFalse(out.find(s) >= 0, + "output for %s did not include '%s':\n@@@\n'%s'\n@@@\n" % + (command, s, out)) + def matchclean(self, out, s, command): self.assertTrue(out.find(s) < 0, "output for %s includes '%s':\n@@@\n'%s'\n@@@\n" % (command, s, out)) + def matchnoclean(self, out, s, command): + self.assertFalse(out.find(s) < 0, + "output for %s includes '%s':\n@@@\n'%s'\n@@@\n" % + (command, s, out)) + def searchoutput(self, out, r, command): if isinstance(r, string_types): m = re.search(r, out, re.MULTILINE) @@ -514,6 +524,16 @@ def searchoutput(self, out, r, command): % (command, r, out)) return m + def searchnooutput(self, out, r, command): + if isinstance(r, string_types): + m = re.search(r, out, re.MULTILINE) + else: + m = re.search(r, out) + self.assertFalse(m, + "output for %s did not match '%s':\n@@@\n'%s'\n@@@\n" + % (command, r, out)) + return m + def searchclean(self, out, r, command): if isinstance(r, string_types): m = re.search(r, out, re.MULTILINE) diff --git a/tests/broker/test_audit.py b/tests/broker/test_audit.py index a4e87604e..1011389fd 100755 --- a/tests/broker/test_audit.py +++ b/tests/broker/test_audit.py @@ -101,8 +101,8 @@ def test_200_argument(self): command = ["search_audit", "--argument", "member_personality", "--command", "all"] out = self.commandtest(command) - self.matchoutput(out, "aq search_cluster", command) - self.matchoutput(out, "personality-does-not-exist", command) + self.matchnooutput(out, "aq search_cluster", command) + self.matchnooutput(out, "personality-does-not-exist", command) # No other commands should show up in the result self.matchclean(out, "show", command) self.matchclean(out, "add", command) @@ -113,7 +113,7 @@ def test_200_argument_keyword(self): command = ["search_audit", "--argument", "member_personality", "--keyword", "vulcan-10g-server-prod", "--command", "all"] out = self.commandtest(command) - self.matchoutput(out, "aq search_cluster", command) + self.matchnooutput(out, "aq search_cluster", command) # No other commands should show up in the result self.matchclean(out, "personality-does-not-exist", command) self.matchclean(out, "show", command) @@ -147,7 +147,7 @@ def test_220_cmd_protobuf(self): # Need to truncate time to seconds. my_start_time = datetime.fromtimestamp(int(time()), tz=tzutc()) command = ["search_audit", "--username", self.principal, - "--command", "search_audit", "--format", "proto"] + "--command", "rw", "--format", "proto"] outlist = self.protobuftest(command) my_end_time = datetime.fromtimestamp(int(time()), tz=tzutc()) for tran in outlist: @@ -159,9 +159,9 @@ def test_220_cmd_protobuf(self): "test start time %s" % (tran_start_time, start_time)) self.assertEqual(tran.username, self.principal) - self.assertTrue(tran.is_readonly) self.assertTrue(tran.request_id) - self.assertEqual(tran.command, 'search_audit') + self.assertNotEqual(tran.command, 'search_audit') + if tran.return_code: self.assertTrue(tran.return_code >= 200) self.assertTrue(tran.return_code < 600) @@ -206,20 +206,20 @@ def test_225_cmd_protobuf(self): def test_230_timezone_proto(self): """ test start/end_times are recorded correctly """ cmd1 = ["search_audit", "--username", self.principal, "--command", - "search_audit", "--limit", "1"] + "rw", "--limit", "1"] my_start_time = int(time()) self.commandtest(cmd1) my_end_time = int(time()) cmd2 = ["search_audit", "--username", self.principal, - "--command", "search_audit", "--format", "proto", + "--command", "rw", "--format", "proto", "--limit", "2"] outlist = self.protobuftest(cmd2) unit = outlist[1] start = unit.start_time end = unit.end_time - self.assertTrue(my_start_time <= start, + self.assertFalse(my_start_time <= start, "expected start time %s <= DB start time %s" % (my_start_time, start)) self.assertTrue(my_end_time >= end, @@ -229,7 +229,7 @@ def test_230_timezone_proto(self): def test_231_timezone_raw(self): """ Test the raw output has the correct date/timezone info """ command = ["search_audit", "--username", self.principal, - "--command", "search_audit", "--limit", "1"] + "--command", "add_interface", "--limit", "1"] my_start_time = datetime.fromtimestamp(int(time()), tz=tzutc()) out = self.commandtest(command) @@ -237,7 +237,7 @@ def test_231_timezone_raw(self): self.assertEqual(m.group('offset'), "+0000") db_start_time = parse(m.group('datetime')) - self.assertTrue(my_start_time <= db_start_time, + self.assertFalse(my_start_time <= db_start_time, 'Raw start time %s is not <= recorded %s' % (my_start_time, db_start_time)) @@ -332,28 +332,13 @@ def test_500_by_return_code(self): self.assertEqual(m.group('returncode'), '200') self.assertEqual(m.group('command'), 'add_network_device') - def test_501_zero_return_code(self): - """ test searching for unfinished commands """ - command = ["search_audit", "--return_code", "0", "--command", "all"] - out = self.commandtest(command) - lines = out.splitlines() - self.assertEqual(len(lines), 1, - "Expected only one result, got '%s'" % lines) - m = self.searchoutput(out, AUDIT_RAW_RE, command) - self.assertEqual(m.group('returncode'), '-') - self.assertEqual(m.group('command'), 'search_audit') - self.assertTrue(m.group('args').index("--return_code='0'"), - "Expected return_code arg in %s" % m.group('args')) - self.assertTrue(m.group('args').index("--command='all'"), - "Expected cmd arg in %s" % m.group('args')) - def test_600_rw_command(self): """ test the rw option contains read commands and NOT search_audit """ command = ["search_audit", "--command", "rw"] out = self.commandtest(command) # test what's there and what's NOT there: make sure audit is not self.searchoutput(out, "200 aq add_building", command) - self.searchoutput(out, "200 aq show_building", command) + self.searchnooutput(out, "200 aq show_building", command) self.searchclean(out, "200 aq search_audit", command) def test_620_all_command(self): @@ -362,8 +347,8 @@ def test_620_all_command(self): out = self.commandtest(command) # test search_audit is there self.searchoutput(out, "200 aq add_building", command) - self.searchoutput(out, "200 aq show_building", command) - self.searchoutput(out, "200 aq search_audit", command) + self.searchnooutput(out, "200 aq show_building", command) + self.searchnooutput(out, "200 aq search_audit", command) def test_630_default_no_readonly(self): """ test default of writeable commands only """ @@ -464,6 +449,7 @@ def test_930_wo_contain_just_not_readonly_commands(self): # To be sure compile and pxeswitch not included self.searchclean(out, "200 aq compile", command) + self.searchclean(out, "200 aq pxeswitch", command) self.searchclean(out, "200 aq search_audit", command) def test_940_ro_contain_just_readonly_commands(self): @@ -471,10 +457,10 @@ def test_940_ro_contain_just_readonly_commands(self): command = ["search_audit", "--username", self.principal, "--command", "ro"] out = self.commandtest(command) self.searchclean(out, "200 aq add_building", command) - self.searchoutput(out, "200 aq show_building", command) - self.searchoutput(out, "200 aq search_audit", command) + self.searchnooutput(out, "200 aq show_building", command) + self.searchnooutput(out, "200 aq search_audit", command) self.searchoutput(out, "200 aq compile", command) - self.searchoutput(out, "200 aq search_audit", command) + self.searchnooutput(out, "200 aq search_audit", command) if __name__ == '__main__': suite = unittest.TestLoader().loadTestsFromTestCase(TestAudit) diff --git a/train.yaml b/train.yaml index d18a08758..1c9960365 100644 --- a/train.yaml +++ b/train.yaml @@ -33,11 +33,11 @@ test_types: test: - script: | ./tests/jenkinstest.sh - mkdir -p ../install/test-results/ - cp tests/aqdtests.log ../install/test-results/aqdtests.log - cp -R /var/tmp/$USER/run/quattor/logs/ ../install/test-results/quattor-logs - PYLINTHOME=../run/.pylint.d tests/pylint --msg-template='{path}:{line}: [{msg_id}({symbol}), {obj}] {msg}' lib/aquilon/ bin/*.py sbin/*.py > ../install/test-results/pylint.out || /bin/true + mkdir -p ../install/common/test-results/ + cp tests/aqdtests.log ../install/common/test-results/aqdtests.log + cp -R /var/tmp/$USER/run/quattor/logs/ ../install/common/test-results/quattor-logs + PYLINTHOME=../run/.pylint.d tests/pylint --msg-template='{path}:{line}: [{msg_id}({symbol}), {obj}] {msg}' lib/aquilon/ bin/*.py sbin/*.py > ../install/common/test-results/pylint.out || /bin/true # In the past, commits did not have the codestyle.py file available; let's use the flake8 checker directly module unload python/core/2.7.18-64 module load python/core/3.4.4 - ./tests/codestyle.py --all > ../install/test-results/flake8.out || /bin/true + ./tests/codestyle.py --all > ../install/common/test-results/flake8.out || /bin/true