function call chain is not explicit when creating volume failed

[Bin Zhou]

    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.

[Yafei Yu (yu-yafei)]

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

[OpenStack Infra (hudson-openstack)]

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

[Eric Harney (eharney)]

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.

[Bin Zhou (binzhou)]

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.

[OpenStack Infra (hudson-openstack)]

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

[Bin Zhou (binzhou)]

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

[Bin Zhou (binzhou)]

Another three examples of exception log are listed in the following:
http://paste.openstack.org/show/515880/
http://paste.openstack.org/show/515879/
http://paste.openstack.org/show/515878/

[OpenStack Infra (hudson-openstack)]

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.

[Sean McGinnis (sean-mcginnis)]

Unassigning due to no activity for > 6 months.