From d63f10eed43663e30bc3cd84db795627827dc28c Mon Sep 17 00:00:00 2001
From: Kim Gustyr <kim.gustyr@flagsmith.com>
Date: Wed, 13 Nov 2024 16:40:53 +0000
Subject: [PATCH] add test, remove redundant error handling

---
 api/tests/unit/util/test_logging.py | 67 +++++++++++++++++++++++++++--
 api/util/logging.py                 |  8 +---
 2 files changed, 66 insertions(+), 9 deletions(-)

diff --git a/api/tests/unit/util/test_logging.py b/api/tests/unit/util/test_logging.py
index 205b31860beb..389437ffdaf4 100644
--- a/api/tests/unit/util/test_logging.py
+++ b/api/tests/unit/util/test_logging.py
@@ -2,12 +2,13 @@
 import logging
 import logging.config
 import os
+from datetime import datetime
 
 import pytest
-from gunicorn.config import Config
+from gunicorn.config import AccessLogFormat, Config
 from pytest_django.fixtures import SettingsWrapper
 
-from util.logging import JsonFormatter
+from util.logging import GunicornAccessLogJsonFormatter, JsonFormatter
 
 
 @pytest.mark.freeze_time("2023-12-08T06:05:47.320000+00:00")
@@ -28,7 +29,7 @@ def test_json_formatter__outputs_expected(
     expected_tb_string = (
         "Traceback (most recent call last):\n"
         f'  File "{expected_module_path}",'
-        " line 37, in _log_traceback\n"
+        " line 38, in _log_traceback\n"
         "    raise Exception()\nException"
     )
 
@@ -64,6 +65,66 @@ def _log_traceback() -> None:
     ]
 
 
+@pytest.mark.freeze_time("2023-12-08T06:05:47.320000+00:00")
+def test_gunicorn_access_log_json_formatter__outputs_expected() -> None:
+    # Given
+    gunicorn_access_log_json_formatter = GunicornAccessLogJsonFormatter()
+    log_record = logging.LogRecord(
+        name="gunicorn.access",
+        level=logging.INFO,
+        pathname="",
+        lineno=1,
+        msg=AccessLogFormat.default,
+        args={
+            "a": "requests",
+            "b": "-",
+            "B": None,
+            "D": 1000000,
+            "f": "-",
+            "h": "192.168.0.1",
+            "H": None,
+            "l": "-",
+            "L": "1.0",
+            "m": "GET",
+            "M": 1000,
+            "p": "<42>",
+            "q": "foo=bar",
+            "r": "GET",
+            "s": 200,
+            "T": 1,
+            "t": datetime.fromisoformat("2023-12-08T06:05:47.320000+00:00").strftime(
+                "[%d/%b/%Y:%H:%M:%S %z]"
+            ),
+            "u": "-",
+            "U": "/test",
+        },
+        exc_info=None,
+    )
+    expected_pid = os.getpid()
+
+    # When
+    json_log = gunicorn_access_log_json_formatter.get_json_record(log_record)
+
+    # Then
+    assert json_log == {
+        "duration_in_ms": 1000,
+        "levelname": "INFO",
+        "logger_name": "gunicorn.access",
+        "message": '192.168.0.1 - - [08/Dec/2023:06:05:47 +0000] "GET" 200 - "-" "requests"',
+        "method": "GET",
+        "path": "/test?foo=bar",
+        "pid": "<42>",
+        "process_id": expected_pid,
+        "referer": "-",
+        "remote_ip": "192.168.0.1",
+        "status": "200",
+        "thread_name": "MainThread",
+        "time": "2023-12-08T06:05:47+00:00",
+        "timestamp": "2023-12-08 06:05:47,319",
+        "user_agent": "requests",
+    }
+
+
 def test_gunicorn_json_capable_logger__non_existent_setting__not_raises(
     settings: SettingsWrapper,
 ) -> None:
diff --git a/api/util/logging.py b/api/util/logging.py
index 06361088de02..45b3fc18fcce 100644
--- a/api/util/logging.py
+++ b/api/util/logging.py
@@ -27,15 +27,11 @@ def get_json_record(self, record: logging.LogRecord) -> dict[str, Any]:
         return json_record
 
     def format(self, record: logging.LogRecord) -> str:
-        try:
-            return json.dumps(self.get_json_record(record))
-        except (ValueError, TypeError) as e:
-            return json.dumps({"message": f"{e} when dumping log"})
+        return json.dumps(self.get_json_record(record))
 
 
 class GunicornAccessLogJsonFormatter(JsonFormatter):
     def get_json_record(self, record: logging.LogRecord) -> dict[str, Any]:
-        response_time = datetime.strptime(record.args["t"], "[%d/%b/%Y:%H:%M:%S %z]")
         args = record.args
         url = args["U"]
         if q := args["q"]:
@@ -43,7 +39,7 @@ def get_json_record(self, record: logging.LogRecord) -> dict[str, Any]:
 
         return {
             **super().get_json_record(record),
-            "time": response_time.isoformat(),
+            "time": datetime.strptime(args["t"], "[%d/%b/%Y:%H:%M:%S %z]").isoformat(),
             "path": url,
             "remote_ip": args["h"],
             "method": args["m"],