Capture logs when scanning

src/openflexure_microscope_server/scan_directories.py

@@ -19,10 +19,15 @@ from pydantic import (
     model_validator,
 )
 
+import labthings_fastapi as lt
 from labthings_fastapi.exceptions import InvocationError
 
 from openflexure_microscope_server.stitching import StitchingSettings
-from openflexure_microscope_server.utilities import make_name_safe, requires_lock
+from openflexure_microscope_server.utilities import (
+    make_name_safe,
+    requires_lock,
+    save_invocation_logs,
+)
 
 LOGGER = logging.getLogger(__name__)
 
@@ -446,6 +451,7 @@ class ScanDirectory:
         :param name: the name of the scan (the scan directory basename).
         :param base_scan_dir: Path of the directory that holds all scans.
         """
+        self._log_saved_at = 0.0
         self._name = name
         self._base_scan_dir = base_scan_dir
         if not os.path.isdir(self.dir_path):
@@ -625,6 +631,19 @@ class ScanDirectory:
         with open(self.scan_data_path, "w", encoding="utf-8") as f:
             f.write(scan_data.model_dump_json(indent=4))
 
+    def save_scan_log(self, thing: lt.Thing) -> None:
+        """Save the scan log to file.
+
+        :param thing: The SmartScanThing. This is needed to exxtract the logs from the
+            LabThings server.
+        """
+        self._log_saved_at = save_invocation_logs(
+            filename=os.path.join(self.dir_path, "log.txt"),
+            thing=thing,
+            last_saved=self._log_saved_at,
+            append=True,
+        )
+
     def zip_files(self, final_version: bool = False) -> str:
         """Zips any images from the scan not yet zipped, return full path to zip.
 

src/openflexure_microscope_server/things/smart_scan.py

@@ -263,6 +263,8 @@ class SmartScanThing(lt.Thing):
             self._ongoing_scan = self._scan_dir_manager.new_scan_dir(scan_name)
             self._latest_scan_name = self.ongoing_scan.name
             self._run_scan(workflow)
+            # Save any final messages.
+            self._ongoing_scan.save_scan_log(self)
         except Exception as e:
             # If _scan_data is set then scan started
             if self._scan_data is not None:
@@ -273,6 +275,9 @@ class SmartScanThing(lt.Thing):
                         "Attempting to stitch and archive the images acquired so far."
                     )
                     self._perform_final_stitch()
+            if self._ongoing_scan is not None:
+                # Save any final messages even if there is an exception.
+                self._ongoing_scan.save_scan_log(self)
             # Error must be raised so UI gives correct output
             raise e
         finally:
@@ -467,6 +472,7 @@ class SmartScanThing(lt.Thing):
                 self.scan_data.image_count += 1
                 # Add it to the incremental zip
                 self.ongoing_scan.zip_files()
+            self.ongoing_scan.save_scan_log(self)
 
     @_scan_running
     def _return_to_starting_position(self) -> None:

src/openflexure_microscope_server/utilities.py

@@ -6,6 +6,7 @@ import os
 import re
 import sys
 import tomllib
+from datetime import datetime
 from functools import wraps
 from importlib.metadata import version
 from typing import (
@@ -24,6 +25,7 @@ from typing import (
 from pydantic import BaseModel
 
 import labthings_fastapi as lt
+from labthings_fastapi.invocation_contexts import get_invocation_id
 
 T = TypeVar("T")
 P = ParamSpec("P")
@@ -432,3 +434,57 @@ def coerce_thing_selector(
 
     # Final option is to return the first key
     return list(thing_mapping)[0]
+
+
+def get_invocation_logs(
+    thing: lt.Thing, logged_since: float = 0.0
+) -> list[logging.LogRecord]:
+    """Get logs from an ongoing action invocation.
+
+    This must be called from the action's context (thread).
+
+    Note that only 1000 logs are stored in LabThings for very long tasks that
+    log regularly it may be good to periodically poll this and request only
+    the logs since the last log was created.
+
+    :param thing: The thing that the action is called from.
+    :param logged_since: The timestamp that records must come after. This could be the
+        ``record.created`` time of the last log.
+    :return: A list of ``LogRecord`` objects.
+    """
+    server = thing._thing_server_interface._server()
+    if server is None:
+        raise RuntimeError("Could not retrieve server from thing_server_interface.")
+    manager = server.action_manager
+    inv_id = get_invocation_id()
+    invocation = manager.get_invocation(inv_id)
+
+    # Type ignore needed as LabThings incorrectly reports the type from invocation.log
+    # If pull request 260 on LabThings is merged we can remove this function.
+    return [record for record in invocation.log if record.created > logged_since]  # type: ignore
+
+
+def save_invocation_logs(
+    filename: str, thing: lt.Thing, last_saved: float = 0.0, append: bool = True
+) -> float:
+    """Save the invocation logs from and ongoing action.
+
+    This must be called from the action's context (thread).
+
+    :param filename: The filename to write the logs to.
+    :param thing: The thing that the action is called from.
+    :param last_saved: The timestamp that records must come after.
+    :param append: If True (default) append to the file if it exists.
+
+    :return: The timestamp of the most recent log.
+    """
+    logs = get_invocation_logs(thing, last_saved)
+    mode = "a" if append else "w"
+    with open(filename, mode, encoding="utf-8") as log_file:
+        for record in logs:
+            level = record.levelname
+            dt = datetime.fromtimestamp(record.created)
+            date_str = dt.strftime("%Y-%m-%d %H:%M:%S")
+            msg = record.getMessage()
+            log_file.write(f"[{date_str}] [{level}] {msg}\n")
+    return 0.0 if not logs else logs[-1].created