From 013341272eeaf971800c23b0e4863c42e15cf807 Mon Sep 17 00:00:00 2001
From: Joe Knapper <jaknapper@hotmail.com>
Date: Tue, 7 Jul 2026 14:47:53 +0100
Subject: [PATCH] Only format file log, add tests

---
 src/openflexure_microscope_server/logging.py | 26 +++++------
 tests/unit_tests/test_logging.py             | 45 ++++++++++++++++++++
 2 files changed, 56 insertions(+), 15 deletions(-)

diff --git a/src/openflexure_microscope_server/logging.py b/src/openflexure_microscope_server/logging.py
index 40709fa8..199f324b 100644
--- a/src/openflexure_microscope_server/logging.py
+++ b/src/openflexure_microscope_server/logging.py
@@ -52,8 +52,8 @@ def configure_logging(log_folder: str, debug: bool = False) -> None:
 
     # Add OFM_HANDLER first so it can capture the error log if the
     # log file can't be accessed.
-    ofm_format_str = "[%(asctime)s] [%(levelname)s]%(invocation_id_str)s %(message)s"
-    OFM_HANDLER.setFormatter(OFMConsoleFormatter(ofm_format_str))
+    ofm_format_str = "[%(asctime)s] [%(levelname)s] %(message)s"
+    OFM_HANDLER.setFormatter(logging.Formatter(ofm_format_str))
     OFM_HANDLER.addFilter(UvicornAccessFilter())
     OFM_HANDLER.addFilter(inject_invocation_id)
     OFM_HANDLER.level = root_logger.level
@@ -120,7 +120,10 @@ def retrieve_log_from_file() -> PlainTextResponse:
 
 
 class OFMLogFileFormatter(logging.Formatter):
-    """The formatter used for the OpenFlexure Microscope Server log file."""
+    """The formatter used for the OpenFlexure Microscope Server log file.
+
+    This is the log that is then read by the GUI.
+    """
 
     def format(self, record: logging.LogRecord) -> str:
         """Adjust the logging formatting for uvicorn logs.
@@ -131,6 +134,11 @@ class OFMLogFileFormatter(logging.Formatter):
         such as server start up. This can lead to people erroneously thinking that
         there is an error with their miroscope.
         """
+        invocation_id = getattr(record, "invocation_id", None)
+        record.invocation_id_str = (
+            f" [invocation:{invocation_id}]" if invocation_id else ""
+        )
+
         if record.name == "uvicorn.error" and record.levelno < logging.ERROR:
             record.name = "uvicorn"
         return super().format(record)
@@ -188,16 +196,4 @@ class UvicornAccessFilter(logging.Filter):
         return not record.name.startswith("uvicorn.access")
 
 
-class OFMConsoleFormatter(logging.Formatter):
-    """Formatter for OFM_HANDLER (the UI-facing log)."""
-
-    def format(self, record: logging.LogRecord) -> str:
-        """Render the invocation ID into the record, if present."""
-        invocation_id = getattr(record, "invocation_id", None)
-        record.invocation_id_str = (
-            f" [invocation:{invocation_id}]" if invocation_id else ""
-        )
-        return super().format(record)
-
-
 OFM_HANDLER = OFMHandler()
diff --git a/tests/unit_tests/test_logging.py b/tests/unit_tests/test_logging.py
index 0f961c23..76ae0f24 100644
--- a/tests/unit_tests/test_logging.py
+++ b/tests/unit_tests/test_logging.py
@@ -234,3 +234,48 @@ def test_configure_logging_debug_mode(debug_flag, expected_level):
         # Cleanup: Remove the OFM_HANDLER from the root logger so it doesn't
         # interfere with other tests in the suite.
         root_logger.removeHandler(ofm_logging.OFM_HANDLER)
+
+
+def test_log_file_formatter_includes_invocation_id():
+    """Check that invocation IDs are included in logs when available."""
+    formatter = ofm_logging.OFMLogFileFormatter(
+        "[%(levelname)s]%(invocation_id_str)s %(message)s"
+    )
+
+    record = logging.LogRecord(
+        name="test",
+        level=logging.INFO,
+        pathname="",
+        lineno=0,
+        msg="Test message",
+        args=(),
+        exc_info=None,
+    )
+    record.invocation_id = "abc123"
+
+    formatted = formatter.format(record)
+
+    assert "[invocation:abc123]" in formatted
+    assert "Test message" in formatted
+
+
+def test_log_file_formatter_without_invocation_id():
+    """Check that logs without invocation IDs still format correctly."""
+    formatter = ofm_logging.OFMLogFileFormatter(
+        "[%(levelname)s]%(invocation_id_str)s %(message)s"
+    )
+
+    record = logging.LogRecord(
+        name="test",
+        level=logging.INFO,
+        pathname="",
+        lineno=0,
+        msg="Test message",
+        args=(),
+        exc_info=None,
+    )
+
+    formatted = formatter.format(record)
+
+    assert "[invocation:" not in formatted
+    assert "Test message" in formatted