yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1788006] Re: neutron_tempest_plugin DNS integration tests fail with "Server [UUID] failed to reach ACTIVE status and task state "None" within the required time ([INTEGER] s). Current status: BUILD. Current task state: spawning."

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Miguel Lavalle <miguel@xxxxxxxxxxxx>
Date: Sun, 26 Aug 2018 23:14:51 -0000
Reply-to: Bug 1788006 <1788006@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
In the execution of DNSIntegrationTests:test_server_with_fip
(https://github.com/openstack/neutron-tempest-
plugin/blob/master/neutron_tempest_plugin/scenario/test_dns_integration.py#L113):

1) The instance ID 9797a641-8925-4f74-abbf-c6111d47f91d has a port with
ID e14bdbb1-ca9a-44b8-9f3b-a296f01a71fd

2) Once the instance POST succeeds, the test waits for it to become
active: https://github.com/openstack/neutron-tempest-
plugin/blob/master/neutron_tempest_plugin/scenario/test_dns_integration.py#L92

3) In the Tempest log we can see that the wait for the instance to
become active timeouts and a request to delete it is sent. Note that the
instance never gets IP addresses:

2018-08-20 13:04:52,793 2367 INFO     [tempest.lib.common.rest_client] Request (DNSIntegrationTests:test_server_with_fip): 200 GET http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d 0.227s
2018-08-20 13:04:52,794 2367 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {u'content-type': 'application/json', 'content-location': 'http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d', u'date': 'Mon, 20 Aug 2018 13:04:52 GMT', u'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', u'x-openstack-request-id': 'req-df98af82-58fa-47a9-83b8-85f840184577', u'x-compute-request-id': 'req-df98af82-58fa-47a9-83b8-85f840184577', u'content-length': '1328', u'connection': 'close', 'status': '200', u'openstack-api-version': 'compute 2.1', u'x-openstack-nova-api-version': '2.1', u'server': 'Apache/2.4.18 (Ubuntu)'}
        Body: {"server": {"OS-EXT-STS:task_state": "spawning", "addresses": {}, "links": [{"href": "http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d";, "rel": "self"}, {"href": "http://213.32.74.39/compute/servers/9797a641-8925-4f74-abbf-c6111d47f91d";, "rel": "bookmark"}], "image": {"id": "4613d815-8eed-440c-a630-85a91292514c", "links": [{"href": "http://213.32.74.39/compute/images/4613d815-8eed-440c-a630-85a91292514c";, "rel": "bookmark"}]}, "OS-EXT-STS:vm_state": "building", "OS-SRV-USG:launched_at": null, "flavor": {"id": "d1", "links": [{"href": "http://213.32.74.39/compute/flavors/d1";, "rel": "bookmark"}]}, "id": "9797a641-8925-4f74-abbf-c6111d47f91d", "security_groups": [{"name": "default"}], "user_id": "4abf0780c8a04aefa22e94d055d6d082", "OS-DCF:diskConfig": "MANUAL", "accessIPv4": "", "accessIPv6": "", "progress": 0, "OS-EXT-STS:power_state": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "status": "BUILD", "updated": "2018-08-20T12:51:50Z", "hostId": "a771a3451772b8b848f9f12576e3243ea69e9ca77ccf82c66d34aa0e", "OS-SRV-USG:terminated_at": null, "key_name": "tempest-keypair-test-832974923", "name": "tempest-server-test-1466220015", "created": "2018-08-20T12:51:48Z", "tenant_id": "df130fc6f8a64ab1b877c39e32e8a1d6", "os-extended-volumes:volumes_attached": [], "metadata": {}}}

2018-08-20 13:04:53,178 2367 INFO     [tempest.lib.common.rest_client] Request (DNSIntegrationTests:_run_cleanups): 204 DELETE http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d 0.376s
2018-08-20 13:04:53,179 2367 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {u'content-type': 'application/json', 'content-location': 'http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d', u'date': 'Mon, 20 Aug 2018 13:04:52 GMT', u'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', u'x-openstack-request-id': 'req-09c5d432-d8f3-4504-a08e-4dc3b8f102b8', u'x-compute-request-id': 'req-09c5d432-d8f3-4504-a08e-4dc3b8f102b8', u'connection': 'close', 'status': '204', u'openstack-api-version': 'compute 2.1', u'x-openstack-nova-api-version': '2.1', u'server': 'Apache/2.4.18 (Ubuntu)'}
        Body: 
