From 244780fba84f008ddb2892b4c24ca2eb3fbcb0db Mon Sep 17 00:00:00 2001 From: Monty Taylor Date: Wed, 16 May 2018 09:41:24 -0500 Subject: [PATCH] Collect timing information for API calls python-openstackclient does this in a wrapper class around Session, and openstacksdk does something similar that could be removed if support were directly in keystoneauth. Add this so that we can remove the custom wrapper/manipulation in openstackclient and openstacksdk. Change-Id: Icf00c66f57d20d2cef724c233160d3b1e0d52102 --- keystoneauth1/loading/session.py | 15 ++++++ keystoneauth1/session.py | 51 ++++++++++++++++++- .../tests/unit/loading/test_session.py | 9 +++- keystoneauth1/tests/unit/test_session.py | 21 ++++++++ .../collect-timing-85f007f0d86c8b26.yaml | 8 +++ 5 files changed, 102 insertions(+), 2 deletions(-) create mode 100644 releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml diff --git a/keystoneauth1/loading/session.py b/keystoneauth1/loading/session.py index 5d21f036..1e580647 100644 --- a/keystoneauth1/loading/session.py +++ b/keystoneauth1/loading/session.py @@ -118,12 +118,19 @@ class Session(base.BaseLoader): metavar='', help='Set request timeout (in seconds).') + session_group.add_argument( + '--collect-timing', + default=False, + action='store_true', + help='Collect per-API call timing information.') + def load_from_argparse_arguments(self, namespace, **kwargs): kwargs.setdefault('insecure', namespace.insecure) kwargs.setdefault('cacert', namespace.os_cacert) kwargs.setdefault('cert', namespace.os_cert) kwargs.setdefault('key', namespace.os_key) kwargs.setdefault('timeout', namespace.timeout) + kwargs.setdefault('collect_timing', namespace.collect_timing) return self.load_from_options(**kwargs) @@ -139,6 +146,7 @@ class Session(base.BaseLoader): :keyfile: The key for the client certificate. :insecure: Whether to ignore SSL verification. :timeout: The max time to wait for HTTP connections. + :collect-timing: Whether to collect API timing information. :param dict deprecated_opts: Deprecated options that should be included in the definition of new options. This should be a dict from the @@ -175,6 +183,11 @@ class Session(base.BaseLoader): cfg.IntOpt('timeout', deprecated_opts=deprecated_opts.get('timeout'), help='Timeout value for http requests'), + cfg.BoolOpt('collect-timing', + deprecated_opts=deprecated_opts.get( + 'collect-timing'), + default=False, + help='Collect per-API call timing information.'), ] def register_conf_options(self, conf, group, deprecated_opts=None): @@ -186,6 +199,7 @@ class Session(base.BaseLoader): :keyfile: The key for the client certificate. :insecure: Whether to ignore SSL verification. :timeout: The max time to wait for HTTP connections. + :collect-timing: Whether to collect API timing information. :param oslo_config.Cfg conf: config object to register with. :param string group: The ini group to register options in. @@ -227,6 +241,7 @@ class Session(base.BaseLoader): kwargs.setdefault('cert', c.certfile) kwargs.setdefault('key', c.keyfile) kwargs.setdefault('timeout', c.timeout) + kwargs.setdefault('collect_timing', c.collect_timing) return self.load_from_options(**kwargs) diff --git a/keystoneauth1/session.py b/keystoneauth1/session.py index 6ab1e144..3d8752c4 100644 --- a/keystoneauth1/session.py +++ b/keystoneauth1/session.py @@ -183,6 +183,24 @@ def _determine_user_agent(): return name +class RequestTiming(object): + """Contains timing information for an HTTP interaction.""" + + #: HTTP method used for the call (GET, POST, etc) + method = None + + #: URL against which the call was made + url = None + + #: Elapsed time information + elapsed = None # type: datetime.timedelta + + def __init__(self, method, url, elapsed): + self.method = method + self.url = url + self.elapsed = elapsed + + class Session(object): """Maintains client communication state and common functionality. @@ -244,6 +262,9 @@ class Session(object): None which means automatically manage) :param bool split_loggers: Split the logging of requests across multiple loggers instead of just one. Defaults to False. + :param bool collect_timing: Whether or not to collect per-method timing + information for each API call. (optional, + defaults to False) """ user_agent = None @@ -256,7 +277,8 @@ class Session(object): cert=None, timeout=None, user_agent=None, redirect=_DEFAULT_REDIRECT_LIMIT, additional_headers=None, app_name=None, app_version=None, additional_user_agent=None, - discovery_cache=None, split_loggers=None): + discovery_cache=None, split_loggers=None, + collect_timing=False): self.auth = auth self.session = _construct_session(session) @@ -276,6 +298,8 @@ class Session(object): # NOTE(mordred) split_loggers kwarg default is None rather than False # so we can distinguish between the value being set or not. self._split_loggers = split_loggers + self._collect_timing = collect_timing + self._api_times = [] if timeout is not None: self.timeout = float(timeout) @@ -808,6 +832,19 @@ class Session(object): resp.status_code) raise exceptions.from_response(resp, method, url) + if self._collect_timing: + for h in resp.history: + self._api_times.append(RequestTiming( + method=h.request.method, + url=h.request.url, + elapsed=h.elapsed, + )) + self._api_times.append(RequestTiming( + method=resp.request.method, + url=resp.request.url, + elapsed=resp.elapsed, + )) + return resp def _send_request(self, url, method, redirect, log, logger, split_loggers, @@ -1172,6 +1209,18 @@ class Session(object): auth = self._auth_required(auth, 'get project_id') return auth.get_project_id(self) + def get_timings(self): + """Return collected API timing information. + + :returns: List of `RequestTiming` objects. + """ + return self._api_times + + def reset_timings(self): + """Clear API timing information.""" + self._api_times = [] + + REQUESTS_VERSION = tuple(int(v) for v in requests.__version__.split('.')) diff --git a/keystoneauth1/tests/unit/loading/test_session.py b/keystoneauth1/tests/unit/loading/test_session.py index 253ec34c..bc42a59d 100644 --- a/keystoneauth1/tests/unit/loading/test_session.py +++ b/keystoneauth1/tests/unit/loading/test_session.py @@ -70,7 +70,14 @@ class ConfLoadingTests(utils.TestCase): def new_deprecated(): return cfg.DeprecatedOpt(uuid.uuid4().hex, group=uuid.uuid4().hex) - opt_names = ['cafile', 'certfile', 'keyfile', 'insecure', 'timeout'] + opt_names = [ + 'cafile', + 'certfile', + 'keyfile', + 'insecure', + 'timeout', + 'collect-timing', + ] depr = dict([(n, [new_deprecated()]) for n in opt_names]) opts = loading.get_session_conf_options(deprecated_opts=depr) diff --git a/keystoneauth1/tests/unit/test_session.py b/keystoneauth1/tests/unit/test_session.py index 94cc7d15..152a030f 100644 --- a/keystoneauth1/tests/unit/test_session.py +++ b/keystoneauth1/tests/unit/test_session.py @@ -10,6 +10,7 @@ # License for the specific language governing permissions and limitations # under the License. +import datetime import itertools import json import logging @@ -1010,6 +1011,26 @@ class SessionAuthTests(utils.TestCase): key=response_key, val=response_val), body_output) + def test_collect_timing(self): + auth = AuthPlugin() + sess = client_session.Session(auth=auth, collect_timing=True) + response = {uuid.uuid4().hex: uuid.uuid4().hex} + + self.stub_url('GET', + json=response, + headers={'Content-Type': 'application/json'}) + + resp = sess.get(self.TEST_URL) + + self.assertEqual(response, resp.json()) + timings = sess.get_timings() + self.assertEqual(timings[0].method, 'GET') + self.assertEqual(timings[0].url, self.TEST_URL) + self.assertIsInstance(timings[0].elapsed, datetime.timedelta) + sess.reset_timings() + timings = sess.get_timings() + self.assertEqual(len(timings), 0) + class AdapterTest(utils.TestCase): diff --git a/releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml b/releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml new file mode 100644 index 00000000..0e09c9e0 --- /dev/null +++ b/releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml @@ -0,0 +1,8 @@ +--- +features: + - | + Added ``collect_timing`` option to ``keystoneauth1.session.Session``. + The option, which is off by default, causes the ``Session`` to collect + API timing information for every call it makes. Methods ``get_timings`` + and ``reset_timings`` have been added to allow getting and clearing the + data.