class LogTestCase(BaseLogTestCase): def setUp(self): self.factory = RequestFactory() self.middleware = LoggingMiddleware() def test_request_body_logged(self, mock_log): body = "some body" datafile = io.StringIO(body) request = self.factory.post("/somewhere", data={"file": datafile}) self.middleware.process_request(request) self._assert_logged(mock_log, "some body") def test_request_headers_logged(self, mock_log): request = self.factory.post("/somewhere", **{'HTTP_USER_AGENT': 'silly-human'}) self.middleware.process_request(request) self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_response_headers_logged(self, mock_log): request = self.factory.post("/somewhere") response = mock.MagicMock() response.get.return_value = 'application/json' response._headers = {'test_headers': 'test_headers'} self.middleware.process_response(request, response) self._assert_logged(mock_log, "test_headers")
def test_logging_http_4xx_level(self, mock_log): for level in (logging.INFO, logging.WARNING, logging.ERROR): mock_log.reset_mock() with override_settings(REQUEST_LOGGING_HTTP_4XX_LOG_LEVEL=level): middleware = LoggingMiddleware() middleware.process_response(self.request, self.response_404) self._assert_logged_with_level(mock_log, level)
class DRFTestCase(BaseLogTestCase): def setUp(self): from django.urls import set_urlconf set_urlconf('test_urls') self.factory = RequestFactory() self.middleware = LoggingMiddleware() def test_no_request_logging_is_honored(self, mock_log): uri = "/widgets" request = self.factory.get(uri) self.middleware.process_request(request) self._assert_logged(mock_log, "DRF explicit annotation") def test_no_response_logging_is_honored(self, mock_log): uri = "/widgets" request = self.factory.get(uri) mock_response = HttpResponse('{"example":"response"}', content_type='application/json', status=422) self.middleware.process_response(request, response=mock_response) self._assert_not_logged(mock_log, '"example":"response"') self._assert_logged(mock_log, '/widgets') def test_non_existent_drf_route_logs(self, mock_log): uri = "/widgets/1234" request = self.factory.patch(uri, data={"almost": "had you"}) self.middleware.process_request(request) self._assert_not_logged(mock_log, "almost") self._assert_not_logged(mock_log, "had you")
class LoggingContextTestCase(BaseLogTestCase): def setUp(self): self.factory = RequestFactory() self.middleware = LoggingMiddleware() def test_request_logging_context(self, mock_log): request = self.factory.post("/somewhere") self.middleware.process_request(request, None, request.body) self._asset_logged_with_additional_args_and_kwargs( mock_log, (), {"extra": { "request": request, "response": None }}) def test_response_logging_context(self, mock_log): request = self.factory.post("/somewhere") response = mock.MagicMock() response.get.return_value = "application/json" headers = {"test_headers": "test_headers"} if IS_DJANGO_VERSION_GTE_3_2_0: response.headers = headers else: response._headers = headers self.middleware.process_response(request, response) self._asset_logged_with_additional_args_and_kwargs( mock_log, (), {"extra": { "request": request, "response": response }}) def test_get_logging_context_extensibility(self, mock_log): request = self.factory.post("/somewhere") self.middleware._get_logging_context = lambda request, response: { "args": (1, True, "Test"), "kwargs": { "extra": { "REQUEST": request, "middleware": self.middleware }, "exc_info": True }, } self.middleware.process_request(request, None, request.body) self._asset_logged_with_additional_args_and_kwargs( mock_log, (1, True, "Test"), { "extra": { "REQUEST": request, "middleware": self.middleware }, "exc_info": True }, )
class LoggingContextTestCase(BaseLogTestCase): def setUp(self): self.factory = RequestFactory() self.middleware = LoggingMiddleware() def test_request_logging_context(self, mock_log): request = self.factory.post("/somewhere") self.middleware.process_request(request) self._asset_logged_with_additional_args_and_kwargs( mock_log, (), { 'extra': { 'request': request, 'response': None, }, }) def test_response_logging_context(self, mock_log): request = self.factory.post("/somewhere") response = mock.MagicMock() response.get.return_value = 'application/json' response._headers = {'test_headers': 'test_headers'} self.middleware.process_response(request, response) self._asset_logged_with_additional_args_and_kwargs( mock_log, (), { 'extra': { 'request': request, 'response': response, }, }) def test_get_logging_context_extensibility(self, mock_log): request = self.factory.post("/somewhere") self.middleware._get_logging_context = lambda request, response: { 'args': (1, True, 'Test'), 'kwargs': { 'extra': { 'REQUEST': request, 'middleware': self.middleware, }, 'exc_info': True, }, } self.middleware.process_request(request) self._asset_logged_with_additional_args_and_kwargs( mock_log, (1, True, 'Test'), { 'extra': { 'REQUEST': request, 'middleware': self.middleware, }, 'exc_info': True, })
class UnicodeLogTestCase(BaseLogTestCase): def setUp(self): def get_response(request): response = mock.MagicMock() response.status_code = 200 response.get.return_value = 'application/json' response._headers = {'test_headers': 'test_headers'} return response self.uri = "/test_class" self.factory = RequestFactory() self.middleware = LoggingMiddleware(get_response) def test_logs_unicode_http_response(self, mock_log): request = self.factory.get(self.uri) response = mock.MagicMock() response.get.return_value = "application/json" response.content = str({"test_unicode_body": "El Niño"}) response.streaming = False self.middleware.process_response(request, response) self._assert_logged(mock_log, response.content) def test_logs_url_with_unicode(self, mock_log): url = "{}/El Niño".format(self.uri) request = self.factory.get(url) self.middleware.process_request(request) self._assert_logged(mock_log, url) def test_logs_unicode_http_request_with_json_type_body(self, mock_log): body = "El Niño" request = self.factory.post("/somewhere", data={"body": body}) self.middleware.process_request(request) self._assert_logged(mock_log, body) def test_logs_unicode_http_request_with_url_encoded_body(self, mock_log): try: # Python 3.x from urllib.parse import quote, unquote except ImportError: # Python 2.7 from urllib import quote, unquote body = "El Niño" request = self.factory.post( "/somewhere", data=quote(body, encoding='utf-8'), content_type="application/x-www-form-urlencoded") self.middleware.process_request(request) self._assert_logged(mock_log, unquote(body))
class LogTestCase(unittest.TestCase): def setUp(self): self.factory = RequestFactory() self.middleware = LoggingMiddleware() def test_does_not_error_with_binary_content_larger_than_chunk_size(self, mock_log): body = MAX_BODY_LENGTH * "0" + "1" datafile = io.StringIO(body) request = self.factory.post("/somewhere", data={"file": datafile}) self.middleware.process_request(request) self._assert_logged(mock_log, str(request.body[:MAX_BODY_LENGTH])) self._assert_not_logged(mock_log, body) def test_request_body_logged(self, mock_log): body = "some body" datafile = io.StringIO(body) request = self.factory.post("/somewhere", data={"file": datafile}) self.middleware.process_request(request) self._assert_logged(mock_log, "some body") def test_request_headers_logged(self, mock_log): request = self.factory.post("/somewhere", **{'HTTP_USER_AGENT': 'silly-human'}) self.middleware.process_request(request) self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_response_headers_logged(self, mock_log): request = self.factory.post("/somewhere") response = mock.MagicMock() response.get.return_value = 'application/json' response._headers = {'test_headers': 'test_headers'} self.middleware.process_response(request, response) self._assert_logged(mock_log, "test_headers") def _assert_logged(self, mock_log, expected_entry): calls = mock_log.log.call_args_list text = " ".join([call[0][1] for call in calls]) self.assertTrue(expected_entry in text) def _assert_not_logged(self, mock_log, unexpected_entry): calls = mock_log.log.call_args_list text = " ".join([call[0][1] for call in calls]) self.assertTrue(unexpected_entry not in text)
class LogTestCase(BaseLogTestCase): def setUp(self): self.factory = RequestFactory() def get_response(request): response = mock.MagicMock() response.status_code = 200 response.get.return_value = 'application/json' response._headers = {'test_headers': 'test_headers'} return response self.middleware = LoggingMiddleware(get_response) def test_request_body_logged(self, mock_log): body = u"some body" request = self.factory.post("/somewhere", data={"file": body}) self.middleware.process_request(request) self._assert_logged(mock_log, body) def test_request_binary_logged(self, mock_log): body = u"some body" datafile = io.StringIO(body) request = self.factory.post("/somewhere", data={"file": datafile}) self.middleware.process_request(request) self._assert_logged(mock_log, "(binary data)") @unittest.skipIf(sys.version_info < (3, 0), "This issue won't happen on python 2") def test_request_jpeg_logged(self, mock_log): body = b'--BoUnDaRyStRiNg\r\nContent-Disposition: form-data; name="file"; filename="campaign_carousel_img.jp' \ b'g"\r\nContent-Type: image/jpeg\r\n\r\n\xff\xd8\xff\xe1\x00\x18Exif\x00\x00II*\x00\x08\x00\x00\x00' \ b'\x00\x00\x00\x00\x00\x00\x00\x00\xff\xec\x00\x11Ducky\x00\x01\x00\x04\x00\x00\x00d\x00\x00\xff\xe1' \ b'\x03{http://ns.adobe.com/' datafile = io.BytesIO(body) request = self.factory.post("/somewhere", data={"file": datafile}) self.middleware.process_request(request) self._assert_logged(mock_log, "(multipart/form)") def test_request_headers_logged(self, mock_log): request = self.factory.post("/somewhere", **{'HTTP_USER_AGENT': 'silly-human'}) self.middleware.process_request(request) self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_response_headers_logged(self, mock_log): request = self.factory.post("/somewhere") response = mock.MagicMock() response.get.return_value = 'application/json' response._headers = {'test_headers': 'test_headers'} self.middleware.process_response(request, response) self._assert_logged(mock_log, "test_headers") def test_call_logged(self, mock_log): body = u"some body" request = self.factory.post("/somewhere", data={"file": body}, **{'HTTP_USER_AGENT': 'silly-human'}) self.middleware.__call__(request) self._assert_logged(mock_log, body) self._assert_logged(mock_log, "test_headers") self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_call_binary_logged(self, mock_log): body = u"some body" datafile = io.StringIO(body) request = self.factory.post("/somewhere", data={"file": datafile}, **{'HTTP_USER_AGENT': 'silly-human'}) self.middleware.__call__(request) self._assert_logged(mock_log, "(binary data)") self._assert_logged(mock_log, "test_headers") self._assert_logged(mock_log, "HTTP_USER_AGENT") @unittest.skipIf(sys.version_info < (3, 0), "This issue won't happen on python 2") def test_call_jpeg_logged(self, mock_log): body = b'--BoUnDaRyStRiNg\r\nContent-Disposition: form-data; name="file"; filename="campaign_carousel_img.jp' \ b'g"\r\nContent-Type: image/jpeg\r\n\r\n\xff\xd8\xff\xe1\x00\x18Exif\x00\x00II*\x00\x08\x00\x00\x00' \ b'\x00\x00\x00\x00\x00\x00\x00\x00\xff\xec\x00\x11Ducky\x00\x01\x00\x04\x00\x00\x00d\x00\x00\xff\xe1' \ b'\x03{http://ns.adobe.com/' datafile = io.BytesIO(body) request = self.factory.post("/somewhere", data={"file": datafile}, **{'HTTP_USER_AGENT': 'silly-human'}) self.middleware.__call__(request) self._assert_logged(mock_log, "(multipart/form)") self._assert_logged(mock_log, "test_headers") self._assert_logged(mock_log, "HTTP_USER_AGENT")
def test_logging_default_http_4xx_error(self, mock_log): middleware = LoggingMiddleware() middleware.process_response(self.request, self.response_404) self.assertEqual(DEFAULT_HTTP_4XX_LOG_LEVEL, logging.ERROR) self._assert_logged_with_level(mock_log, DEFAULT_HTTP_4XX_LOG_LEVEL)
class LogTestCase(BaseLogTestCase): def setUp(self): self.factory = RequestFactory() def get_response(request): response = mock.MagicMock() response.status_code = 200 response.get.return_value = "application/json" response._headers = {"test_headers": "test_headers"} return response self.middleware = LoggingMiddleware(get_response) def test_request_body_logged(self, mock_log): body = u"some body" request = self.factory.post("/somewhere", data={"file": body}) self.middleware.process_request(request) self._assert_logged(mock_log, body) def test_request_binary_logged(self, mock_log): body = u"some body" datafile = io.StringIO(body) request = self.factory.post("/somewhere", data={"file": datafile}) self.middleware.process_request(request) self._assert_logged(mock_log, "(binary data)") def test_request_jpeg_logged(self, mock_log): body = ( b'--BoUnDaRyStRiNg\r\nContent-Disposition: form-data; name="file"; filename="campaign_carousel_img.jp' b'g"\r\nContent-Type: image/jpeg\r\n\r\n\xff\xd8\xff\xe1\x00\x18Exif\x00\x00II*\x00\x08\x00\x00\x00' b"\x00\x00\x00\x00\x00\x00\x00\x00\xff\xec\x00\x11Ducky\x00\x01\x00\x04\x00\x00\x00d\x00\x00\xff\xe1" b"\x03{http://ns.adobe.com/") datafile = io.BytesIO(body) request = self.factory.post("/somewhere", data={"file": datafile}) self.middleware.process_request(request) self._assert_logged(mock_log, "(multipart/form)") def test_request_headers_logged(self, mock_log): request = self.factory.post("/somewhere", **{"HTTP_USER_AGENT": "silly-human"}) self.middleware.process_request(request) self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_request_headers_sensitive_logged_default(self, mock_log): request = self.factory.post( "/somewhere", **{ "HTTP_AUTHORIZATION": "sensitive-token", "HTTP_PROXY_AUTHORIZATION": "proxy-token" }) middleware = LoggingMiddleware() middleware.process_request(request) self._assert_logged(mock_log, "HTTP_AUTHORIZATION") self._assert_logged(mock_log, "HTTP_PROXY_AUTHORIZATION") self._assert_logged_with_key_value(mock_log, "HTTP_AUTHORIZATION", "*****") self._assert_logged_with_key_value(mock_log, "HTTP_PROXY_AUTHORIZATION", "*****") @override_settings( REQUEST_LOGGING_SENSITIVE_HEADERS=["HTTP_AUTHORIZATION"]) def test_request_headers_sensitive_logged(self, mock_log): request = self.factory.post( "/somewhere", **{ "HTTP_AUTHORIZATION": "sensitive-token", "HTTP_USER_AGENT": "silly-human", "HTTP_PROXY_AUTHORIZATION": "proxy-token", }) middleware = LoggingMiddleware() middleware.process_request(request) self._assert_logged(mock_log, "HTTP_AUTHORIZATION") self._assert_logged(mock_log, "HTTP_USER_AGENT") self._assert_logged(mock_log, "HTTP_PROXY_AUTHORIZATION") self._assert_logged_with_key_value(mock_log, "HTTP_AUTHORIZATION", "*****") self._assert_logged_with_key_value(mock_log, "HTTP_USER_AGENT", "silly-human") self._assert_logged_with_key_value(mock_log, "HTTP_PROXY_AUTHORIZATION", "proxy-token") def test_response_headers_logged(self, mock_log): request = self.factory.post("/somewhere") response = mock.MagicMock() response.get.return_value = "application/json" response._headers = {"test_headers": "test_headers"} self.middleware.process_response(request, response) self._assert_logged(mock_log, "test_headers") def test_call_logged(self, mock_log): body = u"some body" request = self.factory.post("/somewhere", data={"file": body}, **{"HTTP_USER_AGENT": "silly-human"}) self.middleware.__call__(request) self._assert_logged(mock_log, body) self._assert_logged(mock_log, "test_headers") self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_call_binary_logged(self, mock_log): body = u"some body" datafile = io.StringIO(body) request = self.factory.post("/somewhere", data={"file": datafile}, **{"HTTP_USER_AGENT": "silly-human"}) self.middleware.__call__(request) self._assert_logged(mock_log, "(binary data)") self._assert_logged(mock_log, "test_headers") self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_call_jpeg_logged(self, mock_log): body = ( b'--BoUnDaRyStRiNg\r\nContent-Disposition: form-data; name="file"; filename="campaign_carousel_img.jp' b'g"\r\nContent-Type: image/jpeg\r\n\r\n\xff\xd8\xff\xe1\x00\x18Exif\x00\x00II*\x00\x08\x00\x00\x00' b"\x00\x00\x00\x00\x00\x00\x00\x00\xff\xec\x00\x11Ducky\x00\x01\x00\x04\x00\x00\x00d\x00\x00\xff\xe1" b"\x03{http://ns.adobe.com/") datafile = io.BytesIO(body) request = self.factory.post("/somewhere", data={"file": datafile}, **{"HTTP_USER_AGENT": "silly-human"}) self.middleware.__call__(request) self._assert_logged(mock_log, "(multipart/form)") self._assert_logged(mock_log, "test_headers") self._assert_logged(mock_log, "HTTP_USER_AGENT") def test_minimal_logging_when_streaming(self, mock_log): uri = "/somewhere" request = self.factory.get(uri) response = StreamingHttpResponse(status=200, streaming_content=b"OK", content_type="application/json") self.middleware.process_response(request, response=response) self._assert_logged(mock_log, "(data_stream)")