2018-08-20 13:04:53,404 2367 INFO     [tempest.lib.common.rest_client] Request (DNSIntegrationTests:_run_cleanups): 200 GET http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d 0.224s
2018-08-20 13:04:53,404 2367 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {u'content-type': 'application/json', 'content-location': 'http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d', u'date': 'Mon, 20 Aug 2018 13:04:53 GMT', u'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', u'x-openstack-request-id': 'req-6ffd3610-e711-4607-bd4e-44e6d341bddb', u'x-compute-request-id': 'req-6ffd3610-e711-4607-bd4e-44e6d341bddb', u'content-length': '1328', u'connection': 'close', 'status': '200', u'openstack-api-version': 'compute 2.1', u'x-openstack-nova-api-version': '2.1', u'server': 'Apache/2.4.18 (Ubuntu)'}
        Body: {"server": {"OS-EXT-STS:task_state": "deleting", "addresses": {}, "links": [{"href": "http://213.32.74.39/compute/v2.1/servers/9797a641-8925-4f74-abbf-c6111d47f91d";, "rel": "self"}, {"href": "http://213.32.74.39/compute/servers/9797a641-8925-4f74-abbf-c6111d47f91d";, "rel": "bookmark"}], "image": {"id": "4613d815-8eed-440c-a630-85a91292514c", "links": [{"href": "http://213.32.74.39/compute/images/4613d815-8eed-440c-a630-85a91292514c";, "rel": "bookmark"}]}, "OS-EXT-STS:vm_state": "building", "OS-SRV-USG:launched_at": null, "flavor": {"id": "d1", "links": [{"href": "http://213.32.74.39/compute/flavors/d1";, "rel": "bookmark"}]}, "id": "9797a641-8925-4f74-abbf-c6111d47f91d", "security_groups": [{"name": "default"}], "user_id": "4abf0780c8a04aefa22e94d055d6d082", "OS-DCF:diskConfig": "MANUAL", "accessIPv4": "", "accessIPv6": "", "progress": 0, "OS-EXT-STS:power_state": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "status": "BUILD", "updated": "2018-08-20T13:04:53Z", "hostId": "a771a3451772b8b848f9f12576e3243ea69e9ca77ccf82c66d34aa0e", "OS-SRV-USG:terminated_at": null, "key_name": "tempest-keypair-test-832974923", "name": "tempest-server-test-1466220015", "created": "2018-08-20T12:51:48Z", "tenant_id": "df130fc6f8a64ab1b877c39e32e8a1d6", "os-extended-volumes:volumes_attached": [], "metadata": {}}}

4) Neutron communicates to Nova vif plugged event:

Aug 20 12:52:07.629196 ubuntu-xenial-ovh-gra1-0001411231 neutron-
server[18781]: INFO neutron.notifiers.nova [-] Nova event response:
{u'status': u'completed', u'tag': u'e14bdbb1-ca9a-44b8-9f3b-
a296f01a71fd', u'name': u'network-vif-plugged', u'server_uuid':
u'9797a641-8925-4f74-abbf-c6111d47f91d', u'code': 200}

5) Nova acknowledges receiving vif plugged event:

Aug 20 12:52:07.628960 ubuntu-xenial-ovh-gra1-0001411231 nova-
compute[27062]: DEBUG nova.compute.manager [None req-633098b6-6b29-473b-
a7d1-76fbf8648e7b service nova] [instance: 9797a641-8925-4f74-abbf-
c6111d47f91d] Processing event network-vif-plugged-e14bdbb1-ca9a-44b8
-9f3b-a296f01a71fd {{(pid=27062) _process_instance_event
/opt/stack/nova/nova/compute/manager.py:7959}}

6) However, the Nova API never communicates (as indicated in point 3)
that the instance's vif has IP addresses

** Changed in: neutron
   Importance: Undecided => High

** Also affects: nova
   Importance: Undecided
       Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1788006

Title:
  neutron_tempest_plugin DNS integration tests fail with "Server [UUID]
  failed to reach ACTIVE status and task state "None" within the
  required time ([INTEGER] s). Current status: BUILD. Current task
  state: spawning."

Status in neutron:
  Confirmed
Status in OpenStack Compute (nova):
  New

Bug description:
  Testr report: http://logs.openstack.org/74/591074/4/check/neutron-
  tempest-plugin-designate-scenario/d02f171/testr_results.html.gz

  Job log: http://logs.openstack.org/74/591074/4/check/neutron-tempest-
  plugin-designate-scenario/d02f171/job-
  output.txt.gz#_2018-08-20_13_11_46_407077

  Traceback:

  2018-08-20 13:11:46.406514 | controller | Captured traceback:
  2018-08-20 13:11:46.406538 | controller | ~~~~~~~~~~~~~~~~~~~
  2018-08-20 13:11:46.406567 | controller |     Traceback (most recent call last):
  2018-08-20 13:11:46.406659 | controller |       File "/opt/stack/neutron-tempest-plugin/neutron_tempest_plugin/scenario/test_dns_integration.py", line 115, in test_server_with_fip
  2018-08-20 13:11:46.406696 | controller |         server = self._create_server(name=name)
  2018-08-20 13:11:46.406771 | controller |       File "/opt/stack/neutron-tempest-plugin/neutron_tempest_plugin/scenario/test_dns_integration.py", line 94, in _create_server
  2018-08-20 13:11:46.406799 | controller |         constants.SERVER_STATUS_ACTIVE)
  2018-08-20 13:11:46.406844 | controller |       File "tempest/common/waiters.py", line 96, in wait_for_server_status
  2018-08-20 13:11:46.406893 | controller |         raise lib_exc.TimeoutException(message)
  2018-08-20 13:11:46.406938 | controller |     tempest.lib.exceptions.TimeoutException: Request timed out
  2018-08-20 13:11:46.407077 | controller |     Details: (DNSIntegrationTests:test_server_with_fip) Server 9797a641-8925-4f74-abbf-c6111d47f91d failed to reach ACTIVE status and task state "None" within the required time (784 s). Current status: BUILD. Current task state: spawning.

  Logstash link:
  http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22DNSIntegrationTests%3Atest_server_with_fip%5C%22%20AND%20%20%20message%3A%5C%22failed%20to%20reach%20ACTIVE%20status%20and%20task%20state%5C%22%20AND%20%20%20tags%3A%5C%22console%5C%22

  40 hits in 7 days, all failures

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1788006/+subscriptions
References

[Bug 1788006] [NEW] neutron_tempest_plugin DNS integration tests fail with "Server [UUID] failed to reach ACTIVE status and task state "None" within the required time ([INTEGER] s). Current status: BUILD. Current task state: spawning."
From: Nate Johnston, 2018-08-20