Instance fails to spawn in tempest tests

[Salvatore Orlando]

This happened only 3 times in the past 12 hours, so nothing to worry about so far.

Logstash query for the exact failure in [1] available at [2]
I am also seeing more "Timeout waiting for thing" errors (not the same condition as bug 1254890, which affects the large_ops job and is due to nova/neutron chatty interface). Logstash query for this at [3] (13 hits in past 12 hours). I think they might have the same root cause.

[1] http://logs.openstack.org/22/62322/2/check/check-tempest-dsvm-neutron-isolated/cce7146
[2] http://logstash.openstack.org/#eyJzZWFyY2giOiJcImZhaWxlZCB0byByZWFjaCBBQ1RJVkUgc3RhdHVzXCIgQU5EICBcIkN1cnJlbnQgc3RhdHVzOiBCVUlMRFwiIEFORCBcIkN1cnJlbnQgdGFzayBzdGF0ZTogc3Bhd25pbmdcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNDMyMDAiLCJncmFwaG1vZGUiOiJjb3VudCIsInRpbWUiOnsidXNlcl9pbnRlcnZhbCI6MH0sInN0YW1wIjoxMzg3MjIzNzQ0Mjk2fQ==
[3] http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiRGV0YWlsczogVGltZWQgb3V0IHdhaXRpbmcgZm9yIHRoaW5nXCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjQzMjAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTM4NzIyMzg2Mjg1MH0=

[Matt Riedemann (mriedem)]

Looking through the scheduler logs for instance 682be6a5-4b31-43a4-bb11-c884eecebc9b I'm not seeing any errors, the scheduler is trying to place the instance.

From the neutron server logs it looks like it's trying to setup ports for the instance:

2013-12-16 18:54:31.362 7254 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 705f4d7e328b4e79916ec7f8e6c26d6c with project_id : 1967063381b84664b08a693b11d2e95f and roles: _member_,admin _build_user_headers /opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py:932
2013-12-16 18:54:31.363 7254 DEBUG routes.middleware [-] No route matched for GET /ports.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:97
2013-12-16 18:54:31.363 7254 DEBUG routes.middleware [-] Matched GET /ports.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-12-16 18:54:31.363 7254 DEBUG routes.middleware [-] Route path: '/ports{.format}', defaults: {'action': u'index', 'controller': <wsgify at 79741008 wrapping <function resource at 0x4c08758>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-12-16 18:54:31.363 7254 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 79741008 wrapping <function resource at 0x4c08758>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-12-16 18:54:31.374 7254 DEBUG neutron.api.v2.base [req-c9f4e8cb-97e4-499b-80af-98189199b070 705f4d7e328b4e79916ec7f8e6c26d6c 1967063381b84664b08a693b11d2e95f] Policy rule:get_port:allowed_address_pairs not found. Assuming no authZ check is defined for allowed_address_pairs _is_visible /opt/stack/new/neutron/neutron/api/v2/base.py:149
2013-12-16 18:54:31.375 7254 DEBUG neutron.api.v2.base [req-c9f4e8cb-97e4-499b-80af-98189199b070 705f4d7e328b4e79916ec7f8e6c26d6c 1967063381b84664b08a693b11d2e95f] Policy rule:get_port:fixed_ips not found. Assuming no authZ check is defined for fixed_ips _is_visible /opt/stack/new/neutron/neutron/api/v2/base.py:149
2013-12-16 18:54:31.375 7254 DEBUG neutron.api.v2.base [req-c9f4e8cb-97e4-499b-80af-98189199b070 705f4d7e328b4e79916ec7f8e6c26d6c 1967063381b84664b08a693b11d2e95f] Policy rule:get_port:mac_address not found. Assuming no authZ check is defined for mac_address _is_visible /opt/stack/new/neutron/neutron/api/v2/base.py:149
2013-12-16 18:54:31.375 7254 INFO neutron.wsgi [req-c9f4e8cb-97e4-499b-80af-98189199b070 705f4d7e328b4e79916ec7f8e6c26d6c 1967063381b84664b08a693b11d2e95f] 127.0.0.1 - - [16/Dec/2013 18:54:31] "GET /v2.0/ports.json?tenant_id=cbe2baa37d104c71bd8db69f229a622e&device_id=682be6a5-4b31-43a4-bb11-c884eecebc9b HTTP/1.1" 200 826 0.014504

I'm seeing a lot of ovs errors in the neutron agent log but they don't match the timestamps of the timeout:

Stderr: 'ovs-vsctl: no row "tapda8a8a73-be" in table Port\n'
2013-12-16 18:49:20.066 8305 ERROR neutron.agent.linux.ovs_lib [-] Unable to execute ['ovs-vsctl', '--timeout=2', 'set', 'Port', 'tapec1e8f0c-97', 'tag=53']. Exception:
Command: ['sudo', '/usr/local/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ovs-vsctl', '--timeout=2', 'set', 'Port', 'tapec1e8f0c-97', 'tag=53']
Exi...

[Mark McClain (markmcclain)]

This is has only shown up in the stable/havana queue and is now know to be caused by kernel fault.

[Alan Pevec (apevec)]

2013.1.5 is Grizzly so I've removed it and added Havana task.

[Kyle Mestery (mestery)]

Marking invalid per Mark's comments in #2.