diff options
author | Monty Taylor <mordred@inaugust.com> | 2018-05-16 09:41:24 -0500 |
---|---|---|
committer | Monty Taylor <mordred@inaugust.com> | 2018-05-16 15:41:59 -0500 |
commit | 244780fba84f008ddb2892b4c24ca2eb3fbcb0db (patch) | |
tree | 102a1f08d4254e4866f546b3a2906d95757740ed | |
parent | 0bebdaf0f90deef5121234ac98daa58e6f1f0f77 (diff) |
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
Notes
Notes (review):
Code-Review+2: Lance Bragstad <lbragstad@gmail.com>
Code-Review+2: Morgan Fainberg <morgan.fainberg@gmail.com>
Workflow+1: Morgan Fainberg <morgan.fainberg@gmail.com>
Verified+2: Zuul
Submitted-by: Zuul
Submitted-at: Thu, 17 May 2018 21:06:52 +0000
Reviewed-on: https://review.openstack.org/568877
Project: openstack/keystoneauth
Branch: refs/heads/master
-rw-r--r-- | keystoneauth1/loading/session.py | 15 | ||||
-rw-r--r-- | keystoneauth1/session.py | 51 | ||||
-rw-r--r-- | keystoneauth1/tests/unit/loading/test_session.py | 9 | ||||
-rw-r--r-- | keystoneauth1/tests/unit/test_session.py | 21 | ||||
-rw-r--r-- | releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml | 8 |
5 files changed, 102 insertions, 2 deletions
diff --git a/keystoneauth1/loading/session.py b/keystoneauth1/loading/session.py index 5d21f03..1e58064 100644 --- a/keystoneauth1/loading/session.py +++ b/keystoneauth1/loading/session.py | |||
@@ -118,12 +118,19 @@ class Session(base.BaseLoader): | |||
118 | metavar='<seconds>', | 118 | metavar='<seconds>', |
119 | help='Set request timeout (in seconds).') | 119 | help='Set request timeout (in seconds).') |
120 | 120 | ||
121 | session_group.add_argument( | ||
122 | '--collect-timing', | ||
123 | default=False, | ||
124 | action='store_true', | ||
125 | help='Collect per-API call timing information.') | ||
126 | |||
121 | def load_from_argparse_arguments(self, namespace, **kwargs): | 127 | def load_from_argparse_arguments(self, namespace, **kwargs): |
122 | kwargs.setdefault('insecure', namespace.insecure) | 128 | kwargs.setdefault('insecure', namespace.insecure) |
123 | kwargs.setdefault('cacert', namespace.os_cacert) | 129 | kwargs.setdefault('cacert', namespace.os_cacert) |
124 | kwargs.setdefault('cert', namespace.os_cert) | 130 | kwargs.setdefault('cert', namespace.os_cert) |
125 | kwargs.setdefault('key', namespace.os_key) | 131 | kwargs.setdefault('key', namespace.os_key) |
126 | kwargs.setdefault('timeout', namespace.timeout) | 132 | kwargs.setdefault('timeout', namespace.timeout) |
133 | kwargs.setdefault('collect_timing', namespace.collect_timing) | ||
127 | 134 | ||
128 | return self.load_from_options(**kwargs) | 135 | return self.load_from_options(**kwargs) |
129 | 136 | ||
@@ -139,6 +146,7 @@ class Session(base.BaseLoader): | |||
139 | :keyfile: The key for the client certificate. | 146 | :keyfile: The key for the client certificate. |
140 | :insecure: Whether to ignore SSL verification. | 147 | :insecure: Whether to ignore SSL verification. |
141 | :timeout: The max time to wait for HTTP connections. | 148 | :timeout: The max time to wait for HTTP connections. |
149 | :collect-timing: Whether to collect API timing information. | ||
142 | 150 | ||
143 | :param dict deprecated_opts: Deprecated options that should be included | 151 | :param dict deprecated_opts: Deprecated options that should be included |
144 | in the definition of new options. This should be a dict from the | 152 | in the definition of new options. This should be a dict from the |
@@ -175,6 +183,11 @@ class Session(base.BaseLoader): | |||
175 | cfg.IntOpt('timeout', | 183 | cfg.IntOpt('timeout', |
176 | deprecated_opts=deprecated_opts.get('timeout'), | 184 | deprecated_opts=deprecated_opts.get('timeout'), |
177 | help='Timeout value for http requests'), | 185 | help='Timeout value for http requests'), |
186 | cfg.BoolOpt('collect-timing', | ||
187 | deprecated_opts=deprecated_opts.get( | ||
188 | 'collect-timing'), | ||
189 | default=False, | ||
190 | help='Collect per-API call timing information.'), | ||
178 | ] | 191 | ] |
179 | 192 | ||
180 | def register_conf_options(self, conf, group, deprecated_opts=None): | 193 | def register_conf_options(self, conf, group, deprecated_opts=None): |
@@ -186,6 +199,7 @@ class Session(base.BaseLoader): | |||
186 | :keyfile: The key for the client certificate. | 199 | :keyfile: The key for the client certificate. |
187 | :insecure: Whether to ignore SSL verification. | 200 | :insecure: Whether to ignore SSL verification. |
188 | :timeout: The max time to wait for HTTP connections. | 201 | :timeout: The max time to wait for HTTP connections. |
202 | :collect-timing: Whether to collect API timing information. | ||
189 | 203 | ||
190 | :param oslo_config.Cfg conf: config object to register with. | 204 | :param oslo_config.Cfg conf: config object to register with. |
191 | :param string group: The ini group to register options in. | 205 | :param string group: The ini group to register options in. |
@@ -227,6 +241,7 @@ class Session(base.BaseLoader): | |||
227 | kwargs.setdefault('cert', c.certfile) | 241 | kwargs.setdefault('cert', c.certfile) |
228 | kwargs.setdefault('key', c.keyfile) | 242 | kwargs.setdefault('key', c.keyfile) |
229 | kwargs.setdefault('timeout', c.timeout) | 243 | kwargs.setdefault('timeout', c.timeout) |
244 | kwargs.setdefault('collect_timing', c.collect_timing) | ||
230 | 245 | ||
231 | return self.load_from_options(**kwargs) | 246 | return self.load_from_options(**kwargs) |
232 | 247 | ||
diff --git a/keystoneauth1/session.py b/keystoneauth1/session.py index 6ab1e14..3d8752c 100644 --- a/keystoneauth1/session.py +++ b/keystoneauth1/session.py | |||
@@ -183,6 +183,24 @@ def _determine_user_agent(): | |||
183 | return name | 183 | return name |
184 | 184 | ||
185 | 185 | ||
186 | class RequestTiming(object): | ||
187 | """Contains timing information for an HTTP interaction.""" | ||
188 | |||
189 | #: HTTP method used for the call (GET, POST, etc) | ||
190 | method = None | ||
191 | |||
192 | #: URL against which the call was made | ||
193 | url = None | ||
194 | |||
195 | #: Elapsed time information | ||
196 | elapsed = None # type: datetime.timedelta | ||
197 | |||
198 | def __init__(self, method, url, elapsed): | ||
199 | self.method = method | ||
200 | self.url = url | ||
201 | self.elapsed = elapsed | ||
202 | |||
203 | |||
186 | class Session(object): | 204 | class Session(object): |
187 | """Maintains client communication state and common functionality. | 205 | """Maintains client communication state and common functionality. |
188 | 206 | ||
@@ -244,6 +262,9 @@ class Session(object): | |||
244 | None which means automatically manage) | 262 | None which means automatically manage) |
245 | :param bool split_loggers: Split the logging of requests across multiple | 263 | :param bool split_loggers: Split the logging of requests across multiple |
246 | loggers instead of just one. Defaults to False. | 264 | loggers instead of just one. Defaults to False. |
265 | :param bool collect_timing: Whether or not to collect per-method timing | ||
266 | information for each API call. (optional, | ||
267 | defaults to False) | ||
247 | """ | 268 | """ |
248 | 269 | ||
249 | user_agent = None | 270 | user_agent = None |
@@ -256,7 +277,8 @@ class Session(object): | |||
256 | cert=None, timeout=None, user_agent=None, | 277 | cert=None, timeout=None, user_agent=None, |
257 | redirect=_DEFAULT_REDIRECT_LIMIT, additional_headers=None, | 278 | redirect=_DEFAULT_REDIRECT_LIMIT, additional_headers=None, |
258 | app_name=None, app_version=None, additional_user_agent=None, | 279 | app_name=None, app_version=None, additional_user_agent=None, |
259 | discovery_cache=None, split_loggers=None): | 280 | discovery_cache=None, split_loggers=None, |
281 | collect_timing=False): | ||
260 | 282 | ||
261 | self.auth = auth | 283 | self.auth = auth |
262 | self.session = _construct_session(session) | 284 | self.session = _construct_session(session) |
@@ -276,6 +298,8 @@ class Session(object): | |||
276 | # NOTE(mordred) split_loggers kwarg default is None rather than False | 298 | # NOTE(mordred) split_loggers kwarg default is None rather than False |
277 | # so we can distinguish between the value being set or not. | 299 | # so we can distinguish between the value being set or not. |
278 | self._split_loggers = split_loggers | 300 | self._split_loggers = split_loggers |
301 | self._collect_timing = collect_timing | ||
302 | self._api_times = [] | ||
279 | 303 | ||
280 | if timeout is not None: | 304 | if timeout is not None: |
281 | self.timeout = float(timeout) | 305 | self.timeout = float(timeout) |
@@ -808,6 +832,19 @@ class Session(object): | |||
808 | resp.status_code) | 832 | resp.status_code) |
809 | raise exceptions.from_response(resp, method, url) | 833 | raise exceptions.from_response(resp, method, url) |
810 | 834 | ||
835 | if self._collect_timing: | ||
836 | for h in resp.history: | ||
837 | self._api_times.append(RequestTiming( | ||
838 | method=h.request.method, | ||
839 | url=h.request.url, | ||
840 | elapsed=h.elapsed, | ||
841 | )) | ||
842 | self._api_times.append(RequestTiming( | ||
843 | method=resp.request.method, | ||
844 | url=resp.request.url, | ||
845 | elapsed=resp.elapsed, | ||
846 | )) | ||
847 | |||
811 | return resp | 848 | return resp |
812 | 849 | ||
813 | def _send_request(self, url, method, redirect, log, logger, split_loggers, | 850 | def _send_request(self, url, method, redirect, log, logger, split_loggers, |
@@ -1172,6 +1209,18 @@ class Session(object): | |||
1172 | auth = self._auth_required(auth, 'get project_id') | 1209 | auth = self._auth_required(auth, 'get project_id') |
1173 | return auth.get_project_id(self) | 1210 | return auth.get_project_id(self) |
1174 | 1211 | ||
1212 | def get_timings(self): | ||
1213 | """Return collected API timing information. | ||
1214 | |||
1215 | :returns: List of `RequestTiming` objects. | ||
1216 | """ | ||
1217 | return self._api_times | ||
1218 | |||
1219 | def reset_timings(self): | ||
1220 | """Clear API timing information.""" | ||
1221 | self._api_times = [] | ||
1222 | |||
1223 | |||
1175 | REQUESTS_VERSION = tuple(int(v) for v in requests.__version__.split('.')) | 1224 | REQUESTS_VERSION = tuple(int(v) for v in requests.__version__.split('.')) |
1176 | 1225 | ||
1177 | 1226 | ||
diff --git a/keystoneauth1/tests/unit/loading/test_session.py b/keystoneauth1/tests/unit/loading/test_session.py index 253ec34..bc42a59 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): | |||
70 | def new_deprecated(): | 70 | def new_deprecated(): |
71 | return cfg.DeprecatedOpt(uuid.uuid4().hex, group=uuid.uuid4().hex) | 71 | return cfg.DeprecatedOpt(uuid.uuid4().hex, group=uuid.uuid4().hex) |
72 | 72 | ||
73 | opt_names = ['cafile', 'certfile', 'keyfile', 'insecure', 'timeout'] | 73 | opt_names = [ |
74 | 'cafile', | ||
75 | 'certfile', | ||
76 | 'keyfile', | ||
77 | 'insecure', | ||
78 | 'timeout', | ||
79 | 'collect-timing', | ||
80 | ] | ||
74 | depr = dict([(n, [new_deprecated()]) for n in opt_names]) | 81 | depr = dict([(n, [new_deprecated()]) for n in opt_names]) |
75 | opts = loading.get_session_conf_options(deprecated_opts=depr) | 82 | opts = loading.get_session_conf_options(deprecated_opts=depr) |
76 | 83 | ||
diff --git a/keystoneauth1/tests/unit/test_session.py b/keystoneauth1/tests/unit/test_session.py index 94cc7d1..152a030 100644 --- a/keystoneauth1/tests/unit/test_session.py +++ b/keystoneauth1/tests/unit/test_session.py | |||
@@ -10,6 +10,7 @@ | |||
10 | # License for the specific language governing permissions and limitations | 10 | # License for the specific language governing permissions and limitations |
11 | # under the License. | 11 | # under the License. |
12 | 12 | ||
13 | import datetime | ||
13 | import itertools | 14 | import itertools |
14 | import json | 15 | import json |
15 | import logging | 16 | import logging |
@@ -1010,6 +1011,26 @@ class SessionAuthTests(utils.TestCase): | |||
1010 | key=response_key, val=response_val), | 1011 | key=response_key, val=response_val), |
1011 | body_output) | 1012 | body_output) |
1012 | 1013 | ||
1014 | def test_collect_timing(self): | ||
1015 | auth = AuthPlugin() | ||
1016 | sess = client_session.Session(auth=auth, collect_timing=True) | ||
1017 | response = {uuid.uuid4().hex: uuid.uuid4().hex} | ||
1018 | |||
1019 | self.stub_url('GET', | ||
1020 | json=response, | ||
1021 | headers={'Content-Type': 'application/json'}) | ||
1022 | |||
1023 | resp = sess.get(self.TEST_URL) | ||
1024 | |||
1025 | self.assertEqual(response, resp.json()) | ||
1026 | timings = sess.get_timings() | ||
1027 | self.assertEqual(timings[0].method, 'GET') | ||
1028 | self.assertEqual(timings[0].url, self.TEST_URL) | ||
1029 | self.assertIsInstance(timings[0].elapsed, datetime.timedelta) | ||
1030 | sess.reset_timings() | ||
1031 | timings = sess.get_timings() | ||
1032 | self.assertEqual(len(timings), 0) | ||
1033 | |||
1013 | 1034 | ||
1014 | class AdapterTest(utils.TestCase): | 1035 | class AdapterTest(utils.TestCase): |
1015 | 1036 | ||
diff --git a/releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml b/releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml new file mode 100644 index 0000000..0e09c9e --- /dev/null +++ b/releasenotes/notes/collect-timing-85f007f0d86c8b26.yaml | |||
@@ -0,0 +1,8 @@ | |||
1 | --- | ||
2 | features: | ||
3 | - | | ||
4 | Added ``collect_timing`` option to ``keystoneauth1.session.Session``. | ||
5 | The option, which is off by default, causes the ``Session`` to collect | ||
6 | API timing information for every call it makes. Methods ``get_timings`` | ||
7 | and ``reset_timings`` have been added to allow getting and clearing the | ||
8 | data. | ||