def test_process_request_user(self): mock_response = Mock() mock_response.status_code.return_value = 200 expected_uuid = "00000000-0000-0000-0000-000000000000" self.log_results = None def get_response(_response): with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.log_results = log_results return mock_response request = self.factory.get("/foo") mock_user = User.objects.create() request.user = mock_user middleware = middlewares.RequestMiddleware(get_response) with patch("uuid.UUID.__str__", return_value=expected_uuid): middleware(request) self.assertEqual(1, len(self.log_results.records)) record = self.log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"]) with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.assertEqual(1, len(log_results.records)) record = log_results.records[0] self.assertNotIn("request_id", record.msg) self.assertNotIn("user_id", record.msg)
def test_signal(self): @receiver(bind_extra_request_metadata) def receiver_bind_extra_request_metadata(sender, signal, request=None, logger=None): logger.bind(user_email=getattr(request.user, "email", "")) mock_response = Mock() mock_response.status_code.return_value = 200 self.log_results = None def get_response(_response): with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.log_results = log_results return mock_response request = self.factory.get("/foo") mock_user = User.objects.create(email="*****@*****.**") request.user = mock_user middleware = middlewares.RequestMiddleware(get_response) middleware(request) self.assertEqual(1, len(self.log_results.records)) record = self.log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(mock_user.email, record.msg["user_email"]) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"])
def test_should_log_correlation_id_from_request_x_correlation_id_header( self): mock_response = Mock() mock_response.status_code.return_value = 200 x_correlation_id = "my-fake-correlation-id" def get_response(_response): with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.log_results = log_results return mock_response request = RequestFactory( HTTP_X_CORRELATION_ID=x_correlation_id).get("/foo") middleware = middlewares.RequestMiddleware(get_response) middleware(request) self.assertEqual(1, len(self.log_results.records)) record = self.log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("request_id", record.msg) self.assertNotIn("user_id", record.msg) self.assertEqual(x_correlation_id, record.msg["correlation_id"])
def test_process_request_user_uuid(self): mock_response = Mock() mock_response.status_code.return_value = 200 expected_uuid = "00000000-0000-0000-0000-000000000000" def get_response(_response): with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.log_results = log_results return mock_response request = self.factory.get("/foo") mock_user = mock.Mock() mock_user.pk = uuid.UUID(expected_uuid) request.user = mock_user middleware = middlewares.RequestMiddleware(get_response) middleware(request) self.assertEqual(1, len(self.log_results.records)) record = self.log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("user_id", record.msg) self.assertIsInstance(record.msg["user_id"], str) self.assertEqual(expected_uuid, record.msg["user_id"])
def test_process_request_error(self): expected_uuid = "00000000-0000-0000-0000-000000000000" request = self.factory.get("/foo") request.user = AnonymousUser() middleware = middlewares.RequestMiddleware(None) exception = Exception("This is an exception") def get_response(_response): """ Simulate an exception """ try: raise exception except Exception as e: middleware.process_exception(request, e) self.exception_traceback = traceback.format_exc() middleware.get_response = get_response with patch("uuid.UUID.__str__", return_value=expected_uuid), self.assertLogs( logging.getLogger("django_structlog"), logging.INFO ) as log_results: middleware(request) self.assertEqual(2, len(log_results.records)) record = log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertIsNone(record.msg["user_id"]) record = log_results.records[1] self.assertEqual("ERROR", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertIsNone(record.msg["user_id"]) self.assertIn("code", record.msg) self.assertEqual(record.msg["code"], 500) self.assertIn("exception", record.msg) self.assertEqual(self.exception_traceback.strip(), record.msg["exception"]) self.assertIn("request", record.msg) with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.assertEqual(1, len(log_results.records)) record = log_results.records[0] self.assertNotIn("request_id", record.msg) self.assertNotIn("user_id", record.msg)
def test_process_request_404_are_processed_as_regular_requests(self): expected_uuid = "00000000-0000-0000-0000-000000000000" self.log_results = None request = self.factory.get("/foo") request.user = AnonymousUser() middleware = middlewares.RequestMiddleware(None) exception = Http404() def get_response(_response): """ Simulate an exception """ middleware.process_exception(request, exception) return HttpResponseNotFound() middleware.get_response = get_response with patch("uuid.UUID.__str__", return_value=expected_uuid), self.assertLogs( logging.getLogger("django_structlog"), logging.INFO) as log_results: middleware(request) self.assertEqual(2, len(log_results.records)) record = log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertIsNone(record.msg["user_id"]) record = log_results.records[1] self.assertEqual("INFO", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertIsNone(record.msg["user_id"]) self.assertIn("code", record.msg) self.assertEqual(record.msg["code"], 404) self.assertNotIn("error", record.msg) self.assertNotIn("error_traceback", record.msg) self.assertIn("request", record.msg) with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.assertEqual(1, len(log_results.records)) record = log_results.records[0] self.assertNotIn("request_id", record.msg) self.assertNotIn("user_id", record.msg)
def test_signal_bind_extra_request_failed_metadata(self): expected_exception = Exception() @receiver(bind_extra_request_failed_metadata) def receiver_bind_extra_request_metadata(sender, signal, request=None, logger=None, exception=None): self.assertEqual(exception, expected_exception) logger.bind(user_email=getattr(request.user, "email", "")) request = self.factory.get("/foo") mock_user = User.objects.create(email="*****@*****.**") request.user = mock_user middleware = middlewares.RequestMiddleware(None) mock_response = Mock() def get_response(_response): middleware.process_exception(request, expected_exception) return mock_response middleware.get_response = get_response with self.assertLogs("django_structlog.middlewares.request", logging.INFO) as log_results: middleware(request) self.assertEqual(2, len(log_results.records)) record = log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("event", record.msg) self.assertEqual("request_started", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertNotIn("user_email", record.msg) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"]) record = log_results.records[1] self.assertEqual("ERROR", record.levelname) self.assertIn("event", record.msg) self.assertEqual("request_failed", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertIn("user_email", record.msg) self.assertEqual(mock_user.email, record.msg["user_email"]) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"])
def test_process_request_error(self): expected_uuid = "00000000-0000-0000-0000-000000000000" self.log_results = None def get_response(_response): raise Exception("This is an exception") request = self.factory.get("/foo") request.user = AnonymousUser() middleware = middlewares.RequestMiddleware(get_response) with patch("uuid.UUID.__str__", return_value=expected_uuid), self.assertLogs( logging.getLogger("django_structlog"), logging.INFO) as log_results, self.assertRaises( Exception) as e: middleware(request) self.assertEqual("This is an exception", str(e.exception)) self.assertEqual(2, len(log_results.records)) record = log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertIsNone(record.msg["user_id"]) record = log_results.records[1] self.assertEqual("ERROR", record.levelname) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertIsNone(record.msg["user_id"]) self.assertIn("code", record.msg) self.assertEqual(record.msg["code"], 500) self.assertIn("error_message", record.msg) self.assertEqual(record.msg["error_message"], "This is an exception") self.assertIn("error_traceback", record.msg) self.assertEqual(type(record.msg["error_traceback"]), list) self.assertIn("request", record.msg) with self.assertLogs(__name__, logging.INFO) as log_results: self.logger.info("hello") self.assertEqual(1, len(log_results.records)) record = log_results.records[0] self.assertNotIn("request_id", record.msg) self.assertNotIn("user_id", record.msg)
def test_log_user_in_request_finished_with_exception(self): mock_response = Mock() mock_response.status_code.return_value = 200 expected_uuid = "00000000-0000-0000-0000-000000000000" mock_user = User.objects.create() request = self.factory.get("/foo") middleware = middlewares.RequestMiddleware(None) exception = Exception() def get_response(_response): request.user = mock_user try: raise exception except Exception as e: middleware.process_exception(request, e) self.exception_traceback = traceback.format_exc() return mock_response middleware.get_response = get_response with patch("uuid.UUID.__str__", return_value=expected_uuid), self.assertLogs( "django_structlog.middlewares.request", logging.INFO ) as log_results: middleware(request) self.assertEqual(2, len(log_results.records)) record = log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertEqual("request_started", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertNotIn("user_id", record.msg) record = log_results.records[1] self.assertEqual("ERROR", record.levelname) self.assertEqual("request_failed", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("exception", record.msg) self.assertEqual(self.exception_traceback.strip(), record.msg["exception"]) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"])
def test_signal_bind_extra_request_finished_metadata(self): mock_response = Mock() mock_response.status_code.return_value = 200 @receiver(bind_extra_request_finished_metadata) def receiver_bind_extra_request_metadata(sender, signal, request=None, logger=None, response=None): self.assertEqual(response, mock_response) logger.bind(user_email=getattr(request.user, "email", "")) def get_response(_response): return mock_response request = self.factory.get("/foo") mock_user = User.objects.create(email="*****@*****.**") request.user = mock_user middleware = middlewares.RequestMiddleware(get_response) with self.assertLogs("django_structlog.middlewares.request", logging.INFO) as log_results: middleware(request) self.assertEqual(2, len(log_results.records)) record = log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertIn("event", record.msg) self.assertEqual("request_started", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertNotIn("user_email", record.msg) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"]) record = log_results.records[1] self.assertEqual("INFO", record.levelname) self.assertIn("event", record.msg) self.assertEqual("request_finished", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertIn("user_email", record.msg) self.assertEqual(mock_user.email, record.msg["user_email"]) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"])
def test_log_user_in_request_finished(self): mock_response = Mock() mock_response.status_code.return_value = 200 expected_uuid = "00000000-0000-0000-0000-000000000000" mock_user = User.objects.create() request = self.factory.get("/foo") def get_response(_response): request.user = mock_user return mock_response middleware = middlewares.RequestMiddleware(get_response) with patch("uuid.UUID.__str__", return_value=expected_uuid), self.assertLogs( "django_structlog.middlewares.request", logging.INFO) as log_results: middleware(request) self.assertEqual(2, len(log_results.records)) record = log_results.records[0] self.assertEqual("INFO", record.levelname) self.assertEqual("request_started", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertNotIn("user_id", record.msg) record = log_results.records[1] self.assertEqual("INFO", record.levelname) self.assertEqual("request_finished", record.msg["event"]) self.assertIn("request_id", record.msg) self.assertEqual(expected_uuid, record.msg["request_id"]) self.assertIn("user_id", record.msg) self.assertEqual(mock_user.id, record.msg["user_id"])