From 623024848e623c4fb4f50315de48d227041670ae Mon Sep 17 00:00:00 2001 From: Alistair Coles Date: Mon, 17 Oct 2022 15:27:21 +0100 Subject: [PATCH] proxy: extract response error handling to single method This patch introduces a check_response method to proxy server Application class. The method provides common checking and reporting of backend response errors (i.e. responses with status code >= 500). This checking was previously duplicated in proxy controller classes. The formatting and content of error logging messages is now more unform, which does result in changes to some logged error messages. Change-Id: I4b935a47f39642c11364f2a8d50a5f2ebb3b84f1 --- swift/proxy/controllers/base.py | 31 +++-------- swift/proxy/controllers/obj.py | 24 ++------- swift/proxy/server.py | 40 +++++++++++++- test/unit/proxy/controllers/test_obj.py | 8 ++- test/unit/proxy/test_server.py | 70 ++++++++++++++++++++++++- 5 files changed, 126 insertions(+), 47 deletions(-) diff --git a/swift/proxy/controllers/base.py b/swift/proxy/controllers/base.py index 10d94cdc97..d7ac449178 100644 --- a/swift/proxy/controllers/base.py +++ b/swift/proxy/controllers/base.py @@ -55,7 +55,7 @@ from swift.common.header_key_dict import HeaderKeyDict from swift.common.http import is_informational, is_success, is_redirection, \ is_server_error, HTTP_OK, HTTP_PARTIAL_CONTENT, HTTP_MULTIPLE_CHOICES, \ HTTP_BAD_REQUEST, HTTP_NOT_FOUND, HTTP_SERVICE_UNAVAILABLE, \ - HTTP_INSUFFICIENT_STORAGE, HTTP_UNAUTHORIZED, HTTP_CONTINUE, HTTP_GONE + HTTP_UNAUTHORIZED, HTTP_CONTINUE, HTTP_GONE from swift.common.swob import Request, Response, Range, \ HTTPException, HTTPRequestedRangeNotSatisfiable, HTTPServiceUnavailable, \ status_map, wsgi_to_str, str_to_wsgi, wsgi_quote, wsgi_unquote, \ @@ -1473,15 +1473,9 @@ class GetOrHeadHandler(object): ts = Timestamp(hdrs.get('X-Backend-Timestamp', 0)) if ts > self.latest_404_timestamp: self.latest_404_timestamp = ts - if possible_source.status == HTTP_INSUFFICIENT_STORAGE: - self.app.error_limit(node, 'ERROR Insufficient Storage') - elif is_server_error(possible_source.status): - self.app.error_occurred( - node, ('ERROR %(status)d %(body)s ' - 'From %(type)s Server') % - {'status': possible_source.status, - 'body': self.bodies[-1][:1024], - 'type': self.server_type}) + self.app.check_response(node, self.server_type, possible_source, + self.req_method, self.path, + self.bodies[-1]) return False def _get_source_and_node(self): @@ -1914,21 +1908,12 @@ class Controller(object): conn.send(body) with Timeout(self.app.node_timeout): resp = conn.getresponse() - if not is_informational(resp.status) and \ - not is_server_error(resp.status): + if (self.app.check_response(node, self.server_type, resp, + method, path) + and not is_informational(resp.status)): return resp.status, resp.reason, resp.getheaders(), \ resp.read() - elif resp.status == HTTP_INSUFFICIENT_STORAGE: - self.app.error_limit(node, - 'ERROR Insufficient Storage') - elif is_server_error(resp.status): - msg = ('ERROR %(status)d Trying to ' - '%(method)s %(path)s From %(type)s Server') - self.app.error_occurred(node, msg % { - 'status': resp.status, - 'method': method, - 'path': path, - 'type': self.server_type}) + except (Exception, Timeout): self.app.exception_occurred( node, self.server_type, diff --git a/swift/proxy/controllers/obj.py b/swift/proxy/controllers/obj.py index 04050ae6e8..4d83b2b26a 100644 --- a/swift/proxy/controllers/obj.py +++ b/swift/proxy/controllers/obj.py @@ -478,18 +478,9 @@ class BaseObjectController(Controller): else: body = b'' bodies.append(body) - if response.status == HTTP_INSUFFICIENT_STORAGE: + if not self.app.check_response(putter.node, 'Object', response, + req.method, req.path, body): putter.failed = True - self.app.error_limit(putter.node, - 'ERROR Insufficient Storage') - elif response.status >= HTTP_INTERNAL_SERVER_ERROR: - putter.failed = True - self.app.error_occurred( - putter.node, - 'ERROR %(status)d %(body)s From Object Server ' - 're: %(path)s' % - {'status': response.status, - 'body': body[:1024], 'path': req.path}) elif is_success(response.status): etags.add(normalize_etag(response.getheader('etag'))) @@ -2791,15 +2782,8 @@ class ECFragGetter(object): self.body = possible_source.read() conn.close() - if possible_source.status == HTTP_INSUFFICIENT_STORAGE: - self.app.error_limit(node, 'ERROR Insufficient Storage') - elif is_server_error(possible_source.status): - self.app.error_occurred( - node, 'ERROR %(status)d %(body)s ' - 'From Object Server' % - {'status': possible_source.status, - 'body': self.body[:1024]}) - else: + if self.app.check_response(node, 'Object', possible_source, 'GET', + self.path): self.logger.debug( 'Ignoring %s from primary' % possible_source.status) diff --git a/swift/proxy/server.py b/swift/proxy/server.py index f764c88f0b..1c57627089 100644 --- a/swift/proxy/server.py +++ b/swift/proxy/server.py @@ -28,7 +28,7 @@ from eventlet import Timeout from swift import __canonical_version__ as swift_version from swift.common import constraints -from swift.common.http import is_server_error +from swift.common.http import is_server_error, HTTP_INSUFFICIENT_STORAGE from swift.common.storage_policy import POLICIES from swift.common.ring import Ring from swift.common.error_limiter import ErrorLimiter @@ -688,6 +688,44 @@ class Application(object): self.logger.error('%(msg)s %(node)s', {'msg': msg, 'node': node_to_string(node)}) + def check_response(self, node, server_type, response, method, path, + body=None): + """ + Check response for error status codes and update error limiters as + required. + + :param node: a dict describing a node + :param server_type: the type of server from which the response was + received (e.g. 'Object'). + :param response: an instance of HTTPResponse. + :param method: the request method. + :param path: the request path. + :param body: an optional response body. If given, up to 1024 of the + start of the body will be included in any log message. + :return True: if the response status code is less than 500, False + otherwise. + """ + ok = False + if response.status == HTTP_INSUFFICIENT_STORAGE: + self.error_limit(node, 'ERROR Insufficient Storage') + elif is_server_error(response.status): + values = {'status': response.status, + 'method': method, + 'path': path, + 'type': server_type} + if body is None: + fmt = 'ERROR %(status)d Trying to %(method)s ' \ + '%(path)s From %(type)s Server' + else: + fmt = 'ERROR %(status)d %(body)s Trying to %(method)s ' \ + '%(path)s From %(type)s Server' + values['body'] = body[:1024] + self.error_occurred(node, fmt % values) + else: + ok = True + + return ok + def iter_nodes(self, ring, partition, logger, node_iter=None, policy=None): return NodeIter(self, ring, partition, logger, node_iter=node_iter, policy=policy) diff --git a/test/unit/proxy/controllers/test_obj.py b/test/unit/proxy/controllers/test_obj.py index 5c280602b9..7d97c04f10 100644 --- a/test/unit/proxy/controllers/test_obj.py +++ b/test/unit/proxy/controllers/test_obj.py @@ -1365,10 +1365,14 @@ class TestReplicatedObjController(CommonObjectControllerMixin, req, log_lines = do_test((201, (100, 500), 201)) if six.PY3: # We allow the b'' in logs because we want to see bad characters. - self.assertIn("ERROR 500 b'' From Object Server", log_lines[0]) + self.assertIn( + "ERROR 500 b'' Trying to PUT /v1/AUTH_kilroy/%ED%88%8E/" + "%E9%90%89 From Object Server", log_lines[0]) self.assertIn(req.path, log_lines[0]) else: - self.assertIn('ERROR 500 From Object Server', log_lines[0]) + self.assertIn( + 'ERROR 500 Trying to PUT /v1/AUTH_kilroy/%ED%88%8E/%E9%90%89 ' + 'From Object Server', log_lines[0]) self.assertIn(req.path.decode('utf-8'), log_lines[0]) def test_DELETE_errors(self): diff --git a/test/unit/proxy/test_server.py b/test/unit/proxy/test_server.py index f3205327ae..1b4b034c3a 100644 --- a/test/unit/proxy/test_server.py +++ b/test/unit/proxy/test_server.py @@ -56,7 +56,7 @@ from test.debug_logger import debug_logger from test.unit import ( connect_tcp, readuntil2crlfs, fake_http_connect, FakeRing, FakeMemcache, patch_policies, write_fake_ring, mocked_http_conn, DEFAULT_TEST_EC_TYPE, - make_timestamp_iter, skip_if_no_xattrs) + make_timestamp_iter, skip_if_no_xattrs, FakeHTTPResponse) from test.unit.helpers import setup_servers, teardown_servers from swift.proxy import server as proxy_server from swift.proxy.controllers.obj import ReplicatedObjectController @@ -1288,6 +1288,74 @@ class TestProxyServer(unittest.TestCase): self.assertIs(log_kwargs['exc_info'][1], expected_err) self.assertEqual(4, node_error_count(app, node)) + def test_check_response_200(self): + app = proxy_server.Application({}, + account_ring=FakeRing(), + container_ring=FakeRing(), + logger=debug_logger()) + node = app.container_ring.get_part_nodes(1)[0] + resp = FakeHTTPResponse(Response()) + ret = app.check_response(node, 'Container', resp, 'PUT', '/v1/a/c') + self.assertTrue(ret) + error_lines = app.logger.get_lines_for_level('error') + self.assertFalse(error_lines) + self.assertEqual(0, node_error_count(app, node)) + + def test_check_response_507(self): + app = proxy_server.Application({}, + account_ring=FakeRing(), + container_ring=FakeRing(), + logger=debug_logger()) + node = app.container_ring.get_part_nodes(1)[0] + resp = FakeHTTPResponse(Response(status=507)) + ret = app.check_response(node, 'Container', resp, 'PUT', '/v1/a/c') + self.assertFalse(ret) + error_lines = app.logger.get_lines_for_level('error') + self.assertEqual(1, len(error_lines)) + self.assertEqual('ERROR Insufficient Storage 10.0.0.0:1000/sda', + error_lines[0]) + self.assertEqual(11, node_error_count(app, node)) + self.assertTrue(app.error_limited(node)) + + app.logger.clear() + ret = app.check_response(node, 'Account', resp, 'PUT', '/v1/a/c', + body='full') + self.assertFalse(ret) + error_lines = app.logger.get_lines_for_level('error') + self.assertEqual(1, len(error_lines)) + self.assertEqual('ERROR Insufficient Storage 10.0.0.0:1000/sda', + error_lines[0]) + self.assertEqual(11, node_error_count(app, node)) + self.assertTrue(app.error_limited(node)) + + def test_check_response_503(self): + app = proxy_server.Application({}, + account_ring=FakeRing(), + container_ring=FakeRing(), + logger=debug_logger()) + node = app.container_ring.get_part_nodes(1)[0] + resp = FakeHTTPResponse(Response(status=503)) + app.logger.clear() + ret = app.check_response(node, 'Container', resp, 'PUT', '/v1/a/c') + self.assertFalse(ret) + error_lines = app.logger.get_lines_for_level('error') + self.assertEqual(1, len(error_lines)) + self.assertEqual('ERROR 503 Trying to PUT /v1/a/c From Container ' + 'Server 10.0.0.0:1000/sda', error_lines[0]) + self.assertEqual(1, node_error_count(app, node)) + self.assertFalse(app.error_limited(node)) + + app.logger.clear() + ret = app.check_response(node, 'Object', resp, 'GET', '/v1/a/c/o', + body='full') + self.assertFalse(ret) + error_lines = app.logger.get_lines_for_level('error') + self.assertEqual(1, len(error_lines)) + self.assertEqual('ERROR 503 full Trying to GET /v1/a/c/o From Object ' + 'Server 10.0.0.0:1000/sda', error_lines[0]) + self.assertEqual(2, node_error_count(app, node)) + self.assertFalse(app.error_limited(node)) + def test_valid_api_version(self): app = proxy_server.Application({}, account_ring=FakeRing(),