x-openstack-request-id logged twice in logs

In the recent release of keystoneauth1 2.18.0 provision is made to log
x-openstack-request-id for session client. Once this new library is synced
in openstack projects, the x-openstack-request-id will be logged twice
on the console if session client is used.

For example,
$ glance --debug image-list

DEBUG:keystoneauth.session:GET call to image for
http://10.232.48.204:9292/v2/schemas/image used request id
req-96a3f203-c605-4c96-a31d-f1199d41705c

DEBUG:glanceclient.common.http:GET call to glance-api for
http://10.232.48.204:9292/v2/schemas/image used request id
req-96a3f203-c605-4c96-a31d-f1199d41705c

Above log will be logged twice on the console.

Removed logging of x-openstack-request-id in case of SessionClient as it
is already logged in keystoneauth1. x-openstack-request-id will only be
logged once on console if HTTPClient is used.

Depends-On: I492b331ff3da8d0b91178bf0d5fe1d3702f15bd7
Closes-Bug: #1657351
Change-Id: I64258f997dc060113f53682aee74bdd40a346e54
This commit is contained in:
Abhishek Kekane
2017-01-18 12:38:26 +05:30
committed by abhishekkekane
parent 1cd7030c8f
commit 87e4f7646f
2 changed files with 28 additions and 10 deletions

View File

@@ -92,16 +92,6 @@ class _BaseHTTPClient(object):
return data
def _handle_response(self, resp):
# log request-id for each api cal
request_id = resp.headers.get('x-openstack-request-id')
if request_id:
LOG.debug('%(method)s call to glance-api for '
'%(url)s used request id '
'%(response_request_id)s',
{'method': resp.request.method,
'url': resp.url,
'response_request_id': request_id})
if not resp.ok:
LOG.debug("Request returned failure status %s.", resp.status_code)
raise exc.from_response(resp, resp.content)
@@ -274,6 +264,16 @@ class HTTPClient(_BaseHTTPClient):
{'endpoint': endpoint, 'e': e})
raise exc.CommunicationError(message=message)
# log request-id for each api call
request_id = resp.headers.get('x-openstack-request-id')
if request_id:
LOG.debug('%(method)s call to image for '
'%(url)s used request id '
'%(response_request_id)s',
{'method': resp.request.method,
'url': resp.url,
'response_request_id': request_id})
resp, body_iter = self._handle_response(resp)
self.log_http_response(resp)
return resp, body_iter

View File

@@ -14,7 +14,9 @@
# under the License.
import functools
import json
import logging
import fixtures
from keystoneauth1 import session
from keystoneauth1 import token_endpoint
import mock
@@ -378,6 +380,22 @@ class TestClient(testtools.TestCase):
matchers.Not(matchers.MatchesRegex(token_regex)),
'token found in LOG.debug parameter')
def test_log_request_id_once(self):
logger = self.useFixture(fixtures.FakeLogger(level=logging.DEBUG))
data = "TEST"
path = '/v1/images/'
self.mock.get(self.endpoint + path, body=six.StringIO(data),
headers={"Content-Type": "application/octet-stream",
'x-openstack-request-id': "1234"})
resp, body = self.client.get(path)
self.assertIsInstance(body, types.GeneratorType)
self.assertEqual([data], list(body))
expected_log = ("GET call to image "
"for http://example.com:9292/v1/images/ "
"used request id 1234")
self.assertEqual(1, logger.output.count(expected_log))
def test_expired_token_has_changed(self):
# instantiate client with some token
fake_token = b'fake-token'