test_volume_extend fails with timeout error

[Armando Migliaccio]

This failure has been observed in the gate:

http://logs.openstack.org/24/123624/3/check/check-tempest-dsvm-neutron-full-2/5cad17d/logs/testr_results.html.gz

The stacktrace is:

Traceback (most recent call last):
  File "tempest/api/volume/test_volumes_extend.py", line 34, in test_volume_extend
    self.volume = self.create_volume()
  File "tempest/api/volume/base.py", line 103, in create_volume
    cls.volumes_client.wait_for_volume_status(volume['id'], 'available')
  File "tempest/services/volume/json/volumes_client.py", line 181, in wait_for_volume_status
    raise exceptions.TimeoutException(message)
TimeoutException: Request timed out
Details: Volume ab3d0a31-4aa7-463b-90f0-6b17daef2cc6 failed to reach available status within the required time (196 s).

On test:

test_volume_extend

[John Griffith (john-griffith)]

Where can I find actual logs for this run?

[Armando Migliaccio (armando-migliaccio)]

My apologies, I thought it was implied there were in:

http://logs.openstack.org/24/123624/3/check/check-tempest-dsvm-neutron-full-2/5cad17d

Is that what you're looking for?

[John Griffith (john-griffith)]

@Armando
Thanks!! For some reason I couldn't extract them from the link you gave.

[John Griffith (john-griffith)]

Wow! So we're just completely blowing the timeout here it looks like. Tracing the volume-create in the c-vol log the create comes in and does complete succesfully; however.... it looks like just the create is taking over 3 minutes??

Start of create process:
http://logs.openstack.org/24/123624/3/check/check-tempest-dsvm-neutron-full-2/5cad17d/logs/screen-c-vol.txt.gz#_2014-10-01_18_57_37_592

Completion and update to success:
http://logs.openstack.org/24/123624/3/check/check-tempest-dsvm-neutron-full-2/5cad17d/logs/screen-c-vol.txt.gz#_2014-10-01_19_00_54_426

seems like we're crushing the Instance maybe, trying to figure out how/why the create is all hung up.

[John Griffith (john-griffith)]

BTW, I started poking around kernel and syslogs to see if I could find any hints to why an lvcreate that normally takes a second or two is taking over 3 minutes and there's all sorts of ugliness going on:

http://logs.openstack.org/24/123624/3/check/check-tempest-dsvm-neutron-full-2/5cad17d/logs/kern_log.txt.gz#_Oct__1_18_52_49

and

http://logs.openstack.org/24/123624/3/check/check-tempest-dsvm-neutron-full-2/5cad17d/logs/syslog.txt.gz#_Oct__1_18_46_27

[Mike Perez (thingee)]

Pretty sure this is related to https://bugs.launchpad.net/cinder/+bug/1376941

[Ghanshyam Mann (ghanshyammann)]

From above analysis, it looks like nothing to do with tempest. Please feel free to open in case of any tempest update required.

[Sean McGinnis (sean-mcginnis)]

Closing stale bug. If this is still an issue please reopen.