feat(telemetry): expose compute pipeline stage metrics

This commit is contained in:
DCCONSTRUCTIONS
2026-07-29 01:53:31 +03:00
parent 783aa444ac
commit 79eb4b46f7
19 changed files with 1000 additions and 24 deletions
@@ -0,0 +1,434 @@
--- run_e15_shadow_inference.py
+++ run_e15_shadow_inference.py
@@ -20,7 +20,8 @@
import threading
import time
from collections import Counter, deque
-from contextlib import suppress
+from collections.abc import Iterator
+from contextlib import contextmanager, suppress
from dataclasses import dataclass
from datetime import UTC, datetime
from pathlib import Path
@@ -108,6 +109,17 @@
WORLD_SCHEMA = "missioncore.live-perception-world-state/v1"
SEMANTIC_SCHEMA = "missioncore.e15-shadow-semantic-frame/v1"
PIPELINE_ID = "shadow-fmp4-yolox-eomt-kb4-amodal-world-state/v1"
+PIPELINE_STAGE_IDS = (
+ "source-ingress",
+ "camera-decode",
+ "preprocessing",
+ "detector",
+ "semantic-model",
+ "sensor-fusion",
+ "tracking",
+ "temporal-state",
+ "result-publication",
+)
def arguments() -> argparse.Namespace:
@@ -539,6 +551,76 @@
summary["rss_growth_mib"] = 0.0
summary["final_queues"] = {}
return summary
+
+
+class _StageExecutionTelemetry:
+ """Measure named pipeline spans without pretending they are OS processes."""
+
+ def __init__(self, stage_ids: tuple[str, ...] = PIPELINE_STAGE_IDS) -> None:
+ if not stage_ids or len(stage_ids) != len(set(stage_ids)):
+ raise RuntimeError("pipeline stage identities are invalid")
+ self._stage_ids = stage_ids
+ self._lock = threading.Lock()
+ self._next_token = 0
+ self._active: dict[int, tuple[str, float, int | None]] = {}
+ self._elapsed_seconds = dict.fromkeys(stage_ids, 0.0)
+ self._activations = dict.fromkeys(stage_ids, 0)
+ self._last_frame_index: int | None = None
+
+ @contextmanager
+ def measure(
+ self,
+ stage_id: str,
+ frame_index: int | None = None,
+ ) -> Iterator[None]:
+ if stage_id not in self._elapsed_seconds:
+ raise RuntimeError(f"unknown pipeline stage: {stage_id}")
+ started = time.perf_counter()
+ with self._lock:
+ self._next_token += 1
+ token = self._next_token
+ self._active[token] = (stage_id, started, frame_index)
+ self._activations[stage_id] += 1
+ if frame_index is not None:
+ self._last_frame_index = frame_index
+ try:
+ yield
+ finally:
+ finished = time.perf_counter()
+ with self._lock:
+ active = self._active.pop(token, None)
+ if active is not None:
+ self._elapsed_seconds[stage_id] += max(0.0, finished - active[1])
+
+ def snapshot(self) -> dict[str, Any]:
+ now = time.perf_counter()
+ with self._lock:
+ elapsed = dict(self._elapsed_seconds)
+ active_rows = list(self._active.values())
+ for stage_id, started, _frame_index in active_rows:
+ elapsed[stage_id] += max(0.0, now - started)
+ total = sum(elapsed.values())
+ active_stages = list(
+ dict.fromkeys(stage_id for stage_id, _started, _frame in active_rows)
+ )
+ current_stage = active_rows[-1][0] if active_rows else None
+ return {
+ "current_stage": current_stage,
+ "active_stages": active_stages,
+ "active_frame_index": self._last_frame_index,
+ "stages": {
+ stage_id: {
+ "elapsed_seconds": round(elapsed[stage_id], 6),
+ "activations": self._activations[stage_id],
+ "share_percent": (
+ round(elapsed[stage_id] / total * 100, 6)
+ if total > 0
+ else None
+ ),
+ }
+ for stage_id in self._stage_ids
+ },
+ }
def _send_client_binary_frame(stream: Any, payload: bytes) -> None:
@@ -571,6 +653,7 @@
sensor_decode_ms: dict[str, list[float]],
result_queue: queue.Queue[bytes],
result_complete: threading.Event,
+ stage_telemetry: _StageExecutionTelemetry,
) -> None:
import select
@@ -632,7 +715,8 @@
continue
if opcode != 0x2:
raise ShadowRuntimeError(f"unexpected websocket opcode: {opcode}")
- header, payload = _decode_event(frame)
+ with stage_telemetry.measure("source-ingress"):
+ header, payload = _decode_event(frame)
sequence = int(header["ingress_sequence"])
if state.last_ingress_sequence is not None:
if sequence <= state.last_ingress_sequence:
@@ -883,7 +967,11 @@
)
-def run(args: argparse.Namespace, loaded: _LoadedModels | None = None) -> int:
+def run(
+ args: argparse.Namespace,
+ loaded: _LoadedModels | None = None,
+ runtime_state: dict[str, Any] | None = None,
+) -> int:
import av
import torch
import transformers
@@ -894,6 +982,15 @@
token = sys.stdin.readline().strip() if args.token_stdin else args.token
if not token or len(token) < 40:
raise RuntimeError("LAB E15 shadow token is missing")
+ stage_telemetry = (
+ runtime_state.get("_stage_telemetry")
+ if runtime_state is not None
+ else None
+ )
+ if not isinstance(stage_telemetry, _StageExecutionTelemetry):
+ stage_telemetry = _StageExecutionTelemetry()
+ if runtime_state is not None:
+ runtime_state["_stage_telemetry"] = stage_telemetry
common = _common(args) if loaded is None else loaded.common
live = common["live"]
e14 = common["e14"]
@@ -982,6 +1079,10 @@
height=600,
maximum_buffer_bytes=int(live["transport"]["maximum_media_buffer_bytes"]),
metadata_capacity=int(live["transport"]["camera_metadata_capacity"]),
+ measure_decode=lambda frame_index: stage_telemetry.measure(
+ "camera-decode",
+ frame_index,
+ ),
)
transport = _TransportState(Counter(), Counter())
result_queue: queue.Queue[bytes] = queue.Queue(maxsize=2)
@@ -1086,6 +1187,11 @@
self.count += 1
completed_semantics = SemanticResultStream()
+
+ def monitored_semantic_inference(image: Any) -> Any:
+ with stage_telemetry.measure("semantic-model"):
+ return infer_semantic(image)
+
semantic_thread = threading.Thread(
target=semantic_worker,
kwargs={
@@ -1094,7 +1200,7 @@
"valid_mask": valid_mask,
"target_lut": target_lut,
"target_names": target_names,
- "infer": infer_semantic,
+ "infer": monitored_semantic_inference,
"latency": semantic_latency,
"completed": completed_semantics,
"failures": semantic_errors,
@@ -1125,6 +1231,7 @@
"sensor_decode_ms": sensor_decode_ms,
"result_queue": result_queue,
"result_complete": result_complete,
+ "stage_telemetry": stage_telemetry,
},
name="lab-e15-shadow-receiver",
daemon=True,
@@ -1157,10 +1264,21 @@
)
try:
detector_started = time.perf_counter()
- tensor = _preprocess(envelope.image, valid_mask, detector)
- output_tensor, _request_ms = _infer(args.triton_url, detector["model"], tensor)
- detections, _rejected = _detections(output_tensor, detector, valid_mask)
- tracks = tracker.update(detections, envelope.frame_index)
+ with stage_telemetry.measure("preprocessing", envelope.frame_index):
+ tensor = _preprocess(envelope.image, valid_mask, detector)
+ with stage_telemetry.measure("detector", envelope.frame_index):
+ output_tensor, _request_ms = _infer(
+ args.triton_url,
+ detector["model"],
+ tensor,
+ )
+ detections, _rejected = _detections(
+ output_tensor,
+ detector,
+ valid_mask,
+ )
+ with stage_telemetry.measure("tracking", envelope.frame_index):
+ tracks = tracker.update(detections, envelope.frame_index)
latency["detector_ms"].append(
(time.perf_counter() - detector_started) * 1000
)
@@ -1194,34 +1312,35 @@
).reshape((-1, 3))
position = binding.pose.position_xyz
quaternion = binding.pose.orientation_xyzw
- projection_started = time.perf_counter()
- pixels, depths, source_indices, points_lidar = project_points(
- points_map,
- position,
- quaternion,
- projection,
- )
- latency["projection_ms"].append(
- (time.perf_counter() - projection_started) * 1000
- )
- association_started = time.perf_counter()
- fusions = fuse_tracks(
- tracks=[_track_document(track) for track in tracks],
- semantic_map=current_semantic.mask,
- pixels=pixels,
- depths=depths,
- source_indices=source_indices,
- points_map=points_map,
- points_lidar=points_lidar,
- association=e14["association"],
- distance_history=history,
- completion_tracker=completion_tracker,
- sensor_position_map=position,
- session_seconds=frame_seconds,
- )
- latency["association_ms"].append(
- (time.perf_counter() - association_started) * 1000
- )
+ with stage_telemetry.measure("sensor-fusion", envelope.frame_index):
+ projection_started = time.perf_counter()
+ pixels, depths, source_indices, points_lidar = project_points(
+ points_map,
+ position,
+ quaternion,
+ projection,
+ )
+ latency["projection_ms"].append(
+ (time.perf_counter() - projection_started) * 1000
+ )
+ association_started = time.perf_counter()
+ fusions = fuse_tracks(
+ tracks=[_track_document(track) for track in tracks],
+ semantic_map=current_semantic.mask,
+ pixels=pixels,
+ depths=depths,
+ source_indices=source_indices,
+ points_map=points_map,
+ points_lidar=points_lidar,
+ association=e14["association"],
+ distance_history=history,
+ completion_tracker=completion_tracker,
+ sensor_position_map=position,
+ session_seconds=frame_seconds,
+ )
+ latency["association_ms"].append(
+ (time.perf_counter() - association_started) * 1000
+ )
fusion_state = "fused"
fused_frames += 1
fusion_state_counts[fusion_state] += 1
@@ -1270,20 +1389,21 @@
if temporal_stabilizer is None:
fusion_objects = raw_fusion_objects
else:
- temporal_started = time.perf_counter()
- fusion_objects = temporal_stabilizer.update(
- frame_index=envelope.frame_index,
- session_seconds=frame_seconds,
- objects=raw_fusion_objects,
- )
- world = stabilize_world_state(
- world,
- fusion_objects,
- temporal_world_memory,
- )
- latency["temporal_2d_3d_ms"].append(
- (time.perf_counter() - temporal_started) * 1000
- )
+ with stage_telemetry.measure("temporal-state", envelope.frame_index):
+ temporal_started = time.perf_counter()
+ fusion_objects = temporal_stabilizer.update(
+ frame_index=envelope.frame_index,
+ session_seconds=frame_seconds,
+ objects=raw_fusion_objects,
+ )
+ world = stabilize_world_state(
+ world,
+ fusion_objects,
+ temporal_world_memory,
+ )
+ latency["temporal_2d_3d_ms"].append(
+ (time.perf_counter() - temporal_started) * 1000
+ )
stabilized_cuboids += sum(
str(item.get("cuboid_status", "")).startswith("accepted-")
for item in fusion_objects
@@ -1351,28 +1471,29 @@
quality=80,
optimize=False,
)
- live_result = encode_live_perception_result(
- frame_index=envelope.frame_index,
- source_frame_index=int(envelope.timeline["source_frame_index"]),
- session_seconds=frame_seconds,
- captured_at_epoch_ns=int(envelope.timeline["captured_at_epoch_ns"]),
- image_jpeg=encoded_image.getvalue(),
- segmentation_mask=(
- current_semantic.mask
- if current_semantic is not None and semantic_status == "fresh"
- else None
- ),
- objects=fusion_objects,
- delivery=world["delivery"],
- )
- try:
- result_queue.put_nowait(live_result)
- except queue.Full:
- with suppress(queue.Empty):
- result_queue.get_nowait()
- result_queue.task_done()
- transport.results_dropped += 1
- result_queue.put_nowait(live_result)
+ with stage_telemetry.measure("result-publication", envelope.frame_index):
+ live_result = encode_live_perception_result(
+ frame_index=envelope.frame_index,
+ source_frame_index=int(envelope.timeline["source_frame_index"]),
+ session_seconds=frame_seconds,
+ captured_at_epoch_ns=int(envelope.timeline["captured_at_epoch_ns"]),
+ image_jpeg=encoded_image.getvalue(),
+ segmentation_mask=(
+ current_semantic.mask
+ if current_semantic is not None and semantic_status == "fresh"
+ else None
+ ),
+ objects=fusion_objects,
+ delivery=world["delivery"],
+ )
+ try:
+ result_queue.put_nowait(live_result)
+ except queue.Full:
+ with suppress(queue.Empty):
+ result_queue.get_nowait()
+ result_queue.task_done()
+ transport.results_dropped += 1
+ result_queue.put_nowait(live_result)
except Exception:
detector_failures += 1
raise
@@ -1645,6 +1766,7 @@
},
"gpu_telemetry": gpu.summary(),
"runtime_telemetry": runtime_summary,
+ "stage_telemetry": stage_telemetry.snapshot(),
"process_cpu_seconds": time.process_time() - process_cpu_started,
"process_peak_rss_mib": resource.getrusage(resource.RUSAGE_SELF).ru_maxrss / 1024,
"cuda_peak_memory_allocated_mib": torch.cuda.max_memory_allocated() / 2**20,
@@ -1816,7 +1938,13 @@
loaded = _load_models(args, common)
model_load_seconds = time.perf_counter() - load_started
run_lock = threading.Lock()
- state = {"busy": False, "completed_runs": 0, "failed_runs": 0}
+ state = {
+ "busy": False,
+ "completed_runs": 0,
+ "failed_runs": 0,
+ "active_request_id": None,
+ "_stage_telemetry": _StageExecutionTelemetry(),
+ }
class Handler(BaseHTTPRequestHandler):
server_version = "MissionCorePersistentPerception/1"
@@ -1844,6 +1972,7 @@
if self.path != "/health":
self._send(404, {"ok": False, "error": "not-found"})
return
+ stage_snapshot = state["_stage_telemetry"].snapshot()
self._send(
200,
{
@@ -1853,6 +1982,11 @@
"model_load_seconds": model_load_seconds,
"completed_runs": state["completed_runs"],
"failed_runs": state["failed_runs"],
+ "active_request_id": state["active_request_id"],
+ "active_frame_index": stage_snapshot["active_frame_index"],
+ "current_stage": stage_snapshot["current_stage"],
+ "active_stages": stage_snapshot["active_stages"],
+ "stage_metrics": stage_snapshot["stages"],
"authority": common["live"]["authority"],
"gpu": torch.cuda.get_device_name(),
},
@@ -1882,7 +2016,9 @@
request_id = str(document.get("request_id", "invalid"))
run_args = _persistent_run_arguments(args, document)
document["token"] = None
- exit_code = run(run_args, loaded)
+ state["active_request_id"] = request_id
+ state["_stage_telemetry"] = _StageExecutionTelemetry()
+ exit_code = run(run_args, loaded, state)
state["completed_runs"] += 1
self._send(
200,
@@ -1917,6 +2053,7 @@
)
finally:
state["busy"] = False
+ state["active_request_id"] = None
run_lock.release()
server = ThreadingHTTPServer((args.listen_host, args.listen_port), Handler)