test_volume_backup_create_get_detailed_list_restore_delete fails with "iscsiadm: Could not execute operation on all records: encountered iSCSI database failure"

Bug #1552009 reported by Matt Riedemann
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Cinder
Invalid
Undecided
Unassigned

Bug Description

http://logs.openstack.org/28/286828/1/check/gate-tempest-dsvm-neutron-full/1fd7c47/logs/screen-c-bak.txt.gz?level=TRACE

2016-03-01 22:49:56.798 ERROR oslo_messaging.rpc.dispatcher [req-32854dfd-c53a-4d7c-b7a9-3cb380423510 tempest-VolumesBackupsV2Test-945738117] Exception during message handling: Unexpected error while running command.
Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf iscsiadm -m node -T iqn.2010-10.org.openstack:volume-70fae24f-023c-4253-aa56-4df15de72d78 -p 149.202.172.216:3260 --op update -n node.startup -v automatic
Exit code: 6
Stdout: u''
Stderr: u'iscsiadm: Could not execute operation on all records: encountered iSCSI database failure\n'
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 138, in _dispatch_and_reply
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher incoming.message))
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 183, in _dispatch
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 127, in _do_dispatch
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/backup/manager.py", line 310, in create_backup
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher self._update_backup_error(backup, context, six.text_type(err))
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher self.force_reraise()
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/backup/manager.py", line 304, in create_backup
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher self._run_backup(context, backup, volume)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/backup/manager.py", line 340, in _run_backup
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher properties, is_snapshot)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/backup/manager.py", line 809, in _attach_device
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher return self._attach_volume(context, backup_device, properties)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/backup/manager.py", line 832, in _attach_volume
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher {'volume_id', volume.id})
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher self.force_reraise()
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/backup/manager.py", line 821, in _attach_volume
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher return self._connect_device(conn)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/backup/manager.py", line 844, in _connect_device
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher vol_handle = connector.connect_volume(conn['data'])
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 271, in inner
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 846, in connect_volume
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher connection_properties)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 655, in _get_potential_volume_paths
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher if self._connect_to_iscsi_portal(props):
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 1183, in _connect_to_iscsi_portal
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher "automatic")
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 1043, in _iscsiadm_update
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher **kwargs)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/os_brick/initiator/connector.py", line 1030, in _run_iscsiadm
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher delay_on_retry=delay_on_retry)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 371, in execute
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher cmd=sanitized_cmd)
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf iscsiadm -m node -T iqn.2010-10.org.openstack:volume-70fae24f-023c-4253-aa56-4df15de72d78 -p 149.202.172.216:3260 --op update -n node.startup -v automatic
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher Exit code: 6
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher Stdout: u''
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher Stderr: u'iscsiadm: Could not execute operation on all records: encountered iSCSI database failure\n'
2016-03-01 22:49:56.798 20251 ERROR oslo_messaging.rpc.dispatcher

Revision history for this message
Matt Riedemann (mriedem) wrote :

I see errors in syslog around that time:

http://logs.openstack.org/28/286828/1/check/gate-tempest-dsvm-neutron-full/1fd7c47/logs/syslog.txt.gz#_Mar__1_22_50_17

Mar 1 22:50:17 devstack-trusty-ovh-gra1-8447539 kernel: [ 3085.846833] connection14:0: detected conn error (1020)
Mar 1 22:50:18 devstack-trusty-ovh-gra1-8447539 tgtd: accept_connection(217) 7
Mar 1 22:50:18 devstack-trusty-ovh-gra1-8447539 tgtd: cmnd_exec_login(694) Login request (security negotiation): 0
Mar 1 22:50:18 devstack-trusty-ovh-gra1-8447539 tgtd: iscsi_tcp_event_handler(287) connection closed 0x1c94490
Mar 1 22:50:18 devstack-trusty-ovh-gra1-8447539 tgtd: conn_close(103) connection closed, 0x1c94490 1
Mar 1 22:50:15 devstack-trusty-ovh-gra1-8447539 iscsid: Kernel reported iSCSI connection 14:0 error (1019 - ISCSI_ERR_XMIT_FAILED: Transmission of iSCSI packet failed) state (2)
Mar 1 22:50:18 devstack-trusty-ovh-gra1-8447539 iscsid: conn 0 login rejected: initiator error - target not found (02/03)

Revision history for this message
Matt Riedemann (mriedem) wrote :
Changed in cinder:
status: New → Confirmed
Revision history for this message
Sean McGinnis (sean-mcginnis) wrote :

Appears to have since been fixed.

Changed in cinder:
status: Confirmed → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.