test_reboot_pinned_server should wait for server to come back ACTIVE

Bug #1572197 reported by Waldemar Znoinski on 2016-04-19
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
intel-nfv-ci-tests
Undecided
Waldemar Znoinski

Bug Description

when testing rebooting of a server a race condition occurs sometimes

1. request to reboot HARD
2016-04-19 14:42:33.062 24414 INFO tempest.lib.common.rest_client [req-61fcfe57-53a7-4cbf-a7e1-8155294406a7 ] Request (CPUPolicyTest:test_reboot_pinned_server): 202 POST http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629/action 0.161s
2016-04-19 14:42:33.062 24414 DEBUG tempest.lib.common.rest_client [req-61fcfe57-53a7-4cbf-a7e1-8155294406a7 ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: {"reboot": {"type": "HARD"}}

2. checking status: HARD_REBOOT

2016-04-19 14:42:33.132 24414 INFO tempest.lib.common.rest_client [req-f5415cd1-4dc8-4a5f-be45-329eecaa24f0 ] Request (CPUPolicyTest:test_reboot_pinned_server): 200 GET http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629 0.069s
2016-04-19 14:42:33.132 24414 DEBUG tempest.lib.common.rest_client [req-f5415cd1-4dc8-4a5f-be45-329eecaa24f0 ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'status': '200', 'content-length': '1583', 'content-location': 'http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629', 'x-compute-request-id': 'req-f5415cd1-4dc8-4a5f-be45-329eecaa24f0', 'vary': 'X-OpenStack-Nova-API-Version',
'connection': 'close', 'x-openstack-nova-api-version': '2.1', 'date': 'Tue, 19 Apr 2016 14:42:33 GMT', 'content-type': 'application/json'}
        Body: {"server": {"status": "HARD_REBOOT", "updated": "2016-04-19T14:42:33Z", "hostId": "77ad4e027a52afb981d2f56e14b1d7fe877473f9d5cb3962969a2c46", "OS-EXT-SRV-ATTR:host": "ubuntu", "addresses": {"private": [{"OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:76:f8:7f", "versi
on": 4, "addr": "10.1.12.9", "OS-EXT-IPS:type": "fixed"}]}, "links": [{"href": "http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629", "rel": "self"}, {"href": "http://127.0.0.1:8774/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629", "rel": "bookmark"}], "
key_name": null, "image": {"id": "8763180f-ecec-492f-9671-9b7cca8963dd", "links": [{"href": "http://127.0.0.1:8774/images/8763180f-ecec-492f-9671-9b7cca8963dd", "rel": "bookmark"}]}, "OS-EXT-STS:task_state": "rebooting_hard", "OS-EXT-STS:vm_state": "active", "OS-EXT-SRV-
ATTR:instance_name": "instance-000000b8", "OS-SRV-USG:launched_at": "2016-04-19T14:42:31.000000", "OS-EXT-SRV-ATTR:hypervisor_hostname": "ubuntu", "flavor": {"id": "30736933", "links": [{"href": "http://127.0.0.1:8774/flavors/30736933", "rel": "bookmark"}]}, "id": "84ab01ac-8d94-4cc8-83a5-287c8e0aa629", "security_groups": [{"name": "default"}], "OS-SRV-USG:terminated_at": null, "OS-EXT-AZ:availability_zone": "nova", "user_id": "8fa7afb29697452fa04ce29f0290fb76", "name": "tempest.common.compute-instance-423347370", "created": "2016-04-19
T14:42:27Z", "tenant_id": "167fbb1b36e74238b9aa206c09ed26f6", "OS-DCF:diskConfig": "MANUAL", "os-extended-volumes:volumes_attached": [], "accessIPv4": "", "accessIPv6": "", "OS-EXT-STS:power_state": 1, "config_drive": "True", "metadata": {}}} _log_request_full tempest/li
b/common/rest_client.py:414

3. cleanup request to DELETE instance
2016-04-19 14:42:33.326 24414 INFO tempest.lib.common.rest_client [req-a35c5085-9059-4b24-a475-c98aa046502d ] Request (CPUPolicyTest:_run_cleanups): 204 DELETE http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629 0.183s
2016-04-19 14:42:33.327 24414 DEBUG tempest.lib.common.rest_client [req-a35c5085-9059-4b24-a475-c98aa046502d ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'status': '204', 'content-length': '0', 'x-compute-request-id': 'req-a35c5085-9059-4b24-a475-c98aa046502d', 'vary': 'X-OpenStack-Nova-API-Version', 'connection': 'close', 'x-openstack-nova-api-version': '2.1', 'date': 'Tue, 19 Apr 2016 14:42:33 G
MT', 'content-type': 'application/json'}

4. conflicting instance state:
expected: u'reboot_pending_hard
actual: u'deleting

2016-04-19 14:42:35.279 24414 INFO tempest.lib.common.rest_client [req-2d1634dc-6bd7-445d-bcb8-704ed4e81cdc ] Request (CPUPolicyTest:tearDownClass): 200 GET http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629 0.076s
2016-04-19 14:42:35.279 24414 DEBUG tempest.lib.common.rest_client [req-2d1634dc-6bd7-445d-bcb8-704ed4e81cdc ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'status': '200', 'content-length': '3308', 'content-location': 'http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629', 'x-compute-request-id': 'req-2d1634dc-6bd7-445d-bcb8-704ed4e81cdc', 'vary': 'X-OpenStack-Nova-API-Version',
'connection': 'close', 'x-openstack-nova-api-version': '2.1', 'date': 'Tue, 19 Apr 2016 14:42:35 GMT', 'content-type': 'application/json'}
        Body: {"server": {"status": "ERROR", "updated": "2016-04-19T14:42:34Z", "hostId": "77ad4e027a52afb981d2f56e14b1d7fe877473f9d5cb3962969a2c46", "OS-EXT-SRV-ATTR:host": "ubuntu", "addresses": {"private": [{"OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:76:f8:7f", "version": 4
, "addr": "10.1.12.9", "OS-EXT-IPS:type": "fixed"}]}, "links": [{"href": "http://127.0.0.1:8774/v2.1/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629", "rel": "self"}, {"href": "http://127.0.0.1:8774/servers/84ab01ac-8d94-4cc8-83a5-287c8e0aa629", "rel": "bookmark"}], "key_na
me": null, "image": {"id": "8763180f-ecec-492f-9671-9b7cca8963dd", "links": [{"href": "http://127.0.0.1:8774/images/8763180f-ecec-492f-9671-9b7cca8963dd", "rel": "bookmark"}]}, "OS-EXT-STS:task_state": "deleting", "OS-EXT-STS:vm_state": "error", "OS-EXT-SRV-ATTR:instance
_name": "instance-000000b8", "OS-SRV-USG:launched_at": "2016-04-19T14:42:31.000000", "OS-EXT-SRV-ATTR:hypervisor_hostname": "ubuntu", "flavor": {"id": "30736933", "links": [{"href": "http://127.0.0.1:8774/flavors/30736933", "rel": "bookmark"}]}, "id": "84ab01ac-8d94-4cc8
-83a5-287c8e0aa629", "security_groups": [{"name": "default"}], "OS-SRV-USG:terminated_at": null, "OS-EXT-AZ:availability_zone": "nova", "user_id": "8fa7afb29697452fa04ce29f0290fb76", "name": "tempest.common.compute-instance-423347370", "created": "2016-04-19T14:42:27Z",
"tenant_id": "167fbb1b36e74238b9aa206c09ed26f6", "OS-DCF:diskConfig": "MANUAL", "os-extended-volumes:volumes_attached": [], "accessIPv4": "", "accessIPv6": "", "fault": {"message": "Conflict updating instance 84ab01ac-8d94-4cc8-83a5-287c8e0aa629. Expected: {'task_state':
 [u'reboot_pending_hard']}. Actual: {'task_state': u'deleting'}", "code": 500, "details": " File \"/opt/stack/new/nova/nova/compute/manager.py\", line 366, in decorated_function\n return function(self, context, *args, **kwargs)\n File \"/opt/stack/new/nova/nova/comp
ute/manager.py\", line 3084, in reboot_instance\n self._set_instance_obj_error_state(context, instance)\n File \"/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py\", line 220, in __exit__\n self.force_reraise()\n File \"/usr/local/lib/python2.7/dist-p
ackages/oslo_utils/excutils.py\", line 196, in force_reraise\n six.reraise(self.type_, self.value, self.tb)\n File \"/opt/stack/new/nova/nova/compute/manager.py\", line 3060, in reboot_instance\n instance.save(expected_task_state=expected_state)\n File \"/usr/loc
al/lib/python2.7/dist-packages/oslo_versionedobjects/base.py\", line 207, in wrapper\n ctxt, self, fn.__name__, args, kwargs)\n File \"/opt/stack/new/nova/nova/conductor/rpcapi.py\", line 241, in object_action\n objmethod=objmethod, args=args, kwargs=kwargs)\n Fi
le \"/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py\", line 158, in call\n retry=self.retry)\n File \"/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py\", line 90, in _send\n timeout=timeout, retry=retry)\n File \"/usr/local/
lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py\", line 470, in send\n retry=retry)\n File \"/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py\", line 461, in _send\n raise result\n", "created": "2016-04-19T14:42:34Z"},
 "OS-EXT-STS:power_state": 1, "config_drive": "True", "metadata": {}}} _log_request_full tempest/lib/common/rest_client.py:414
2016-04-19 14:42:35.287 24414 ERROR tempest.api.compute.base [-] Waiting for deletion of server 84ab01ac-8d94-4cc8-83a5-287c8e0aa629 failed
2016-04-19 14:42:35.287 24414 ERROR tempest.api.compute.base Traceback (most recent call last):
2016-04-19 14:42:35.287 24414 ERROR tempest.api.compute.base File "tempest/api/compute/base.py", line 148, in clear_servers
2016-04-19 14:42:35.287 24414 ERROR tempest.api.compute.base server['id'])
2016-04-19 14:42:35.287 24414 ERROR tempest.api.compute.base File "tempest/common/waiters.py", line 111, in wait_for_server_termination
2016-04-19 14:42:35.287 24414 ERROR tempest.api.compute.base raise exceptions.BuildErrorException(server_id=server_id)
2016-04-19 14:42:35.287 24414 ERROR tempest.api.compute.base BuildErrorException: Server 84ab01ac-8d94-4cc8-83a5-287c8e0aa629 failed to build and is in ERROR status

5. it looks like lack of waiter after requesting to reboot the server is causing the race condition (server is being cleaned up as the runtime of the code has finished - but the server hasn't shutdown for reboot yet)

Changed in intel-nfv-ci-tests:
assignee: nobody → Waldemar Znoinski (wznoinsk)

Reviewed: https://review.openstack.org/307867
Committed: https://git.openstack.org/cgit/openstack/intel-nfv-ci-tests/commit/?id=8d82cbe0d62a16b547e42a1d1b83054426b543c3
Submitter: Jenkins
Branch: master

commit 8d82cbe0d62a16b547e42a1d1b83054426b543c3
Author: Waldemar Znoinski <email address hidden>
Date: Tue Apr 19 16:16:10 2016 +0100

    add waiter for server to become ACTIVE after reboot

    There looks to be a race condition between server
    reboot request and cleanup fuction that runs when the test finishes.
    This change add explicit waiting for server to be back to 'ACTIVE'
    state after being rebooted.

    Change-Id: I990977e02bd09e59b52ab72cb461aa720b8e2052
    Closes-Bug: #1572197

Changed in intel-nfv-ci-tests:
status: New → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers