cinder-backup context.message_action is None on errors

[Jesper Schmitz Mouridsen]

If a driver raises an exception another exception is thrown from https://opendev.org/openstack/cinder/src/commit/3dfc519301aeb92ed4595788450b57e0be74db12/cinder/message/api.py#L104 because
AFAICT the action is None. (also cheked above https://opendev.org/openstack/cinder/src/commit/3dfc519301aeb92ed4595788450b57e0be74db12/cinder/message/api.py#L101 for setting action_id.

One solution is for drivers to set context.message_action in init another would be to test if action is not None in api.py l 104, though it would be even better if we could figure out how message_action turned out to be None even though we had set it earlier (see comment #3, below).

[Sofia Enriquez (lsofia-enriquez)]

Greetings Jesper Schmitz Mouridsen,
Thank you for the suggestion on how to solve this problem. I will mention this bug in tomorrow's bug report email. Could you describe a situation with steps so we can reproduce the problem and have a more accurate idea of the scope of this issue?
Thank you very much in advance.
Sofia

[Jesper Schmitz Mouridsen (jsmdk)]

The easiest way to reproduce is to use the PosixBackupDriver with a backup_posix_path = /var/cinder/permdenied (where cinder does not have write access to the directory) Then you get

 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
 ERROR oslo_messaging.rpc.server File "/opt/stack/cinder/cinder/backup/manager.py", line 491, in continue_backup
 ERROR oslo_messaging.rpc.server updates = backup_service.backup(backup,
 ERROR oslo_messaging.rpc.server File "/opt/stack/cinder/cinder/backup/chunkeddriver.py", line 546, in backup
 ERROR oslo_messaging.rpc.server volume_size_bytes) = self._prepare_backup(backup)
 ERROR oslo_messaging.rpc.server File "/opt/stack/cinder/cinder/backup/chunkeddriver.py", line 332, in _prepare_backup
 ERROR oslo_messaging.rpc.server container = self._create_container(backup)
 ERROR oslo_messaging.rpc.server File "/opt/stack/cinder/cinder/backup/chunkeddriver.py", line 235, in _create_container
 ERROR oslo_messaging.rpc.server self.put_container(backup.container)
 ERROR oslo_messaging.rpc.server File "/opt/stack/cinder/cinder/backup/drivers/posix.py", line 105, in put_container
 ERROR oslo_messaging.rpc.server os.makedirs(path)
 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.8/os.py", line 213, in makedirs
 ERROR oslo_messaging.rpc.server makedirs(head, exist_ok=exist_ok)
 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.8/os.py", line 213, in makedirs
 ERROR oslo_messaging.rpc.server makedirs(head, exist_ok=exist_ok)
 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.8/os.py", line 213, in makedirs
 ERROR oslo_messaging.rpc.server makedirs(head, exist_ok=exist_ok)
 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.8/os.py", line 223, in makedirs
 ERROR oslo_messaging.rpc.server mkdir(name, mode)
 ERROR oslo_messaging.rpc.server PermissionError: [Errno 13] Permission denied: '/var/cinder/permdenied'
 ERROR oslo_messaging.rpc.server
 ERROR oslo_messaging.rpc.server During handling of the above exception, another exception occurred:
 ERROR oslo_messaging.rpc.server
 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python3.8/dist-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python3.8/dist-packages/oslo_messaging/rpc/dispatcher.py", line 309, in dispatch
 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python3.8/dist-packages/oslo_messaging/rpc/dispatcher.py", line 229, in _do_dispatch
 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
 ERROR oslo_messaging.rpc.server File "/opt/stack/cinder/cinder/backup/manager.py", line 525, in continue_backup
 ERROR oslo_messaging.rpc.server volume_utils.update_backup_error(backup, str(err))
 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
 ERROR oslo_messaging.rpc.s...

[Brian Rosmaita (brian-rosmaita)]

I looked into this a bit. The exception is being raised from continue_backup(). The backup manager workflow when you create a backup is:

1. create_backup() - does initial setup; the context.message_* properties are added here
2. _start_backup() - makes an rpcapi call to the volume manager to get the backup device; passes the context
3. continue_backup() - the callback from the volume manager; is passed the context object

I think what's happening is that the message_* properties are being lost when the context is serialized to be sent over the wire for the rpc calls. We're not getting an AttributeError, which makes sense because the message_* members are set in the cinder.context.RequestContext's __init__() method [0]. I think the problem is that they aren't included in the to_dict() [1] and from_dict() [2] methods, and so they disappear when the context is passed over rpc.

[0] https://opendev.org/openstack/cinder/src/commit/9a8583b2ef59f6a392b8b1a1efef8d3d270cf9ea/cinder/context.py#L122-L124
[1] https://opendev.org/openstack/cinder/src/commit/9a8583b2ef59f6a392b8b1a1efef8d3d270cf9ea/cinder/context.py#L167
[2] https://opendev.org/openstack/cinder/src/commit/9a8583b2ef59f6a392b8b1a1efef8d3d270cf9ea/cinder/context.py#L182

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/c/openstack/cinder/+/846303

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/cinder/+/846303
Committed: https://opendev.org/openstack/cinder/commit/c46d41719e0c8199dc17ef566413889692644ef5
Submitter: "Zuul (22348)"
Branch: master

commit c46d41719e0c8199dc17ef566413889692644ef5
Author: Jesper Schmitz Mouridsen <email address hidden>
Date: Fri Jun 17 10:29:00 2022 +0000

    Serialize message_* properties of RequestContext

    Change Idc00b125b33b added the ability to store and retrieve user
    message data in the request context, but it neglected to add code to
    make sure they would persist across serialization and deserialization
    of the request context object, as happens in the create-backup
    workflow. As a result, when a user message needed to be created to
    describe an error condition in the backup driver, instead we'd get an
    exception raised: "TypeError: 'NoneType' object is not subscriptable".

    This patch fixes the issue by making sure the message_* properties
    persist across serialization/deserialization of RequestContext objects.

    Closes-Bug: 1978729
    Change-Id: Ibdaaf39abafbae6bfcb9fdf9fb7a55d968ad9f11
    Signed-off-by: Jesper Schmitz Mouridsen <email address hidden>

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/cinder 21.0.0.0rc1 release candidate.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/yoga
Review: https://review.opendev.org/c/openstack/cinder/+/867023

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/cinder/+/867023
Committed: https://opendev.org/openstack/cinder/commit/1bc0b9caba955d73389e6b88bfd9fa40b942f3aa
Submitter: "Zuul (22348)"
Branch: stable/yoga

commit 1bc0b9caba955d73389e6b88bfd9fa40b942f3aa
Author: Jesper Schmitz Mouridsen <email address hidden>
Date: Fri Jun 17 10:29:00 2022 +0000

    Serialize message_* properties of RequestContext

    Change Idc00b125b33b added the ability to store and retrieve user
    message data in the request context, but it neglected to add code to
    make sure they would persist across serialization and deserialization
    of the request context object, as happens in the create-backup
    workflow. As a result, when a user message needed to be created to
    describe an error condition in the backup driver, instead we'd get an
    exception raised: "TypeError: 'NoneType' object is not subscriptable".

    This patch fixes the issue by making sure the message_* properties
    persist across serialization/deserialization of RequestContext objects.

    Closes-Bug: 1978729
    Change-Id: Ibdaaf39abafbae6bfcb9fdf9fb7a55d968ad9f11
    Signed-off-by: Jesper Schmitz Mouridsen <email address hidden>
    (cherry picked from commit c46d41719e0c8199dc17ef566413889692644ef5)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/cinder 20.1.0 release.