CI pingtest fails to create test instance

[Gabriele Cerami]

today's periodic jobs are failing after deploy while performing ping test

The test instance cannot be created. This is the error

2017-02-02 08:13:20.655739 | tenant-stack.server1:
2017-02-02 08:13:20.655813 | resource_type: OS::Nova::Server
2017-02-02 08:13:20.655854 | physical_resource_id: baf5bb05-1443-46be-8644-9b541049dd22
2017-02-02 08:13:20.655878 | status: CREATE_FAILED
2017-02-02 08:13:20.655913 | status_reason: |
2017-02-02 08:13:20.656005 | NotFound: resources.server1: Instance baf5bb05-1443-46be-8644-9b541049dd22 could not be found. (HTTP 404) (Request-ID: req-6a9269c7-e92a-4210-8add-62605ffe8a0f)

complete log is at http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/632c7f2/console.html#_2017-02-02_08_13_20_655739

[Gabriele Cerami (gcerami)]

overcloud novacompute logs starting at

http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/632c7f2/logs/overcloud-novacompute-0/var/log/nova/nova-compute.txt.gz#_2017-02-02_08_13_29_759

contain

2017-02-02 08:13:29.759 17517 INFO nova.compute.manager [req-dc1029b5-bb22-4cc9-b0be-6aa931880152 - - - - -] [instance: baf5bb05-1443-46be-8644-9b541049dd22] Failed to process external instance event network-changed due to: Info cache for instance baf5bb05-1443-46be-8644-9b541049dd22 could not be found.
Traceback (most recent call last):

  File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 92, in _object_dispatch
    return getattr(target, method)(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 226, in wrapper
    return fn(self, *args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/objects/instance_info_cache.py", line 111, in refresh
    self.instance_uuid)

  File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 184, in wrapper
    result = fn(cls, context, *args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/objects/instance_info_cache.py", line 72, in get_by_instance_uuid
    instance_uuid=instance_uuid)

InstanceInfoCacheNotFound: Info cache for instance baf5bb05-1443-46be-8644-9b541049dd22 could not be found.

[Gabriele Cerami (gcerami)]

Another error in the same log at

http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/632c7f2/logs/overcloud-novacompute-0/var/log/nova/nova-compute.txt.gz#_2017-02-02_07_41_23_041

ERROR nova.compute.manager [req-4c2f5758-1333-46f4-aab9-149ef70033fb - - - - -] No compute node record for host overcloud-novacompute-0.localdomain

[Oliver Walsh (owalsh)]

Nova API returned 404 for the instance:
http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/632c7f2/logs/overcloud-controller-0/var/log/nova/nova-api.txt.gz#_2017-02-02_08_12_45_325

It had not started building it yet:
http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/632c7f2/logs/overcloud-novacompute-0/var/log/nova/nova-compute.txt.gz#_2017-02-02_08_12_47_089

Looks like the race condition in nova we hit in the undercloud. This bug is tracking it AFAIK https://bugs.launchpad.net/nova/+bug/1660878

[Dan Smith (danms)]

Just FYI, the "no compute node record" message is not a concerning error as long as you see "service record created" just after it:

http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/632c7f2/logs/overcloud-novacompute-0/var/log/nova/nova-compute.txt.gz#_2017-02-02_07_41_23_183

and especially if you see resource update messages complete successfully after that.

[Alfredo Moralejo (amoralej)]

I guess this is a duplicate of https://bugs.launchpad.net/nova/+bug/1661360

[Gabriele Cerami (gcerami)]

I've opened this duplicate bug 9 hours before the original. But anyway, I see there is no work going forward here, and only the other is referenced. Marking as invalid.

[Brent Eagles (beagles)]

Removing milestone since this is marked invalid - if you have reason that this is still valid, please change status and re-add milestone.