Cinder api shows timeouts from amqp - messages are logged in nova-api, cinder-api and cinder-volume
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit routing_key=self.routing_key) 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/messaging.py", line 82, in __init__ 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit self.revive(self._channel) 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/messaging.py", line 216, in revive 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit self.declare() 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/messaging.py", line 102, in declare 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit self.exchange.declare() 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/entity.py", line 166, in declare 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit nowait=nowait, passive=passive, 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/channel.py", line 613, in exchange_declare 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit self._send_method((40, 10), args) 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/abstract_channel.py", line 56, in _send_method 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit self.channel_id, method_sig, args, content, 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/method_framing.py", line 221, in write_method 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit write_frame(1, channel, payload) 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/transport.py", line 177, in write_frame 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit frame_type, channel, size, payload, 0xce, 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 307, in sendall 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit tail = self.send(data, flags) 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 293, in send 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit total_sent += fd.send(data[total_sent:], flags) 2015-06-22 21:30:13.432 38170 TRACE oslo.messaging._drivers.impl_rabbit error: [Errno 104] Connection reset by peer
2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/api/contrib/volume_actions.py", line 197, in _initialize_connection 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault connector) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/volume/api.py", line 87, in wrapped 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault return func(self, context, target_obj, *args, **kwargs) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/volume/api.py", line 511, in initialize_connection 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault connector) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/volume/rpcapi.py", line 164, in initialize_connection 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault connector=connector) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/client.py", line 152, in call 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault retry=self.retry) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/oslo/messaging/transport.py", line 90, in _send 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault timeout=timeout, retry=retry) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 417, in send 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault retry=retry) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 406, in _send 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault result = self._waiter.wait(msg_id, timeout) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 294, in wait 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault reply, ending = self._poll_connection(msg_id, timer) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 240, in _poll_connection 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault self._raise_timeout_exception(msg_id) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 209, in _raise_timeout_exception 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault _('Timed out waiting for a reply to message ID %s.') % msg_id) 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault MessagingTimeout: Timed out waiting for a reply to message ID 06c52a24e2fb45fcaa9696ad9749605d. 2015-06-22 21:31:24.102 26908 TRACE cinder.api.middleware.fault
2015-06-22 21:31:24.018 27366 ERROR oslo.messaging.rpc.dispatcher [req-02ea5765-0d65-42d8-8262-64363c66ac2e a9b90ce5977d44ec8b65ada3d31c4747 1657ff89c9c54aa1b42d100a4a663a1f - - -] Exception during message handling: Invalid volume: status must be available or attaching 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last): 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher incoming.message)) 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args) 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args) 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/osprofiler/profiler.py", line 105, in wrapper 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher return f(*args, **kwargs) 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 712, in attach_volume 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher return do_attach() 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/lockutils.py", line 233, in inner 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher retval = f(*args, **kwargs) 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 655, in do_attach 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher raise exception.InvalidVolume(reason=msg) 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher InvalidVolume: Invalid volume: status must be available or attaching 2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.rpc.dispatcher
Cinder api shows timeouts from amqp - messages are logged in nova-api, cinder-api and cinder-volume
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging. _drivers. impl_rabbit routing_ key=self. routing_ key) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/messaging .py", line 82, in __init__ _drivers. impl_rabbit self.revive( self._channel) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/messaging .py", line 216, in revive _drivers. impl_rabbit self.declare() _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/messaging .py", line 102, in declare _drivers. impl_rabbit self.exchange. declare( ) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/entity. py", line 166, in declare _drivers. impl_rabbit nowait=nowait, passive=passive, _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/channel. py", line 613, in exchange_declare _drivers. impl_rabbit self._send_ method( (40, 10), args) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/abstract_ channel. py", line 56, in _send_method _drivers. impl_rabbit self.channel_id, method_sig, args, content, _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/method_ framing. py", line 221, in write_method _drivers. impl_rabbit write_frame(1, channel, payload) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/transport. py", line 177, in write_frame _drivers. impl_rabbit frame_type, channel, size, payload, 0xce, _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ eventlet/ greenio. py", line 307, in sendall _drivers. impl_rabbit tail = self.send(data, flags) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ eventlet/ greenio. py", line 293, in send _drivers. impl_rabbit total_sent += fd.send( data[total_ sent:], flags) _drivers. impl_rabbit error: [Errno 104] Connection reset by peer
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:30:13.432 38170 TRACE oslo.messaging.
2015-06-22 21:31:24.102 26908 TRACE cinder. api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ cinder/ api/contrib/ volume_ actions. py", line 197, in _initialize_ connection api.middleware. fault connector) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ api.py" , line 87, in wrapped api.middleware. fault return func(self, context, target_obj, *args, **kwargs) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ api.py" , line 511, in initialize_ connection api.middleware. fault connector) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ rpcapi. py", line 164, in initialize_ connection api.middleware. fault connector= connector) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ rpc/client. py", line 152, in call api.middleware. fault retry=self.retry) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ transport. py", line 90, in _send api.middleware. fault timeout=timeout, retry=retry) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ _drivers/ amqpdriver. py", line 417, in send api.middleware. fault retry=retry) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ _drivers/ amqpdriver. py", line 406, in _send api.middleware. fault result = self._waiter. wait(msg_ id, timeout) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ _drivers/ amqpdriver. py", line 294, in wait api.middleware. fault reply, ending = self._poll_ connection( msg_id, timer) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ _drivers/ amqpdriver. py", line 240, in _poll_connection api.middleware. fault self._raise_ timeout_ exception( msg_id) api.middleware. fault File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ _drivers/ amqpdriver. py", line 209, in _raise_ timeout_ exception api.middleware. fault _('Timed out waiting for a reply to message ID %s.') % msg_id) api.middleware. fault MessagingTimeout: Timed out waiting for a reply to message ID 06c52a24e2fb45f caa9696ad974960 5d. api.middleware. fault
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.102 26908 TRACE cinder.
2015-06-22 21:31:24.018 27366 ERROR oslo.messaging. rpc.dispatcher [req-02ea5765- 0d65-42d8- 8262-64363c66ac 2e a9b90ce5977d44e c8b65ada3d31c47 47 1657ff89c9c54aa 1b42d100a4a663a 1f - - -] Exception during message handling: Invalid volume: status must be available or attaching rpc.dispatcher Traceback (most recent call last): rpc.dispatcher File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ rpc/dispatcher. py", line 134, in _dispatch_and_reply rpc.dispatcher incoming.message)) rpc.dispatcher File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ rpc/dispatcher. py", line 177, in _dispatch rpc.dispatcher return self._do_ dispatch( endpoint, method, ctxt, args) rpc.dispatcher File "/usr/lib/ python2. 7/dist- packages/ oslo/messaging/ rpc/dispatcher. py", line 123, in _do_dispatch rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args) rpc.dispatcher File "/usr/lib/ python2. 7/dist- packages/ osprofiler/ profiler. py", line 105, in wrapper rpc.dispatcher return f(*args, **kwargs) rpc.dispatcher File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ manager. py", line 712, in attach_volume rpc.dispatcher return do_attach() rpc.dispatcher File "/usr/lib/ python2. 7/dist- packages/ cinder/ openstack/ common/ lockutils. py", line 233, in inner rpc.dispatcher retval = f(*args, **kwargs) rpc.dispatcher File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ manager. py", line 655, in do_attach rpc.dispatcher raise exception. InvalidVolume( reason= msg) rpc.dispatcher InvalidVolume: Invalid volume: status must be available or attaching rpc.dispatcher
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.
2015-06-22 21:31:24.018 27366 TRACE oslo.messaging.