Ironic

Ironic doesn't eject virtual media DVD in Cisco UCS blades

Bug #2039042 reported by Iury Gregory Melo Ferreira on 2023-10-11

This bug affects 2 people

Affects		Status	Importance	Assigned to	Milestone
	Ironic	Fix Released	Undecided	Iury Gregory Melo Ferreira

Bug Description

In https://bugs.launchpad.net/ironic/+bug/2031595 we decided to retry connecting vmedia through a DVD device if available to solve the problem.

We didn't have access to hardware to fully test the deployment workflow, this week a person from Cisco attempted to test the fix and reported that when the first insertion of vmedia is correct, but after finishing inspection and going to cleaning ironic can't find the vmedia device to insert the media again, this is because we forgot to handle the vmedia eject.

From the logs

Oct 10 14:54:17 localhost.localdomain ironic[7995]: 2023-10-10 14:54:17.590 1 DEBUG sushy.resources.base [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] Received representation of VirtualMedia /redfish/v1/Managers/CIMC/VirtualMedia/3: {'_actions': {'eject_media': {'operation_apply_time_support': None, 'target_uri': '/redfish/v1/Managers/CIMC/VirtualMedia/3/Actions/VirtualMedia.EjectMedia'}, 'insert_media': {'operation_apply_time_support': None, 'target_uri': '/redfish/v1/Managers/CIMC/VirtualMedia/3/Actions/VirtualMedia.InsertMedia'}}, '_certificates_path': None, '_oem_vendors': ['Cisco'], 'connected_via': <ConnectedVia.URI: 'URI'>, 'identity': '3', 'image': 'myip:6180/redfish/boot-a993ff4e-b8da-4598-ae27-6ca3df88a28e.iso', 'image_name': 'boot-a993ff4e-b8da-4598-ae27-6ca3df88a28e.iso', 'inserted': True, 'links': None, 'media_types': [<VirtualMediaType.DVD: 'DVD'>], 'name': 'CIMC-Mapped vDVD', 'status': {'health': <Health.OK: 'OK'>, 'health_rollup': None, 'state': <State.ENABLED: 'Enabled'>}, 'transfer_method': None, 'user_name': None, 'verify_certificate': None, 'write_protected': True} refresh /usr/lib/python3.9/site-packages/sushy/resources/base.py:694
Oct 10 14:54:17 localhost.localdomain ironic[7995]: 2023-10-10 14:54:17.590 1 DEBUG sushy.connector [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] HTTP request: GET https://10.5.4.75/redfish/v1/Managers/CIMC/VirtualMedia/4; headers: {'OData-Version': '4.0'}; body: None; blocking: False; timeout: 60; session arguments: {}; _op /usr/lib/python3.9/site-packages/sushy/connector.py:147
Oct 10 14:54:18 localhost.localdomain ironic[7995]: 2023-10-10 14:54:18.264 1 INFO eventlet.wsgi.server [None req-cdec19a3-df99-4413-a438-9aff2a413a3c - - - - - -] ::ffff:10.5.5.9 "GET /v1/nodes/a993ff4e-b8da-4598-ae27-6ca3df88a28e HTTP/1.1" status: 200 len: 4182 time: 0.0083137

