I think Change-Id: I389f939b9a36bc20b3b66e98d006d694622bd963 that introduced background allocation of networks is to blame for a recent race condition that can be seen here: http://logs.openstack.org/31888/6/gate/gate-tempest-devstack-vm-quantum/29217/logs/screen-n-cpu.txt.gz
Basically, if an instance is being spawned at the same time as periodic task _heal_instance_info_cache runs, the spawn fails and the following is logged:
2013-06-10 20:59:40.670 21763 DEBUG quantumclient.client [-] RESP:{'status': '400', 'content-length': 311, 'content-type': 'text/plain'} Second simultaneous read on fileno 20 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-10 20:59:40.670 21763 DEBUG quantumclient.v2_0.client [-] Error message: Second simultaneous read on fileno 20 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-10 20:59:40.670 21763 ERROR nova.compute.manager [-] [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] Instance failed network setup
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] Traceback (most recent call last):
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/nova/nova/compute/manager.py", line 1146, in async_alloc
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] security_groups=security_groups)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/nova/nova/network/api.py", line 48, in wrapper
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] res = f(self, context, *args, **kwargs)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 285, in allocate_for_instance
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] nw_info = self._get_instance_nw_info(context, instance, networks=nets)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 377, in _get_instance_nw_info
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] nw_info = self._build_network_info_model(context, instance, networks)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 854, in _build_network_info_model
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] network_IPs = self._nw_info_get_ips(client, port)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 783, in _nw_info_get_ips
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] client, fixed_ip['ip_address'], port['id'])
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 721, in _get_floating_ips_by_fixed_and_port
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] port_id=port)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 108, in with_params
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] ret = self.function(instance, *args, **kwargs)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 441, in list_floatingips
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] **_params)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 1021, in list
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] for r in self._pagination(collection, path, **params):
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 1034, in _pagination
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] res = self.get(path, params=params)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 1007, in get
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] headers=headers, params=params)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 992, in retry_request
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] headers=headers, params=params)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 934, in do_request
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] self._handle_fault_response(status_code, replybody)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 908, in _handle_fault_response
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] exception_handler_v20(status_code, des_error_body)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 88, in exception_handler_v20
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] message=message)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2] QuantumClientException: Second simultaneous read on fileno 20 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)
2013-06-10 20:59:40.670 21763 TRACE nova.compute.manager [instance: fe220db4-4c94-40d0-91c0-48178550c1a2]
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/poll.py", line 97, in wait
readers.get(fileno, noop).cb(fileno)
File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 194, in main
result = function(*args, **kwargs)
File "/opt/stack/new/nova/nova/compute/manager.py", line 1150, in async_alloc
instance=instance)
File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
self.gen.next()
File "/opt/stack/new/nova/nova/compute/manager.py", line 1146, in async_alloc
security_groups=security_groups)
File "/opt/stack/new/nova/nova/network/api.py", line 48, in wrapper
res = f(self, context, *args, **kwargs)
File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 285, in allocate_for_instance
nw_info = self._get_instance_nw_info(context, instance, networks=nets)
File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 377, in _get_instance_nw_info
nw_info = self._build_network_info_model(context, instance, networks)
File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 854, in _build_network_info_model
network_IPs = self._nw_info_get_ips(client, port)
File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 783, in _nw_info_get_ips
client, fixed_ip['ip_address'], port['id'])
File "/opt/stack/new/nova/nova/network/quantumv2/api.py", line 721, in _get_floating_ips_by_fixed_and_port
port_id=port)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 108, in with_params
ret = self.function(instance, *args, **kwargs)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 441, in list_floatingips
**_params)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 1021, in list
for r in self._pagination(collection, path, **params):
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 1034, in _pagination
res = self.get(path, params=params)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 1007, in get
headers=headers, params=params)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 992, in retry_request
headers=headers, params=params)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 934, in do_request
self._handle_fault_response(status_code, replybody)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 908, in _handle_fault_response
exception_handler_v20(status_code, des_error_body)
File "/opt/stack/new/python-quantumclient/quantumclient/v2_0/client.py", line 88, in exception_handler_v20
message=message)
QuantumClientException: Second simultaneous read on fileno 20 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)
Removing descriptor: 23
This real problem is the admin client caching code that was added for quantum recently. That code is broken as it doesn't allow 2 different greenthreads to make network queries in parallel.
We'll need to revert or fix that patch.