diff --git a/docs/api/profiler.md b/docs/api/profiler.md index 902c415..95d4bf7 100644 --- a/docs/api/profiler.md +++ b/docs/api/profiler.md @@ -233,8 +233,9 @@ compressed into one greppable line. zero-allocation probe's precedent: sanitizer instrumentation inflates the profiler's fixed per-tick cost disproportionately (1.46% measured on the ASan tree, 2026-09-21), so it measures the - instrumentation, not the profiler; the CI linux-gcc and linux-clang - P0 jobs enforce it). + instrumentation, not the profiler; every non-instrumented P0 CI + job enforces it — the linux-gcc and linux-clang jobs, and the + windows-msvc and both macOS jobs' ctest alike). - **Cold path:** `snapshot()` / `tickTime()` / `frameTime()` are O(n log n) over the stored window (no allocation — the `Histogram`'s pre-reserved scratch buffer); the report formatters @@ -287,8 +288,8 @@ compressed into one greppable line. line; **non-sanitizer trees only** — the `LAIGE_ALLOC_COUNTER` gate, the zero-allocation probe's precedent: sanitizer instrumentation inflates the profiler's fixed per-tick cost and - would measure the instrumentation, not the profiler; the CI - linux-gcc / linux-clang P0 jobs enforce the bound). + would measure the instrumentation, not the profiler; every + non-instrumented P0 CI job enforces the bound). - `ctest -R laige_run_smoke` — the CLI smoke (the byte-stable `status=ok` line; the profile summary line follows it). - The TSan job runs the `profiler` entry with diff --git a/src/laige-sim/profiler.cpp b/src/laige-sim/profiler.cpp index 881b3b3..c8778bc 100644 --- a/src/laige-sim/profiler.cpp +++ b/src/laige-sim/profiler.cpp @@ -21,6 +21,10 @@ #include #include +#if defined(_MSC_VER) +#include // _SH_DENYNO: plain-fopen sharing for _fsopen +#endif + #include "laige/budget_harness.h" // formatStatsLine (the stats-line format) #include "laige/fpx16_16.h" // fpx16_16::toFloat (the system budgets) #include "laige/json.h" // JsonValue + serializeJson (the report) @@ -66,6 +70,19 @@ void appendCount(std::string& out, const char* name, std::uint64_t value) { out += ' '; } +// Portable file open (CPP-009 platform boundary, the replay.cpp / +// logging.cpp precedent): MSVC's CRT deprecates plain `fopen` (C4996, +// fatal under the engine's /WX policy); the MSVC path uses +// `_fsopen(path, mode, _SH_DENYNO)` — plain-`fopen` sharing semantics +// every other supported compiler provides. +std::FILE* openProfileFile(const std::string& path, const char* mode) { +#if defined(_MSC_VER) + return ::_fsopen(path.c_str(), mode, _SH_DENYNO); +#else + return std::fopen(path.c_str(), mode); +#endif +} + // The JSON form of one window's stats (null when empty — the report // never carries NaN, the serializeJson precondition). JsonValue statsObject(const HistogramStats& s) { @@ -274,12 +291,16 @@ std::string formatProfileJson(const Profiler& profiler, const World& world) { root.setMember("version", JsonValue::fromNumber(1)); JsonValue counters = JsonValue::makeObject(); - counters.setMember("ticks", JsonValue::fromNumber(stats.ticks)); - counters.setMember("frames", JsonValue::fromNumber(stats.frames)); - counters.setMember("draw_calls", JsonValue::fromNumber(stats.drawCalls)); + counters.setMember("ticks", + JsonValue::fromNumber(static_cast(stats.ticks))); // LAIGE-DETERM-EXCEPTION: G-R8 report field: u64 counter to JSON number (M1-PROF-01, ARCH-009) + counters.setMember("frames", + JsonValue::fromNumber(static_cast(stats.frames))); // LAIGE-DETERM-EXCEPTION: G-R8 report field: u64 counter to JSON number (M1-PROF-01, ARCH-009) + counters.setMember("draw_calls", + JsonValue::fromNumber(static_cast(stats.drawCalls))); // LAIGE-DETERM-EXCEPTION: G-R8 report field: u64 counter to JSON number (M1-PROF-01, ARCH-009) counters.setMember("texture_binds", - JsonValue::fromNumber(stats.textureBinds)); - counters.setMember("net_bytes", JsonValue::fromNumber(stats.netBytes)); + JsonValue::fromNumber(static_cast(stats.textureBinds))); // LAIGE-DETERM-EXCEPTION: G-R8 report field: u64 counter to JSON number (M1-PROF-01, ARCH-009) + counters.setMember("net_bytes", + JsonValue::fromNumber(static_cast(stats.netBytes))); // LAIGE-DETERM-EXCEPTION: G-R8 report field: u64 counter to JSON number (M1-PROF-01, ARCH-009) root.setMember("counters", std::move(counters)); root.setMember("tick_time_ms", statsObject(stats.tickTimeMs)); @@ -292,7 +313,8 @@ std::string formatProfileJson(const Profiler& profiler, const World& world) { JsonValue::fromNumber(stats.entitiesTotal)); worldObj.setMember("entity_capacity", JsonValue::fromNumber(stats.entityCapacity)); - worldObj.setMember("sim_allocs", JsonValue::fromNumber(stats.simAllocs)); + worldObj.setMember("sim_allocs", + JsonValue::fromNumber(static_cast(stats.simAllocs))); // LAIGE-DETERM-EXCEPTION: G-R8 report field: u64 counter to JSON number (M1-PROF-01, ARCH-009) worldObj.setMember("systems", JsonValue::fromNumber(stats.systems)); root.setMember("world", std::move(worldObj)); @@ -318,7 +340,8 @@ std::string formatProfileJson(const Profiler& profiler, const World& world) { : "")); sys.setMember("budget_ms", JsonValue::fromNumber(fpx16_16::toFloat(info.def.budgetMs))); - sys.setMember("runs", JsonValue::fromNumber(timing.runs)); + sys.setMember("runs", + JsonValue::fromNumber(static_cast(timing.runs))); // LAIGE-DETERM-EXCEPTION: G-R8 report field: u64 counter to JSON number (M1-PROF-01, ARCH-009) sys.setMember("last_ms", JsonValue::fromNumber(timing.lastMs)); sys.setMember("warns", JsonValue::fromNumber(timing.warns)); sys.setMember("errors", JsonValue::fromNumber(timing.errors)); @@ -341,7 +364,7 @@ Result writeProfile(const Profiler& profiler, (format == ProfileFormat::Json) ? formatProfileJson(profiler, world) : formatProfileText(profiler, world); - std::FILE* f = std::fopen(pathCopy.data(), "wb"); + std::FILE* f = openProfileFile(pathCopy, "wb"); if (f == nullptr) { return ErrorCode::IoError; } diff --git a/tests/laige-sim/profiler_tests.cpp b/tests/laige-sim/profiler_tests.cpp index b34c178..7a345f6 100644 --- a/tests/laige-sim/profiler_tests.cpp +++ b/tests/laige-sim/profiler_tests.cpp @@ -36,6 +36,10 @@ #include #include +#if defined(_MSC_VER) +#include // _SH_DENYNO: plain-fopen sharing for _fsopen +#endif + #include "gtest/gtest.h" #include "laige/budget_harness.h" #include "laige/errors.h" @@ -139,8 +143,25 @@ SystemSchedule makeSchedule(World& world) { // The file helpers (report readers/cleaners — C stdio, the writeProfile // implementation's own boundary). +// +// Portable file open (CPP-009 platform boundary, the +// replay_record_tests.cpp / src/laige-sim/replay.cpp precedent): MSVC's +// CRT deprecates plain `fopen` (C4996, fatal under the engine's /WX +// policy). As in replay.cpp, the MSVC path uses `_fsopen(path, mode, +// _SH_DENYNO)` — plain-`fopen` sharing semantics (the secure `fopen_s` +// opens with `_SH_SECURE` and would deny it). +#if defined(_MSC_VER) +std::FILE* openReportFile(const std::string& path, const char* mode) { + return ::_fsopen(path.c_str(), mode, _SH_DENYNO); +} +#else +std::FILE* openReportFile(const std::string& path, const char* mode) { + return std::fopen(path.c_str(), mode); +} +#endif + std::string readFile(const std::string& path) { - std::FILE* f = std::fopen(path.c_str(), "rb"); + std::FILE* f = openReportFile(path, "rb"); if (f == nullptr) return {}; std::string out; char buf[4096]; @@ -151,7 +172,7 @@ std::string readFile(const std::string& path) { } bool fileExists(const std::string& path) { - std::FILE* f = std::fopen(path.c_str(), "rb"); + std::FILE* f = openReportFile(path, "rb"); if (f != nullptr) std::fclose(f); return f != nullptr; } @@ -746,8 +767,9 @@ TEST(ProfilerZeroAlloc, RecordPathAllocatesNothing) { // profiler's fixed per-tick cost (the extra clock reads + the ring // write) disproportionately, and the measured overhead there (1.46% // on the ASan tree, 2026-09-21) measures the INSTRUMENTATION, not -// the profiler. The gate is enforced on the non-instrumented trees — -// the CI linux-gcc and linux-clang P0 jobs. +// the profiler. The gate is enforced on every non-instrumented P0 CI +// job (the linux-gcc and linux-clang P0 jobs, and the +// windows-msvc and both macOS jobs' ctest alike). // --------------------------------------------------------------------------- #if defined(LAIGE_ALLOC_COUNTER) @@ -781,16 +803,28 @@ void fnCostMove(laige::World& world, laige::SystemContext& ctx) { namespace { inline constexpr std::uint32_t kCostEntities = 10000; // PRD §8.1 -inline constexpr std::uint32_t kCostTicks = 2000; // the window fills -inline constexpr std::uint32_t kCostWindow = 2000; // samples per window - -// One profiler-window's worth of 10k-entity ticks; returns the -// test-side frame-time p50 (ms). Each run wraps its GameLoop frames -// in the test's OWN TimeIt window (identical in both runs — it -// cancels in the A/B ratio), so the two runs differ ONLY in the -// profiler instrumentation: `enabled` flips the always-on counters -// (the DBG-002 switch) and the loop's per-tick timing with it. -double runCostWindow(bool enabled) { +inline constexpr std::uint32_t kCostTicks = 2000; // samples PER ARM +inline constexpr std::uint32_t kCostWindow = 2000; // the profiler's tick window + +// The two arms' frame-time p50s of one INTERLEAVED run (ms): the +// profiler is enabled on every other tick (tick i+1 is enabled iff i +// is odd), so each ON sample is adjacent to an OFF sample ~1 ms +// apart — the two subsequences sample the SAME machine-state +// trajectory (a CI runner's frequency ramp or thermal oscillation +// under sustained load shifts the whole trajectory, not one arm vs +// the other — the phase cancels in the A/B ratio at the +// adjacent-sample level; a blocked or per-run-interleaved order +// measured two phases of that trajectory and showed the drift +// itself as overhead — the macOS arm64 CI failure of M1-PROF-01, +// 2.14% on a 0.255 ms tick). A transient CI stall slows at most +// one tick = one sample of 2000 in one window — no p50 effect, so +// no best-of-N repetition is needed. +struct CostSample { + double onP50{}; + double offP50{}; +}; + +CostSample runCostInterleaved() { gSynthClockNs = 0; World::Options wo; wo.capacity = kCostEntities; @@ -841,63 +875,61 @@ double runCostWindow(bool enabled) { SystemSchedule sched = makeSchedule(world); Profiler::Options po; - po.tickWindowSamples = kCostWindow; - po.enabled = enabled; + po.tickWindowSamples = kCostWindow; // == kCostTicks: every ON sample stored + po.enabled = false; // start disabled; toggled per tick below Profiler prof(po); GameLoop loop = makeLoopWithProfiler(world, sched, &prof, 1); - // The test-side frame window: present in BOTH runs (it cancels in - // the A/B ratio) — the profiler's own tick window only exists in - // the enabled run (the disabled one records nothing). - laige::Histogram frameWindow(laige::Histogram::Options{kCostWindow}); + // The test-side frame windows: every frame is recorded in exactly + // one of the two (by its arm) — identical wrapping in both arms, + // it cancels in the A/B ratio. The profiler's own tick window + // stores the ON arm's ticks only (the OFF ticks are not + // measured — the disabled branch is one branch). + laige::Histogram onWindow(laige::Histogram::Options{kCostTicks}); + laige::Histogram offWindow(laige::Histogram::Options{kCostTicks}); if (!loop.frame().ok()) { // the start reference (zero ticks) ADD_FAILURE() << "the start-reference frame failed"; abort(); } - for (std::uint32_t i = 0; i < kCostTicks; ++i) { + for (std::uint32_t i = 0; i < 2 * kCostTicks; ++i) { + const bool enabled = (i % 2 == 1); // tick i+1: odd => ON, even => OFF + prof.setEnabled(enabled); gSynthClockNs += kSynthTickNs; const laige::TimeIt timer; if (!loop.frame().ok()) { ADD_FAILURE() << "frame " << i << " failed"; abort(); } - frameWindow.record(timer.elapsedMs()); + if (enabled) { + onWindow.record(timer.elapsedMs()); + } else { + offWindow.record(timer.elapsedMs()); + } } - EXPECT_EQ(loop.currentTick(), static_cast(kCostTicks)); + EXPECT_EQ(loop.currentTick(), static_cast(2 * kCostTicks)); const ProfilerStats s = prof.snapshot(); - if (!enabled) { - EXPECT_EQ(s.ticks, 0u); // the disabled run records nothing - } else { - EXPECT_EQ(s.ticks, static_cast(kCostTicks)); - EXPECT_EQ(s.tickTimeMs.n, static_cast(kCostWindow)); - } - return frameWindow.stats().p50; + EXPECT_EQ(s.ticks, static_cast(kCostTicks)); // ON ticks only + EXPECT_EQ(s.tickTimeMs.n, static_cast(kCostWindow)); + return CostSample{onWindow.stats().p50, offWindow.stats().p50}; } } // namespace TEST(ProfilerCost, EnabledCostBoundedToOnePercent) { // Warm-up run (cache/page-fault effects fall out of the measured - // windows — the benchmark's warm-up discipline, AGENTS §12). - const double warmup = runCostWindow(false); + // windows — the benchmark's warm-up discipline, AGENTS §12). It + // also warms both arms' one-time state (the ON arm's ring). + const CostSample warmup = runCostInterleaved(); static_cast(warmup); - // Best of 2 per configuration (the benchmarking norm: a - // preemption stall only ever makes a run SLOWER, so the faster - // run of a pair is the clean measurement — this keeps a - // transient CI stall from breaching the gate). - double onP50 = runCostWindow(true); - const double onAlt = runCostWindow(true); - if (onAlt < onP50) onP50 = onAlt; - double offP50 = runCostWindow(false); - const double offAlt = runCostWindow(false); - if (offAlt < offP50) offP50 = offAlt; - + // One measured interleaved run — the per-tick A/B structure is + // stall-proof and drift-free by construction (runCostInterleaved), + // so no repetition is needed. + const CostSample m = runCostInterleaved(); std::printf("profiler-cost on_p50=%.6g off_p50=%.6g overhead_pct=%.6g\n", - onP50, offP50, - (onP50 - offP50) / offP50 * 100.0); - ASSERT_GT(offP50, 0.0); - const double overhead = (onP50 - offP50) / offP50; + m.onP50, m.offP50, (m.onP50 - m.offP50) / m.offP50 * 100.0); + ASSERT_GT(m.offP50, 0.0); + const double overhead = (m.onP50 - m.offP50) / m.offP50; // The always-on enabled cost is bounded at 1% of a 10k-entity tick // (CORE-001, DBG-004; roadmap/M1-heartbeat.md M1-PROF-01). EXPECT_LE(overhead, 0.01);