failed to reach RESCUE status and task state "None" within the required time

[Jamie Lennox]

2014-01-28 06:12:32.060 | Traceback (most recent call last):
2014-01-28 06:12:32.060 | File "tempest/api/compute/servers/test_server_rescue.py", line 172, in test_rescued_vm_detach_volume
2014-01-28 06:12:32.060 | self.volume_to_detach['id'], 'in-use')
2014-01-28 06:12:32.060 | File "tempest/services/compute/json/volumes_extensions_client.py", line 102, in wait_for_volume_status
2014-01-28 06:12:32.060 | raise exceptions.TimeoutException(message)
2014-01-28 06:12:32.060 | TimeoutException: Request timed out
2014-01-28 06:12:32.061 | Details: Volume test_detach failed to reach in-use status within the required time (196 s).

2014-01-28 06:12:31.817 | FAIL: tempest.api.compute.servers.test_server_rescue.ServerRescueTestJSON.test_rescued_vm_detach_volume[gate,negative]
2014-01-28 06:12:31.817 | tempest.api.compute.servers.test_server_rescue.ServerRescueTestJSON.test_rescued_vm_detach_volume[gate,negative]

http://logs.openstack.org/41/67441/3/gate/gate-tempest-dsvm-full/8110d64/console.html

[Matt Riedemann (mriedem)]

The error message has changed a bit:

http://logs.openstack.org/77/74977/3/gate/gate-tempest-dsvm-full/485d630/console.html

2014-02-25 11:23:12.736 | Traceback (most recent call last):
2014-02-25 11:23:12.736 | File "tempest/api/compute/v3/servers/test_server_rescue.py", line 144, in test_rescued_vm_detach_volume
2014-02-25 11:23:12.736 | self.servers_client.wait_for_server_status(self.server_id, 'RESCUE')
2014-02-25 11:23:12.736 | File "tempest/services/compute/v3/json/servers_client.py", line 165, in wait_for_server_status
2014-02-25 11:23:12.736 | raise_on_error=raise_on_error)
2014-02-25 11:23:12.736 | File "tempest/common/waiters.py", line 89, in wait_for_server_status
2014-02-25 11:23:12.736 | raise exceptions.TimeoutException(message)
2014-02-25 11:23:12.736 | TimeoutException: Request timed out
2014-02-25 11:23:12.736 | Details: Server 6e55cbea-7b47-462c-8bed-649ec36d3292 failed to reach RESCUE status and task state "None" within the required time (196 s). Current status: ACTIVE. Current task state: rescuing.

[Matt Riedemann (mriedem)]

36 hits in the last 7 days:

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiU2VydmVyXCIgQU5EIG1lc3NhZ2U6XCJmYWlsZWQgdG8gcmVhY2ggUkVTQ1VFIHN0YXR1cyBhbmQgdGFzayBzdGF0ZSBcXFwiTm9uZVxcXCIgd2l0aGluIHRoZSByZXF1aXJlZCB0aW1lXCIgQU5EIG1lc3NhZ2U6XCJDdXJyZW50IHN0YXR1czogQUNUSVZFLiBDdXJyZW50IHRhc2sgc3RhdGU6IHJlc2N1aW5nLlwiIEFORCBmaWxlbmFtZTpcImNvbnNvbGUuaHRtbFwiIiwiZmllbGRzIjpbXSwib2Zmc2V0IjowLCJ0aW1lZnJhbWUiOiI2MDQ4MDAiLCJncmFwaG1vZGUiOiJjb3VudCIsInRpbWUiOnsidXNlcl9pbnRlcnZhbCI6MH0sInN0YW1wIjoxMzkzMzU1NjgwMzQ4fQ==

[Matt Riedemann (mriedem)]

Maybe related to bug 1254772.

[Matt Riedemann (mriedem)]

From the n-cpu logs it looks like it's doing image cache updates when this fails, but there are no errors in the logs.

[Matt Riedemann (mriedem)]

e-r query patch: https://review.openstack.org/#/c/76335/

[Zhikun Liu (zhikunliu)]

Got the same problem: http://logs.openstack.org/74/96674/2/check/check-tempest-dsvm-full/9384da3/console.html.gz

2014-05-30 10:37:01.022 | {0} tempest.api.compute.v3.servers.test_server_rescue_negative.ServerRescueNegativeV3Test.test_rescued_vm_detach_volume [197.475501s] ... FAILED
2014-05-30 10:37:01.022 |
2014-05-30 10:37:01.022 | Captured traceback:
2014-05-30 10:37:01.022 | ~~~~~~~~~~~~~~~~~~~
2014-05-30 10:37:01.022 | Traceback (most recent call last):
2014-05-30 10:37:01.022 | File "tempest/api/compute/v3/servers/test_server_rescue_negative.py", line 127, in test_rescued_vm_detach_volume
2014-05-30 10:37:01.022 | self.volumes_client.wait_for_volume_status(self.volume['id'], 'in-use')
2014-05-30 10:37:01.022 | File "tempest/services/volume/json/volumes_client.py", line 169, in wait_for_volume_status
2014-05-30 10:37:01.022 | raise exceptions.TimeoutException(message)
2014-05-30 10:37:01.022 | TimeoutException: Request timed out
2014-05-30 10:37:01.022 | Details: Volume 2483e089-ebe1-45ee-bcf8-9c9aa7832d88 failed to reach in-use status within the required time (196 s).

[Joe Gordon (jogo)]

no hits anymore either the bug was fixed or the fingerprint changed