From 3d5a97f76bbcc0131814b2e086605aad47924e6f Mon Sep 17 00:00:00 2001 From: Alistair Coles Date: Fri, 19 Apr 2024 12:33:48 +0100 Subject: [PATCH] proxy_logging: unit test first-byte.timing metrics Add some test assertions to cover the first-byte timing metrics introduced in the related change. Add ttfb param to log_request docstring. Change-Id: I530652dd672d7d4e5eac351ccbad318773414f7d Related-Change: I1611e34846e586703e9d3709fa64e8df41f2d685 --- swift/common/middleware/proxy_logging.py | 1 + test/unit/common/middleware/test_proxy_logging.py | 11 +++++++++++ 2 files changed, 12 insertions(+) diff --git a/swift/common/middleware/proxy_logging.py b/swift/common/middleware/proxy_logging.py index 90eb2f7ab8..ed5d218f34 100644 --- a/swift/common/middleware/proxy_logging.py +++ b/swift/common/middleware/proxy_logging.py @@ -247,6 +247,7 @@ class ProxyLoggingMiddleware(object): :param start_time: timestamp request started :param end_time: timestamp request completed :param resp_headers: dict of the response headers + :param ttfb: time to first byte :param wire_status_int: the on the wire status int """ self.obscure_req(req) diff --git a/test/unit/common/middleware/test_proxy_logging.py b/test/unit/common/middleware/test_proxy_logging.py index 598e2eb999..251e52b71b 100644 --- a/test/unit/common/middleware/test_proxy_logging.py +++ b/test/unit/common/middleware/test_proxy_logging.py @@ -235,11 +235,16 @@ class TestProxyLogging(unittest.TestCase): self.assertEqual(b'7654321', b''.join(iter_response)) self.assertTiming('%s.GET.321.timing' % exp_type, app, exp_timing=2.71828182846 * 1000) + self.assertTiming('%s.GET.321.first-byte.timing' + % exp_type, app, exp_timing=0.5 * 1000) if exp_type == 'object': # Object operations also return stats by policy # In this case, the value needs to match the timing for GET self.assertTiming('%s.policy.0.GET.321.timing' % exp_type, app, exp_timing=2.71828182846 * 1000) + self.assertTiming( + '%s.policy.0.GET.321.first-byte.timing' + % exp_type, app, exp_timing=0.5 * 1000) self.assertUpdateStats([('%s.GET.321.xfer' % exp_type, 4 + 7), ('object.policy.0.GET.321.xfer', @@ -432,6 +437,8 @@ class TestProxyLogging(unittest.TestCase): # we can also expect error metrics self.assertTiming('object.GET.503.timing', app, exp_timing=700.0) + self.assertTiming('object.GET.503.first-byte.timing', app, + exp_timing=200.0) def test_basic_error(self): swift = FakeSwift() @@ -457,6 +464,8 @@ class TestProxyLogging(unittest.TestCase): # we can also expect error metrics self.assertTiming('UNKNOWN.GET.503.timing', app, exp_timing=700.0) + self.assertTiming('UNKNOWN.GET.503.first-byte.timing', app, + exp_timing=200.0) def test_middleware_exception(self): self.logger = debug_logger() @@ -507,6 +516,8 @@ class TestProxyLogging(unittest.TestCase): # we can also expect error metrics self.assertTiming('FA.GET.503.timing', app, exp_timing=700.0) + self.assertTiming('FA.GET.503.first-byte.timing', app, + exp_timing=200.0) def test_basic_req_second_time(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {})