Merge "Test coverage for compute flavor_manage policies"
diff --git a/HACKING.rst b/HACKING.rst
index 3bc8270..a94b47c 100644
--- a/HACKING.rst
+++ b/HACKING.rst
@@ -46,7 +46,7 @@
 test does not call ``rbac_utils.switch_role`` with ``toggle_rbac_role=True``
 within the RBAC test, then the test is *not* a valid RBAC test: The API
 endpoint under test will be performed with admin credentials, which is always
-wrong unless ``CONF.rbac_test_role`` is admin.
+wrong unless ``CONF.patrole.rbac_test_role`` is admin.
 
 .. note::
 
diff --git a/patrole_tempest_plugin/config.py b/patrole_tempest_plugin/config.py
index a53edd4..fcf29af 100644
--- a/patrole_tempest_plugin/config.py
+++ b/patrole_tempest_plugin/config.py
@@ -147,3 +147,23 @@
                           help="This group is deprecated and will be removed "
                                "in the next release. Use the [patrole] group "
                                "instead.")
+
+patrole_log_group = cfg.OptGroup(
+    name='patrole_log', title='Patrole Logging Options')
+
+PatroleLogGroup = [
+    cfg.BoolOpt('enable_reporting',
+                default=False,
+                help="Enables reporting on RBAC expected and actual test "
+                     "results for each Patrole test"),
+    cfg.StrOpt('report_log_name',
+               default='patrole.log',
+               help="Name of file where output from 'enable_reporting' is "
+                    "logged. Note that this file is recreated on each "
+                    "invocation of patrole"),
+    cfg.StrOpt('report_log_path',
+               default='.',
+               help="Path (relative or absolute) where the output from "
+                    "'enable_reporting' is logged. This is combined with"
+                    "report_log_name to generate the full path."),
+]
diff --git a/patrole_tempest_plugin/plugin.py b/patrole_tempest_plugin/plugin.py
index 4bba037..b7717ea 100644
--- a/patrole_tempest_plugin/plugin.py
+++ b/patrole_tempest_plugin/plugin.py
@@ -13,15 +13,21 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
 import os
 
+from oslo_concurrency import lockutils
+
 from tempest import config
 from tempest.test_discover import plugins
 
 from patrole_tempest_plugin import config as project_config
 
+RBACLOG = logging.getLogger('rbac_reporting')
+
 
 class PatroleTempestPlugin(plugins.TempestPlugin):
+
     def load_tests(self):
         base_path = os.path.split(os.path.dirname(
             os.path.abspath(__file__)))[0]
@@ -29,6 +35,32 @@
         full_test_dir = os.path.join(base_path, test_dir)
         return full_test_dir, base_path
 
+    @lockutils.synchronized('_reset_log_file')
+    def _reset_log_file(self, logfile):
+        try:
+            os.remove(logfile)
+        except OSError:
+            pass
+
+    def _configure_per_test_logging(self, conf):
+        # Separate log handler for rbac reporting
+        RBACLOG.setLevel(level=logging.INFO)
+        # Set up proper directory handling
+        report_abs_path = os.path.abspath(conf.patrole_log.report_log_path)
+        report_path = os.path.join(
+            report_abs_path, conf.patrole_log.report_log_name)
+
+        # Remove the log file if it exists
+        self._reset_log_file(report_path)
+
+        # Delay=True so that we don't end up creating an empty file if we
+        # never log to it.
+        rbac_report_handler = logging.FileHandler(
+            filename=report_path, delay=True, mode='a')
+        rbac_report_handler.setFormatter(
+            fmt=logging.Formatter(fmt='%(message)s'))
+        RBACLOG.addHandler(rbac_report_handler)
+
     def register_opts(self, conf):
         # TODO(fmontei): Remove ``rbac_group`` in a future release as it is
         # currently deprecated.
@@ -40,6 +72,13 @@
             conf,
             project_config.patrole_group,
             project_config.PatroleGroup)
