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'>}))
Reviewed: https:/ /review. opendev. org/c/openstack /ironic/ +/897989 /opendev. org/openstack/ ironic/ commit/ 766d2804a1743e2 38a37762c946dec 0984721167
Committed: https:/
Submitter: "Zuul (22348)"
Branch: master
commit 766d2804a1743e2 38a37762c946dec 0984721167
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 ea8a77ad5bfd9a0 b045c24c201
Change-Id: I7a5e871133300f