I have been looking into this as well, and it does not help when I say that I am unable to reproduce. However I found something interesting on a failure that occurred on this gate job: http://logs.openstack.org/32534/4/gate/gate-tempest-devstack-vm-quantum/30188/ If I look at tempest, the failure is due to a timeout on waiting for the VM to be rescued. Time-wise this is completely unrelated to the recurring KeyError issue we see in the nova-compute log. However, and this is where it gets interesting...I see these traces in the log: 2013-06-13 06:18:48.596 22325 DEBUG quantumclient.client [-] RESP:{'status': '400', 'content-length': 311, 'content-type': 'text/plain'} Second simultaneous read on fileno 24 detected. Unless you really know what you're doing, make sure that only one greenthread can read any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_multiple_reader_prevention(False) http_log_resp /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:179 2013-06-13 06:18:48.596 22325 DEBUG quantumclient.v2_0.client [-] Error message: Second simultaneous read on fileno 24 detected. Unless you really know what you're doing, make sure that only one greenthread can read any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_multiple_reader_prevention(False) _handle_fault_response /opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py:899 2013-06-13 06:18:48.596 22325 DEBUG nova.openstack.common.loopingcall [-] Dynamic looping call sleeping for 60.00 seconds _inner /opt/stack/new/nova/nova/openstack/common/loopingcall.py:132 2013-06-13 06:18:48.630 22325 DEBUG quantumclient.client [-] RESP:{'date': 'Thu, 13 Jun 2013 06:18:48 GMT', 'status': '200', 'content-length': '596', 'content-type': 'application/json; charset=UTF-8', 'content-location': 'http://127.0.0.1:9696//v2.0/ports.json?tenant_id=de8db2b90a724e728e2186db1c3e1235&device_id=ba7c58d0-4237-481b-b066-9511a9b85f8c'} {"ports": [{"status": "ACTIVE", "binding:host_id": null, "name": "", "admin_state_up": true, "network_id": "772daa7b-467a-423d-8dfa-49de7fd97f29", "tenant_id": "de8db2b90a724e728e2186db1c3e1235", "binding:vif_type": "ovs", "device_owner": "compute:None", "binding:capabilities": {"port_filter": true}, "mac_address": "fa:16:3e:eb:65:cc", "fixed_ips": [{"subnet_id": "e72648e8-ce27-4090-89bf-28f3c7b58cdb", "ip_address": "10.1.0.16"}], "id": "22525b73-6012-4d63-8535-868e7f6eada5", "security_groups": ["055711d3-be14-439c-aa15-b743dc20d37c"], "device_id": "ba7c58d0-4237-481b-b066-9511a9b85f8c"}]} http_log_resp /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:179 2013-06-13 06:18:48.631 22325 DEBUG quantumclient.client [-] REQ: curl -i http://127.0.0.1:9696/v2.0/networks.json?tenant_id=de8db2b90a724e728e2186db1c3e1235&shared=False -X GET -H "X-Auth-Token: " -H "Content-Type: application/json" -H "Accept: application/json" -H "User-Agent: python-quantumclient" http_log_req /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:173 2013-06-13 06:18:48.645 22325 DEBUG quantumclient.client [-] RESP:{'date': 'Thu, 13 Jun 2013 06:18:48 GMT', 'status': '200', 'content-length': '270', 'content-type': 'application/json; charset=UTF-8', 'content-location': 'http://127.0.0.1:9696/v2.0/networks.json?tenant_id=de8db2b90a724e728e2186db1c3e1235&shared=False'} {"networks": [{"status": "ACTIVE", "subnets": ["e72648e8-ce27-4090-89bf-28f3c7b58cdb"], "name": "private", "router:external": false, "tenant_id": "de8db2b90a724e728e2186db1c3e1235", "admin_state_up": true, "shared": false, "id": "772daa7b-467a-423d-8dfa-49de7fd97f29"}]} http_log_resp /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:179 2013-06-13 06:18:48.646 22325 DEBUG quantumclient.client [-] REQ: curl -i http://127.0.0.1:9696/v2.0/networks.json?shared=True -X GET -H "X-Auth-Token: " -H "Content-Type: application/json" -H "Accept: application/json" -H "User-Agent: python-quantumclient" http_log_req /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:173 2013-06-13 06:18:48.651 22325 DEBUG quantumclient.client [-] RESP:{'date': 'Thu, 13 Jun 2013 06:18:48 GMT', 'status': '200', 'content-length': '16', 'content-type': 'application/json; charset=UTF-8', 'content-location': 'http://127.0.0.1:9696/v2.0/networks.json?shared=True'} {"networks": []} http_log_resp /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:179 2013-06-13 06:18:48.652 22325 DEBUG quantumclient.client [-] REQ: curl -i http://127.0.0.1:9696//v2.0/floatingips.json?fixed_ip_address=10.1.0.16&port_id=22525b73-6012-4d63-8535-868e7f6eada5 -X GET -H "X-Auth-Token: " -H "Content-Type: application/json" -H "Accept: application/json" -H "User-Agent: python-quantumclient" http_log_req /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:173 2013-06-13 06:18:48.653 22325 DEBUG quantumclient.client [-] RESP:{'date': 'Thu, 13 Jun 2013 06:18:48 GMT', 'status': '200', 'content-length': '16', 'content-type': 'application/json; charset=UTF-8', 'content-location': 'http://127.0.0.1:9696//v2.0/floatingips.json?fixed_ip_address=10.1.0.16&port_id=22525b73-6012-4d63-8535-868e7f6eada5'} {"networks": []} http_log_resp /opt/stack/new/python-quantumclient/quantumclient/common/utils.py:179 2013-06-13 06:18:48.655 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] Making synchronous call on conductor ... multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:586 2013-06-13 06:18:48.655 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] MSG_ID is 1df60a9885a04ee29d8da313153c6b9d multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:589 2013-06-13 06:18:48.656 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] UNIQUE_ID is 9798bbac01784cb2b3ab7289f63f547e. _add_unique_id /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:337 2013-06-13 06:18:48.679 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] Making synchronous call on conductor ... multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:586 2013-06-13 06:18:48.679 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] MSG_ID is b5eed5fe4aad4b85b55b92f25ced21b9 multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:589 2013-06-13 06:18:48.680 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] UNIQUE_ID is 0f71354a8c1c4a50b9fd578ef133d551. _add_unique_id /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:337 2013-06-13 06:18:48.744 DEBUG nova.virt.libvirt.driver [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] Updating host stats update_status /opt/stack/new/nova/nova/virt/libvirt/driver.py:3881 2013-06-13 06:18:48.768 DEBUG nova.openstack.common.lockutils [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] Got semaphore "compute_resources" for method "update_usage"... inner /opt/stack/new/nova/nova/openstack/common/lockutils.py:190 2013-06-13 06:18:48.769 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] Making synchronous call on conductor ... multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:586 2013-06-13 06:18:48.769 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] MSG_ID is 1b1a9fc829d84d2192fe8afbf3372e7d multicall /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:589 2013-06-13 06:18:48.770 DEBUG nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] UNIQUE_ID is d9fea33a66874e73b56b087e57ad5f0b. _add_unique_id /opt/stack/new/nova/nova/openstack/common/rpc/amqp.py:337 2013-06-13 06:18:48.807 ERROR nova.openstack.common.rpc.amqp [req-31e2bbd9-d7b7-4e03-aa98-b65e4f0ed508 demo demo] Exception during message handling 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last): 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/openstack/common/rpc/amqp.py", line 433, in _process_data 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp **args) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/openstack/common/rpc/dispatcher.py", line 172, in dispatch 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp result = getattr(proxyobj, method)(ctxt, **kwargs) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/exception.py", line 98, in wrapped 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp temp_level, payload) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp self.gen.next() 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/exception.py", line 75, in wrapped 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp return f(self, context, *args, **kw) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/compute/manager.py", line 214, in decorated_function 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp pass 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__ 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp self.gen.next() 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/compute/manager.py", line 200, in decorated_function 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/compute/manager.py", line 265, in decorated_function 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp function(self, context, *args, **kwargs) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/compute/manager.py", line 2088, in rescue_instance 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp network_info = self._get_instance_nw_info(context, instance) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/compute/manager.py", line 761, in _get_instance_nw_info 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp instance, conductor_api=self.conductor_api) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 369, in get_instance_nw_info 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp result = self._get_instance_nw_info(context, instance, networks) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 377, in _get_instance_nw_info 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp nw_info = self._build_network_info_model(context, instance, networks) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 854, in _build_network_info_model 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp network_IPs = self._nw_info_get_ips(client, port) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 783, in _nw_info_get_ips 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp client, fixed_ip['ip_address'], port['id']) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 721, in _get_floating_ips_by_fixed_and_port 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp port_id=port) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 108, in with_params 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp ret = self.function(instance, *args, **kwargs) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 441, in list_floatingips 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp **_params) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 1022, in list 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp res.extend(r[collection]) 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp KeyError: 'floatingips' 2013-06-13 06:18:48.807 22325 TRACE nova.openstack.common.rpc.amqp In a nutshell, what I see is this: -- Contention errors caused by eventlet -- A call to http://127.0.0.1:9696/v2.0/networks.json?shared=True -- A response in the shape of {"networks": []} -- A call to http://127.0.0.1:9696//v2.0/floatingips.json?fixed_ip_address=$IP&port_id=$PORT -- A (bad) response in the shape of {"networks": []} Maybe this all boils down to something funky in how eventlet is handled, and Dirk's comment starts to make sense :) I'll keep digging.