Merge "Split request logging into four different loggers"
This commit is contained in:
commit
43698b65c9
@ -39,6 +39,10 @@ Features
|
|||||||
plugins. Discovery information is automatically cached in memory, so the user
|
plugins. Discovery information is automatically cached in memory, so the user
|
||||||
need not worry about excessive use of discovery metadata.
|
need not worry about excessive use of discovery metadata.
|
||||||
|
|
||||||
|
- Safe logging of HTTP interactions
|
||||||
|
|
||||||
|
Clients need to be able to enable logging of the HTTP interactions, but some
|
||||||
|
things, such as the token or secrets, need to be ommitted.
|
||||||
|
|
||||||
Sessions for Users
|
Sessions for Users
|
||||||
==================
|
==================
|
||||||
@ -433,8 +437,163 @@ expects ``volume``.
|
|||||||
'min_version': '3',
|
'min_version': '3',
|
||||||
'max_version': 'latest'})
|
'max_version': 'latest'})
|
||||||
|
|
||||||
|
Logging
|
||||||
|
=======
|
||||||
|
|
||||||
|
The logging system uses standard `python logging`_ rooted on the
|
||||||
|
``keystoneauth`` namespace as would be expected. There are two possibilities
|
||||||
|
of where log messages about HTTP interactions will go.
|
||||||
|
|
||||||
|
By default, all messages will go to the ``keystoneauth.session`` logger.
|
||||||
|
|
||||||
|
If the ``split_loggers`` option on the :class:`keystoneauth1.session.Session`
|
||||||
|
constructor is set to ``True``, the HTTP content will be split across four
|
||||||
|
subloggers to allow for fine-grained control of what is logged and how:
|
||||||
|
|
||||||
|
keystoneauth.session.request-id
|
||||||
|
Emits a log entry at the ``DEBUG`` level for every http request
|
||||||
|
including information about the URL, ``service-type`` and ``request-id``.
|
||||||
|
|
||||||
|
keystoneauth.session.request
|
||||||
|
Emits a log entry at the ``DEBUG`` level for every http request including a
|
||||||
|
curl formatted string of the request.
|
||||||
|
|
||||||
|
keystoneauth.session.response
|
||||||
|
Emits a log entry at the ``DEBUG`` level for every http response received,
|
||||||
|
including the status code, and the headers received.
|
||||||
|
|
||||||
|
keystoneauth.session.body
|
||||||
|
Emits a log entry at the ``DEBUG`` level containing the contents of the
|
||||||
|
response body if the ``content-type`` is either ``text`` or ``json``.
|
||||||
|
|
||||||
|
Using loggers
|
||||||
|
-------------
|
||||||
|
|
||||||
|
A full description of how to consume `python logging`_ is out of scope of this
|
||||||
|
document, but a few simple examples are provided.
|
||||||
|
|
||||||
|
If you would like to configure logging to log keystoneuath at the ``INFO``
|
||||||
|
level with no ``DEBUG`` messages:
|
||||||
|
|
||||||
|
.. code-block:: python
|
||||||
|
|
||||||
|
import keystoneauth1
|
||||||
|
import logging
|
||||||
|
|
||||||
|
logger = logging.getLogger('keystoneauth')
|
||||||
|
logger.addHandler(logging.StreamHandler())
|
||||||
|
logger.setLevel(logging.INFO)
|
||||||
|
|
||||||
|
If you would like to get a full HTTP debug trace including bodies:
|
||||||
|
|
||||||
|
.. code-block:: python
|
||||||
|
|
||||||
|
import keystoneauth1
|
||||||
|
import logging
|
||||||
|
|
||||||
|
logger = logging.getLogger('keystoneauth')
|
||||||
|
logger.addHandler(logging.StreamHandler())
|
||||||
|
logger.setLevel(logging.DEBUG)
|
||||||
|
|
||||||
|
If you would like to get a full HTTP debug trace bug with no bodies:
|
||||||
|
|
||||||
|
.. code-block:: python
|
||||||
|
|
||||||
|
import keystoneauth1
|
||||||
|
import keystoneauth1.session
|
||||||
|
import logging
|
||||||
|
|
||||||
|
logger = logging.getLogger('keystoneauth')
|
||||||
|
logger.addHandler(logging.StreamHandler())
|
||||||
|
logger.setLevel(logging.DEBUG)
|
||||||
|
body_logger = logging.getLogger('keystoneauth.session.body')
|
||||||
|
body_logger.setLevel(logging.WARN)
|
||||||
|
session = keystoneauth1.session.Session(split_loggers=True)
|
||||||
|
|
||||||
|
Finally, if you would like to log request-ids and response headers to one file,
|
||||||
|
request commands, response headers and response bodies to a different file,
|
||||||
|
and everything else to the console:
|
||||||
|
|
||||||
|
.. code-block:: python
|
||||||
|
|
||||||
|
import keystoneauth1
|
||||||
|
import keystoneauth1.session
|
||||||
|
import logging
|
||||||
|
|
||||||
|
# Create a handler that outputs only outputs INFO level messages to stdout
|
||||||
|
stream_handler = logging.StreamHandler()
|
||||||
|
stream_handler.setLevel(logging.INFO)
|
||||||
|
|
||||||
|
# Configure the default behavior of all keystoneauth logging to log at the
|
||||||
|
# INFO level.
|
||||||
|
logger = logging.getLogger('keystoneauth')
|
||||||
|
logger.setLevel(logging.INFO)
|
||||||
|
|
||||||
|
# Emit INFO messages from all keystoneauth loggers to stdout
|
||||||
|
logger.addHandler(stream_handler)
|
||||||
|
|
||||||
|
# Create an output formatter that includes logger name and timestamp.
|
||||||
|
formatter = logging.Formatter('%(asctime)s %(name)s %(message)s')
|
||||||
|
|
||||||
|
# Create a file output for request ids and response headers
|
||||||
|
request_handler = logging.FileHandler('request.log')
|
||||||
|
request_handler.setFormatter(formatter)
|
||||||
|
|
||||||
|
# Create a file output for request commands, response headers and bodies
|
||||||
|
body_handler = logging.FileHandler('response-body.log')
|
||||||
|
body_handler.setFormatter(formatter)
|
||||||
|
|
||||||
|
# Log all HTTP interactions at the DEBUG level
|
||||||
|
session_logger = logging.getLogger('keystoneauth.session')
|
||||||
|
session_logger.setLevel(logging.DEBUG)
|
||||||
|
|
||||||
|
# Emit request ids to the request log
|
||||||
|
request_id_logger = logging.getLogger('keystoneauth.session.request-id')
|
||||||
|
request_id_logger.addHandler(request_handler)
|
||||||
|
|
||||||
|
# Emit response headers to both the request log and the body log
|
||||||
|
header_logger = logging.getLogger('keystoneauth.session.response')
|
||||||
|
header_logger.addHandler(request_handler)
|
||||||
|
header_logger.addHandler(body_handler)
|
||||||
|
|
||||||
|
# Emit request commands to the body log
|
||||||
|
request_logger = logging.getLogger('keystoneauth.session.request')
|
||||||
|
request_logger.addHandler(body_handler)
|
||||||
|
|
||||||
|
# Emit bodies only to the body log
|
||||||
|
body_logger = logging.getLogger('keystoneauth.session.body')
|
||||||
|
body_logger.addHandler(body_handler)
|
||||||
|
|
||||||
|
session = keystoneauth1.session.Session(split_loggers=True)
|
||||||
|
|
||||||
|
The above will produce messages like the following in request.log:
|
||||||
|
|
||||||
|
::
|
||||||
|
|
||||||
|
2017-09-19 22:10:09,466 keystoneauth.session.request-id GET call to volumev2 for http://cloud.example.com/volume/v2/137155c35fb34172a284a3c2540c92ab/volumes/detail used request id req-f4f2058a-9308-4c4a-94e6-5ee1cd6c78bd
|
||||||
|
2017-09-19 22:10:09,751 keystoneauth.session.response [200] Date: Tue, 19 Sep 2017 22:10:09 GMT Server: Apache/2.4.18 (Ubuntu) x-compute-request-id: req-2e9181d2-9f3e-404e-a12f-1f1566736ab3 Content-Type: application/json Content-Length: 15 x-openstack-request-id: req-2e9181d2-9f3e-404e-a12f-1f1566736ab3 Connection: close
|
||||||
|
|
||||||
|
And content like the following into response-body.log:
|
||||||
|
|
||||||
|
::
|
||||||
|
|
||||||
|
2017-09-19 22:10:09,490 keystoneauth.session.request curl -g -i -X GET http://cloud.example.com/volume/v2/137155c35fb34172a284a3c2540c92ab/volumes/detail?marker=34cd00cf-bf67-4667-a900-5ce233e383d5 -H "User-Agent: os-client-config/1.28.0 shade/1.23.1 keystoneauth1/3.2.0 python-requests/2.18.4 CPython/2.7.12" -H "X-Auth-Token: {SHA1}a1d03d2a4cbee590a55f1786d452e1027d5fd781"
|
||||||
|
2017-09-19 22:10:09,751 keystoneauth.session.response [200] Date: Tue, 19 Sep 2017 22:10:09 GMT Server: Apache/2.4.18 (Ubuntu) x-compute-request-id: req-2e9181d2-9f3e-404e-a12f-1f1566736ab3 Content-Type: application/json Content-Length: 15 x-openstack-request-id: req-2e9181d2-9f3e-404e-a12f-1f1566736ab3 Connection: close
|
||||||
|
2017-09-19 22:10:09,751 keystoneauth.session.body {"volumes": []}
|
||||||
|
|
||||||
|
User Provided Loggers
|
||||||
|
---------------------
|
||||||
|
|
||||||
|
The HTTP methods (request, get, post, put, etc) on
|
||||||
|
`keystoneauth1.session.Session` and `keystoneauth1.adapter.Adapter` all support
|
||||||
|
a ``logger`` parameter. A user can provide their own `logger`_ which will
|
||||||
|
override the session loggers mentioned above. If a single logger is provided
|
||||||
|
in this manner, request, response and body content will all be logged to that
|
||||||
|
logger at the ``DEBUG`` level, and the strings ``REQ:``, ``RESP:`` and
|
||||||
|
``RESP BODY:`` will be pre-pended as appropriate.
|
||||||
|
|
||||||
.. _API-WG Specs: http://specs.openstack.org/openstack/api-wg/
|
.. _API-WG Specs: http://specs.openstack.org/openstack/api-wg/
|
||||||
.. _Consuming the Catalog: http://specs.openstack.org/openstack/api-wg/guidelines/consuming-catalog.html
|
.. _Consuming the Catalog: http://specs.openstack.org/openstack/api-wg/guidelines/consuming-catalog.html
|
||||||
.. _Microversions: http://specs.openstack.org/openstack/api-wg/guidelines/microversion_specification.html#version-discovery
|
.. _Microversions: http://specs.openstack.org/openstack/api-wg/guidelines/microversion_specification.html#version-discovery
|
||||||
|
.. _python logging: https://docs.python.org/3/library/logging.html
|
||||||
|
.. _logger: https://docs.python.org/3/library/logging.html#logging.Logger
|
||||||
|
@ -50,8 +50,6 @@ DEFAULT_USER_AGENT = 'keystoneauth1/%s %s %s/%s' % (
|
|||||||
# here and we'll add it to the list as required.
|
# here and we'll add it to the list as required.
|
||||||
_LOG_CONTENT_TYPES = set(['application/json'])
|
_LOG_CONTENT_TYPES = set(['application/json'])
|
||||||
|
|
||||||
_logger = utils.get_logger(__name__)
|
|
||||||
|
|
||||||
|
|
||||||
def _construct_session(session_obj=None):
|
def _construct_session(session_obj=None):
|
||||||
# NOTE(morganfainberg): if the logic in this function changes be sure to
|
# NOTE(morganfainberg): if the logic in this function changes be sure to
|
||||||
@ -244,6 +242,8 @@ class Session(object):
|
|||||||
that do not share an auth plugin, it can
|
that do not share an auth plugin, it can
|
||||||
be provided here. (optional, defaults to
|
be provided here. (optional, defaults to
|
||||||
None which means automatically manage)
|
None which means automatically manage)
|
||||||
|
:param bool split_loggers: Split the logging of requests across multiple
|
||||||
|
loggers instead of just one. Defaults to False.
|
||||||
"""
|
"""
|
||||||
|
|
||||||
user_agent = None
|
user_agent = None
|
||||||
@ -256,7 +256,7 @@ class Session(object):
|
|||||||
cert=None, timeout=None, user_agent=None,
|
cert=None, timeout=None, user_agent=None,
|
||||||
redirect=_DEFAULT_REDIRECT_LIMIT, additional_headers=None,
|
redirect=_DEFAULT_REDIRECT_LIMIT, additional_headers=None,
|
||||||
app_name=None, app_version=None, additional_user_agent=None,
|
app_name=None, app_version=None, additional_user_agent=None,
|
||||||
discovery_cache=None):
|
discovery_cache=None, split_loggers=None):
|
||||||
|
|
||||||
self.auth = auth
|
self.auth = auth
|
||||||
self.session = _construct_session(session)
|
self.session = _construct_session(session)
|
||||||
@ -273,6 +273,7 @@ class Session(object):
|
|||||||
if discovery_cache is None:
|
if discovery_cache is None:
|
||||||
discovery_cache = {}
|
discovery_cache = {}
|
||||||
self._discovery_cache = discovery_cache
|
self._discovery_cache = discovery_cache
|
||||||
|
self._split_loggers = split_loggers
|
||||||
|
|
||||||
if timeout is not None:
|
if timeout is not None:
|
||||||
self.timeout = float(timeout)
|
self.timeout = float(timeout)
|
||||||
@ -324,16 +325,33 @@ class Session(object):
|
|||||||
return (header[0], '{SHA1}%s' % token_hash)
|
return (header[0], '{SHA1}%s' % token_hash)
|
||||||
return header
|
return header
|
||||||
|
|
||||||
|
def _get_split_loggers(self, split_loggers):
|
||||||
|
if split_loggers is None:
|
||||||
|
split_loggers = self._split_loggers
|
||||||
|
if split_loggers is None:
|
||||||
|
split_loggers = False
|
||||||
|
return split_loggers
|
||||||
|
|
||||||
def _http_log_request(self, url, method=None, data=None,
|
def _http_log_request(self, url, method=None, data=None,
|
||||||
json=None, headers=None, query_params=None,
|
json=None, headers=None, query_params=None,
|
||||||
logger=_logger):
|
logger=None, split_loggers=None):
|
||||||
|
string_parts = []
|
||||||
|
|
||||||
|
if self._get_split_loggers(split_loggers):
|
||||||
|
logger = utils.get_logger(__name__ + '.request')
|
||||||
|
else:
|
||||||
|
# Only a single logger was passed in, use string prefixing.
|
||||||
|
string_parts.append('REQ:')
|
||||||
|
if not logger:
|
||||||
|
logger = utils.get_logger(__name__)
|
||||||
|
|
||||||
if not logger.isEnabledFor(logging.DEBUG):
|
if not logger.isEnabledFor(logging.DEBUG):
|
||||||
# NOTE(morganfainberg): This whole debug section is expensive,
|
# NOTE(morganfainberg): This whole debug section is expensive,
|
||||||
# there is no need to do the work if we're not going to emit a
|
# there is no need to do the work if we're not going to emit a
|
||||||
# debug log.
|
# debug log.
|
||||||
return
|
return
|
||||||
|
|
||||||
string_parts = ['REQ: curl -g -i']
|
string_parts.append('curl -g -i')
|
||||||
|
|
||||||
# NOTE(jamielennox): None means let requests do its default validation
|
# NOTE(jamielennox): None means let requests do its default validation
|
||||||
# so we need to actually check that this is False.
|
# so we need to actually check that this is False.
|
||||||
@ -356,7 +374,8 @@ class Session(object):
|
|||||||
string_parts.append(url)
|
string_parts.append(url)
|
||||||
|
|
||||||
if headers:
|
if headers:
|
||||||
for header in headers.items():
|
# Sort headers so that testing can work consistently.
|
||||||
|
for header in sorted(headers.items()):
|
||||||
string_parts.append('-H "%s: %s"'
|
string_parts.append('-H "%s: %s"'
|
||||||
% self._process_header(header))
|
% self._process_header(header))
|
||||||
if json:
|
if json:
|
||||||
@ -373,7 +392,18 @@ class Session(object):
|
|||||||
|
|
||||||
def _http_log_response(self, response=None, json=None,
|
def _http_log_response(self, response=None, json=None,
|
||||||
status_code=None, headers=None, text=None,
|
status_code=None, headers=None, text=None,
|
||||||
logger=_logger):
|
logger=None, split_loggers=True):
|
||||||
|
string_parts = []
|
||||||
|
body_parts = []
|
||||||
|
if self._get_split_loggers(split_loggers):
|
||||||
|
logger = utils.get_logger(__name__ + '.response')
|
||||||
|
body_logger = utils.get_logger(__name__ + '.body')
|
||||||
|
else:
|
||||||
|
# Only a single logger was passed in, use string prefixing.
|
||||||
|
string_parts.append('RESP:')
|
||||||
|
body_parts.append('RESP BODY:')
|
||||||
|
body_logger = logger
|
||||||
|
|
||||||
if not logger.isEnabledFor(logging.DEBUG):
|
if not logger.isEnabledFor(logging.DEBUG):
|
||||||
return
|
return
|
||||||
|
|
||||||
@ -382,6 +412,19 @@ class Session(object):
|
|||||||
status_code = response.status_code
|
status_code = response.status_code
|
||||||
if not headers:
|
if not headers:
|
||||||
headers = response.headers
|
headers = response.headers
|
||||||
|
|
||||||
|
if status_code:
|
||||||
|
string_parts.append('[%s]' % status_code)
|
||||||
|
if headers:
|
||||||
|
# Sort headers so that testing can work consistently.
|
||||||
|
for header in sorted(headers.items()):
|
||||||
|
string_parts.append('%s: %s' % self._process_header(header))
|
||||||
|
logger.debug(' '.join(string_parts))
|
||||||
|
|
||||||
|
if not body_logger.isEnabledFor(logging.DEBUG):
|
||||||
|
return
|
||||||
|
|
||||||
|
if response is not None:
|
||||||
if not text:
|
if not text:
|
||||||
# NOTE(samueldmq): If the response does not provide enough info
|
# NOTE(samueldmq): If the response does not provide enough info
|
||||||
# about the content type to decide whether it is useful and
|
# about the content type to decide whether it is useful and
|
||||||
@ -406,17 +449,9 @@ class Session(object):
|
|||||||
if json:
|
if json:
|
||||||
text = self._json.encode(json)
|
text = self._json.encode(json)
|
||||||
|
|
||||||
string_parts = ['RESP:']
|
|
||||||
|
|
||||||
if status_code:
|
|
||||||
string_parts.append('[%s]' % status_code)
|
|
||||||
if headers:
|
|
||||||
for header in headers.items():
|
|
||||||
string_parts.append('%s: %s' % self._process_header(header))
|
|
||||||
if text:
|
if text:
|
||||||
string_parts.append('\nRESP BODY: %s\n' % text)
|
body_parts.append(text)
|
||||||
|
body_logger.debug(' '.join(body_parts))
|
||||||
logger.debug(' '.join(string_parts))
|
|
||||||
|
|
||||||
@staticmethod
|
@staticmethod
|
||||||
def _set_microversion_headers(
|
def _set_microversion_headers(
|
||||||
@ -465,7 +500,7 @@ class Session(object):
|
|||||||
user_agent=None, redirect=None, authenticated=None,
|
user_agent=None, redirect=None, authenticated=None,
|
||||||
endpoint_filter=None, auth=None, requests_auth=None,
|
endpoint_filter=None, auth=None, requests_auth=None,
|
||||||
raise_exc=True, allow_reauth=True, log=True,
|
raise_exc=True, allow_reauth=True, log=True,
|
||||||
endpoint_override=None, connect_retries=0, logger=_logger,
|
endpoint_override=None, connect_retries=0, logger=None,
|
||||||
allow=None, client_name=None, client_version=None,
|
allow=None, client_name=None, client_version=None,
|
||||||
microversion=None, microversion_service_type=None,
|
microversion=None, microversion_service_type=None,
|
||||||
**kwargs):
|
**kwargs):
|
||||||
@ -560,6 +595,14 @@ class Session(object):
|
|||||||
|
|
||||||
:returns: The response to the request.
|
:returns: The response to the request.
|
||||||
"""
|
"""
|
||||||
|
# If a logger is passed in, use it and do not log requests, responses
|
||||||
|
# and bodies separately.
|
||||||
|
if logger:
|
||||||
|
split_loggers = False
|
||||||
|
else:
|
||||||
|
split_loggers = None
|
||||||
|
logger = logger or utils.get_logger(__name__)
|
||||||
|
|
||||||
headers = kwargs.setdefault('headers', dict())
|
headers = kwargs.setdefault('headers', dict())
|
||||||
if microversion:
|
if microversion:
|
||||||
self._set_microversion_headers(
|
self._set_microversion_headers(
|
||||||
@ -671,7 +714,7 @@ class Session(object):
|
|||||||
data=kwargs.get('data'),
|
data=kwargs.get('data'),
|
||||||
headers=headers,
|
headers=headers,
|
||||||
query_params=query_params,
|
query_params=query_params,
|
||||||
logger=logger)
|
logger=logger, split_loggers=split_loggers)
|
||||||
|
|
||||||
# Force disable requests redirect handling. We will manage this below.
|
# Force disable requests redirect handling. We will manage this below.
|
||||||
kwargs['allow_redirects'] = False
|
kwargs['allow_redirects'] = False
|
||||||
@ -681,7 +724,7 @@ class Session(object):
|
|||||||
|
|
||||||
send = functools.partial(self._send_request,
|
send = functools.partial(self._send_request,
|
||||||
url, method, redirect, log, logger,
|
url, method, redirect, log, logger,
|
||||||
connect_retries)
|
split_loggers, connect_retries)
|
||||||
|
|
||||||
try:
|
try:
|
||||||
connection_params = self.get_auth_connection_params(auth=auth)
|
connection_params = self.get_auth_connection_params(auth=auth)
|
||||||
@ -713,13 +756,29 @@ class Session(object):
|
|||||||
request_id = (resp.headers.get('x-openstack-request-id') or
|
request_id = (resp.headers.get('x-openstack-request-id') or
|
||||||
resp.headers.get('x-compute-request-id'))
|
resp.headers.get('x-compute-request-id'))
|
||||||
if request_id:
|
if request_id:
|
||||||
logger.debug('%(method)s call to %(service_name)s for '
|
if self._get_split_loggers(split_loggers):
|
||||||
|
id_logger = utils.get_logger(__name__ + '.request-id')
|
||||||
|
else:
|
||||||
|
id_logger = logger
|
||||||
|
if service_name:
|
||||||
|
id_logger.debug(
|
||||||
|
'%(method)s call to %(service_name)s for '
|
||||||
'%(url)s used request id '
|
'%(url)s used request id '
|
||||||
'%(response_request_id)s',
|
'%(response_request_id)s', {
|
||||||
{'method': resp.request.method,
|
'method': resp.request.method,
|
||||||
'service_name': service_name,
|
'service_name': service_name,
|
||||||
'url': resp.url,
|
'url': resp.url,
|
||||||
'response_request_id': request_id})
|
'response_request_id': request_id
|
||||||
|
})
|
||||||
|
else:
|
||||||
|
id_logger.debug(
|
||||||
|
'%(method)s call to '
|
||||||
|
'%(url)s used request id '
|
||||||
|
'%(response_request_id)s', {
|
||||||
|
'method': resp.request.method,
|
||||||
|
'url': resp.url,
|
||||||
|
'response_request_id': request_id
|
||||||
|
})
|
||||||
|
|
||||||
# handle getting a 401 Unauthorized response by invalidating the plugin
|
# handle getting a 401 Unauthorized response by invalidating the plugin
|
||||||
# and then retrying the request. This is only tried once.
|
# and then retrying the request. This is only tried once.
|
||||||
@ -738,7 +797,7 @@ class Session(object):
|
|||||||
|
|
||||||
return resp
|
return resp
|
||||||
|
|
||||||
def _send_request(self, url, method, redirect, log, logger,
|
def _send_request(self, url, method, redirect, log, logger, split_loggers,
|
||||||
connect_retries, connect_retry_delay=0.5, **kwargs):
|
connect_retries, connect_retry_delay=0.5, **kwargs):
|
||||||
# NOTE(jamielennox): We handle redirection manually because the
|
# NOTE(jamielennox): We handle redirection manually because the
|
||||||
# requests lib follows some browser patterns where it will redirect
|
# requests lib follows some browser patterns where it will redirect
|
||||||
@ -784,13 +843,15 @@ class Session(object):
|
|||||||
time.sleep(connect_retry_delay)
|
time.sleep(connect_retry_delay)
|
||||||
|
|
||||||
return self._send_request(
|
return self._send_request(
|
||||||
url, method, redirect, log, logger,
|
url, method, redirect, log, logger, split_loggers,
|
||||||
connect_retries=connect_retries - 1,
|
connect_retries=connect_retries - 1,
|
||||||
connect_retry_delay=connect_retry_delay * 2,
|
connect_retry_delay=connect_retry_delay * 2,
|
||||||
**kwargs)
|
**kwargs)
|
||||||
|
|
||||||
if log:
|
if log:
|
||||||
self._http_log_response(response=resp, logger=logger)
|
self._http_log_response(
|
||||||
|
response=resp, logger=logger,
|
||||||
|
split_loggers=split_loggers)
|
||||||
|
|
||||||
if resp.status_code in self._REDIRECT_STATUSES:
|
if resp.status_code in self._REDIRECT_STATUSES:
|
||||||
# be careful here in python True == 1 and False == 0
|
# be careful here in python True == 1 and False == 0
|
||||||
@ -812,7 +873,7 @@ class Session(object):
|
|||||||
# NOTE(jamielennox): We don't pass through connect_retry_delay.
|
# NOTE(jamielennox): We don't pass through connect_retry_delay.
|
||||||
# This request actually worked so we can reset the delay count.
|
# This request actually worked so we can reset the delay count.
|
||||||
new_resp = self._send_request(
|
new_resp = self._send_request(
|
||||||
location, method, redirect, log, logger,
|
location, method, redirect, log, logger, split_loggers,
|
||||||
connect_retries=connect_retries,
|
connect_retries=connect_retries,
|
||||||
**kwargs)
|
**kwargs)
|
||||||
|
|
||||||
|
@ -956,6 +956,60 @@ class SessionAuthTests(utils.TestCase):
|
|||||||
self.assertNotIn(list(response.keys())[0], self.logger.output)
|
self.assertNotIn(list(response.keys())[0], self.logger.output)
|
||||||
self.assertNotIn(list(response.values())[0], self.logger.output)
|
self.assertNotIn(list(response.values())[0], self.logger.output)
|
||||||
|
|
||||||
|
def test_split_loggers(self):
|
||||||
|
|
||||||
|
def get_logger_io(name):
|
||||||
|
logger_name = 'keystoneauth.session.{name}'.format(name=name)
|
||||||
|
logger = logging.getLogger(logger_name)
|
||||||
|
logger.setLevel(logging.DEBUG)
|
||||||
|
|
||||||
|
io = six.StringIO()
|
||||||
|
handler = logging.StreamHandler(io)
|
||||||
|
logger.addHandler(handler)
|
||||||
|
return io
|
||||||
|
|
||||||
|
io = {}
|
||||||
|
for name in ('request', 'body', 'response', 'request-id'):
|
||||||
|
io[name] = get_logger_io(name)
|
||||||
|
|
||||||
|
auth = AuthPlugin()
|
||||||
|
sess = client_session.Session(auth=auth, split_loggers=True)
|
||||||
|
response_key = uuid.uuid4().hex
|
||||||
|
response_val = uuid.uuid4().hex
|
||||||
|
response = {response_key: response_val}
|
||||||
|
request_id = uuid.uuid4().hex
|
||||||
|
|
||||||
|
self.stub_url(
|
||||||
|
'GET',
|
||||||
|
json=response,
|
||||||
|
headers={
|
||||||
|
'Content-Type': 'application/json',
|
||||||
|
'X-OpenStack-Request-ID': request_id,
|
||||||
|
})
|
||||||
|
|
||||||
|
resp = sess.get(self.TEST_URL)
|
||||||
|
|
||||||
|
self.assertEqual(response, resp.json())
|
||||||
|
|
||||||
|
request_output = io['request'].getvalue().strip()
|
||||||
|
response_output = io['response'].getvalue().strip()
|
||||||
|
body_output = io['body'].getvalue().strip()
|
||||||
|
id_output = io['request-id'].getvalue().strip()
|
||||||
|
|
||||||
|
self.assertIn('curl -g -i -X GET {url}'.format(url=self.TEST_URL),
|
||||||
|
request_output)
|
||||||
|
self.assertEqual('[200] Content-Type: application/json '
|
||||||
|
'X-OpenStack-Request-ID: '
|
||||||
|
'{id}'.format(id=request_id), response_output)
|
||||||
|
self.assertEqual(
|
||||||
|
'GET call to {url} used request id {id}'.format(
|
||||||
|
url=self.TEST_URL, id=request_id),
|
||||||
|
id_output)
|
||||||
|
self.assertEqual(
|
||||||
|
'{{"{key}": "{val}"}}'.format(
|
||||||
|
key=response_key, val=response_val),
|
||||||
|
body_output)
|
||||||
|
|
||||||
|
|
||||||
class AdapterTest(utils.TestCase):
|
class AdapterTest(utils.TestCase):
|
||||||
|
|
||||||
|
1
tox.ini
1
tox.ini
@ -7,6 +7,7 @@ envlist = py35,py27,pep8,releasenotes
|
|||||||
usedevelop = True
|
usedevelop = True
|
||||||
install_command = {toxinidir}/tools/tox_install.sh {env:UPPER_CONSTRAINTS_FILE:https://git.openstack.org/cgit/openstack/requirements/plain/upper-constraints.txt} {opts} {packages}
|
install_command = {toxinidir}/tools/tox_install.sh {env:UPPER_CONSTRAINTS_FILE:https://git.openstack.org/cgit/openstack/requirements/plain/upper-constraints.txt} {opts} {packages}
|
||||||
setenv = VIRTUAL_ENV={envdir}
|
setenv = VIRTUAL_ENV={envdir}
|
||||||
|
PYTHONHASHSEED=0
|
||||||
BRANCH_NAME=master
|
BRANCH_NAME=master
|
||||||
CLIENT_NAME=keystoneauth1
|
CLIENT_NAME=keystoneauth1
|
||||||
OS_STDOUT_NOCAPTURE=False
|
OS_STDOUT_NOCAPTURE=False
|
||||||
|
Loading…
Reference in New Issue
Block a user