diff --git a/swift/common/middleware/proxy_logging.py b/swift/common/middleware/proxy_logging.py index 273c31064d..081188a98b 100644 --- a/swift/common/middleware/proxy_logging.py +++ b/swift/common/middleware/proxy_logging.py @@ -23,7 +23,7 @@ The logging format implemented below is as follows: client_ip remote_addr datetime request_method request_path protocol status_int referer user_agent auth_token bytes_recvd bytes_sent - client_etag transaction_id headers request_time source + client_etag transaction_id headers request_time source log_info These values are space-separated, and each is url-encoded, so that they can be separated with a simple .split() @@ -33,6 +33,18 @@ be separated with a simple .split() from the X-Forwarded-For header, X-Cluster-Ip header, or the REMOTE_ADDR environment variable. +* source (swift.source in the WSGI environment) indicates the code + that generated the request, such as most middleware. (See below for + more detail.) + +* log_info (swift.log_info in the WSGI environment) is for additional + information that could prove quite useful, such as any x-delete-at + value or other "behind the scenes" activity that might not + otherwise be detectable from the plain log information. Code that + wishes to add additional log information should use code like + ``env.setdefault('swift.log_info', []).append(your_info)`` so as to + not disturb others' log information. + * Values that are missing (e.g. due to a header not being present) or zero are generally represented by a single hyphen ('-'). @@ -152,6 +164,7 @@ class ProxyLoggingMiddleware(object): logged_headers, '%.4f' % request_time, req.environ.get('swift.source'), + ','.join(req.environ.get('swift.log_info') or '-'), ))) self.mark_req_logged(req) # Log timing and bytes-transfered data to StatsD diff --git a/swift/proxy/controllers/obj.py b/swift/proxy/controllers/obj.py index 01e21a6078..369763c36e 100644 --- a/swift/proxy/controllers/obj.py +++ b/swift/proxy/controllers/obj.py @@ -589,6 +589,8 @@ class ObjectController(Controller): return HTTPBadRequest(request=req, content_type='text/plain', body='Non-integer X-Delete-At') + req.environ.setdefault('swift.log_info', []).append( + 'x-delete-at:%d' % x_delete_at) delete_at_container = str( x_delete_at / self.app.expiring_objects_container_divisor * @@ -866,6 +868,8 @@ class ObjectController(Controller): except ValueError: return HTTPBadRequest(request=req, content_type='text/plain', body='Non-integer X-Delete-At') + req.environ.setdefault('swift.log_info', []).append( + 'x-delete-at:%d' % x_delete_at) delete_at_container = str( x_delete_at / self.app.expiring_objects_container_divisor * diff --git a/test/unit/common/middleware/test_proxy_logging.py b/test/unit/common/middleware/test_proxy_logging.py index 04b574e43b..0b47a0cbef 100644 --- a/test/unit/common/middleware/test_proxy_logging.py +++ b/test/unit/common/middleware/test_proxy_logging.py @@ -537,6 +537,44 @@ class TestProxyLogging(unittest.TestCase): self.assertEquals(resp_body, 'FAKE APP') self.assertEquals(log_parts[11], str(len(resp_body))) + def test_log_info_none(self): + app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) + app.access_logger = FakeLogger() + req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) + resp = app(req.environ, start_response) + resp_body = ''.join(resp) + log_parts = self._log_parts(app) + self.assertEquals(log_parts[17], '-') + + app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) + app.access_logger = FakeLogger() + req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) + req.environ['swift.log_info'] = [] + resp = app(req.environ, start_response) + resp_body = ''.join(resp) + log_parts = self._log_parts(app) + self.assertEquals(log_parts[17], '-') + + def test_log_info_single(self): + app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) + app.access_logger = FakeLogger() + req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) + req.environ['swift.log_info'] = ['one'] + resp = app(req.environ, start_response) + resp_body = ''.join(resp) + log_parts = self._log_parts(app) + self.assertEquals(log_parts[17], 'one') + + def test_log_info_multiple(self): + app = proxy_logging.ProxyLoggingMiddleware(FakeApp(), {}) + app.access_logger = FakeLogger() + req = Request.blank('/', environ={'REQUEST_METHOD': 'GET'}) + req.environ['swift.log_info'] = ['one', 'and two'] + resp = app(req.environ, start_response) + resp_body = ''.join(resp) + log_parts = self._log_parts(app) + self.assertEquals(log_parts[17], 'one%2Cand%20two') + if __name__ == '__main__': unittest.main()