function call chain is not explicit when creating volume failed

Bug #1582473 reported by Bin Zhou
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Cinder
New
Low
Tushar Trambak Gite

Bug Description

    when I create volume from image in my daily test, it may fail for all kind of reasons.The log always pointed to the function _copy_image_to_volume in cinder.volume.flows.manager.create_volume.py. But the exception was re-raised in this function and the call chain was not exactly where the exception throwed out. It confuse me every time when the failure happens. I think it's not necessary to re-raise the exception when failure happens, for better use of engineer's troubleshooting.
    Here is an example as follows, I bet you can not get the exactly exception call chain from the log.

78200b0157aa4694809838f43fdd7e41 - - -] Exception during message handling: Failed to copy image to volume: Not authorized for image f62793d3-e48b-4482-849c-d3f0e4537b70.
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher executor_callback))
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher executor_callback)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 468, in create_volume
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher _run_flow()
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 456, in _run_flow
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher flow_engine.run()
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 96, in run
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher for _state in self.run_iter():
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 153, in run_iter
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher failure.Failure.reraise_if_any(failures.values())
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/taskflow/types/failure.py", line 244, in reraise_if_any
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher failures[0].reraise()
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/taskflow/types/failure.py", line 251, in reraise
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher six.reraise(*self._exc_info)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 67, in _execute_task
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher result = task.execute(**arguments)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 653, in execute
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher **volume_spec)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 605, in _create_from_image
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher image_id, image_location, image_service)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 516, in _copy_image_to_volume
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher raise exception.ImageCopyFailure(reason=ex)
2016-05-16 19:26:54.461 10279 TRACE oslo_messaging.rpc.dispatcher ImageCopyFailure: Failed to copy image to volume: Not authorized for image f62793d3-e48b-4482-849c-d3f0e4537b70.

Tags: cinder volume
Revision history for this message
Yafei Yu (yu-yafei) wrote :

The bug confuse me too, do you have a gool solution to solve it ?

Changed in cinder:
status: New → Confirmed
importance: Undecided → Low
summary: - function call chain is not explict when create volume failed
+ function call chain is not explicit when create volume failed
Bin Zhou (binzhou)
Changed in cinder:
assignee: nobody → Bin Zhou (binzhou)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to cinder (master)

Fix proposed to branch: master
Review: https://review.openstack.org/317295

Changed in cinder:
status: Confirmed → In Progress
Yafei Yu (yu-yafei)
tags: added: cinder volume
Yafei Yu (yu-yafei)
summary: - function call chain is not explicit when create volume failed
+ function call chain is not explicit when creating volume failed
Revision history for this message
Eric Harney (eharney) wrote :

Is there not an earlier logged traceback? Usually the traceback from the "messaging" layer (what appears to be in this bug) is the second copy of this info, and not from where the exception was originally logged, which may be better.

Revision history for this message
Bin Zhou (binzhou) wrote :

To Eric:
    Actually, there is not. The function _copy_image_to_volume is fulfilled in volume backend driver. Most of those drivers have not realized try-exception scenario in this function. I was confused by this exception for a long time in my daily work.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on cinder (master)

Change abandoned by Bin Zhou (<email address hidden>) on branch: master
Review: https://review.openstack.org/317295

Revision history for this message
Bin Zhou (binzhou) wrote :

An example of exception log is listed in the following:
http://paste.openstack.org/show/510905/

Revision history for this message
Bin Zhou (binzhou) wrote :
Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Change abandoned by Sean McGinnis (<email address hidden>) on branch: master
Review: https://review.openstack.org/317295
Reason: This review is > 4 weeks without comment, and failed Jenkins the last time it was checked. We are abandoning this for now. Feel free to reactivate the review by pressing the restore button and leaving a 'recheck' comment to get fresh test results.

Revision history for this message
Sean McGinnis (sean-mcginnis) wrote : Bug Assignee Expired

Unassigning due to no activity for > 6 months.

Changed in cinder:
assignee: Bin Zhou (binzhou) → nobody
status: In Progress → New
Changed in cinder:
assignee: nobody → Tushar Trambak Gite (tushargite96)
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.