adding calculation time per processing step

Author: toqduj

src/modacor/dataclasses/trace_event.py

@@ -17,7 +17,7 @@
 from hashlib import sha256
 from typing import Any
 
-from attrs import define, field
+from attrs import define, field, validators
 
 
 def _to_jsonable(value: Any) -> Any:
@@ -93,6 +93,9 @@ class TraceEvent:
     # reserved for later (MessageHandler, timing, etc.)
     messages: list[dict[str, Any]] = field(factory=list)
 
+    # wall-clock runtime for this step execution (seconds)
+    duration_s: float | None = field(default=None, validator=validators.optional(validators.instance_of(float)))
+
     def __attrs_post_init__(self) -> None:
         object.__setattr__(self, "config_hash", _stable_hash_dict(self.config))
 
@@ -109,6 +112,7 @@ def to_dict(self) -> dict[str, Any]:
             "requires_steps": list(self.requires_steps),
             "config": _to_jsonable(self.config),
             "config_hash": self.config_hash,
+            "duration_s": self.duration_s,
             "datasets": _to_jsonable(self.datasets),
             "messages": _to_jsonable(self.messages),
         }

src/modacor/debug/pipeline_tracer.py

@@ -305,7 +305,13 @@ def _diff_kinds(self, prev: BaseDataProbe, now: BaseDataProbe) -> set[str]:
 
         return kinds
 
-    def after_step(self, step: ProcessStep, data: ProcessingData) -> None:  # noqa: C901 # too complex, resolve later
+    def after_step(  # noqa: C901 # too complex, resolve later
+        self,
+        step: ProcessStep,
+        data: ProcessingData,
+        *,
+        duration_s: float | None = None,
+    ) -> None:
         step_id = getattr(step, "step_id", "<??>")
         module = getattr(step.documentation, "calling_id", None) or step.__class__.__name__
         name = getattr(step.documentation, "calling_name", "")
@@ -411,6 +417,7 @@ def after_step(self, step: ProcessStep, data: ProcessingData) -> None:  # noqa:
                     "module": module,
                     "name": name,
                     "changed": changed,
+                    "duration_s": duration_s,
                 }
             )
 
@@ -488,7 +495,11 @@ def fmt_kv(label: str, prev: object | None, now: object, is_changed: bool) -> st
     step_id = tracer_event.get("step_id", "<??>")
     module = tracer_event.get("module", "")
     name = tracer_event.get("name", "")
-    lines.append(r.header(f"Step {step_id} — {module} — {name}"))
+    dur = tracer_event.get("duration_s", None)
+    dur_txt = ""
+    if isinstance(dur, (int, float)):
+        dur_txt = f" {r.dim(f'⏱ {dur * 1e3:.2f} ms')}"  # noqa: E231
+    lines.append(r.header(f"Step {step_id} — {module} — {name}") + dur_txt)
 
     changed_map: dict[tuple[str, str], dict[str, Any]] = tracer_event.get("changed", {}) or {}
     items = sorted(changed_map.items(), key=lambda kv: (kv[0][0], kv[0][1]))

src/modacor/runner/pipeline.py

@@ -642,6 +642,12 @@ def _html_escape(s: str) -> str:
                         datasets = tracer_event_to_datasets_payload(ev)
                         break
 
+        duration_s: float | None = None
+        if matched_ev is not None:
+            d = matched_ev.get("duration_s", None)
+            if isinstance(d, (int, float)):
+                duration_s = float(d)
+
         messages: list[dict[str, Any]] = []
 
         # --- Rendered trace (STRICTLY step-local) ---
@@ -721,6 +727,7 @@ def _html_escape(s: str) -> str:
             requires_steps=prereqs,
             config=cfg,
             datasets=datasets,
+            duration_s=duration_s,
             messages=messages,
         )
 

src/modacor/tests/debug/test_tracing_integration.py

@@ -177,3 +177,14 @@ def test_attach_tracer_event_embeds_rendered_trace_and_config():
     trace_blocks = [m for m in ev.messages if m.get("kind") == "rendered_trace"]
     if trace_blocks:
         assert "Step A" in trace_blocks[0].get("content", "")
+
+
+def test_attach_tracer_event_copies_duration():
+    step = DummyStep(io_sources=None, step_id="A")
+    pipeline = Pipeline.from_dict({step: []}, name="t")
+
+    tracer = PipelineTracer(watch={"sample": ["signal"]}, record_only_on_change=False)
+    tracer.after_step(step, ProcessingData(), duration_s=0.0123)
+
+    ev = pipeline.attach_tracer_event(step, tracer)
+    assert ev.duration_s == 0.0123