+        config.register_opt_group(
+            conf,
+            project_config.patrole_log_group,
+            project_config.PatroleLogGroup)
+
+        if conf.patrole_log.enable_reporting:
+            self._configure_per_test_logging(conf)
 
     def get_opt_lists(self):
         return [(project_config.patrole_group.name,
diff --git a/patrole_tempest_plugin/rbac_rule_validation.py b/patrole_tempest_plugin/rbac_rule_validation.py
index d06986a..69a98e3 100644
--- a/patrole_tempest_plugin/rbac_rule_validation.py
+++ b/patrole_tempest_plugin/rbac_rule_validation.py
@@ -33,6 +33,8 @@
 
 _SUPPORTED_ERROR_CODES = [403, 404]
 
+RBACLOG = logging.getLogger('rbac_reporting')
+
 
 def action(service, rule='', admin_only=False, expected_error_code=403,
            extra_target_data=None):
@@ -118,7 +120,7 @@
     if extra_target_data is None:
         extra_target_data = {}
 
-    def decorator(func):
+    def decorator(test_func):
         role = CONF.patrole.rbac_test_role
 
         def wrapper(*args, **kwargs):
@@ -129,28 +131,26 @@
                     '`rbac_rule_validation` decorator can only be applied to '
                     'an instance of `tempest.test.BaseTestCase`.')
 
-            if admin_only:
-                LOG.info("As admin_only is True, only admin role should be "
-                         "allowed to perform the API. Skipping oslo.policy "
-                         "check for policy action {0}.".format(rule))
-                allowed = rbac_utils.is_admin()
-            else:
-                allowed = _is_authorized(test_obj, service, rule,
-                                         extra_target_data)
+            allowed = _is_authorized(test_obj, service, rule,
+                                     extra_target_data, admin_only)
 
             expected_exception, irregular_msg = _get_exception_type(
                 expected_error_code)
 
+            test_status = 'Allowed'
+
             try:
-                func(*args, **kwargs)
+                test_func(*args, **kwargs)
             except rbac_exceptions.RbacInvalidService as e:
                 msg = ("%s is not a valid service." % service)
+                test_status = ('Error, %s' % (msg))
                 LOG.error(msg)
                 raise exceptions.NotFound(
                     "%s RbacInvalidService was: %s" % (msg, e))
             except (expected_exception,
                     rbac_exceptions.RbacConflictingPolicies,
                     rbac_exceptions.RbacMalformedResponse) as e:
+                test_status = 'Denied'
                 if irregular_msg:
                     LOG.warning(irregular_msg.format(rule, service))
                 if allowed:
@@ -162,9 +162,10 @@
             except Exception as e:
                 exc_info = sys.exc_info()
                 error_details = exc_info[1].__str__()
-                msg = ("%s An unexpected exception has occurred: Expected "
-                       "exception was %s, which was not thrown."
-                       % (error_details, expected_exception.__name__))
+                msg = ("An unexpected exception has occurred during test: %s, "
+                       "Exception was: %s"
+                       % (test_func.__name__, error_details))
+                test_status = ('Error, %s' % (error_details))
                 LOG.error(msg)
                 six.reraise(exc_info[0], exc_info[0](msg), exc_info[2])
             else:
@@ -177,13 +178,20 @@
             finally:
                 test_obj.rbac_utils.switch_role(test_obj,
                                                 toggle_rbac_role=False)
+                if CONF.patrole_log.enable_reporting:
+                    RBACLOG.info(
+                        "[Service]: %s, [Test]: %s, [Rule]: %s, "
+                        "[Expected]: %s, [Actual]: %s",
+                        service, test_func.__name__, rule,
+                        "Allowed" if allowed else "Denied",
+                        test_status)
 
         _wrapper = testtools.testcase.attr(role)(wrapper)
         return _wrapper
     return decorator
 
 
-def _is_authorized(test_obj, service, rule, extra_target_data):
+def _is_authorized(test_obj, service, rule, extra_target_data, admin_only):
     """Validates whether current RBAC role has permission to do policy action.
 
     :param test_obj: An instance or subclass of `tempest.base.BaseTestCase`.
@@ -195,8 +203,15 @@
         `tempest.base.BaseTestCase` attributes. Used by `oslo.policy` for
         performing matching against attributes that are sent along with the API
         calls.
+    :param admin_only: Skips over `oslo.policy` check because the policy action
+        defined by `rule` is not enforced by the service's policy
+        enforcement engine. For example, Keystone v2 performs an admin check
+        for most of its endpoints. If True, `rule` is effectively
+        ignored.
+
     :returns: True if the current RBAC role can perform the policy action,
         else False.
+
     :raises RbacResourceSetupFailed: If `project_id` or `user_id` are missing
         from the `auth_provider` attribute in `test_obj`.
     :raises RbacParsingException: if ``[patrole] strict_policy_check`` is True
@@ -204,6 +219,13 @@
     :raises skipException: If ``[patrole] strict_policy_check`` is False and
         the ``rule`` does not exist in the system.
     """
+
+    if admin_only:
+        LOG.info("As admin_only is True, only admin role should be "
+                 "allowed to perform the API. Skipping oslo.policy "
+                 "check for policy action {0}.".format(rule))
+        return rbac_utils.is_admin()
+
     try:
         project_id = test_obj.os_primary.credentials.project_id
         user_id = test_obj.os_primary.credentials.user_id
@@ -260,7 +282,7 @@
     irregular_msg = None
 
     if not isinstance(expected_error_code, six.integer_types) \
-        or expected_error_code not in _SUPPORTED_ERROR_CODES:
+            or expected_error_code not in _SUPPORTED_ERROR_CODES:
         msg = ("Please pass an expected error code. Currently "
                "supported codes: {0}".format(_SUPPORTED_ERROR_CODES))
         LOG.error(msg)
diff --git a/patrole_tempest_plugin/tests/api/compute/test_security_groups_rbac.py b/patrole_tempest_plugin/tests/api/compute/test_security_groups_rbac.py
index 17a6c74..a28ddb9 100644
--- a/patrole_tempest_plugin/tests/api/compute/test_security_groups_rbac.py
+++ b/patrole_tempest_plugin/tests/api/compute/test_security_groups_rbac.py
@@ -14,19 +14,106 @@
 #    under the License.
 
 from tempest.lib.common.utils import data_utils
+from tempest.lib.common.utils import test_utils
 from tempest.lib import decorators
 
 from patrole_tempest_plugin import rbac_rule_validation
 from patrole_tempest_plugin.tests.api.compute import rbac_base
 
 
-class SecurityGroupsRbacTest(rbac_base.BaseV2ComputeRbacTest):
+class SecurtiyGroupsRbacTest(rbac_base.BaseV2ComputeRbacTest):
+    """Tests non-deprecated security group policies. Requires network service.
+
+    This class tests non-deprecated policies for adding and removing a security
+    group to and from a server.
+    """
+
+    @classmethod
+    def skip_checks(cls):
+        super(SecurtiyGroupsRbacTest, cls).skip_checks()
+        # All the tests below require the network service.
+        # NOTE(gmann) Currently 'network' service is always True in
+        # test.get_service_list() So below check is not much of use.
+        # Commenting the below check as Tempest is moving the get_service_list
+        # from test.py to utils.
+        # If we want to check 'network' service availability, then
+        # get_service_list can be used from new location.
+        # if not test.get_service_list()['network']:
+        #    raise cls.skipException(
+        #        'Skipped because the network service is not available')
+
+    @classmethod
+    def setup_credentials(cls):
+        # A network and a subnet will be created for these tests.
+        cls.set_network_resources(network=True, subnet=True)
+        super(SecurtiyGroupsRbacTest, cls).setup_credentials()
+
+    @classmethod
+    def resource_setup(cls):
+        super(SecurtiyGroupsRbacTest, cls).resource_setup()
+        cls.server = cls.create_test_server(wait_until='ACTIVE')
+
+    @rbac_rule_validation.action(
+        service="nova",
+        rule="os_compute_api:os-security-groups")
+    @decorators.idempotent_id('3db159c6-a467-469f-9a25-574197885520')
+    def test_list_security_groups_by_server(self):
+        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
+        self.servers_client.list_security_groups_by_server(self.server['id'])
+
+    @decorators.attr(type=["slow"])
+    @rbac_rule_validation.action(
+        service="nova",
+        rule="os_compute_api:os-security-groups")
+    @decorators.idempotent_id('ea1ca73f-2d1d-43cb-9a46-900d7927b357')
+    def test_create_security_group_for_server(self):
+        sg_name = self.create_security_group()['name']
+
+        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
+        self.servers_client.add_security_group(self.server['id'], name=sg_name)
+        self.addCleanup(test_utils.call_and_ignore_notfound_exc,
+                        self.servers_client.remove_security_group,
+                        self.server['id'], name=sg_name)
+
+    @decorators.attr(type=["slow"])
+    @rbac_rule_validation.action(
+        service="nova",
+        rule="os_compute_api:os-security-groups")
+    @decorators.idempotent_id('0ad2e856-e2d3-4ac5-a620-f93d0d3d2626')
+    def test_remove_security_group_from_server(self):
+        sg_name = self.create_security_group()['name']
+
+        self.servers_client.add_security_group(self.server['id'], name=sg_name)
+        self.addCleanup(test_utils.call_and_ignore_notfound_exc,
+                        self.servers_client.remove_security_group,
+                        self.server['id'], name=sg_name)
+
+        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
+        self.servers_client.remove_security_group(
+            self.server['id'], name=sg_name)
+
+
+class SecurityGroupsRbacMaxV235Test(rbac_base.BaseV2ComputeRbacTest):
 
     # Tests in this class will fail with a 404 from microversion 2.36,
     # according to:
     # https://developer.openstack.org/api-ref/compute/#security-groups-os-security-groups-deprecated
     max_microversion = '2.35'
 
+    @classmethod
+    def skip_checks(cls):
+        super(SecurityGroupsRbacMaxV235Test, cls).skip_checks()
+        # All the tests below require the network service.
+        # NOTE(gmann) Currently 'network' service is always True in
+        # test.get_service_list() So below check is not much of use.
+        # Commenting the below check as Tempest is moving the get_service_list
+        # from test.py to utils.
+        # If we want to check 'network' service availability, then
+        # get_service_list can be used from new location.
+        # if not test.get_service_list()['network']:
+        #    raise cls.skipException(
+        #        'Skipped because the network service is not available')
+
     @rbac_rule_validation.action(
         service="nova",
         rule="os_compute_api:os-security-groups")
@@ -58,9 +145,10 @@
     @decorators.idempotent_id('3de5c6bc-b822-469e-a627-82427d38b067')
     def test_update_security_groups(self):
         sec_group_id = self.create_security_group()['id']
-        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
         new_name = data_utils.rand_name()
         new_desc = data_utils.rand_name()
+
+        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
         self.security_groups_client.update_security_group(sec_group_id,
                                                           name=new_name,
                                                           description=new_desc)
diff --git a/patrole_tempest_plugin/tests/api/compute/test_server_rbac.py b/patrole_tempest_plugin/tests/api/compute/test_server_rbac.py
index 10ea801..35ca437 100644
--- a/patrole_tempest_plugin/tests/api/compute/test_server_rbac.py
+++ b/patrole_tempest_plugin/tests/api/compute/test_server_rbac.py
@@ -18,7 +18,6 @@
 from tempest.common import waiters
 from tempest import config
 from tempest.lib.common.utils import data_utils
-from tempest.lib.common.utils import test_utils
 from tempest.lib import decorators
 from tempest.lib import exceptions
 from tempest import test
@@ -41,69 +40,12 @@
         cls.networks_client = cls.os_primary.networks_client
         cls.ports_client = cls.os_primary.ports_client
         cls.subnets_client = cls.os_primary.subnets_client
+        cls.admin_servers_client = cls.os_admin.servers_client
 
     @classmethod
     def resource_setup(cls):
         super(ComputeServersRbacTest, cls).resource_setup()
         cls.server = cls.create_test_server(wait_until='ACTIVE')
-        # Create a volume
-        volume_name = data_utils.rand_name(cls.__name__ + '-volume')
-        name_field = 'name'
-        if not CONF.volume_feature_enabled.api_v2:
-            name_field = 'display_name'
-
-        params = {name_field: volume_name,
-                  'imageRef': CONF.compute.image_ref,
-                  'size': CONF.volume.volume_size}
-
-        volume = cls.volumes_client.create_volume(**params)['volume']
-        waiters.wait_for_volume_resource_status(cls.volumes_client,
-                                                volume['id'], 'available')
-        cls.volumes.append(volume)
-        cls.volume_id = volume['id']
-
-    def _create_network_resources(self):
-        # Create network
-        network_name = data_utils.rand_name(
-            self.__class__.__name__ + '-network')
-
-        network = self.networks_client.create_network(
-            name=network_name, port_security_enabled=True)['network']
-        self.addCleanup(self.networks_client.delete_network, network['id'])
-
-        # Create subnet for the network
-        subnet_name = data_utils.rand_name(self.__class__.__name__ + '-subnet')
-        subnet = self.subnets_client.create_subnet(
-            name=subnet_name,
-            network_id=network['id'],
-            cidr=CONF.network.project_network_cidr,
-            ip_version=4)['subnet']
-        self.addCleanup(self.subnets_client.delete_subnet, subnet['id'])
-
-        return network
-
-    def _create_test_server_with_volume(self, volume_id):
-        # Create a server with the volume created earlier
-        server_name = data_utils.rand_name(self.__class__.__name__ + "-server")
-        bd_map_v2 = [{'uuid': volume_id,
-                      'source_type': 'volume',
-                      'destination_type': 'volume',
-                      'boot_index': 0,
-                      'delete_on_termination': True}]
-        device_mapping = {'block_device_mapping_v2': bd_map_v2}
-
-        # Since the server is booted from volume, the imageRef does not need
-        # to be specified.
-        server = self.servers_client.create_server(
-            name=server_name, imageRef='',
-            flavorRef=CONF.compute.flavor_ref,
-            **device_mapping)['server']
-
-        waiters.wait_for_server_status(
-            self.os_admin.servers_client, server['id'], 'ACTIVE')
-
-        self.servers.append(server)
-        return server
 
     @rbac_rule_validation.action(
         service="nova",
@@ -139,8 +81,25 @@
         rule="os_compute_api:servers:create:attach_volume")
     @decorators.idempotent_id('eeddac5e-15aa-454f-838d-db608aae4dd8')
     def test_create_server_attach_volume(self):
+        # To create a bootable volume, the UUID of the image from which
+        # to create the volume must be included as the imageRef attribute in
+        # the request body.
+        volume_id = self.create_volume(
+            imageRef=CONF.compute.image_ref,
+            size=CONF.volume.volume_size)['id']
+
+        server_name = data_utils.rand_name(self.__class__.__name__ + "-server")
+        bd_map_v2 = [{'uuid': volume_id,
+                      'source_type': 'volume',
+                      'destination_type': 'volume',
+                      'boot_index': 0,
+                      'delete_on_termination': True}]
+        device_mapping = {'block_device_mapping_v2': bd_map_v2}
+
         self.rbac_utils.switch_role(self, toggle_rbac_role=True)
-        self._create_test_server_with_volume(self.volume_id)
+        # Use image_id='' to avoid using the default image in tempest.conf.
+        self.create_test_server(name=server_name, image_id='',
+                                **device_mapping)
 
     @test.services('network')
     @rbac_rule_validation.action(
@@ -148,12 +107,33 @@
         rule="os_compute_api:servers:create:attach_network")
     @decorators.idempotent_id('b44cd4ff-50a4-42ce-ada3-724e213cd540')
     def test_create_server_attach_network(self):
-        network = self._create_network_resources()
-        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
+        def _create_network_resources():
+            # Create network
+            network_name = data_utils.rand_name(
+                self.__class__.__name__ + '-network')
+
+            network = self.networks_client.create_network(
+                name=network_name, port_security_enabled=True)['network']
+            self.addCleanup(self.networks_client.delete_network, network['id'])
+
+            # Create subnet for the network
+            subnet_name = data_utils.rand_name(
+                self.__class__.__name__ + '-subnet')
+            subnet = self.subnets_client.create_subnet(
+                name=subnet_name,
+                network_id=network['id'],
+                cidr=CONF.network.project_network_cidr,
+                ip_version=4)['subnet']
+            self.addCleanup(self.subnets_client.delete_subnet, subnet['id'])
+
+            return network
+
+        network = _create_network_resources()
         network_id = {'uuid': network['id']}
+
+        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
         server = self.create_test_server(wait_until='ACTIVE',
                                          networks=[network_id])
-
         self.addCleanup(waiters.wait_for_server_termination,
                         self.servers_client, server['id'])
         self.addCleanup(self.servers_client.delete_server, server['id'])
@@ -164,10 +144,11 @@
     @decorators.idempotent_id('062e3440-e873-4b41-9317-bf6d8be50c12')
     def test_delete_server(self):
         server = self.create_test_server(wait_until='ACTIVE')
+
         self.rbac_utils.switch_role(self, toggle_rbac_role=True)
         self.servers_client.delete_server(server['id'])
         waiters.wait_for_server_termination(
-            self.os_admin.servers_client, server['id'])
+            self.admin_servers_client, server['id'])
 
     @rbac_rule_validation.action(
         service="nova",
@@ -178,76 +159,10 @@
         self.rbac_utils.switch_role(self, toggle_rbac_role=True)
         try:
             self.servers_client.update_server(self.server['id'], name=new_name)
-            waiters.wait_for_server_status(self.os_admin.servers_client,
+            waiters.wait_for_server_status(self.admin_servers_client,
                                            self.server['id'], 'ACTIVE')
         except exceptions.ServerFault as e:
             # Some other policy may have blocked it.
             LOG.info("ServerFault exception caught. Some other policy "
                      "blocked updating of server")
             raise rbac_exceptions.RbacConflictingPolicies(e)
-
-
-class SecurtiyGroupsRbacTest(base.BaseV2ComputeRbacTest):
-    """Tests non-deprecated security group policies. Requires network service.
-
-    This class tests non-deprecated policies for adding and removing a security
-    group to and from a server.
-    """
-
-    @classmethod
-    def setup_credentials(cls):
-        # A network and a subnet will be created for these tests.
-        cls.set_network_resources(network=True, subnet=True)
-        super(SecurtiyGroupsRbacTest, cls).setup_credentials()
-
-    @classmethod
-    def skip_checks(cls):
-        super(SecurtiyGroupsRbacTest, cls).skip_checks()
-        # All the tests below require the network service.
-        if not test.get_service_list()['network']:
-            raise cls.skipException(
-                'Skipped because the network service is not available')
-
-    @classmethod
-    def resource_setup(cls):
-        super(SecurtiyGroupsRbacTest, cls).resource_setup()
-        cls.server = cls.create_test_server(wait_until='ACTIVE')
-
-    @rbac_rule_validation.action(
-        service="nova",
-        rule="os_compute_api:os-security-groups")
-    @decorators.idempotent_id('3db159c6-a467-469f-9a25-574197885520')
-    def test_list_security_groups_by_server(self):
-        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
-        self.servers_client.list_security_groups_by_server(self.server['id'])
-
-    @decorators.attr(type=["slow"])
-    @rbac_rule_validation.action(
-        service="nova",
-        rule="os_compute_api:os-security-groups")
-    @decorators.idempotent_id('ea1ca73f-2d1d-43cb-9a46-900d7927b357')
-    def test_create_security_group_for_server(self):
-        sg_name = self.create_security_group()['name']
-
-        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
-        self.servers_client.add_security_group(self.server['id'], name=sg_name)
-        self.addCleanup(test_utils.call_and_ignore_notfound_exc,
-                        self.servers_client.remove_security_group,
-                        self.server['id'], name=sg_name)
-
-    @decorators.attr(type=["slow"])
-    @rbac_rule_validation.action(
-        service="nova",
-        rule="os_compute_api:os-security-groups")
-    @decorators.idempotent_id('0ad2e856-e2d3-4ac5-a620-f93d0d3d2626')
-    def test_remove_security_group_from_server(self):
-        sg_name = self.create_security_group()['name']
-
-        self.servers_client.add_security_group(self.server['id'], name=sg_name)
-        self.addCleanup(test_utils.call_and_ignore_notfound_exc,
-                        self.servers_client.remove_security_group,
-                        self.server['id'], name=sg_name)
-
-        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
-        self.servers_client.remove_security_group(
-            self.server['id'], name=sg_name)
diff --git a/patrole_tempest_plugin/tests/api/identity/v3/test_users_rbac.py b/patrole_tempest_plugin/tests/api/identity/v3/test_users_rbac.py
index 0c85240..5812f9e 100644
--- a/patrole_tempest_plugin/tests/api/identity/v3/test_users_rbac.py
+++ b/patrole_tempest_plugin/tests/api/identity/v3/test_users_rbac.py
@@ -20,11 +20,11 @@
 from patrole_tempest_plugin.tests.api.identity import rbac_base
 
 
-class IdentityUserV3AdminRbacTest(rbac_base.BaseIdentityV3RbacTest):
+class IdentityUserV3RbacTest(rbac_base.BaseIdentityV3RbacTest):
 
     @classmethod
     def resource_setup(cls):
-        super(IdentityUserV3AdminRbacTest, cls).resource_setup()
+        super(IdentityUserV3RbacTest, cls).resource_setup()
         cls.default_user_id = cls.os_primary.credentials.user_id
 
     @rbac_rule_validation.action(service="keystone",
@@ -71,19 +71,6 @@
         self.users_client.show_user(self.default_user_id)
 
     @rbac_rule_validation.action(service="keystone",
-                                 rule="identity:change_password")
-    @decorators.idempotent_id('0f148510-63bf-11e6-4522-080044d0d90a')
-    def test_change_password(self):
-        original_password = data_utils.rand_password()
-        user = self.setup_test_user(password=original_password)
-
-        self.rbac_utils.switch_role(self, toggle_rbac_role=True)
-        self.users_client.update_user_password(
-            user['id'],
-            original_password=original_password,
-            password=data_utils.rand_password())
-
-    @rbac_rule_validation.action(service="keystone",
                                  rule="identity:list_groups_for_user")
     @decorators.idempotent_id('bd5946d4-46d2-423d-a800-a3e7aabc18b3')
     def test_list_own_user_group(self):
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")
diff --git a/releasenotes/notes/rbac-per-test-log-071a530e957c1c26.yaml b/releasenotes/notes/rbac-per-test-log-071a530e957c1c26.yaml
new file mode 100644
index 0000000..b1d400c
--- /dev/null
+++ b/releasenotes/notes/rbac-per-test-log-071a530e957c1c26.yaml
@@ -0,0 +1,28 @@
+---
+features:
+  - |
+    Added in a new logging feature which logs the result of each Patrole test
+
+    The format of the new log output is:
+
+      "[Service]: %s, [Test]: %s, [Rule]: %s, [Expected]: %s, [Actual]: %s"
+
+      where each "%s" is a string that contains:
+
+      * [Service] - The openstack service being tested (Nova, Neutron, etc)
+      * [Test] - The name of the test function being invoked (eg: test_list_aggregate_rbac)
+      * [Rule] - The name of the rule the Patrole test is testing (eg: os_compute_api:os-aggregates)
+      * [Expected] - The expected outcome (one of Allowed/Denied)
+      * [Actual] - The actual outcome from the Patrole test (one of Allowed/Denied/Error)
+
+    This logging feature has two config variables:
+
+      These variables are part of a new config group ``patrole_log``
+
+      * enable_reporting:
+          This enables or disables the enhanced rbac reporting
+      * report_log_name:
+          This variable specifies the name of the log file to write
+      * report_log_path:
+          This variable specifies the path (relative or absolute)
+          of the log file to write
diff --git a/requirements.txt b/requirements.txt
index cd6a577..00c7e64 100644
--- a/requirements.txt
+++ b/requirements.txt
@@ -4,7 +4,7 @@
 hacking!=0.13.0,<0.14,>=0.12.0 # Apache-2.0
 pbr!=2.1.0,>=2.0.0 # Apache-2.0
 urllib3>=1.21.1 # MIT
-oslo.log>=3.22.0 # Apache-2.0
+oslo.log>=3.30.0 # Apache-2.0
 oslo.config!=4.3.0,!=4.4.0,>=4.0.0 # Apache-2.0
 oslo.policy>=1.23.0 # Apache-2.0
 tempest>=16.1.0 # Apache-2.0
diff --git a/test-requirements.txt b/test-requirements.txt
index 772694e..0657438 100644
--- a/test-requirements.txt
+++ b/test-requirements.txt
@@ -13,5 +13,5 @@
 nosexcover # BSD
 oslotest>=1.10.0 # Apache-2.0
 oslo.policy>=1.23.0 # Apache-2.0
-oslo.log>=3.22.0 # Apache-2.0
+oslo.log>=3.30.0 # Apache-2.0
 tempest>=16.1.0 # Apache-2.0