Oct 10 14:54:18 localhost.localdomain ironic[7995]: 2023-10-10 14:54:18.347 1 DEBUG sushy.connector [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] HTTP response for GET https://10.5.4.75/redfish/v1/Managers/CIMC/VirtualMedia/4: status code: 200 _op /usr/lib/python3.9/site-packages/sushy/connector.py:283
Oct 10 14:54:18 localhost.localdomain ironic[7995]: 2023-10-10 14:54:18.347 1 DEBUG sushy.resources.base [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] Received representation of VirtualMedia /redfish/v1/Managers/CIMC/VirtualMedia/4: {'_actions': {'eject_media': {'operation_apply_time_support': None, 'target_uri': '/redfish/v1/Managers/CIMC/VirtualMedia/4/Actions/VirtualMedia.EjectMedia'}, 'insert_media': {'operation_apply_time_support': None, 'target_uri': '/redfish/v1/Managers/CIMC/VirtualMedia/4/Actions/VirtualMedia.InsertMedia'}}, '_certificates_path': None, '_oem_vendors': ['Cisco'], 'connected_via': <ConnectedVia.URI: 'URI'>, 'identity': '4', 'image': None, 'image_name': None, 'inserted': False, 'links': None, 'media_types': [<VirtualMediaType.USB_STICK: 'USBStick'>], 'name': 'CIMC-Mapped vHDD', 'status': {'health': <Health.OK: 'OK'>, 'health_rollup': None, 'state': <State.DISABLED: 'Disabled'>}, 'transfer_method': None, 'user_name': None, 'verify_certificate': None, 'write_protected': False} refresh /usr/lib/python3.9/site-packages/sushy/resources/base.py:694
Oct 10 14:54:18 localhost.localdomain ironic[7995]: 2023-10-10 14:54:18.348 1 WARNING ironic.drivers.modules.redfish.boot [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] Fast track is possible for node a993ff4e-b8da-4598-ae27-6ca3df88a28e, but no ISO is currently inserted! Proceeding with normal operation.

