Log request-id for each api call

Added support to log 'X-Openstack-Request-Id' or
'X-Compute-Request-Id' in case of Nova for each api call.

If any python-*client which is using session is used from
command line then following log will be logged on console
if --debug flag is used.

DEBUG (session:350) GET call to compute for
http://10.232.48.201:8774/v2.1/servers/detail used
request id req-c54b8f3e-a7e4-4085-a5e3-fd5244ef3ce5

If any python-*client which is using session  is used in
applications (e.g. Nova) then following log message will be
logged in service logs.

DEBUG keystoneauth.session
[req-a6929d46-765c-44a9-8370-49ff0f1958ca admin admin] GET call
to network for
http://10.232.48.201:9696/v2.0/security-groups.json?id=040cc729-9086-4f41-8977-acb4ef71c7de used request id req-de6bfe07-22ac-4940-b65e-367cb0e8102d

DocImpact:
To use this feature user need to set 'default_log_levels' in third
party application. For example in nova.conf 'default_log_levels'
should be set as below:

default_log_levels = keystoneauth1=DEBUG

Closes-Bug: #1605488
Change-Id: If0c5a4eb7d51c601ba38149f846ebcd6116d18be
This commit is contained in:
Abhishek Kekane 2016-06-22 16:26:01 +05:30
parent b7008bd1b6
commit af658d0686
2 changed files with 51 additions and 0 deletions

View File

@ -605,6 +605,30 @@ class Session(object):
resp = send(**kwargs)
# log callee and caller request-id for each api call
if log:
# service_name should be fetched from endpoint_filter if it is not
# present then use service_type as service_name.
service_name = None
if endpoint_filter:
service_name = endpoint_filter.get('service_name')
if not service_name:
service_name = endpoint_filter.get('service_type')
# Nova uses 'x-compute-request-id' and other services like
# Glance, Cinder etc are using 'x-openstack-request-id' to store
# request-id in the header
request_id = (resp.headers.get('x-openstack-request-id') or
resp.headers.get('x-compute-request-id'))
if request_id:
logger.debug('%(method)s call to %(service_name)s for '
'%(url)s used request id '
'%(response_request_id)s',
{'method': resp.request.method,
'service_name': service_name,
'url': resp.url,
'response_request_id': request_id})
# handle getting a 401 Unauthorized response by invalidating the plugin
# and then retrying the request. This is only tried once.
if resp.status_code == 401 and authenticated and allow_reauth:

View File

@ -218,6 +218,33 @@ class SessionTests(utils.TestCase):
self.assertEqual(v, resp.headers[k])
self.assertNotIn(v, self.logger.output)
def test_session_debug_output_logs_openstack_request_id(self):
"""Test x-openstack-request-id is logged in debug logs."""
def get_response(log=True):
session = client_session.Session(verify=False)
endpoint_filter = {'service_name': 'Identity'}
headers = {'X-OpenStack-Request-Id': 'req-1234'}
body = 'BODYRESPONSE'
data = 'BODYDATA'
all_headers = dict(itertools.chain(headers.items()))
self.stub_url('POST', text=body, headers=all_headers)
resp = session.post(self.TEST_URL, endpoint_filter=endpoint_filter,
headers=all_headers, data=data, log=log)
return resp
# if log is disabled then request-id is not logged in debug logs
resp = get_response(log=False)
self.assertEqual(resp.status_code, 200)
expected_log = ('POST call to Identity for %s used request '
'id req-1234' % self.TEST_URL)
self.assertNotIn(expected_log, self.logger.output)
# if log is enabled then request-id is logged in debug logs
resp = get_response()
self.assertEqual(resp.status_code, 200)
self.assertIn(expected_log, self.logger.output)
def test_logs_failed_output(self):
"""Test that output is logged even for failed requests."""
session = client_session.Session()