Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1055665

Summary: qpid: please add command and uuid to qpid requests
Product: Red Hat OpenStack Reporter: Dafna Ron <dron>
Component: openstack-cinderAssignee: Eric Harney <eharney>
Status: CLOSED WONTFIX QA Contact: nlevinki <nlevinki>
Severity: high Docs Contact:
Priority: unspecified    
Version: 4.0CC: eharney, markmc, sgordon, sgotliv, yeylon, zkraus
Target Milestone: ---Keywords: ZStream
Target Release: 5.0 (RHEL 7)   
Hardware: x86_64   
OS: Linux   
Whiteboard: storage
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-03-05 14:25:58 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
logs none

Description Dafna Ron 2014-01-20 17:53:51 UTC
Created attachment 852811 [details]
logs

Description of problem:

If we get an exception or timeout from qpid I can't tell what command the exception is for.

I was creating a volume from an image which is local to another server and while it was creating I ran a cinder list command.

I got an exception and I am not sure if this was related to the create or to the list commands.
so I think it would be a good idea to add the command+vol id to requests sent to qpid

Version-Release number of selected component (if applicable):

[root@cougar06 ~(keystone_admin)]# rpm -qa |grep qpid
qpid-cpp-server-0.18-14.el6.x86_64
python-qpid-0.18-4.el6.noarch
qpid-cpp-client-0.18-14.el6.x86_64
[root@cougar06 ~(keystone_admin)]# 

[root@nott-vdsa ~(keystone_admin)]# rpm -qa |grep cinder 
python-cinderclient-1.0.7-2.el6ost.noarch
openstack-cinder-2013.2.1-5.el6ost.noarch
python-cinder-2013.2.1-5.el6ost.noarch

How reproducible:

This needs a stand alone glance and a stand alone cinder in the same setup. 

Steps to Reproduce:
1. create a local image : glance 
image-create --name <name> --disk-format  qcow2 --container-format bare --file /tmp/<file> 
2. create a volume from an image
cinder create <smaller size than image> --display-name <name> --image-id <image_id>
3.during create run cinder list 

Actual results:

we get a time-out from qpid and a failure in cinder but we don't know if the time-out is on the command failure or on the cinder list request. 


Expected results:

since we can have a lot of requests in the system we need to be able to follow them in the log. so adding identification like command and UUID of object to qpid requests will help debugging 


Additional info:


Jan 20 18:35:33 cougar06 dnsmasq-dhcp[7642]: DHCPRELEASE(br100) 192.168.32.2 fa:16:3e:97:f6:63 unknown lease
Jan 20 18:39:59 cougar06 qpidd[6619]: 2014-01-20 18:39:59 [Broker] error Connection 10.35.160.133:5672-10.35.64.69:54228 timed out: closing
Jan 20 18:46:52 cougar06 qpidd[6619]: 2014-01-20 18:46:52 [Broker] error Connection 10.35.160.133:5672-10.35.64.69:54274 timed out: closing
Jan 20 18:46:52 cougar06 qpidd[6619]: 2014-01-20 18:46:52 [Broker] error Connection 10.35.160.133:5672-10.35.64.69:54214 timed out: closing
Jan 20 18:47:02 cougar06 qpidd[6619]: 2014-01-20 18:47:02 [Broker] error Connection 10.35.160.133:5672-10.35.64.69:54217 timed out: closing


2014-01-20 18:44:18.367 6827 ERROR cinder.openstack.common.rpc.amqp [req-3b99be3b-c704-4c47-83b1-013606dc107f e6ee6034307247b78807be047bd10e76 d4aaa7c237054d408a65f40bb4ee74d0] Exception during message handling
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     **args)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 820, in wrapper
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     return func(self, *args, **kwargs)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 257, in create_volume
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     flow.run(context.elevated())
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/taskflow/decorators.py", line 105, in wrapper
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     return f(self, *args, **kwargs)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/taskflow/patterns/linear_flow.py", line 232, in run
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     run_it(r)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/taskflow/patterns/linear_flow.py", line 212, in run_it
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     self.rollback(context, cause)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     self.gen.next()
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/taskflow/patterns/linear_flow.py", line 172, in run_it
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     result = runner(context, *args, **kwargs)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/taskflow/utils.py", line 260, in __call__
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     self.result = self.task(*args, **kwargs)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/flows/create_volume/__init__.py", line 1499, in __call__
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     **volume_spec)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/flows/create_volume/__init__.py", line 1462, in _create_from_image
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     image_id, image_location, image_service)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/cinder/volume/flows/create_volume/__init__.py", line 1369, in _copy_image_to_volume
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp     raise exception.ImageUnacceptable(ex)
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp ImageUnacceptable: Image 0b299b8a-bd63-4ff5-bfa2-c247c696b970 is unacceptable: Size is 50GB and doesn't fit in a volume of size 20GB.
2014-01-20 18:44:18.367 6827 TRACE cinder.openstack.common.rpc.amqp 
2014-01-20 18:47:04.065 6827 ERROR cinder.openstack.common.rpc.impl_qpid [-] Failed to consume message from queue: heartbeat timeout
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid Traceback (most recent call last):
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/impl_qpid.py", line 480, in ensure
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid     return method(*args, **kwargs)
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/impl_qpid.py", line 531, in _consume
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid     nxt_receiver = self.session.next_receiver(timeout=timeout)
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "<string>", line 6, in next_receiver
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 660, in next_receiver
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid     if self._ecwait(lambda: self.incoming, timeout):
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 50, in _ecwait
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid     result = self._ewait(lambda: self.closed or predicate(), timeout)
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 566, in _ewait
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid     result = self.connection._ewait(lambda: self.error or predicate(), timeout)
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 209, in _ewait
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid     self.check_error()
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid   File "/usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py", line 202, in check_error
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid     raise self.error
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid HeartbeatTimeout: heartbeat timeout
2014-01-20 18:47:04.065 6827 TRACE cinder.openstack.common.rpc.impl_qpid

Comment 1 Sergey Gotliv 2015-03-05 14:25:58 UTC
Not a zstream material.