From 990481709c7aa8643cce4fd3c662b314fcb4a306 Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 20:47:01 +0900 Subject: [PATCH 1/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/check_p28_01_report.py | 277 +++++++++++++ .../p28-01/collector/collect_p28_01.py | 322 ++++++++++++++++ .../p28-01/collector/measure_p28_01.gd | 364 ++++++++++++++++++ .../p28-01/collector/test_collect_p28_01.py | 211 ++++++++++ 4 files changed, 1174 insertions(+) create mode 100644 docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py create mode 100644 docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py create mode 100644 docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd create mode 100644 docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py new file mode 100644 index 0000000..abb9a53 --- /dev/null +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py @@ -0,0 +1,277 @@ +#!/usr/bin/env python3 +"""Structural/consistency gate, not proof of execution or truthful observations.""" +import argparse +import hashlib +import json +import math +from pathlib import Path +import re + +PREFIX = "P28_01_PERF_REPORT=" +PHASES = {"R0": ("R", 1, 0, 10), "P1": ("R", 1, 30, 120), + "P2": ("R", 3, 30, 120), "O0": ("O", 1, 0, 10), + "P3": ("O", 1, 30, 120), "P4": ("O", 3, 30, 120)} +FORBIDDEN = ("_toggle_pause", "clear(", "enable_production_", "set_paused(false)", + "advance_", "spawn_guest", "SimulationRuntime.new", "initialize(") + + +def need(ok, reason): + if not ok: + raise ValueError(reason) + + +def keys(obj, names): + need(isinstance(obj, dict), "expected object") + need(set(names) <= obj.keys(), "missing fields: " + str(set(names) - obj.keys())) + + +def number(value): + return type(value) in (int, float) and math.isfinite(value) + + +def sha_string(value): + return isinstance(value, str) and re.fullmatch("[0-9a-f]{64}", value) is not None + + +def nullable(obj, field): + need(field in obj, "missing " + field) + if obj[field] is None: + need(bool(obj.get(field + "_reason")), "null without reason: " + field) + + +def stats(values, reason="no_samples"): + if not values: + return dict(count=0, mean=None, p95=None, max=None, reason=reason) + ordered = sorted(values) + return dict(count=len(values), mean=sum(values) / len(values), + p95=ordered[math.ceil(len(values) * .95) - 1], max=max(values), reason=None) + + +def equal(actual, expected, label): + if isinstance(expected, dict): + need(isinstance(actual, dict) and actual.keys() == expected.keys(), label + " keys") + for key in expected: + equal(actual[key], expected[key], label + "." + key) + elif number(expected): + need(number(actual) and math.isclose(actual, expected, rel_tol=1e-9, abs_tol=1e-7), label) + else: + need(actual == expected, label) + + +def metadata(meta): + keys(meta, ("machine", "build")) + machine = meta["machine"] + keys(machine, ("hw.model", "cores", "memory_bytes")) + need(isinstance(machine["hw.model"], str) and machine["hw.model"], "model") + need(type(machine["cores"]) is int and machine["cores"] > 0, "cores") + need(type(machine["memory_bytes"]) is int and machine["memory_bytes"] > 0, "memory") + build = meta["build"] + keys(build, ("engine_string", "engine_hash", "engine_sha256", "project_commit", "source_map_sha256")) + need(build["engine_string"] == "4.7.2.stable.official.ed1daf0bf", "engine string") + need(build["engine_hash"] == "ed1daf0bf", "engine hash") + need(re.fullmatch("[0-9a-f]{40}", build["project_commit"]) is not None, "commit") + need(sha_string(build["engine_sha256"]) and sha_string(build["source_map_sha256"]), "build SHA") + + +def interval(report, name): + rows = [f for f in report["frames"] if f["segment"] == name] + value = report[name] + keys(value, ("frames", "actual_minutes", "start_minute", "end_minute", "start_wall", "end_wall", + "zero_minute_frames_excluded", "count_ranges", "budget", "stall_budget")) + need(value["frames"] == len(rows), "frame count") + need(value["actual_minutes"] == sum(f["minutes_advanced"] for f in rows), "false interval duration") + for field, expected in (("start_minute", rows[0]["game_start"] if rows else None), + ("end_minute", rows[-1]["game_end"] if rows else None), + ("start_wall", rows[0]["wall_start"] if rows else None), + ("end_wall", rows[-1]["wall"] if rows else None)): + equal(value[field], expected, field) + need(value.get("empty_reason") == ("no_frames" if not rows else None), "empty interval reason") + wall = [f["frame_wall_us"] for f in rows] + minutes = [f["frame_wall_us"] / f["minutes_advanced"] for f in rows if f["minutes_advanced"]] + equal(value["frame_wall_us"], stats(wall), "frame stats") + equal(value["sim_us_per_minute"], stats(minutes), "minute stats") + equal(value["stall_over_50000_us"], stats([x for x in wall if x > 50000]), "stalls") + equal(value["time_process_seconds"], stats([f["time_process_seconds"] for f in rows]), "process") + need(value["zero_minute_frames_excluded"] == sum(f["minutes_advanced"] == 0 for f in rows), "excluded frames") + for kind in ("cpu", "gpu"): + samples = [f["render_" + kind + "_raw_ms"] for f in rows] + expected = (stats([], "zero_from_api_on_gl_compatibility_unsupported_or_unmeasured") + if any(x <= 0 for x in samples) else stats(samples)) + equal(value["render_" + kind + "_ms"], expected, "render " + kind) + ranges = {} + for kind in ("registered", "active"): + ranges[kind] = {key: {"min": min(f[kind][key] for f in rows), "max": max(f[kind][key] for f in rows)} + for key in rows[0][kind]} if rows else {} + equal(value["count_ranges"], ranges, "count ranges") + metric = stats(minutes)["mean" if report["speed"] == 1 else "p95"] + limit = 4000 if report["speed"] == 1 else 12000 + equal(value["budget"], {"limit_us": limit, "value": metric, + "passed": metric <= limit if metric is not None else None, + "reason": "no_samples" if metric is None else None}, "budget") + maximum = max(wall) if wall else None + equal(value["stall_budget"], {"limit_us": 50000, "value": maximum, + "passed": maximum <= 50000 if maximum is not None else None, + "reason": "no_samples" if maximum is None else None}, "stall budget") + + +def check_report(report): + keys(report, ("schema", "pid", "phase", "input", "speed", "metadata", "input_sha256", + "frames", "stop_reason", "warmup", "measurement", "actual_minutes", + "elapsed_wall_seconds", "kernel_at_phase_end", "operations_at_end", "end_wall", + "window_note", "toggle_pause_calls", "performance_clear_calls", "overloads", "checkpoints")) + need(report["schema"] == "p28-01-v1", "schema") + need(type(report["pid"]) is int and report["pid"] > 0, "pid") + need(report["phase"] in PHASES, "unknown phase") + source, speed, warmup, target = PHASES[report["phase"]] + need((report["input"], report["speed"], report["warmup_target"], report["measurement_target"]) == + (source, speed, warmup, target), "phase parameters") + need(report["speed_path"] == "main._set_speed->SimulationKernel._process", "speed route") + need(report["toggle_pause_calls"] == 0 and report["performance_clear_calls"] == 0, "forbidden mutation") + need("512" in report["window_note"] and "warm-up" in report["window_note"], "rolling report note") + metadata(report["metadata"]) + nullable(report, "input_sha256") + if source == "R": + need(report["input_sha256"] == "eb4f770071eb07cd7e136fe54c3f78768cc8de7a4264e62a9af1f06a8f90f9bd", + "input SHA") + else: + need(report["input_sha256"] is None, "fresh input cannot claim fixture") + frames = report["frames"] + need(isinstance(frames, list), "frames") + need(report["stop_reason"] in ("complete", "input_shortfall", "simulation_overloaded", + "operations_runtime_failure", "operations_terminal", "operations_pause", "clock_paused", + "camera_changed", "timeout"), "stop reason") + # Shortfall reports preserve partial startup observations rather than invent them. + if report["stop_reason"] == "input_shortfall": + need(not frames and report["actual_minutes"] == 0, "shortfall after measurement") + return + keys(report, ("startup", "preparation_sha256", "seed", "rng_streams", "camera", + "start_minute", "start_wall", "speed_after", "paused_after_speed", "renderer")) + need(sha_string(report["preparation_sha256"]), "preparation SHA") + need(report["speed_after"] == speed and report["paused_after_speed"] is False, "start speed") + startup = report["startup"] + keys(startup, ("pause_fresh_opening", "save_policy", "save_policy_after", "start_report", + "operations_enabled_after", "opening_minute")) + need(startup["pause_fresh_opening"]["return"] is None and + startup["pause_fresh_opening"]["reason"] == "void_function", "pause return invented") + need(type(startup["pause_fresh_opening"]["paused_before"]) is bool and + type(startup["pause_fresh_opening"]["paused_after"]) is bool, "pause observations") + equal(startup["save_policy"], {"return": None, "reason": "return_discarded_by_main（main.gd:222）"}, + "save policy return") + need(isinstance(startup["save_policy_after"], dict), "save policy actual") + start = startup["start_report"] + need(isinstance(start, dict), "start_report must retain dictionary") + if not start: + need(bool(startup.get("start_report_reason")), "empty start report reason") + if source == "O": + need(start.get("ok") is True and startup["operations_enabled_after"] is True + and startup["opening_minute"] == 360, "O startup") + else: + need(start.get("code") == "INVALID_START_TIME" and startup["operations_enabled_after"] is False, "R startup") + previous = report["start_minute"] + previous_wall = report["start_wall"] + previous_drawing = None + for index, frame in enumerate(frames): + keys(frame, ("frame", "game_start", "game_end", "minutes_advanced", "frame_wall_us", "wall", "wall_start", + "speed", "paused", "segment", "registered", "active", "drawn", "seed", "rng_streams", + "metadata", "input_sha256", "preparation_sha256", "render_cpu_raw_ms", + "render_gpu_raw_ms", "time_process_seconds")) + need(frame["frame"] == index and frame["game_start"] == previous, "frame continuity") + need(type(frame["minutes_advanced"]) is int and 0 <= frame["minutes_advanced"] <= 8, "kernel frame cap") + need(frame["game_end"] - previous == frame["minutes_advanced"], "minute delta") + need(frame["speed"] == speed, "Clock speed disagreement") + need(number(frame["frame_wall_us"]) and frame["frame_wall_us"] > 0, "frame timing") + need(number(frame["wall"]) and frame["wall"] >= previous_wall, "wall chronology") + equal(frame["wall_start"], previous_wall, "frame wall continuity") + need(frame["segment"] == ("warmup" if previous - report["start_minute"] < warmup else "measurement"), + "segment boundary") + for field in ("seed", "rng_streams"): + nullable(frame, field) + need(frame["seed"] is None or type(frame["seed"]) is int, "seed is not scalar") + need(frame["rng_streams"] is None or isinstance(frame["rng_streams"], dict), "RNG state") + need(frame["seed"] != frame["rng_streams"] or frame["seed"] is None, "seed/RNG conflation") + metadata(frame["metadata"]) + need(frame["metadata"] == report["metadata"] and frame["seed"] == report["seed"], "sample metadata") + need(frame["input_sha256"] == report["input_sha256"] and + frame["preparation_sha256"] == report["preparation_sha256"], "sample SHA") + need(set(frame["registered"]) == {"guests", "staff", "facilities", "walkable_cells"}, "registered schema") + need(set(frame["active"]) == {"guests", "staff", "facilities"}, "active copied from registered") + for kind in ("registered", "active"): + need(all(type(x) is int and x >= 0 for x in frame[kind].values()), "counts") + need(all(frame["active"][k] <= frame["registered"][k] for k in frame["active"]), "active > registered") + drawn = frame["drawn"] + keys(drawn, ("actors_in_layer", "actors_in_viewport", "facilities", "cells", + "observation_serial", "carried_from_serial", "camera")) + need(all(type(drawn[k]) is int and drawn[k] >= 0 for k in + ("actors_in_layer", "actors_in_viewport", "facilities", "cells", "observation_serial")), "draw counts") + need(drawn["actors_in_viewport"] <= drawn["actors_in_layer"], "draw viewport") + if previous_drawing and drawn["observation_serial"] == previous_drawing["observation_serial"]: + need(drawn["carried_from_serial"] == drawn["observation_serial"], "carried observation called fresh") + equal({k: v for k, v in drawn.items() if k != "carried_from_serial"}, + {k: v for k, v in previous_drawing.items() if k != "carried_from_serial"}, "carried changed") + else: + need(drawn["carried_from_serial"] is None, "fresh drawing marked carried") + need(drawn["camera"] == report["camera"], "camera changed") + for field in ("render_cpu_raw_ms", "render_gpu_raw_ms", "time_process_seconds"): + need(number(frame[field]) and frame[field] >= 0, "raw time") + if frame["paused"]: + need(index == len(frames) - 1 and report["stop_reason"] != "complete", "continued after pause") + previous, previous_wall, previous_drawing = frame["game_end"], frame["wall"], drawn + need(report["actual_minutes"] == previous - report["start_minute"], "total minutes") + need(number(report["elapsed_wall_seconds"]) and report["elapsed_wall_seconds"] >= 0, "elapsed") + if report["overloads"]: + need(report["stop_reason"] == "simulation_overloaded", "ignored overload") + need(all(x["frame"] == len(frames) - 1 for x in report["overloads"]), "continued after overload") + if report["stop_reason"] == "complete": + need(report["actual_minutes"] >= warmup + target and report["measurement"]["actual_minutes"] >= target, + "incomplete interval called complete") + need("kernel_at_warmup_end" in report, "warmup kernel report") + for name in ("warmup", "measurement"): + interval(report, name) + if report.get("label") == "200客": + need(frames and all(f["registered"]["guests"] == 200 for f in frames), "200 guest claim") + + +def check_receipt(receipt, directory): + need(receipt["source_before"] == receipt["source_after"], "source map changed") + need(receipt["default_player_before"] == receipt["default_player_after"], "player changed") + need(not receipt["cleanup_errors"] and all(r["engine_ended"] is True for r in receipt["cleanup"]), "cleanup") + need(receipt["error"] is None and receipt["passed"] is True, "failed collection") + rows = receipt["phases"] + need([r["phase"] for r in rows] == ["import", *PHASES], "phase order") + for row in rows: + need(row["timeout_seconds"] == 1800 and row["passed"] is True, "phase timeout/pass") + for name, pin in row["raw"].items(): + data = (directory / row["phase"] / name).read_bytes() + need(hashlib.sha256(data).hexdigest() == pin["sha256"] and len(data) == pin["bytes"], "raw SHA") + if row["phase"] == "import": + continue + stdout = (directory / row["phase"] / "stdout.log").read_text() + printed = [json.loads(x[len(PREFIX):]) for x in stdout.splitlines() if x.startswith(PREFIX)] + need(printed == [row["report"]], "raw/report mismatch") + need(row["capture"]["actual_captured_pids"] == [row["report"]["pid"]], "PID mismatch") + check_report(row["report"]) + need(row["report"]["stop_reason"] == "complete", "collection includes stopped phase") + if row["phase"] in ("R0", "O0"): + estimate = row["extrapolation"] + equal(estimate["seconds_per_phase"], row["report"]["elapsed_wall_seconds"] * 150 / + row["report"]["actual_minutes"], "extrapolation") + + +def check_probe(text): + # The SceneTree bootstrap name is required; all other initialization is forbidden. + body = text.replace("func _initialize()", "func BOOTSTRAP()") + for token in FORBIDDEN: + need(token not in body, "forbidden probe token: " + token) + need('main.call("_set_speed", speed)' in body, "missing UI speed path") + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument("receipt", type=Path) + args = parser.parse_args() + check_receipt(json.loads(args.receipt.read_text()), args.receipt.parent) + print("P28-01 structural consistency only; execution/static-review gates remain separate.") + + +if __name__ == "__main__": + main() diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py new file mode 100644 index 0000000..2da0e9f --- /dev/null +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py @@ -0,0 +1,322 @@ +#!/usr/bin/env python3 +"""Owned windowed P28-01 performance collection. Only Root executes --run.""" +import argparse +import hashlib +import importlib.util +import json +import os +from pathlib import Path +import re +import subprocess +import sys +import uuid +from datetime import datetime, timezone + +sys.dont_write_bytecode = True +from check_p28_01_report import check_report, check_receipt +HERE = Path(__file__).resolve().parent +ROOT = HERE.parents[5] +FIXTURE_SHA = "eb4f770071eb07cd7e136fe54c3f78768cc8de7a4264e62a9af1f06a8f90f9bd" +ENGINE_SHA = "c7cccbf8fb143e34e02fd6521e09be2c2b974f0d5db080b19071c9c570718ccf" +VERSION = "4.7.2.stable.official.ed1daf0bf" +LIMIT = 1800 +PHASES = (("R0", "R", 1, 0, 10), ("P1", "R", 1, 30, 120), + ("P2", "R", 3, 30, 120), ("O0", "O", 1, 0, 10), + ("P3", "O", 1, 30, 120), ("P4", "O", 3, 30, 120)) +EXTERNAL_IMPORTS = ("tools/run_all_tests.py", "tools/regression/owned_outer.py") + + +def require(value, message): + if not value: + raise ValueError(message) + + +def sha(path): + return hashlib.sha256(Path(path).read_bytes()).hexdigest() + + +def digest(value): + return hashlib.sha256(json.dumps(value, sort_keys=True, separators=(",", ":")).encode()).hexdigest() + + +def write(path, value): + with Path(path).open("x", encoding="utf-8") as stream: + json.dump(value, stream, ensure_ascii=False, indent=2, allow_nan=False) + stream.write("\n") + + +def now(): + return datetime.now(timezone.utc).isoformat() + + +def load_tool(relative): + require(relative in EXTERNAL_IMPORTS, "external import outside allowlist") + spec = importlib.util.spec_from_file_location("p28_" + Path(relative).stem, ROOT / relative) + module = importlib.util.module_from_spec(spec) + spec.loader.exec_module(module) + return module + + +def profile_files(directory): + directory = Path(directory) + result = {} + if not directory.exists(): + return result + require(not directory.is_symlink(), "profile/stage symlink") + for path in sorted(directory.rglob("*")): + require(not path.is_symlink(), "nested profile/stage symlink") + if path.is_file(): + result[path.relative_to(directory).as_posix()] = {"sha256": sha(path), "bytes": path.stat().st_size} + return result + + +def live_engines(): + rows = subprocess.check_output(["ps", "-axo", "pid=,comm="], text=True) + return [line for line in rows.splitlines() + if re.search(r"(?:^|/)(?:Godot|godot)(?:[ ._-]|$)", line.split(None, 1)[-1])] + + +def no_live_engine(): + require(not live_engines(), "another engine exists") + + +def diagnostics(text): + return [line for line in text.splitlines() if re.search( + r"ERROR:|SCRIPT ERROR:|Parse Error:|^\s*FAIL(?:ED)?[: ]|" + r"Unicode parsing error|ObjectDB instances leaked|instances were leaked|" + r"resources? still in use at exit|Leaked instance:", line)] + + +def source_map(standard, root): + return {name: {"bytes": row["bytes"], "sha256": row["sha256"]} + for name, row in standard.source_refs(root).items()} + + +def argv_for(engine, stage, wrapper, importing=False): + if importing: + return [str(engine), "--headless", "--editor", "--import", "--path", str(stage), "--quit"] + return [str(engine), "--path", str(stage), "--script", str(wrapper)] + + +def run_engine(outer, command, folder, environment): + no_live_engine() + native = folder / "engine-native.log" + command = command + ["--log-file", str(native), "--verbose"] + env = {key: value for key, value in os.environ.items() if not key.startswith("THE_TREE_")} + env.update(environment) + result, capture = outer.run_phase(command, folder, LIMIT, env, now_fn=now, + dump_fn=write, sha_fn=sha, live_engines_fn=live_engines) + raw = {} + text = "" + for name in ("stdout.log", "stderr.log", "engine-native.log"): + path = folder / name + raw[name] = {"sha256": sha(path), "bytes": path.stat().st_size} if path.is_file() else None + if path.is_file(): + text += path.read_text(errors="replace") + bad = diagnostics(text) + clean = bool(result) and all(( + result.get("exit_code") == 0, result.get("helper_exit_code") == 0, + result.get("timed_out") is False, result.get("error_lines") == [], + result.get("owned_popen_ended") is True, result.get("old_helper_engine_ended") is True, + result.get("start_receipt_written") is True, result.get("end_receipt_written") is True, + result.get("lifecycle_error") is None, result.get("external_process_or_group_signals") == 0, + capture.get("passed") is True, capture.get("all_captured_ended") is True, + len(capture.get("actual_captured_pids", [])) == 1, all(raw.values()), not bad)) + row = {"passed": clean, "process": result, "capture": capture, "raw": raw, + "diagnostics": bad, "timeout_seconds": LIMIT, "argv": command} + write(folder / "process.json", row) + return row + + +def inputs(readonly): + manifest_path = readonly / "ROOT_INPUT_MANIFEST.json" + require(sha(manifest_path) == "9dac0a51d52087e691c5723b4f78f171f7998c78b582b2b6c4c904798e77644d", + "Root input manifest changed") + manifest = json.loads(manifest_path.read_text()) + pins = {} + for row in manifest["files"]: + path = Path(row["destination"]) + require(path.resolve().is_relative_to(readonly.resolve()), "input escapes read-only directory") + require(sha(path) == row["sha256"] and path.stat().st_size == row["bytes"], "read-only input changed") + pins[str(path.relative_to(readonly))] = row["sha256"] + return {"manifest_sha256": sha(manifest_path), "files": pins} + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument("--readonly", type=Path, required=True) + parser.add_argument("--fixture", type=Path, required=True) + parser.add_argument("--engine", type=Path, default=Path("/Applications/Godot.app/Contents/MacOS/Godot")) + parser.add_argument("--output", type=Path, required=True) + mode = parser.add_mutually_exclusive_group(required=True) + mode.add_argument("--check", action="store_true") + mode.add_argument("--run", action="store_true") + args = parser.parse_args() + standard = load_tool(EXTERNAL_IMPORTS[0]) + pins = inputs(args.readonly.resolve()) + fixture_actual = sha(args.fixture) if args.fixture.is_file() else None + if fixture_actual != FIXTURE_SHA: + shortfall = {"stop_reason": "input_shortfall", "fixture_expected_sha256": FIXTURE_SHA, + "fixture_actual_sha256": fixture_actual, "engines_started": 0, "stages_created": 0} + if args.run: + require(not args.output.exists(), "fresh output required") + args.output.mkdir(parents=True) + write(args.output / "input-shortfall.json", shortfall) + print(json.dumps(shortfall)) + return 1 + require(sha(args.engine) == ENGINE_SHA, "engine SHA") + before = source_map(standard, ROOT) + commit = subprocess.check_output(["git", "-C", str(ROOT), "rev-parse", "HEAD"], text=True).strip() + tracked = subprocess.check_output(["git", "-C", str(ROOT), "ls-tree", "-r", commit], text=True) + selected = {} + for line in tracked.splitlines(): + info, name = line.split("\t", 1) + if name.split("/", 1)[0] in ("autoload", "scripts", "scenes", "data", "tests", "assets", "tools") \ + or name in ("project.godot", "export_presets.cfg", "Makefile", "AGENTS.md"): + if Path(name).name != ".DS_Store" and "__pycache__" not in Path(name).parts: + selected[name] = info.split()[2] + require(set(selected) == set(before), "source map differs from committed file set") + for name, blob in selected.items(): + actual = subprocess.check_output(["git", "-C", str(ROOT), "hash-object", str(ROOT / name)], text=True).strip() + require(actual == blob, "dirty source: " + name) + stage = args.output.resolve() / "stage" + wrapper = args.output.resolve() / "guarded.gd" + planned = [argv_for(args.engine, stage, wrapper, True)] + [ + argv_for(args.engine, stage, wrapper) for _ in PHASES] + admission = {"commit": commit, "source_map": before, "source_map_sha256": digest(before), + "readonly": pins, "engine_sha256": ENGINE_SHA, "engine_version": VERSION, + "fixture_sha256": FIXTURE_SHA, "planned_argv": planned, "phases": PHASES, + "reused_r02": {"execution_sha256": pins["files"]["run-r02/execution.json"], + "report_sha256": pins["files"]["run-r02/after/evidence/report.json"], + "scope": "x1 headless Operations OFF; reused without remeasurement", + "tick_ms": {"mean": 826.6, "p95": 1702.7, "max": 2918.1}, + "path_cold_p95_ms": 0.61, "snapshot_mean_ms": 77.6, + "manual_save_ms": 297, "autosave_ms": 327, + "load_mean_ms": 3193, "load_max_ms": 3368, + "budget_comparisons_ms": { + "x1_tick_mean": {"value": 826.6, "limit": 4, "passed": False}, + "path_cold_p95": {"value": 0.61, "limit": 2, "passed": True}, + "manual_save": {"value": 297, "limit": 5000, "passed": True}, + "autosave": {"value": 327, "limit": 5000, "passed": True}, + "load_max": {"value": 3368, "limit": 8000, "passed": True}}}} + if args.check: + print(json.dumps(dict(admission, stages_created=0, engines_started=0), ensure_ascii=False, indent=2)) + return 0 + require(sys.platform == "darwin", "reviewed CoW execution requires macOS") + require(not args.output.exists(), "fresh output required") + no_live_engine() + player = standard.default_player(ROOT) + outer = load_tool(EXTERNAL_IMPORTS[1]) + out = args.output.resolve() + out.mkdir(parents=True) + write(out / "admission.json", admission) + rows = [] + error = None + profiles = [] + try: + stage.mkdir() + for name in before: + target = stage / name + target.parent.mkdir(parents=True, exist_ok=True) + standard.copy_source(ROOT / name, target) + require(source_map(standard, stage) == before, "CoW source differs") + probe = out / "measure_p28_01.gd" + probe.write_bytes((HERE / probe.name).read_bytes()) + guard = out / "profile_guard.gd" + guard.write_bytes((args.readonly / "run-r02/profile_guard.gd").read_bytes()) + wrapper.write_text("extends " + json.dumps(str(probe)) + "\nconst Guard = preload(" + + json.dumps(str(guard)) + ")\nfunc _initialize() -> void:\n" + "\tif not Guard.activate():\n\t\tquit(97)\n\t\treturn\n\tsuper._initialize()\n") + script_pins = {str(p): sha(p) for p in (probe, guard, wrapper)} + hardware = subprocess.check_output( + ["sysctl", "-n", "hw.model", "hw.logicalcpu", "hw.memsize"], text=True).splitlines() + meta = {"machine": {"hw.model": hardware[0], "cores": int(hardware[1]), "memory_bytes": int(hardware[2])}, + "build": {"engine_string": VERSION, "engine_hash": "ed1daf0bf", "engine_sha256": ENGINE_SHA, + "project_commit": commit, "source_map_sha256": digest(before)}} + public = (stage / "project.godot").read_bytes() + expected = before + for index, phase in enumerate((("import", "", 0, 0, 0),) + PHASES): + label, source, speed, warmup, minutes = phase + require(source_map(standard, ROOT) == before and standard.default_player(ROOT) == player, + "source/player changed before phase") + require(source_map(standard, stage) == expected, "stage changed before phase") + require(all(sha(Path(p)) == pin for p, pin in script_pins.items()), "execution scripts changed") + require(sha(args.fixture) == FIXTURE_SHA, "input_shortfall: changed input") + name = "TheTree-PCK-tests-" + uuid.uuid4().hex + "-p28-startup" + startup = standard.profile_path(name) + require(not startup.exists(), "startup profile not fresh") + runtime_name = "TheTree-PCK-tests-" + uuid.uuid4().hex + "-p28-runtime" + runtime = standard.profile_path(runtime_name) + require(not runtime.exists(), "runtime profile not fresh") + profiles.extend([startup, runtime]) + guard_path = out / (label + "-guard.json") + env = {"THE_TREE_PACK_PROFILE_NAME": runtime_name, "THE_TREE_PACK_PROFILE_EXPECTED": str(runtime), + "THE_TREE_PACK_PROFILE_REPORT": str(guard_path), "THE_TREE_P28_PHASE": label, + "THE_TREE_P28_INPUT": source, "THE_TREE_P28_SPEED": str(speed), + "THE_TREE_P28_WARMUP": str(warmup), "THE_TREE_P28_MINUTES": str(minutes), + "THE_TREE_P28_FIXTURE": str(args.fixture.resolve()), "THE_TREE_P28_FIXTURE_SHA": FIXTURE_SHA, + "THE_TREE_P28_META": json.dumps(meta)} + (stage / "project.godot").write_bytes(standard.private_project(public, name)) + try: + row = run_engine(outer, planned[index], out / label, env) + finally: + (stage / "project.godot").write_bytes(public) + row["phase"] = label + rows.append(row) + require(row["passed"], "native phase failed; raw retained: " + label) + after = source_map(standard, stage) + if label == "import": + require(all(after.get(k) == v for k, v in before.items()), "import changed source") + added = set(after) - set(before) + require(all((n.endswith(".gd.uid") and n[:-4] in before) or + (n.endswith(".import") and n[:-7] in before) for n in added), + "unexpected import-generated files") + expected = after + else: + require(after == expected, "stage changed during measurement") + observation = json.loads(guard_path.read_text()) + require(observation["verified"] is True and observation["conditions"] == [True] * 5 + and observation["actual_user_data_dir"] == str(runtime) + and observation["fresh_before_parent_initialize"] is True + and observation["profile_writes_before_guard"] == 0 + and observation["project_settings_persisted"] is False, "profile guard failure") + raw = (out / label / "stdout.log").read_text() + printed = [line.split("=", 1)[1] for line in raw.splitlines() if line.startswith("P28_01_PERF_REPORT=")] + require(len(printed) == 1, "exactly one raw report required") + report = json.loads(printed[0]) + require(report["pid"] == row["capture"]["actual_captured_pids"][0], "PID binding") + row.update(report=report, report_sha256=digest(report), guard=observation, + guard_sha256=sha(guard_path)) + write(out / label / "report.json", report) + check_report(report) + require(report["stop_reason"] == "complete", "phase stopped: " + report["stop_reason"]) + if label in ("R0", "O0"): + duration = report["elapsed_wall_seconds"] + row["extrapolation"] = {"observed_minutes": report["actual_minutes"], + "observed_seconds": duration, "target_minutes": 150, + "seconds_per_phase": duration * 150 / report["actual_minutes"], + "method": "stage0 wall seconds per game minute; x1/x3 same conservative estimate"} + require(standard.default_player(ROOT) == player, "default player changed") + except BaseException as caught: + error = repr(caught) + finally: + cleanup, cleanup_errors = outer.finish_captured(outer.OWNED) + after = source_map(standard, ROOT) + player_after = standard.default_player(ROOT) + receipt = {"phases": rows, "error": error, "source_before": before, "source_after": after, + "default_player_before": player, "default_player_after": player_after, + "cleanup": cleanup, "cleanup_errors": cleanup_errors, + "profiles": {str(p): profile_files(p) for p in profiles}, + "passed": error is None and not cleanup_errors and after == before and player_after == player, + "original_credit": 0, "windows_verified": False, "operations_200_guests_verified": False} + if receipt["passed"]: + try: + check_receipt(receipt, out) + except (ValueError, KeyError, TypeError) as caught: + receipt.update(passed=False, error="checker: " + repr(caught)) + write(out / "execution.json", receipt) + return 0 if receipt["passed"] else 1 + + +if __name__ == "__main__": + raise SystemExit(main()) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd new file mode 100644 index 0000000..de5d661 --- /dev/null +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd @@ -0,0 +1,364 @@ +extends SceneTree +## External, passive observer of the default autoload world. +## Raw per-frame lines survive an owned timeout before the final report. + +class Observer: + extends Node + var owner_probe: Variant + func _process(_delta: float) -> void: + owner_probe.sample() + +var clock: Variant +var runtime: Variant +var main: Variant +var preview: Variant +var report := {} +var frames: Array = [] +var ready_to_sample := false +var start_us := 0 +var previous_us := 0 +var previous_minute := 0 +var start_minute := 0 +var warmup := 0 +var target := 0 +var speed := 0 +var previous_serial := -1 +var drawing := {} +var camera := {} +var overloads: Array = [] +var checkpoints: Array = [] +var warmup_ended := false +var measurement_start := 0 +var minute_ticks: Array = [] +var previous_tick_us := 0 +var previous_wall := 0.0 + +func _initialize() -> void: + call_deferred("begin") + +func hashed(value: Variant) -> String: + var hash_context := HashingContext.new() + hash_context.start(HashingContext.HASH_SHA256) + hash_context.update(var_to_bytes(value)) + return hash_context.finish().hex_encode() + +func vec(value: Vector2) -> Array: + return [value.x, value.y] + +func camera_state() -> Dictionary: + return {"layer": preview.layer_mode, "zoom": preview.zoom_level, + "pan": vec(preview.pan_offset), "viewport": vec(preview.size), + "window_size": vec(root.size), "screen_size": vec(DisplayServer.screen_get_size()), + "content_scale_size": vec(root.content_scale_size), + "content_scale_factor": root.content_scale_factor, + "vsync_mode": DisplayServer.window_get_vsync_mode()} + +func registered() -> Dictionary: + return {"guests": runtime.guest_service.get_guests().size(), + "staff": runtime.staff_service.get_staff_members().size(), + "facilities": runtime.facility_service.get_instances().size(), + "walkable_cells": runtime.world_service.get_walkable_cells().size()} + +func active_counts() -> Dictionary: + var guests := 0 + var staff := 0 + var facilities := 0 + for guest: Variant in runtime.guest_service.get_guests(): + if guest.state not in [GuestRuntime.State.SPAWNING, GuestRuntime.State.LEAVING, GuestRuntime.State.DESPAWNING]: + guests += 1 + for person: Variant in runtime.staff_service.get_staff_members(): + var shift: Variant = runtime.staff_service.get_shift(person.shift_id) + if shift != null and not shift.cancelled and shift.actual_started_at >= 0 \ + and shift.actual_ended_at < 0 and (shift.contains_minute(clock.absolute_minute) or person.is_overtime): + staff += 1 + for facility: Variant in runtime.facility_service.get_instances(): + if facility.operation_state == FacilityInstance.OperationState.OPERATING: + facilities += 1 + return {"guests": guests, "staff": staff, "facilities": facilities} + +func rng_state() -> Dictionary: + var result := {} + var streams: Dictionary = runtime.get("_rng_streams") + for key: Variant in streams: + result[String(key)] = streams[key].snapshot() + return result + +func draw_counts() -> Dictionary: + var observation: Dictionary = preview.get_life_observation_report() + var serial := int(observation.get("observation_serial", -1)) + if serial == previous_serial and not drawing.is_empty(): + var carried := drawing.duplicate(true) + carried["carried_from_serial"] = serial + return carried + previous_serial = serial + var area := Rect2(Vector2.ZERO, preview.size) + var actors: Array = observation.get("actor_drawings", []) + var visible := 0 + for actor: Dictionary in actors: + if area.has_point(actor["at"]): + visible += 1 + var facilities := 0 + for facility: Dictionary in preview.call("_completed_facilities_for_draw"): + if int(facility.get("layer", 0)) != int(preview.layer_mode): + continue + var cells: Array = preview.call("_cells_from_serialized", facility.get("occupied_cells", [])) + if not cells.is_empty() and preview.call("_cell_bounds_rect", cells).intersects(area): + facilities += 1 + var bounds: Dictionary = preview.call("_world_bounds") + var cells := 0 + if not bounds.is_empty(): + for y in range(int(bounds["min_y"]), int(bounds["max_y"]) + 1): + for x in range(int(bounds["min_x"]), int(bounds["max_x"]) + 1): + if preview.get_cell_rect(Vector3i(x, y, preview.layer_mode)).intersects(area): + cells += 1 + drawing = {"actors_in_layer": actors.size(), "actors_in_viewport": visible, + "facilities": facilities, "cells": cells, "observation_serial": serial, + "carried_from_serial": null, "camera": camera_state()} + return drawing.duplicate(true) + +func begin() -> void: + clock = root.get_node("GameClock") + runtime = root.get_node("SimulationRuntime") + clock.set_paused(true) + var input := OS.get_environment("THE_TREE_P28_INPUT") + speed = int(OS.get_environment("THE_TREE_P28_SPEED")) + warmup = int(OS.get_environment("THE_TREE_P28_WARMUP")) + target = int(OS.get_environment("THE_TREE_P28_MINUTES")) + report = {"schema": "p28-01-v1", "pid": OS.get_process_id(), + "phase": OS.get_environment("THE_TREE_P28_PHASE"), "input": input, + "metadata": JSON.parse_string(OS.get_environment("THE_TREE_P28_META")), + "input_sha256": null, "input_sha256_reason": "fresh_autoload_initialization", + "speed": speed, "speed_path": "main._set_speed->SimulationKernel._process", + "toggle_pause_calls": 0, "performance_clear_calls": 0, + "renderer": ProjectSettings.get_setting("rendering/renderer/rendering_method"), + "warmup_target": warmup, "measurement_target": target, + "window_note": "Product reports are raw rolling capacity-512 reports; warm-up may remain; no subtraction.", + "count_definitions": {"registered": "service collections; walkable cells", + "active": "guests exclude SPAWNING/LEAVING/DESPAWNING; staff current attended unended shift; facilities OPERATING", + "drawn": "world_preview submitted model serial and viewport geometry"}, + "overloads": overloads, "checkpoints": checkpoints, "frames": frames, "minute_ticks": minute_ticks} + if input == "R": + var path := OS.get_environment("THE_TREE_P28_FIXTURE") + report["input_sha256"] = FileAccess.get_sha256(path) + report["input_sha256_reason"] = null + if report["input_sha256"] != OS.get_environment("THE_TREE_P28_FIXTURE_SHA"): + finish("input_shortfall") + return + var file := FileAccess.open(path, FileAccess.READ) + if file == null: + finish("input_shortfall") + return + var snapshot: Variant = file.get_var(false) + file.close() + var restored: Variant = runtime.restore_snapshot(snapshot) + report["restore_result"] = restored + if not restored: + finish("input_shortfall") + return + if registered() != {"guests": 200, "staff": 50, "facilities": 150, "walkable_cells": 20000}: + report["initial_registered"] = registered() + finish("input_shortfall") + return + # Restore may carry a paused value. Pause before adding main, never resume here. + clock.set_paused(true) + var paused_before: bool = clock.paused + var opening_minute: int = clock.absolute_minute + main = load("res://scenes/main/main.tscn").instantiate() + root.add_child(main) + report["startup"] = {"pause_fresh_opening": {"return": null, "reason": "void_function", + "paused_before": paused_before, "paused_after": clock.paused}, + "save_policy": {"return": null, "reason": "return_discarded_by_main（main.gd:222）"}, + "save_policy_after": runtime.get_save_policy(), + "start_report": main.get("_operations_start_report").duplicate(true), + "operations_enabled_after": runtime.get_operations_report().enabled, + "opening_minute": opening_minute} + if report.startup.start_report.is_empty(): + report.startup["start_report_reason"] = "main_retained_empty_dictionary" + var start: Dictionary = report.startup.start_report + var expected: bool = bool(start.get("ok", false)) and report.startup.operations_enabled_after and opening_minute == 360 + if input == "R": + expected = not report.startup.operations_enabled_after and String(start.get("code", "")) == "INVALID_START_TIME" + if not expected: + finish("input_shortfall") + return + await process_frame + await process_frame + preview = main.get("world_preview") + camera = camera_state() + report["camera"] = camera + report["initial_registered"] = registered() + report["preparation_sha256"] = hashed(runtime.create_snapshot()) + report["seed"] = runtime.world_seed + report["rng_streams"] = rng_state() + RenderingServer.viewport_set_measure_render_time(root.get_viewport_rid(), true) + clock.simulation_overloaded.connect(on_overload) + clock.tick_completed.connect(on_tick) + runtime.checkpoint_presentation_requested.connect(on_checkpoint) + var observer := Observer.new() + observer.owner_probe = self + observer.process_priority = 100000 + root.add_child(observer) + main.call("_set_speed", speed) + report["speed_after"] = clock.speed + report["paused_after_speed"] = clock.paused + if clock.paused or clock.speed != speed: + finish("input_shortfall") + return + start_minute = clock.absolute_minute + measurement_start = start_minute if warmup == 0 else -1 + previous_minute = start_minute + start_us = Time.get_ticks_usec() + previous_us = start_us + previous_tick_us = start_us + report["start_minute"] = start_minute + report["start_wall"] = Time.get_unix_time_from_system() + previous_wall = report["start_wall"] + ready_to_sample = true + +func on_overload(backlog: int) -> void: + overloads.append({"backlog": backlog, "game_minute": clock.absolute_minute, "frame": frames.size()}) + +func on_checkpoint(_presentation: Dictionary) -> void: + checkpoints.append({"game_minute": clock.absolute_minute, "frame": frames.size(), + "wall": Time.get_unix_time_from_system(), "cause": "production_checkpoint_presentation_requested"}) + +func on_tick(minute: int) -> void: + if not ready_to_sample: + return + var tick_us := Time.get_ticks_usec() + var row := {"game_minute": minute, "wall": Time.get_unix_time_from_system(), + "wall_us_since_previous_tick": tick_us - previous_tick_us, + "frame": frames.size(), "note": "passive tick_completed; includes inter-frame waiting"} + minute_ticks.append(row) + previous_tick_us = tick_us + print("P28_01_MINUTE=" + JSON.stringify(row)) + +func sample() -> void: + if not ready_to_sample: + return + var current_us := Time.get_ticks_usec() + var minute: int = clock.absolute_minute + var elapsed := current_us - previous_us + var advanced := minute - previous_minute + var row := {"frame": frames.size(), "game_start": previous_minute, "game_end": minute, + "minutes_advanced": advanced, "frame_wall_us": elapsed, "wall_start": previous_wall, + "wall": Time.get_unix_time_from_system(), + "speed": clock.speed, "paused": clock.paused, + "segment": "warmup" if previous_minute - start_minute < warmup else "measurement", + "registered": registered(), "active": active_counts(), "drawn": draw_counts(), + "seed": runtime.world_seed, "rng_streams": rng_state(), + "metadata": report.metadata, "input_sha256": report.input_sha256, + "input_sha256_reason": report.input_sha256_reason, + "preparation_sha256": report.preparation_sha256, + "render_cpu_raw_ms": RenderingServer.viewport_get_measured_render_time_cpu(root.get_viewport_rid()), + "render_gpu_raw_ms": RenderingServer.viewport_get_measured_render_time_gpu(root.get_viewport_rid()), + "time_process_seconds": Performance.get_monitor(Performance.TIME_PROCESS)} + frames.append(row) + print("P28_01_FRAME=" + JSON.stringify(row)) + previous_us = current_us + previous_wall = row.wall + previous_minute = minute + if not warmup_ended and minute - start_minute >= warmup: + warmup_ended = true + report["kernel_at_warmup_end"] = clock.get_performance_reports() + if warmup > 0: + measurement_start = minute + var operations: Dictionary = runtime.get_operations_report() + if not overloads.is_empty(): + finish("simulation_overloaded") + elif bool(operations.get("runtime_failure_latched", false)): + finish("operations_runtime_failure") + elif runtime.operations_coordinator != null and runtime.operations_coordinator.is_terminal(): + finish("operations_terminal") + elif bool(operations.get("tick_blocked", false)): + finish("operations_pause") + elif clock.paused: + finish("clock_paused") + elif camera_state() != camera: + finish("camera_changed") + elif float(current_us - start_us) / 1000000.0 >= 1800.0: + finish("timeout") + elif measurement_start >= 0 and minute - measurement_start >= target: + finish("complete") + +func stats(values: Array, reason := "no_samples") -> Dictionary: + if values.is_empty(): + return {"count": 0, "mean": null, "p95": null, "max": null, "reason": reason} + var ordered := values.duplicate() + ordered.sort() + var total := 0.0 + for value: float in values: + total += value + return {"count": values.size(), "mean": total / values.size(), + "p95": ordered[int(ceil(values.size() * 0.95)) - 1], "max": ordered.back(), "reason": null} + +func summary(segment: String) -> Dictionary: + var wall: Array = [] + var per_minute: Array = [] + var cpu: Array = [] + var gpu: Array = [] + var process: Array = [] + var selected: Array = [] + var stalls: Array = [] + var excluded := 0 + var minutes := 0 + var cpu_missing := false + var gpu_missing := false + var ranges := {"registered": {}, "active": {}} + for frame: Dictionary in frames: + if frame.segment != segment: + continue + selected.append(frame) + wall.append(frame.frame_wall_us) + process.append(frame.time_process_seconds) + minutes += frame.minutes_advanced + if frame.frame_wall_us > 50000: + stalls.append(frame.frame_wall_us) + if frame.minutes_advanced > 0: + per_minute.append(float(frame.frame_wall_us) / frame.minutes_advanced) + else: + excluded += 1 + cpu_missing = cpu_missing or frame.render_cpu_raw_ms <= 0 + gpu_missing = gpu_missing or frame.render_gpu_raw_ms <= 0 + cpu.append(frame.render_cpu_raw_ms) + gpu.append(frame.render_gpu_raw_ms) + for kind: String in ["registered", "active"]: + for key: String in frame[kind]: + var value: int = frame[kind][key] + if not ranges[kind].has(key): + ranges[kind][key] = {"min": value, "max": value} + ranges[kind][key].min = mini(ranges[kind][key].min, value) + ranges[kind][key].max = maxi(ranges[kind][key].max, value) + var unavailable := "zero_from_api_on_gl_compatibility_unsupported_or_unmeasured" + var minute_stats := stats(per_minute) + var budget := 4000 if speed == 1 else 12000 + var metric: Variant = minute_stats.mean if speed == 1 else minute_stats.p95 + return {"frames": selected.size(), "actual_minutes": minutes, + "start_minute": selected.front().game_start if not selected.is_empty() else null, + "end_minute": selected.back().game_end if not selected.is_empty() else null, + "start_wall": selected.front().wall_start if not selected.is_empty() else null, + "end_wall": selected.back().wall if not selected.is_empty() else null, + "empty_reason": "no_frames" if selected.is_empty() else null, + "frame_wall_us": stats(wall), "sim_us_per_minute": minute_stats, + "zero_minute_frames_excluded": excluded, "stall_over_50000_us": stats(stalls), + "render_cpu_ms": stats([], unavailable) if cpu_missing else stats(cpu), + "render_gpu_ms": stats([], unavailable) if gpu_missing else stats(gpu), + "time_process_seconds": stats(process), "count_ranges": ranges, + "budget": {"limit_us": budget, "value": metric, "passed": metric <= budget if metric != null else null, + "reason": "no_samples" if metric == null else null}, + "stall_budget": {"limit_us": 50000, "value": wall.max() if not wall.is_empty() else null, + "passed": wall.max() <= 50000 if not wall.is_empty() else null, + "reason": "no_samples" if wall.is_empty() else null}} + +func finish(reason: String) -> void: + ready_to_sample = false + report["stop_reason"] = reason + report["actual_minutes"] = int(clock.absolute_minute) - start_minute if start_us > 0 else 0 + report["elapsed_wall_seconds"] = float(Time.get_ticks_usec() - start_us) / 1000000.0 if start_us > 0 else 0.0 + report["end_wall"] = Time.get_unix_time_from_system() + report["kernel_at_phase_end"] = clock.get_performance_reports() + report["operations_at_end"] = runtime.get_operations_report() + report["warmup"] = summary("warmup") + report["measurement"] = summary("measurement") + print("P28_01_PERF_REPORT=" + JSON.stringify(report)) + quit(0) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py new file mode 100644 index 0000000..ede1048 --- /dev/null +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -0,0 +1,211 @@ +#!/usr/bin/env python3 +"""Synthetic tests only. No native engine, fixture, profile, or Runner operations.""" +import ast +import copy +import hashlib +import json +from pathlib import Path +import sys +from types import SimpleNamespace +import unittest +from unittest.mock import patch + +sys.dont_write_bytecode = True +import check_p28_01_report as checker +import collect_p28_01 as collector + +HERE = Path(__file__).resolve().parent + + +def synthetic_report(): + meta = {"machine": {"hw.model": "synthetic", "cores": 10, "memory_bytes": 24000000000}, + "build": {"engine_string": collector.VERSION, "engine_hash": "ed1daf0bf", + "engine_sha256": collector.ENGINE_SHA, "project_commit": "8" * 40, + "source_map_sha256": "a" * 64}} + camera = {"layer": 0, "zoom": 1, "pan": [0, 0], "viewport": [600, 380], + "window_size": [1000, 700], "screen_size": [1920, 1080], "content_scale_size": [0, 0], + "content_scale_factor": 1, "vsync_mode": 1} + frames = [] + for i in range(10): + frames.append({"frame": i, "game_start": 360 + i, "game_end": 361 + i, + "minutes_advanced": 1, "frame_wall_us": 200000, "wall": 100 + (i + 1) * .2, + "wall_start": 100 + i * .2, + "speed": 1, "paused": False, "segment": "measurement", + "registered": {"guests": 3, "staff": 2, "facilities": 4, "walkable_cells": 50}, + "active": {"guests": 2, "staff": 1, "facilities": 3}, + "drawn": {"actors_in_layer": 4, "actors_in_viewport": 3, "facilities": 2, + "cells": 40, "observation_serial": i + 1, + "carried_from_serial": None, "camera": camera}, + "seed": 42, "rng_streams": {"weather": {"state": 93 + i}}, "metadata": meta, + "input_sha256": None, "input_sha256_reason": "fresh_autoload_initialization", + "preparation_sha256": "b" * 64, "render_cpu_raw_ms": 1, + "render_gpu_raw_ms": 0, "time_process_seconds": .001}) + report = {"schema": "p28-01-v1", "pid": 123, "phase": "O0", "input": "O", + "speed": 1, "speed_after": 1, "paused_after_speed": False, "metadata": meta, + "input_sha256": None, "input_sha256_reason": "fresh_autoload_initialization", + "preparation_sha256": "b" * 64, "seed": 42, "rng_streams": {"weather": {"state": 93}}, + "speed_path": "main._set_speed->SimulationKernel._process", + "toggle_pause_calls": 0, "performance_clear_calls": 0, "renderer": "gl_compatibility", + "warmup_target": 0, "measurement_target": 10, "start_minute": 360, "start_wall": 100, + "end_wall": 102, "actual_minutes": 10, "elapsed_wall_seconds": 2, + "window_note": "raw rolling capacity-512; warm-up may remain", + "overloads": [], "checkpoints": [], "frames": frames, "stop_reason": "complete", + "camera": camera, "kernel_at_warmup_end": [], "kernel_at_phase_end": [], + "operations_at_end": {"enabled": True}, "startup": { + "pause_fresh_opening": {"return": None, "reason": "void_function", + "paused_before": True, "paused_after": True}, + "save_policy": {"return": None, "reason": "return_discarded_by_main（main.gd:222）"}, + "save_policy_after": {"enabled": True, "autosave_path": "user://saves/autosave"}, + "start_report": {"ok": True}, "operations_enabled_after": True, "opening_minute": 360}} + # Explicit oracle: ten identical frames and an empty warm-up. + def constant(count, value, reason="no_samples"): + return {"count": count, "mean": value if count else None, "p95": value if count else None, + "max": value if count else None, "reason": None if count else reason} + report["measurement"] = { + "frames": 10, "actual_minutes": 10, "start_minute": 360, "end_minute": 370, + "start_wall": 100, "end_wall": 102, "zero_minute_frames_excluded": 0, "empty_reason": None, + "frame_wall_us": constant(10, 200000), "sim_us_per_minute": constant(10, 200000), + "stall_over_50000_us": constant(10, 200000), "render_cpu_ms": constant(10, 1), + "render_gpu_ms": constant(0, None, "zero_from_api_on_gl_compatibility_unsupported_or_unmeasured"), + "time_process_seconds": constant(10, .001), + "count_ranges": {kind: {k: {"min": v, "max": v} for k, v in frames[0][kind].items()} + for kind in ("registered", "active")}, + "budget": {"limit_us": 4000, "value": 200000, "passed": False, "reason": None}, + "stall_budget": {"limit_us": 50000, "value": 200000, "passed": False, "reason": None}} + report["warmup"] = { + "frames": 0, "actual_minutes": 0, "start_minute": None, "end_minute": None, + "start_wall": None, "end_wall": None, "zero_minute_frames_excluded": 0, "empty_reason": "no_frames", + **{k: constant(0, None) for k in ("frame_wall_us", "sim_us_per_minute", "stall_over_50000_us", + "render_cpu_ms", "render_gpu_ms", "time_process_seconds")}, + "count_ranges": {"registered": {}, "active": {}}, + "budget": {"limit_us": 4000, "value": None, "passed": None, "reason": "no_samples"}, + "stall_budget": {"limit_us": 50000, "value": None, "passed": None, "reason": "no_samples"}} + return report + + +class ReportTests(unittest.TestCase): + def reject(self, mutate): + report = synthetic_report() + mutate(report) + with self.assertRaises((ValueError, KeyError, TypeError)): + checker.check_report(report) + + def test_valid_synthetic(self): + checker.check_report(synthetic_report()) + + def test_rejections(self): + mutations = { + "direct advance x3": lambda r: r.update(speed_path="advance_minutes"), + "clock speed mismatch": lambda r: r["frames"][0].update(speed=3), + "frame minute mismatch": lambda r: r["frames"][0].update(minutes_advanced=8), + "frame cap exceeded": lambda r: r["frames"][0].update(minutes_advanced=9), + "registered copied as active": lambda r: r["frames"][0].update(active=r["frames"][0]["registered"]), + "registered copied as drawn": lambda r: r["frames"][0].update(drawn=r["frames"][0]["registered"]), + "rng copied as seed": lambda r: r["frames"][0].update(seed=r["frames"][0]["rng_streams"]), + "GPU zero accepted": lambda r: r["measurement"]["render_gpu_ms"].update(mean=0, p95=0, max=0), + "GPU reason omitted": lambda r: r["measurement"]["render_gpu_ms"].update(reason=None), + "sample machine omitted": lambda r: r["frames"][0].pop("metadata"), + "preparation hash omitted": lambda r: r.pop("preparation_sha256"), + "seed null without reason": lambda r: r["frames"][0].update(seed=None), + "fabricated save return": lambda r: r["startup"]["save_policy"].update(return_value=True, **{"return": True}), + "fabricated void return": lambda r: r["startup"]["pause_fresh_opening"].update(**{"return": True}), + "start report null": lambda r: r["startup"].update(start_report=None), + "toggle pause": lambda r: r.update(toggle_pause_calls=1), + "clear performance": lambda r: r.update(performance_clear_calls=1), + "continue after overload": lambda r: r.update(overloads=[{"frame": 0, "backlog": 121}], + stop_reason="simulation_overloaded"), + "carried as fresh": lambda r: r["frames"][1]["drawn"].update(observation_serial=1), + "short measurement called 120": lambda r: r["measurement"].update(actual_minutes=120), + "false 200 guests": lambda r: r.update(label="200客"), + "budget fabricated pass": lambda r: r["measurement"]["budget"].update(passed=True), + "statistics fabricated": lambda r: r["measurement"]["frame_wall_us"].update(p95=3), + "continue after pause": lambda r: r["frames"][0].update(paused=True), + "wrong O start minute": lambda r: r["startup"].update(opening_minute=602), + } + for label, mutate in mutations.items(): + with self.subTest(label=label): + self.reject(mutate) + + def test_carried_observation(self): + r = synthetic_report() + r["frames"][1]["drawn"].update(observation_serial=1, carried_from_serial=1) + checker.check_report(r) + + def test_probe_static_contract(self): + text = (HERE / "measure_p28_01.gd").read_text() + checker.check_probe(text) + for token in checker.FORBIDDEN: + with self.subTest(token=token), self.assertRaises(ValueError): + checker.check_probe(text + "\n" + token) + + def test_allowed_dependencies_only(self): + tree = ast.parse((HERE / "collect_p28_01.py").read_text()) + self.assertEqual(collector.EXTERNAL_IMPORTS, + ("tools/run_all_tests.py", "tools/regression/owned_outer.py")) + with self.assertRaises(ValueError): + collector.load_tool("adapter/windows_adapter.py") + paths = [n.value for n in ast.walk(tree) if isinstance(n, ast.Constant) and isinstance(n.value, str) + and n.value.endswith(".py")] + self.assertEqual(set(paths), set(collector.EXTERNAL_IMPORTS)) + + def test_windowed_and_phase_plan(self): + self.assertNotIn("--headless", collector.argv_for("engine", Path("stage"), Path("wrapper"))) + self.assertIn("--headless", collector.argv_for("engine", Path("stage"), Path("wrapper"), True)) + self.assertEqual(collector.LIMIT, 1800) + self.assertEqual([p[0] for p in collector.PHASES], ["R0", "P1", "P2", "O0", "P3", "P4"]) + + def test_natural_population_change_is_not_shortfall(self): + r = synthetic_report() + r["frames"][5]["registered"]["guests"] = 2 + r["frames"][5]["active"]["guests"] = 1 + r["measurement"]["count_ranges"]["registered"]["guests"]["min"] = 2 + r["measurement"]["count_ranges"]["active"]["guests"]["min"] = 1 + checker.check_report(r) + + def test_owned_timeout_keeps_raw_and_1800_limit(self): + calls = [] + def owned(*args, **kwargs): + calls.append((args, kwargs)) + return {"timed_out": True}, {"passed": False, "actual_captured_pids": [456]} + with patch.object(collector, "no_live_engine"), patch.object(collector, "write") as output, \ + patch.object(Path, "is_file", return_value=True), \ + patch.object(Path, "read_bytes", return_value=b"partial raw\n"), \ + patch.object(Path, "read_text", return_value="partial raw\n"), \ + patch.object(Path, "stat", return_value=SimpleNamespace(st_size=12)): + row = collector.run_engine(SimpleNamespace(run_phase=owned), ["engine"], Path("synthetic"), {}) + self.assertEqual(calls[0][0][2], 1800) + self.assertFalse(row["passed"]) + self.assertTrue(row["process"]["timed_out"]) + self.assertEqual(set(row["raw"]), {"stdout.log", "stderr.log", "engine-native.log"}) + output.assert_called_once() + + def test_receipt_rejects_source_player_and_raw_pid(self): + r = synthetic_report() + raw = (checker.PREFIX + json.dumps(r) + "\n").encode() + row = {"phase": "O0", "passed": True, "timeout_seconds": 1800, + "raw": {"stdout.log": {"sha256": hashlib.sha256(raw).hexdigest(), "bytes": len(raw)}}, + "report": r, "capture": {"actual_captured_pids": [123]}, + "extrapolation": {"seconds_per_phase": 30}} + receipt = {"source_before": {"x": "a"}, "source_after": {"x": "a"}, + "default_player_before": {}, "default_player_after": {}, "cleanup_errors": [], + "cleanup": [{"engine_ended": True}], "error": None, "passed": True, + "phases": [{"phase": "import", "passed": True, "timeout_seconds": 1800, "raw": {}}, row]} + with patch.object(checker, "PHASES", {"O0": ("O", 1, 0, 10)}), \ + patch.object(Path, "read_bytes", return_value=raw), \ + patch.object(Path, "read_text", return_value=raw.decode()): + checker.check_receipt(receipt, Path("synthetic")) + for label, mutate in { + "source": lambda x: x.update(source_after={"x": "b"}), + "player": lambda x: x.update(default_player_after={"save": "changed"}), + "raw mismatch": lambda x: x["phases"][1]["report"].update(pid=444), + "PID mismatch": lambda x: x["phases"][1]["capture"].update(actual_captured_pids=[444]), + "raw SHA": lambda x: x["phases"][1]["raw"]["stdout.log"].update(sha256="f" * 64), + }.items(): + broken = copy.deepcopy(receipt) + mutate(broken) + with self.subTest(label=label), self.assertRaises(ValueError): + checker.check_receipt(broken, Path("synthetic")) + + +if __name__ == "__main__": + unittest.main(verbosity=2) From 11b7a24a5207a8aaa2be9f47aeec2fbd19288d4c Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 21:19:49 +0900 Subject: [PATCH 2/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/check_p28_01_report.py | 172 +++++++++-- .../p28-01/collector/collect_p28_01.py | 34 ++- .../p28-01/collector/measure_p28_01.gd | 285 ++++++++++++++---- .../p28-01/collector/test_collect_p28_01.py | 156 +++++++++- 4 files changed, 569 insertions(+), 78 deletions(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py index abb9a53..3e9657d 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py @@ -14,6 +14,77 @@ PHASES = {"R0": ("R", 1, 0, 10), "P1": ("R", 1, 30, 120), FORBIDDEN = ("_toggle_pause", "clear(", "enable_production_", "set_paused(false)", "advance_", "spawn_guest", "SimulationRuntime.new", "initialize(") +# Only declared collector fields are normalized. Product dictionaries (RNG, +# startup, raw reports) retain their original JSON representation. +INTEGER_FIELDS = { + "cores", "memory_bytes", "pid", "seed", "frame", "game_start", "game_end", "game_minute", + "minutes_advanced", "start_minute", "end_minute", "opening_minute", "actual_minutes", + "warmup_target", "measurement_target", "speed", "speed_after", "backlog", + "toggle_pause_calls", "performance_clear_calls", "zero_minute_frames_excluded", + "observation_serial", "carried_from_serial", "counts_from_minute", + "actors_in_layer", "actors_in_viewport", "facilities", "cells", "guests", + "staff", "walkable_cells", "count", "lifetime_count", "observed_minutes", "target_minutes", +} +OPAQUE_FIELDS = {"rng_streams", "startup", "kernel_at_warmup_end", "kernel_at_phase_end", + "operations_at_end", "restore_result", "save_policy_after"} + + +def normalize_report(value, path=()): + """Single ingestion boundary, also used when checking raw stdout binding.""" + if isinstance(value, dict): + return {k: (v if k in OPAQUE_FIELDS else normalize_report(v, path + (k,))) + for k, v in value.items()} + if isinstance(value, list): + return [normalize_report(v, path + ("[]",)) for v in value] + key = path[-1] if path else "" + declared = key in INTEGER_FIELDS or key.endswith("_us") + declared = declared or (key == "frames" and not isinstance(value, list)) + declared = declared or (len(path) >= 2 and path[-2] in ("samples_us", "kernel_stall_samples_us", "sample_counts")) + declared = declared or ("budget_verdict" in path and key == "value") + declared = declared or ("count_ranges" in path and key in ("min", "max")) + declared = declared or (len(path) >= 2 and path[-2] in + ("frame_wall_us", "stall_over_50000_us", "observer_us", "render_submit_wall_us") + and key in ("p95", "max")) + if declared and value is not None: + need(type(value) in (int, float) and math.isfinite(value) + and abs(value) <= 2**53 and (type(value) is int or value.is_integer()), + "invalid declared integer: " + ".".join(path)) + return int(value) + return value + + +def budget_verdict(before, after, speed): + result = {} + for metric, aggregation, limit in ((f"simulation_x{speed}", "average" if speed == 1 else "p95", + 4000 if speed == 1 else 12000), + ("main_thread_stall", "maximum", 50000)): + begin = (before or {}).get(metric, {}) + end = (after or {}).get(metric, {}) + a, b = begin.get("lifetime_count"), end.get("lifetime_count") + raw = end.get("samples_us") + reason = None + if type(a) is not int or type(b) is not int or b < a or not isinstance(raw, list): + reason = "counts_unavailable" + elif b == a: + reason = "no_interval_samples" + elif b - a > len(raw): + reason = "interval_exceeds_window" + samples = [] if reason else raw[-(b - a):] + need(all(type(x) is int and x >= 0 for x in samples), "invalid kernel sample") + summary = None + if samples: + ordered = sorted(samples) + summary = {"count": len(samples), "average_us": sum(samples) // len(samples), + "p95_us": ordered[(95 * len(samples) + 99) // 100 - 1], + "maximum_us": max(samples)} + value = summary[aggregation + "_us"] if summary else None + result[metric] = {"source": "clock.performance_budget._samples", "aggregation": aggregation, + "limit_us": limit, "value": value, + "passed": value <= limit if value is not None else None, + "window": "interval_exact_from_samples" if not reason else None, + "reason": reason, "statistics": summary} + return result + def need(ok, reason): if not ok: @@ -52,6 +123,8 @@ def equal(actual, expected, label): need(isinstance(actual, dict) and actual.keys() == expected.keys(), label + " keys") for key in expected: equal(actual[key], expected[key], label + "." + key) + elif type(expected) is int: + need(number(actual) and actual == expected, label) elif number(expected): need(number(actual) and math.isclose(actual, expected, rel_tol=1e-9, abs_tol=1e-7), label) else: @@ -77,7 +150,12 @@ def interval(report, name): rows = [f for f in report["frames"] if f["segment"] == name] value = report[name] keys(value, ("frames", "actual_minutes", "start_minute", "end_minute", "start_wall", "end_wall", - "zero_minute_frames_excluded", "count_ranges", "budget", "stall_budget")) + "zero_minute_frames_excluded", "count_ranges", "frame_observation")) + need("budget" not in value and "stall_budget" not in value and "passed" not in value, + "probe budget forbidden") + observation = value["frame_observation"] + need(set(observation) == {"frame_wall_us", "sim_us_per_minute", "stall_over_50000_us"}, + "frame observation must not contain verdict") need(value["frames"] == len(rows), "frame count") need(value["actual_minutes"] == sum(f["minutes_advanced"] for f in rows), "false interval duration") for field, expected in (("start_minute", rows[0]["game_start"] if rows else None), @@ -88,9 +166,12 @@ def interval(report, name): need(value.get("empty_reason") == ("no_frames" if not rows else None), "empty interval reason") wall = [f["frame_wall_us"] for f in rows] minutes = [f["frame_wall_us"] / f["minutes_advanced"] for f in rows if f["minutes_advanced"]] - equal(value["frame_wall_us"], stats(wall), "frame stats") - equal(value["sim_us_per_minute"], stats(minutes), "minute stats") - equal(value["stall_over_50000_us"], stats([x for x in wall if x > 50000]), "stalls") + equal(observation["frame_wall_us"], stats(wall), "frame stats") + equal(observation["sim_us_per_minute"], stats(minutes), "minute stats") + equal(observation["stall_over_50000_us"], stats([x for x in wall if x > 50000]), "stalls") + equal(value["observer_us"], stats([f["observer_us"] for f in rows]), "observer stats") + equal(value["render_submit_wall_us"], stats([f["render_submit_wall_us"] for f in rows + if f["render_submit_wall_us"] is not None]), "render submission stats") equal(value["time_process_seconds"], stats([f["time_process_seconds"] for f in rows]), "process") need(value["zero_minute_frames_excluded"] == sum(f["minutes_advanced"] == 0 for f in rows), "excluded frames") for kind in ("cpu", "gpu"): @@ -103,15 +184,6 @@ def interval(report, name): ranges[kind] = {key: {"min": min(f[kind][key] for f in rows), "max": max(f[kind][key] for f in rows)} for key in rows[0][kind]} if rows else {} equal(value["count_ranges"], ranges, "count ranges") - metric = stats(minutes)["mean" if report["speed"] == 1 else "p95"] - limit = 4000 if report["speed"] == 1 else 12000 - equal(value["budget"], {"limit_us": limit, "value": metric, - "passed": metric <= limit if metric is not None else None, - "reason": "no_samples" if metric is None else None}, "budget") - maximum = max(wall) if wall else None - equal(value["stall_budget"], {"limit_us": 50000, "value": maximum, - "passed": maximum <= 50000 if maximum is not None else None, - "reason": "no_samples" if maximum is None else None}, "stall budget") def check_report(report): @@ -170,11 +242,33 @@ def check_report(report): previous = report["start_minute"] previous_wall = report["start_wall"] previous_drawing = None + previous_counts = None for index, frame in enumerate(frames): keys(frame, ("frame", "game_start", "game_end", "minutes_advanced", "frame_wall_us", "wall", "wall_start", "speed", "paused", "segment", "registered", "active", "drawn", "seed", "rng_streams", "metadata", "input_sha256", "preparation_sha256", "render_cpu_raw_ms", - "render_gpu_raw_ms", "time_process_seconds")) + "render_gpu_raw_ms", "time_process_seconds", "observer_us", "stall_causes", + "kernel_stall_samples_us", "is_minute_sample", "counts_from_minute", + "render_submit_wall_us", "render_time_source")) + need(type(frame["observer_us"]) is int and frame["observer_us"] >= 0, "observer cost") + nullable(frame, "render_submit_wall_us") + need(frame["render_submit_wall_us"] is None or + (type(frame["render_submit_wall_us"]) is int and frame["render_submit_wall_us"] >= 0), + "render submit duration") + need(frame["render_time_source"] == "RenderingServer.viewport_get_measured_render_time", + "render submit is not GPU time") + need(frame["is_minute_sample"] is (frame["minutes_advanced"] > 0), "minute sampling") + if frame["is_minute_sample"]: + need(frame["counts_from_minute"] == frame["game_end"], "minute sample provenance") + elif previous_counts: + equal({k: frame[k] for k in previous_counts}, previous_counts, "carried minute counts") + previous_counts = {k: frame[k] for k in ("registered", "active", "rng_streams", "counts_from_minute")} + saves = [s for s in report["save_events"] if s["frame"] == index] + kernel_stalls = frame["kernel_stall_samples_us"] + need(isinstance(kernel_stalls, list) and all(type(x) is int and x >= 0 for x in kernel_stalls), + "kernel frame stalls") + cause = bool(saves) and (frame["frame_wall_us"] > 50000 or any(x > 50000 for x in kernel_stalls)) + equal(frame["stall_causes"], ["save_operation_completed"] if cause else [], "save stall cause") need(frame["frame"] == index and frame["game_start"] == previous, "frame continuity") need(type(frame["minutes_advanced"]) is int and 0 <= frame["minutes_advanced"] <= 8, "kernel frame cap") need(frame["game_end"] - previous == frame["minutes_advanced"], "minute delta") @@ -200,14 +294,20 @@ def check_report(report): need(all(frame["active"][k] <= frame["registered"][k] for k in frame["active"]), "active > registered") drawn = frame["drawn"] keys(drawn, ("actors_in_layer", "actors_in_viewport", "facilities", "cells", - "observation_serial", "carried_from_serial", "camera")) - need(all(type(drawn[k]) is int and drawn[k] >= 0 for k in - ("actors_in_layer", "actors_in_viewport", "facilities", "cells", "observation_serial")), "draw counts") - need(drawn["actors_in_viewport"] <= drawn["actors_in_layer"], "draw viewport") - if previous_drawing and drawn["observation_serial"] == previous_drawing["observation_serial"]: + "observation_serial", "carried_from_serial", "camera", "cell_count_from_hash")) + need(sha_string(drawn["cell_count_from_hash"]), "cell cache provenance") + for k in ("actors_in_layer", "actors_in_viewport", "facilities", "cells", "observation_serial"): + nullable(drawn, k) + need(drawn[k] is None or (type(drawn[k]) is int and drawn[k] >= 0), "draw counts") + if drawn["actors_in_viewport"] is not None and drawn["actors_in_layer"] is not None: + need(drawn["actors_in_viewport"] <= drawn["actors_in_layer"], "draw viewport") + if previous_drawing and drawn["cell_count_from_hash"] == previous_drawing["cell_count_from_hash"]: + equal(drawn["cells"], previous_drawing["cells"], "cached cell count changed") + if previous_drawing and drawn["observation_serial"] is not None and \ + drawn["observation_serial"] == previous_drawing["observation_serial"]: need(drawn["carried_from_serial"] == drawn["observation_serial"], "carried observation called fresh") - equal({k: v for k, v in drawn.items() if k != "carried_from_serial"}, - {k: v for k, v in previous_drawing.items() if k != "carried_from_serial"}, "carried changed") + for k in ("actors_in_layer", "actors_in_viewport", "facilities"): + equal(drawn[k], previous_drawing[k], "carried changed") else: need(drawn["carried_from_serial"] is None, "fresh drawing marked carried") need(drawn["camera"] == report["camera"], "camera changed") @@ -227,6 +327,20 @@ def check_report(report): need("kernel_at_warmup_end" in report, "warmup kernel report") for name in ("warmup", "measurement"): interval(report, name) + need(report["budget_scope"] == "kernel process_real_delta only; excludes observer_us", "budget scope") + need(report["render_submit_note"] == "CPU側の描画提出wall、GPU時間ではない", "render submit scope") + equal(report["budget_verdict"], budget_verdict(report["budget_at_warmup_end"], + report["budget_at_phase_end"], speed), "kernel interval budget") + need(number(report["startup_wall_seconds"]) and report["startup_wall_seconds"] >= 0, "startup timing") + for save in report["save_events"]: + keys(save, ("frame", "game_minute", "ok", "operation", "path", "sample_counts")) + need(type(save["frame"]) is int and 0 <= save["frame"] < len(frames), "save frame") + for field in ("ok", "operation", "path"): + nullable(save, field) + need(save["path"] is None or + (isinstance(save["path"], str) and not Path(save["path"]).is_absolute() + and ".." not in Path(save["path"]).parts and not save["path"].startswith("user://")), + "save path must be private relative") if report.get("label") == "200客": need(frames and all(f["registered"]["guests"] == 200 for f in frames), "200 guest claim") @@ -236,21 +350,35 @@ def check_receipt(receipt, directory): need(receipt["default_player_before"] == receipt["default_player_after"], "player changed") need(not receipt["cleanup_errors"] and all(r["engine_ended"] is True for r in receipt["cleanup"]), "cleanup") need(receipt["error"] is None and receipt["passed"] is True, "failed collection") + probe = receipt["probe_check"] + text = (directory / "measure_p28_01.gd").read_text() + need(probe == {"sha256": hashlib.sha256(text.encode()).hexdigest(), "passed": True}, + "execution probe pin/check") + check_probe(text) rows = receipt["phases"] need([r["phase"] for r in rows] == ["import", *PHASES], "phase order") for row in rows: need(row["timeout_seconds"] == 1800 and row["passed"] is True, "phase timeout/pass") + need(row["probe_check"] == probe, "phase execution copy check") for name, pin in row["raw"].items(): data = (directory / row["phase"] / name).read_bytes() need(hashlib.sha256(data).hexdigest() == pin["sha256"] and len(data) == pin["bytes"], "raw SHA") if row["phase"] == "import": continue stdout = (directory / row["phase"] / "stdout.log").read_text() - printed = [json.loads(x[len(PREFIX):]) for x in stdout.splitlines() if x.startswith(PREFIX)] + printed = [normalize_report(json.loads(x[len(PREFIX):])) for x in stdout.splitlines() if x.startswith(PREFIX)] need(printed == [row["report"]], "raw/report mismatch") need(row["capture"]["actual_captured_pids"] == [row["report"]["pid"]], "PID mismatch") check_report(row["report"]) need(row["report"]["stop_reason"] == "complete", "collection includes stopped phase") + if row["phase"] in ("P1", "P2", "P3", "P4"): + stage0 = next(r for r in rows if r["phase"] == row["report"]["input"] + "0") + duration = stage0["extrapolation"]["seconds_per_phase"] + startup = stage0["report"]["startup_wall_seconds"] + equal(row["projection"], {"seconds_per_phase": duration, "startup_wall_seconds": startup, + "projected_total_seconds": duration + startup, "limit_seconds": 1800, + "stage0_phase": stage0["phase"], "stop_reason": None}, "phase projection") + need(duration + startup <= 1800, "phase exceeds projected limit") if row["phase"] in ("R0", "O0"): estimate = row["extrapolation"] equal(estimate["seconds_per_phase"], row["report"]["elapsed_wall_seconds"] * 150 / diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py index 2da0e9f..afb3e63 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py @@ -13,7 +13,7 @@ import uuid from datetime import datetime, timezone sys.dont_write_bytecode = True -from check_p28_01_report import check_report, check_receipt +from check_p28_01_report import check_report, check_receipt, check_probe, normalize_report HERE = Path(__file__).resolve().parent ROOT = HERE.parents[5] FIXTURE_SHA = "eb4f770071eb07cd7e136fe54c3f78768cc8de7a4264e62a9af1f06a8f90f9bd" @@ -98,6 +98,22 @@ def argv_for(engine, stage, wrapper, importing=False): return [str(engine), "--path", str(stage), "--script", str(wrapper)] +def checked_probe(path): + text = path.read_text() + check_probe(text) + return {"sha256": sha(path), "passed": True} + + +def projection(stage0): + evidence = stage0["extrapolation"] + seconds = evidence["seconds_per_phase"] + stage0["report"]["startup_wall_seconds"] + return {"seconds_per_phase": evidence["seconds_per_phase"], + "startup_wall_seconds": stage0["report"]["startup_wall_seconds"], + "projected_total_seconds": seconds, "limit_seconds": LIMIT, + "stage0_phase": stage0["phase"], + "stop_reason": "projected_over_limit" if seconds > LIMIT else None} + + def run_engine(outer, command, folder, environment): no_live_engine() native = folder / "engine-native.log" @@ -213,6 +229,7 @@ def main(): rows = [] error = None profiles = [] + probe_check = None try: stage.mkdir() for name in before: @@ -222,6 +239,7 @@ def main(): require(source_map(standard, stage) == before, "CoW source differs") probe = out / "measure_p28_01.gd" probe.write_bytes((HERE / probe.name).read_bytes()) + probe_check = checked_probe(probe) guard = out / "profile_guard.gd" guard.write_bytes((args.readonly / "run-r02/profile_guard.gd").read_bytes()) wrapper.write_text("extends " + json.dumps(str(probe)) + "\nconst Guard = preload(" + @@ -241,7 +259,16 @@ def main(): "source/player changed before phase") require(source_map(standard, stage) == expected, "stage changed before phase") require(all(sha(Path(p)) == pin for p, pin in script_pins.items()), "execution scripts changed") + require(checked_probe(probe) == probe_check, "probe check changed") require(sha(args.fixture) == FIXTURE_SHA, "input_shortfall: changed input") + forecast = None + if label in ("P1", "P2", "P3", "P4"): + stage0 = next(r for r in rows if r["phase"] == source + "0") + forecast = projection(stage0) + if forecast["stop_reason"]: + rows.append({"phase": label, "passed": False, "engines_started": 0, + "stop_reason": "projected_over_limit", "projection": forecast}) + raise ValueError("projected_over_limit: " + label) name = "TheTree-PCK-tests-" + uuid.uuid4().hex + "-p28-startup" startup = standard.profile_path(name) require(not startup.exists(), "startup profile not fresh") @@ -262,6 +289,8 @@ def main(): finally: (stage / "project.godot").write_bytes(public) row["phase"] = label + row["projection"] = forecast + row["probe_check"] = probe_check rows.append(row) require(row["passed"], "native phase failed; raw retained: " + label) after = source_map(standard, stage) @@ -283,7 +312,7 @@ def main(): raw = (out / label / "stdout.log").read_text() printed = [line.split("=", 1)[1] for line in raw.splitlines() if line.startswith("P28_01_PERF_REPORT=")] require(len(printed) == 1, "exactly one raw report required") - report = json.loads(printed[0]) + report = normalize_report(json.loads(printed[0])) require(report["pid"] == row["capture"]["actual_captured_pids"][0], "PID binding") row.update(report=report, report_sha256=digest(report), guard=observation, guard_sha256=sha(guard_path)) @@ -304,6 +333,7 @@ def main(): after = source_map(standard, ROOT) player_after = standard.default_player(ROOT) receipt = {"phases": rows, "error": error, "source_before": before, "source_after": after, + "probe_check": probe_check, "default_player_before": player, "default_player_after": player_after, "cleanup": cleanup, "cleanup_errors": cleanup_errors, "profiles": {str(p): profile_files(p) for p in profiles}, diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd index de5d661..c981ab5 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd @@ -6,7 +6,8 @@ class Observer: extends Node var owner_probe: Variant func _process(_delta: float) -> void: - owner_probe.sample() + var observer_started_us := Time.get_ticks_usec() + owner_probe.sample(observer_started_us) var clock: Variant var runtime: Variant @@ -22,7 +23,7 @@ var start_minute := 0 var warmup := 0 var target := 0 var speed := 0 -var previous_serial := -1 +var previous_serial: Variant = null var drawing := {} var camera := {} var overloads: Array = [] @@ -32,6 +33,100 @@ var measurement_start := 0 var minute_ticks: Array = [] var previous_tick_us := 0 var previous_wall := 0.0 +var key_forms := {} +var cached_registered := {} +var cached_active := {} +var cached_rng := {} +var counts_minute := 0 +var cell_hash := "" +var cached_cells: Variant = null +var save_events: Array = [] +var last_stall_count: Variant = null +var render_started_us := -1 +var render_submit_us: Variant = null +var render_serial := 0 +var last_render_serial := -1 + +# Product dictionaries may expose StringName keys. Never supply inferred defaults. +func field(d: Variant, name: String) -> Variant: + if d is Dictionary: + if d.has(StringName(name)): + key_forms[name] = {"key_form": "StringName", "reason": null} + return d[StringName(name)] + if d.has(String(name)): + key_forms[name] = {"key_form": "String", "reason": null} + return d[String(name)] + key_forms[name] = {"key_form": null, "reason": "missing_product_field"} + return null + +func budget_snapshot() -> Dictionary: + var result := {} + var profiler: Variant = clock.performance_budget + for metric: String in ["simulation_x1", "simulation_x3", "main_thread_stall"]: + var samples: Variant = field(profiler.get("_samples"), metric) + var count: Variant = field(profiler.get("_sample_counts"), metric) + result[metric] = {"samples_us": samples.duplicate() if samples is Array else null, + "lifetime_count": count, "reason": "counts_unavailable" if count == null or samples == null else null} + return result + +func kernel_verdict(before: Dictionary, after: Dictionary) -> Dictionary: + var result := {} + for metric: String in ["simulation_x%d" % speed, "main_thread_stall"]: + var first: Dictionary = before.get(metric, {}) + var last: Dictionary = after.get(metric, {}) + var a: Variant = first.get("lifetime_count") + var b: Variant = last.get("lifetime_count") + var raw: Variant = last.get("samples_us") + var reason: Variant = null + var selected: Array = [] + if a == null or b == null or b < a or not raw is Array: + reason = "counts_unavailable" + elif b == a: + reason = "no_interval_samples" + elif b - a > raw.size(): + reason = "interval_exceeds_window" + else: + selected = raw.slice(raw.size() - (b - a)) + var aggregate := "maximum" if metric == "main_thread_stall" else ("average" if speed == 1 else "p95") + var limit := 50000 if metric == "main_thread_stall" else (4000 if speed == 1 else 12000) + var statistics: Variant = null + var value: Variant = null + if not selected.is_empty(): + var total: int = 0 + for duration: int in selected: + total += duration + selected.sort() + var count: int = selected.size() + statistics = {"count": count, "average_us": total / count, + "p95_us": selected[(95 * count + 99) / 100 - 1], "maximum_us": selected.back()} + value = statistics[aggregate + "_us"] + result[metric] = {"source": "clock.performance_budget._samples", "aggregation": aggregate, + "limit_us": limit, "value": value, "passed": value <= limit if value != null else null, + "window": "interval_exact_from_samples" if reason == null else null, + "reason": reason, "statistics": statistics} + return result + +func on_save(result: Dictionary) -> void: + var path: Variant = field(result, "save_path") + var relative: Variant = null + if path is String and path.begins_with("user://") and not ".." in path.split("/"): + relative = path.trim_prefix("user://") + var counts: Variant = clock.performance_budget.get("_sample_counts") + var event := {"frame": frames.size(), "game_minute": clock.absolute_minute, + "ok": field(result, "ok"), "ok_reason": key_forms["ok"].reason, + "operation": field(result, "operation"), "operation_reason": key_forms["operation"].reason, + "path": relative, "path_reason": "missing_or_not_private_user_path" if relative == null else null, + "sample_counts": counts.duplicate(true)} + save_events.append(event) + print("P28_01_SAVE=" + JSON.stringify(event)) + +func on_pre_draw() -> void: + render_started_us = Time.get_ticks_usec() + +func on_post_draw() -> void: + if render_started_us >= 0: + render_submit_us = Time.get_ticks_usec() - render_started_us + render_serial += 1 func _initialize() -> void: call_deferred("begin") @@ -80,42 +175,76 @@ func rng_state() -> Dictionary: var result := {} var streams: Dictionary = runtime.get("_rng_streams") for key: Variant in streams: - result[String(key)] = streams[key].snapshot() + var stream: Variant = field(streams, String(key)) + result[String(key)] = stream.snapshot() if stream != null else null return result func draw_counts() -> Dictionary: var observation: Dictionary = preview.get_life_observation_report() - var serial := int(observation.get("observation_serial", -1)) - if serial == previous_serial and not drawing.is_empty(): + var serial: Variant = field(observation, "observation_serial") + update_cell_count() + if serial != null and serial == previous_serial and not drawing.is_empty(): var carried := drawing.duplicate(true) carried["carried_from_serial"] = serial + carried["cells"] = cached_cells + carried["cells_reason"] = "missing_bounds" if cached_cells == null else null + carried["cell_count_from_hash"] = cell_hash + carried["camera"] = camera_state() return carried previous_serial = serial var area := Rect2(Vector2.ZERO, preview.size) - var actors: Array = observation.get("actor_drawings", []) - var visible := 0 - for actor: Dictionary in actors: - if area.has_point(actor["at"]): - visible += 1 - var facilities := 0 + var actors: Variant = field(observation, "actor_drawings") + var visible: Variant = null + if actors is Array: + visible = 0 + for actor: Dictionary in actors: + var at: Variant = field(actor, "at") + if at == null: + visible = null + break + if area.has_point(at): + visible += 1 + var facilities: Variant = 0 for facility: Dictionary in preview.call("_completed_facilities_for_draw"): - if int(facility.get("layer", 0)) != int(preview.layer_mode): + var layer: Variant = field(facility, "layer") + var occupied: Variant = field(facility, "occupied_cells") + if layer == null or occupied == null: + facilities = null + break + if int(layer) != int(preview.layer_mode): continue - var cells: Array = preview.call("_cells_from_serialized", facility.get("occupied_cells", [])) + var cells: Array = preview.call("_cells_from_serialized", occupied) if not cells.is_empty() and preview.call("_cell_bounds_rect", cells).intersects(area): facilities += 1 - var bounds: Dictionary = preview.call("_world_bounds") - var cells := 0 - if not bounds.is_empty(): - for y in range(int(bounds["min_y"]), int(bounds["max_y"]) + 1): - for x in range(int(bounds["min_x"]), int(bounds["max_x"]) + 1): - if preview.get_cell_rect(Vector3i(x, y, preview.layer_mode)).intersects(area): - cells += 1 - drawing = {"actors_in_layer": actors.size(), "actors_in_viewport": visible, - "facilities": facilities, "cells": cells, "observation_serial": serial, + drawing = {"actors_in_layer": actors.size() if actors is Array else null, + "actors_in_layer_reason": "missing_actor_drawings" if not actors is Array else null, + "actors_in_viewport": visible, "actors_in_viewport_reason": "missing_actor_geometry" if visible == null else null, + "facilities": facilities, "facilities_reason": "missing_facility_geometry" if facilities == null else null, + "cells": cached_cells, "observation_serial": serial, + "observation_serial_reason": "missing_observation_serial" if serial == null else null, + "cells_reason": "missing_bounds" if cached_cells == null else null, + "cell_count_from_hash": cell_hash, "carried_from_serial": null, "camera": camera_state()} return drawing.duplicate(true) +func update_cell_count() -> void: + var area := Rect2(Vector2.ZERO, preview.size) + var bounds: Dictionary = preview.call("_world_bounds") + var geometry_hash := hashed({"bounds": bounds, "camera": camera_state()}) + if geometry_hash != cell_hash: + cell_hash = geometry_hash + cached_cells = null + var min_y: Variant = field(bounds, "min_y") + var max_y: Variant = field(bounds, "max_y") + var min_x: Variant = field(bounds, "min_x") + var max_x: Variant = field(bounds, "max_x") + if min_y != null and max_y != null and min_x != null and max_x != null: + cached_cells = 0 + for y in range(int(min_y), int(max_y) + 1): + for x in range(int(min_x), int(max_x) + 1): + if preview.get_cell_rect(Vector3i(x, y, preview.layer_mode)).intersects(area): + cached_cells += 1 + func begin() -> void: clock = root.get_node("GameClock") runtime = root.get_node("SimulationRuntime") @@ -133,6 +262,11 @@ func begin() -> void: "renderer": ProjectSettings.get_setting("rendering/renderer/rendering_method"), "warmup_target": warmup, "measurement_target": target, "window_note": "Product reports are raw rolling capacity-512 reports; warm-up may remain; no subtraction.", + "budget_scope": "kernel process_real_delta only; excludes observer_us", + "render_submit_note": "CPU側の描画提出wall、GPU時間ではない", + "observer_note": "observer_us includes reads, serialization and frame emission; excludes its own timing line and final report; never subtracted", + "sample_definition": "is_minute_sample marks a changed game minute; other frames carry counts_from_minute", + "budget_at_warmup_end": {}, "save_events": save_events, "key_form": key_forms, "count_definitions": {"registered": "service collections; walkable cells", "active": "guests exclude SPAWNING/LEAVING/DESPAWNING; staff current attended unended shift; facilities OPERATING", "drawn": "world_preview submitted model serial and viewport geometry"}, @@ -170,14 +304,14 @@ func begin() -> void: "save_policy": {"return": null, "reason": "return_discarded_by_main（main.gd:222）"}, "save_policy_after": runtime.get_save_policy(), "start_report": main.get("_operations_start_report").duplicate(true), - "operations_enabled_after": runtime.get_operations_report().enabled, + "operations_enabled_after": field(runtime.get_operations_report(), "enabled"), "opening_minute": opening_minute} if report.startup.start_report.is_empty(): report.startup["start_report_reason"] = "main_retained_empty_dictionary" var start: Dictionary = report.startup.start_report - var expected: bool = bool(start.get("ok", false)) and report.startup.operations_enabled_after and opening_minute == 360 + var expected: bool = field(start, "ok") == true and report.startup.operations_enabled_after == true and opening_minute == 360 if input == "R": - expected = not report.startup.operations_enabled_after and String(start.get("code", "")) == "INVALID_START_TIME" + expected = report.startup.operations_enabled_after == false and field(start, "code") == "INVALID_START_TIME" if not expected: finish("input_shortfall") return @@ -194,10 +328,16 @@ func begin() -> void: clock.simulation_overloaded.connect(on_overload) clock.tick_completed.connect(on_tick) runtime.checkpoint_presentation_requested.connect(on_checkpoint) + runtime.save_operation_completed.connect(on_save) + RenderingServer.frame_pre_draw.connect(on_pre_draw) + RenderingServer.frame_post_draw.connect(on_post_draw) var observer := Observer.new() observer.owner_probe = self observer.process_priority = 100000 root.add_child(observer) + cached_registered = registered() + cached_active = active_counts() + cached_rng = rng_state() main.call("_set_speed", speed) report["speed_after"] = clock.speed report["paused_after_speed"] = clock.paused @@ -210,6 +350,14 @@ func begin() -> void: start_us = Time.get_ticks_usec() previous_us = start_us previous_tick_us = start_us + counts_minute = start_minute + var initial_budget := budget_snapshot() + last_stall_count = initial_budget.main_thread_stall.lifetime_count + if warmup == 0: + warmup_ended = true + report["kernel_at_warmup_end"] = clock.get_performance_reports() + report["budget_at_warmup_end"] = initial_budget + report["startup_wall_seconds"] = float(start_us) / 1000000.0 report["start_minute"] = start_minute report["start_wall"] = Time.get_unix_time_from_system() previous_wall = report["start_wall"] @@ -233,53 +381,86 @@ func on_tick(minute: int) -> void: previous_tick_us = tick_us print("P28_01_MINUTE=" + JSON.stringify(row)) -func sample() -> void: +func sample(observer_started_us: int) -> void: if not ready_to_sample: return var current_us := Time.get_ticks_usec() var minute: int = clock.absolute_minute var elapsed := current_us - previous_us var advanced := minute - previous_minute + if advanced > 0: + cached_registered = registered() + cached_active = active_counts() + cached_rng = rng_state() + counts_minute = minute + var stall_raw: Variant = field(clock.performance_budget.get("_samples"), "main_thread_stall") + var stall_count: Variant = field(clock.performance_budget.get("_sample_counts"), "main_thread_stall") + var kernel_stalls: Array = [] + if stall_count != null and last_stall_count != null and stall_raw is Array: + var delta: int = stall_count - last_stall_count + if delta > 0 and delta <= stall_raw.size(): + kernel_stalls = stall_raw.slice(stall_raw.size() - delta) + last_stall_count = stall_count + var causes: Array = [] + for event: Dictionary in save_events: + if event.frame == frames.size() and (elapsed > 50000 or (not kernel_stalls.is_empty() and kernel_stalls.max() > 50000)): + causes = ["save_operation_completed"] + break var row := {"frame": frames.size(), "game_start": previous_minute, "game_end": minute, "minutes_advanced": advanced, "frame_wall_us": elapsed, "wall_start": previous_wall, "wall": Time.get_unix_time_from_system(), "speed": clock.speed, "paused": clock.paused, "segment": "warmup" if previous_minute - start_minute < warmup else "measurement", - "registered": registered(), "active": active_counts(), "drawn": draw_counts(), - "seed": runtime.world_seed, "rng_streams": rng_state(), + "registered": cached_registered, "active": cached_active, "drawn": draw_counts(), + "seed": runtime.world_seed, "rng_streams": cached_rng, + "is_minute_sample": advanced > 0, "counts_from_minute": counts_minute, + "stall_causes": causes, "kernel_stall_samples_us": kernel_stalls, + "render_submit_wall_us": render_submit_us if render_serial != last_render_serial else null, + "render_submit_wall_us_reason": "no_new_draw_submission" if render_serial == last_render_serial or render_submit_us == null else null, + "render_time_source": "RenderingServer.viewport_get_measured_render_time", "metadata": report.metadata, "input_sha256": report.input_sha256, "input_sha256_reason": report.input_sha256_reason, "preparation_sha256": report.preparation_sha256, "render_cpu_raw_ms": RenderingServer.viewport_get_measured_render_time_cpu(root.get_viewport_rid()), "render_gpu_raw_ms": RenderingServer.viewport_get_measured_render_time_gpu(root.get_viewport_rid()), "time_process_seconds": Performance.get_monitor(Performance.TIME_PROCESS)} - frames.append(row) - print("P28_01_FRAME=" + JSON.stringify(row)) + last_render_serial = render_serial previous_us = current_us previous_wall = row.wall previous_minute = minute if not warmup_ended and minute - start_minute >= warmup: warmup_ended = true report["kernel_at_warmup_end"] = clock.get_performance_reports() + report["budget_at_warmup_end"] = budget_snapshot() if warmup > 0: measurement_start = minute var operations: Dictionary = runtime.get_operations_report() + var reason := "" if not overloads.is_empty(): - finish("simulation_overloaded") - elif bool(operations.get("runtime_failure_latched", false)): - finish("operations_runtime_failure") + reason = "simulation_overloaded" + elif field(operations, "runtime_failure_latched") == true: + reason = "operations_runtime_failure" elif runtime.operations_coordinator != null and runtime.operations_coordinator.is_terminal(): - finish("operations_terminal") - elif bool(operations.get("tick_blocked", false)): - finish("operations_pause") + reason = "operations_terminal" + elif field(operations, "tick_blocked") == true: + reason = "operations_pause" elif clock.paused: - finish("clock_paused") + reason = "clock_paused" elif camera_state() != camera: - finish("camera_changed") - elif float(current_us - start_us) / 1000000.0 >= 1800.0: - finish("timeout") + reason = "camera_changed" + elif float(current_us) / 1000000.0 >= 1740.0: + reason = "timeout" elif measurement_start >= 0 and minute - measurement_start >= target: - finish("complete") + reason = "complete" + # This includes count/drawing reads and serialization; emission and final + # summary are disclosed separately and are never subtracted from frame wall. + var raw_line := JSON.stringify(row) + print("P28_01_FRAME=" + raw_line) + row["observer_us"] = Time.get_ticks_usec() - observer_started_us + frames.append(row) + print("P28_01_OBSERVER=" + JSON.stringify({"frame": row.frame, "observer_us": row.observer_us})) + if not reason.is_empty(): + finish(reason) func stats(values: Array, reason := "no_samples") -> Dictionary: if values.is_empty(): @@ -300,6 +481,8 @@ func summary(segment: String) -> Dictionary: var process: Array = [] var selected: Array = [] var stalls: Array = [] + var observer: Array = [] + var submit: Array = [] var excluded := 0 var minutes := 0 var cpu_missing := false @@ -310,6 +493,9 @@ func summary(segment: String) -> Dictionary: continue selected.append(frame) wall.append(frame.frame_wall_us) + observer.append(frame.observer_us) + if frame.render_submit_wall_us != null: + submit.append(frame.render_submit_wall_us) process.append(frame.time_process_seconds) minutes += frame.minutes_advanced if frame.frame_wall_us > 50000: @@ -331,24 +517,19 @@ func summary(segment: String) -> Dictionary: ranges[kind][key].max = maxi(ranges[kind][key].max, value) var unavailable := "zero_from_api_on_gl_compatibility_unsupported_or_unmeasured" var minute_stats := stats(per_minute) - var budget := 4000 if speed == 1 else 12000 - var metric: Variant = minute_stats.mean if speed == 1 else minute_stats.p95 return {"frames": selected.size(), "actual_minutes": minutes, "start_minute": selected.front().game_start if not selected.is_empty() else null, "end_minute": selected.back().game_end if not selected.is_empty() else null, "start_wall": selected.front().wall_start if not selected.is_empty() else null, "end_wall": selected.back().wall if not selected.is_empty() else null, "empty_reason": "no_frames" if selected.is_empty() else null, - "frame_wall_us": stats(wall), "sim_us_per_minute": minute_stats, - "zero_minute_frames_excluded": excluded, "stall_over_50000_us": stats(stalls), + "frame_observation": {"frame_wall_us": stats(wall), "sim_us_per_minute": minute_stats, + "stall_over_50000_us": stats(stalls)}, + "observer_us": stats(observer), "render_submit_wall_us": stats(submit), + "zero_minute_frames_excluded": excluded, "render_cpu_ms": stats([], unavailable) if cpu_missing else stats(cpu), "render_gpu_ms": stats([], unavailable) if gpu_missing else stats(gpu), - "time_process_seconds": stats(process), "count_ranges": ranges, - "budget": {"limit_us": budget, "value": metric, "passed": metric <= budget if metric != null else null, - "reason": "no_samples" if metric == null else null}, - "stall_budget": {"limit_us": 50000, "value": wall.max() if not wall.is_empty() else null, - "passed": wall.max() <= 50000 if not wall.is_empty() else null, - "reason": "no_samples" if wall.is_empty() else null}} + "time_process_seconds": stats(process), "count_ranges": ranges} func finish(reason: String) -> void: ready_to_sample = false @@ -357,6 +538,8 @@ func finish(reason: String) -> void: report["elapsed_wall_seconds"] = float(Time.get_ticks_usec() - start_us) / 1000000.0 if start_us > 0 else 0.0 report["end_wall"] = Time.get_unix_time_from_system() report["kernel_at_phase_end"] = clock.get_performance_reports() + report["budget_at_phase_end"] = budget_snapshot() + report["budget_verdict"] = kernel_verdict(report.budget_at_warmup_end, report.budget_at_phase_end) report["operations_at_end"] = runtime.get_operations_report() report["warmup"] = summary("warmup") report["measurement"] = summary("measurement") diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index ede1048..145ea0d 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -80,6 +80,34 @@ def synthetic_report(): "count_ranges": {"registered": {}, "active": {}}, "budget": {"limit_us": 4000, "value": None, "passed": None, "reason": "no_samples"}, "stall_budget": {"limit_us": 50000, "value": None, "passed": None, "reason": "no_samples"}} + for name in ("warmup", "measurement"): + section = report[name] + section.pop("budget") + section.pop("stall_budget") + section["frame_observation"] = {k: section.pop(k) for k in + ("frame_wall_us", "sim_us_per_minute", "stall_over_50000_us")} + section["observer_us"] = constant(section["frames"], 1500) + section["render_submit_wall_us"] = constant(section["frames"], 1100) + for frame in frames: + frame.update(observer_us=1500, render_submit_wall_us=1100, is_minute_sample=True, + counts_from_minute=frame["game_end"], stall_causes=[], + kernel_stall_samples_us=[3000], + render_time_source="RenderingServer.viewport_get_measured_render_time") + frame["drawn"]["cell_count_from_hash"] = "c" * 64 + report.update(save_events=[], startup_wall_seconds=1.5, + budget_scope="kernel process_real_delta only; excludes observer_us", + render_submit_note="CPU側の描画提出wall、GPU時間ではない", + budget_at_warmup_end={k: {"lifetime_count": 30, "samples_us": [3000] * 30} + for k in ("simulation_x1", "main_thread_stall")}, + budget_at_phase_end={k: {"lifetime_count": 40, "samples_us": [3000] * 40} + for k in ("simulation_x1", "main_thread_stall")}) + report["budget_verdict"] = { + k: {"source": "clock.performance_budget._samples", "aggregation": aggregate, + "limit_us": limit, "value": 3000, "passed": True, + "window": "interval_exact_from_samples", "reason": None, + "statistics": {"count": 10, "average_us": 3000, "p95_us": 3000, "maximum_us": 3000}} + for k, aggregate, limit in (("simulation_x1", "average", 4000), + ("main_thread_stall", "maximum", 50000))} return report @@ -117,8 +145,8 @@ class ReportTests(unittest.TestCase): "carried as fresh": lambda r: r["frames"][1]["drawn"].update(observation_serial=1), "short measurement called 120": lambda r: r["measurement"].update(actual_minutes=120), "false 200 guests": lambda r: r.update(label="200客"), - "budget fabricated pass": lambda r: r["measurement"]["budget"].update(passed=True), - "statistics fabricated": lambda r: r["measurement"]["frame_wall_us"].update(p95=3), + "budget fabricated pass": lambda r: r["budget_verdict"]["simulation_x1"].update(passed=False), + "statistics fabricated": lambda r: r["measurement"]["frame_observation"]["frame_wall_us"].update(p95=3), "continue after pause": lambda r: r["frames"][0].update(paused=True), "wrong O start minute": lambda r: r["startup"].update(opening_minute=602), } @@ -190,9 +218,14 @@ class ReportTests(unittest.TestCase): "default_player_before": {}, "default_player_after": {}, "cleanup_errors": [], "cleanup": [{"engine_ended": True}], "error": None, "passed": True, "phases": [{"phase": "import", "passed": True, "timeout_seconds": 1800, "raw": {}}, row]} + probe_text = (HERE / "measure_p28_01.gd").read_text() + receipt["probe_check"] = {"sha256": hashlib.sha256(probe_text.encode()).hexdigest(), "passed": True} + for phase in receipt["phases"]: + phase["probe_check"] = receipt["probe_check"].copy() with patch.object(checker, "PHASES", {"O0": ("O", 1, 0, 10)}), \ patch.object(Path, "read_bytes", return_value=raw), \ - patch.object(Path, "read_text", return_value=raw.decode()): + patch.object(Path, "read_text", autospec=True, + side_effect=lambda p: probe_text if p.name == "measure_p28_01.gd" else raw.decode()): checker.check_receipt(receipt, Path("synthetic")) for label, mutate in { "source": lambda x: x.update(source_after={"x": "b"}), @@ -200,12 +233,129 @@ class ReportTests(unittest.TestCase): "raw mismatch": lambda x: x["phases"][1]["report"].update(pid=444), "PID mismatch": lambda x: x["phases"][1]["capture"].update(actual_captured_pids=[444]), "raw SHA": lambda x: x["phases"][1]["raw"]["stdout.log"].update(sha256="f" * 64), + "probe SHA": lambda x: x["probe_check"].update(sha256="f" * 64), + "probe not checked": lambda x: x["probe_check"].update(passed=False), + "different execution copy": lambda x: x["phases"][1]["probe_check"].update(sha256="e" * 64), }.items(): broken = copy.deepcopy(receipt) mutate(broken) with self.subTest(label=label), self.assertRaises(ValueError): checker.check_receipt(broken, Path("synthetic")) + def test_h1_h2_exact_kernel_aggregation(self): + before = {"simulation_x1": {"lifetime_count": 100}, + "simulation_x3": {"lifetime_count": 100}, + "main_thread_stall": {"lifetime_count": 100}} + samples = [900000] * 10 + [3001, 3002, 3002] + after = {k: {"lifetime_count": 103, "samples_us": samples} for k in before} + verdict = checker.budget_verdict(before, after, 1) + self.assertEqual(verdict["simulation_x1"]["value"], 3001) + self.assertEqual(verdict["main_thread_stall"]["value"], 3002) + self.assertEqual(verdict["simulation_x1"]["window"], "interval_exact_from_samples") + self.assertEqual(checker.budget_verdict(before, after, 3)["simulation_x3"]["value"], 3002) + for mutate in ( + lambda r: r["measurement"]["frame_observation"].update(passed=True), + lambda r: r["measurement"].update(budget={"passed": True}), + lambda r: r["budget_verdict"]["simulation_x1"].update(value=200000), + lambda r: r["budget_verdict"]["simulation_x1"].update(window="lifetime"), + lambda r: r["budget_verdict"]["simulation_x1"].update(value=3000.01), + ): + self.reject(mutate) + + def test_h1_h2_unavailable_intervals(self): + for reason, count in (("interval_exceeds_window", 600), + ("no_interval_samples", 30), ("counts_unavailable", None)): + r = synthetic_report() + r["budget_at_phase_end"]["simulation_x1"]["lifetime_count"] = count + r["budget_verdict"] = checker.budget_verdict(r["budget_at_warmup_end"], + r["budget_at_phase_end"], 1) + self.assertEqual(r["budget_verdict"]["simulation_x1"]["reason"], reason) + self.assertIsNone(r["budget_verdict"]["simulation_x1"]["value"]) + checker.check_report(r) + r["budget_verdict"]["simulation_x1"].update(value=3000, passed=True) + with self.assertRaises(ValueError): + checker.check_report(r) + + def test_h3_save_stall_correlation(self): + r = synthetic_report() + r["save_events"] = [{"frame": 2, "game_minute": 363, "ok": True, + "operation": "autosave", "path": "saves/autosave.variant", + "sample_counts": {"main_thread_stall": 32}}] + r["frames"][2]["stall_causes"] = ["save_operation_completed"] + checker.check_report(r) + r["frames"][2]["stall_causes"] = [] + with self.assertRaises(ValueError): + checker.check_report(r) + self.reject(lambda r: r["frames"][0].update(stall_causes=["save_operation_completed"])) + r["frames"][2]["stall_causes"] = ["save_operation_completed"] + r["save_events"][0]["path"] = "../public-save" + with self.assertRaises(ValueError): + checker.check_report(r) + + def test_h4_observer_and_cache_provenance(self): + checker.check_report(synthetic_report()) + for mutate in ( + lambda r: r["frames"][0].update(observer_us=-1), + lambda r: r["measurement"]["observer_us"].update(mean=0), + lambda r: r["frames"][0]["drawn"].pop("cell_count_from_hash"), + lambda r: r["frames"][0].update(is_minute_sample=False), + lambda r: r["frames"][0].update(counts_from_minute=360), + ): + self.reject(mutate) + + def test_h5_godot_json_integer_normalization(self): + r = synthetic_report() + r["metadata"]["machine"]["cores"] = 10.0 + r["metadata"]["machine"]["memory_bytes"] = 24000000000.0 + r["pid"] = 123.0 + r["frames"][0]["registered"]["guests"] = 3.0 + r["budget_at_phase_end"]["simulation_x1"]["samples_us"] = [3000.0] * 40 + normalized = collector.normalize_report(json.loads(json.dumps(r))) + checker.check_report(normalized) + self.assertIs(type(normalized["pid"]), int) + for value in (1.5, float(2**53 + 2), float("inf"), True): + with self.subTest(value=value), self.assertRaises(ValueError): + collector.normalize_report({"pid": value}) + unknown = collector.normalize_report({"undeclared": 1.0, "rng_streams": {"state": 1.0}}) + self.assertIs(type(unknown["undeclared"]), float) + self.assertIs(type(unknown["rng_streams"]["state"]), float) + text = (HERE / "measure_p28_01.gd").read_text() + self.assertIn("d.has(StringName(name))", text) + self.assertIn("d.has(String(name))", text) + self.assertIn('"missing_product_field"', text) + for bad in ('actor["at"]', 'facility.get("layer"', 'observation.get("observation_serial"'): + self.assertNotIn(bad, text) + + def test_h6_projection_and_probe_deadline(self): + stage0 = {"phase": "O0", "report": {"startup_wall_seconds": 20}, + "extrapolation": {"seconds_per_phase": 1780}} + self.assertIsNone(collector.projection(stage0)["stop_reason"]) + stage0["report"]["startup_wall_seconds"] = 21 + self.assertEqual(collector.projection(stage0)["stop_reason"], "projected_over_limit") + text = (HERE / "measure_p28_01.gd").read_text() + self.assertIn("float(current_us) / 1000000.0 >= 1740.0", text) + self.assertNotIn("current_us - start_us) / 1000000.0 >= 1800", text) + + def test_h7_execution_copy_admission(self): + text = (HERE / "measure_p28_01.gd").read_text() + with patch.object(Path, "read_text", return_value=text), \ + patch.object(collector, "sha", return_value="a" * 64): + self.assertEqual(collector.checked_probe(Path("execution-copy")), + {"sha256": "a" * 64, "passed": True}) + with patch.object(Path, "read_text", return_value=text + "\nspawn_guest()"), \ + patch.object(collector, "run_engine") as launch: + with self.assertRaises(ValueError): + collector.checked_probe(Path("execution-copy")) + launch.assert_not_called() + + def test_render_submission_not_gpu(self): + r = synthetic_report() + checker.check_report(r) + self.assertIsNone(r["measurement"]["render_gpu_ms"]["mean"]) + self.assertEqual(r["measurement"]["render_submit_wall_us"]["mean"], 1100) + self.reject(lambda r: r["measurement"].update(render_gpu_ms=r["measurement"]["render_submit_wall_us"])) + self.reject(lambda r: r["frames"][0].update(render_time_source="render_submit_wall_us")) + if __name__ == "__main__": unittest.main(verbosity=2) From 7bf44b072cb17cb122b41c07e57a4df2f33ed50b Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 21:35:45 +0900 Subject: [PATCH 3/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/check_p28_01_report.py | 33 ++-- .../p28-01/collector/collect_p28_01.py | 116 ++++++++---- .../p28-01/collector/measure_p28_01.gd | 3 + .../p28-01/collector/test_collect_p28_01.py | 175 +++++++++++++++++- 4 files changed, 277 insertions(+), 50 deletions(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py index 3e9657d..0a52ab2 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py @@ -346,6 +346,7 @@ def check_report(report): def check_receipt(receipt, directory): + from collect_p28_01 import OWNED_FILES, projection, extrapolation, guard_gate need(receipt["source_before"] == receipt["source_after"], "source map changed") need(receipt["default_player_before"] == receipt["default_player_after"], "player changed") need(not receipt["cleanup_errors"] and all(r["engine_ended"] is True for r in receipt["cleanup"]), "cleanup") @@ -358,31 +359,39 @@ def check_receipt(receipt, directory): rows = receipt["phases"] need([r["phase"] for r in rows] == ["import", *PHASES], "phase order") for row in rows: + forecast = None + if row["phase"] in ("P1", "P2", "P3", "P4"): + source = PHASES[row["phase"]][0] + stage0 = next(r for r in rows if r["phase"] == source + "0") + forecast = projection(stage0) + equal(row["projection"], forecast, "phase projection") + if row.get("stop_reason") == "projected_over_limit": + need(forecast is not None and forecast["stop_reason"] == "projected_over_limit" + and row["engines_started"] == 0 and row["passed"] is False, + "invalid skipped phase") + need("report" not in row and "raw" not in row, "skipped phase claims execution") + continue + need(forecast is None or forecast["stop_reason"] is None, "started over projected limit") need(row["timeout_seconds"] == 1800 and row["passed"] is True, "phase timeout/pass") need(row["probe_check"] == probe, "phase execution copy check") + need(set(row["owned_files"]) == set(OWNED_FILES), "owned evidence missing") + for name, pin in row["owned_files"].items(): + data = (directory / row["phase"] / name).read_bytes() + need(hashlib.sha256(data).hexdigest() == pin["sha256"] and len(data) == pin["bytes"], + "owned evidence changed") for name, pin in row["raw"].items(): data = (directory / row["phase"] / name).read_bytes() need(hashlib.sha256(data).hexdigest() == pin["sha256"] and len(data) == pin["bytes"], "raw SHA") if row["phase"] == "import": continue + guard_gate(row["guard"], Path(row["runtime_profile"]), row["runtime_name"]) stdout = (directory / row["phase"] / "stdout.log").read_text() printed = [normalize_report(json.loads(x[len(PREFIX):])) for x in stdout.splitlines() if x.startswith(PREFIX)] need(printed == [row["report"]], "raw/report mismatch") need(row["capture"]["actual_captured_pids"] == [row["report"]["pid"]], "PID mismatch") check_report(row["report"]) - need(row["report"]["stop_reason"] == "complete", "collection includes stopped phase") - if row["phase"] in ("P1", "P2", "P3", "P4"): - stage0 = next(r for r in rows if r["phase"] == row["report"]["input"] + "0") - duration = stage0["extrapolation"]["seconds_per_phase"] - startup = stage0["report"]["startup_wall_seconds"] - equal(row["projection"], {"seconds_per_phase": duration, "startup_wall_seconds": startup, - "projected_total_seconds": duration + startup, "limit_seconds": 1800, - "stage0_phase": stage0["phase"], "stop_reason": None}, "phase projection") - need(duration + startup <= 1800, "phase exceeds projected limit") if row["phase"] in ("R0", "O0"): - estimate = row["extrapolation"] - equal(estimate["seconds_per_phase"], row["report"]["elapsed_wall_seconds"] * 150 / - row["report"]["actual_minutes"], "extrapolation") + equal(row["extrapolation"], extrapolation(row["report"]), "extrapolation") def check_probe(text): diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py index afb3e63..21b683f 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py @@ -106,12 +106,68 @@ def checked_probe(path): def projection(stage0): evidence = stage0["extrapolation"] - seconds = evidence["seconds_per_phase"] + stage0["report"]["startup_wall_seconds"] + seconds = (evidence["seconds_per_phase"] + stage0["report"]["startup_wall_seconds"] + if evidence["seconds_per_phase"] is not None else None) return {"seconds_per_phase": evidence["seconds_per_phase"], "startup_wall_seconds": stage0["report"]["startup_wall_seconds"], "projected_total_seconds": seconds, "limit_seconds": LIMIT, "stage0_phase": stage0["phase"], - "stop_reason": "projected_over_limit" if seconds > LIMIT else None} + "stop_reason": "projected_over_limit" if seconds is not None and seconds > LIMIT else None} + + +OWNED_FILES = ("process.json", "started.json", "ended.json", "adapter-owned-cleanup.json", + "outer-owned-finally.json") + + +def extrapolation(report): + minutes = report["actual_minutes"] + return {"observed_minutes": minutes, "observed_seconds": report["elapsed_wall_seconds"], + "target_minutes": 150, + "seconds_per_phase": report["elapsed_wall_seconds"] * 150 / minutes if minutes else None, + "reason": None if minutes else "no_minutes_observed", + "method": "stage0 wall seconds per game minute; x1/x3 same conservative estimate"} + + +def stage_gate(before, after, importing=False): + require(all(after.get(k) == v for k, v in before.items()), "stage files changed") + added = set(after) - set(before) + require(not added or importing and all( + (n.endswith(".gd.uid") and n[:-4] in before) or + (n.endswith(".import") and n[:-7] in before) for n in added), "unexpected stage files") + + +def guard_gate(value, runtime, name): + expected = {"verified": True, "conditions": [True] * 5, "conditions_checked": 5, + "actual_user_data_dir": str(runtime), "expected_user_data_dir": str(runtime), + "globalized_probe": str(runtime / "guard-probe"), "custom_user_dir_name": name, + "fresh_before_parent_initialize": True, "profile_writes_before_guard": 0, + "project_settings_persisted": False} + require(all(k in value and type(value[k]) is type(v) and value[k] == v + for k, v in expected.items()), "profile guard failure") + + +def bound_report(folder, row): + printed = [line.split("=", 1)[1] for line in (folder / "stdout.log").read_text().splitlines() + if line.startswith("P28_01_PERF_REPORT=")] + require(len(printed) == 1, "exactly one raw report required") + report = normalize_report(json.loads(printed[0])) + require(row["capture"]["actual_captured_pids"] == [report["pid"]], "PID binding") + return report + + +def phase_schedule(rows): + """Caller appends each executed result; exceptions abort the consuming loop.""" + for index, phase in enumerate((("import", "", 0, 0, 0),) + PHASES): + label, source, _, _, _ = phase + forecast = None + if label in ("P1", "P2", "P3", "P4"): + stage0 = next(r for r in rows if r["phase"] == source + "0") + forecast = projection(stage0) + if forecast["stop_reason"]: + rows.append({"phase": label, "passed": False, "engines_started": 0, + "stop_reason": "projected_over_limit", "projection": forecast}) + continue + yield index, phase, forecast def run_engine(outer, command, folder, environment): @@ -140,7 +196,11 @@ def run_engine(outer, command, folder, environment): len(capture.get("actual_captured_pids", [])) == 1, all(raw.values()), not bad)) row = {"passed": clean, "process": result, "capture": capture, "raw": raw, "diagnostics": bad, "timeout_seconds": LIMIT, "argv": command} - write(folder / "process.json", row) + row["owned_files"] = {name: {"sha256": sha(folder / name), + "bytes": (folder / name).stat().st_size} + for name in OWNED_FILES if (folder / name).is_file()} + row["passed"] = clean and set(row["owned_files"]) == set(OWNED_FILES) + write(folder.parent / (folder.name + "-collector-receipt.json"), row) return row @@ -252,23 +312,16 @@ def main(): "build": {"engine_string": VERSION, "engine_hash": "ed1daf0bf", "engine_sha256": ENGINE_SHA, "project_commit": commit, "source_map_sha256": digest(before)}} public = (stage / "project.godot").read_bytes() - expected = before - for index, phase in enumerate((("import", "", 0, 0, 0),) + PHASES): + expected = standard.inventory(stage, stage=True) + require(expected == before, "initial whole stage differs") + for index, phase, forecast in phase_schedule(rows): label, source, speed, warmup, minutes = phase require(source_map(standard, ROOT) == before and standard.default_player(ROOT) == player, "source/player changed before phase") - require(source_map(standard, stage) == expected, "stage changed before phase") + require(standard.inventory(stage, stage=True) == expected, "stage changed before phase") require(all(sha(Path(p)) == pin for p, pin in script_pins.items()), "execution scripts changed") require(checked_probe(probe) == probe_check, "probe check changed") require(sha(args.fixture) == FIXTURE_SHA, "input_shortfall: changed input") - forecast = None - if label in ("P1", "P2", "P3", "P4"): - stage0 = next(r for r in rows if r["phase"] == source + "0") - forecast = projection(stage0) - if forecast["stop_reason"]: - rows.append({"phase": label, "passed": False, "engines_started": 0, - "stop_reason": "projected_over_limit", "projection": forecast}) - raise ValueError("projected_over_limit: " + label) name = "TheTree-PCK-tests-" + uuid.uuid4().hex + "-p28-startup" startup = standard.profile_path(name) require(not startup.exists(), "startup profile not fresh") @@ -293,39 +346,28 @@ def main(): row["probe_check"] = probe_check rows.append(row) require(row["passed"], "native phase failed; raw retained: " + label) - after = source_map(standard, stage) + after = standard.inventory(stage, stage=True) if label == "import": - require(all(after.get(k) == v for k, v in before.items()), "import changed source") - added = set(after) - set(before) - require(all((n.endswith(".gd.uid") and n[:-4] in before) or - (n.endswith(".import") and n[:-7] in before) for n in added), - "unexpected import-generated files") + stage_gate(expected, after, importing=True) expected = after else: require(after == expected, "stage changed during measurement") observation = json.loads(guard_path.read_text()) - require(observation["verified"] is True and observation["conditions"] == [True] * 5 - and observation["actual_user_data_dir"] == str(runtime) - and observation["fresh_before_parent_initialize"] is True - and observation["profile_writes_before_guard"] == 0 - and observation["project_settings_persisted"] is False, "profile guard failure") - raw = (out / label / "stdout.log").read_text() - printed = [line.split("=", 1)[1] for line in raw.splitlines() if line.startswith("P28_01_PERF_REPORT=")] - require(len(printed) == 1, "exactly one raw report required") - report = normalize_report(json.loads(printed[0])) - require(report["pid"] == row["capture"]["actual_captured_pids"][0], "PID binding") + guard_gate(observation, runtime, runtime_name) + row["runtime_profile"] = str(runtime) + row["runtime_name"] = runtime_name + report = bound_report(out / label, row) row.update(report=report, report_sha256=digest(report), guard=observation, guard_sha256=sha(guard_path)) - write(out / label / "report.json", report) + write(out / (label + "-report.json"), report) check_report(report) - require(report["stop_reason"] == "complete", "phase stopped: " + report["stop_reason"]) + row["stop_reason"] = report["stop_reason"] if label in ("R0", "O0"): - duration = report["elapsed_wall_seconds"] - row["extrapolation"] = {"observed_minutes": report["actual_minutes"], - "observed_seconds": duration, "target_minutes": 150, - "seconds_per_phase": duration * 150 / report["actual_minutes"], - "method": "stage0 wall seconds per game minute; x1/x3 same conservative estimate"} + row["extrapolation"] = extrapolation(report) require(standard.default_player(ROOT) == player, "default player changed") + require(source_map(standard, ROOT) == before, "source changed after phase") + require(sha(args.fixture) == FIXTURE_SHA, "input changed after phase") + require(all(sha(Path(p)) == pin for p, pin in script_pins.items()), "scripts changed after phase") except BaseException as caught: error = repr(caught) finally: diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd index c981ab5..c845cb1 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd @@ -533,6 +533,9 @@ func summary(segment: String) -> Dictionary: func finish(reason: String) -> void: ready_to_sample = false + # Early input shortfalls also need observed startup time for stage0 evidence. + if not report.has("startup_wall_seconds"): + report["startup_wall_seconds"] = float(Time.get_ticks_usec()) / 1000000.0 report["stop_reason"] = reason report["actual_minutes"] = int(clock.absolute_minute) - start_minute if start_us > 0 else 0 report["elapsed_wall_seconds"] = float(Time.get_ticks_usec() - start_us) / 1000000.0 if start_us > 0 else 0.0 diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index 145ea0d..2610cf5 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -6,6 +6,8 @@ import hashlib import json from pathlib import Path import sys +import tempfile +import time from types import SimpleNamespace import unittest from unittest.mock import patch @@ -17,6 +19,14 @@ import collect_p28_01 as collector HERE = Path(__file__).resolve().parent +def synthetic_guard(runtime=Path("private"), name="runtime"): + return {"verified": True, "conditions": [True] * 5, "conditions_checked": 5, + "actual_user_data_dir": str(runtime), "expected_user_data_dir": str(runtime), + "globalized_probe": str(runtime / "guard-probe"), "custom_user_dir_name": name, + "fresh_before_parent_initialize": True, "profile_writes_before_guard": 0, + "project_settings_persisted": False} + + def synthetic_report(): meta = {"machine": {"hw.model": "synthetic", "cores": 10, "memory_bytes": 24000000000}, "build": {"engine_string": collector.VERSION, "engine_hash": "ed1daf0bf", @@ -213,7 +223,8 @@ class ReportTests(unittest.TestCase): row = {"phase": "O0", "passed": True, "timeout_seconds": 1800, "raw": {"stdout.log": {"sha256": hashlib.sha256(raw).hexdigest(), "bytes": len(raw)}}, "report": r, "capture": {"actual_captured_pids": [123]}, - "extrapolation": {"seconds_per_phase": 30}} + "extrapolation": collector.extrapolation(r), + "guard": synthetic_guard(), "runtime_profile": "private", "runtime_name": "runtime"} receipt = {"source_before": {"x": "a"}, "source_after": {"x": "a"}, "default_player_before": {}, "default_player_after": {}, "cleanup_errors": [], "cleanup": [{"engine_ended": True}], "error": None, "passed": True, @@ -222,6 +233,8 @@ class ReportTests(unittest.TestCase): receipt["probe_check"] = {"sha256": hashlib.sha256(probe_text.encode()).hexdigest(), "passed": True} for phase in receipt["phases"]: phase["probe_check"] = receipt["probe_check"].copy() + phase["owned_files"] = {name: {"sha256": hashlib.sha256(raw).hexdigest(), "bytes": len(raw)} + for name in collector.OWNED_FILES} with patch.object(checker, "PHASES", {"O0": ("O", 1, 0, 10)}), \ patch.object(Path, "read_bytes", return_value=raw), \ patch.object(Path, "read_text", autospec=True, @@ -356,6 +369,166 @@ class ReportTests(unittest.TestCase): self.reject(lambda r: r["measurement"].update(render_gpu_ms=r["measurement"]["render_submit_wall_us"])) self.reject(lambda r: r["frames"][0].update(render_time_source="render_submit_wall_us")) + def test_j1_j2_actual_owned_path(self): + outer = collector.load_tool(collector.EXTERNAL_IMPORTS[1]) + # Child self-observation supplies the public probe_fn in this synthetic + # test, so no host ps permission is needed. Real Popen/lifecycle remain. + child = ( + "import os,sys,json,time,pathlib\n" + "mode=sys.argv[1]\n" + "identity={'pid':os.getpid(),'ppid':os.getppid(),'pgid':os.getpgrp()," + "'args':' '.join([sys.executable]+sys.argv)}\n" + "identity_path=pathlib.Path(sys.argv[0]).parent/(mode+'-identity')\n" + "tmp=identity_path.with_suffix('.tmp')\n" + "tmp.write_text(json.dumps(identity)); tmp.replace(identity_path)\n" + "pathlib.Path(sys.argv[sys.argv.index('--log-file')+1]).write_text('native raw\\n')\n" + "print('Godot Engine v4.7.2.stable.official.ed1daf0bf - https://godotengine.org',flush=True)\n" + "time.sleep(0.15)\n" + "if mode=='timeout': time.sleep(5)\n" + "for i in range(0 if mode=='missing' else 2 if mode=='duplicate' else 1):\n" + " print('P28_01_PERF_REPORT='+json.dumps({'pid':os.getpid()+int(mode=='pid')}),flush=True)\n" + "sys.exit(3 if mode=='exit' else 0)\n") + with tempfile.TemporaryDirectory() as temp: + base = Path(temp) + script = base / "child" + script.write_text(child) + def diagnostic(command, folder, timeout, env, **kwargs): + def probe(pid): + identity_path = base / (command[2] + "-identity") + deadline = time.monotonic() + 2 + while time.monotonic() < deadline: + if identity_path.exists(): + identity = json.loads(identity_path.read_text()) + if identity["pid"] == pid: + return identity + time.sleep(.005) + raise RuntimeError("child identity unavailable") + return outer.native.run_owned_diagnostic(command, folder, timeout, env, + probe_fn=probe, **kwargs) + for mode in ("ok", "exit", "timeout", "missing", "duplicate", "pid"): + folder = base / mode + def run_phase(command, output, limit, env, **kwargs): + self.assertEqual(limit, 1800) + return outer.run_phase(command, output, .3 if mode == "timeout" else 5, + env, diagnostic_fn=diagnostic, **kwargs) + # Record every collector write; the helper gets the original + # writer through the public dump_fn parameter below. + writes = [] + original_write = collector.write + def guarded_write(path, value): + self.assertFalse(Path(path).is_relative_to(folder), + "collector wrote inside owned folder") + writes.append(Path(path)) + original_write(path, value) + with self.assertRaises(AssertionError): + guarded_write(folder / "process.json", {}) + def real_phase(*args, **kwargs): + kwargs["dump_fn"] = original_write + return run_phase(*args, **kwargs) + with self.subTest(mode=mode), patch.object(collector, "live_engines", return_value=[]), \ + patch.object(collector, "write", side_effect=guarded_write): + row = collector.run_engine(SimpleNamespace(run_phase=real_phase), + [sys.executable, str(script), mode], folder, {}) + self.assertEqual(writes, [base / (mode + "-collector-receipt.json")]) + self.assertEqual(set(row["owned_files"]), set(collector.OWNED_FILES), row) + for name, pin in row["owned_files"].items(): + self.assertEqual(collector.sha(folder / name), pin["sha256"]) + self.assertEqual(json.loads((folder / "process.json").read_text()), row["process"]) + if mode in ("exit", "timeout"): + self.assertFalse(row["passed"]) + elif mode == "ok": + self.assertTrue(row["passed"], row) + report = collector.bound_report(folder, row) + self.assertEqual(report["pid"], row["process"]["pid"]) + else: + with self.assertRaises(ValueError): + collector.bound_report(folder, row) + # Actual owned receipts are immutable after return. The collector + # detects missing files even when the helper reports success. + def missing_file(*args, **kwargs): + result = outer.run_phase(*args, diagnostic_fn=diagnostic, **kwargs) + (args[1] / "ended.json").unlink() + return result + with patch.object(collector, "live_engines", return_value=[]): + row = collector.run_engine(SimpleNamespace(run_phase=missing_file), + [sys.executable, str(script), "ok"], base / "lost", {}) + self.assertFalse(row["passed"]) + cleanup, errors = outer.finish_captured(outer.OWNED) + self.assertFalse(errors) + self.assertTrue(all(r["engine_ended"] for r in cleanup)) + + def test_j3_guard_and_whole_inventory(self): + guard = synthetic_guard() + collector.guard_gate(guard, Path("private"), "runtime") + for key in guard: + for missing in (True, False): + bad = copy.deepcopy(guard) + if missing: + del bad[key] + else: + bad[key] = "wrong" + with self.subTest(key=key, missing=missing), self.assertRaises(ValueError): + collector.guard_gate(bad, Path("private"), "runtime") + standard = collector.load_tool(collector.EXTERNAL_IMPORTS[0]) + with tempfile.TemporaryDirectory() as temp: + stage = Path(temp) + (stage / "source.gd").write_text("source") + before = standard.inventory(stage, stage=True) + collector.stage_gate(before, before) + (stage / "source.gd.uid").write_text("uid") + imported = standard.inventory(stage, stage=True) + collector.stage_gate(before, imported, importing=True) + with self.assertRaises(ValueError): + collector.stage_gate(before, imported) + (stage / "untracked.txt").write_text("unexpected") + with self.assertRaises(ValueError): + collector.stage_gate(imported, standard.inventory(stage, stage=True)) + with self.assertRaises(ValueError): + collector.stage_gate(before, standard.inventory(stage, stage=True), importing=True) + with self.assertRaises(ValueError): + collector.stage_gate(imported, {}) + + def test_j4_phase_stop_propagation(self): + def execute(minutes=1, duration=1, failure=False): + rows, launched = [], [] + try: + for _, phase, forecast in collector.phase_schedule(rows): + label = phase[0] + launched.append(label) + if label == "R0" and failure: + collector.require(False, "native phase failed") + report = {"actual_minutes": minutes, + "elapsed_wall_seconds": duration if phase[1] == "R" else 1, + "startup_wall_seconds": 1, "stop_reason": "simulation_overloaded"} + rows.append({"phase": label, "report": report, "projection": forecast, + "extrapolation": collector.extrapolation(report)}) + except ValueError: + pass + return rows, launched + rows, launched = execute() + self.assertEqual(launched, ["import", "R0", "P1", "P2", "O0", "P3", "P4"]) + self.assertEqual(rows[1]["report"]["stop_reason"], "simulation_overloaded") + self.assertEqual(execute(failure=True)[1], ["import", "R0"]) + rows, launched = execute(duration=20) + self.assertEqual(launched, ["import", "R0", "O0", "P3", "P4"]) + self.assertEqual([r["phase"] for r in rows if r.get("engines_started") == 0], + ["P1", "P2"]) + rows, launched = execute(minutes=0) + self.assertEqual(len(launched), 7) + self.assertIsNone(rows[1]["extrapolation"]["seconds_per_phase"]) + self.assertEqual(rows[1]["extrapolation"]["reason"], "no_minutes_observed") + self.assertIsNone(rows[2]["projection"]["projected_total_seconds"]) + shortfall = synthetic_report() + shortfall.update(stop_reason="input_shortfall", frames=[], actual_minutes=0) + checker.check_report(shortfall) + self.assertIsNone(collector.extrapolation(shortfall)["seconds_per_phase"]) + stopped = synthetic_report() + stopped["stop_reason"] = "timeout" + checker.check_report(stopped) + stopped["stop_reason"] = "unrecognized_stop" + with self.assertRaises(ValueError): + checker.check_report(stopped) + if __name__ == "__main__": unittest.main(verbosity=2) From 3ac3243dfb691774bc2db25d8a6720bff47cf311 Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 21:48:59 +0900 Subject: [PATCH 4/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/check_p28_01_report.py | 91 +++++++++++++++- .../p28-01/collector/collect_p28_01.py | 46 ++++---- .../p28-01/collector/measure_p28_01.gd | 18 ++-- .../p28-01/collector/test_collect_p28_01.py | 101 ++++++++++++++++-- 4 files changed, 222 insertions(+), 34 deletions(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py index 0a52ab2..c78e94b 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py @@ -8,6 +8,24 @@ from pathlib import Path import re PREFIX = "P28_01_PERF_REPORT=" +RAW_SOURCE = "clock.performance_budget (product diagnostic, raw, not a verdict)" +CAP_SOURCE = "SPEC §5 phase cap" +DEADLINE_SOURCE = "H6 probe deadline (cap−60s)" +VERDICT_SCOPE = ("Budget verdicts come only from windowed phases, using kernel samples, for " + "simulation_x1, simulation_x3 and main_thread_stall. Save, load and path_query " + "verdicts are null in this collector, reason: not_measured_with_kernel_definition.") +RAW_FIELDS = {"budget_at_warmup_end", "budget_at_phase_end", "kernel_at_warmup_end", "kernel_at_phase_end"} +METRICS = {"simulation_x1", "simulation_x3", "main_thread_stall"} +R02_FIELDS = { + **{"x1_outer_advance_one_minute_wall_" + stat: + ("advance_one_minute_wall_ms_x1." + stat, stat, + "headless outer advance_one_minute wall; not kernel-defined") for stat in ("mean", "p95", "max")}, + "path_cold_p95": ("path_after_tick_ms.found_cold.p95", "p95", "headless probe path timing; not kernel-defined"), + "snapshot_mean": ("save_load_ms.snapshot.mean", "mean", "headless probe snapshot timing; not kernel-defined"), + **{kind + "_" + stat: ("save_load_ms." + kind + "." + stat, stat, + "headless probe " + kind + " timing; not kernel-defined") + for kind in ("manual", "autosave", "load") for stat in ("mean", "max")}, +} PHASES = {"R0": ("R", 1, 0, 10), "P1": ("R", 1, 30, 120), "P2": ("R", 3, 30, 120), "O0": ("O", 1, 0, 10), "P3": ("O", 1, 30, 120), "P4": ("O", 3, 30, 120)} @@ -28,6 +46,64 @@ INTEGER_FIELDS = { OPAQUE_FIELDS = {"rng_streams", "startup", "kernel_at_warmup_end", "kernel_at_phase_end", "operations_at_end", "restore_result", "save_policy_after"} +def check_budget_scope(value, report_paths=(), path=(), raw=False): + """Walk the entire receipt; privileges are tied to exact report locations.""" + if isinstance(value, list): + for i, child in enumerate(value): + check_budget_scope(child, report_paths, path + (i,), raw) + return + if not isinstance(value, dict): + return + raw_root = any(path == root + (name,) for root in report_paths for name in RAW_FIELDS) + verdict = any(len(path) == len(root) + 2 and path[:len(root)] == root + and path[-2] == "budget_verdict" and path[-1] in METRICS for root in report_paths) + has_pass = bool({"passed", "within_budget"} & value.keys()) + in_report = any(path[:len(root)] == root for root in report_paths) + if has_pass and in_report and not raw: + need(verdict, "pass flag copied outside kernel verdict") + if "budget_verdict" in value: + need(path in report_paths and isinstance(value["budget_verdict"], dict) + and set(value["budget_verdict"]) <= METRICS, "budget verdict location/metrics") + if has_pass and {"limit", "limit_us", "limit_ms"} & value.keys(): + need(verdict, "budget verdict outside report.budget_verdict") + if raw_root: + need(value.get("source") == RAW_SOURCE, "raw diagnostic source missing") + keys(value, ("source", "data")) + if not raw: + need("budget_exceeded" not in value, "copied product budget_exceeded") + need("limit_us" not in value or verdict, "copied product limit_us") + if "limit_seconds" in value: + need(path and path[-1] in ("projection", "phase_stop", "probe_deadline"), "limit location") + deadline = path[-1] == "probe_deadline" + need(not has_pass and value["limit_seconds"] == (1740 if deadline else 1800) + and value.get("source") == (DEADLINE_SOURCE if deadline else CAP_SOURCE), "execution limit") + for key, child in value.items(): + check_budget_scope(child, report_paths, path + (key,), raw or (raw_root and key == "data")) + + +def check_admission(admission): + check_budget_scope(admission) + need(admission.get("budget_verdict_scope") == VERDICT_SCOPE, "admission verdict scope") + reused = admission["reused_r02"] + def no_verdict_fields(value): + if isinstance(value, dict): + need(all(not k.startswith(("limit", "budget")) and k not in ("passed", "within_budget") + for k in value), "verdict fields in reused_r02") + for child in value.values(): + no_verdict_fields(child) + elif isinstance(value, list): + for child in value: + no_verdict_fields(child) + no_verdict_fields(reused) + observations = reused["observations"] + need(set(observations) == set(R02_FIELDS), "r02 observations") + for name, (field, statistic, scope) in R02_FIELDS.items(): + item = observations[name] + keys(item, ("value", "unit", "statistic", "scope", "r02_field")) + need(number(item["value"]) and item["value"] >= 0, "r02 value") + need((item["unit"], item["statistic"], item["scope"], item["r02_field"]) == + ("ms", statistic, scope, field), "r02 observation provenance") + def normalize_report(value, path=()): """Single ingestion boundary, also used when checking raw stdout binding.""" @@ -187,6 +263,12 @@ def interval(report, name): def check_report(report): + check_budget_scope(report, ((),)) + for name in RAW_FIELDS: + keys(report[name], ("source", "data")) + equal(report["probe_deadline"], {"limit_seconds": 1740, "source": DEADLINE_SOURCE}, "probe deadline") + equal(report["budget_verdict"], budget_verdict(report["budget_at_warmup_end"]["data"], + report["budget_at_phase_end"]["data"], report["speed"]), "kernel interval budget") keys(report, ("schema", "pid", "phase", "input", "speed", "metadata", "input_sha256", "frames", "stop_reason", "warmup", "measurement", "actual_minutes", "elapsed_wall_seconds", "kernel_at_phase_end", "operations_at_end", "end_wall", @@ -329,8 +411,8 @@ def check_report(report): interval(report, name) need(report["budget_scope"] == "kernel process_real_delta only; excludes observer_us", "budget scope") need(report["render_submit_note"] == "CPU側の描画提出wall、GPU時間ではない", "render submit scope") - equal(report["budget_verdict"], budget_verdict(report["budget_at_warmup_end"], - report["budget_at_phase_end"], speed), "kernel interval budget") + equal(report["budget_verdict"], budget_verdict(report["budget_at_warmup_end"]["data"], + report["budget_at_phase_end"]["data"], speed), "kernel interval budget") need(number(report["startup_wall_seconds"]) and report["startup_wall_seconds"] >= 0, "startup timing") for save in report["save_events"]: keys(save, ("frame", "game_minute", "ok", "operation", "path", "sample_counts")) @@ -347,6 +429,10 @@ def check_report(report): def check_receipt(receipt, directory): from collect_p28_01 import OWNED_FILES, projection, extrapolation, guard_gate + check_budget_scope(receipt, tuple(("phases", i, "report") + for i, row in enumerate(receipt["phases"]) if "report" in row)) + check_admission(receipt["admission"]) + equal(receipt["admission"], json.loads((directory / "admission.json").read_text()), "admission binding") need(receipt["source_before"] == receipt["source_after"], "source map changed") need(receipt["default_player_before"] == receipt["default_player_after"], "player changed") need(not receipt["cleanup_errors"] and all(r["engine_ended"] is True for r in receipt["cleanup"]), "cleanup") @@ -359,6 +445,7 @@ def check_receipt(receipt, directory): rows = receipt["phases"] need([r["phase"] for r in rows] == ["import", *PHASES], "phase order") for row in rows: + equal(row["phase_stop"], {"limit_seconds": 1800, "source": CAP_SOURCE}, "phase cap origin") forecast = None if row["phase"] in ("P1", "P2", "P3", "P4"): source = PHASES[row["phase"]][0] diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py index 21b683f..bd803a6 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py @@ -13,7 +13,7 @@ import uuid from datetime import datetime, timezone sys.dont_write_bytecode = True -from check_p28_01_report import check_report, check_receipt, check_probe, normalize_report +from check_p28_01_report import check_report, check_receipt, check_probe, normalize_report, check_admission, R02_FIELDS, VERDICT_SCOPE, CAP_SOURCE HERE = Path(__file__).resolve().parent ROOT = HERE.parents[5] FIXTURE_SHA = "eb4f770071eb07cd7e136fe54c3f78768cc8de7a4264e62a9af1f06a8f90f9bd" @@ -110,7 +110,7 @@ def projection(stage0): if evidence["seconds_per_phase"] is not None else None) return {"seconds_per_phase": evidence["seconds_per_phase"], "startup_wall_seconds": stage0["report"]["startup_wall_seconds"], - "projected_total_seconds": seconds, "limit_seconds": LIMIT, + "projected_total_seconds": seconds, "limit_seconds": LIMIT, "source": CAP_SOURCE, "stage0_phase": stage0["phase"], "stop_reason": "projected_over_limit" if seconds is not None and seconds > LIMIT else None} @@ -165,7 +165,8 @@ def phase_schedule(rows): forecast = projection(stage0) if forecast["stop_reason"]: rows.append({"phase": label, "passed": False, "engines_started": 0, - "stop_reason": "projected_over_limit", "projection": forecast}) + "stop_reason": "projected_over_limit", "projection": forecast, + "phase_stop": {"limit_seconds": LIMIT, "source": CAP_SOURCE}}) continue yield index, phase, forecast @@ -195,7 +196,8 @@ def run_engine(outer, command, folder, environment): capture.get("passed") is True, capture.get("all_captured_ended") is True, len(capture.get("actual_captured_pids", [])) == 1, all(raw.values()), not bad)) row = {"passed": clean, "process": result, "capture": capture, "raw": raw, - "diagnostics": bad, "timeout_seconds": LIMIT, "argv": command} + "diagnostics": bad, "timeout_seconds": LIMIT, "argv": command, + "phase_stop": {"limit_seconds": LIMIT, "source": CAP_SOURCE}} row["owned_files"] = {name: {"sha256": sha(folder / name), "bytes": (folder / name).stat().st_size} for name in OWNED_FILES if (folder / name).is_file()} @@ -218,6 +220,24 @@ def inputs(readonly): return {"manifest_sha256": sha(manifest_path), "files": pins} +def reused_observations(readonly, pins): + relative = "run-r02/after/evidence/report.json" + path = readonly / relative + require(sha(path) == pins["files"][relative], "r02 report SHA changed") + raw = json.loads(path.read_text()) + observations = {} + for name, (field, statistic, scope) in R02_FIELDS.items(): + value = raw + for part in field.split("."): + value = value[part] + observations[name] = {"value": value, "unit": "ms", "statistic": statistic, + "scope": scope, "r02_field": field} + return {"execution_sha256": pins["files"]["run-r02/execution.json"], + "report_sha256": pins["files"][relative], + "scope": "x1 headless Operations OFF; reused without remeasurement", + "observations": observations} + + def main(): parser = argparse.ArgumentParser(description=__doc__) parser.add_argument("--readonly", type=Path, required=True) @@ -262,19 +282,9 @@ def main(): admission = {"commit": commit, "source_map": before, "source_map_sha256": digest(before), "readonly": pins, "engine_sha256": ENGINE_SHA, "engine_version": VERSION, "fixture_sha256": FIXTURE_SHA, "planned_argv": planned, "phases": PHASES, - "reused_r02": {"execution_sha256": pins["files"]["run-r02/execution.json"], - "report_sha256": pins["files"]["run-r02/after/evidence/report.json"], - "scope": "x1 headless Operations OFF; reused without remeasurement", - "tick_ms": {"mean": 826.6, "p95": 1702.7, "max": 2918.1}, - "path_cold_p95_ms": 0.61, "snapshot_mean_ms": 77.6, - "manual_save_ms": 297, "autosave_ms": 327, - "load_mean_ms": 3193, "load_max_ms": 3368, - "budget_comparisons_ms": { - "x1_tick_mean": {"value": 826.6, "limit": 4, "passed": False}, - "path_cold_p95": {"value": 0.61, "limit": 2, "passed": True}, - "manual_save": {"value": 297, "limit": 5000, "passed": True}, - "autosave": {"value": 327, "limit": 5000, "passed": True}, - "load_max": {"value": 3368, "limit": 8000, "passed": True}}}} + "budget_verdict_scope": VERDICT_SCOPE, + "reused_r02": reused_observations(args.readonly, pins)} + check_admission(admission) if args.check: print(json.dumps(dict(admission, stages_created=0, engines_started=0), ensure_ascii=False, indent=2)) return 0 @@ -374,7 +384,7 @@ def main(): cleanup, cleanup_errors = outer.finish_captured(outer.OWNED) after = source_map(standard, ROOT) player_after = standard.default_player(ROOT) - receipt = {"phases": rows, "error": error, "source_before": before, "source_after": after, + receipt = {"admission": admission, "phases": rows, "error": error, "source_before": before, "source_after": after, "probe_check": probe_check, "default_player_before": player, "default_player_after": player_after, "cleanup": cleanup, "cleanup_errors": cleanup_errors, diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd index c845cb1..0842b04 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd @@ -266,7 +266,9 @@ func begin() -> void: "render_submit_note": "CPU側の描画提出wall、GPU時間ではない", "observer_note": "observer_us includes reads, serialization and frame emission; excludes its own timing line and final report; never subtracted", "sample_definition": "is_minute_sample marks a changed game minute; other frames carry counts_from_minute", - "budget_at_warmup_end": {}, "save_events": save_events, "key_form": key_forms, + "budget_at_warmup_end": {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": {}}, + "kernel_at_warmup_end": {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": null, "reason": "warmup_not_reached"}, + "probe_deadline": {"limit_seconds": 1740, "source": "H6 probe deadline (cap−60s)"}, "save_events": save_events, "key_form": key_forms, "count_definitions": {"registered": "service collections; walkable cells", "active": "guests exclude SPAWNING/LEAVING/DESPAWNING; staff current attended unended shift; facilities OPERATING", "drawn": "world_preview submitted model serial and viewport geometry"}, @@ -355,8 +357,8 @@ func begin() -> void: last_stall_count = initial_budget.main_thread_stall.lifetime_count if warmup == 0: warmup_ended = true - report["kernel_at_warmup_end"] = clock.get_performance_reports() - report["budget_at_warmup_end"] = initial_budget + report["kernel_at_warmup_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": clock.get_performance_reports()} + report["budget_at_warmup_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": initial_budget} report["startup_wall_seconds"] = float(start_us) / 1000000.0 report["start_minute"] = start_minute report["start_wall"] = Time.get_unix_time_from_system() @@ -430,8 +432,8 @@ func sample(observer_started_us: int) -> void: previous_minute = minute if not warmup_ended and minute - start_minute >= warmup: warmup_ended = true - report["kernel_at_warmup_end"] = clock.get_performance_reports() - report["budget_at_warmup_end"] = budget_snapshot() + report["kernel_at_warmup_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": clock.get_performance_reports()} + report["budget_at_warmup_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": budget_snapshot()} if warmup > 0: measurement_start = minute var operations: Dictionary = runtime.get_operations_report() @@ -540,9 +542,9 @@ func finish(reason: String) -> void: report["actual_minutes"] = int(clock.absolute_minute) - start_minute if start_us > 0 else 0 report["elapsed_wall_seconds"] = float(Time.get_ticks_usec() - start_us) / 1000000.0 if start_us > 0 else 0.0 report["end_wall"] = Time.get_unix_time_from_system() - report["kernel_at_phase_end"] = clock.get_performance_reports() - report["budget_at_phase_end"] = budget_snapshot() - report["budget_verdict"] = kernel_verdict(report.budget_at_warmup_end, report.budget_at_phase_end) + report["kernel_at_phase_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": clock.get_performance_reports()} + report["budget_at_phase_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": budget_snapshot()} + report["budget_verdict"] = kernel_verdict(report.budget_at_warmup_end.data, report.budget_at_phase_end.data) report["operations_at_end"] = runtime.get_operations_report() report["warmup"] = summary("warmup") report["measurement"] = summary("measurement") diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index 2610cf5..fd8f1d0 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -118,10 +118,97 @@ def synthetic_report(): "statistics": {"count": 10, "average_us": 3000, "p95_us": 3000, "maximum_us": 3000}} for k, aggregate, limit in (("simulation_x1", "average", 4000), ("main_thread_stall", "maximum", 50000))} + for name in checker.RAW_FIELDS: + report[name] = {"source": checker.RAW_SOURCE, "data": report[name]} + report["probe_deadline"] = {"limit_seconds": 1740, "source": checker.DEADLINE_SOURCE} return report +def synthetic_admission(): + return {"budget_verdict_scope": checker.VERDICT_SCOPE, "reused_r02": {"observations": { + name: {"value": 1.25, "unit": "ms", "statistic": stat, "scope": scope, "r02_field": field} + for name, (field, stat, scope) in checker.R02_FIELDS.items()}}} + + class ReportTests(unittest.TestCase): + def test_r1_recursive_verdict_scope(self): + report = synthetic_report() + receipt = {"admission": synthetic_admission(), "phases": [{"report": report, "passed": True}], + "process": {"passed": True}, "capture": {"passed": True}, + "probe_check": {"passed": True}, "passed": True} + checker.check_budget_scope(receipt, (("phases", 0, "report"),)) + for flag in ("passed", "within_budget"): + for limit in ("limit", "limit_us", "limit_ms"): + for location in ("admission", "extra"): + broken = copy.deepcopy(receipt) + broken.setdefault(location, {})["nested"] = [{flag: True, limit: 4}] + with self.subTest(flag=flag, limit=limit, location=location), self.assertRaises(ValueError): + checker.check_budget_scope(broken, (("phases", 0, "report"),)) + self.reject(lambda r: r.update(extra={"passed": True, "limit": 4})) + self.reject(lambda r: r["budget_verdict"].update(path_query=copy.deepcopy(r["budget_verdict"]["simulation_x1"]))) + + def test_r2_raw_diagnostics_preserved(self): + r = synthetic_report() + original = [{"limit_us": 4000, "budget_exceeded": True, "measured_us": 5000}] + r["kernel_at_phase_end"]["data"] = copy.deepcopy(original) + checker.check_report(r) + self.assertEqual(r["kernel_at_phase_end"]["data"], original) + for name in checker.RAW_FIELDS: + self.reject(lambda r, name=name: r[name].pop("source")) + self.reject(lambda r, name=name: r[name].update(source="invented")) + for field, value in (("budget_exceeded", False), ("limit_us", 4000), ("passed", True)): + self.reject(lambda r, field=field, value=value: r.update(extra={field: value})) + self.reject(lambda r: r["kernel_at_phase_end"].update(data={"passed": True, "limit_us": 4000})) + + def test_r3_execution_limit_origin(self): + projection = collector.projection({"phase": "R0", "report": {"startup_wall_seconds": 1}, + "extrapolation": {"seconds_per_phase": 20}}) + valid = {"projection": projection, + "phase_stop": {"limit_seconds": 1800, "source": checker.CAP_SOURCE}, + "probe_deadline": {"limit_seconds": 1740, "source": checker.DEADLINE_SOURCE}} + checker.check_budget_scope(valid) + for location in valid: + for change in ({"passed": True}, {"limit_seconds": 1799}, {"source": "wrong"}): + broken = copy.deepcopy(valid) + broken[location].update(change) + with self.subTest(location=location, change=change), self.assertRaises(ValueError): + checker.check_budget_scope(broken) + with self.assertRaises(ValueError): + checker.check_budget_scope({"elsewhere": {"limit_seconds": 1800, "source": checker.CAP_SOURCE}}) + self.reject(lambda r: r["probe_deadline"].update(limit_seconds=1800)) + + def test_r4_observations_and_pinned_input(self): + admission = synthetic_admission() + checker.check_admission(admission) + for key in ("limit", "limit_ms", "passed", "budget_comparisons_ms", "budget_exceeded"): + broken = copy.deepcopy(admission) + broken["reused_r02"]["nested"] = [{key: 4}] + with self.subTest(key=key), self.assertRaises(ValueError): + checker.check_admission(broken) + for key in ("unit", "statistic", "scope", "r02_field"): + broken = copy.deepcopy(admission) + broken["reused_r02"]["observations"]["manual_max"].pop(key) + with self.subTest(key=key), self.assertRaises(ValueError): + checker.check_admission(broken) + # Synthetic source with distinct exact values tests extraction, not rounded constants. + raw = {} + for i, (field, _, _) in enumerate(checker.R02_FIELDS.values()): + target = raw + parts = field.split(".") + for part in parts[:-1]: + target = target.setdefault(part, {}) + target[parts[-1]] = i + .123456789 + pins = {"files": {"run-r02/after/evidence/report.json": "a" * 64, + "run-r02/execution.json": "b" * 64}} + with patch.object(collector, "sha", return_value="a" * 64), \ + patch.object(Path, "read_text", return_value=json.dumps(raw)): + reused = collector.reused_observations(Path("readonly"), pins) + for i, name in enumerate(checker.R02_FIELDS): + self.assertEqual(reused["observations"][name]["value"], i + .123456789) + checker.check_admission({"budget_verdict_scope": checker.VERDICT_SCOPE, "reused_r02": reused}) + with patch.object(collector, "sha", return_value="c" * 64), self.assertRaises(ValueError): + collector.reused_observations(Path("readonly"), pins) + def reject(self, mutate): report = synthetic_report() mutate(report) @@ -225,20 +312,22 @@ class ReportTests(unittest.TestCase): "report": r, "capture": {"actual_captured_pids": [123]}, "extrapolation": collector.extrapolation(r), "guard": synthetic_guard(), "runtime_profile": "private", "runtime_name": "runtime"} - receipt = {"source_before": {"x": "a"}, "source_after": {"x": "a"}, + receipt = {"admission": synthetic_admission(), "source_before": {"x": "a"}, "source_after": {"x": "a"}, "default_player_before": {}, "default_player_after": {}, "cleanup_errors": [], "cleanup": [{"engine_ended": True}], "error": None, "passed": True, "phases": [{"phase": "import", "passed": True, "timeout_seconds": 1800, "raw": {}}, row]} probe_text = (HERE / "measure_p28_01.gd").read_text() receipt["probe_check"] = {"sha256": hashlib.sha256(probe_text.encode()).hexdigest(), "passed": True} for phase in receipt["phases"]: + phase["phase_stop"] = {"limit_seconds": 1800, "source": checker.CAP_SOURCE} phase["probe_check"] = receipt["probe_check"].copy() phase["owned_files"] = {name: {"sha256": hashlib.sha256(raw).hexdigest(), "bytes": len(raw)} for name in collector.OWNED_FILES} with patch.object(checker, "PHASES", {"O0": ("O", 1, 0, 10)}), \ patch.object(Path, "read_bytes", return_value=raw), \ patch.object(Path, "read_text", autospec=True, - side_effect=lambda p: probe_text if p.name == "measure_p28_01.gd" else raw.decode()): + side_effect=lambda p: (probe_text if p.name == "measure_p28_01.gd" else + json.dumps(receipt["admission"]) if p.name == "admission.json" else raw.decode())): checker.check_receipt(receipt, Path("synthetic")) for label, mutate in { "source": lambda x: x.update(source_after={"x": "b"}), @@ -279,9 +368,9 @@ class ReportTests(unittest.TestCase): for reason, count in (("interval_exceeds_window", 600), ("no_interval_samples", 30), ("counts_unavailable", None)): r = synthetic_report() - r["budget_at_phase_end"]["simulation_x1"]["lifetime_count"] = count - r["budget_verdict"] = checker.budget_verdict(r["budget_at_warmup_end"], - r["budget_at_phase_end"], 1) + r["budget_at_phase_end"]["data"]["simulation_x1"]["lifetime_count"] = count + r["budget_verdict"] = checker.budget_verdict(r["budget_at_warmup_end"]["data"], + r["budget_at_phase_end"]["data"], 1) self.assertEqual(r["budget_verdict"]["simulation_x1"]["reason"], reason) self.assertIsNone(r["budget_verdict"]["simulation_x1"]["value"]) checker.check_report(r) @@ -322,7 +411,7 @@ class ReportTests(unittest.TestCase): r["metadata"]["machine"]["memory_bytes"] = 24000000000.0 r["pid"] = 123.0 r["frames"][0]["registered"]["guests"] = 3.0 - r["budget_at_phase_end"]["simulation_x1"]["samples_us"] = [3000.0] * 40 + r["budget_at_phase_end"]["data"]["simulation_x1"]["samples_us"] = [3000.0] * 40 normalized = collector.normalize_report(json.loads(json.dumps(r))) checker.check_report(normalized) self.assertIs(type(normalized["pid"]), int) From a09681e2875413fe4b0e6e790b1404adb2e30608 Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 22:37:35 +0900 Subject: [PATCH 5/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/check_p28_01_report.py | 104 +++++++++++++ .../p28-01/collector/collect_p28_01.py | 7 +- .../p28-01/collector/measure_p28_01.gd | 124 +++++++++++++-- .../p28-01/collector/test_collect_p28_01.py | 146 +++++++++++++++++- 4 files changed, 368 insertions(+), 13 deletions(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py index c78e94b..886a3ff 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py @@ -6,6 +6,7 @@ import json import math from pathlib import Path import re +import struct PREFIX = "P28_01_PERF_REPORT=" RAW_SOURCE = "clock.performance_budget (product diagnostic, raw, not a verdict)" @@ -35,6 +36,9 @@ FORBIDDEN = ("_toggle_pause", "clear(", "enable_production_", "set_paused(false) # Only declared collector fields are normalized. Product dictionaries (RNG, # startup, raw reports) retain their original JSON representation. INTEGER_FIELDS = { + "engine_frame_pre", "engine_frame_post", "pre_order", "post_order", + "minute_at_frame_start", "minute_after", "speed_at_frame_start", + "allowed_ticks_observation", "short_of_allowed_frames", "cores", "memory_bytes", "pid", "seed", "frame", "game_start", "game_end", "game_minute", "minutes_advanced", "start_minute", "end_minute", "opening_minute", "actual_minutes", "warmup_target", "measurement_target", "speed", "speed_after", "backlog", @@ -233,6 +237,9 @@ def interval(report, name): need(set(observation) == {"frame_wall_us", "sim_us_per_minute", "stall_over_50000_us"}, "frame observation must not contain verdict") need(value["frames"] == len(rows), "frame count") + need(value.get("short_of_allowed_frames") == + sum(f["minutes_advanced"] < f["allowed_ticks_observation"] for f in rows), + "short-of-allowed observation count") need(value["actual_minutes"] == sum(f["minutes_advanced"] for f in rows), "false interval duration") for field, expected in (("start_minute", rows[0]["game_start"] if rows else None), ("end_minute", rows[-1]["game_end"] if rows else None), @@ -325,7 +332,15 @@ def check_report(report): previous_wall = report["start_wall"] previous_drawing = None previous_counts = None + keys(report, ("baseline",)) + previous_pair = report["baseline"] + check_pair(previous_pair) + need(previous_pair.get("excluded_from_statistics") is True and + previous_pair["minute_after"] == previous and previous_pair.get("wall") == previous_wall, + "missing/exposed baseline") for index, frame in enumerate(frames): + check_pair(frame, previous_pair, speed) + previous_pair = frame keys(frame, ("frame", "game_start", "game_end", "minutes_advanced", "frame_wall_us", "wall", "wall_start", "speed", "paused", "segment", "registered", "active", "drawn", "seed", "rng_streams", "metadata", "input_sha256", "preparation_sha256", "render_cpu_raw_ms", @@ -475,18 +490,107 @@ def check_receipt(receipt, directory): stdout = (directory / row["phase"] / "stdout.log").read_text() printed = [normalize_report(json.loads(x[len(PREFIX):])) for x in stdout.splitlines() if x.startswith(PREFIX)] need(printed == [row["report"]], "raw/report mismatch") + equal(audio_close(stdout, row["report"]), row["audio_close"], "audio close binding") need(row["capture"]["actual_captured_pids"] == [row["report"]["pid"]], "PID mismatch") check_report(row["report"]) if row["phase"] in ("R0", "O0"): equal(row["extrapolation"], extrapolation(row["report"]), "extrapolation") +def decode_f64(value): + need(isinstance(value, str) and re.fullmatch("[0-9a-f]{16}", value) is not None, + "missing/malformed f64 evidence") + result = struct.unpack("= 0, "invalid pair integer") + for key in ("paused_at_frame_start", "paused_after", "skip_at_frame_start"): + need(type(pair[key]) is bool, "invalid pair boolean") + need(pair["engine_frame_pre"] == pair["engine_frame_post"] and + pair["post_order"] == pair["pre_order"] + 1, "unpaired frame") + acc = decode_f64(pair["acc_at_frame_start_f64_hex"]) + after = decode_f64(pair["acc_after_f64_hex"]) + delta = decode_f64(pair["process_delta_f64_hex"]) + decode_f64(pair["post_delta_f64_hex"]) + need(pair["process_delta_f64_hex"] == pair["post_delta_f64_hex"], "different process deltas") + if previous is None: + # First complete pair is an excluded anchor, never an inferred pre-begin state. + return + need(pair["engine_frame_pre"] == previous["engine_frame_post"] + 1 and + pair["pre_order"] == previous["post_order"] + 1, "frame order gap") + need(pair["minute_at_frame_start"] == previous["minute_after"] and + pair["acc_at_frame_start_f64_hex"] == previous["acc_after_f64_hex"], "pair continuity") + need(pair["speed_at_frame_start"] == speed, "cadence speed") + advanced = pair["minute_after"] - pair["minute_at_frame_start"] + allowed = 0 + if not pair["skip_at_frame_start"] and not pair["paused_at_frame_start"] and speed > 0 and delta > 0: + acc += delta * speed + allowed = min(int(acc / (10.0 / 60.0)), 8) + need(0 <= advanced <= allowed, "cadence upper bound") + need(type(pair.get("allowed_ticks_observation")) is int and + pair["allowed_ticks_observation"] == allowed, "allowed tick observation") + for _ in range(advanced): + acc -= 10.0 / 60.0 + need(struct.pack("= 0, + "audio close wait") + else: + need(not report["main_added"] or not report["audio_owner_present"], "owner drain bypassed") + need(row == {"coordinator": False, "reason": + "no_audio_owner" if report["main_added"] else "main_not_added"}, + "invalid no-owner receipt") + return row + + def check_probe(text): # The SceneTree bootstrap name is required; all other initialization is forbidden. body = text.replace("func _initialize()", "func BOOTSTRAP()") for token in FORBIDDEN: need(token not in body, "forbidden probe token: " + token) need('main.call("_set_speed", speed)' in body, "missing UI speed path") + close_branch = '''\tif not is_instance_valid(main) or not main.is_inside_tree(): +\t\temit_audio_close({"coordinator": false, "reason": "main_not_added"}) +\t\tquit(0) +\telif not root.has_meta(UIAudioOwnerShutdownScript.OWNER_META): +\t\temit_audio_close({"coordinator": false, "reason": "no_audio_owner"}) +\t\tquit(0) +\telse: +\t\tmain.ui_audio_window_close_drained.connect(emit_audio_close, CONNECT_ONE_SHOT) +\t\troot.close_requested.emit()''' + need(close_branch in body, "missing product close branch") + need(re.search(r"\bquit\s*\(", body.replace(close_branch, "")) is None, + "quit outside no-main/no-owner branches") + need("tests/helpers/ui_audio_fixture_cleanup" not in body, "fixture close forbidden") + for token in ("pre_observer.process_priority = -1000000", "observer.process_priority = 100000", + "PackedFloat64Array([value]).to_byte_array().hex_encode()", "anchor_baseline()"): + need(token in body, "missing passive pair observation: " + token) def main(): diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py index bd803a6..61d5623 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py @@ -13,7 +13,7 @@ import uuid from datetime import datetime, timezone sys.dont_write_bytecode = True -from check_p28_01_report import check_report, check_receipt, check_probe, normalize_report, check_admission, R02_FIELDS, VERDICT_SCOPE, CAP_SOURCE +from check_p28_01_report import check_report, check_receipt, check_probe, normalize_report, check_admission, audio_close, R02_FIELDS, VERDICT_SCOPE, CAP_SOURCE HERE = Path(__file__).resolve().parent ROOT = HERE.parents[5] FIXTURE_SHA = "eb4f770071eb07cd7e136fe54c3f78768cc8de7a4264e62a9af1f06a8f90f9bd" @@ -152,6 +152,11 @@ def bound_report(folder, row): require(len(printed) == 1, "exactly one raw report required") report = normalize_report(json.loads(printed[0])) require(row["capture"]["actual_captured_pids"] == [report["pid"]], "PID binding") + try: + row["audio_close"] = audio_close((folder / "stdout.log").read_text(), report) + except (ValueError, KeyError, TypeError): + row.update(passed=False, stop_reason="engine_failure") + raise return report diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd index 0842b04..cb7c0cc 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd @@ -1,14 +1,28 @@ extends SceneTree +const UIAudioOwnerShutdownScript = preload("res://scripts/ui/ui_audio_owner_shutdown.gd") ## External, passive observer of the default autoload world. ## Raw per-frame lines survive an owned timeout before the final report. +class PreObserver: + extends Node + var owner_probe: Variant + func _process(delta: float) -> void: + owner_probe.pre_sample(delta) + class Observer: extends Node var owner_probe: Variant - func _process(_delta: float) -> void: + func _process(delta: float) -> void: var observer_started_us := Time.get_ticks_usec() - owner_probe.sample(observer_started_us) + owner_probe.sample(observer_started_us, delta) +var pending_pair := {} +var baseline := {} +var last_pair := {} +var finished := false +var audio_emitted := false +var observation_order := 0 +var pre_cost_us := 0 var clock: Variant var runtime: Variant var main: Variant @@ -253,7 +267,7 @@ func begin() -> void: speed = int(OS.get_environment("THE_TREE_P28_SPEED")) warmup = int(OS.get_environment("THE_TREE_P28_WARMUP")) target = int(OS.get_environment("THE_TREE_P28_MINUTES")) - report = {"schema": "p28-01-v1", "pid": OS.get_process_id(), + report = {"schema": "p28-01-v1", "pid": OS.get_process_id(), "main_added": false, "phase": OS.get_environment("THE_TREE_P28_PHASE"), "input": input, "metadata": JSON.parse_string(OS.get_environment("THE_TREE_P28_META")), "input_sha256": null, "input_sha256_reason": "fresh_autoload_initialization", @@ -301,6 +315,7 @@ func begin() -> void: var opening_minute: int = clock.absolute_minute main = load("res://scenes/main/main.tscn").instantiate() root.add_child(main) + report["main_added"] = true report["startup"] = {"pause_fresh_opening": {"return": null, "reason": "void_function", "paused_before": paused_before, "paused_after": clock.paused}, "save_policy": {"return": null, "reason": "return_discarded_by_main（main.gd:222）"}, @@ -333,6 +348,10 @@ func begin() -> void: runtime.save_operation_completed.connect(on_save) RenderingServer.frame_pre_draw.connect(on_pre_draw) RenderingServer.frame_post_draw.connect(on_post_draw) + var pre_observer := PreObserver.new() + pre_observer.owner_probe = self + pre_observer.process_priority = -1000000 + root.add_child(pre_observer) var observer := Observer.new() observer.owner_probe = self observer.process_priority = 100000 @@ -346,6 +365,9 @@ func begin() -> void: if clock.paused or clock.speed != speed: finish("input_shortfall") return + ready_to_sample = true + +func anchor_baseline() -> void: start_minute = clock.absolute_minute measurement_start = start_minute if warmup == 0 else -1 previous_minute = start_minute @@ -363,7 +385,12 @@ func begin() -> void: report["start_minute"] = start_minute report["start_wall"] = Time.get_unix_time_from_system() previous_wall = report["start_wall"] - ready_to_sample = true + baseline["wall"] = report.start_wall + baseline["excluded_from_statistics"] = true + report["baseline"] = baseline + cached_registered = registered() + cached_active = active_counts() + cached_rng = rng_state() func on_overload(backlog: int) -> void: overloads.append({"backlog": backlog, "game_minute": clock.absolute_minute, "frame": frames.size()}) @@ -373,7 +400,7 @@ func on_checkpoint(_presentation: Dictionary) -> void: "wall": Time.get_unix_time_from_system(), "cause": "production_checkpoint_presentation_requested"}) func on_tick(minute: int) -> void: - if not ready_to_sample: + if not ready_to_sample or baseline.is_empty(): return var tick_us := Time.get_ticks_usec() var row := {"game_minute": minute, "wall": Time.get_unix_time_from_system(), @@ -383,9 +410,61 @@ func on_tick(minute: int) -> void: previous_tick_us = tick_us print("P28_01_MINUTE=" + JSON.stringify(row)) -func sample(observer_started_us: int) -> void: +func f64(value: float) -> String: + return PackedFloat64Array([value]).to_byte_array().hex_encode() + +func pre_sample(delta: float) -> void: if not ready_to_sample: return + var began := Time.get_ticks_usec() + if not pending_pair.is_empty(): + report["frame_order_evidence"] = pending_pair + finish("frame_order_unverified") + return + observation_order += 1 + pending_pair = {"engine_frame_pre": Engine.get_process_frames(), "pre_order": observation_order, + "paused_at_frame_start": clock.paused, "speed_at_frame_start": clock.speed, + "skip_at_frame_start": clock.get("_skip_next_process"), + "acc_at_frame_start_f64_hex": f64(clock.get("_accumulator")), + "minute_at_frame_start": clock.absolute_minute, "process_delta_f64_hex": f64(delta)} + var allowed := 0 + if not pending_pair.skip_at_frame_start and not clock.paused and clock.speed > 0 and delta > 0: + allowed = mini(int((float(clock.get("_accumulator")) + delta * clock.speed) / (10.0 / 60.0)), 8) + pending_pair["allowed_ticks_observation"] = allowed + pre_cost_us = Time.get_ticks_usec() - began + +func sample(observer_started_us: int, delta: float) -> void: + if not ready_to_sample: + return + if pending_pair.is_empty(): + if baseline.is_empty(): + report["leading_partial_frame"] = {"engine_frame_post": Engine.get_process_frames()} + return + report["frame_order_evidence"] = {"engine_frame_post": Engine.get_process_frames()} + finish("frame_order_unverified") + return + var pair := pending_pair + pending_pair = {} + observation_order += 1 + pair.merge({"engine_frame_post": Engine.get_process_frames(), "post_order": observation_order, + "post_delta_f64_hex": f64(delta), "paused_after": clock.paused, + "minute_after": clock.absolute_minute, "acc_after_f64_hex": f64(clock.get("_accumulator"))}) + if pair.engine_frame_pre != pair.engine_frame_post or pair.process_delta_f64_hex != pair.post_delta_f64_hex: + report["frame_order_evidence"] = pair + finish("frame_order_unverified") + return + if baseline.is_empty(): + baseline = pair + last_pair = pair + anchor_baseline() + baseline["observer_us"] = pre_cost_us + Time.get_ticks_usec() - observer_started_us + return + if pair.engine_frame_pre != last_pair.engine_frame_post + 1 or pair.pre_order != last_pair.post_order + 1 \ + or pair.minute_at_frame_start != last_pair.minute_after or pair.acc_at_frame_start_f64_hex != last_pair.acc_after_f64_hex: + report["frame_order_evidence"] = {"previous": last_pair, "current": pair} + finish("frame_order_unverified") + return + last_pair = pair var current_us := Time.get_ticks_usec() var minute: int = clock.absolute_minute var elapsed := current_us - previous_us @@ -426,6 +505,7 @@ func sample(observer_started_us: int) -> void: "render_cpu_raw_ms": RenderingServer.viewport_get_measured_render_time_cpu(root.get_viewport_rid()), "render_gpu_raw_ms": RenderingServer.viewport_get_measured_render_time_gpu(root.get_viewport_rid()), "time_process_seconds": Performance.get_monitor(Performance.TIME_PROCESS)} + row.merge(pair) last_render_serial = render_serial previous_us = current_us previous_wall = row.wall @@ -458,7 +538,7 @@ func sample(observer_started_us: int) -> void: # summary are disclosed separately and are never subtracted from frame wall. var raw_line := JSON.stringify(row) print("P28_01_FRAME=" + raw_line) - row["observer_us"] = Time.get_ticks_usec() - observer_started_us + row["observer_us"] = pre_cost_us + Time.get_ticks_usec() - observer_started_us frames.append(row) print("P28_01_OBSERVER=" + JSON.stringify({"frame": row.frame, "observer_us": row.observer_us})) if not reason.is_empty(): @@ -486,6 +566,7 @@ func summary(segment: String) -> Dictionary: var observer: Array = [] var submit: Array = [] var excluded := 0 + var short_of_allowed := 0 var minutes := 0 var cpu_missing := false var gpu_missing := false @@ -500,6 +581,8 @@ func summary(segment: String) -> Dictionary: submit.append(frame.render_submit_wall_us) process.append(frame.time_process_seconds) minutes += frame.minutes_advanced + if frame.minutes_advanced < frame.allowed_ticks_observation: + short_of_allowed += 1 if frame.frame_wall_us > 50000: stalls.append(frame.frame_wall_us) if frame.minutes_advanced > 0: @@ -520,6 +603,7 @@ func summary(segment: String) -> Dictionary: var unavailable := "zero_from_api_on_gl_compatibility_unsupported_or_unmeasured" var minute_stats := stats(per_minute) return {"frames": selected.size(), "actual_minutes": minutes, + "short_of_allowed_frames": short_of_allowed, "start_minute": selected.front().game_start if not selected.is_empty() else null, "end_minute": selected.back().game_end if not selected.is_empty() else null, "start_wall": selected.front().wall_start if not selected.is_empty() else null, @@ -534,7 +618,13 @@ func summary(segment: String) -> Dictionary: "time_process_seconds": stats(process), "count_ranges": ranges} func finish(reason: String) -> void: + if finished: + return + finished = true ready_to_sample = false + if not pending_pair.is_empty(): + report["trailing_partial_frame"] = pending_pair + pending_pair = {} # Early input shortfalls also need observed startup time for stage0 evidence. if not report.has("startup_wall_seconds"): report["startup_wall_seconds"] = float(Time.get_ticks_usec()) / 1000000.0 @@ -544,9 +634,25 @@ func finish(reason: String) -> void: report["end_wall"] = Time.get_unix_time_from_system() report["kernel_at_phase_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": clock.get_performance_reports()} report["budget_at_phase_end"] = {"source": "clock.performance_budget (product diagnostic, raw, not a verdict)", "data": budget_snapshot()} - report["budget_verdict"] = kernel_verdict(report.budget_at_warmup_end.data, report.budget_at_phase_end.data) + if reason != "frame_order_unverified": + report["budget_verdict"] = kernel_verdict(report.budget_at_warmup_end.data, report.budget_at_phase_end.data) report["operations_at_end"] = runtime.get_operations_report() report["warmup"] = summary("warmup") report["measurement"] = summary("measurement") + report["audio_owner_present"] = root.has_meta(UIAudioOwnerShutdownScript.OWNER_META) print("P28_01_PERF_REPORT=" + JSON.stringify(report)) - quit(0) + if not is_instance_valid(main) or not main.is_inside_tree(): + emit_audio_close({"coordinator": false, "reason": "main_not_added"}) + quit(0) + elif not root.has_meta(UIAudioOwnerShutdownScript.OWNER_META): + emit_audio_close({"coordinator": false, "reason": "no_audio_owner"}) + quit(0) + else: + main.ui_audio_window_close_drained.connect(emit_audio_close, CONNECT_ONE_SHOT) + root.close_requested.emit() + +func emit_audio_close(result: Dictionary) -> void: + if audio_emitted: + return + audio_emitted = true + print("P28_01_AUDIO_CLOSE=" + JSON.stringify(result)) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index fd8f1d0..d59c9ee 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -4,6 +4,7 @@ import ast import copy import hashlib import json +import struct from pathlib import Path import sys import tempfile @@ -19,6 +20,30 @@ import collect_p28_01 as collector HERE = Path(__file__).resolve().parent +def f64(value): + return struct.pack(" 0 and delta > 0: + after += delta * speed + allowed = min(int(after / (10.0 / 60.0)), 8) + for _ in range(ticks): + after -= 10.0 / 60.0 + return {"engine_frame_pre": number, "engine_frame_post": number, + "pre_order": number * 2 + 1, "post_order": number * 2 + 2, + "paused_at_frame_start": paused, "speed_at_frame_start": speed, + "skip_at_frame_start": skip, "acc_at_frame_start_f64_hex": f64(acc), + "minute_at_frame_start": minute, "process_delta_f64_hex": f64(delta), + "post_delta_f64_hex": f64(delta), "paused_after": paused_after, + "minute_after": minute + ticks, "acc_after_f64_hex": f64(after), + "minutes_advanced": ticks, "game_start": minute, "game_end": minute + ticks, + "paused": paused_after, "allowed_ticks_observation": allowed} + + def synthetic_guard(runtime=Path("private"), name="runtime"): return {"verified": True, "conditions": [True] * 5, "conditions_checked": 5, "actual_user_data_dir": str(runtime), "expected_user_data_dir": str(runtime), @@ -121,6 +146,19 @@ def synthetic_report(): for name in checker.RAW_FIELDS: report[name] = {"source": checker.RAW_SOURCE, "data": report[name]} report["probe_deadline"] = {"limit_seconds": 1740, "source": checker.DEADLINE_SOURCE} + report["main_added"] = True + report["audio_owner_present"] = True + report["baseline"] = pair(0, 360, 0, delta=0, ticks=0, skip=True) + report["baseline"].update(excluded_from_statistics=True, wall=100) + acc = 0.0 + for i, frame in enumerate(frames): + evidence = pair(i + 1, frame["game_start"], acc) + frame.update(evidence) + acc = checker.decode_f64(evidence["acc_after_f64_hex"]) + for name in ("warmup", "measurement"): + report[name]["short_of_allowed_frames"] = sum( + f["minutes_advanced"] < f["allowed_ticks_observation"] + for f in frames if f["segment"] == name) return report @@ -131,6 +169,105 @@ def synthetic_admission(): class ReportTests(unittest.TestCase): + def test_k1_audio_close_receipts(self): + report = {"main_added": True, "audio_owner_present": True} + close = {"coordinator": True, "passed": True, "deadline_reached": False, + "all_owned_targets_released": True, "waited_actual_us": 15000} + def raw(value): + return "P28_01_AUDIO_CLOSE=" + json.dumps(value) + "\n" + self.assertEqual(checker.audio_close(raw(close), report), close) + no_owner = {"coordinator": False, "reason": "no_audio_owner"} + self.assertEqual(checker.audio_close(raw(no_owner), + dict(report, audio_owner_present=False)), no_owner) + for text in ("", raw(close) * 2, raw(dict(close, passed=False)), + raw(dict(close, deadline_reached=True)), + raw(dict(close, all_owned_targets_released=False)), + raw({"coordinator": False, "reason": "main_not_added"}), raw(no_owner)): + with self.subTest(text=text), self.assertRaises(ValueError): + checker.audio_close(text, report) + # Binding uses the actual raw marker, independently of a phase's claimed pass. + with patch.object(Path, "read_text", return_value=checker.PREFIX + + json.dumps({"pid": 123, **report}) + "\n" + raw(close)): + row = {"capture": {"actual_captured_pids": [123]}} + collector.bound_report(Path("synthetic"), row) + self.assertEqual(row["audio_close"], close) + + def test_k1_product_close_static(self): + text = (HERE / "measure_p28_01.gd").read_text() + checker.check_probe(text) + owner = text.split("\telse:\n\t\tmain.ui_audio_window_close_drained.connect", 1)[1] + self.assertNotIn("quit(", owner) + for broken in (text + "\nfunc bypass():\n\tquit(0)\n", + text.replace("\t\tquit(0)", "\tquit(0)", 1), + text.replace("root.close_requested.emit()", "quit(0)"), + text + "\n# tests/helpers/ui_audio_fixture_cleanup.gd"): + with self.assertRaises(ValueError): + checker.check_probe(broken) + + def test_k2_valid_cadence_boundaries(self): + for options in ({"acc": 2.0, "delta": .016, "ticks": 8}, + {"acc": 2.0, "delta": .016, "ticks": 3, "paused_after": True}, + {"acc": 2.0, "delta": .016, "ticks": 0, "skip": True}, + {"acc": 30.0, "delta": .016, "ticks": 8, "paused_after": True}, + {"acc": 30.0, "delta": .016, "ticks": 0, "paused": True, + "paused_after": True}): + baseline = pair(0, 360, options["acc"], delta=0, ticks=0) + current = pair(1, 360, **options) + with self.subTest(options=options): + checker.check_pair(current, baseline, 1) + # A real skip may follow an excluded baseline; don't guess it was consumed. + baseline = pair(0, 360, 0, delta=0, ticks=0) + skipped = pair(1, 360, 0, ticks=0, skip=True) + checker.check_pair(skipped, baseline, 1) + checker.check_pair(pair(2, 360, 0), skipped, 1) + + def test_k2_reject_cadence_and_missing_evidence(self): + baseline = pair(0, 360, 0, delta=0, ticks=0) + valid = pair(1, 360, 0) + mutations = [ + lambda x: x.update(**pair(1, 360, 0, delta=.016, ticks=1)), + lambda x: x.update(**pair(1, 360, 0, delta=.2, ticks=3)), + lambda x: x.update(**pair(1, 360, 0, delta=2, ticks=9)), + lambda x: x.update(**pair(1, 360, 0, paused=True)), + lambda x: x.update(minute_at_frame_start=361), + lambda x: x.update(acc_at_frame_start_f64_hex=f64(.01)), + lambda x: x.update(engine_frame_post=2), + lambda x: x.update(pre_order=4), + ] + for key in ("process_delta_f64_hex", "post_delta_f64_hex", + "acc_at_frame_start_f64_hex", "acc_after_f64_hex", "skip_at_frame_start"): + mutations.append(lambda x, k=key: x.pop(k)) + mutations.append(lambda x, k=key: x.update({k: "broken"})) + mutations.append(lambda x: x.update(process_delta_f64_hex=f64(float("nan")))) + for mutate in mutations: + current = copy.deepcopy(valid) + mutate(current) + with self.subTest(current=current), self.assertRaises(ValueError): + checker.check_pair(current, baseline, 1) + baseline = pair(0, 360, 2.0, delta=0, ticks=0) + current = pair(1, 360, 2.0, delta=.016, ticks=8) + bulk = f64((2.0 + .016) - (10.0 / 60.0) * 8) + self.assertNotEqual(bulk, current["acc_after_f64_hex"]) + current["acc_after_f64_hex"] = bulk + with self.assertRaises(ValueError): + checker.check_pair(current, baseline, 1) + + def test_k3_baseline_and_complete_pairs(self): + checker.check_report(synthetic_report()) + for mutate in ( + lambda r: r.pop("baseline"), + lambda r: r["baseline"].update(excluded_from_statistics=False), + lambda r: r["baseline"].update(minute_after=359), + lambda r: r["baseline"].update(wall=99), + lambda r: r["frames"][0].update(engine_frame_pre=0, engine_frame_post=0, + pre_order=1, post_order=2), + lambda r: r["frames"][1].pop("post_order"), + lambda r: r["frames"][1].update(acc_at_frame_start_f64_hex=f64(0)), + lambda r: r["frames"][1].update(minute_at_frame_start=360), + ): + with self.subTest(mutate=mutate): + self.reject(mutate) + def test_r1_recursive_verdict_scope(self): report = synthetic_report() receipt = {"admission": synthetic_admission(), "phases": [{"report": report, "passed": True}], @@ -306,10 +443,12 @@ class ReportTests(unittest.TestCase): def test_receipt_rejects_source_player_and_raw_pid(self): r = synthetic_report() - raw = (checker.PREFIX + json.dumps(r) + "\n").encode() + close = {"coordinator": True, "passed": True, "deadline_reached": False, + "all_owned_targets_released": True, "waited_actual_us": 15000} + raw = (checker.PREFIX + json.dumps(r) + "\nP28_01_AUDIO_CLOSE=" + json.dumps(close) + "\n").encode() row = {"phase": "O0", "passed": True, "timeout_seconds": 1800, "raw": {"stdout.log": {"sha256": hashlib.sha256(raw).hexdigest(), "bytes": len(raw)}}, - "report": r, "capture": {"actual_captured_pids": [123]}, + "report": r, "audio_close": close, "capture": {"actual_captured_pids": [123]}, "extrapolation": collector.extrapolation(r), "guard": synthetic_guard(), "runtime_profile": "private", "runtime_name": "runtime"} receipt = {"admission": synthetic_admission(), "source_before": {"x": "a"}, "source_after": {"x": "a"}, @@ -475,7 +614,8 @@ class ReportTests(unittest.TestCase): "time.sleep(0.15)\n" "if mode=='timeout': time.sleep(5)\n" "for i in range(0 if mode=='missing' else 2 if mode=='duplicate' else 1):\n" - " print('P28_01_PERF_REPORT='+json.dumps({'pid':os.getpid()+int(mode=='pid')}),flush=True)\n" + " print('P28_01_PERF_REPORT='+json.dumps({'pid':os.getpid()+int(mode=='pid'),'main_added':False,'audio_owner_present':False}),flush=True)\n" + "print('P28_01_AUDIO_CLOSE='+json.dumps({'coordinator':False,'reason':'main_not_added'}),flush=True)\n" "sys.exit(3 if mode=='exit' else 0)\n") with tempfile.TemporaryDirectory() as temp: base = Path(temp) From c1d9ad51db4dc9758f6f52b26cdd11971346fae6 Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 23:12:06 +0900 Subject: [PATCH 6/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/check_p28_01_report.py | 92 ++++++++- .../p28-01/collector/collect_p28_01.py | 62 +++++- .../p28-01/collector/measure_p28_01.gd | 6 +- .../p28-01/collector/test_collect_p28_01.py | 179 +++++++++++++++++- 4 files changed, 318 insertions(+), 21 deletions(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py index 886a3ff..e5fbab1 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py @@ -87,6 +87,19 @@ def check_budget_scope(value, report_paths=(), path=(), raw=False): def check_admission(admission): check_budget_scope(admission) + if "planned_argv" in admission: + from collect_p28_01 import argv_for, parse_argv + planned = admission["planned_argv"] + need(len(planned) == 3 + len(admission["phases"]), "internal phase plan length") + engine = planned[0][0] + need("--path" in planned[0], "import stage missing") + stage = Path(planned[0][planned[0].index("--path") + 1]) + wrapper = Path(planned[2][-1]) + need(wrapper.name == "guarded.gd", "wrapper plan target") + equal(planned, [argv_for(engine, stage, wrapper, True), + parse_argv(engine, stage, wrapper.parent / "measure_p28_01.gd"), + parse_argv(engine, stage, wrapper)] + + [argv_for(engine, stage, wrapper) for _ in admission["phases"]], "execution argv plan") need(admission.get("budget_verdict_scope") == VERDICT_SCOPE, "admission verdict scope") reused = admission["reused_r02"] def no_verdict_fields(value): @@ -442,6 +455,75 @@ def check_report(report): need(frames and all(f["registered"]["guests"] == 200 for f in frames), "200 guest claim") +def check_parse_process(row, directory): + from collect_p28_01 import PARSE_NA, diagnostics, sha + equal(row["parse_na"], PARSE_NA, "parse-only N/A reasons") + need(not any(k in row for k in ("report", "guard", "audio_close", "runtime_profile")), + "parse claims runtime evidence") + need(row["passed"] is True, "parse failed") + need(row["source_preserved"] is True and row["player_preserved"] is True, "parse preservation") + need(set(row["raw"]) == {"stdout.log", "stderr.log", "engine-native.log"}, "parse raw missing") + text = "" + for name, pin in row["raw"].items(): + path = directory / row["phase"] / name + need(pin == {"sha256": sha(path), "bytes": path.stat().st_size}, "parse raw pin") + text += path.read_text(errors="replace") + "\n" + need(not diagnostics(text) and row["diagnostics"] == [], "parse diagnostics") + need("P28_01_PERF_REPORT=" not in text and "P28_01_AUDIO_CLOSE=" not in text, + "runtime markers during parse") + process, capture = row["process"], row["capture"] + need(process["exit_code"] == 0 and process["helper_exit_code"] == 0 and + process["timed_out"] is False and process["error_lines"] == [] and + process["owned_popen_ended"] is True and process["old_helper_engine_ended"] is True and + process["start_receipt_written"] is True and process["end_receipt_written"] is True and + process["lifecycle_error"] is None and process["external_process_or_group_signals"] == 0, + "parse process failure") + need(capture["passed"] is True and capture["all_captured_ended"] is True and + capture["actual_captured_pids"] == [process["pid"]] and + not capture["outer_cleanup_errors"] and capture["foreign_process_or_group_signals"] == 0 and + all(c["engine_ended"] is True and not c["outer_cleanup_errors"] and + not c["cleanup"].get("errors") for c in capture["cleanup"]), "parse ownership") + equal(json.loads((directory / row["phase"] / "process.json").read_text()), process, + "parse process binding") + for name, pin in row["owned_files"].items(): + path = directory / row["phase"] / name + need(pin == {"sha256": sha(path), "bytes": path.stat().st_size}, "parse owned pin") + from collect_p28_01 import OWNED_FILES + need(set(row["owned_files"]) == set(OWNED_FILES), "parse ownership evidence missing") + saved_capture = json.loads((directory / row["phase"] / "outer-owned-finally.json").read_text()) + equal(saved_capture, {k: v for k, v in capture.items() + if k not in ("passed", "outer_receipt_written", "outer_receipt_error")}, + "parse capture binding") + + +def check_parse(row, directory, source): + from collect_p28_01 import parse_argv, sha, digest + check_parse_process(row, directory) + target = directory / ("measure_p28_01.gd" if row["phase"] == "parse-base" else "guarded.gd") + command = parse_argv(row["argv"][0], directory / "stage", target) + command += ["--log-file", str(directory / row["phase"] / "engine-native.log"), "--verbose"] + equal(row["argv"], command, "parse argv") + equal(row["process"]["argv"], command, "parse owned argv") + equal(row["script_pins"], {str(directory / n): sha(directory / n) + for n in ("measure_p28_01.gd", "guarded.gd", "profile_guard.gd")}, + "parse script pins") + startup = row["startup_project"] + need(not (directory / (row["phase"] + "-guard.json")).exists(), "Guard ran during parse") + path = directory / (row["phase"] + "-startup-project.godot") + need(startup["path"] == str(path) and startup["sha256"] == sha(path) and + startup["fresh_before"] is True, "parse startup evidence") + from collect_p28_01 import load_tool, EXTERNAL_IMPORTS + standard = load_tool(EXTERNAL_IMPORTS[0]) + public = (directory / "stage/project.godot").read_bytes() + need(path.read_bytes() == standard.private_project(public, startup["name"]) and + startup["profile"] == str(standard.profile_path(startup["name"])) and + startup["restored_sha256"] == hashlib.sha256(public).hexdigest(), "parse private project") + stage_inventory = standard.inventory(directory / "stage", stage=True) + need(row["stage_before_sha256"] == row["stage_after_sha256"] == + digest(stage_inventory), "parse stage preservation") + need(all(stage_inventory.get(k) == v for k, v in source.items()), "parse product preservation") + + def check_receipt(receipt, directory): from collect_p28_01 import OWNED_FILES, projection, extrapolation, guard_gate check_budget_scope(receipt, tuple(("phases", i, "report") @@ -458,7 +540,10 @@ def check_receipt(receipt, directory): "execution probe pin/check") check_probe(text) rows = receipt["phases"] - need([r["phase"] for r in rows] == ["import", *PHASES], "phase order") + from collect_p28_01 import PARSE_PHASES + need([r["phase"] for r in rows] == ["import", *PARSE_PHASES, *PHASES], "phase order") + parse_profiles = [r["startup_project"]["profile"] for r in rows if r["phase"] in PARSE_PHASES] + need(len(set(parse_profiles)) == len(parse_profiles), "parse profiles reused") for row in rows: equal(row["phase_stop"], {"limit_seconds": 1800, "source": CAP_SOURCE}, "phase cap origin") forecast = None @@ -486,6 +571,11 @@ def check_receipt(receipt, directory): need(hashlib.sha256(data).hexdigest() == pin["sha256"] and len(data) == pin["bytes"], "raw SHA") if row["phase"] == "import": continue + if row["phase"] in PARSE_PHASES: + check_parse(row, directory, receipt["source_before"]) + index = 1 + PARSE_PHASES.index(row["phase"]) + equal(row["argv"][:-3], receipt["admission"]["planned_argv"][index], "parse plan binding") + continue guard_gate(row["guard"], Path(row["runtime_profile"]), row["runtime_name"]) stdout = (directory / row["phase"] / "stdout.log").read_text() printed = [normalize_report(json.loads(x[len(PREFIX):])) for x in stdout.splitlines() if x.startswith(PREFIX)] diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py index 61d5623..56fa984 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py @@ -24,6 +24,9 @@ PHASES = (("R0", "R", 1, 0, 10), ("P1", "R", 1, 30, 120), ("P2", "R", 3, 30, 120), ("O0", "O", 1, 0, 10), ("P3", "O", 1, 30, 120), ("P4", "O", 3, 30, 120)) EXTERNAL_IMPORTS = ("tools/run_all_tests.py", "tools/regression/owned_outer.py") +PARSE_PHASES = ("parse-base", "parse-wrapper") +PARSE_NA = {key: {"value": None, "reason": "--check-only does not run Runtime or Guard"} + for key in ("PERF_REPORT", "AUDIO_CLOSE", "Guard.activate", "runtime_profile")} def require(value, message): @@ -98,6 +101,38 @@ def argv_for(engine, stage, wrapper, importing=False): return [str(engine), "--path", str(stage), "--script", str(wrapper)] +def parse_argv(engine, stage, target): + return [str(engine), "--headless", "--path", str(stage), "--check-only", "--script", str(target)] + + +def execution_plan(engine, stage, wrapper): + return [argv_for(engine, stage, wrapper, True), + parse_argv(engine, stage, wrapper.parent / "measure_p28_01.gd"), + parse_argv(engine, stage, wrapper)] + [argv_for(engine, stage, wrapper) for _ in PHASES] + + +def run_private_engine(standard, outer, command, folder, environment, stage, public, name): + """Keep launch settings outside the owned folder and restore even on failure.""" + project = stage / "project.godot" + private = standard.private_project(public, name) + startup = standard.profile_path(name) + require(not startup.exists(), "startup profile not fresh") + evidence = folder.parent / (folder.name + "-startup-project.godot") + evidence.write_bytes(private) + try: + project.write_bytes(private) + require(project.read_bytes() == private, "private startup project differs") + row = run_engine(outer, command, folder, environment) + require(project.read_bytes() == private, "startup project changed during execution") + finally: + project.write_bytes(public) + row["startup_project"] = {"path": str(evidence), "sha256": sha(evidence), + "name": name, "profile": str(startup), "fresh_before": True, + "restored_sha256": sha(project)} + require(project.read_bytes() == public, "project restoration failed") + return row + + def checked_probe(path): text = path.read_text() check_probe(text) @@ -162,7 +197,8 @@ def bound_report(folder, row): def phase_schedule(rows): """Caller appends each executed result; exceptions abort the consuming loop.""" - for index, phase in enumerate((("import", "", 0, 0, 0),) + PHASES): + for index, phase in enumerate((("import", "", 0, 0, 0),) + + tuple((label, "", 0, 0, 0) for label in PARSE_PHASES) + PHASES): label, source, _, _, _ = phase forecast = None if label in ("P1", "P2", "P3", "P4"): @@ -282,8 +318,7 @@ def main(): require(actual == blob, "dirty source: " + name) stage = args.output.resolve() / "stage" wrapper = args.output.resolve() / "guarded.gd" - planned = [argv_for(args.engine, stage, wrapper, True)] + [ - argv_for(args.engine, stage, wrapper) for _ in PHASES] + planned = execution_plan(args.engine, stage, wrapper) admission = {"commit": commit, "source_map": before, "source_map_sha256": digest(before), "readonly": pins, "engine_sha256": ENGINE_SHA, "engine_version": VERSION, "fixture_sha256": FIXTURE_SHA, "planned_argv": planned, "phases": PHASES, @@ -351,20 +386,31 @@ def main(): "THE_TREE_P28_WARMUP": str(warmup), "THE_TREE_P28_MINUTES": str(minutes), "THE_TREE_P28_FIXTURE": str(args.fixture.resolve()), "THE_TREE_P28_FIXTURE_SHA": FIXTURE_SHA, "THE_TREE_P28_META": json.dumps(meta)} - (stage / "project.godot").write_bytes(standard.private_project(public, name)) - try: - row = run_engine(outer, planned[index], out / label, env) - finally: - (stage / "project.godot").write_bytes(public) + row = run_private_engine(standard, outer, planned[index], out / label, env, + stage, public, name) row["phase"] = label row["projection"] = forecast row["probe_check"] = probe_check + if label in PARSE_PHASES: + row.update(parse_na=PARSE_NA, script_pins=script_pins, + stage_before_sha256=digest(expected), + stage_after_sha256=digest(standard.inventory(stage, stage=True)), + source_preserved=source_map(standard, ROOT) == before, + player_preserved=standard.default_player(ROOT) == player) rows.append(row) + if label in PARSE_PHASES: + require(row["stage_before_sha256"] == row["stage_after_sha256"] and + row["source_preserved"] and row["player_preserved"] and + all(sha(Path(p)) == pin for p, pin in script_pins.items()), + "parse preservation failed") require(row["passed"], "native phase failed; raw retained: " + label) after = standard.inventory(stage, stage=True) if label == "import": stage_gate(expected, after, importing=True) expected = after + elif label in PARSE_PHASES: + require(after == expected, "stage changed during parse") + row["stage_after_sha256"] = digest(after) else: require(after == expected, "stage changed during measurement") observation = json.loads(guard_path.read_text()) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd index cb7c0cc..05d2f4b 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd @@ -478,9 +478,9 @@ func sample(observer_started_us: int, delta: float) -> void: var stall_count: Variant = field(clock.performance_budget.get("_sample_counts"), "main_thread_stall") var kernel_stalls: Array = [] if stall_count != null and last_stall_count != null and stall_raw is Array: - var delta: int = stall_count - last_stall_count - if delta > 0 and delta <= stall_raw.size(): - kernel_stalls = stall_raw.slice(stall_raw.size() - delta) + var stall_delta: int = stall_count - last_stall_count + if stall_delta > 0 and stall_delta <= stall_raw.size(): + kernel_stalls = stall_raw.slice(stall_raw.size() - stall_delta) last_stall_count = stall_count var causes: Array = [] for event: Dictionary in save_events: diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index d59c9ee..dfb6378 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -462,7 +462,10 @@ class ReportTests(unittest.TestCase): phase["probe_check"] = receipt["probe_check"].copy() phase["owned_files"] = {name: {"sha256": hashlib.sha256(raw).hexdigest(), "bytes": len(raw)} for name in collector.OWNED_FILES} - with patch.object(checker, "PHASES", {"O0": ("O", 1, 0, 10)}), \ + # This fixture isolates the original runtime receipt checks. The actual + # parse prefix and its evidence are covered by test_l2_owned_parse_gate. + with patch.object(collector, "PARSE_PHASES", ()), \ + patch.object(checker, "PHASES", {"O0": ("O", 1, 0, 10)}), \ patch.object(Path, "read_bytes", return_value=raw), \ patch.object(Path, "read_text", autospec=True, side_effect=lambda p: (probe_text if p.name == "measure_p28_01.gd" else @@ -686,6 +689,164 @@ class ReportTests(unittest.TestCase): self.assertFalse(errors) self.assertTrue(all(r["engine_ended"] for r in cleanup)) + def test_l2_owned_parse_gate(self): + """Real owned Python children; no engine and no fabricated Runtime markers.""" + standard = collector.load_tool(collector.EXTERNAL_IMPORTS[0]) + outer = collector.load_tool(collector.EXTERNAL_IMPORTS[1]) + child = ( + "import os,sys,json,time,pathlib\n" + "mode=sys.argv[1]\n" + "identity={'pid':os.getpid(),'ppid':os.getppid(),'pgid':os.getpgrp()," + "'args':' '.join([sys.executable]+sys.argv)}\n" + "base=pathlib.Path(sys.argv[0]).parent\n" + "tmp=base/'identity.tmp'; tmp.write_text(json.dumps(identity)); tmp.replace(base/'identity')\n" + "stage=pathlib.Path(sys.argv[sys.argv.index('--path')+1])\n" + "assert 'config/use_custom_user_dir=true' in (stage/'project.godot').read_text()\n" + "native=pathlib.Path(sys.argv[sys.argv.index('--log-file')+1])\n" + "native.write_text('ERROR: native parse failure\\n' if mode=='native' else 'native raw\\n')\n" + "print('Godot Engine v4.7.2.stable.official.ed1daf0bf - https://godotengine.org',flush=True)\n" + "print('SCRIPT ERROR: Parse Error: synthetic' if mode=='stdout' else 'parse stdout',flush=True)\n" + "print('Parse Error: synthetic' if mode=='stderr' else 'parse stderr',file=sys.stderr,flush=True)\n" + "time.sleep(.15)\n" + "sys.exit(3 if mode=='exit' else 0)\n") + for failure_phase, mode in ((None, "ok"), ("parse-base", "stdout"), + ("parse-base", "stderr"), ("parse-base", "native"), + ("parse-base", "exit"), ("parse-wrapper", "stdout")): + with self.subTest(failure_phase=failure_phase, mode=mode), tempfile.TemporaryDirectory() as temp: + base = Path(temp) + stage = base / "stage" + stage.mkdir() + public = b'[application]\n\nconfig/name="The Tree"\n' + (stage / "project.godot").write_bytes(public) + script = base / "child.py" + script.write_text(child) + pins = {} + for name in ("measure_p28_01.gd", "profile_guard.gd", "guarded.gd"): + (base / name).write_text("# Synthetic parse input; never executed by Godot.\n") + pins[str(base / name)] = collector.sha(base / name) + source = standard.inventory(stage, stage=True) + def diagnostic(command, folder, timeout, env, **kwargs): + def probe(pid): + deadline = time.monotonic() + 2 + while time.monotonic() < deadline: + if (base / "identity").exists(): + identity = json.loads((base / "identity").read_text()) + if identity["pid"] == pid: + return identity + time.sleep(.005) + raise RuntimeError("child identity unavailable") + return outer.native.run_owned_diagnostic(command, folder, timeout, env, + probe_fn=probe, **kwargs) + def owned(command, folder, limit, env, **kwargs): + self.assertEqual(limit, 1800) + return outer.run_phase(command, folder, 5, env, diagnostic_fn=diagnostic, **kwargs) + rows, launched = [], [] + try: + with patch.object(collector, "live_engines", return_value=[]): + for index, phase, _ in collector.phase_schedule(rows): + label = phase[0] + if label == "import": + rows.append({"phase": label}) + continue # This engine-free fixture begins after successful import. + launched.append(label) + if label not in collector.PARSE_PHASES: + break # Record admission of R0 without starting any Runtime. + command = [sys.executable, str(script), mode if label == failure_phase else "ok", + "--headless", "--path", str(stage), "--check-only", "--script", "probe"] + row = collector.run_private_engine( + standard, SimpleNamespace(run_phase=owned), command, base / label, {}, + stage, public, "TheTree-PCK-tests-" + base.name + "-" + label) + row.update(phase=label, parse_na=copy.deepcopy(collector.PARSE_NA), + source_preserved=True, player_preserved=True, script_pins=pins, + stage_before_sha256=collector.digest(source), + stage_after_sha256=collector.digest(standard.inventory(stage, stage=True))) + rows.append(row) + self.assertEqual((stage / "project.godot").read_bytes(), public) + self.assertEqual(row["startup_project"]["sha256"], + collector.sha(Path(row["startup_project"]["path"]))) + self.assertTrue(row["capture"]["all_captured_ended"]) + self.assertFalse(row["capture"]["outer_cleanup_errors"]) + self.assertEqual(row["capture"]["actual_captured_pids"], [row["process"]["pid"]]) + self.assertTrue((base / (label + "-collector-receipt.json")).is_file()) + if label == failure_phase: + self.assertFalse(row["passed"]) + # Claimed success cannot override actual diagnostics/nonzero exit. + broken = copy.deepcopy(row) + broken["passed"] = True + with self.assertRaises(ValueError): + checker.check_parse_process(broken, base) + else: + checker.check_parse_process(row, base) + # Only argv generation is substituted for the Python fake child; + # exact Godot argv is asserted separately in the static plan test. + with patch.object(collector, "parse_argv", return_value=row["argv"][:-3]): + checker.check_parse(row, base, source) + for mutation in ( + lambda r: r["startup_project"].update(name="wrong"), + lambda r: r.update(stage_after_sha256="f" * 64), + lambda r: r["script_pins"].update({str(base / "guarded.gd"): "f" * 64}), + ): + broken = copy.deepcopy(row) + mutation(broken) + with self.assertRaises(ValueError): + checker.check_parse(broken, base, source) + for mutation in ( + lambda r: r["parse_na"]["AUDIO_CLOSE"].update(reason=""), + lambda r: r.update(report={"pid": r["process"]["pid"]}), + lambda r: r["capture"].update(actual_captured_pids=[-1]), + lambda r: r.update(player_preserved=False), + lambda r: r["owned_files"].pop("ended.json"), + ): + broken = copy.deepcopy(row) + mutation(broken) + with self.assertRaises(ValueError): + checker.check_parse_process(broken, base) + collector.require(row["passed"], "parse failed") + except ValueError: + self.assertIsNotNone(failure_phase) + finally: + cleanup, errors = outer.finish_captured(outer.OWNED) + self.assertFalse(errors) + self.assertTrue(all(r["engine_ended"] for r in cleanup)) + self.assertEqual(launched, ["parse-base"] if failure_phase == "parse-base" else + ["parse-base", "parse-wrapper"] if failure_phase else + ["parse-base", "parse-wrapper", "R0"]) + self.assertFalse(any((base / p).exists() for p in ("R0", "P1", "P2", "O0", "P3", "P4"))) + + def test_l2_plan_and_restoration(self): + plan = collector.execution_plan("engine", Path("/stage"), Path("/out/guarded.gd")) + self.assertEqual(len(plan), 9) + self.assertEqual(plan[1], ["engine", "--headless", "--path", "/stage", "--check-only", + "--script", "/out/measure_p28_01.gd"]) + self.assertEqual(plan[2][-1], "/out/guarded.gd") + self.assertEqual(collector.PHASES[0], ("R0", "R", 1, 0, 10)) + admission = synthetic_admission() + admission.update(planned_argv=plan, phases=collector.PHASES) + checker.check_admission(admission) + for mutate in ( + lambda a: a["planned_argv"].pop(1), + lambda a: a["planned_argv"][1].remove("--check-only"), + lambda a: a["planned_argv"][1].__setitem__(-1, "/out/guarded.gd"), + lambda a: a["planned_argv"][3].append("--headless"), + ): + broken = copy.deepcopy(admission) + mutate(broken) + with self.assertRaises(ValueError): + checker.check_admission(broken) + for command in plan[3:]: + self.assertNotIn("--headless", command) + self.assertNotIn("--check-only", command) + standard = collector.load_tool(collector.EXTERNAL_IMPORTS[0]) + with tempfile.TemporaryDirectory() as temp: + base = Path(temp) + public = b'[application]\n\nconfig/name="The Tree"\n' + (base / "project.godot").write_bytes(public) + with patch.object(collector, "run_engine", side_effect=RuntimeError("owned failure")), \ + self.assertRaises(RuntimeError): + collector.run_private_engine(standard, None, [], base / "parse-base", {}, base, + public, "TheTree-PCK-tests-" + base.name) + self.assertEqual((base / "project.godot").read_bytes(), public) + def test_j3_guard_and_whole_inventory(self): guard = synthetic_guard() collector.guard_gate(guard, Path("private"), "runtime") @@ -735,18 +896,18 @@ class ReportTests(unittest.TestCase): pass return rows, launched rows, launched = execute() - self.assertEqual(launched, ["import", "R0", "P1", "P2", "O0", "P3", "P4"]) - self.assertEqual(rows[1]["report"]["stop_reason"], "simulation_overloaded") - self.assertEqual(execute(failure=True)[1], ["import", "R0"]) + self.assertEqual(launched, ["import", "parse-base", "parse-wrapper", "R0", "P1", "P2", "O0", "P3", "P4"]) + self.assertEqual(rows[3]["report"]["stop_reason"], "simulation_overloaded") + self.assertEqual(execute(failure=True)[1], ["import", "parse-base", "parse-wrapper", "R0"]) rows, launched = execute(duration=20) - self.assertEqual(launched, ["import", "R0", "O0", "P3", "P4"]) + self.assertEqual(launched, ["import", "parse-base", "parse-wrapper", "R0", "O0", "P3", "P4"]) self.assertEqual([r["phase"] for r in rows if r.get("engines_started") == 0], ["P1", "P2"]) rows, launched = execute(minutes=0) - self.assertEqual(len(launched), 7) - self.assertIsNone(rows[1]["extrapolation"]["seconds_per_phase"]) - self.assertEqual(rows[1]["extrapolation"]["reason"], "no_minutes_observed") - self.assertIsNone(rows[2]["projection"]["projected_total_seconds"]) + self.assertEqual(len(launched), 9) + self.assertIsNone(rows[3]["extrapolation"]["seconds_per_phase"]) + self.assertEqual(rows[3]["extrapolation"]["reason"], "no_minutes_observed") + self.assertIsNone(rows[4]["projection"]["projected_total_seconds"]) shortfall = synthetic_report() shortfall.update(stop_reason="input_shortfall", frames=[], actual_minutes=0) checker.check_report(shortfall) From 061df6f12050bae5bee58fdcedec19a11324c1a4 Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 23:27:09 +0900 Subject: [PATCH 7/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../execution/p28-01/collector/test_collect_p28_01.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index dfb6378..690c113 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -11,6 +11,7 @@ import tempfile import time from types import SimpleNamespace import unittest +import uuid from unittest.mock import patch sys.dont_write_bytecode = True @@ -755,7 +756,7 @@ class ReportTests(unittest.TestCase): "--headless", "--path", str(stage), "--check-only", "--script", "probe"] row = collector.run_private_engine( standard, SimpleNamespace(run_phase=owned), command, base / label, {}, - stage, public, "TheTree-PCK-tests-" + base.name + "-" + label) + stage, public, "TheTree-PCK-tests-" + uuid.uuid4().hex + "-p28-" + label) row.update(phase=label, parse_na=copy.deepcopy(collector.PARSE_NA), source_preserved=True, player_preserved=True, script_pins=pins, stage_before_sha256=collector.digest(source), @@ -842,9 +843,9 @@ class ReportTests(unittest.TestCase): public = b'[application]\n\nconfig/name="The Tree"\n' (base / "project.godot").write_bytes(public) with patch.object(collector, "run_engine", side_effect=RuntimeError("owned failure")), \ - self.assertRaises(RuntimeError): + self.assertRaisesRegex(RuntimeError, "owned failure"): collector.run_private_engine(standard, None, [], base / "parse-base", {}, base, - public, "TheTree-PCK-tests-" + base.name) + public, "TheTree-PCK-tests-" + uuid.uuid4().hex + "-p28-parse-base") self.assertEqual((base / "project.godot").read_bytes(), public) def test_j3_guard_and_whole_inventory(self): From 25198e2924948e5ac2c0c4774d5adfcb6267833c Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 23:44:54 +0900 Subject: [PATCH 8/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/collect_p28_01.py | 3 +- .../p28-01/collector/test_collect_p28_01.py | 104 ++++++++++++++++++ 2 files changed, 106 insertions(+), 1 deletion(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py index 56fa984..707111f 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/collect_p28_01.py @@ -321,9 +321,10 @@ def main(): planned = execution_plan(args.engine, stage, wrapper) admission = {"commit": commit, "source_map": before, "source_map_sha256": digest(before), "readonly": pins, "engine_sha256": ENGINE_SHA, "engine_version": VERSION, - "fixture_sha256": FIXTURE_SHA, "planned_argv": planned, "phases": PHASES, + "fixture_sha256": FIXTURE_SHA, "planned_argv": planned, "phases": [list(p) for p in PHASES], "budget_verdict_scope": VERDICT_SCOPE, "reused_r02": reused_observations(args.readonly, pins)} + require(admission == json.loads(json.dumps(admission)), "admission JSON representation drift") check_admission(admission) if args.check: print(json.dumps(dict(admission, stages_created=0, engines_started=0), ensure_ascii=False, indent=2)) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index 690c113..1a3ea0e 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -170,6 +170,110 @@ def synthetic_admission(): class ReportTests(unittest.TestCase): + def constructed_admission(self, reused=None): + """Run actual CLI construction, stopping before stages or engines exist.""" + class AdmissionReached(Exception): + pass + + captured = {} + def capture(admission): + checker.check_admission(admission) + captured.update(admission) + raise AdmissionReached() + + with tempfile.TemporaryDirectory() as temp: + base = Path(temp) + fixture = base / "fixture" + fixture.write_bytes(b"synthetic") + engine = base / "engine" + argv = ["collect", "--readonly", str(base), "--fixture", str(fixture), + "--engine", str(engine), "--output", str(base / "output"), "--run"] + with patch.object(sys, "argv", argv), \ + patch.object(collector, "load_tool") as load_tool, \ + patch.object(collector, "inputs", return_value={}), \ + patch.object(collector, "sha", side_effect=lambda p: + collector.FIXTURE_SHA if p == fixture else collector.ENGINE_SHA), \ + patch.object(collector, "source_map", return_value={}), \ + patch.object(collector.subprocess, "check_output", side_effect=["synthetic\n", ""]), \ + patch.object(collector, "reused_observations", + return_value=synthetic_admission()["reused_r02"] if reused is None else reused), \ + patch.object(collector, "check_admission", side_effect=capture) as admission_gate, \ + patch.object(collector, "no_live_engine") as live_gate, \ + patch.object(collector, "run_engine") as engine_gate: + try: + try: + collector.main() + except AdmissionReached: + pass + finally: + live_gate.assert_not_called() + engine_gate.assert_not_called() + self.assertEqual(load_tool.call_args_list, [ + unittest.mock.call(collector.EXTERNAL_IMPORTS[0])]) + self.assertFalse((base / "output").exists()) + if reused is not None: + admission_gate.assert_not_called() + self.assertTrue(captured) + return captured + + def admission_receipt(self, base, admission, labels): + collector.write(base / "admission.json", admission) + probe = (HERE / "measure_p28_01.gd").read_bytes() + (base / "measure_p28_01.gd").write_bytes(probe) + return {"admission": admission, + "phases": [{"phase": label, "phase_stop": {}, + "startup_project": {"profile": "synthetic-" + label}} for label in labels], + "source_before": {}, "source_after": {}, + "default_player_before": {}, "default_player_after": {}, + "cleanup_errors": [], "cleanup": [], "error": None, "passed": True, + "probe_check": {"sha256": hashlib.sha256(probe).hexdigest(), "passed": True}} + + def test_n1_admission_roundtrip_receipt_binding(self): + admission = self.constructed_admission() + self.assertEqual(admission["phases"], [list(p) for p in collector.PHASES]) + self.assertIsInstance(collector.PHASES, tuple) + with tempfile.TemporaryDirectory() as temp: + base = Path(temp) + receipt = self.admission_receipt( + base, admission, ["import", *collector.PARSE_PHASES, *checker.PHASES]) + self.assertEqual(admission, json.loads((base / "admission.json").read_text())) + # Actual binding and full phase-order gates pass. Stop at the next + # gate using an intentionally incomplete synthetic phase cap. + with self.assertRaisesRegex(ValueError, r"^phase cap origin keys$"): + checker.check_receipt(receipt, base) + + def test_n1_persisted_admission_tampering(self): + admission = self.constructed_admission() + for field in ("phases", "commit"): + with self.subTest(field=field), tempfile.TemporaryDirectory() as temp: + base = Path(temp) + receipt = self.admission_receipt( + base, admission, ["import", *collector.PARSE_PHASES, *checker.PHASES]) + persisted = json.loads((base / "admission.json").read_text()) + if field == "phases": + persisted[field][0][2] = 3 + else: + persisted[field] = "tampered" + (base / "admission.json").write_text(json.dumps(persisted)) + with self.assertRaisesRegex(ValueError, r"^admission binding\." + field + "$"): + checker.check_receipt(receipt, base) + + def test_n2_remaining_tuple_rejected_before_startup(self): + reused = synthetic_admission()["reused_r02"] + reused["remaining_tuple"] = ("must", "reject") + with self.assertRaisesRegex(ValueError, r"^admission JSON representation drift$"): + self.constructed_admission(reused) + + def test_n3_subset_receipt_rejected_by_phase_order(self): + admission = self.constructed_admission() + for labels in (["import", "parse-base", "parse-wrapper", "R0"], + ["import", *collector.PARSE_PHASES, *list(checker.PHASES)[:-1]]): + with self.subTest(labels=labels), tempfile.TemporaryDirectory() as temp: + base = Path(temp) + receipt = self.admission_receipt(base, admission, labels) + with self.assertRaisesRegex(ValueError, r"^phase order$"): + checker.check_receipt(receipt, base) + def test_k1_audio_close_receipts(self): report = {"main_added": True, "audio_owner_present": True} close = {"coordinator": True, "passed": True, "deadline_reached": False, From 5db97d78a15c2895ac5379a8bbba2fb95f0004dd Mon Sep 17 00:00:00 2001 From: Agent Control Runner Date: Tue, 20 Oct 2026 23:56:37 +0900 Subject: [PATCH 9/9] =?UTF-8?q?P28-01-COLLECTOR:=20=E7=8F=BEHEAD=E3=81=AE?= =?UTF-8?q?=E6=80=A7=E8=83=BD=E5=9F=BA=E6=BA=96=EF=BC=9Awindowed=20x1/x3?= =?UTF-8?q?=E3=83=BBOperations=20ON=20collector?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../p28-01/collector/check_p28_01_report.py | 39 ++++++++++- .../p28-01/collector/measure_p28_01.gd | 29 ++++++-- .../p28-01/collector/test_collect_p28_01.py | 69 +++++++++++++++++++ 3 files changed, 132 insertions(+), 5 deletions(-) diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py index e5fbab1..36a0663 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/check_p28_01_report.py @@ -132,7 +132,8 @@ def normalize_report(value, path=()): key = path[-1] if path else "" declared = key in INTEGER_FIELDS or key.endswith("_us") declared = declared or (key == "frames" and not isinstance(value, list)) - declared = declared or (len(path) >= 2 and path[-2] in ("samples_us", "kernel_stall_samples_us", "sample_counts")) + declared = declared or (len(path) >= 2 and (path[-2] == "sample_counts" or + (key == "[]" and path[-2] in ("samples_us", "kernel_stall_samples_us")))) declared = declared or ("budget_verdict" in path and key == "value") declared = declared or ("count_ranges" in path and key in ("min", "max")) declared = declared or (len(path) >= 2 and path[-2] in @@ -146,6 +147,40 @@ def normalize_report(value, path=()): return value +def check_budget_snapshot(snapshot): + need(isinstance(snapshot, dict), "budget snapshot object") + for entry in snapshot.values(): + keys(entry, ("samples_us", "lifetime_count", "reason", "provenance")) + provenance = entry["provenance"] + columns = ("samples_us", "lifetime_count") + keys(provenance, columns) + for column in columns: + keys(provenance[column], ("dictionary_readable", "key_form")) + need(type(provenance[column]["dictionary_readable"]) is bool, + "budget dictionary availability") + both_readable = all(provenance[c]["dictionary_readable"] for c in columns) + for column, zero in (("samples_us", []), ("lifetime_count", 0)): + observed = provenance[column] + form, value = observed["key_form"], entry[column] + if not observed["dictionary_readable"]: + need(form is None and value is None, "budget unreadable dictionary must remain null") + elif form in ("absent", "absent_means_zero_per_product"): + if both_readable: + need(form == "absent_means_zero_per_product" and type(value) is type(zero) + and value == zero, "budget readable absent key must use product zero") + else: + need(form == "absent" and value is None, + "budget absent key without readable dictionaries") + else: + need(form in ("String", "StringName"), "budget present key form") + if value is not None: + need((isinstance(value, list) and all(type(x) is int and x >= 0 for x in value)) + if column == "samples_us" else type(value) is int and value >= 0, + "budget sample value") + expected = "counts_unavailable" if entry["samples_us"] is None or entry["lifetime_count"] is None else None + need(entry["reason"] == expected, "budget availability reason") + + def budget_verdict(before, after, speed): result = {} for metric, aggregation, limit in ((f"simulation_x{speed}", "average" if speed == 1 else "p95", @@ -284,6 +319,8 @@ def interval(report, name): def check_report(report): check_budget_scope(report, ((),)) + for name in ("budget_at_warmup_end", "budget_at_phase_end"): + check_budget_snapshot(report[name]["data"]) for name in RAW_FIELDS: keys(report[name], ("source", "data")) equal(report["probe_deadline"], {"limit_seconds": 1740, "source": DEADLINE_SOURCE}, "probe deadline") diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd index 05d2f4b..c33538a 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/measure_p28_01.gd @@ -76,11 +76,32 @@ func field(d: Variant, name: String) -> Variant: func budget_snapshot() -> Dictionary: var result := {} var profiler: Variant = clock.performance_budget + var sample_dictionary: Variant = profiler.get("_samples") + var count_dictionary: Variant = profiler.get("_sample_counts") + var both_readable := sample_dictionary is Dictionary and count_dictionary is Dictionary for metric: String in ["simulation_x1", "simulation_x3", "main_thread_stall"]: - var samples: Variant = field(profiler.get("_samples"), metric) - var count: Variant = field(profiler.get("_sample_counts"), metric) - result[metric] = {"samples_us": samples.duplicate() if samples is Array else null, - "lifetime_count": count, "reason": "counts_unavailable" if count == null or samples == null else null} + var entry := {} + var provenance := {} + for column: String in ["samples_us", "lifetime_count"]: + var dictionary: Variant = sample_dictionary if column == "samples_us" else count_dictionary + var value: Variant = null + var key_form: Variant = null + if dictionary is Dictionary: + key_form = "absent" + for key: Variant in dictionary.keys(): + if (key is StringName or key is String) and String(key) == metric: + key_form = "StringName" if key is StringName else "String" + value = dictionary[key] + break + if key_form == "absent" and both_readable: + # performance_budget.gd uses get(metric, []) / get(metric, 0). + value = [] if column == "samples_us" else 0 + key_form = "absent_means_zero_per_product" + provenance[column] = {"dictionary_readable": dictionary is Dictionary, "key_form": key_form} + entry[column] = (value.duplicate() if value is Array else null) if column == "samples_us" else value + entry["provenance"] = provenance + entry["reason"] = "counts_unavailable" if entry.samples_us == null or entry.lifetime_count == null else null + result[metric] = entry return result func kernel_verdict(before: Dictionary, after: Dictionary) -> Dictionary: diff --git a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py index 1a3ea0e..09611e4 100644 --- a/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py +++ b/docs/plans/original-completion-2026-10-02/execution/p28-01/collector/test_collect_p28_01.py @@ -144,6 +144,11 @@ def synthetic_report(): "statistics": {"count": 10, "average_us": 3000, "p95_us": 3000, "maximum_us": 3000}} for k, aggregate, limit in (("simulation_x1", "average", 4000), ("main_thread_stall", "maximum", 50000))} + for name in ("budget_at_warmup_end", "budget_at_phase_end"): + for entry in report[name].values(): + entry.update(reason=None, provenance={ + c: {"dictionary_readable": True, "key_form": "StringName"} + for c in ("samples_us", "lifetime_count")}) for name in checker.RAW_FIELDS: report[name] = {"source": checker.RAW_SOURCE, "data": report[name]} report["probe_deadline"] = {"limit_seconds": 1740, "source": checker.DEADLINE_SOURCE} @@ -616,6 +621,10 @@ class ReportTests(unittest.TestCase): ("no_interval_samples", 30), ("counts_unavailable", None)): r = synthetic_report() r["budget_at_phase_end"]["data"]["simulation_x1"]["lifetime_count"] = count + if count is None: + entry = r["budget_at_phase_end"]["data"]["simulation_x1"] + entry["reason"] = "counts_unavailable" + entry["provenance"]["lifetime_count"] = {"dictionary_readable": False, "key_form": None} r["budget_verdict"] = checker.budget_verdict(r["budget_at_warmup_end"]["data"], r["budget_at_phase_end"]["data"], 1) self.assertEqual(r["budget_verdict"]["simulation_x1"]["reason"], reason) @@ -625,6 +634,66 @@ class ReportTests(unittest.TestCase): with self.assertRaises(ValueError): checker.check_report(r) + def test_c8_readable_absent_baseline_uses_actual_interval(self): + r = synthetic_report() + samples = [401870, 368451, 374607, 363011, 371589, + 465303, 359596, 361040, 362532, 354702] + for metric in ("simulation_x1", "main_thread_stall"): + entry = r["budget_at_warmup_end"]["data"][metric] + entry.update(lifetime_count=0, samples_us=[]) + for observed in entry["provenance"].values(): + observed["key_form"] = "absent_means_zero_per_product" + r["budget_at_phase_end"]["data"][metric].update( + lifetime_count=10, samples_us=samples) + r["budget_verdict"] = checker.budget_verdict( + r["budget_at_warmup_end"]["data"], r["budget_at_phase_end"]["data"], 1) + checker.check_report(r) + for metric, value in (("simulation_x1", sum(samples) // 10), + ("main_thread_stall", max(samples))): + verdict = r["budget_verdict"][metric] + self.assertEqual(verdict["value"], value) + self.assertEqual(verdict["statistics"]["count"], 10) + self.assertIs(verdict["passed"], False) + self.assertIsNone(verdict["reason"]) + for column in ("samples_us", "lifetime_count"): + broken = copy.deepcopy(r) + entry = broken["budget_at_warmup_end"]["data"]["simulation_x1"] + entry[column] = None + entry["reason"] = "counts_unavailable" + with self.subTest(column=column), self.assertRaisesRegex( + ValueError, "budget readable absent key must use product zero"): + checker.check_report(broken) + broken = copy.deepcopy(r) + broken["budget_at_warmup_end"]["data"]["simulation_x1"]["reason"] = "counts_unavailable" + with self.assertRaisesRegex(ValueError, "budget availability reason"): + checker.check_report(broken) + + def test_c8_unreadable_dictionaries_remain_unavailable(self): + for unavailable in (("samples_us",), ("lifetime_count",), + ("samples_us", "lifetime_count")): + r = synthetic_report() + entry = r["budget_at_warmup_end"]["data"]["simulation_x1"] + for column in unavailable: + entry[column] = None + entry["provenance"][column] = {"dictionary_readable": False, "key_form": None} + entry["reason"] = "counts_unavailable" + r["budget_verdict"] = checker.budget_verdict( + r["budget_at_warmup_end"]["data"], r["budget_at_phase_end"]["data"], 1) + # An unreadable samples dictionary alone leaves the actual count usable; + # retain the existing verdict extraction rule (it uses the end samples). + checker.check_report(r) + if "lifetime_count" in unavailable: + self.assertEqual(r["budget_verdict"]["simulation_x1"]["reason"], "counts_unavailable") + self.assertIsNone(r["budget_verdict"]["simulation_x1"]["passed"]) + for column in unavailable: + broken = copy.deepcopy(r) + bad = broken["budget_at_warmup_end"]["data"]["simulation_x1"] + bad[column] = [] if column == "samples_us" else 0 + bad["provenance"][column]["key_form"] = "absent_means_zero_per_product" + with self.subTest(unavailable=unavailable, column=column), self.assertRaisesRegex( + ValueError, "budget unreadable dictionary must remain null"): + checker.check_report(broken) + def test_h3_save_stall_correlation(self): r = synthetic_report() r["save_events"] = [{"frame": 2, "game_minute": 363, "ok": True,