tempest

  1. Bug #1807723
  2. Comment #3

Comment 3 for bug 1807723

Revision history for this message
Matt Riedemann (mriedem) wrote : Re: swap multiattach volume intermittently fails when servers are on different hosts

For the fail scenario, it looks like this is where we delete the old attachment record:

http://logs.openstack.org/81/606981/4/check/tempest-slow/fafde23/controller/logs/screen-c-vol.txt.gz#_Dec_08_01_45_40_765428

Dec 08 01:45:40.765428 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: DEBUG cinder.volume.manager [req-4aa23d64-309a-44a4-a7c9-381a6fbef330 req-f47e0ea9-7e80-4481-bce1-7a1060c6728b tempest-TestMultiAttachVolumeSwap-1803326020 None] Deleting attachment d7bfeddf-c8c6-4072-8d34-91aaba0ab343. {{(pid=1884) _do_attachment_delete /opt/stack/cinder/cinder/volume/manager.py:4525}}

And removing the connection fails:

Dec 08 01:45:41.058514 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: INFO cinder.volume.targets.tgt [req-4aa23d64-309a-44a4-a7c9-381a6fbef330 req-f47e0ea9-7e80-4481-bce1-7a1060c6728b tempest-TestMultiAttachVolumeSwap-1803326020 None] Removing iscsi_target for Volume ID: 2a48ae08-2833-488c-8771-eea86f41c7b8
Dec 08 01:45:41.060048 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: DEBUG oslo_concurrency.processutils [req-4aa23d64-309a-44a4-a7c9-381a6fbef330 req-f47e0ea9-7e80-4481-bce1-7a1060c6728b tempest-TestMultiAttachVolumeSwap-1803326020 None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf tgt-admin --force --delete iqn.2010-10.org.openstack:volume-2a48ae08-2833-488c-8771-eea86f41c7b8 {{(pid=1884) execute /usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372}}
Dec 08 01:45:41.074707 ubuntu-xenial-ovh-gra1-0001066161 sudo[9566]: stack : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/local/bin/cinder-rootwrap /etc/cinder/rootwrap.conf tgt-admin --force --delete iqn.2010-10.org.openstack:volume-2a48ae08-2833-488c-8771-eea86f41c7b8
Dec 08 01:45:41.076726 ubuntu-xenial-ovh-gra1-0001066161 sudo[9566]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 08 01:45:41.373922 ubuntu-xenial-ovh-gra1-0001066161 sudo[9566]: pam_unix(sudo:session): session closed for user root
Dec 08 01:45:41.376988 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: DEBUG oslo_concurrency.processutils [req-4aa23d64-309a-44a4-a7c9-381a6fbef330 req-f47e0ea9-7e80-4481-bce1-7a1060c6728b tempest-TestMultiAttachVolumeSwap-1803326020 None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf tgt-admin --force --delete iqn.2010-10.org.openstack:volume-2a48ae08-2833-488c-8771-eea86f41c7b8" returned: 22 in 0.316s {{(pid=1884) execute /usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409}}
Dec 08 01:45:41.378167 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: DEBUG oslo_concurrency.processutils [req-4aa23d64-309a-44a4-a7c9-381a6fbef330 req-f47e0ea9-7e80-4481-bce1-7a1060c6728b tempest-TestMultiAttachVolumeSwap-1803326020 None] u'sudo cinder-rootwrap /etc/cinder/rootwrap.conf tgt-admin --force --delete iqn.2010-10.org.openstack:volume-2a48ae08-2833-488c-8771-eea86f41c7b8' failed. Not Retrying. {{(pid=1884) execute /usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:457}}
Dec 08 01:45:41.380161 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: ERROR cinder.volume.targets.tgt [req-4aa23d64-309a-44a4-a7c9-381a6fbef330 req-f47e0ea9-7e80-4481-bce1-7a1060c6728b tempest-TestMultiAttachVolumeSwap-1803326020 None] Failed to remove iscsi target for Volume ID: 2a48ae08-2833-488c-8771-eea86f41c7b8: Unexpected error while running command.
Dec 08 01:45:41.380475 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf tgt-admin --force --delete iqn.2010-10.org.openstack:volume-2a48ae08-2833-488c-8771-eea86f41c7b8
Dec 08 01:45:41.380783 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: Exit code: 22
Dec 08 01:45:41.381094 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: Stdout: u'Command:\n\ttgtadm -C 0 --mode target --op delete --tid=1\nexited with code: 22.\n'
Dec 08 01:45:41.381386 ubuntu-xenial-ovh-gra1-0001066161 cinder-volume[1776]: Stderr: u'tgtadm: this target is still active\n': ProcessExecutionError: Unexpected error while running command.

That is 4 seconds after we logged out the connection on the subnode for that volume:

Dec 08 01:45:37.336156 ubuntu-xenial-ovh-gra1-0001066278 nova-compute[20206]: Logout of [sid: 1, target: iqn.2010-10.org.openstack:volume-2a48ae08-2833-488c-8771-eea86f41c7b8, portal: 149.202.185.218,3260] successful.

Maybe that's the race? Is data in the primary node (where the volume "lives") old?