From 09c1111904410c22d16b850fa142e9e12f8c33c9 Mon Sep 17 00:00:00 2001 From: Brian Rosmaita Date: Wed, 27 Mar 2019 18:46:10 -0400 Subject: [PATCH] Document behavior of message.create Add docstrings to clarify the behavior of message.create() when both an exception and detail are passed as arguments. Updates the user_messages section of the contributor docs to reflect the changes introduced in Pike by implementation of the "Explicit user messages" spec. Adds tests to prevent regressions. Closes-bug: #1822000 Change-Id: Ia0425dc9c241d0c101057fbc534e68e7e5fdc317 --- cinder/message/api.py | 47 ++++- cinder/message/message_field.py | 12 ++ cinder/tests/unit/message/test_api.py | 203 ++++++++++++++++++++- doc/source/contributor/user_messages.rst | 213 +++++++++++++++++++++-- 4 files changed, 454 insertions(+), 21 deletions(-) diff --git a/cinder/message/api.py b/cinder/message/api.py index 553ff8babad..291ff19e7b5 100644 --- a/cinder/message/api.py +++ b/cinder/message/api.py @@ -38,12 +38,55 @@ LOG = logging.getLogger(__name__) class API(base.Base): - """API for handling user messages.""" + """API for handling user messages. + + Cinder Messages describe the outcome of a user action using predefined + fields that are members of objects defined in the + cinder.message.message_field package. They are intended to be exposed to + end users. Their primary purpose is to provide end users with a means of + discovering what went wrong when an asynchronous action in the Volume REST + API (for which they've already received a 2xx response) fails. + + Messages contain an 'expires_at' field based on the creation time plus the + value of the 'message_ttl' configuration option. They are periodically + reaped by a task of the SchedulerManager class whose periodicity is given + by the 'message_reap_interval' configuration option. + + """ def create(self, context, action, resource_type=message_field.Resource.VOLUME, resource_uuid=None, exception=None, detail=None, level="ERROR"): - """Create a message with the specified information.""" + """Create a message record with the specified information. + + :param context: current context object + :param action: + a message_field.Action field describing what was taking place + when this message was created + :param resource_type: + a message_field.Resource field describing the resource this + message applies to. Default is message_field.Resource.VOLUME + :param resource_uuid: + the resource ID if this message applies to an existing resource. + Default is None + :param exception: + if an exception has occurred, you can pass it in and it will be + translated into an appropriate message detail ID (possibly + message_field.Detail.UNKNOWN_ERROR). The message + in the exception itself is ignored in order not to expose + sensitive information to end users. Default is None + :param detail: + a message_field.Detail field describing the event the message + is about. Default is None, in which case + message_field.Detail.UNKNOWN_ERROR will be used for the message + unless an exception in the message_field.EXCEPTION_DETAIL_MAPPINGS + is passed; in that case the message_field.Detail field that's + mapped to the exception is used. + :param level: + a string describing the severity of the message. Suggested + values are 'INFO', 'ERROR', 'WARNING'. Default is 'ERROR'. + """ + LOG.info("Creating message record for request_id = %s", context.request_id) # Updates expiry time for message as per message_ttl config. diff --git a/cinder/message/message_field.py b/cinder/message/message_field.py index a091988af8b..875059caf01 100644 --- a/cinder/message/message_field.py +++ b/cinder/message/message_field.py @@ -124,6 +124,18 @@ def translate_detail(detail_id): def translate_detail_id(exception, detail): + """Get a detail_id to use for a message. + + If exception is in the EXCEPTION_DETAIL_MAPPINGS, returns the detail_id + of the mapped Detail field. If exception is not in the mapping or is None, + returns the detail_id of the passed-in Detail field. Otherwise, returns + the detail_id of Detail.UNKNOWN_ERROR. + + :param exception: an Exception (or None) + :param detail: a message_field.Detail field (or None) + :returns: string + :returns: the detail_id of a message_field.Detail field + """ if exception is not None and isinstance(exception, Exception): for key, value in Detail.EXCEPTION_DETAIL_MAPPINGS.items(): if exception.__class__.__name__ in value: diff --git a/cinder/tests/unit/message/test_api.py b/cinder/tests/unit/message/test_api.py index e9cee6533fd..c300873f8f1 100644 --- a/cinder/tests/unit/message/test_api.py +++ b/cinder/tests/unit/message/test_api.py @@ -20,6 +20,7 @@ from cinder.api import microversions as mv from cinder.api.openstack import api_version_request as api_version from cinder.api.v3 import messages from cinder import context +from cinder import exception from cinder.message import api as message_api from cinder.message import message_field from cinder import test @@ -54,8 +55,7 @@ class MessageApiTest(test.TestCase): 'request_id': 'fakerequestid', 'resource_type': 'fake_resource_type', 'resource_uuid': None, - 'action_id': - message_field.Action.SCHEDULE_ALLOCATE_VOLUME[0], + 'action_id': message_field.Action.SCHEDULE_ALLOCATE_VOLUME[0], 'detail_id': message_field.Detail.UNKNOWN_ERROR[0], 'message_level': 'ERROR', 'expires_at': expected_expires_at, @@ -70,6 +70,205 @@ class MessageApiTest(test.TestCase): self.ctxt, expected_message_record) mock_utcnow.assert_called_with() + @mock.patch('oslo_utils.timeutils.utcnow') + def test_create_with_minimum_args(self, mock_utcnow): + CONF.set_override('message_ttl', 300) + mock_utcnow.return_value = datetime.datetime.utcnow() + expected_expires_at = timeutils.utcnow() + datetime.timedelta( + seconds=300) + expected_message_record = { + 'project_id': 'fakeproject', + 'request_id': 'fakerequestid', + 'resource_type': message_field.Resource.VOLUME, + 'resource_uuid': None, + 'action_id': message_field.Action.SCHEDULE_ALLOCATE_VOLUME[0], + 'detail_id': message_field.Detail.UNKNOWN_ERROR[0], + 'message_level': 'ERROR', + 'expires_at': expected_expires_at, + 'event_id': "VOLUME_VOLUME_001_001", + } + self.message_api.create( + self.ctxt, + action=message_field.Action.SCHEDULE_ALLOCATE_VOLUME) + + self.message_api.db.message_create.assert_called_once_with( + self.ctxt, expected_message_record) + mock_utcnow.assert_called_with() + + @mock.patch('oslo_utils.timeutils.utcnow') + def test_create_with_no_detail(self, mock_utcnow): + # Should get Detail.UNKNOWN_ERROR + CONF.set_override('message_ttl', 300) + mock_utcnow.return_value = datetime.datetime.utcnow() + expected_expires_at = timeutils.utcnow() + datetime.timedelta( + seconds=300) + expected_message_record = { + 'project_id': 'fakeproject', + 'request_id': 'fakerequestid', + 'resource_type': 'fake_resource_type', + 'resource_uuid': None, + 'action_id': message_field.Action.SCHEDULE_ALLOCATE_VOLUME[0], + 'detail_id': message_field.Detail.UNKNOWN_ERROR[0], + 'message_level': 'ERROR', + 'expires_at': expected_expires_at, + 'event_id': "VOLUME_fake_resource_type_001_001", + } + self.message_api.create( + self.ctxt, + action=message_field.Action.SCHEDULE_ALLOCATE_VOLUME, + resource_type="fake_resource_type") + + self.message_api.db.message_create.assert_called_once_with( + self.ctxt, expected_message_record) + mock_utcnow.assert_called_with() + + @mock.patch('oslo_utils.timeutils.utcnow') + def test_create_with_detail_only(self, mock_utcnow): + CONF.set_override('message_ttl', 300) + mock_utcnow.return_value = datetime.datetime.utcnow() + expected_expires_at = timeutils.utcnow() + datetime.timedelta( + seconds=300) + expected_message_record = { + 'project_id': 'fakeproject', + 'request_id': 'fakerequestid', + 'resource_type': 'fake_resource_type', + 'resource_uuid': None, + 'action_id': message_field.Action.SCHEDULE_ALLOCATE_VOLUME[0], + # this doesn't make sense for this Action, but that's the point + 'detail_id': message_field.Detail.FAILED_TO_UPLOAD_VOLUME[0], + 'message_level': 'ERROR', + 'expires_at': expected_expires_at, + 'event_id': "VOLUME_fake_resource_type_001_004", + } + self.message_api.create( + self.ctxt, + action=message_field.Action.SCHEDULE_ALLOCATE_VOLUME, + detail=message_field.Detail.FAILED_TO_UPLOAD_VOLUME, + resource_type="fake_resource_type") + + self.message_api.db.message_create.assert_called_once_with( + self.ctxt, expected_message_record) + mock_utcnow.assert_called_with() + + @mock.patch('oslo_utils.timeutils.utcnow') + def test_create_passed_exception_no_detail(self, mock_utcnow): + # Detail should be automatically supplied based on the + # message_field.Detail.EXCEPTION_DETAIL_MAPPINGS + CONF.set_override('message_ttl', 300) + mock_utcnow.return_value = datetime.datetime.utcnow() + expected_expires_at = timeutils.utcnow() + datetime.timedelta( + seconds=300) + expected_message_record = { + 'project_id': 'fakeproject', + 'request_id': 'fakerequestid', + 'resource_type': 'fake_resource_type', + 'resource_uuid': None, + 'action_id': message_field.Action.SCHEDULE_ALLOCATE_VOLUME[0], + # this is determined by the exception we'll be passing + 'detail_id': message_field.Detail.NOT_ENOUGH_SPACE_FOR_IMAGE[0], + 'message_level': 'ERROR', + 'expires_at': expected_expires_at, + 'event_id': "VOLUME_fake_resource_type_001_007", + } + exc = exception.ImageTooBig(image_id='fake_image', reason='MYOB') + self.message_api.create( + self.ctxt, + action=message_field.Action.SCHEDULE_ALLOCATE_VOLUME, + exception=exc, + resource_type="fake_resource_type") + + self.message_api.db.message_create.assert_called_once_with( + self.ctxt, expected_message_record) + mock_utcnow.assert_called_with() + + @mock.patch('oslo_utils.timeutils.utcnow') + def test_create_passed_unmapped_exception_no_detail(self, mock_utcnow): + CONF.set_override('message_ttl', 300) + mock_utcnow.return_value = datetime.datetime.utcnow() + expected_expires_at = timeutils.utcnow() + datetime.timedelta( + seconds=300) + expected_message_record = { + 'project_id': 'fakeproject', + 'request_id': 'fakerequestid', + 'resource_type': 'fake_resource_type', + 'resource_uuid': None, + 'action_id': message_field.Action.COPY_IMAGE_TO_VOLUME[0], + 'detail_id': message_field.Detail.UNKNOWN_ERROR[0], + 'message_level': 'ERROR', + 'expires_at': expected_expires_at, + 'event_id': "VOLUME_fake_resource_type_005_001", + } + exc = exception.ImageUnacceptable(image_id='fake_image', reason='MYOB') + self.message_api.create( + self.ctxt, + action=message_field.Action.COPY_IMAGE_TO_VOLUME, + exception=exc, + resource_type="fake_resource_type") + + self.message_api.db.message_create.assert_called_once_with( + self.ctxt, expected_message_record) + mock_utcnow.assert_called_with() + + @mock.patch('oslo_utils.timeutils.utcnow') + def test_create_passed_mapped_exception_and_detail(self, mock_utcnow): + # passed Detail should be ignored because this is a mapped exception + CONF.set_override('message_ttl', 300) + mock_utcnow.return_value = datetime.datetime.utcnow() + expected_expires_at = timeutils.utcnow() + datetime.timedelta( + seconds=300) + expected_message_record = { + 'project_id': 'fakeproject', + 'request_id': 'fakerequestid', + 'resource_type': 'fake_resource_type', + 'resource_uuid': None, + 'action_id': message_field.Action.UPDATE_ATTACHMENT[0], + 'detail_id': message_field.Detail.NOT_ENOUGH_SPACE_FOR_IMAGE[0], + 'message_level': 'ERROR', + 'expires_at': expected_expires_at, + 'event_id': "VOLUME_fake_resource_type_004_007", + } + exc = exception.ImageTooBig(image_id='fake_image', reason='MYOB') + self.message_api.create( + self.ctxt, + action=message_field.Action.UPDATE_ATTACHMENT, + detail=message_field.Detail.VOLUME_ATTACH_MODE_INVALID, + exception=exc, + resource_type="fake_resource_type") + + self.message_api.db.message_create.assert_called_once_with( + self.ctxt, expected_message_record) + mock_utcnow.assert_called_with() + + @mock.patch('oslo_utils.timeutils.utcnow') + def test_create_passed_unmapped_exception_and_detail(self, mock_utcnow): + # passed Detail should be honored + CONF.set_override('message_ttl', 300) + mock_utcnow.return_value = datetime.datetime.utcnow() + expected_expires_at = timeutils.utcnow() + datetime.timedelta( + seconds=300) + expected_message_record = { + 'project_id': 'fakeproject', + 'request_id': 'fakerequestid', + 'resource_type': 'fake_resource_type', + 'resource_uuid': None, + 'action_id': message_field.Action.UPDATE_ATTACHMENT[0], + 'detail_id': message_field.Detail.VOLUME_ATTACH_MODE_INVALID[0], + 'message_level': 'ERROR', + 'expires_at': expected_expires_at, + 'event_id': "VOLUME_fake_resource_type_004_005", + } + exc = ValueError('bogus error') + self.message_api.create( + self.ctxt, + action=message_field.Action.UPDATE_ATTACHMENT, + detail=message_field.Detail.VOLUME_ATTACH_MODE_INVALID, + exception=exc, + resource_type="fake_resource_type") + + self.message_api.db.message_create.assert_called_once_with( + self.ctxt, expected_message_record) + mock_utcnow.assert_called_with() + def test_create_swallows_exception(self): self.mock_object(self.message_api.db, 'create', side_effect=Exception()) diff --git a/doc/source/contributor/user_messages.rst b/doc/source/contributor/user_messages.rst index 7ce1e0470fd..5d46cf2fd2c 100644 --- a/doc/source/contributor/user_messages.rst +++ b/doc/source/contributor/user_messages.rst @@ -1,53 +1,226 @@ User Messages ============= +General information +~~~~~~~~~~~~~~~~~~~ + User messages are a way to inform users about the state of asynchronous operations. One example would be notifying the user of why a volume -provisioning request failed. These messages can be requested via the -/messages API. All user visible messages must be defined in the permitted -messages module in order to prevent sharing sensitive information with users. +provisioning request failed. End users can request these messages via the +Volume v3 REST API under the ``/messages`` resource. The REST API allows +only GET and DELETE verbs for this resource. +Internally, you use the ``cinder.message.api`` to work with messages. In +order to prevent leakage of sensitive information or breaking the volume +service abstraction layer, free-form messages are *not* allowed. Instead, all +messages must be defined using a combination of pre-defined fields in the +``cinder.message.message_field`` module. + +The message ultimately displayed to end users is combined from an ``Action`` +field and a ``Detail`` field. + +* The ``Action`` field describes what was taking place when the message + was created, for example, ``Action.COPY_IMAGE_TO_VOLUME``. + +* The ``Detail`` field is used to provide more information, for example, + ``Detail.NOT_ENOUGH_SPACE_FOR_IMAGE`` or ``Detail.QUOTA_EXCEED``. + +Example +~~~~~~~ Example message generation:: from cinder import context from cinder.message import api as message_api - from cinder.message import defined_messages - from cinder.message import resource_types + from cinder.message import message_field self.message_api = message_api.API() context = context.RequestContext() - project_id = '6c430ede-9476-4128-8838-8d3929ced223' volume_id = 'f292cc0c-54a7-4b3b-8174-d2ff82d87008' self.message_api.create( context, - defined_messages.EventIds.UNABLE_TO_ALLOCATE, - project_id, - resource_type=resource_types.VOLUME, - resource_uuid=volume_id) + message_field.Action.UNMANAGE_VOLUME, + resource_uuid=volume_id, + detail=message_field.Detail.UNMANAGE_ENC_NOT_SUPPORTED) -Will produce the following:: +Will produce roughly the following:: GET /v3/6c430ede-9476-4128-8838-8d3929ced223/messages { "messages": [ { "id": "5429fffa-5c76-4d68-a671-37a8e24f37cf", - "event_id": "000002", - "user_message": "No storage could be allocated for this volume request.", + "event_id": "VOLUME_VOLUME_006_008", + "user_message": "unmanage volume: Unmanaging encrypted volumes is not supported.", "message_level": "ERROR", "resource_type": "VOLUME", "resource_uuid": "f292cc0c-54a7-4b3b-8174-d2ff82d87008", - "created_at": 2015-08-27T09:49:58-05:00, - "guaranteed_until": 2015-09-27T09:49:58-05:00, + "created_at": 2018-08-27T09:49:58-05:00, + "guaranteed_until": 2018-09-27T09:49:58-05:00, "request_id": "req-936666d2-4c8f-4e41-9ac9-237b43f8b848", } ] } +Adding user messages +~~~~~~~~~~~~~~~~~~~~ +If you are creating a message in the code but find that the predefined fields +are insufficient, just add what you need to ``cinder.message.message_field``. +The key thing to keep in mind is that all defined fields should be appropriate +for any API user to see and not contain any sensitive information. A good +rule-of-thumb is to be very general in error messages unless the issue is due +to a bad user action, then be specific. + +As a convenience to developers, the ``Detail`` class contains a +``EXCEPTION_DETAIL_MAPPINGS`` dict. This maps ``Detail`` fields to particular +Cinder exceptions, and allows you to create messages in a context where you've +caught an Exception that could be any of several possibilities. Instead of +having to sort through them where you've caught the exception, you can call +``message_api.create`` and pass it both the exception and a general detail +field like ``Detail.SOMETHING_BAD_HAPPENED`` (that's not a real field, but +you get the idea). If the passed exception is in the mapping, the resulting +message will have the mapped ``Detail`` field instead of the generic one. + +Usage patterns +~~~~~~~~~~~~~~ + +These are taken from the Cinder code. The exact code may have changed +by the time you read this, but the general idea should hold. + +No exception in context +----------------------- + +From cinder/compute/nova.py:: + + def extend_volume(self, context, server_ids, volume_id): + api_version = '2.51' + events = [self._get_volume_extended_event(server_id, volume_id) + for server_id in server_ids] + result = self._send_events(context, events, api_version=api_version) + if not result: + self.message_api.create( + context, + message_field.Action.EXTEND_VOLUME, + resource_uuid=volume_id, + detail=message_field.Detail.NOTIFY_COMPUTE_SERVICE_FAILED) + return result + +* You must always pass the context object and an action. +* We're working with an existing volume, so pass its ID as the + ``resource_uuid``. +* You need to fill in some detail, or else the code will supply an + ``UNKNOWN_ERROR``, which isn't very helpful. + +Cinder exception in context +--------------------------- + +From cinder/scheduler/manager.py:: + + except exception.NoValidBackend as ex: + QUOTAS.rollback(context, reservations, + project_id=volume.project_id) + _extend_volume_set_error(self, context, ex, request_spec) + self.message_api.create( + context, + message_field.Action.EXTEND_VOLUME, + resource_uuid=volume.id, + exception=ex) + +* You must always pass the context object and an action. +* Since we have it available, pass the volume ID as the resource_uuid. +* It's a Cinder exception. Check to see if it's in the mapping. + + * If it's there, we can pass it, and the detail will be supplied + by the code. + * It it's not, consider adding it and mapping it to an existing + ``Detail`` field. If there's no current ``Detail`` field for that + exception, go ahead and add that, too. + * On the other hand, maybe it's in the mapping, but you have more + information in this code context than is available in the mapped + ``Detail`` field. In that case, you may want to use a different + ``Detail`` field (creating it if necessary). + * Remember, if you pass *both* a mapped exception *and* a detail, the + passed detail will be ignored and the mapped ``Detail`` field will be + used instead. + +General Exception in context +---------------------------- + +Not passing the Exception to message_api.create() ++++++++++++++++++++++++++++++++++++++++++++++++++ + +From cinder/volume/manager.py:: + + try: + self.driver.extend_volume(volume, new_size) + except exception.TargetUpdateFailed: + # We just want to log this but continue on with quota commit + LOG.warning('Volume extended but failed to update target.') + except Exception: + LOG.exception("Extend volume failed.", + resource=volume) + self.message_api.create( + context, + message_field.Action.EXTEND_VOLUME, + resource_uuid=volume.id, + detail=message_field.Detail.DRIVER_FAILED_EXTEND) + +* Pass the context object and an action; pass a ``resource_uuid`` since we + have it. +* We're not passing the exception, so the ``detail`` we pass is guaranteed + to be used. + +Passing the Exception to message_api.create() ++++++++++++++++++++++++++++++++++++++++++++++ + +From cinder/volume/manager.py:: + + try: + if volume_metadata.get('readonly') == 'True' and mode != 'ro': + raise exception.InvalidVolumeAttachMode(mode=mode, + volume_id=volume.id) + utils.require_driver_initialized(self.driver) + + LOG.info('Attaching volume %(volume_id)s to instance ' + '%(instance)s at mountpoint %(mount)s on host ' + '%(host)s.', + {'volume_id': volume_id, 'instance': instance_uuid, + 'mount': mountpoint, 'host': host_name_sanitized}, + resource=volume) + self.driver.attach_volume(context, + volume, + instance_uuid, + host_name_sanitized, + mountpoint) + except Exception as excep: + with excutils.save_and_reraise_exception(): + self.message_api.create( + context, + message_field.Action.ATTACH_VOLUME, + resource_uuid=volume_id, + exception=excep) + attachment.attach_status = ( + fields.VolumeAttachStatus.ERROR_ATTACHING) + attachment.save() + +* Pass the context object and an action; pass a resource_uuid since we + have it. +* We're passing an exception, which could be a Cinder + ``InvalidVolumeAttachMode``, which is in the mapping. In that case, the + mapped ``Detail`` will be used; + otherwise, the code will supply a ``Detail.UNKNOWN_ERROR``. + + This is appropriate if we really have no idea what happened. If it's + possible to provide more information, we can pass a different, generic + ``Detail`` field (creating it if necessary). The passed detail would be + used for any exception that's *not* in the mapping. If it's a mapped + exception, then the mapped ``Detail`` field will be used. + +Module documentation +~~~~~~~~~~~~~~~~~~~~ The Message API Module ---------------------- @@ -63,8 +236,14 @@ The Message Field Module .. automodule:: cinder.message.message_field :noindex: -The Permitted Messages Module ------------------------------ +The Defined Messages Module +--------------------------- + +This module is DEPRECATED and is currently only used by +``cinder.api.v3.messages`` to handle pre-Pike message database objects. +(Editorial comment:: With the default ``message_ttl`` of 2592000 seconds +(30 days), it's probably safe to remove this module during the Train +development cycle.) .. automodule:: cinder.message.defined_messages :noindex: