Cinder outputs traceback in c-api service logs if taskflow raises exception.InvalidInput and exception.QuotaError

[Dinesh Bhor]

Cinder uses '_format_failure' method to suppress the traceback in logs [1]. But this method no
longer exists in taskflow. It is removed in this patch [2]. Thus if exception.InvalidInput or exception.QuotaError raised from the taskflow, it outputs traceback in c-api service logs.

Command:

exception.InvalidInput:

$ cinder create --name new_volume 0
ERROR: Invalid input received: Volume size '0' must be an integer and greater than 0 (HTTP 400) (Request-ID: req-0ef0583c-8821-4adc-a4ff-36c10e37f77f)

C-api logs:

2016-12-08 19:48:03.332 WARNING cinder.volume.api [req-0ef0583c-8821-4adc-a4ff-36c10e37f77f 3d35af5830fb42c6a09d2a66e637314c 9af7d252854447ebbfcac4505f6fa860] Task 'cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create' (dcfe38d7-426e-45d6-a285-7f8dc9efafef) transitioned into state 'FAILURE' from state 'RUNNING'
1 predecessors (most recent first):
  Flow 'volume_create_api'
2016-12-08 19:48:03.332 TRACE cinder.volume.api Traceback (most recent call last):
2016-12-08 19:48:03.332 TRACE cinder.volume.api File "/usr/local/lib/python2.7/dist-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
2016-12-08 19:48:03.332 TRACE cinder.volume.api result = task.execute(**arguments)
2016-12-08 19:48:03.332 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/volume/flows/api/create_volume.py", line 418, in execute
2016-12-08 19:48:03.332 TRACE cinder.volume.api size = self._extract_size(size, source_volume, snapshot)
2016-12-08 19:48:03.332 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/volume/flows/api/create_volume.py", line 197, in _extract_size
2016-12-08 19:48:03.332 TRACE cinder.volume.api func(size)
2016-12-08 19:48:03.332 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/volume/flows/api/create_volume.py", line 175, in validate_int
2016-12-08 19:48:03.332 TRACE cinder.volume.api raise exception.InvalidInput(reason=msg)
2016-12-08 19:48:03.332 TRACE cinder.volume.api InvalidInput: Invalid input received: Volume size '0' must be an integer and greater than 0
2016-12-08 19:48:03.332 TRACE cinder.volume.api
2016-12-08 19:48:03.335 DEBUG cinder.volume.api [req-0ef0583c-8821-4adc-a4ff-36c10e37f77f 3d35af5830fb42c6a09d2a66e637314c 9af7d252854447ebbfcac4505f6fa860] Task 'cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create' (dcfe38d7-426e-45d6-a285-7f8dc9efafef) transitioned into state 'REVERTING' from state 'FAILURE' from (pid=19321) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:194

exception.QuotaError:

$ cinder create 1111111111111111
ERROR: VolumeSizeExceedsAvailableQuota: Requested volume or snapshot exceeds allowed gigabytes quota. Requested 1111111111111111G, quota is 1000G and 11G has been consumed. (HTTP 413) (Request-ID: req-ee0d47b0-de32-4bc5-b327-98d7af223941)

C-api logs:

|__Flow 'volume_create_api'
2016-12-14 15:17:35.417 TRACE cinder.volume.api Traceback (most recent call last):
2016-12-14 15:17:35.417 TRACE cinder.volume.api File "/usr/local/lib/python2.7/di
st-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
2016-12-14 15:17:35.417 TRACE cinder.volume.api result = task.execute(**argumen
ts)
2016-12-14 15:17:35.417 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/vo
lume/flows/api/create_volume.py", line 614, in execute
2016-12-14 15:17:35.417 TRACE cinder.volume.api size=size)
2016-12-14 15:17:35.417 TRACE cinder.volume.api File "/opt/stack/cinder/cinder/qu
ota_utils.py", line 283, in process_reserve_over_quota
2016-12-14 15:17:35.417 TRACE cinder.volume.api quota=quotas[over])
2016-12-14 15:17:35.417 TRACE cinder.volume.api VolumeSizeExceedsAvailableQuota: Requested volume or snapshot exceeds allowed gigabytes quota. Requested 1111111111111111G, quota is 1000G and 11G has been consumed.
2016-12-14 15:17:35.417 TRACE cinder.volume.api
2016-12-14 15:17:35.424 DEBUG cinder.volume.api [req-ee0d47b0-de32-4bc5-b327-98d7af223941 3d35af5830fb42c6a09d2a66e637314c 9af7d252854447ebbfcac4505f6fa860] Task 'cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create' (a57c35f3-f707-4d87-a794-5a44d93135f1) transitioned into state 'REVERTING' from state 'FAILURE' from (pid=1864) _task_receiver /usr/local/lib/python2.7/dist-packages/taskflow/listeners/logging.py:194

Taskflow has introduced a new class 'taskflow.formatters.FailureFormatter' which can be used to shut off the traceback in logs.

[1] https://github.com/openstack/cinder/blob/master/cinder/flow_utils.py#L74
[2] https://review.openstack.org/#/c/205903/

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/412819
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=ca43430680bacbba7a17d5fde88aa253a7229c68
Submitter: Jenkins
Branch: master

commit ca43430680bacbba7a17d5fde88aa253a7229c68
Author: dineshbhor <email address hidden>
Date: Tue Dec 13 19:30:25 2016 +0530

    Fix logging traceback in service logs

    The '_format_failure' method of DynamicLoggingListener class
    from taskflow is overridden to suppress traceback for special
    exceptions (InvalidInput, QuotaError). You can still see
    traceback in logs for these exceptions as _format_failure method
    was replaced with fail_formatter parameter in taskflow version
    1.22.0 [1] but the code was not modified to accommodate these
    changes.

    This patch uses fail_formatter parameter to suppress traceback
    log messages.

    [1] https://github.com/openstack/taskflow/tree/1.22.0

    Closes-Bug: #1649850
    Change-Id: I9bb4a690759974206bbd95ae53339ab302b1db5a

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/cinder 10.0.0.0b3 development milestone.