Add elapsed time timestamps to codeplain log file

Add elapsed time timestamps (HH:MM:SS format) to file logging, matching the format shown in the TUI logs view. The timestamps reflect time since render started, accounting for pauses.

- Created ElapsedTimeFormatter that uses RunState to calculate elapsed time
- File logs now show [HH:MM:SS] timestamps identical to TUI display
- Multi-line messages are properly indented to align with the timestamp
- Console output remains unchanged with TUI-driven timestamps

Fixes #76

Author: NejcS

plain2code.py

@@ -41,6 +41,7 @@
 from plain2code_logger import (
     LOGGER_NAME,
     CrashLogHandler,
+    ElapsedTimeFormatter,
     IndentedFormatter,
     LoggingHandler,
     dump_crash_logs,
@@ -90,6 +91,7 @@ def setup_logging(
     root_logger.setLevel(logging.DEBUG)  # Capture all logs; handlers will filter levels as needed
 
     formatter = IndentedFormatter("%(levelname)s:%(name)s:%(message)s")
+    file_formatter = ElapsedTimeFormatter(run_state)
 
     if not headless:
         handler = LoggingHandler(event_bus, run_state)
@@ -99,7 +101,7 @@ def setup_logging(
     if log_to_file and log_file_path:
         try:
             file_handler = logging.FileHandler(log_file_path, mode="w", encoding="utf-8")
-            file_handler.setFormatter(formatter)
+            file_handler.setFormatter(file_formatter)
             file_handler.setLevel(configured_log_level)
             root_logger.addHandler(file_handler)
         except Exception as e:
@@ -108,7 +110,7 @@ def setup_logging(
         # If file logging is disabled, use CrashLogHandler to buffer logs in memory
         # in case we need to dump them on crash.
         crash_handler = CrashLogHandler()
-        crash_handler.setFormatter(formatter)
+        crash_handler.setFormatter(file_formatter)
         crash_handler.setLevel(configured_log_level)
         root_logger.addHandler(crash_handler)
 
@@ -355,7 +357,7 @@ def main():  # noqa: C901
         )
         if exc_info:
             # Log traceback
-            dump_crash_logs(args)
+            dump_crash_logs(args, run_state)
 
     if args.headless and (exc_info is not None or not run_state.render_succeeded):
         sys.exit(1)

plain2code_logger.py

@@ -20,6 +20,40 @@ def format(self, record):
         return super().format(record)
 
 
+class ElapsedTimeFormatter(logging.Formatter):
+    """Formatter that adds elapsed time since render started, accounting for pauses."""
+
+    def __init__(self, run_state: RunState, fmt: str = "%(elapsed_time)s %(levelname)s %(name)s: %(message)s"):
+        super().__init__(fmt=fmt)
+        self.run_state = run_state
+
+    def format(self, record):
+        # Calculate elapsed time the same way as LoggingHandler does for the TUI
+        try:
+            offset_seconds = self.run_state.render_time_accumulated + int(
+                time.monotonic() - self.run_state.last_render_start_timestamp
+            )
+        except Exception:
+            # If RunState is not available or there's any error, default to 00:00:00
+            offset_seconds = 0
+
+        hours = offset_seconds // 3600
+        minutes = (offset_seconds % 3600) // 60
+        seconds = offset_seconds % 60
+        elapsed_time = f"[{hours:02d}:{minutes:02d}:{seconds:02d}]"
+
+        # Add elapsed_time to the record so it can be used in the format string
+        record.elapsed_time = elapsed_time
+
+        # Handle multi-line messages with proper indentation
+        original_message = record.getMessage()
+        indent = " " * len(elapsed_time + " ")
+        modified_message = original_message.replace("\n", "\n" + indent)
+        record.msg = modified_message
+
+        return super().format(record)
+
+
 class LoggingHandler(logging.Handler):
     def __init__(self, event_bus: EventBus, run_state: RunState):
         super().__init__()
@@ -85,13 +119,13 @@ def get_log_file_path(plain_file_path: Optional[str], log_file_name: str) -> Opt
     return os.path.join(plain_dir, log_file_name)
 
 
-def dump_crash_logs(args, formatter=None):
+def dump_crash_logs(args, run_state: RunState, formatter=None):
     """Dump buffered logs to file if CrashLogHandler is present."""
     if args.log_to_file:
         return
 
     if formatter is None:
-        formatter = IndentedFormatter("%(levelname)s:%(name)s:%(message)s")
+        formatter = ElapsedTimeFormatter(run_state)
 
     root_logger = logging.getLogger(LOGGER_NAME)
     crash_handler = next((h for h in root_logger.handlers if isinstance(h, CrashLogHandler)), None)