Merge "s3api: include error response reason in log_info"

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(
+                append_log_info(req.environ, 'cs:not-3-args')
-                    '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(
+                    append_log_info(req.environ, 'cs:no-local-realm-key')
-                        'cs:no-local-realm-key')
                 else:
                     user_key = info.get('sync_key')
                     if not user_key:
-                        req.environ.setdefault('swift.log_info', []).append(
+                        append_log_info(req.environ, 'cs:no-local-user-key')
-                            '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(
+                            append_log_info(req.environ, 'cs:invalid-sig')
-                                'swift.log_info', []).append('cs:invalid-sig')
                         else:
-                            req.environ.setdefault(
+                            append_log_info(req.environ, 'cs:valid')
-                                'swift.log_info', []).append('cs:valid')
                             valid = True
             if not valid:
                 exc = HTTPUnauthorized(

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':
+            'log_info': get_log_info(req.environ),
-                ','.join(req.environ.get('swift.log_info', '')),
             'policy_index': policy_index,
             'ttfb': ttfb,
             'pid': self.pid,

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

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):
+    def summary(self):
-        parts = [str(self.status_int), self._code]
+        """Provide a summary of the error code and reason."""
         if self.reason:
-            parts.append(self.reason)
+            summary = '.'.join([self._code, self.reason])
-        metric = '.'.join(parts)
+        else:
-        return metric.replace(' ', '_')
+            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')

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', []))

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(
+            append_log_info(req.environ, 'x-delete-at:%s' % x_delete_at)
-                'x-delete-at:%s' % x_delete_at)
 
             delete_at_container = get_expirer_container(
                 x_delete_at, self.app.expiring_objects_container_divisor,

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__':

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"<?xml version='1.0' encoding='UTF-8'?>\n"
+            b"<Error>"
+            b"<Code>DummyErrorResponse</Code>"
+            b"<Message>my-msg</Message>"
+            b"</Error>",
+            resp.body)
+
+
 if __name__ == '__main__':
     unittest.main()

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))