iscsiadm: Could not execute operation on all records: encountered iSCSI

[John Griffith]

Noticed a number of failures on my CI setup the past few days for iscsiadm failures coming from brick.
2015-06-02 21:12:55.005 ERROR cinder.volume.flows.manager.create_volume [req-6b1a7ee2-2f91-4fbc-9c97-a65cd9cdd747 None] Failed to copy image 3c243988-f81f-4fa4-98d3-c57941eff443 to volume: a39c88cb-2268-46c5-b487-6e58a4f82b93
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume Traceback (most recent call last):
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 501, in _copy_image_to_volume
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume copy_image_to_volume(context, volume_ref, image_service, image_id)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 105, in wrapper
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume return f(*args, **kwargs)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/opt/stack/cinder/cinder/volume/driver.py", line 568, in copy_image_to_volume
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume self._detach_volume(context, attach_info, volume, properties)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/opt/stack/cinder/cinder/volume/driver.py", line 342, in _detach_volume
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume attach_info['device'])
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 445, in inner
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume return f(*args, **kwargs)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 412, in disconnect_volume
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume self._disconnect_volume_iscsi(props)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 439, in _disconnect_volume_iscsi
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume self._disconnect_from_iscsi_portal(connection_properties)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 615, in _disconnect_from_iscsi_portal
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume check_exit_code=[0, 21, 255])
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 468, in _run_iscsiadm
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume check_exit_code=check_exit_code)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 240, in execute
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume cmd=sanitized_cmd)
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume ProcessExecutionError: Unexpected error while running command.
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf iscsiadm -m node -T iqn.2010-01.com.solidfire:l74j.uuid-a39c88cb-2268-46c5-b487-6e58a4f82b93.85176 -p 10.10.64.3:3260 --op delete
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume Exit code: 6
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume Stdout: u''
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume Stderr: u'iscsiadm: Could not execute operation on all records: encountered iSCSI database failure\n'
2015-06-02 21:12:55.005 14589 ERROR cinder.volume.flows.manager.create_volume
2015-06-02 21:12:55.009 DEBUG taskflow.engines.action_engine.runner [req-6b1a7ee2-2f91-4fbc-9c97-a65cd9cdd747 None] Exiting old state 'SCHEDULING' in response to event 'wait_finished' on_exit /usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/runner.py:201
2015-06-02 21:12:55.009 DEBUG taskflow.engines.action_engine.runner [req-6b1a7ee2-2f91-4fbc-9c97-a65cd9cdd747 None] Entering new state 'WAITING' in response to event 'wait_finished' on_enter /usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/runner.py:205
2015-06-02 21:12:55.009 DEBUG taskflow.engines.action_engine.runner [req-6b1a7ee2-2f91-4fbc-9c97-a65cd9cdd747 None] Exiting old state 'WAITING' in response to event 'examine_finished' on_exit /usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/runner.py:201
2015-06-02 21:12:55.010 DEBUG taskflow.engines.action_engine.runner [req-6b1a7ee2-2f91-4fbc-9c97-a65cd9cdd747 None] Entering new state 'ANALYZING' in response to event 'examine_finished' on_enter /usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/runner.py:205
2015-06-02 21:12:55.011 WARNING cinder.volume.manager [req-6b1a7ee2-2f91-4fbc-9c97-a65cd9cdd747 None] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (aed33b2d-bb2f-4350-91e8-0081ecd7dfd9) transitioned into state 'FAILURE' from state 'RUNNING'
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager Traceback (most recent call last):
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager File "/usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/executor.py", line 67, in _execute_task
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager result = task.execute(**arguments)
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 653, in execute
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager **volume_spec)
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 605, in _create_from_image
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager image_id, image_location, image_service)
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 506, in _copy_image_to_volume
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager raise exception.ImageCopyFailure(reason=ex.stderr)
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager ImageCopyFailure: Failed to copy image to volume: iscsiadm: Could not execute operation on all records: encountered iSCSI database failure
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager
2015-06-02 21:12:55.011 14589 ERROR cinder.volume.manager

[Walt Boring (walter-boring)]

might be a related issue found here that has a possible fix using a retry....

https://bugs.launchpad.net/ironic/+bug/1324670

https://review.openstack.org/#/c/96577/

[Walt Boring (walter-boring)]

https://review.openstack.org/#/c/187811/

Not sure why but the patch didn't get associated with this bug

[John Griffith (john-griffith)]

Looks like it didn't fix things anyway. Have seen this in the RBD gate test, but also locally on CI systems a few times this week.

2015-06-26 11:06:35.905 ERROR cinder.volume.flows.manager.create_volume [req-d786eb8d-faf2-4904-af22-616008f0aa2a None] Failed to copy image 190d5982-24b2-4b24-aaa7-2e88bce83d35 to volume: d0437a9f-d181-41e6-93d3-f88803c323b5
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume Traceback (most recent call last):
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 515, in _copy_image_to_volume
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume copy_image_to_volume(context, volume_ref, image_service, image_id)
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 105, in wrapper
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume return f(*args, **kwargs)
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/opt/stack/cinder/cinder/volume/driver.py", line 568, in copy_image_to_volume
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume attach_info, volume = self._attach_volume(context, volume, properties)
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/opt/stack/cinder/cinder/volume/driver.py", line 712, in _attach_volume
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume return (self._connect_device(conn), volume)
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/opt/stack/cinder/cinder/volume/driver.py", line 724, in _connect_device
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume device = connector.connect_volume(conn['data'])
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 251, in inner
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume return f(*args, **kwargs)
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 320, in connect_volume
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume if self._connect_to_iscsi_portal(props):
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 551, in _connect_to_iscsi_portal
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume self._run_iscsiadm(connection_properties, ())
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 468, in _run_iscsiadm
2015-06-26 11:06:35.905 11515 ERROR cinder.volume.flows.manager.create_volume check_exit_code=check_exit_code)
2015...

[Sean McGinnis (sean-mcginnis)]

Looks like this error has only come up once since the last comment here.

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message:%5C%22encountered%20iSCSI%20database%20failure%5C%22

Switching back to Fix Committed under assumption that errors seen after the fix was made were residual issues.