test_encrypted_cinder_volumes_cryptsetup times out waiting for volume to be available
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
OpenStack Compute (nova) |
Confirmed
|
High
|
Unassigned | ||
Icehouse |
New
|
Critical
|
Unassigned |
Bug Description
2014-07-24 01:07:09.116 | tempest.
2014-07-24 01:07:09.116 | -------
2014-07-24 01:07:09.116 |
2014-07-24 01:07:09.116 | Captured traceback:
2014-07-24 01:07:09.117 | ~~~~~~~~~~~~~~~~~~~
2014-07-24 01:07:09.117 | Traceback (most recent call last):
2014-07-24 01:07:09.117 | File "tempest/test.py", line 128, in wrapper
2014-07-24 01:07:09.117 | return f(self, *func_args, **func_kwargs)
2014-07-24 01:07:09.117 | File "tempest/
2014-07-24 01:07:09.117 | self.attach_
2014-07-24 01:07:09.117 | File "tempest/
2014-07-24 01:07:09.117 | self.nova_
2014-07-24 01:07:09.117 | File "tempest/
2014-07-24 01:07:09.117 | self._wait_
2014-07-24 01:07:09.117 | File "tempest/
2014-07-24 01:07:09.117 | self.volume_
2014-07-24 01:07:09.118 | File "tempest/
2014-07-24 01:07:09.118 | not_found_
2014-07-24 01:07:09.118 | File "tempest/
2014-07-24 01:07:09.118 | raise exceptions.
2014-07-24 01:07:09.118 | TimeoutException: Request timed out
2014-07-24 01:07:09.118 | Details: Timed out waiting for thing 4ef6a14a-
I've actually been seeing this out of tree in our internal CI also but thought it was just us or our slow VMs, this is the first I've seen it upstream.
From the traceback in the console log, it looks like the volume does get to available status because it doesn't get out of that state when tempest is trying to delete the volume on tear down.
tags: | added: volumes |
tags: | added: testing |
Changed in nova: | |
milestone: | none → juno-3 |
status: | Fix Committed → Fix Released |
Changed in cinder: | |
status: | New → Fix Committed |
tags: | added: icehouse-backport-potential |
Changed in nova: | |
importance: | Undecided → Critical |
Nothing is really jumping out at me from the cinder volume log, there aren't errors in the c-vol log for 4ef6a14a- 3fce-417f- aa13-5aab178943 6e, there are warnings about quotas but those are probably not related since they are usage deprecation warnings.
The cinder-api log has a lot of traces of this though:
2014-07-24 00:37:57.499 21230 ERROR cinder. volume. volume_ types [req-fb6bda10- 61d3-4cee- 9855-0b602eb23e b7 7a9c74f73e4645d 48d83d22735da64 98 a7b5b2c20c324ab e8d81ed6a877327 31 - - -] Default volume type is not found, please check default_volume_type config: Volume type with name lvm could not be found. volume. volume_ types Traceback (most recent call last): volume. volume_ types File "/opt/stack/ new/cinder/ cinder/ volume/ volume_ types.py" , line 128, in get_default_ volume_ type volume. volume_ types vol_type = get_volume_ type_by_ name(ctxt, name) volume. volume_ types File "/opt/stack/ new/cinder/ cinder/ volume/ volume_ types.py" , line 117, in get_volume_ type_by_ name volume. volume_ types return db.volume_ type_get_ by_name( context, name) volume. volume_ types File "/opt/stack/ new/cinder/ cinder/ db/api. py", line 379, in volume_ type_get_ by_name volume. volume_ types return IMPL.volume_ type_get_ by_name( context, name) volume. volume_ types File "/opt/stack/ new/cinder/ cinder/ db/sqlalchemy/ api.py" , line 161, in wrapper volume. volume_ types return f(*args, **kwargs) volume. volume_ types File "/opt/stack/ new/cinder/ cinder/ db/sqlalchemy/ api.py" , line 1836, in volume_ type_get_ by_name volume. volume_ types return _volume_ type_get_ by_name( context, name) volume. volume_ types File "/opt/stack/ new/cinder/ cinder/ db/sqlalchemy/ api.py" , line 161, in wrapper volume. volume_ types return f(*args, **kwargs) volume. volume_ types File "/opt/stack/ new/cinder/ cinder/ db/sqlalchemy/ api.py" , line 1827, in _volume_ type_get_ by_name volume. volume_ types raise exception. VolumeTypeNotFo undByName( volume_ type_name= name) volume. volume_ types VolumeTypeNotFo undByName: Volume type with name lvm could not be found. volume. volume_ types
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
2014-07-24 00:37:57.499 21230 TRACE cinder.
I'm not sure if that's related, or somehow causing things to slow down, but it looks bad for sure.