[Openstack] Suddenly plagued with RPC response errors

Mike Smith mismith at overstock.com
Wed Dec 3 18:43:18 UTC 2014


This issue that we experienced in May has hit us again, although this time I don’t see a large number of exchanges using qpid-tool.  I believe the “fix” that I will have to perform is for me to failover/restart my nova-network service, which somehow unwedged the RPC subsystem last time.

Before I do so, I would love to know if anyone has an idea as to why this would be occurring.    Restarting nova-network is not something I love doing because we lose network connectivity to our instances for several minutes.

Thanks



On May 28, 2014, at 10:06 AM, Mike Smith <mismith at overstock.com<mailto:mismith at overstock.com>> wrote:

I have a CentOS 6.5 Folsom cluster running 716 VMs across 16 hypervisors.   This past week I have started seeing problems which I believe are related to message queueing.

Symptom one:  Horizon stalls for a long time upon login or when changing tenants, and eventually displays a "Could not retrieve quota information" message.

Symptom two:  Metadata services calls are not being serviced, and nova api logs show messages similar to the following:   2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler Timeout: Timeout while waiting on RPC response.

Using qpid-tool, I can see that the exchange count (currently more than 10,000) is growing larger and larger.

qpid: list
Summary of Objects by Type:
    Package                 Class         Active  Deleted
    =======================================================
    org.apache.qpid.broker  binding       110     184
    org.apache.qpid.broker  broker        1       0
    org.apache.qpid.broker  system        1       0
    org.apache.qpid.broker  subscription  66      92
    org.apache.qpid.broker  connection    40      0
    org.apache.qpid.broker  session       40      157
    org.apache.qpid.broker  queue         54      92
    org.apache.qpid.broker  exchange      10025   0
    org.apache.qpid.broker  vhost         1       0


Can anyone help me identify what is going on here and get things back to normal?   Please let me know what other information would be helpful to provide.

Thanks,
Mike
Overstock.com<http://Overstock.com>




Here is a more complete traceback:

2014-05-28 09:57:15 16759 ERROR nova.openstack.common.rpc.impl_qpid [-] Timed out waiting for RPC response: None
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid Traceback (most recent call last):
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 358, in ensure
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid     return method(*args, **kwargs)
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 407, in _consume
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid     nxt_receiver = self.session.next_receiver(timeout=timeout)
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "<string>", line 6, in next_receiver
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 663, in next_receiver
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid     raise Empty
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid Empty: None
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid
2014-05-28 09:57:15 16759 ERROR nova.openstack.common.rpc.impl_qpid [-] Timed out waiting for RPC response: None
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid Traceback (most recent call last):
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 358, in ensure
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid     return method(*args, **kwargs)
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 407, in _consume
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid     nxt_receiver = self.session.next_receiver(timeout=timeout)
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "<string>", line 6, in next_receiver
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 663, in next_receiver
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid     raise Empty
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid Empty: None
2014-05-28 09:57:15 16759 TRACE nova.openstack.common.rpc.impl_qpid
2014-05-28 09:57:16 ERROR nova.api.metadata.handler [req-93548aee-cd7e-46af-8e95-df3e0d6b96a2 None None] Failed to get metadata for ip: 10.8.55.11
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler Traceback (most recent call last):
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/api/metadata/handler.py", line 75, in __call__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     meta_data = self.get_metadata(remote_address)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/api/metadata/handler.py", line 57, in get_metadata
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     data = base.get_metadata_by_address(address)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/api/metadata/base.py", line 385, in get_metadata_by_address
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     fixed_ip = network.API().get_fixed_ip_by_address(ctxt, address)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 126, in get_fixed_ip_by_address
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     'args': {'address': address}})
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/__init__.py", line 108, in call
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     return _get_impl().call(cfg.CONF, context, topic, msg, timeout)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 543, in call
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     rpc_amqp.get_connection_pool(conf, Connection))
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 369, in call
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     rv = list(rv)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 330, in __iter__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     self.done()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     self.gen.next()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 327, in __iter__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     self._iterator.next()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 416, in iterconsume
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     yield self.ensure(_error_callback, _consume)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 362, in ensure
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     error_callback(e)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 401, in _error_callback
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     raise rpc_common.Timeout()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler Timeout: Timeout while waiting on RPC response.
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler
2014-05-28 09:57:16 16759 INFO nova.api.ec2 [-] 13656.257934s 10.8.55.11 GET / None:None 500 [None] text/plain text/html
2014-05-28 09:57:16 16759 INFO nova.metadata.wsgi.server [-] 10.8.55.11 - - [28/May/2014 09:57:16] "GET / HTTP/1.1" 500 343 13656.259023

2014-05-28 09:57:16 ERROR nova.api.metadata.handler [req-da2813bf-69a9-491e-b655-ca99c6cf97a2 None None] Failed to get metadata for ip: 10.8.11.17
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler Traceback (most recent call last):
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/api/metadata/handler.py", line 75, in __call__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     meta_data = self.get_metadata(remote_address)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/api/metadata/handler.py", line 57, in get_metadata
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     data = base.get_metadata_by_address(address)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/api/metadata/base.py", line 385, in get_metadata_by_address
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     fixed_ip = network.API().get_fixed_ip_by_address(ctxt, address)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 126, in get_fixed_ip_by_address
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     'args': {'address': address}})
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/__init__.py", line 108, in call
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     return _get_impl().call(cfg.CONF, context, topic, msg, timeout)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 543, in call
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     rpc_amqp.get_connection_pool(conf, Connection))
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 369, in call
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     rv = list(rv)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 330, in __iter__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     self.done()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     self.gen.next()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 327, in __iter__
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     self._iterator.next()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 416, in iterconsume
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     yield self.ensure(_error_callback, _consume)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 362, in ensure
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     error_callback(e)
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/impl_qpid.py", line 401, in _error_callback
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler     raise rpc_common.Timeout()
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler Timeout: Timeout while waiting on RPC response.
2014-05-28 09:57:16 16759 TRACE nova.api.metadata.handler


________________________________

CONFIDENTIALITY NOTICE: This message is intended only for the use and review of the individual or entity to which it is addressed and may contain information that is privileged and confidential. If the reader of this message is not the intended recipient, or the employee or agent responsible for delivering the message solely to the intended recipient, you are hereby notified that any dissemination, distribution or copying of this communication is strictly prohibited. If you have received this communication in error, please notify sender immediately by telephone or return email. Thank you.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack/attachments/20141203/02e4d873/attachment.html>


More information about the Openstack mailing list