Skip to content

[M1-PROF-01] Profiler core: always-on counters, snapshot, per-run report, --prof-out - #47

Merged
offdev merged 4 commits into
masterfrom
m1-prof-01-profiler-core
Sep 21, 2026
Merged

offdev merged 4 commits into
masterfrom
m1-prof-01-profiler-core

Conversation

@offdev

@offdev offdev commented Sep 21, 2026 •

Copy link
Copy Markdown
Owner

Implements M1-PROF-01 · Profiler core (cheap counters) from roadmap/M1-heartbeat.md (FR-11.1, FR-11.2; PRD §15.1 DBG-008; AGENTS CORE-001, PERF-003, DBG-004). Depends M1-SYS-03 + M1-ECS-06 (done).

What

  • Profiler (src/laige-sim/include/laige/sim/profiler.h + profiler.cpp): the always-on counters with fixed storage and no allocation after init — tick/frame time rolling windows (512/256 samples, M0-CORE-08 Histogram; O(1) allocation-free record(), drops the oldest, totalRecorded() keeps counting), the FR-11.1 render/network counter fields (0 in headless M1 — the fields exist; M2/M3 feed them), and the cold snapshot() / snapshot(world) (world-pulled fields: entity total/alive/capacity, sim alloc count = World::archetypeStats().totalReservations (M1-ECS-03 pool accounting, target 0), system count — pulled cold, never copied; the per-system M1-SYS-03 windows stay in World, pulled only in the report). Move-only; moved-from = stopped (records no-op, empty snapshot); setEnabled (disabled = one branch, no recording).
  • Reports (FR-11.1 file export): formatProfileSummaryLine (the CLI one-liner), formatProfileText (greppable text form), formatProfileJson (version 1 schema — n==0 windows render n=0 / JSON null, never NaN), writeProfile (truncating write, no partial file on failure, Result<u64, ErrorCode>).
  • GameLoop: Options::profiler (non-owning); runOneTick times the tick body (the frame's beginFrame + one runSystems dispatch) with the M0-CORE-08 TimeIt and records on success only (a failed tick is neither counted nor recorded); null/disabled = one branch (DBG-004).
  • Engine: owns the profiler (created in Engine::create — engine setup, not run setup, so the "exactly three one-shot allocations per run" claim stays true; released in the ordered shutdown after the world). runFrames adds the frame feed (two clock reads + one ring write per frame, excluding the pacing sleep; first frame not recorded; failed frames not recorded). Per-run report: startProfileReport(path) (EVERY build — diagnostics, not replay state), written at the END of the run on EVERY path (a zero-tick run writes a zero-tick report, CORE-008); a write failure does not fail the run (sticky profileReportStatus(), profiler/report_write_failed); profileStats() = the last run's cached snapshot (the world is released in shutdown); structured profiler/* events (NFR-13.3 5-field grammar).
  • laige-run: --prof-out <report> + the always-printed laige-run profile: … one-line summary on stdout — the byte-stable status=ok line is untouched (separate line; laige_run_smoke's PASS_REGULAR_EXPRESSION stays valid). A report write failure leaves the run status=ok and exits 2.
  • Docs in the same change: docs/api/profiler.md (new — full contract, counter table, report schemas, Performance, misuse), engine.md, game_loop.md, docs/README.md, src/laige-sim/README.md, docs/debugging/README.md, tools/README.md; baseline docs/benchmarks/baselines/m1-profiler-cost.md (full AGENTS §12 metadata + verbatim runs).
  • Roadmap: M1-heartbeat checkbox [x]; Progress Board M1 20 → 21 (total 38 → 39) + one Change Log line; laige-api.json regenerated.

The 1% disabled-cost gate (CORE-001, DBG-004)

ProfilerCost suite: ON vs OFF over 10k-entity ticks (2000 ticks/run, best-of-2 per arm, warm-up discarded), measured with a test-side TimeIt+Histogram in both arms (cancels in the ratio). Measured on the canonical Debug g++ tree:

profiler-cost on_p50=0.557288 off_p50=0.555746 overhead_pct=0.277465

+0.28% — well inside the 1% gate; the suite asserts the bound on every non-instrumented tree, every CI run (the CI linux-gcc / linux-clang P0 jobs). The gate is scoped to non-sanitizer trees (LAIGE_ALLOC_COUNTER, the zero-allocation probe's precedent): the first ASan CI run measured 1.46% — sanitizer instrumentation inflates the profiler's fixed per-tick cost (extra clock reads + the ring write's shadow bookkeeping) disproportionately, so a sanitizer-tree number would measure the instrumentation, not the profiler (recorded in the baseline doc). The sanitizer trees instead verify the profiler's safety properties (leak-free ASan run, race-free TSan run).

Verification

  • Canonical g++ tree: zero warnings; full ctest 89/89 (new profiler entry; api-real-tree + determinism-lint-real-tree green — the raw double tokens carry LAIGE-DETERM-EXCEPTION: G-R8 wall-clock diagnostic markers per the M1-SYS-03 precedent; laige_run_smoke byte-stable line intact).
  • laige-run --prof-out smoke: profile summary line on stdout + valid version-1 JSON report on disk (counters, windows, world fields, per-system windows).
  • Cross-trees: build-asan, build-clang, build-release, build-tsan (TSan halt_on_error=1 on profiler), build-shared — all built zero-warning, full ctest green.
  • tools/laige-include-lint OK (43 source files, 1/10 vendored deps).
  • Record path zero-allocation: profiler-zeroalloc ticks=1000 allocs=0 (non-sanitizer trees).

Unverified: MSVC/AppleClang compile proof (CI-only, the house precedent); the M2 overlay surface and the M3 net-byte feed (later steps by design).

…ort, --prof-out

- New public header src/laige-sim/include/laige/sim/profiler.h (+ profiler.cpp):
  the FR-11.1 always-on counters (fixed storage, no allocation after init)
  — tick/frame time rolling windows (512/256 samples, M0-CORE-08
  Histogram; O(1) allocation-free record, drops the oldest, the windows'
  totalRecorded() keeps counting), draw calls / texture binds / net bytes
  counters (0 in headless M1 — the fields exist; M2/M3 feed them), and the
  cold snapshot (own counters; snapshot(world) adds the world-pulled
  fields — entity total/alive/capacity, sim alloc count =
  World::archetypeStats().totalReservations (M1-ECS-03 pool accounting,
  target 0), system count — pulled cold, never copied; the per-system
  M1-SYS-03 windows stay in World and are pulled only in the report).
  Move-only (moved-from = stopped: records no-op, empty snapshot);
  setEnabled/enabled (disabled = one branch, no recording); G-R8
  exception markers on the raw double tokens (wall-clock diagnostic —
  never enters sim state, hashes, or replays, ARCH-009).
- Report surface: formatProfileSummaryLine (the CLI one-liner),
  formatProfileText (greppable text form), formatProfileJson (version 1
  schema — counters, tick/frame windows (n==0 -> n=0 text / JSON null,
  never NaN), world fields, per-system entries with the M1-SYS-03 window
  stats), writeProfile (truncating write, no partial file on failure,
  Result<u64, ErrorCode> -> IoError).
- game_loop.h/.cpp: Options::profiler (non-owning); runOneTick times the
  tick body (beginFrame + runSystems) with the M0-CORE-08 TimeIt and
  records on SUCCESS only (a failed tick is neither counted nor recorded);
  null/disabled = one branch (DBG-004).
- engine.h/.cpp: the engine owns the profiler (created in Engine::create
  — engine setup, not run setup: the run's 'exactly three one-shot
  allocations' claim stays true; released in the ordered shutdown after
  the world, abandoning a started-but-unfinalized report with
  profiler/report_aborted); runFrames adds the frame feed (two clock
  reads + one ring write per frame, excluding the pacing sleep; first
  frame not recorded; failed frames not recorded); the per-run report:
  startProfileReport(path) (EVERY build — diagnostics, not replay state),
  written at the END of the run on EVERY path (a zero-tick run writes a
  zero-tick report, CORE-008); a write failure does NOT fail the run
  (sticky profileReportStatus(), profiler/report_write_failed Error);
  profileStats() = the last run's cached snapshot (the world is released
  in shutdown); structured profiler/* events (NFR-13.3 5-field grammar).
- tools/run/laige-run.cpp: --prof-out <report> (start failure exits 2; a
  write failure leaves the run status=ok and exits 2) + the always-
  printed 'laige-run profile: ...' one-line summary on stdout (the
  byte-stable 'status=ok' line untouched — the summary is a separate
  line, the laige_run_smoke PASS_REGULAR_EXPRESSION stays valid).
- tests: new profiler CTest entry (26 tests: exact percentiles 1..100
  -> p50=50/p95=95/p99=99/mean=50.5, rollover, independent windows,
  zero-capacity drop, adders, disabled no-op + preserved state,
  moved-from stop, cold snapshot, per-completed-tick timing (failed
  tick unrecorded), the engine's per-run cache + report (written on
  every run path, version-1 JSON parseable, double-start/empty-path/
  stopped-engine rejections, write failure sticky without failing the
  run, pre-run shutdown abandonment with no file on disk), the greppable
  text form, the record path's zero-allocation
  (profiler-zeroalloc ticks=1000 allocs=0, non-sanitizer trees), and
  the enabled-cost gate ON vs OFF over 10k-entity ticks <= 1%
  (profiler-cost on_p50=0.557288 off_p50=0.555746 overhead_pct=0.277465,
  best-of-2 per arm, every tree)); profiler added to the TSan
  halt_on_error list.
- Docs in the same change: docs/api/profiler.md (new — the full
  contract, counter table, report schemas, Performance, misuse),
  engine.md (the profiler section, --prof-out, exit codes, performance,
  misuse, testing), game_loop.md (Options::profiler, the profiler feed
  section, performance, misuse), docs/README.md, src/laige-sim/README.md,
  docs/debugging/README.md, tools/README.md; baseline
  docs/benchmarks/baselines/m1-profiler-cost.md (full AGENTS §12
  metadata + verbatim runs; measured +0.28% vs the 1% gate).
- Roadmap: M1-heartbeat.md checkbox [x]; Progress Board M1 20 -> 21
  (total 38 -> 39) + one Change Log line.
- laige-api.json regenerated (api-real-tree green).
- Verified: canonical g++ tree zero-warning, full ctest 89/89 (incl. the
  new profiler entry, api-real-tree, determinism-lint-real-tree,
  laige_run_smoke with the byte-stable line intact); cross-trees
  build-asan / build-clang / build-release / build-tsan / build-shared
  all built zero-warning with full ctest green; tools/laige-include-lint
  OK (43 source files); laige-run --prof-out smoke: the profile summary
  line on stdout + the valid version-1 JSON report on disk.
The ASan CI job measured profiler overhead at 1.46% (on_p50=1.14485
off_p50=1.12836) — sanitizer instrumentation inflates the
profiler's fixed per-tick cost (extra clock reads + the ring write
shadow bookkeeping) disproportionately, so a sanitizer-tree
measurement would measure the instrumentation, not the profiler.
Gate the ProfilerCost suite on LAIGE_ALLOC_COUNTER (the
zero-allocation probe's precedent for excluding measurement probes
from sanitizer trees); the CI linux-gcc / linux-clang P0 jobs
enforce the bound. Docs + baseline updated (the ASan measurement
recorded as an instrumentation property).
@offdev
offdev merged commit 8c5770b into master Sep 21, 2026
11 checks passed
offdev added a commit that referenced this pull request Sep 22, 2026
Every non-instrumented P0 CI job enforces the 1% enabled-cost gate
(the linux-gcc and linux-clang jobs AND the windows-msvc and both
macOS jobs' ctest alike) — the macOS arm64 job's run of the gate is
exactly what exposed the blocked-arm-order drift in #47's merge;
the old 'the CI linux-gcc and linux-clang P0 jobs' wording understated
the live scope.
offdev added a commit that referenced this pull request Sep 22, 2026
…r-cost gate (#48)

* Fix Windows/macOS CI: profiler MSVC /WX warnings; drift-proof profiler-cost gate

The M1-PROF-01 merge (#47) broke two P0 jobs on master:

- windows-msvc (BUILD): profiler.cpp (new in the merge) had never been
  compiled under MSVC's /W4 /WX. The CI log's exact warning set:
  * C4244 (treated as error): the seven uint64_t counters implicitly
    converted to double at JsonValue::fromNumber in formatProfileJson
    (ticks, frames, draw_calls, texture_binds, net_bytes, sim_allocs,
    system runs; the uint32_t fields convert exactly and are left
    alone). Fixed with explicit static_cast<double> + the per-line
    LAIGE-DETERM-EXCEPTION marker for the double token (the
    determinism-lint policy; the existing stats.n cast precedent).
  * C4996 (treated as error): plain std::fopen in writeProfile. Fixed
    with a portable openProfileFile helper following the
    _fsopen(..., _SH_DENYNO) precedent of replay.cpp / config.cpp /
    logging.cpp (plain-fopen sharing semantics).

- windows-msvc (TEST, latent): profiler_tests.cpp used plain
  std::fopen in readFile/fileExists — uncompiled in the failed run
  because the build stopped at profiler.cpp. Same _fsopen(_SH_DENYNO)
  precedent via an openReportFile helper (replay_record_tests.cpp
  precedent).

- macos-arm64 (TEST): ProfilerCost.EnabledCostBoundedToOnePercent
  measured 2.14% against the 1% gate (on_p50=0.260291
  off_p50=0.254833) while the canonical baseline of the same
  measurement is 0.28% — the profiler's fixed per-tick cost (two
  steady_clock reads + one O(1) ring write) is far below 2% of any
  supported platform's 10k-entity tick. Root cause: the original
  BLOCKED arm order (all ON runs before all OFF runs) measured the
  two arms in two different phases of the CI runner's frequency/
  thermal drift under sustained load — the drift itself showed up
  as overhead, one direction only. Verified locally on the
  baseline's own CPU (Ryzen 7950X3D, sustained load): the blocked
  order spread -1.9%...+1.3% over 10 runs while the true overhead is
  ~0.03-0.08%. Fix: per-tick A/B interleaving — the profiler is
  enabled on every other tick (a runtime setEnabled, the DBG-002
  switch), so each ON sample is adjacent (~1 ms) to an OFF sample;
  both subsequences sample the same machine-state trajectory, and
  the phase cancels at the adjacent-sample level. A transient CI
  stall slows at most one tick = one sample of 2000 in one window
  (no p50 effect — no best-of-N repetition needed). After the fix:
  10/10 runs at -0.01%...+0.08% (12-30x inside the gate). The 1%
  gate, the workload, and the machine-greppable line format are
  unchanged.

Verified: canonical g++ and clang++ trees build zero-warning, full
ctest 89/89 green (incl. the profiler entry, api-real-tree,
determinism-lint-real-tree, laige_run_smoke); the ASan tree builds
zero-warning and the profiler suite passes there (the ProfilerCost
gate stays excluded from sanitizer trees — the LAIGE_ALLOC_COUNTER
gate, unchanged). include-lint + determinism-lint OK; no public API
surface change (laige-api.json untouched). The 12 hello_* failures of
the first local run were a race on the shared samples/hello/bin/
binaries (three local trees building the same source-tree path in
parallel — CI checkouts are isolated); sequential per-tree runs are
green. MSVC and AppleClang verified through the PR's ci:windows /
ci:macos jobs.

* ci: retrigger PR workflow (label context)

* docs(api/profiler): correct the cost-gate enforcement scope

Every non-instrumented P0 CI job enforces the 1% enabled-cost gate
(the linux-gcc and linux-clang jobs AND the windows-msvc and both
macOS jobs' ctest alike) — the macOS arm64 job's run of the gate is
exactly what exposed the blocked-arm-order drift in #47's merge;
the old 'the CI linux-gcc and linux-clang P0 jobs' wording understated
the live scope.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant