From 5d640985f7c7104b8ce9992c63c159c58c85ebe8 Mon Sep 17 00:00:00 2001 From: Alistair Coles Date: Thu, 6 Jun 2024 12:55:35 +0100 Subject: [PATCH] s3api: include error response reason in log_info There's a variety of reasons why s3api may return a 4xx or 5xx response. It's useful to get some more detail in the log message, particularly when the request is a HEAD which won't get any detail in the response body. Change-Id: I0a499dc5c50bb534a23adcbfe7c3822d8954b0e0 --- swift/common/middleware/container_sync.py | 16 +-- swift/common/middleware/proxy_logging.py | 4 +- swift/common/middleware/s3api/s3api.py | 2 + swift/common/middleware/s3api/s3response.py | 15 ++- swift/common/request_helpers.py | 8 ++ swift/proxy/controllers/obj.py | 5 +- .../common/middleware/s3api/test_s3api.py | 119 ++++++++++++++++-- .../middleware/s3api/test_s3response.py | 24 +++- test/unit/common/test_request_helpers.py | 16 +++ 9 files changed, 179 insertions(+), 30 deletions(-) diff --git a/swift/common/middleware/container_sync.py b/swift/common/middleware/container_sync.py index cc6b16aeea..35b1a7d4b6 100644 --- a/swift/common/middleware/container_sync.py +++ b/swift/common/middleware/container_sync.py @@ -17,6 +17,7 @@ import os from swift.common.constraints import valid_api_version from swift.common.container_sync_realms import ContainerSyncRealms +from swift.common.request_helpers import append_log_info from swift.common.swob import HTTPBadRequest, HTTPUnauthorized, wsgify from swift.common.utils import ( config_true_value, get_logger, streq_const_time) @@ -109,20 +110,17 @@ class ContainerSync(object): valid = False auth = auth.split() if len(auth) != 3: - req.environ.setdefault('swift.log_info', []).append( - 'cs:not-3-args') + append_log_info(req.environ, 'cs:not-3-args') else: realm, nonce, sig = auth realm_key = self.realms_conf.key(realm) realm_key2 = self.realms_conf.key2(realm) if not realm_key: - req.environ.setdefault('swift.log_info', []).append( - 'cs:no-local-realm-key') + append_log_info(req.environ, 'cs:no-local-realm-key') else: user_key = info.get('sync_key') if not user_key: - req.environ.setdefault('swift.log_info', []).append( - 'cs:no-local-user-key') + append_log_info(req.environ, 'cs:no-local-user-key') else: # x-timestamp headers get shunted by gatekeeper if 'x-backend-inbound-x-timestamp' in req.headers: @@ -139,11 +137,9 @@ class ContainerSync(object): realm_key2, user_key) if realm_key2 else expected if not streq_const_time(sig, expected) and \ not streq_const_time(sig, expected2): - req.environ.setdefault( - 'swift.log_info', []).append('cs:invalid-sig') + append_log_info(req.environ, 'cs:invalid-sig') else: - req.environ.setdefault( - 'swift.log_info', []).append('cs:valid') + append_log_info(req.environ, 'cs:valid') valid = True if not valid: exc = HTTPUnauthorized( diff --git a/swift/common/middleware/proxy_logging.py b/swift/common/middleware/proxy_logging.py index ed5d218f34..75a991530b 100644 --- a/swift/common/middleware/proxy_logging.py +++ b/swift/common/middleware/proxy_logging.py @@ -89,6 +89,7 @@ import os import time from swift.common.middleware.catch_errors import enforce_byte_count +from swift.common.request_helpers import get_log_info from swift.common.swob import Request from swift.common.utils import (get_logger, get_remote_client, config_true_value, reiterate, @@ -318,8 +319,7 @@ class ProxyLoggingMiddleware(object): 'transaction_id': req.environ.get('swift.trans_id'), 'request_time': duration_time_str, 'source': req.environ.get('swift.source'), - 'log_info': - ','.join(req.environ.get('swift.log_info', '')), + 'log_info': get_log_info(req.environ), 'policy_index': policy_index, 'ttfb': ttfb, 'pid': self.pid, diff --git a/swift/common/middleware/s3api/s3api.py b/swift/common/middleware/s3api/s3api.py index bd0f0c01e1..55c8732f6c 100644 --- a/swift/common/middleware/s3api/s3api.py +++ b/swift/common/middleware/s3api/s3api.py @@ -149,6 +149,7 @@ from six.moves.urllib.parse import parse_qs from swift.common.constraints import valid_api_version from swift.common.middleware.listing_formats import \ MAX_CONTAINER_LISTING_CONTENT_LENGTH +from swift.common.request_helpers import append_log_info from swift.common.wsgi import PipelineWrapper, loadcontext, WSGIContext from swift.common.middleware import app_property @@ -353,6 +354,7 @@ class S3ApiMiddleware(object): self.logger.debug(e.cause) except ErrorResponse as err_resp: self.logger.increment(err_resp.metric_name) + append_log_info(env, 's3:err:%s' % err_resp.summary) if isinstance(err_resp, InternalError): self.logger.exception(err_resp) resp = err_resp diff --git a/swift/common/middleware/s3api/s3response.py b/swift/common/middleware/s3api/s3response.py index bcd2240c33..66b553ac7f 100644 --- a/swift/common/middleware/s3api/s3response.py +++ b/swift/common/middleware/s3api/s3response.py @@ -252,12 +252,17 @@ class ErrorResponse(S3ResponseBase, swob.HTTPException): self.headers = HeaderKeyDict(self.headers) @property - def metric_name(self): - parts = [str(self.status_int), self._code] + def summary(self): + """Provide a summary of the error code and reason.""" if self.reason: - parts.append(self.reason) - metric = '.'.join(parts) - return metric.replace(' ', '_') + summary = '.'.join([self._code, self.reason]) + else: + summary = self._code + return summary.replace(' ', '_') + + @property + def metric_name(self): + return '.'.join([str(self.status_int), self.summary]) def _body_iter(self): error_elem = Element('Error') diff --git a/swift/common/request_helpers.py b/swift/common/request_helpers.py index f38048c3d1..32cc7e3f61 100644 --- a/swift/common/request_helpers.py +++ b/swift/common/request_helpers.py @@ -1021,3 +1021,11 @@ def is_backend_open_expired(request): x_backend_replication = config_true_value(request.headers.get( 'x-backend-replication', 'false')) return x_backend_open_expired or x_backend_replication + + +def append_log_info(environ, log_info): + environ.setdefault('swift.log_info', []).append(log_info) + + +def get_log_info(environ): + return ','.join(environ.get('swift.log_info', [])) diff --git a/swift/proxy/controllers/obj.py b/swift/proxy/controllers/obj.py index fd79e0c970..94e6399521 100644 --- a/swift/proxy/controllers/obj.py +++ b/swift/proxy/controllers/obj.py @@ -78,7 +78,7 @@ from swift.common.swob import HTTPAccepted, HTTPBadRequest, HTTPNotFound, \ normalize_etag, str_to_wsgi from swift.common.request_helpers import update_etag_is_at_header, \ resolve_etag_is_at_header, validate_internal_obj, get_ip_port, \ - is_open_expired + is_open_expired, append_log_info def check_content_type(req): @@ -631,8 +631,7 @@ class BaseObjectController(Controller): int(req.headers['x-delete-at'])) x_delete_at = int(req.headers['x-delete-at']) - req.environ.setdefault('swift.log_info', []).append( - 'x-delete-at:%s' % x_delete_at) + append_log_info(req.environ, 'x-delete-at:%s' % x_delete_at) delete_at_container = get_expirer_container( x_delete_at, self.app.expiring_objects_container_divisor, diff --git a/test/unit/common/middleware/s3api/test_s3api.py b/test/unit/common/middleware/s3api/test_s3api.py index 39fd39a3a2..673d8749e4 100644 --- a/test/unit/common/middleware/s3api/test_s3api.py +++ b/test/unit/common/middleware/s3api/test_s3api.py @@ -27,11 +27,13 @@ from paste.deploy import loadwsgi from six.moves.urllib.parse import unquote, quote import swift.common.middleware.s3api +from swift.common.middleware.proxy_logging import ProxyLoggingMiddleware from swift.common.middleware.s3api.s3response import ErrorResponse, \ AccessDenied from swift.common.middleware.s3api.utils import Config from swift.common.middleware.keystoneauth import KeystoneAuth from swift.common import swob, registry +from swift.common.request_helpers import get_log_info from swift.common.swob import Request from swift.common.utils import md5, get_logger, UTC @@ -255,6 +257,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_header_auth': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_header_auth', + get_log_info(req.environ)) def test_bad_method(self): req = Request.blank('/', @@ -266,6 +270,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'405.MethodNotAllowed': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:MethodNotAllowed', + get_log_info(req.environ)) def test_bad_method_but_method_exists_in_controller(self): req = Request.blank( @@ -278,6 +284,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'405.MethodNotAllowed': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:MethodNotAllowed', + get_log_info(req.environ)) def test_path_info_encode(self): bucket_name = 'b%75cket' @@ -412,6 +420,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.expired': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.expired', + get_log_info(req.environ)) def test_signed_urls(self): # Set expire to last 32b timestamp value @@ -461,6 +471,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_expires': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_expires', + get_log_info(req.environ)) def test_signed_urls_no_sign(self): expire = '2147483647' # 19 Jan 2038 03:14:07 @@ -475,6 +487,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_query_auth': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_query_auth', + get_log_info(req.environ)) def test_signed_urls_no_access(self): expire = '2147483647' # 19 Jan 2038 03:14:07 @@ -488,6 +502,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_query_auth': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_query_auth', + get_log_info(req.environ)) def test_signed_urls_v4(self): req = Request.blank( @@ -537,6 +553,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.AuthorizationQueryParametersError': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AuthorizationQueryParametersError', + get_log_info(req.environ)) dt = self.get_v4_amz_date_header().split('T', 1)[0] test('test:tester/not-a-date/us-east-1/s3/aws4_request', @@ -568,6 +586,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_date': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_date', + get_log_info(req.environ)) def test_signed_urls_v4_invalid_algorithm(self): req = Request.blank( @@ -586,6 +606,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidArgument': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidArgument', + get_log_info(req.environ)) def test_signed_urls_v4_missing_signed_headers(self): req = Request.blank( @@ -604,6 +626,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.AuthorizationHeaderMalformed': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AuthorizationHeaderMalformed', + get_log_info(req.environ)) def test_signed_urls_v4_invalid_credentials(self): req = Request.blank('/bucket/object' @@ -621,6 +645,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_credential': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_credential', + get_log_info(req.environ)) def test_signed_urls_v4_missing_signature(self): req = Request.blank( @@ -638,6 +664,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_query_auth': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_query_auth', + get_log_info(req.environ)) def test_bucket_virtual_hosted_style(self): req = Request.blank('/', @@ -737,6 +765,7 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidURI': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidURI', get_log_info(req.environ)) def test_object_create_bad_md5_unreadable(self): req = Request.blank('/bucket/object', @@ -749,6 +778,7 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidDigest': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidDigest', get_log_info(req.environ)) def test_object_create_bad_md5_too_short(self): too_short_digest = md5(b'hey', usedforsecurity=False).digest()[:-1] @@ -766,6 +796,7 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidDigest': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidDigest', get_log_info(req.environ)) def test_object_create_bad_md5_bad_padding(self): too_short_digest = md5(b'hey', usedforsecurity=False).digest() @@ -783,6 +814,7 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidDigest': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidDigest', get_log_info(req.environ)) def test_object_create_bad_md5_too_long(self): too_long_digest = md5( @@ -801,6 +833,7 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidDigest': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidDigest', get_log_info(req.environ)) def test_invalid_metadata_directive(self): req = Request.blank('/', @@ -814,6 +847,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidArgument': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidArgument', + get_log_info(req.environ)) def test_invalid_storage_class(self): req = Request.blank('/', @@ -826,6 +861,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidStorageClass': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidStorageClass', + get_log_info(req.environ)) def test_invalid_ssc(self): req = Request.blank('/', @@ -838,6 +875,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidArgument': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidArgument', + get_log_info(req.environ)) def _test_unsupported_header(self, header, value=None): if value is None: @@ -853,6 +892,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'501.NotImplemented': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:NotImplemented', + get_log_info(req.environ)) def test_mfa(self): self._test_unsupported_header('x-amz-mfa') @@ -915,6 +956,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'501.NotImplemented': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:NotImplemented', + get_log_info(req.environ)) def test_notification(self): self._test_unsupported_resource('notification') @@ -955,6 +998,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'501.NotImplemented': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:NotImplemented', + get_log_info(req.environ)) req = Request.blank('/bucket?tagging', environ={'REQUEST_METHOD': 'DELETE'}, @@ -966,6 +1011,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'501.NotImplemented': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:NotImplemented', + get_log_info(req.environ)) def test_restore(self): self._test_unsupported_resource('restore') @@ -983,6 +1030,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'405.MethodNotAllowed': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:MethodNotAllowed', + get_log_info(req.environ)) @mock.patch.object(registry, '_sensitive_headers', set()) @mock.patch.object(registry, '_sensitive_params', set()) @@ -1118,6 +1167,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_date': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_date', + get_log_info(req.environ)) def test_signature_v4_no_payload(self): environ = { @@ -1140,6 +1191,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'400.InvalidRequest': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:InvalidRequest', + get_log_info(req.environ)) def test_signature_v4_bad_authorization_string(self): def test(auth_str, error, msg, metric, extra=b''): @@ -1160,6 +1213,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {metric: 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:%s' % metric[4:], + get_log_info(req.environ)) auth_str = ('AWS4-HMAC-SHA256 ' 'SignedHeaders=host;x-amz-date,' @@ -1424,6 +1479,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_expires': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_expires', + get_log_info(req.environ)) # But if we are missing Signature in query param req = Request.blank( @@ -1440,6 +1497,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.AccessDenied.invalid_expires': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_expires', + get_log_info(req.environ)) def test_s3api_with_only_s3_token(self): self.swift = FakeSwift() @@ -1555,6 +1614,8 @@ class TestS3ApiMiddleware(S3ApiTestCase): self.assertEqual( {'403.SignatureDoesNotMatch': 1}, statsd_client.get_increment_counts()) + self.assertEqual('s3:err:SignatureDoesNotMatch', + get_log_info(req.environ)) def test_s3api_with_only_s3_token_in_s3acl(self): self.swift = FakeSwift() @@ -1600,39 +1661,46 @@ class TestS3ApiMiddleware(S3ApiTestCase): 'AWS test:tester:hmac'}, headers={'Date': self.get_date_header(skew=skew)}) self.s3api.logger.logger.clear() - return self.call_s3api(req) + status, headers, body = self.call_s3api(req) + return req, status, headers, body - status, _, body = do_test(800) + req, status, _, body = do_test(800) self.assertEqual('200 OK', status) self.assertFalse( self.s3api.logger.logger.statsd_client.get_increment_counts()) - status, _, body = do_test(-800) + req, status, _, body = do_test(-800) self.assertEqual('200 OK', status) self.assertFalse( self.s3api.logger.logger.statsd_client.get_increment_counts()) - status, _, body = do_test(1000) + req, status, _, body = do_test(1000) self.assertEqual('403 Forbidden', status) self.assertEqual(self._get_error_code(body), 'RequestTimeTooSkewed') self.assertEqual( {'403.RequestTimeTooSkewed': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:RequestTimeTooSkewed', + get_log_info(req.environ)) - status, _, body = do_test(-1000) + req, status, _, body = do_test(-1000) self.assertEqual('403 Forbidden', status) self.assertEqual(self._get_error_code(body), 'RequestTimeTooSkewed') self.assertEqual( {'403.RequestTimeTooSkewed': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:RequestTimeTooSkewed', + get_log_info(req.environ)) self.s3api.conf.allowable_clock_skew = 100 - status, _, body = do_test(800) + req, status, _, body = do_test(800) self.assertEqual('403 Forbidden', status) self.assertEqual(self._get_error_code(body), 'RequestTimeTooSkewed') self.assertEqual( {'403.RequestTimeTooSkewed': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:RequestTimeTooSkewed', + get_log_info(req.environ)) def test_s3api_error_metric(self): class KaboomResponse(ErrorResponse): @@ -1650,22 +1718,55 @@ class TestS3ApiMiddleware(S3ApiTestCase): with mock.patch.object( self.s3api, 'handle_request', side_effect=err_response): self.call_s3api(req) + return req - do_test(ErrorResponse(status=403, msg='not good', reason='bad')) + req = do_test(ErrorResponse(status=403, msg='not good', reason='bad')) self.assertEqual( {'403.ErrorResponse.bad': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:ErrorResponse.bad', + get_log_info(req.environ)) - do_test(AccessDenied(msg='no entry', reason='invalid_date')) + req = do_test(AccessDenied(msg='no entry', reason='invalid_date')) self.assertEqual( {'403.AccessDenied.invalid_date': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_date', + get_log_info(req.environ)) # check whitespace replaced with underscore - do_test(KaboomResponse(status=400, msg='boom', reason='boom boom')) + req = do_test(KaboomResponse(status=400, msg='boom', + reason='boom boom')) self.assertEqual( {'400.ka_boom.boom_boom': 1}, self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:ka_boom.boom_boom', + get_log_info(req.environ)) + + def test_error_response_reason_logging(self): + # verify that proxy logging gets error reason in log_info + environ = {'REQUEST_METHOD': 'HEAD'} + headers = { + 'Authorization': + 'AWS4-HMAC-SHA256 SignedHeaders=host;x-amz-date,Signature=X', + 'X-Amz-Date': self.get_v4_amz_date_header(), + # invalid sha + 'X-Amz-Content-SHA256': '0123456789'} + req = Request.blank('/bucket/object', environ=environ, + headers=headers) + req.content_type = 'text/plain' + log_conf = {'log_msg_template': '{method} {path} {log_info}'} + app = ProxyLoggingMiddleware(self.s3api, log_conf, self.logger) + status, headers, body = self.call_app(req, app=app) + + self.assertEqual( + {'403.AccessDenied.invalid_credential': 1}, + self.s3api.logger.logger.statsd_client.get_increment_counts()) + self.assertEqual('s3:err:AccessDenied.invalid_credential', + get_log_info(req.environ)) + self.assertEqual( + ['HEAD /bucket/object s3:err:AccessDenied.invalid_credential'], + self.logger.get_lines_for_level('info')) if __name__ == '__main__': diff --git a/test/unit/common/middleware/s3api/test_s3response.py b/test/unit/common/middleware/s3api/test_s3response.py index cbdae77c13..accd7aecb7 100644 --- a/test/unit/common/middleware/s3api/test_s3response.py +++ b/test/unit/common/middleware/s3api/test_s3response.py @@ -17,7 +17,7 @@ import unittest from swift.common.swob import Response from swift.common.utils import HeaderKeyDict -from swift.common.middleware.s3api.s3response import S3Response +from swift.common.middleware.s3api.s3response import S3Response, ErrorResponse from swift.common.middleware.s3api.utils import sysmeta_prefix @@ -103,5 +103,27 @@ class TestResponse(unittest.TestCase): self.assertEqual(expected_headers, s3resp.sysmeta_headers) +class DummyErrorResponse(ErrorResponse): + _status = "418 I'm a teapot" + + +class TestErrorResponse(unittest.TestCase): + def test_error_response(self): + resp = DummyErrorResponse(msg='my-msg', reason='my reason') + self.assertEqual("418 I'm a teapot", str(resp)) + self.assertEqual("418 I'm a teapot", resp.status) + self.assertEqual(418, resp.status_int) + self.assertEqual('my reason', resp.reason) + self.assertEqual('DummyErrorResponse.my_reason', resp.summary) + self.assertEqual('418.DummyErrorResponse.my_reason', resp.metric_name) + self.assertEqual( + b"\n" + b"" + b"DummyErrorResponse" + b"my-msg" + b"", + resp.body) + + if __name__ == '__main__': unittest.main() diff --git a/test/unit/common/test_request_helpers.py b/test/unit/common/test_request_helpers.py index 767e2d11d5..cc31b7df44 100644 --- a/test/unit/common/test_request_helpers.py +++ b/test/unit/common/test_request_helpers.py @@ -32,6 +32,22 @@ server_types = ['account', 'container', 'object'] class TestRequestHelpers(unittest.TestCase): + def test_append_log_info(self): + req = Request.blank('/v/a/c/o') + self.assertNotIn('swift.log_info', req.environ) + rh.append_log_info(req.environ, 'msg1') + self.assertEqual(['msg1'], req.environ.get('swift.log_info')) + rh.append_log_info(req.environ, 'msg2') + self.assertEqual(['msg1', 'msg2'], req.environ.get('swift.log_info')) + + def test_get_log_info(self): + req = Request.blank('/v/a/c/o') + self.assertEqual('', rh.get_log_info(req.environ)) + req.environ['swift.log_info'] = ['msg1'] + self.assertEqual('msg1', rh.get_log_info(req.environ)) + rh.append_log_info(req.environ, 'msg2') + self.assertEqual('msg1,msg2', rh.get_log_info(req.environ)) + def test_constrain_req_limit(self): req = Request.blank('') self.assertEqual(10, rh.constrain_req_limit(req, 10))