Fix log entry timestamps

plain2code.py

@@ -42,7 +42,7 @@
     LOGGER_NAME,
     CrashLogHandler,
     IndentedFormatter,
-    TuiLoggingHandler,
+    LoggingHandler,
     dump_crash_logs,
     get_log_file_path,
 )
@@ -125,6 +125,7 @@ def _get_frids_range(plain_source, start, end=None):
 def setup_logging(
     args,
     event_bus: EventBus,
+    run_state: RunState,
     log_to_file: bool,
     log_file_name: str,
     plain_file_path: Optional[str],
@@ -150,15 +151,15 @@ def setup_logging(
             console.warning(f"Failed to load logging configuration from {args.logging_config_path}: {str(e)}")
 
     # The IndentedFormatter provides better multiline log readability.
-    # We add the TuiLoggingHandler to the root logger.
+    # We add the LoggingHandler to the root logger.
     root_logger = logging.getLogger(LOGGER_NAME)
     configured_log_level = root_logger.level
     root_logger.setLevel(logging.DEBUG)  # Capture all logs; handlers will filter levels as needed
 
     formatter = IndentedFormatter("%(levelname)s:%(name)s:%(message)s")
 
     if not headless:
-        handler = TuiLoggingHandler(event_bus)
+        handler = LoggingHandler(event_bus, run_state)
         handler.setFormatter(formatter)
         root_logger.addHandler(handler)
 
@@ -313,7 +314,7 @@ def main():  # noqa: C901
         # Suppress Rich console output.
         console.quiet = True
 
-    setup_logging(args, event_bus, args.log_to_file, args.log_file_name, args.filename, args.headless)
+    setup_logging(args, event_bus, run_state, args.log_to_file, args.log_file_name, args.filename, args.headless)
 
     exc_info = None
     try:

plain2code_logger.py

@@ -5,6 +5,7 @@
 
 from event_bus import EventBus
 from plain2code_events import LogMessageEmitted
+from plain2code_state import RunState
 
 LOGGER_NAME = "codeplain"
 
@@ -19,15 +20,18 @@ def format(self, record):
         return super().format(record)
 
 
-class TuiLoggingHandler(logging.Handler):
-    def __init__(self, event_bus: EventBus):
+class LoggingHandler(logging.Handler):
+    def __init__(self, event_bus: EventBus, run_state: RunState):
         super().__init__()
         self.event_bus = event_bus
-        self.start_time = time.time()
+        self.run_state = run_state
 
     def emit(self, record):
         try:
-            offset_seconds = int(record.created - self.start_time)
+            offset_seconds = self.run_state.render_time_accumulated + int(
+                time.monotonic() - self.run_state.last_render_start_timestamp
+            )
+
             hours = offset_seconds // 3600
             minutes = (offset_seconds % 3600) // 60
             seconds = offset_seconds % 60

render_machine/code_renderer.py

@@ -76,6 +76,8 @@ def run(self):
             next_trigger = self.action_result_triggers_map[outcome]
             self.machine.dispatch(next_trigger)
 
+        self.render_context.run_state.add_to_render_time()
+
     def generate_render_machine_graph(self):
         """Generate a visual diagram of the state machine."""
         self.render_context.get_graph().draw("render_machine_diagram.png", prog="dot")

render_machine/render_context.py

@@ -450,8 +450,6 @@ def finish_fixing_conformance_tests(self):
 
     def start_render_completed(self):
         self.run_state.set_render_succeeded(True)
-        self.run_state.add_to_render_time()
 
     def start_render_failed(self):
         self.run_state.set_render_succeeded(False)
-        self.run_state.add_to_render_time()