(TestVolumeBootPattern:_run_cleanups) Failed to delete volume within the required time

[Matt Riedemann]

I'm opening this separately from bug 1373513 since I'm not seeing the blocked message in syslog.

Tempest timed out on volume delete here:

http://logs.openstack.org/90/131490/4/gate/gate-grenade-dsvm-partial-ncpu/0537e3b/logs/grenade.sh.txt.gz#_2014-11-25_03_44_48_217

There is a 3 minute hang in the cinder volume logs between delete here:

http://logs.openstack.org/90/131490/4/gate/gate-grenade-dsvm-partial-ncpu/0537e3b/logs/old/screen-c-vol.txt.gz#_2014-11-25_03_41_22_466

And when the volume uuid is mentioned again here:

http://logs.openstack.org/90/131490/4/gate/gate-grenade-dsvm-partial-ncpu/0537e3b/logs/old/screen-c-vol.txt.gz#_2014-11-25_03_44_41_032

Just using the timeout in tempest, there are 94 hits in 7 days, check and gate, all failures:

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiKFRlc3RWb2x1bWVCb290UGF0dGVybjpfcnVuX2NsZWFudXBzKSBGYWlsZWQgdG8gZGVsZXRlIHZvbHVtZVwiIEFORCBtZXNzYWdlOlwid2l0aGluIHRoZSByZXF1aXJlZCB0aW1lXCIgQU5EIHRhZ3M6XCJjb25zb2xlXCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjYwNDgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjE0MTY5MjYwMDY1NTZ9

[Matt Riedemann (mriedem)]

e-r query: https://review.openstack.org/137090

[Matt Riedemann (mriedem)]

This command took ~50 seconds:

2014-11-25 03:41:48.993 7804 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C vgs --noheadings --unit=g -o name,size,free,lv_count,uuid --separator : --nosuffix stack-volumes-lvmdriver-1 execute /opt/stack/old/cinder/cinder/openstack/common/processutils.py:158

[Matt Riedemann (mriedem)]

This command took almost 2 minutes:

2014-11-25 03:42:44.858 7804 DEBUG cinder.openstack.common.processutils [req-81b41283-0928-4572-891e-c45ef4667e64 4eb70d740cda49618ccb9ac9b64ca824 5a2e289cbd224a84a78f496717d98684 - - -] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C lvs --noheadings --unit=g -o vg_name,name,size --nosuffix stack-volumes-lvmdriver-1 execute /opt/stack/old/cinder/cinder/openstack/common/processutils.py:158

So between that and the vgs call in comment 2 that's the 3 minute gap we have.

[Matt Riedemann (mriedem)]

Can we fork a subprocess to run the lvs/vgs calls in these cases in case there is a periodic task hitting this at the same time?

[Matt Riedemann (mriedem)]

Tempest patch to propose skipping test_volume_boot_pattern until this is fixed:

https://review.openstack.org/137096

[Matt Riedemann (mriedem)]

I just noticed that the e-r query for bug 1373513 has an OR with the same query as I wrote for this bug, so let's just track the one bug.