While disconnecting the volume, multipath fails with error,
2023-02-16 00:23:25.298 1920 ERROR oslo_messaging.rpc.server Stderr: 'Feb 16 00:22:45 | 3624a93705842cfae35d7483200015ec6 is not a multipath device\n'
This happens because multipath retries the flush multiple times
First time it fails with a timeout,
cli cmd 'del map 3624a93705842cfae35d7483200015fd8' timeout reached after 4.858561 secs
but in the background, we keep retrying to flush the multipath device so when the flush successfully happens, the next flush request fails with "not a multipath device" since it's already flushed.
Initial flushing failures,
> 2023-03-10 16:42:42.655 2878341 DEBUG os_brick.initiator.linuxscsi [req-bdebfdef-daf3-4250-8594-9ed91adb7c00 f91779ad06064ebfbeeff54de535a6cd 8a676a415f9541c59705a373a36b0ec4 - - -] Flush multipath device 3624a93705842cfae35d7483200015fce flush_multipath_device /usr/lib/python3.6/site-packages/os_brick/initiator/linuxscsi.py:376
> 2023-03-10 16:42:42.657 2880468 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): multipath -f 3624a93705842cfae35d7483200015fce execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:384
> 2023-03-10 16:42:46.675 2880468 DEBUG oslo_concurrency.processutils [-] CMD "multipath -f 3624a93705842cfae35d7483200015fce" returned: 1 in 4.019s execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:423
> 2023-03-10 16:42:46.676 2880468 DEBUG oslo_concurrency.processutils [-] 'multipath -f 3624a93705842cfae35d7483200015fce' failed. Retrying. execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:478
> 2023-03-10 16:42:46.676 2880468 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): multipath -f 3624a93705842cfae35d7483200015fce execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:384
> 2023-03-10 16:42:46.685 2880468 DEBUG os_brick.privileged.rootwrap [-] Sleeping for 20 seconds on_execute /usr/lib/python3.6/site-packages/os_brick/privileged/rootwrap.py:106
> 2023-03-10 16:42:55.994 2878341 DEBUG oslo_service.periodic_task [req-b7d7b4ae-b092-40bf-9105-97bede752389 - - - - -] Running periodic task BackupManager.publish_service_capabilities run_periodic_tasks /usr/lib/python3.6/site-packages/oslo_service/periodic_task.py:211
> 2023-03-10 16:42:55.995 2878341 DEBUG cinder.manager [req-b7d7b4ae-b092-40bf-9105-97bede752389 - - - - -] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python3.6/site-packages/cinder/manager.py:197
> 2023-03-10 16:43:06.707 2880468 DEBUG oslo_concurrency.processutils [-] CMD "multipath -f 3624a93705842cfae35d7483200015fce" returned: 1 in 20.031s execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:423
> 2023-03-10 16:43:06.707 2880468 DEBUG oslo_concurrency.processutils [-] 'multipath -f 3624a93705842cfae35d7483200015fce' failed. Retrying. execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:478
> 2023-03-10 16:43:06.707 2880468 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): multipath -f 3624a93705842cfae35d7483200015fce execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:384
> 2023-03-10 16:43:06.714 2880468 DEBUG os_brick.privileged.rootwrap [-] Sleeping for 40 seconds on_execute /usr/lib/python3.6/site-packages/os_brick/privileged/rootwrap.py:106
> 2023-03-10 16:43:46.753 2880468 DEBUG oslo_concurrency.processutils [-] CMD "multipath -f 3624a93705842cfae35d7483200015fce" returned: 1 in 40.046s execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:423
> 2023-03-10 16:43:46.754 2880468 DEBUG oslo_concurrency.processutils [-] 'multipath -f 3624a93705842cfae35d7483200015fce' failed. Not Retrying. execute /usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py:474
> 2023-03-10 16:43:46.754 2880468 DEBUG oslo.privsep.daemon [-] privsep: Exception during request[140628271231200]: Unexpected error while running command.
> Command: multipath -f 3624a93705842cfae35d7483200015fce
> Exit code: 1
> Stdout: ''
> Stderr: 'Mar 10 16:43:06 | 3624a93705842cfae35d7483200015fce is not a multipath device\n' _process_cmd /usr/lib/python3.6/site-packages/oslo_privsep/daemon.py:490
> Traceback (most recent call last):
> File "/usr/lib/python3.6/site-packages/oslo_privsep/daemon.py", line 485, in _process_cmd
> ret = func(*f_args, **f_kwargs)
> File "/usr/lib/python3.6/site-packages/oslo_privsep/priv_context.py", line 249, in _wrap
> return func(*args, **kwargs)
> File "/usr/lib/python3.6/site-packages/os_brick/privileged/rootwrap.py", line 197, in execute_root
> return custom_execute(*cmd, shell=False, run_as_root=False, **kwargs)
> File "/usr/lib/python3.6/site-packages/os_brick/privileged/rootwrap.py", line 146, in custom_execute
> on_completion=on_completion, *cmd, **kwargs)
> File "/usr/lib/python3.6/site-packages/oslo_concurrency/processutils.py", line 441, in execute
> cmd=sanitized_cmd)
> oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
> Command: multipath -f 3624a93705842cfae35d7483200015fce
> Exit code: 1
> Stdout: ''
> Stderr: 'Mar 10 16:43:06 | 3624a93705842cfae35d7483200015fce is not a multipath device\n'
> 2023-03-10 16:43:46.757 2880468 DEBUG oslo.privsep.daemon [-] privsep: reply[140628271231200]: (5, 'oslo_concurrency.processutils.ProcessExecutionError', ('', 'Mar 10 16:43:06 | 3624a93705842cfae35d7483200015fce is not a multipath device\n', 1, 'multipath -f 3624a93705842cfae35d7483200015fce', None)) _call_back /usr/lib/python3.6/site-packages/oslo_privsep/daemon.py:511
> 2023-03-10 16:43:46.758 2878341 WARNING os_brick.exception [req-bdebfdef-daf3-4250-8594-9ed91adb7c00 f91779ad06064ebfbeeff54de535a6cd 8a676a415f9541c59705a373a36b0ec4 - - -] Flushing 3624a93705842cfae35d7483200015fce failed: oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
Final failures,
> oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
> Command: multipath -f 3624a93705842cfae35d7483200015fce
> Exit code: 1
> Stdout: ''
> Stderr: 'Mar 10 16:44:07 | 3624a93705842cfae35d7483200015fce is not a multipath device\n'
> 2023-03-10 16:44:47.288 2880468 DEBUG oslo.privsep.daemon [-] privsep: reply[140628271231200]: (5, 'oslo_concurrency.processutils.ProcessExecutionError', ('', 'Mar 10 16:44:07 | 3624a93705842cfae35d7483200015fce is not a multipath device\n', 1, 'multipath -f 3624a93705842cfae35d7483200015fce', None)) _call_back /usr/lib/python3.6/site-packages/oslo_privsep/daemon.py:511
> 2023-03-10 16:44:47.289 2878341 DEBUG oslo_concurrency.lockutils [req-bdebfdef-daf3-4250-8594-9ed91adb7c00 f91779ad06064ebfbeeff54de535a6cd 8a676a415f9541c59705a373a36b0ec4 - - -] Lock "connect_volume" released by "os_brick.initiator.connectors.iscsi.ISCSIConnector.disconnect_volume" :: held 124.674s inner /usr/lib/python3.6/site-packages/oslo_concurrency/lockutils.py:371
> 2023-03-10 16:44:47.289 2878341 DEBUG os_brick.initiator.connectors.iscsi [req-bdebfdef-daf3-4250-8594-9ed91adb7c00 f91779ad06064ebfbeeff54de535a6cd 8a676a415f9541c59705a373a36b0ec4 - - -] <== disconnect_volume: exception (124674ms) ProcessExecutionError('', 'Mar 10 16:44:07 | 3624a93705842cfae35d7483200015fce is not a multipath device\n', 1, 'multipath -f 3624a93705842cfae35d7483200015fce', None) trace_logging_wrapper /usr/lib/python3.6/site-packages/os_brick/utils.py:160
> 2023-03-10 16:44:47.314 2878341 ERROR oslo_messaging.rpc.server [req-bdebfdef-daf3-4250-8594-9ed91adb7c00 f91779ad06064ebfbeeff54de535a6cd 8a676a415f9541c59705a373a36b0ec4 - - -] Exception during message handling: oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
> Command: multipath -f 3624a93705842cfae35d7483200015fce
> Exit code: 1
> Stdout: ''
> Stderr: 'Mar 10 16:44:07 | 3624a93705842cfae35d7483200015fce is not a multipath device\n'
Proposed fix here: https:/