From d90ee78966f893f9dc4b85dfe97bf93b6b25f792 Mon Sep 17 00:00:00 2001 From: Tim Burke Date: Thu, 29 Oct 2020 15:40:17 -0700 Subject: [PATCH] tests: Replace FakeLogger with debug_logger in test_proxy_logging Change-Id: I4ecc98bbe6d9817fa40fbb54f743859550e84994 --- .../common/middleware/test_proxy_logging.py | 108 +++++++++--------- 1 file changed, 54 insertions(+), 54 deletions(-) diff --git a/test/unit/common/middleware/test_proxy_logging.py b/test/unit/common/middleware/test_proxy_logging.py index d33b7bebea..3e65f82652 100644 --- a/test/unit/common/middleware/test_proxy_logging.py +++ b/test/unit/common/middleware/test_proxy_logging.py @@ -26,7 +26,7 @@ from swift.common.middleware import proxy_logging from swift.common.swob import Request, Response from swift.common import constraints from swift.common.storage_policy import StoragePolicy -from test.unit import FakeLogger +from test.unit import debug_logger from test.unit import patch_policies from test.unit.common.middleware.helpers import FakeAppThatExcepts @@ -151,7 +151,7 @@ class TestProxyLogging(unittest.TestCase): def test_log_request_statsd_invalid_stats_types(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() for url in ['/', '/foo', '/foo/bar', '/v1']: req = Request.blank(url, environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) @@ -164,7 +164,7 @@ class TestProxyLogging(unittest.TestCase): for bad_path in ['', '/', '/bad', '/baddy/mc_badderson', '/v1', '/v1/']: app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank(bad_path, environ={'REQUEST_METHOD': 'GET'}) now = 10000.0 app.log_request(req, 123, 7, 13, now, now + 2.71828182846) @@ -199,7 +199,7 @@ class TestProxyLogging(unittest.TestCase): # GET app = proxy_logging.ProxyLoggingMiddleware( FakeApp(body=b'7654321', response_str='321 Fubar'), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank(path, environ={ 'REQUEST_METHOD': 'GET', 'wsgi.input': BytesIO(b'4321')}) @@ -230,7 +230,7 @@ class TestProxyLogging(unittest.TestCase): app = proxy_logging.ProxyLoggingMiddleware( FakeApp(body=b'7654321', response_str='321 Fubar', policy_idx='-1'), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank(path, environ={ 'REQUEST_METHOD': 'GET', 'wsgi.input': BytesIO(b'4321')}) @@ -248,7 +248,7 @@ class TestProxyLogging(unittest.TestCase): # GET with swift.proxy_access_log_made already set app = proxy_logging.ProxyLoggingMiddleware( FakeApp(body=b'7654321', response_str='321 Fubar'), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank(path, environ={ 'REQUEST_METHOD': 'GET', 'swift.proxy_access_log_made': True, @@ -265,7 +265,7 @@ class TestProxyLogging(unittest.TestCase): # PUT (no first-byte timing!) app = proxy_logging.ProxyLoggingMiddleware( FakeApp(body=b'87654321', response_str='314 PiTown'), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank(path, environ={ 'REQUEST_METHOD': 'PUT', 'wsgi.input': BytesIO(b'654321')}) @@ -298,7 +298,7 @@ class TestProxyLogging(unittest.TestCase): app = proxy_logging.ProxyLoggingMiddleware( FakeApp(body=b'87654321', response_str='314 PiTown', policy_idx='-1'), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank(path, environ={ 'REQUEST_METHOD': 'PUT', 'wsgi.input': BytesIO(b'654321')}) @@ -332,7 +332,7 @@ class TestProxyLogging(unittest.TestCase): } for method, exp_method in method_map.items(): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/v1/a/', environ={'REQUEST_METHOD': method}) now = 10000.0 app.log_request(req, 299, 11, 3, now, now + 1.17) @@ -358,7 +358,7 @@ class TestProxyLogging(unittest.TestCase): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), { conf_key: 'SPECIAL, GET,PUT ', # crazy spaces ok }) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/v1/a/c', environ={'REQUEST_METHOD': method}) now = 10000.0 @@ -370,7 +370,7 @@ class TestProxyLogging(unittest.TestCase): def test_basic_req(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) resp_body = b''.join(resp) @@ -384,7 +384,7 @@ class TestProxyLogging(unittest.TestCase): def test_basic_req_second_time(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={ 'swift.proxy_access_log_made': True, 'REQUEST_METHOD': 'GET'}) @@ -402,7 +402,7 @@ class TestProxyLogging(unittest.TestCase): '{protocol} {path} {method} ' '{path.anonymized} {container.anonymized} ' '{request_time} {start_time.datetime} {end_time} {ttfb}')}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) with mock.patch('time.time', mock.MagicMock( @@ -429,7 +429,7 @@ class TestProxyLogging(unittest.TestCase): 'log_msg_template': ( '{protocol} {path} {method} ' '{account} {container} {object}')}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/bucket/path/to/key', environ={ 'REQUEST_METHOD': 'GET', # This would actually get set in the app, but w/e @@ -470,7 +470,7 @@ class TestProxyLogging(unittest.TestCase): def test_multi_segment_resp(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp( [b'some', b'chunks', b'of data']), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'swift.source': 'SOS'}) resp = app(req.environ, start_response) @@ -488,7 +488,7 @@ class TestProxyLogging(unittest.TestCase): for conf_key in ['access_log_headers', 'log_headers']: app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {conf_key: 'yes'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) # exhaust generator @@ -501,7 +501,7 @@ class TestProxyLogging(unittest.TestCase): app = proxy_logging.ProxyLoggingMiddleware( FakeApp(), {'log_headers': 'yes', 'access_log_headers_only': 'FIRST, seCond'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}, headers={'First': '1', @@ -521,7 +521,7 @@ class TestProxyLogging(unittest.TestCase): # Using default policy app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {'log_headers': 'yes'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank( '/v1/a/c/o/foo', environ={'REQUEST_METHOD': 'PUT', @@ -541,7 +541,7 @@ class TestProxyLogging(unittest.TestCase): # Using a non-existent policy app = proxy_logging.ProxyLoggingMiddleware(FakeApp(policy_idx='-1'), {'log_headers': 'yes'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank( '/v1/a/c/o/foo', environ={'REQUEST_METHOD': 'PUT', @@ -559,7 +559,7 @@ class TestProxyLogging(unittest.TestCase): def test_upload_size_no_policy(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(policy_idx=None), {'log_headers': 'yes'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank( '/v1/a/c/o/foo', environ={'REQUEST_METHOD': 'PUT', @@ -577,7 +577,7 @@ class TestProxyLogging(unittest.TestCase): def test_upload_line(self): app = proxy_logging.ProxyLoggingMiddleware(FakeAppReadline(), {'log_headers': 'yes'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank( '/v1/a/c', environ={'REQUEST_METHOD': 'POST', @@ -594,7 +594,7 @@ class TestProxyLogging(unittest.TestCase): def test_log_query_string(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'QUERY_STRING': 'x=3'}) resp = app(req.environ, start_response) @@ -605,7 +605,7 @@ class TestProxyLogging(unittest.TestCase): def test_client_logging(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'REMOTE_ADDR': '1.2.3.4'}) resp = app(req.environ, start_response) @@ -654,7 +654,7 @@ class TestProxyLogging(unittest.TestCase): def test_proxy_client_logging(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={ 'REQUEST_METHOD': 'GET', 'REMOTE_ADDR': '1.2.3.4', @@ -667,7 +667,7 @@ class TestProxyLogging(unittest.TestCase): self.assertEqual(log_parts[1], '1.2.3.4') # remote addr app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={ 'REQUEST_METHOD': 'GET', 'REMOTE_ADDR': '1.2.3.4', @@ -695,7 +695,7 @@ class TestProxyLogging(unittest.TestCase): def test_unread_body(self): app = proxy_logging.ProxyLoggingMiddleware( FakeApp(['some', 'stuff']), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) # read first chunk @@ -717,7 +717,7 @@ class TestProxyLogging(unittest.TestCase): 'log_msg_template': '{method} {path} ' '{status_int} {wire_status_int}', }) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = req.get_response(app) with self.assertRaises(Exception) as ctx: @@ -728,7 +728,7 @@ class TestProxyLogging(unittest.TestCase): def test_disconnect_on_readline(self): app = proxy_logging.ProxyLoggingMiddleware(FakeAppReadline(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'wsgi.input': FileLikeExceptor()}) try: @@ -744,7 +744,7 @@ class TestProxyLogging(unittest.TestCase): def test_disconnect_on_read(self): app = proxy_logging.ProxyLoggingMiddleware( FakeApp(['some', 'stuff']), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'wsgi.input': FileLikeExceptor()}) try: @@ -760,7 +760,7 @@ class TestProxyLogging(unittest.TestCase): def test_app_exception(self): app = proxy_logging.ProxyLoggingMiddleware( FakeAppThatExcepts(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) try: app(req.environ, start_response) @@ -776,7 +776,7 @@ class TestProxyLogging(unittest.TestCase): # test the "while not chunk: chunk = next(iterator)" body=[b'', b'', b'line1\n', b'line2\n'], ), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) resp_body = b''.join(resp) @@ -794,7 +794,7 @@ class TestProxyLogging(unittest.TestCase): # test the "while not chunk: chunk = next(iterator)" body=[b'', b'', b''], ), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) resp_body = b''.join(resp) @@ -819,7 +819,7 @@ class TestProxyLogging(unittest.TestCase): FakeAppNoContentLengthNoTransferEncoding( body=BodyGen(b'abc'), ), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) resp_body = b''.join(resp) @@ -833,7 +833,7 @@ class TestProxyLogging(unittest.TestCase): def test_req_path_info_popping(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/v1/something', environ={'REQUEST_METHOD': 'GET'}) req.path_info_pop() self.assertEqual(req.environ['PATH_INFO'], '/something') @@ -850,7 +850,7 @@ class TestProxyLogging(unittest.TestCase): def test_ipv6(self): ipv6addr = '2001:db8:85a3:8d3:1319:8a2e:370:7348' app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) req.remote_addr = ipv6addr resp = app(req.environ, start_response) @@ -867,14 +867,14 @@ class TestProxyLogging(unittest.TestCase): def test_log_info_none(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) list(app(req.environ, start_response)) log_parts = self._log_parts(app) self.assertEqual(log_parts[17], '-') app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) req.environ['swift.log_info'] = [] list(app(req.environ, start_response)) @@ -883,7 +883,7 @@ class TestProxyLogging(unittest.TestCase): def test_log_info_single(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) req.environ['swift.log_info'] = ['one'] list(app(req.environ, start_response)) @@ -892,7 +892,7 @@ class TestProxyLogging(unittest.TestCase): def test_log_info_multiple(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) req.environ['swift.log_info'] = ['one', 'and two'] list(app(req.environ, start_response)) @@ -905,7 +905,7 @@ class TestProxyLogging(unittest.TestCase): # Default - reveal_sensitive_prefix is 16 # No x-auth-token header app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) resp_body = b''.join(resp) @@ -913,7 +913,7 @@ class TestProxyLogging(unittest.TestCase): self.assertEqual(log_parts[9], '-') # Has x-auth-token header app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'HTTP_X_AUTH_TOKEN': auth_token}) resp = app(req.environ, start_response) @@ -924,7 +924,7 @@ class TestProxyLogging(unittest.TestCase): # Truncate to first 8 characters app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), { 'reveal_sensitive_prefix': '8'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) resp_body = b''.join(resp) @@ -932,7 +932,7 @@ class TestProxyLogging(unittest.TestCase): self.assertEqual(log_parts[9], '-') app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), { 'reveal_sensitive_prefix': '8'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'HTTP_X_AUTH_TOKEN': auth_token}) resp = app(req.environ, start_response) @@ -943,7 +943,7 @@ class TestProxyLogging(unittest.TestCase): # Token length and reveal_sensitive_prefix are same (no truncate) app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), { 'reveal_sensitive_prefix': str(len(auth_token))}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'HTTP_X_AUTH_TOKEN': auth_token}) resp = app(req.environ, start_response) @@ -954,7 +954,7 @@ class TestProxyLogging(unittest.TestCase): # No effective limit on auth token app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), { 'reveal_sensitive_prefix': constraints.MAX_HEADER_SIZE}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'HTTP_X_AUTH_TOKEN': auth_token}) resp = app(req.environ, start_response) @@ -965,7 +965,7 @@ class TestProxyLogging(unittest.TestCase): # Don't log x-auth-token app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), { 'reveal_sensitive_prefix': '0'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) resp = app(req.environ, start_response) resp_body = b''.join(resp) @@ -973,7 +973,7 @@ class TestProxyLogging(unittest.TestCase): self.assertEqual(log_parts[9], '-') app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), { 'reveal_sensitive_prefix': '0'}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET', 'HTTP_X_AUTH_TOKEN': auth_token}) resp = app(req.environ, start_response) @@ -987,7 +987,7 @@ class TestProxyLogging(unittest.TestCase): def test_ensure_fields(self): app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) with mock.patch('time.time', mock.MagicMock( @@ -1023,10 +1023,10 @@ class TestProxyLogging(unittest.TestCase): # Since no internal request is being made, outer most proxy logging # middleware, log1, should have performed the logging. app = FakeApp() - flg0 = FakeLogger() + flg0 = debug_logger() env = {} log0 = proxy_logging.ProxyLoggingMiddleware(app, env, logger=flg0) - flg1 = FakeLogger() + flg1 = debug_logger() log1 = proxy_logging.ProxyLoggingMiddleware(log0, env, logger=flg1) req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) @@ -1072,11 +1072,11 @@ class TestProxyLogging(unittest.TestCase): # Since an internal request is being made, inner most proxy logging # middleware, log0, should have performed the logging. app = FakeApp() - flg0 = FakeLogger() + flg0 = debug_logger() env = {} log0 = proxy_logging.ProxyLoggingMiddleware(app, env, logger=flg0) fake = FakeMiddleware(log0, env) - flg1 = FakeLogger() + flg1 = debug_logger() log1 = proxy_logging.ProxyLoggingMiddleware(fake, env, logger=flg1) req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) @@ -1104,7 +1104,7 @@ class TestProxyLogging(unittest.TestCase): # Policy index can be specified by X-Backend-Storage-Policy-Index # in the request header for object API app = proxy_logging.ProxyLoggingMiddleware(FakeApp(policy_idx='1'), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/v1/a/c/o', environ={'REQUEST_METHOD': 'PUT'}) resp = app(req.environ, start_response) b''.join(resp) @@ -1114,7 +1114,7 @@ class TestProxyLogging(unittest.TestCase): # Policy index can be specified by X-Backend-Storage-Policy-Index # in the response header for container API app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) - app.access_logger = FakeLogger() + app.access_logger = debug_logger() req = Request.blank('/v1/a/c', environ={'REQUEST_METHOD': 'GET'}) def fake_call(app, env, start_response):