Please see - https://review.openstack.org/#/c/31657/
Bummer we could have had this behind us if
https://review.openstack.org/#/c/27265/ had gotten through.
I hope that maybe we can put this behind us for a while
On 06/04/2013 03:46 PM, Gary Kotton wrote:
Hi,
Just to provide a little more information. The problem is a result of
a timeout with the Quantum client (used by Nova) to interface with the
Quantum service ([2]). There are 2 issues here:
1. Keystone is a bottleneck
2. At times there is an exception with the Quantum database (an
example of a trace is below in [1])
Thanks
Gary
1.
Traceback (most recent call last):
File "/usr/lib/python2.6/site-packages/quantum/api/v2/resource.py",
line 82, in resource
result = method(request=request, **args)
File "/usr/lib/python2.6/site-packages/quantum/api/v2/base.py", line
239, in index
return self._items(request, True, parent_id)
File "/usr/lib/python2.6/site-packages/quantum/api/v2/base.py", line
192, in _items
obj_list = obj_getter(request.context, **kwargs)
File
"/usr/lib/python2.6/site-packages/quantum/db/securitygroups_db.py",
line 136, in get_security_groups
page_reverse=page_reverse)
File
"/usr/lib/python2.6/site-packages/quantum/db/db_base_plugin_v2.py",
line 240, in _get_collection
items = [dict_func(c, fields) for c in query.all()]
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py",
line 2115, in all
return list(self)
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py",
line 2227, in __iter__
return self._execute_and_instances(context)
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py",
line 2240, in _execute_and_instances
close_with_result=True)
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py",
line 2231, in _connection_from_session
**kw)
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py",
line 730, in connection
close_with_result=close_with_result)
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py",
line 736, in _connection_for_bind
return engine.contextual_connect(**kwargs)
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py",
line 2490, in contextual_connect
self.pool.connect(),
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py",
line 224, in connect
return _ConnectionFairy(self).checkout()
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py",
line 387, in __init__
rec = self._connection_record = pool._do_get()
File
"/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py",
line 729, in _do_get
(self.size(), self.overflow(), self._timeout))
TimeoutError: QueuePool limit of size 5 overflow 10 reached,
connection timed out, timeout 30
2.
[root@dhcp-4-126 ~(keystone_admin)]# cd /var/log/nova/
[root@dhcp-4-126 nova(keystone_admin)]# grep -r
6cd39e4d-a805-4f05-83e8-3a9ecc2117b1 *
api.log:2013-06-04 04:55:19.425 INFO nova.osapi_compute.wsgi.server
[req-51d09365-8f74-4759-a29e-7d06d9c22e10
ba5e489e00d64ae4834b535646ee80df cb2207818a394626937f878e0538ac7b]
10.35.4.126 "GET
/v2/cb2207818a394626937f878e0538ac7b/servers/6cd39e4d-a805-4f05-83e8-3a9ecc2117b1
HTTP/1.1" status: 200 len: 1477 time: 28.6792312
api.log:2013-06-04 04:57:36.743 INFO nova.osapi_compute.wsgi.server
[req-924fee73-7883-4160-8d7d-6ea77c3d34f3
ba5e489e00d64ae4834b535646ee80df cb2207818a394626937f878e0538ac7b]
10.35.4.126 "GET
/v2/cb2207818a394626937f878e0538ac7b/servers/6cd39e4d-a805-4f05-83e8-3a9ecc2117b1
HTTP/1.1" status: 200 len: 1725 time: 3.2600341
scheduler.log:2013-06-04 04:57:33.662 ERROR
nova.scheduler.filter_scheduler
[req-899adfbb-059e-473d-9508-7419127def73
ba5e489e00d64ae4834b535646ee80df cb2207818a394626937f878e0538ac7b]
[instance: 6cd39e4d-a805-4f05-83e8-3a9ecc2117b1] Error from last host:
dhcp-4-227.tlv.redhat.com (node dhcp-4-227.tlv.redhat.com):
[u'Traceback (most recent call last):\n', u' File
"/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 831,
in _run_instance\n requested_networks, macs, security_groups)\n',
u' File "/usr/lib/python2.6/site-packages/nova/compute/manager.py",
line 1075, in _allocate_network\n instance=instance)\n', u' File
"/usr/lib64/python2.6/contextlib.py", line 23, in __exit__\n
self.gen.next()\n', u' File
"/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1071,
in _allocate_network\n security_groups=security_groups)\n', u'
File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 46,
in wrapper\n res = f(self, context, *args, **kwargs)\n', u' File
"/usr/lib/python2.6/site-packages/nova/network/quantumv2/api.py", line
281, in allocate_for_instance\n \'exception\': ex})\n', u' File
"/usr/lib64/python2.6/contextlib.py", line 23, in __exit__\n
self.gen.next()\n', u' File
"/usr/lib/python2.6/site-packages/nova/network/quantumv2/api.py", line
264, in allocate_for_instance\n
quantum.create_port(port_req_body)[\'port\'][\'id\'])\n', u' File
"/usr/lib/python2.6/site-packages/quantumclient/v2_0/client.py", line
107, in with_params\n ret = self.function(instance, *args,
**kwargs)\n', u' File
"/usr/lib/python2.6/site-packages/quantumclient/v2_0/client.py", line
269, in create_port\n return self.post(self.ports_path,
body=body)\n', u' File
"/usr/lib/python2.6/site-packages/quantumclient/v2_0/client.py", line
987, in post\n headers=headers, params=params)\n', u' File
"/usr/lib/python2.6/site-packages/quantumclient/v2_0/client.py", line
912, in do_request\n self._handle_fault_response(status_code,
replybody)\n', u' File
"/usr/lib/python2.6/site-packages/quantumclient/v2_0/client.py", line
893, in _handle_fault_response\n exception_handler_v20(status_code,
des_error_body)\n', u' File
"/usr/lib/python2.6/site-packages/quantumclient/v2_0/client.py", line
87, in exception_handler_v20\n message=message)\n',
u'QuantumClientException: Request Timeout\n']
scheduler.log:2013-06-04 04:57:33.680 WARNING nova.scheduler.driver
[req-899adfbb-059e-473d-9508-7419127def73
ba5e489e00d64ae4834b535646ee80df cb2207818a394626937f878e0538ac7b]
[instance: 6cd39e4d-a805-4f05-83e8-3a9ecc2117b1] Setting instance to
ERROR state.
On 06/04/2013 12:28 PM, Gary Kotton wrote:
Hi,
Thanks to Aarons script I was able to reproduce and find the problem
for https://bugs.launchpad.net/quantum/+bug/1160442. I have found the
problem and will push a patch soon.
Thanks
Gary
--
Mailing list: https://launchpad.net/~quantum-core
Post to : [email protected]
Unsubscribe : https://launchpad.net/~quantum-core
More help : https://help.launchpad.net/ListHelp
