fix(perception): isolate recorded decode from realtime admission
This commit is contained in:
@@ -47,14 +47,14 @@ from k1link.perception.m48s_reference_graph_runtime import (
|
||||
from k1link.perception.motion import ClassIndependentMotionEstimator
|
||||
from k1link.perception.object_understanding import AdvisoryResponse
|
||||
from k1link.perception.providers import SourcePacket
|
||||
from k1link.perception.recorded_source import DecodedFrameTiming
|
||||
from k1link.perception.recorded_source import DecodedFrameTiming, SourcePacingTiming
|
||||
from k1link.perception.reference_graph_runtime import ReferenceGraphRuntimePaths
|
||||
from k1link.perception.rolling_map import RollingLocalObstacleMapProvider
|
||||
from k1link.perception.temporal import BoundedSpatialTemporalProvider
|
||||
|
||||
SCHEMA_VERSION: Final = "missioncore.m48s-reference-graph-shadow-load/v4"
|
||||
SCHEMA_VERSION: Final = "missioncore.m48s-reference-graph-shadow-load/v5"
|
||||
FRAME_EVIDENCE_SCHEMA: Final = "missioncore.m48s-reference-graph-frame-evidence/v1"
|
||||
PIPELINE_TIMING_SCHEMA: Final = "missioncore.m48s-frame-pipeline-timing/v0"
|
||||
PIPELINE_TIMING_SCHEMA: Final = "missioncore.m48s-frame-pipeline-timing/v1"
|
||||
GC_POLICY_SCHEMA: Final = "missioncore.cyclic-gc-hot-loop-policy/v0"
|
||||
AUTHORITY: Final = {
|
||||
"ground_truth": False,
|
||||
@@ -228,14 +228,23 @@ class FrameTimingStore:
|
||||
|
||||
def __init__(self) -> None:
|
||||
self._lock = threading.Lock()
|
||||
self._decode: dict[int, int] = {}
|
||||
self._decode: dict[int, DecodedFrameTiming] = {}
|
||||
self._pacing: dict[int, SourcePacingTiming] = {}
|
||||
self._all_decode: list[DecodedFrameTiming] = []
|
||||
self._all_pacing: list[SourcePacingTiming] = []
|
||||
self._detector: dict[int, DetectorFrameTiming] = {}
|
||||
self._providers: dict[int, dict[str, int]] = defaultdict(dict)
|
||||
self._delivered: list[dict[str, object]] = []
|
||||
|
||||
def observe_decode(self, timing: DecodedFrameTiming) -> None:
|
||||
with self._lock:
|
||||
self._decode[timing.sequence] = timing.duration_ns
|
||||
self._decode[timing.sequence] = timing
|
||||
self._all_decode.append(timing)
|
||||
|
||||
def observe_pacing(self, timing: SourcePacingTiming) -> None:
|
||||
with self._lock:
|
||||
self._pacing[timing.sequence] = timing
|
||||
self._all_pacing.append(timing)
|
||||
|
||||
def observe_detector(self, timing: DetectorFrameTiming) -> None:
|
||||
with self._lock:
|
||||
@@ -257,7 +266,8 @@ class FrameTimingStore:
|
||||
) -> dict[str, object]:
|
||||
with self._lock:
|
||||
try:
|
||||
decode_ns = self._decode.pop(sequence)
|
||||
decode = self._decode.pop(sequence)
|
||||
pacing = self._pacing.pop(sequence)
|
||||
detector = self._detector.pop(sequence)
|
||||
providers = self._providers.pop(sequence)
|
||||
except KeyError as exc:
|
||||
@@ -272,13 +282,19 @@ class FrameTimingStore:
|
||||
document = {
|
||||
"schema_version": PIPELINE_TIMING_SCHEMA,
|
||||
"sequence": sequence,
|
||||
"decode_duration_ns": decode_ns,
|
||||
"decode_duration_ns": decode.duration_ns,
|
||||
"decode_phase": decode.phase.value,
|
||||
"source_pacing": {
|
||||
"scheduled_monotonic_ns": pacing.scheduled_monotonic_ns,
|
||||
"emitted_monotonic_ns": pacing.emitted_monotonic_ns,
|
||||
"lateness_ns": pacing.lateness_ns,
|
||||
},
|
||||
"detector": detector.to_dict(),
|
||||
"providers": dict(sorted(providers.items())),
|
||||
"graph_admission_to_delivery_ns": admission_to_delivery_ns,
|
||||
"graph_attributed_provider_ns": attributed_graph_ns,
|
||||
"graph_unattributed_ns": unattributed_ns,
|
||||
"decode_to_delivery_processing_ns": decode_ns + admission_to_delivery_ns,
|
||||
"decode_to_delivery_processing_ns": decode.duration_ns + admission_to_delivery_ns,
|
||||
}
|
||||
with self._lock:
|
||||
self._delivered.append(document)
|
||||
@@ -288,6 +304,14 @@ class FrameTimingStore:
|
||||
with self._lock:
|
||||
return tuple(self._delivered)
|
||||
|
||||
def all_decode(self) -> tuple[DecodedFrameTiming, ...]:
|
||||
with self._lock:
|
||||
return tuple(self._all_decode)
|
||||
|
||||
def all_pacing(self) -> tuple[SourcePacingTiming, ...]:
|
||||
with self._lock:
|
||||
return tuple(self._all_pacing)
|
||||
|
||||
|
||||
class TimedProviderProxy:
|
||||
"""Record one provider's actual call duration without another inference pass."""
|
||||
@@ -420,6 +444,8 @@ def main() -> int:
|
||||
map_output_ages_ms: list[float] = []
|
||||
all_deliveries: list[DeliveredFrame] = []
|
||||
all_pipeline_timings: list[dict[str, object]] = []
|
||||
all_decode_timings: list[DecodedFrameTiming] = []
|
||||
all_pacing_timings: list[SourcePacingTiming] = []
|
||||
with (
|
||||
progress.open("x", encoding="utf-8") as progress_stream,
|
||||
frame_ledger.open("x", encoding="utf-8") as frame_ledger_stream,
|
||||
@@ -447,6 +473,7 @@ def main() -> int:
|
||||
timing_store,
|
||||
),
|
||||
decode_timing_observer=timing_store.observe_decode,
|
||||
source_pacing_observer=timing_store.observe_pacing,
|
||||
detector_timing_observer=timing_store.observe_detector,
|
||||
maximum_frames=arguments.maximum_frames,
|
||||
source_rate_hz=arguments.source_rate_hz,
|
||||
@@ -469,8 +496,10 @@ def main() -> int:
|
||||
),
|
||||
)
|
||||
detector_warmup = runtime.warm_up_detector()
|
||||
source_prefetch = runtime.prepare_source()
|
||||
gc_policy = CyclicGcHotLoopPolicy()
|
||||
with gc_policy:
|
||||
runtime.mark_source_admission_started()
|
||||
loop_started_ns = time.monotonic_ns()
|
||||
result = runtime.graph.run()
|
||||
loop_completed_ns = time.monotonic_ns()
|
||||
@@ -523,6 +552,7 @@ def main() -> int:
|
||||
setup_seconds=setup_seconds,
|
||||
gc_policy=gc_policy.to_dict(),
|
||||
detector_warmup=detector_warmup,
|
||||
source_prefetch=asdict(source_prefetch),
|
||||
)
|
||||
loop_documents.append(loop_document)
|
||||
completion_ages_ms.extend(value / 1_000_000.0 for value in loop_completion_ages_ns)
|
||||
@@ -531,6 +561,8 @@ def main() -> int:
|
||||
)
|
||||
all_deliveries.extend(result.deliveries)
|
||||
all_pipeline_timings.extend(loop_pipeline_timings)
|
||||
all_decode_timings.extend(timing_store.all_decode())
|
||||
all_pacing_timings.extend(timing_store.all_pacing())
|
||||
frame_ledger_stream.flush()
|
||||
progress_row = {
|
||||
"loop": loop_index + 1,
|
||||
@@ -608,6 +640,12 @@ def main() -> int:
|
||||
and cast(dict[str, object], loop["detector_warmup"])["inference_passes"] == 1
|
||||
for loop in loop_documents
|
||||
),
|
||||
"source_prefetch_completed_before_source_admission": all(
|
||||
cast(dict[str, object], loop["source_prefetch"])["buffered_frames"]
|
||||
== cast(dict[str, object], loop["source_prefetch"])["ready_frames"]
|
||||
for loop in loop_documents
|
||||
),
|
||||
"source_pacing_attribution_complete": len(all_pacing_timings) == admitted,
|
||||
"authority_remains_false": all(value is False for value in AUTHORITY.values()),
|
||||
}
|
||||
operating_target_checks = {
|
||||
@@ -672,6 +710,8 @@ def main() -> int:
|
||||
"identity_continuity": identity,
|
||||
"semantic_advisory": semantic,
|
||||
"pipeline_timing": _pipeline_timing_metrics(all_pipeline_timings),
|
||||
"source_decode": _source_decode_metrics(all_decode_timings),
|
||||
"source_pacing": _source_pacing_metrics(all_pacing_timings),
|
||||
"python_gc": _gc_telemetry_summary(gc_telemetry.events),
|
||||
"gpu": _telemetry_summary(gpu.samples),
|
||||
"process_peak_rss_before_mib": round(rss_before_kib / 1024.0, 6),
|
||||
@@ -762,6 +802,7 @@ def _loop_document(
|
||||
setup_seconds: float,
|
||||
gc_policy: dict[str, object],
|
||||
detector_warmup: DetectorWarmupSnapshot,
|
||||
source_prefetch: dict[str, object],
|
||||
) -> dict[str, object]:
|
||||
outcomes = Counter(item.outcome.value for item in result.terminal_outcomes)
|
||||
outcome_stages = Counter(
|
||||
@@ -774,6 +815,7 @@ def _loop_document(
|
||||
"setup_seconds": round(setup_seconds, 6),
|
||||
"cyclic_gc_hot_loop": gc_policy,
|
||||
"detector_warmup": asdict(detector_warmup),
|
||||
"source_prefetch": source_prefetch,
|
||||
"admitted_count": result.admitted_count,
|
||||
"delivered_count": len(result.deliveries),
|
||||
"effective_world_state_fps": round(len(result.deliveries) / wall_seconds, 6),
|
||||
@@ -899,6 +941,8 @@ def _pipeline_timing_metrics(
|
||||
"decode_to_delivery_processing_ns",
|
||||
)
|
||||
top_level_values: dict[str, list[float]] = {key: [] for key in top_level_fields}
|
||||
decode_by_phase: dict[str, list[float]] = defaultdict(list)
|
||||
delivered_pacing_lateness_ms: list[float] = []
|
||||
for document in documents:
|
||||
detector = cast(Mapping[str, int], document["detector"])
|
||||
providers = cast(Mapping[str, int], document["providers"])
|
||||
@@ -908,6 +952,11 @@ def _pipeline_timing_metrics(
|
||||
provider_values[key].append(providers[key] / 1_000_000.0)
|
||||
for key in top_level_fields:
|
||||
top_level_values[key].append(cast(int, document[key]) / 1_000_000.0)
|
||||
decode_by_phase[cast(str, document["decode_phase"])].append(
|
||||
cast(int, document["decode_duration_ns"]) / 1_000_000.0
|
||||
)
|
||||
source_pacing = cast(Mapping[str, int], document["source_pacing"])
|
||||
delivered_pacing_lateness_ms.append(source_pacing["lateness_ns"] / 1_000_000.0)
|
||||
maximum = max(
|
||||
documents,
|
||||
key=lambda document: cast(int, document["graph_admission_to_delivery_ns"]),
|
||||
@@ -916,6 +965,12 @@ def _pipeline_timing_metrics(
|
||||
return {
|
||||
"sample_count": len(documents),
|
||||
"decode_duration_ms": _distribution(top_level_values["decode_duration_ns"]),
|
||||
"decode_duration_by_phase_ms": {
|
||||
phase: _distribution(values) for phase, values in sorted(decode_by_phase.items())
|
||||
},
|
||||
"delivered_source_pacing_lateness_ms": _distribution(
|
||||
delivered_pacing_lateness_ms
|
||||
),
|
||||
"detector_ms": {
|
||||
key.removesuffix("_duration_ns"): _distribution(values)
|
||||
for key, values in detector_values.items()
|
||||
@@ -936,6 +991,50 @@ def _pipeline_timing_metrics(
|
||||
}
|
||||
|
||||
|
||||
def _source_decode_metrics(samples: list[DecodedFrameTiming]) -> dict[str, object]:
|
||||
by_phase: dict[str, list[float]] = defaultdict(list)
|
||||
for sample in samples:
|
||||
by_phase[sample.phase.value].append(sample.duration_ns / 1_000_000.0)
|
||||
return {
|
||||
"sample_count": len(samples),
|
||||
"phase_counts": {
|
||||
phase: len(values) for phase, values in sorted(by_phase.items())
|
||||
},
|
||||
"duration_by_phase_ms": {
|
||||
phase: _distribution(values) for phase, values in sorted(by_phase.items())
|
||||
},
|
||||
}
|
||||
|
||||
|
||||
def _source_pacing_metrics(samples: list[SourcePacingTiming]) -> dict[str, object]:
|
||||
ordered = sorted(samples, key=lambda sample: sample.sequence)
|
||||
lateness_ms = [sample.lateness_ns / 1_000_000.0 for sample in ordered]
|
||||
scheduled_intervals_ms = [
|
||||
(current.scheduled_monotonic_ns - previous.scheduled_monotonic_ns) / 1_000_000.0
|
||||
for previous, current in zip(ordered, ordered[1:], strict=False)
|
||||
]
|
||||
emitted_intervals_ms = [
|
||||
(current.emitted_monotonic_ns - previous.emitted_monotonic_ns) / 1_000_000.0
|
||||
for previous, current in zip(ordered, ordered[1:], strict=False)
|
||||
]
|
||||
catch_up_emissions = sum(
|
||||
emitted < scheduled * 0.5
|
||||
for scheduled, emitted in zip(
|
||||
scheduled_intervals_ms,
|
||||
emitted_intervals_ms,
|
||||
strict=True,
|
||||
)
|
||||
if scheduled > 0
|
||||
)
|
||||
return {
|
||||
"sample_count": len(ordered),
|
||||
"lateness_ms": _distribution(lateness_ms),
|
||||
"scheduled_interval_ms": _distribution(scheduled_intervals_ms),
|
||||
"emitted_interval_ms": _distribution(emitted_intervals_ms),
|
||||
"catch_up_emission_count": catch_up_emissions,
|
||||
}
|
||||
|
||||
|
||||
def _telemetry_summary(samples: list[dict[str, float]]) -> dict[str, Any]:
|
||||
result: dict[str, Any] = {"sample_count": len(samples)}
|
||||
for key in (
|
||||
|
||||
Reference in New Issue
Block a user