python-cinderclient

Log request_id for each api call

Registered by Abhishek Kekane on 2016-04-20

Blueprint [1] was implemented in the last Mitaka release cycle which returns request_id back to the caller as per design proposed in the cross-project specs [2]. Now, in step 2, we would like to log x-openstack-request-id returned in the response header using the python logging module.

Following log message will be logged in debug logging level.

LOG.debug(_("%(method)s call to '%(my_service_name)s' for %(my_url)s "
            "used request_id '%(response_request_id)s'") %
    {"method": resp.request.method,
     "my_service_name": "cinder",
     "my_url": resp.url, "response_request_id": request_id})

method: HTTP request method (GET/POST/PUT/DELETE etc.)
my_service_name: Name of service processing the request (cinder or
cinder-api in this case)
my_url: Request URL with endpoint
response_request_id: request_id extracted from response header

The log messages logged by the log handlers would be dependant on how the root loggers are configured.

1. python-cinderclient used as a shell command:

In this case, the root loggers will be configured in the client itself. So if --debug flag is passed in the command, then following log message will be shown on console:-

DEBUG:keystoneclient:GET call to cinder for
http://172.31.21.78:8776/v2/ebb78c2dea2d4e81920abb460345a11e/volumes/detail
used request id req-9dd9ffc4-e3cf-4d76-8f2a-1fc3abd29d20

Nothing will be logged on console if --debug flag is not set.

Note:
By default python-cinderclient uses keystone session to create object of SessionClient and 'ks_logger' configured in cinderclient/shell.py can be used for logging. If user provides auth mecahnism other than keystone using auth_plugin then HTTPClient will be initialized and 'client_logger' configured in cinderclient/shell.py can be used for logging.

2. python-cinderclient is used in applications (e.g. Nova)

In this case, when Nova calls apis of Cinder service using python-cinderclient, then following log message for get volume api will be logged in nova log file:-

DEBUG cinderclient.v2.client [req-0569e5c5-ddbe-42a2-b07c-4f4afb1926c9
demo demo] GET call to 'cinder' for http://172.31.21.78:8776/v2/
9ffea7c24c9d440d9690850da90c8bfb/volumes/f5d1aefa-5632-4c42-89ef-c115df659875
used request_id 'req-33821d15-22fb-4939-a210-70921e6937d3'

In the above log message, you will see both nova (callee) and cinder (caller) request_ids are logged in the same log message. This is because, the root loggers are configured in Nova and the same will be used by the client as well. Since nova uses oslo.log library, it internally logs request_id using ContextFormatter configured in the "formatter_context" section of the nova configuration file.

References:
[1] https://blueprints.launchpad.net/python-cinderclient/+spec/return-request-id-to-caller
[2] http://specs.openstack.org/openstack/openstack-specs/specs/return-request-id.html