Add a per-test log
This patch adds a new per-test logging feature to Patrole
To accomplish this, it adds two new config variables
The logging now prints a log message containing the results of each RBAC
test to a separate log file, as well as to the normal
tempest.log file. This message is of the form:
[Service] <nova, neutron, etc>
[Test] <name of the test's method>
followed by either the result of the test as Allowed/Denied/Error, or
the expected result (from oslopolicy) and then the actual result
There are two new config variables that control this, added in a new
config group called patrole_log:
enable_reporting - defaults to True, which enables this new logging
functionality
report_log_name - defaults to patrole.log, controls the name of the log
the output is written to.
report_log_path - Defaults to the local directory, path (relative or
absolute) where to store the log
Change-Id: Iff2176f1a7c7d10f78b96d748f1d70b222fd5072
diff --git a/patrole_tempest_plugin/tests/unit/fixtures.py b/patrole_tempest_plugin/tests/unit/fixtures.py
index 9d53eb9..ce13029 100644
--- a/patrole_tempest_plugin/tests/unit/fixtures.py
+++ b/patrole_tempest_plugin/tests/unit/fixtures.py
@@ -73,7 +73,7 @@
'os_primary.credentials.project_id': self.PROJECT_ID,
'get_identity_version.return_value': 'v3'
}
- self.mock_test_obj = mock.Mock(**test_obj_kwargs)
+ self.mock_test_obj = mock.Mock(__name__='foo', **test_obj_kwargs)
# Mock out functionality that can't be used by unit tests.
self.mock_time = mock.patch.object(rbac_utils, 'time').start()
diff --git a/patrole_tempest_plugin/tests/unit/test_rbac_policy_parser.py b/patrole_tempest_plugin/tests/unit/test_rbac_policy_parser.py
index 6f173a2..5fa26df 100644
--- a/patrole_tempest_plugin/tests/unit/test_rbac_policy_parser.py
+++ b/patrole_tempest_plugin/tests/unit/test_rbac_policy_parser.py
@@ -81,7 +81,7 @@
group='identity-feature-enabled')
def _get_fake_policy_rule(self, name, rule):
- fake_rule = mock.Mock(check=rule)
+ fake_rule = mock.Mock(check=rule, __name__='foo')
fake_rule.name = name
return fake_rule
@@ -291,6 +291,7 @@
parser = rbac_policy_parser.RbacPolicyParser(
test_tenant_id, test_user_id, "custom_rbac_policy")
parser.rules = mock.MagicMock(
+ __name__='foo',
**{'__getitem__.return_value.side_effect': Exception(
mock.sentinel.error)})
@@ -314,7 +315,7 @@
'rule:code_rule_3'),
]
- mock_manager = mock.Mock(obj=fake_policy_rules)
+ mock_manager = mock.Mock(obj=fake_policy_rules, __name__='foo')
mock_manager.configure_mock(name='fake_service')
mock_stevedore.named.NamedExtensionManager.return_value = [
mock_manager
@@ -355,7 +356,7 @@
'rule:code_rule_3'),
]
- mock_manager = mock.Mock(obj=fake_policy_rules)
+ mock_manager = mock.Mock(obj=fake_policy_rules, __name__='foo')
mock_manager.configure_mock(name='fake_service')
mock_stevedore.named.NamedExtensionManager.return_value = [
mock_manager
@@ -401,10 +402,10 @@
@mock.patch.object(rbac_policy_parser, 'stevedore', autospec=True)
def test_get_policy_data_without_valid_policy(self, mock_stevedore,
mock_json):
- test_policy_action = mock.Mock(check='rule:bar')
+ test_policy_action = mock.Mock(check='rule:bar', __name__='foo')
test_policy_action.configure_mock(name='foo')
- test_policy = mock.Mock(obj=[test_policy_action])
+ test_policy = mock.Mock(obj=[test_policy_action], __name__='foo')
test_policy.configure_mock(name='test_service')
mock_stevedore.named.NamedExtensionManager\
diff --git a/patrole_tempest_plugin/tests/unit/test_rbac_rule_validation.py b/patrole_tempest_plugin/tests/unit/test_rbac_rule_validation.py
index 8a69ff6..0dcaaa7 100644
--- a/patrole_tempest_plugin/tests/unit/test_rbac_rule_validation.py
+++ b/patrole_tempest_plugin/tests/unit/test_rbac_rule_validation.py
@@ -40,6 +40,9 @@
CONF.set_override('rbac_test_role', 'Member', group='patrole')
self.addCleanup(CONF.clear_override, 'rbac_test_role', group='patrole')
+ self.mock_rbaclog = mock.patch.object(
+ rbac_rv.RBACLOG, 'info', autospec=False).start()
+
@mock.patch.object(rbac_rv, 'LOG', autospec=True)
@mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
def test_rule_validation_have_permission_no_exc(self, mock_policy,
@@ -50,7 +53,7 @@
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
wrapper = decorator(mock_function)
mock_policy.RbacPolicyParser.return_value.allowed.return_value = True
@@ -71,7 +74,7 @@
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = exceptions.Forbidden
wrapper = decorator(mock_function)
@@ -93,7 +96,7 @@
raised.
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = exceptions.Forbidden
wrapper = decorator(mock_function)
@@ -108,16 +111,15 @@
@mock.patch.object(rbac_rv, 'LOG', autospec=True)
@mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
- def test_rule_validation_rbac_malformed_response_positive(self,
- mock_policy,
- mock_log):
+ def test_rule_validation_rbac_malformed_response_positive(
+ self, mock_policy, mock_log):
"""Test RbacMalformedResponse error is thrown without permission passes.
Positive test case: if RbacMalformedResponse is thrown and the user is
not allowed to perform the action, then this is a success.
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = rbac_exceptions.RbacMalformedResponse
wrapper = decorator(mock_function)
@@ -131,16 +133,15 @@
@mock.patch.object(rbac_rv, 'LOG', autospec=True)
@mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
- def test_rule_validation_rbac_malformed_response_negative(self,
- mock_policy,
- mock_log):
+ def test_rule_validation_rbac_malformed_response_negative(
+ self, mock_policy, mock_log):
"""Test RbacMalformedResponse error is thrown with permission fails.
Negative test case: if RbacMalformedResponse is thrown and the user is
allowed to perform the action, then this is an expected failure.
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = rbac_exceptions.RbacMalformedResponse
wrapper = decorator(mock_function)
@@ -156,16 +157,15 @@
@mock.patch.object(rbac_rv, 'LOG', autospec=True)
@mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
- def test_rule_validation_rbac_conflicting_policies_positive(self,
- mock_policy,
- mock_log):
+ def test_rule_validation_rbac_conflicting_policies_positive(
+ self, mock_policy, mock_log):
"""Test RbacConflictingPolicies error is thrown without permission passes.
Positive test case: if RbacConflictingPolicies is thrown and the user
is not allowed to perform the action, then this is a success.
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = rbac_exceptions.RbacConflictingPolicies
wrapper = decorator(mock_function)
@@ -179,16 +179,15 @@
@mock.patch.object(rbac_rv, 'LOG', autospec=True)
@mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
- def test_rule_validation_rbac_conflicting_policies_negative(self,
- mock_policy,
- mock_log):
+ def test_rule_validation_rbac_conflicting_policies_negative(
+ self, mock_policy, mock_log):
"""Test RbacConflictingPolicies error is thrown with permission fails.
Negative test case: if RbacConflictingPolicies is thrown and the user
is allowed to perform the action, then this is an expected failure.
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = rbac_exceptions.RbacConflictingPolicies
wrapper = decorator(mock_function)
@@ -217,13 +216,12 @@
decorator = rbac_rv.action(mock.sentinel.service,
mock.sentinel.action,
expected_error_code=404)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = exceptions.Forbidden('Random message.')
wrapper = decorator(mock_function)
- expected_error = "Forbidden\nDetails: Random message. An unexpected "\
- "exception has occurred: Expected exception was "\
- "NotFound, which was not thrown."
+ expected_error = "An unexpected exception has occurred during test: "\
+ "foo, Exception was: Forbidden\nDetails: Random message."
for permission in [True, False]:
mock_policy.RbacPolicyParser.return_value.allowed.return_value =\
@@ -237,7 +235,8 @@
@mock.patch.object(rbac_rv, 'LOG', autospec=True)
@mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
- def test_expect_not_found_and_raise_not_found(self, mock_policy, mock_log):
+ def test_expect_not_found_and_raise_not_found(self, mock_policy,
+ mock_log):
"""Test that expecting 404 and getting 404 works for all scenarios.
Tests the following scenarios:
@@ -250,7 +249,7 @@
decorator = rbac_rv.action(mock.sentinel.service,
mock.sentinel.action,
expected_error_code=404)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
mock_function.side_effect = exceptions.NotFound
wrapper = decorator(mock_function)
@@ -293,7 +292,7 @@
"""
decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
- mock_function = mock.Mock()
+ mock_function = mock.Mock(__name__='foo')
wrapper = decorator(mock_function)
mock_policy.RbacPolicyParser.return_value.allowed.return_value = False
@@ -301,7 +300,7 @@
e = self.assertRaises(rbac_exceptions.RbacOverPermission, wrapper,
self.mock_args)
self.assertIn(("OverPermission: Role Member was allowed to perform "
- "sentinel.action"), e.__str__())
+ "sentinel.action"), e.__str__())
mock_log.error.assert_called_once_with(
'Role %s was allowed to perform %s', 'Member',
mock.sentinel.action)
@@ -319,7 +318,7 @@
decorator = rbac_rv.action(mock.sentinel.service,
mock.sentinel.policy_rule)
- wrapper = decorator(mock.Mock())
+ wrapper = decorator(mock.Mock(__name__='foo'))
e = self.assertRaises(rbac_exceptions.RbacParsingException, wrapper,
self.mock_args)
@@ -382,3 +381,51 @@
"codes: [403, 404]")
mock_log.error.reset_mock()
+
+ @mock.patch.object(rbac_rv, 'RBACLOG', autospec=True)
+ @mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
+ def test_rbac_report_logging_disabled(self, mock_policy, mock_rbaclog):
+ """Test case to ensure that we DON'T write logs when
+ enable_reporting is False
+ """
+ CONF.set_override('enable_reporting', False, group='patrole_log')
+ self.addCleanup(CONF.clear_override,
+ 'enable_reporting', group='patrole_log')
+
+ decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
+
+ mock_function = mock.Mock(__name__='foo-nolog')
+ wrapper = decorator(mock_function)
+
+ mock_policy.RbacPolicyParser.return_value.allowed.return_value = True
+
+ wrapper(self.mock_args)
+
+ self.assertFalse(mock_rbaclog.info.called)
+
+ @mock.patch.object(rbac_rv, 'RBACLOG', autospec=True)
+ @mock.patch.object(rbac_rv, 'rbac_policy_parser', autospec=True)
+ def test_rbac_report_logging_enabled(self, mock_policy, mock_rbaclog):
+ """Test case to ensure that we DO write logs when
+ enable_reporting is True
+ """
+ CONF.set_override('enable_reporting', True, group='patrole_log')
+ self.addCleanup(CONF.clear_override,
+ 'enable_reporting', group='patrole_log')
+
+ decorator = rbac_rv.action(mock.sentinel.service, mock.sentinel.action)
+
+ mock_function = mock.Mock(__name__='foo-log')
+ wrapper = decorator(mock_function)
+
+ mock_policy.RbacPolicyParser.return_value.allowed.return_value = True
+
+ wrapper(self.mock_args)
+
+ mock_rbaclog.info.assert_called_once_with(
+ "[Service]: %s, [Test]: %s, [Rule]: %s, "
+ "[Expected]: %s, [Actual]: %s",
+ mock.sentinel.service, 'foo-log',
+ mock.sentinel.action,
+ "Allowed",
+ "Allowed")