Log request_id for each api call

Blueprint [1] is up for review 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": "glance-api",
     "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 (glance or
                 glance-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-glanceclient 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:glanceclient.common.http:GET call to glance-api for http://172.26.88.20:9292/v2/schemas/image used request id req-e0c7c97a-8fc0-4ce3-a669-d0b1eb5d7aae

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

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

In this case, when Nova calls apis of Glance service using python-glanceclient, then following log message for get image-list api will be logged in nova log file:-

DEBUG glanceclient.common.http [req-be074f1e-1c17-4786-b703-2a221751c8f4 demo demo] GET call to glance-api for http://172.26.88.20:9292/v1/images/detail?is_public=none&limit=20 used request id req-9b1dd929-df30-46b2-a8f2-dfd6ffbad3fc

In the above log message, you will see both nova (callee) and glance (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-glanceclient/+spec/return-request-id-to-caller
[2] http://specs.openstack.org/openstack/openstack-specs/specs/return-request-id.html

Mailing List discussion:
http://lists.openstack.org/pipermail/openstack-dev/2016-March/088001.html