98% of idle-with-holes windows wait on the expanded critical set; region compile runs 0.26 ms but its gate stays pending 18 ms p50. Broad early admission: near +15.4 pt but p99 13.4 ms (over the VR 11 ms frame); near-only: +9.9 pt but far holes +1.5 pt. Trace instrumentation kept as a patch. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016dhxM43dnWvUu2B5Ph1iG1
199 lines
10 KiB
Python
199 lines
10 KiB
Python
#!/usr/bin/env python3
|
|
"""Summarize L122 scheduler blockers and Core region compile timing."""
|
|
from __future__ import annotations
|
|
|
|
import json
|
|
import math
|
|
import statistics
|
|
from pathlib import Path
|
|
|
|
ROOT = Path(__file__).resolve().parents[4]
|
|
TRACE_DIR = ROOT / "Saved/Linux/l122/diagnostic/unreal"
|
|
OUT = ROOT / "Saved/Linux/l122/diagnostic/analysis.json"
|
|
|
|
|
|
def read_events(path: Path) -> list[dict]:
|
|
rows = []
|
|
for line in path.read_text(encoding="utf-8", errors="replace").splitlines():
|
|
if line.startswith("{"):
|
|
try:
|
|
rows.append(json.loads(line))
|
|
except json.JSONDecodeError:
|
|
continue
|
|
return rows
|
|
|
|
|
|
def percentile(values: list[float], fraction: float) -> float | None:
|
|
if not values:
|
|
return None
|
|
ordered = sorted(values)
|
|
index = max(0, min(len(ordered) - 1, math.ceil(len(ordered) * fraction) - 1))
|
|
return ordered[index]
|
|
|
|
|
|
def distribution(values: list[float]) -> dict:
|
|
if not values:
|
|
return {"n": 0, "p50": None, "p95": None, "max": None}
|
|
return {
|
|
"n": len(values), "p50": statistics.median(values),
|
|
"p95": percentile(values, 0.95), "max": max(values),
|
|
}
|
|
|
|
|
|
def summarize_run(path: Path) -> tuple[dict, list[dict], list[dict]]:
|
|
events = read_events(path)
|
|
stop = next(float(event["t_s"]) for event in events
|
|
if event.get("type") == "streaming_test_move_stopped")
|
|
move_start = min(float(event["t_s"]) for event in events
|
|
if event.get("type") == "streaming_sample"
|
|
and float(event.get("speed_cm_s", 0.0)) >= 50.0)
|
|
scheduler = [event for event in events if event.get("type") == "scheduler_admission"
|
|
and move_start <= float(event.get("t_s", 0.0)) < stop
|
|
and event.get("moving", 0)]
|
|
idle = [event for event in scheduler
|
|
if event.get("running_workers", 0) == 0
|
|
and sum(event.get("desired_missing_by_lod", [0] * 9)[:3])
|
|
+ sum(event.get("pending_by_lod", [0] * 9)[:3]) > 0]
|
|
samples = [event for event in events if event.get("type") == "streaming_sample"
|
|
and float(event.get("speed_cm_s", 0.0)) >= 50.0]
|
|
near = []
|
|
far_holes = []
|
|
for event in samples:
|
|
desired = event.get("desired_by_lod", [0] * 9)
|
|
resident = event.get("resident_by_lod", [0] * 9)
|
|
covered = event.get("covered_by_lod", resident)
|
|
near.append(100.0 * sum(resident[:3]) / max(1, sum(desired[:3])))
|
|
far_holes.append(100.0 * (sum(desired[3:]) - sum(covered[3:]))
|
|
/ max(1, sum(desired[3:])))
|
|
ticks = [float(event.get("tick_ms", 0.0)) for event in events
|
|
if event.get("type") == "game_thread_work_frame"
|
|
and move_start <= float(event.get("t_s", 0.0)) < stop]
|
|
|
|
def near_array(event: dict, name: str) -> list[int]:
|
|
return event.get(name, [0] * 9)[:3]
|
|
|
|
def near_count(event: dict, name: str) -> int:
|
|
return sum(near_array(event, name))
|
|
|
|
reason_counts = {
|
|
"core_region_pending": sum(event.get("core_region_compile_pending", 0) > 0
|
|
for event in idle),
|
|
"core_region_exact_near_decline": sum(
|
|
sum(near_array(event, "region_compile_declines_by_lod")) > 0 for event in idle),
|
|
"far_parent_near_decline": sum(
|
|
sum(near_array(event, "far_parent_declines_by_lod")) > 0 for event in idle),
|
|
"near_cap_decline": sum(any(value in (1, 2)
|
|
for value in event.get("declined_rule_by_lod", [0] * 9)[:3])
|
|
for event in idle),
|
|
"critical_set_not_ready": sum(event.get("critical_tiles_ready", 1) == 0
|
|
for event in idle),
|
|
"walkable_ring_not_ready": sum(event.get("walkable_ready", 1) == 0 for event in idle),
|
|
"pawn_collision_gate_held": sum(event.get("pawn_collision_gate_engaged", 0) > 0
|
|
for event in idle),
|
|
"desired_center_stale": sum(event.get("desired_center_current", 1) == 0 for event in idle),
|
|
"only_pending_near_work": sum(near_count(event, "desired_missing_by_lod") == 0
|
|
and near_count(event, "pending_by_lod") > 0 for event in idle),
|
|
"no_near_admission_this_frame": sum(
|
|
near_count(event, "submitted_by_lod") == 0 for event in idle),
|
|
}
|
|
|
|
compiles = [event for event in events if event.get("type") == "core_region_compile_complete"]
|
|
requests = {event.get("request_serial"): event for event in events
|
|
if event.get("type") == "core_region_compile_request"}
|
|
starts = [event for event in events if event.get("type") == "core_region_compile_start"]
|
|
request_start = [
|
|
(float(event["t_s"]) - float(requests[event["request_serial"]]["t_s"])) * 1000.0
|
|
for event in starts if event.get("request_serial") in requests
|
|
]
|
|
near_missing = [near_count(event, "desired_missing_by_lod") for event in idle]
|
|
near_pending = [near_count(event, "pending_by_lod") for event in idle]
|
|
occupancy = [float(event.get("admission_occupancy", 0)) for event in idle]
|
|
row = {
|
|
"trace": str(path.relative_to(ROOT)),
|
|
"moving_scheduler_samples": len(scheduler),
|
|
"idle_missing_near_windows": len(idle),
|
|
"idle_window_share_pct": 100.0 * len(idle) / max(1, len(scheduler)),
|
|
"near_ready_moving_mean_pct": statistics.mean(near) if near else None,
|
|
"far_holes_moving_mean_pct": statistics.mean(far_holes) if far_holes else None,
|
|
"tick_p99_ms": percentile(ticks, 0.99), "tick_max_ms": max(ticks, default=None),
|
|
"idle_near_unadmitted_mean": statistics.mean(near_missing) if near_missing else None,
|
|
"idle_near_pending_mean": statistics.mean(near_pending) if near_pending else None,
|
|
"idle_admission_occupancy_p95": percentile(occupancy, 0.95),
|
|
"idle_admission_occupancy_max": max(occupancy, default=None),
|
|
"idle_critical_missing_p50": statistics.median(
|
|
[float(event.get("critical_missing", 0)) for event in idle]) if idle else None,
|
|
"idle_reasons": reason_counts,
|
|
"region_compile_request_start_ms": distribution(request_start),
|
|
"region_compile_task_queue_ms": distribution(
|
|
[float(event.get("compile_queue_ms", 0)) for event in compiles]),
|
|
"region_compile_task_runtime_ms": distribution(
|
|
[float(event.get("compile_task_ms", 0)) for event in compiles]),
|
|
"region_compile_core_wall_ms": distribution(
|
|
[float(event.get("compile_core_wall_ms", 0)) for event in compiles]),
|
|
"region_compile_pending_gate_ms": distribution(
|
|
[float(event.get("pending_gate_elapsed_ms", 0)) for event in compiles]),
|
|
"region_compiled_tile_batches": sum(event.get("compiled_tiles", 0) > 0
|
|
for event in compiles),
|
|
"region_compile_worker_thread_count": len({event.get("compile_worker_thread_id")
|
|
for event in compiles}),
|
|
"region_compile_submitted_while_generation_idle": sum(
|
|
event.get("active_generation_workers", -1) == 0 for event in starts),
|
|
"region_compile_requests": len(requests),
|
|
"region_compile_starts": len(starts),
|
|
"region_compile_completions": len(compiles),
|
|
}
|
|
return row, idle, compiles
|
|
|
|
|
|
def main() -> int:
|
|
traces = sorted(TRACE_DIR.glob("fast-r*.trace.jsonl"))
|
|
if len(traces) != 5:
|
|
raise SystemExit(f"expected five diagnostic traces, found {len(traces)} in {TRACE_DIR}")
|
|
runs = [summarize_run(path) for path in traces]
|
|
rows = [run[0] for run in runs]
|
|
idles = [event for run in runs for event in run[1]]
|
|
compiles = [event for run in runs for event in run[2]]
|
|
total_scheduler = sum(row["moving_scheduler_samples"] for row in rows)
|
|
reason_names = rows[0]["idle_reasons"].keys()
|
|
summary = {
|
|
"runs": rows,
|
|
"pooled_idle_windows": len(idles),
|
|
"pooled_scheduler_samples": total_scheduler,
|
|
"pooled_idle_window_share_pct": 100.0 * len(idles) / max(1, total_scheduler),
|
|
"pooled_idle_reasons": {
|
|
reason: sum(row["idle_reasons"][reason] for row in rows)
|
|
for reason in reason_names
|
|
},
|
|
"pooled_near_ready_moving_mean_pct": statistics.mean(
|
|
row["near_ready_moving_mean_pct"] for row in rows),
|
|
"pooled_tick_p99_ms": distribution(
|
|
[float(row["tick_p99_ms"]) for row in rows if row["tick_p99_ms"] is not None]),
|
|
"pooled_tick_max_ms": max(float(row["tick_max_ms"]) for row in rows
|
|
if row["tick_max_ms"] is not None),
|
|
"pooled_region_compile_task_queue_ms": distribution(
|
|
[float(event.get("compile_queue_ms", 0)) for event in compiles]),
|
|
"pooled_region_compile_task_runtime_ms": distribution(
|
|
[float(event.get("compile_task_ms", 0)) for event in compiles]),
|
|
"pooled_region_compile_core_wall_ms": distribution(
|
|
[float(event.get("compile_core_wall_ms", 0)) for event in compiles]),
|
|
"pooled_region_compile_pending_gate_ms": distribution(
|
|
[float(event.get("pending_gate_elapsed_ms", 0)) for event in compiles]),
|
|
"pooled_region_compiled_tile_batches": sum(
|
|
event.get("compiled_tiles", 0) > 0 for event in compiles),
|
|
"pooled_region_compile_worker_thread_count": len({
|
|
event.get("compile_worker_thread_id") for event in compiles}),
|
|
"pooled_region_compile_submitted_while_generation_idle": sum(
|
|
event.get("active_generation_workers", -1) == 0
|
|
for run in runs for event in read_events(ROOT / run[0]["trace"])
|
|
if event.get("type") == "core_region_compile_start"),
|
|
"pooled_region_compile_requests": sum(row["region_compile_requests"] for row in rows),
|
|
}
|
|
OUT.parent.mkdir(parents=True, exist_ok=True)
|
|
OUT.write_text(json.dumps(summary, indent=2) + "\n", encoding="utf-8")
|
|
print(json.dumps(summary, indent=2))
|
|
return 0
|
|
|
|
|
|
if __name__ == "__main__":
|
|
raise SystemExit(main())
|