As you can see the device 3 didn't remove the image. After some seconds we see ironic trying to insert the vmedia and fails because couldn't find devices

Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.898 1 DEBUG sushy.exceptions [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] HTTP response for PATCH https://bmcaddress/redfish/v1/Managers/CIMC/VirtualMedia/0: status code: 400, error: Base.1.13.0.GeneralError: The action 'Patch Update For Resource' is not supported by the resource., extended: [{'@odata.type': '#Message.v1_1_1.Message', 'MessageId': 'Base.1.13.0.ActionNotSupported', 'Message': "The action 'Patch Update For Resource' is not supported by the resource.", 'MessageArgs': ['Patch Update For Resource'], 'Severity': 'Critical', 'Resolution': 'The action supplied cannot be resubmitted to the implementation. Perhaps the action was invalid, the wrong resource was the target or the implementation documentation may be of assistance.'}] __init__ /usr/lib/python3.9/site-packages/sushy/exceptions.py:122
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 WARNING sushy.connector [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] Initial request with eTag failed: HTTP PATCH https://bmcaddress/redfish/v1/Managers/CIMC/VirtualMedia/0 returned code 400. Base.1.13.0.GeneralError: The action 'Patch Update For Resource' is not supported by the resource. Extended information: [{'@odata.type': '#Message.v1_1_1.Message', 'MessageId': 'Base.1.13.0.ActionNotSupported', 'Message': "The action 'Patch Update For Resource' is not supported by the resource.", 'MessageArgs': ['Patch Update For Resource'], 'Severity': 'Critical', 'Resolution': 'The action supplied cannot be resubmitted to the implementation. Perhaps the action was invalid, the wrong resource was the target or the implementation documentation may be of assistance.'}]: sushy.exceptions.BadRequestError: HTTP PATCH https://bmcaddress/redfish/v1/Managers/CIMC/VirtualMedia/0 returned code 400. Base.1.13.0.GeneralError: The action 'Patch Update For Resource' is not supported by the resource. Extended information: [{'@odata.type': '#Message.v1_1_1.Message', 'MessageId': 'Base.1.13.0.ActionNotSupported', 'Message': "The action 'Patch Update For Resource' is not supported by the resource.", 'MessageArgs': ['Patch Update For Resource'], 'Severity': 'Critical', 'Resolution': 'The action supplied cannot be resubmitted to the implementation. Perhaps the action was invalid, the wrong resource was the target or the implementation documentation may be of assistance.'}]
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 WARNING ironic.drivers.modules.redfish.boot [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] ('Inserting virtual media into %(boot_device)s failed for node %(node)s, moving to next virtual media device, if available', {'node': 'a993ff4e-b8da-4598-ae27-6ca3df88a28e', 'boot_device': <VirtualMediaType.CD: 'CD'>}): sushy.exceptions.BadRequestError: HTTP PATCH https://bmcaddress/redfish/v1/Managers/CIMC/VirtualMedia/0 returned code 400. Base.1.13.0.GeneralError: The action 'Patch Update For Resource' is not supported by the resource. Extended information: [{'@odata.type': '#Message.v1_1_1.Message', 'MessageId': 'Base.1.13.0.ActionNotSupported', 'Message': "The action 'Patch Update For Resource' is not supported by the resource.", 'MessageArgs': ['Patch Update For Resource'], 'Severity': 'Critical', 'Resolution': 'The action supplied cannot be resubmitted to the implementation. Perhaps the action was invalid, the wrong resource was the target or the implementation documentation may be of assistance.'}]
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 DEBUG ironic.drivers.modules.redfish.boot [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] While looking for VirtualMediaType.CD virtual media device, found VirtualMediaType.DVD instead. Attempting to configure it. _insert_vmedia /usr/lib/python3.9/site-packages/ironic/drivers/modules/redfish/boot.py:200
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils [None req-e490de91-ab2e-4251-9403-2fade714b203 - - - - - -] Failed to prepare node a993ff4e-b8da-4598-ae27-6ca3df88a28e for cleaning: ('All virtual media mount attempts failed. Most recent error: ', ('Inserting virtual media into %(boot_device)s failed for node %(node)s, moving to next virtual media device, if available', {'node': 'a993ff4e-b8da-4598-ae27-6ca3df88a28e', 'boot_device': <VirtualMediaType.CD: 'CD'>})): ironic.common.exception.InvalidParameterValue: ('All virtual media mount attempts failed. Most recent error: ', ('Inserting virtual media into %(boot_device)s failed for node %(node)s, moving to next virtual media device, if available', {'node': 'a993ff4e-b8da-4598-ae27-6ca3df88a28e', 'boot_device': <VirtualMediaType.CD: 'CD'>}))
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils Traceback (most recent call last):
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/ironic/conductor/cleaning.py", line 92, in do_node_clean
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils prepare_result = task.driver.deploy.prepare_cleaning(task)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/ironic_lib/metrics.py", line 60, in wrapped
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils result = f(*args, **kwargs)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/ironic/drivers/modules/agent_base.py", line 796, in prepare_cleaning
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils result = deploy_utils.prepare_inband_cleaning(
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/ironic/drivers/modules/deploy_utils.py", line 726, in prepare_inband_cleaning
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils prepare_agent_boot(task)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/ironic/drivers/modules/deploy_utils.py", line 1536, in prepare_agent_boot
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils task.driver.boot.prepare_ramdisk(task, deploy_opts)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/ironic/drivers/modules/redfish/boot.py", line 595, in prepare_ramdisk
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils _insert_vmedia(task, managers, iso_ref, sushy.VIRTUAL_MEDIA_CD)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/tenacity/__init__.py", line 333, in wrapped_f
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils return self(f, *args, **kw)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/tenacity/__init__.py", line 423, in __call__
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils do = self.iter(retry_state=retry_state)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/tenacity/__init__.py", line 360, in iter
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils return fut.result()
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib64/python3.9/concurrent/futures/_base.py", line 439, in result
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils return self.__get_result()
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib64/python3.9/concurrent/futures/_base.py", line 391, in __get_result
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils raise self._exception
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/tenacity/__init__.py", line 426, in __call__
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils result = fn(*args, **kwargs)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils File "/usr/lib/python3.9/site-packages/ironic/drivers/modules/redfish/boot.py", line 250, in _insert_vmedia
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils raise exception.InvalidParameterValue(exc_msg)
Oct 10 14:54:48 localhost.localdomain ironic[7995]: 2023-10-10 14:54:48.899 1 ERROR ironic.conductor.utils ironic.common.exception.InvalidParameterValue: ('All virtual media mount attempts failed. Most recent error: ', ('Inserting virtual media into %(boot_device)s failed for node %(node)s, moving to next virtual media device, if available', {'node': 'a993ff4e-b8da-4598-ae27-6ca3df88a28e', 'boot_device': <VirtualMediaType.CD: 'CD'>}))

Iury Gregory Melo Ferreira (iurygregory) on 2023-10-11

Changed in ironic:
assignee:	nobody → Iury Gregory Melo Ferreira (iurygregory)
status:	New → In Progress

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-30: Fix merged to ironic (master)

Reviewed: https://review.opendev.org/c/openstack/ironic/+/897989
Committed: https://opendev.org/openstack/ironic/commit/766d2804a1743e238a37762c946dec0984721167
Submitter: "Zuul (22348)"
Branch: master

commit 766d2804a1743e238a37762c946dec0984721167
Author: Iury Gregory Melo Ferreira <email address hidden>
Date: Wed Oct 11 13:51:02 2023 -0300

Make sure we eject media from DVD when CD is requested

    It's possible to use virtual media based provisioning on
    servers that only support DVD MediaTypes and do not support CD
    MediaTypes. The problem in this scenario is that Ironic will keep
    the media attached since it will only eject the ones matching the
    CD device, now we check if there is any DVD device with media inserted
    when looking for CD devices.

Closes-Bug: 2039042
Change-Id: I7a5e871133300fea8a77ad5bfd9a0b045c24c201

Changed in ironic:
status:	In Progress → Fix Released

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-30: Fix proposed to ironic (stable/2023.2)

Fix proposed to branch: stable/2023.2
Review: https://review.opendev.org/c/openstack/ironic/+/899335

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-30: Fix proposed to ironic (bugfix/22.1)

Fix proposed to branch: bugfix/22.1
Review: https://review.opendev.org/c/openstack/ironic/+/899336

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-30: Fix proposed to ironic (bugfix/22.0)

Fix proposed to branch: bugfix/22.0
Review: https://review.opendev.org/c/openstack/ironic/+/899337

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-30: Fix proposed to ironic (stable/2023.1)

Fix proposed to branch: stable/2023.1
Review: https://review.opendev.org/c/openstack/ironic/+/899338

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-31: Fix merged to ironic (stable/2023.1)

Reviewed: https://review.opendev.org/c/openstack/ironic/+/899338
Committed: https://opendev.org/openstack/ironic/commit/5379f18fd632bcf1c84c4da0b8869e3e703ae30a
Submitter: "Zuul (22348)"
Branch: stable/2023.1

commit 5379f18fd632bcf1c84c4da0b8869e3e703ae30a
Author: Iury Gregory Melo Ferreira <email address hidden>
Date: Wed Oct 11 13:51:02 2023 -0300

Make sure we eject media from DVD when CD is requested

Closes-Bug: 2039042
Change-Id: I7a5e871133300fea8a77ad5bfd9a0b045c24c201

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-31: Fix merged to ironic (bugfix/22.1)

Reviewed: https://review.opendev.org/c/openstack/ironic/+/899336
Committed: https://opendev.org/openstack/ironic/commit/b39a686d712ba9bbde8b621eb51c8905ef9e9227
Submitter: "Zuul (22348)"
Branch: bugfix/22.1

commit b39a686d712ba9bbde8b621eb51c8905ef9e9227
Author: Iury Gregory Melo Ferreira <email address hidden>
Date: Wed Oct 11 13:51:02 2023 -0300

Make sure we eject media from DVD when CD is requested

Closes-Bug: 2039042
Change-Id: I7a5e871133300fea8a77ad5bfd9a0b045c24c201

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-31: Fix merged to ironic (stable/2023.2)

Reviewed: https://review.opendev.org/c/openstack/ironic/+/899335
Committed: https://opendev.org/openstack/ironic/commit/235e6ccb9835a2583984a1a47614b8bab1dbad0e
Submitter: "Zuul (22348)"
Branch: stable/2023.2

commit 235e6ccb9835a2583984a1a47614b8bab1dbad0e
Author: Iury Gregory Melo Ferreira <email address hidden>
Date: Wed Oct 11 13:51:02 2023 -0300

Make sure we eject media from DVD when CD is requested

    Closes-Bug: 2039042
    Change-Id: I7a5e871133300fea8a77ad5bfd9a0b045c24c201
    (cherry picked from commit 766d2804a1743e238a37762c946dec0984721167)