diff --git a/docs/benchmark.md b/docs/benchmark.md new file mode 100644 index 0000000000..e7efdbd168 --- /dev/null +++ b/docs/benchmark.md @@ -0,0 +1,139 @@ +# Client Benchmark + +The client can measure itself. `$bench` runs a fixed list of scenarios, records every frame, +and writes a report you can put next to another one — so a graphics change is judged against a +measurement instead of an impression. + +It is a developer tool: available in every build, but it reconfigures the scene while it runs +and writes files next to the client, so it is not something a player would leave on. + +For the per-frame overlays this builds on, see the `$details` and `$glstats` commands. + +--- + +## 1. Running one + +Stand where you want to measure, then type in chat: + +``` +$bench label glp09-ring-allocator +$bench run +``` + +The client freezes nothing and takes over nothing — it plays on. A line at the top of the +screen shows which segment is running and how far along it is. When the run finishes, the chat +prints the directory it was written to. + +| Command | What it does | +|---|---| +| `$bench list` | Prints the segment catalog and the tags you can select by. | +| `$bench run` | Every segment, 3 repeats of 300 frames each. | +| `$bench run fx.*` | Only the segments whose name matches the pattern. | +| `$bench run #particles` | Only the segments carrying that tag. | +| `$bench run fx.* 5 600` | 5 repeats of 600 frames each. | +| `$bench quick fx.particles.off` | One repeat of 120 frames — for iterating, not for reporting. | +| `$bench label ` | Names the next run. It ends up in the directory name and the report. | +| `$bench stop` | Ends the run early. What was measured is still written out, marked aborted. | + +A full run is a couple of minutes. `$bench quick` is seconds and is deliberately too short to +trust a small difference — use it to see whether a change did anything at all, then re-measure +properly. + +### Getting numbers worth comparing + +- **Turn vsync off** (`$vsync off`). With it on, every frame time is pinned to the display + refresh, so the segments come out looking alike no matter what they switch off. The run says + so in chat as it starts, and the report flags it again — but neither gets the run back. +- **Stand in the same place**, facing the same way, for both runs. The segments hold the + effect configuration steady; they cannot hold the world steady. +- **Don't alt-tab.** A frame longer than half a second discards its whole repeat — the client + was not running normally, so what it measured was the interruption. +- **Compare like with like.** Two runs are comparable when their manifest hash, GPU, resolution + and build configuration match. All four are in the report header. + +## 2. What a segment is + +A segment is one named scenario, measured on its own. Splitting a run into segments is what +lets the result say *where* a change had an effect, rather than only whether the frame got +faster: a change that helps particle-heavy scenes and does nothing elsewhere reads very +differently from one that shifts every segment by the same amount. + +The current catalog varies the effect surfaces of whatever scene you are standing in. Each +segment switches one surface off, so the difference between it and the baseline is what that +surface costs at that spot. + +| Segment | What it isolates | +|---|---| +| `scene.full` | Nothing disabled. The reference every other row is read against. | +| `fx.all.off` | Every effect surface at once, exactly as `$effects off` does it — the upper bound. | +| `fx.sprites.off` | The sprite draw path. | +| `fx.particles.off` | The particle draw path. | +| `fx.joints.off` | Beam and tail-trail effects. | +| `fx.skillmodels.off` | Skill effect models, leaving impact effects rendering. | +| `fx.boids.off` | Ambient wildlife — an always-on cost in towns. | +| `fx.wingshadow.off` | The extra per-wing body shadow draw. | +| `fx.winglayers.off` | Wing glow overlay passes. Visibly changes the wing while it runs. | + +`scene.full` is always measured first and again last, whatever you selected. The difference +between those two is drift: the machine getting hotter, or busier, under the run. If it is +large, nothing measured in between is trustworthy, and the report says so. + +Each repeat discards a warmup window before recording. The first frames of a segment pay for +shader compiles, texture uploads and buffer growth — real hitching, but not the steady state a +comparison is about. + +## 3. What you get + +Each run writes one directory under `bench/runs/`, named after the timestamp and your label. + +| File | What it is for | +|---|---| +| `run.json` | The canonical result. Everything else is a view of this. Versioned, so an old run stays readable. | +| `report.md` | The human view: environment, per-segment summary, pacing, findings, pass breakdown. | +| `frames.csv` | One row per measured frame — frame time and per-pass CPU/GPU ms. For spreadsheets and plots. | +| `passes.csv` | Per segment, repeat and pass: timings plus every GL counter, averaged per frame. | + +`report.md` opens with what makes the run comparable: the build configuration, the GPU and +driver, the GL context version the client actually got, the capability flags the driver +reported, the resolution, and whether vsync was on. Those decide which code path the client is +even running, and a frame time without them next to it is not something anyone can act on +later. + +### Reading the summary + +Alongside the median it reports the **1% low** (the mean of the worst 1% of frames) and the +**pacing** numbers. A change can lower the average frame time and make the stream stutter more, +and an average on its own will call that a win. If the mean delta between consecutive frames +climbs while the median falls, that is what happened. + +**Repeat spread** is the noise band. It is the gap between the repeat medians of the same +segment on the same machine measuring the same thing. A difference between two runs that is +smaller than this is not a result. + +### Findings + +The report ends with a table of rule-based observations — each one a named rule with a fixed +threshold, so you can see what was actually tested. They describe the run; they do not judge a +code change. The rules cover things like a segment whose frame time is mostly outside every +profiled pass (work running unmeasured), a batching path merging nothing, a buffer ring +wrapping repeatedly, drift across the run, and repeats that had to be discarded. + +One of them is worth knowing before you read a table: **`segment-inert`** fires when a segment +submitted the same number of draw calls as the baseline. That segment disabled nothing here — +either the scene had none of what it targets (no wings equipped, no particles on screen) or its +configuration does not reach the path it names. Its timing is then not evidence that what it +targets is cheap, and the report says so rather than leaving the row to be misread. + +## 4. Recording which commit a run came from + +The report has a commit field, and the build system does not fill it in. To get it, define it +when you build: + +``` +-DMU_GIT_DESCRIBE="\"$(git describe --always --dirty)\"" -DMU_GIT_DIRTY +``` + +Without it the field reads `(unknown)`, which is honest — better than a commit that was stale +by the time the binary was built. Pass `MU_GIT_DIRTY` only when the tree really was dirty; the +report warns about it, because a run of uncommitted code cannot be reproduced from the commit +alone. diff --git a/src/source/Core/Utilities/Benchmark/BenchConsoleCommand.cpp b/src/source/Core/Utilities/Benchmark/BenchConsoleCommand.cpp new file mode 100644 index 0000000000..bc814ff765 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchConsoleCommand.cpp @@ -0,0 +1,151 @@ +#include "stdafx.h" + +#include "BenchConsoleCommand.h" + +#include "BenchRecorder.h" +#include "BenchSegment.h" +#include "Render/Textures/ZzzOpenglUtil.h" +#include "UI/NewUI/NewUISystem.h" + +#include +#include + +namespace Core::Benchmark::Console +{ +namespace +{ + constexpr const wchar_t* kCommandPrefix = L"$bench"; + + // A shorter, noisier run for iterating on one effect: enough frames to see a large change, + // not enough to trust a small one. The full defaults are what a reported number comes from. + constexpr int kQuickRepeats = 1; + constexpr int kQuickWarmupFrames = 30; + constexpr int kQuickMeasureFrames = 120; + + void Say(const std::wstring& text) + { + g_pChatListBox->AddText(L"", text.c_str(), SEASON3B::TYPE_SYSTEM_MESSAGE); + } + + void Say(const std::string& text) + { + Say(std::wstring(text.begin(), text.end())); + } + + std::vector SplitWords(const std::wstring& text) + { + std::wistringstream stream(text); + std::vector words; + std::wstring word; + while (stream >> word) words.push_back(word); + return words; + } + + std::string Narrow(const std::wstring& text) + { + std::string out; + for (wchar_t c : text) out += (c > 0 && c < 128) ? (char)c : '?'; + return out; + } + + int ParsePositive(const std::wstring& text, int fallback) + { + try + { + const int value = std::stoi(text); + return (value > 0) ? value : fallback; + } + catch (const std::exception&) + { + return fallback; + } + } + + void PrintUsage() + { + Say(L"$bench list - the segment catalog"); + Say(L"$bench run [pattern] [n] [f] - run segments, n repeats of f frames"); + Say(L"$bench quick [pattern] - one short repeat, for iterating"); + Say(L"$bench label - name the next run"); + Say(L"$bench stop - end the current run early"); + } + + void PrintCatalog() + { + for (const Segment& segment : Segments::All()) + Say(std::string(segment.name) + " [" + Segments::TagsToString(segment.tags) + "]"); + Say(L"patterns: 'fx.*', '*.off', '#particles', '*'"); + } + + void StartRun(const std::vector& words, int repeats, int warmupFrames, int measureFrames) + { + const std::string pattern = (words.size() > 2) ? Narrow(words[2]) : "*"; + + std::string message; + if (!Recorder::Instance().Start(pattern, repeats, warmupFrames, measureFrames, message)) + { + Say("benchmark: " + message); + return; + } + Say(message); + + // Said at the start, not only in the finished report: under vsync every segment's frame + // time is pinned to the display refresh, so the segments come out looking alike whatever + // they switch off. Learning that from the report costs a whole run. + if (IsVSyncEnabled()) + Say(L"benchmark: vsync is ON -- frame times are pinned to the refresh rate and the " + L"segments will look alike. Run '$vsync off' and measure again."); + } + + void RunWithArguments(const std::vector& words) + { + const int repeats = (words.size() > 3) + ? ParsePositive(words[3], Recorder::kDefaultRepeats) : Recorder::kDefaultRepeats; + const int measureFrames = (words.size() > 4) + ? ParsePositive(words[4], Recorder::kDefaultMeasureFrames) : Recorder::kDefaultMeasureFrames; + + StartRun(words, repeats, Recorder::kDefaultWarmupFrames, measureFrames); + } + + void StopRun() + { + Recorder& recorder = Recorder::Instance(); + if (!recorder.IsRunning()) + { + Say(L"benchmark: nothing is running"); + return; + } + + recorder.Abort(); + Say("benchmark aborted, partial results in " + recorder.LastOutputPath()); + } + + void SetLabel(const std::wstring& command) + { + // Everything after "$bench label ", so a label may contain spaces. + const size_t labelAt = command.find(L"label "); + const std::wstring label = (labelAt == std::wstring::npos) ? L"" : command.substr(labelAt + 6); + + Recorder::Instance().SetLabel(Narrow(label)); + Say("benchmark label: " + Narrow(label)); + } +} + +bool HandleCommand(const std::wstring& command) +{ + if (command.compare(0, wcslen(kCommandPrefix), kCommandPrefix) != 0) return false; + + const std::vector words = SplitWords(command); + const std::wstring verb = (words.size() > 1) ? words[1] : L""; + + if (verb.empty() || verb == L"help") PrintUsage(); + else if (verb == L"list") PrintCatalog(); + else if (verb == L"run") RunWithArguments(words); + else if (verb == L"quick") StartRun(words, kQuickRepeats, kQuickWarmupFrames, kQuickMeasureFrames); + else if (verb == L"label") SetLabel(command); + else if (verb == L"stop") StopRun(); + else Say(L"benchmark: unknown command, try '$bench help'"); + + return true; +} +} diff --git a/src/source/Core/Utilities/Benchmark/BenchConsoleCommand.h b/src/source/Core/Utilities/Benchmark/BenchConsoleCommand.h new file mode 100644 index 0000000000..fec29f30cb --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchConsoleCommand.h @@ -0,0 +1,12 @@ +#pragma once + +#include + +// The `$bench ...` console/chat commands. Kept out of muConsoleDebug.cpp's dispatch chain so the +// benchmark's own vocabulary lives with the rest of the benchmark. + +namespace Core::Benchmark::Console +{ + // Returns true when the text was a $bench command and has been handled. + bool HandleCommand(const std::wstring& command); +} diff --git a/src/source/Core/Utilities/Benchmark/BenchEnvironment.cpp b/src/source/Core/Utilities/Benchmark/BenchEnvironment.cpp new file mode 100644 index 0000000000..c720f9bb14 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchEnvironment.cpp @@ -0,0 +1,155 @@ +#include "stdafx.h" + +#include "BenchEnvironment.h" + +#include "Core/Utilities/BuildInfo.h" +#include "Core/Utilities/PlatformInfo.h" +#include "Render/RHI/RHI.h" +#include "Render/Textures/ZzzOpenglUtil.h" +#include "Scenes/SceneManager.h" +#include "World/MapInfra/MapManager.h" + +#include +#include +#include + +#if defined(_MSC_VER) +#include +#elif defined(__GNUC__) && (defined(__i386__) || defined(__x86_64__)) +#include +#endif + +namespace Core::Benchmark::Environment +{ +namespace +{ + std::string Narrow(const std::wstring& text) + { + std::string out; + out.reserve(text.size()); + // Diagnostic strings only -- map names and OS strings are ASCII in practice, and a + // mangled non-ASCII character in a report header is better than a dependency on a + // codepage conversion here. + for (wchar_t c : text) out += (c > 0 && c < 128) ? (char)c : '?'; + return out; + } + + std::string UtcTimestamp() + { + const std::time_t now = std::time(nullptr); + std::tm utc = {}; +#if defined(_WIN32) + gmtime_s(&utc, &now); +#else + gmtime_r(&now, &utc); +#endif + char buffer[32]; + std::strftime(buffer, sizeof(buffer), "%Y-%m-%dT%H:%M:%SZ", &utc); + return buffer; + } + + // CPUID leaves 0x80000002..0x80000004 hold the processor brand string on every x86 part that + // reports it. Empty elsewhere -- an unknown CPU is more useful in a report than a wrong one. + std::string CpuBrand() + { +#if defined(_MSC_VER) || (defined(__GNUC__) && (defined(__i386__) || defined(__x86_64__))) + int registers[4] = {}; + char brand[49] = {}; + for (int leaf = 0; leaf < 3; leaf++) + { +#if defined(_MSC_VER) + __cpuid(registers, (int)(0x80000002u + leaf)); +#else + __get_cpuid(0x80000002u + leaf, (unsigned*)®isters[0], (unsigned*)®isters[1], + (unsigned*)®isters[2], (unsigned*)®isters[3]); +#endif + memcpy(brand + leaf * sizeof(registers), registers, sizeof(registers)); + } + + std::string result = brand; + // The brand string is space-padded to a fixed width on many parts. + while (!result.empty() && result.back() == ' ') result.pop_back(); + return result; +#else + return std::string(); +#endif + } + + uint64_t SystemMemoryMB() + { +#if defined(_WIN32) + MEMORYSTATUSEX status = {}; + status.dwLength = sizeof(status); + if (!GlobalMemoryStatusEx(&status)) return 0; + + constexpr uint64_t kBytesPerMB = 1024ull * 1024ull; + return status.ullTotalPhys / kBytesPerMB; +#else + return 0; +#endif + } + + void CaptureBuild(EnvironmentInfo& info) + { + info.buildConfig = Core::Build::kConfiguration; + info.buildEditor = Core::Build::kEditor; + info.buildCompiler = Core::Build::kCompiler; + info.buildArch = Core::Build::kArchitecture; + info.buildTimestamp = std::string(Core::Build::kDate) + " " + Core::Build::kTime; + info.gitDescribe = Core::Build::kGitDescribe; + info.gitDirty = Core::Build::kGitDirty; + } + + void CaptureGraphics(EnvironmentInfo& info) + { + // Through the RHI rather than glGetString directly: GL entry points belong behind the + // render layer (DXP-10), and the driver strings are captured next to the capability + // probe that reads the same GL_VERSION anyway. + const RHI::DriverInfo& driver = RHI::GetDriverInfo(); + info.glVendor = driver.vendor; + info.glRenderer = driver.renderer; + info.glVersion = driver.version; + info.glslVersion = driver.shadingLanguageVersion; + + const RHI::Caps& caps = RHI::GetCaps(); + info.contextMajor = caps.glMajor; + info.contextMinor = caps.glMinor; + info.capsBufferStorage = caps.bufferStorage; + info.capsVertexAttribBinding = caps.vertexAttribBinding; + info.capsProgramBinary = caps.programBinary; + info.capsTimerQuery = caps.timerQuery; + info.capsUboOffsetAlignment = caps.uboOffsetAlignment; + info.capsMaxUniformBlockSize = caps.maxUniformBlockSize; + } + + void CaptureSession(EnvironmentInfo& info) + { + info.windowWidth = (int)WindowWidth; + info.windowHeight = (int)WindowHeight; + // Requested and effective are read from the same source today. They are separate fields + // because a driver can force vsync on behind the client's back, and a run measured under + // a forced swap interval is not measuring the client at all. + info.vsyncRequested = IsVSyncEnabled(); + info.vsyncEffective = IsVSyncEnabled(); + info.targetFps = GetTargetFps(); + + const wchar_t* mapName = gMapManager.GetMapName(gMapManager.WorldActive); + info.mapName = mapName ? Narrow(mapName) : std::string(); + } +} + +EnvironmentInfo Capture() +{ + EnvironmentInfo info; + info.timestampUtc = UtcTimestamp(); + info.osVersion = Narrow(Core::Platform::GetOSVersionString()); + info.cpu = CpuBrand(); + info.cpuThreads = (int)std::thread::hardware_concurrency(); + info.systemMemoryMB = SystemMemoryMB(); + + CaptureBuild(info); + CaptureGraphics(info); + CaptureSession(info); + return info; +} +} diff --git a/src/source/Core/Utilities/Benchmark/BenchEnvironment.h b/src/source/Core/Utilities/Benchmark/BenchEnvironment.h new file mode 100644 index 0000000000..8f66aba686 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchEnvironment.h @@ -0,0 +1,17 @@ +#pragma once + +#include "BenchTypes.h" + +// Captures what makes a run's numbers comparable -- or not. Called once, at run start. +// +// The graphics half is the part that has been missing: which GL context the version chain +// actually settled on, and which capability flags the driver reported. On the weak hardware this +// tooling exists for, those two facts decide which code path the client is even running, and +// they have so far had to be read out of a boot log by hand. +// +// Fields that cannot be resolved on a platform stay empty rather than being guessed at. + +namespace Core::Benchmark::Environment +{ + EnvironmentInfo Capture(); +} diff --git a/src/source/Core/Utilities/Benchmark/BenchFindings.cpp b/src/source/Core/Utilities/Benchmark/BenchFindings.cpp new file mode 100644 index 0000000000..642f96a586 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchFindings.cpp @@ -0,0 +1,223 @@ +#include "BenchFindings.h" + +#include +#include + +namespace Core::Benchmark::Findings +{ +namespace +{ + int IndexOf(const std::vector& names, const char* wanted) + { + for (size_t i = 0; i < names.size(); i++) + if (names[i] == wanted) return (int)i; + return -1; + } + + void Add(std::vector& out, Level level, const char* rule, const std::string& segment, std::string text) + { + out.push_back(Finding{ level, rule, segment, std::move(text) }); + } + + std::string Fixed(double value, int decimals) + { + char buffer[64]; + snprintf(buffer, sizeof(buffer), "%.*f", decimals, value); + return buffer; + } + + // The frame time that sits outside every FRAME_PROFILE scope. A large remainder means work is + // running unmeasured -- the blind spot GLP-24 found after it had already invalidated a phase + // of measurements, and the one check that would have caught it automatically. + void CheckAttribution(const Stats::SegmentStats& segment, std::vector& out) + { + if (std::fabs(segment.unattributedPercent) <= kAttributionGapPercent) return; + + Add(out, Level::Warning, "attribution-gap", segment.name, + Fixed(segment.unattributedPercent, 1) + "% of the frame (" + + Fixed(segment.unattributedMs, 2) + " ms) is outside every profiled pass"); + } + + // Run-to-run spread within one segment. A delta between two runs smaller than this is not a + // result, it is the machine. + void CheckRepeatSpread(const Stats::SegmentStats& segment, std::vector& out) + { + if (segment.repeatSpreadPercent <= kNoisySegmentSpreadPercent) return; + + Add(out, Level::Warning, "noisy-segment", segment.name, + "repeat medians spread " + Fixed(segment.repeatSpreadPercent, 1) + "% (" + + Fixed(segment.repeatSpreadMs, 2) + " ms) -- treat smaller deltas as noise"); + } + + void CheckInvalidRepeats(const Stats::SegmentStats& segment, std::vector& out) + { + if (segment.invalidRepeats == 0) return; + + Add(out, Level::Warning, "invalid-repeats", segment.name, + std::to_string(segment.invalidRepeats) + " of " + + std::to_string(segment.invalidRepeats + segment.validRepeats) + + " repeats were discarded"); + } + + void CheckPresentStall(const RunData& run, const Stats::SegmentStats& segment, std::vector& out) + { + const int presentIndex = IndexOf(run.passNames, "Present"); + if (presentIndex < 0 || segment.frame.meanMs <= 0.0f) return; + + const float presentPercent = 100.0f * segment.passCpuMs[presentIndex] / segment.frame.meanMs; + if (presentPercent <= kPresentStallPercent) return; + + Add(out, Level::Info, "present-stall", segment.name, + "Present is " + Fixed(presentPercent, 1) + + "% of the frame -- the CPU is waiting on the GPU command queue"); + } + + // Fewer than two quads per IR draw in a pass that submits a lot of them: batching is merging + // nothing there, so the cost is submission, not the work each draw does. + void CheckSubmissionBound(const RunData& run, const Stats::SegmentStats& segment, std::vector& out) + { + const int drawsIndex = IndexOf(run.counterNames, "IRDraws"); + const int verticesIndex = IndexOf(run.counterNames, "IRVertices"); + if (drawsIndex < 0 || verticesIndex < 0) return; + + for (size_t pass = 0; pass < run.passNames.size() && pass < (size_t)kMaxPasses; pass++) + { + const double draws = segment.passCounterPerFrame[pass][drawsIndex]; + if (draws < kSubmissionBoundMinDraws) continue; + + const double verticesPerDraw = segment.passCounterPerFrame[pass][verticesIndex] / draws; + if (verticesPerDraw >= kSubmissionBoundVerticesPerDraw) continue; + + Add(out, Level::Info, "submission-bound", segment.name, + run.passNames[pass] + ": " + Fixed(draws, 0) + " IR draws/frame at " + + Fixed(verticesPerDraw, 1) + " vertices per draw -- batching is merging nothing"); + } + } + + void CheckBufferOrphans(const RunData& run, const Stats::SegmentStats& segment, std::vector& out) + { + const int orphansIndex = IndexOf(run.counterNames, "BufferOrphans"); + if (orphansIndex < 0) return; + + const double orphans = segment.counterPerFrame[orphansIndex]; + if (orphans <= kBufferOrphansPerFrameWarn) return; + + Add(out, Level::Info, "buffer-orphans", segment.name, + Fixed(orphans, 1) + " buffer orphans per frame -- a streaming ring is wrapping repeatedly"); + } + + // Skips matching draw calls one-for-one is the red flag GLP-10 named for its own dirty check: + // a dedupe that never misses is more likely broken than perfect. + void CheckUboSkips(const RunData& run, const Stats::SegmentStats& segment, std::vector& out) + { + const int skipsIndex = IndexOf(run.counterNames, "UboSkips"); + const int drawsIndex = IndexOf(run.counterNames, "DrawCalls"); + if (skipsIndex < 0 || drawsIndex < 0) return; + + const double draws = segment.counterPerFrame[drawsIndex]; + if (draws <= 0.0) return; + + const double ratio = segment.counterPerFrame[skipsIndex] / draws; + if (ratio < kUboSkipSuspiciousRatio) return; + + Add(out, Level::Warning, "ubo-skip-suspicious", segment.name, + Fixed(ratio, 2) + " uniform-block skips per draw call -- check the dirty check is not over-skipping"); + } + + // A segment that changed nothing the client submitted did not test what it claims to. Either + // the scene had none of what it disables (no wings equipped, no particles on screen) or the + // segment's configuration does not reach the path it names. Both are worth saying out loud: + // otherwise the row reads as "this costs nothing", which is a very different claim. + void CheckInertSegments(const RunData& run, const std::vector& stats, + std::vector& out) + { + const int drawsIndex = IndexOf(run.counterNames, "DrawCalls"); + const int baselineIndex = Stats::FindSegment(stats, kBaselineSegmentName); + if (drawsIndex < 0 || baselineIndex < 0) return; + + const double baselineDraws = stats[baselineIndex].counterPerFrame[drawsIndex]; + if (baselineDraws <= 0.0) return; + + for (const Stats::SegmentStats& segment : stats) + { + if (segment.name == kBaselineSegmentName) continue; + if (segment.name == std::string(kBaselineSegmentName) + kDriftControlSuffix) continue; + + const double draws = segment.counterPerFrame[drawsIndex]; + const double differencePercent = 100.0 * std::fabs(draws - baselineDraws) / baselineDraws; + if (differencePercent >= kInertSegmentDrawPercent) continue; + + Add(out, Level::Warning, "segment-inert", segment.name, + "submitted " + Fixed(draws, 1) + " draws/frame against the baseline's " + + Fixed(baselineDraws, 1) + " -- this segment disabled nothing measurable here, so " + "its timing is not evidence that what it targets is cheap"); + } + } + + // The opening and closing measurements of the baseline segment. They ran minutes apart on the + // same scene, so any difference between them is the machine drifting under the run. + void CheckDrift(const std::vector& stats, std::vector& out) + { + const int startIndex = Stats::FindSegment(stats, kBaselineSegmentName); + const int endIndex = Stats::FindSegment(stats, std::string(kBaselineSegmentName) + kDriftControlSuffix); + if (startIndex < 0 || endIndex < 0) return; + + const float startMs = stats[startIndex].frame.medianMs; + const float endMs = stats[endIndex].frame.medianMs; + if (startMs <= 0.0f) return; + + const float driftPercent = 100.0f * (endMs - startMs) / startMs; + if (std::fabs(driftPercent) <= kDriftWarnPercent) return; + + Add(out, Level::Warning, "drift", "", + "the baseline segment moved " + Fixed(driftPercent, 1) + + "% between the start and the end of the run -- every segment in between is suspect"); + } + + void CheckRunStatus(const RunData& run, std::vector& out) + { + if (run.status == RunStatus::Aborted) + Add(out, Level::Warning, "aborted", "", "the run did not finish; partial data only"); + + if (run.environment.gitDirty) + Add(out, Level::Warning, "dirty-tree", "", + "the working tree had uncommitted changes -- this run cannot be reproduced from the commit alone"); + + if (run.environment.vsyncEffective) + Add(out, Level::Warning, "vsync-on", "", + "vsync was active -- frame times are pinned to the display refresh, not to what the client can do"); + } +} + +const char* ToString(Level level) +{ + switch (level) + { + case Level::Info: return "info"; + case Level::Warning: return "warning"; + } + return "unknown"; +} + +std::vector Evaluate(const RunData& run, const std::vector& stats) +{ + std::vector findings; + + CheckRunStatus(run, findings); + CheckDrift(stats, findings); + CheckInertSegments(run, stats, findings); + + for (const Stats::SegmentStats& segment : stats) + { + CheckInvalidRepeats(segment, findings); + CheckAttribution(segment, findings); + CheckRepeatSpread(segment, findings); + CheckPresentStall(run, segment, findings); + CheckSubmissionBound(run, segment, findings); + CheckBufferOrphans(run, segment, findings); + CheckUboSkips(run, segment, findings); + } + + return findings; +} +} diff --git a/src/source/Core/Utilities/Benchmark/BenchFindings.h b/src/source/Core/Utilities/Benchmark/BenchFindings.h new file mode 100644 index 0000000000..09b97d5339 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchFindings.h @@ -0,0 +1,49 @@ +#pragma once + +#include +#include + +#include "BenchStats.h" +#include "BenchTypes.h" + +// Rule-based observations over a finished run. Pure, and deliberately narrow: every finding is +// produced by one named rule with a fixed threshold, and carries that rule's code so a reader +// can check what it actually tested. The tool does not write conclusions it cannot support -- +// "this change improves particle performance" is a claim for a human to make after looking at +// two runs, not something a single run's numbers can establish. + +namespace Core::Benchmark::Findings +{ + // Thresholds. Named because a magic number buried in a rule is a bug waiting to happen, and + // because a reader has to be able to see what "warning" meant. + inline constexpr float kAttributionGapPercent = 10.0f; // frame time outside every pass scope + inline constexpr float kDriftWarnPercent = 5.0f; // baseline start vs. end of run + inline constexpr float kNoisySegmentSpreadPercent = 10.0f; + inline constexpr float kPresentStallPercent = 30.0f; // Present as a share of frame time + inline constexpr float kUboSkipSuspiciousRatio = 0.9f; // skips per draw call + inline constexpr float kBufferOrphansPerFrameWarn = 5.0f; + inline constexpr int kSubmissionBoundMinDraws = 100; + // Below this relative difference in draw calls per frame, a segment did not measurably change + // what the client submitted -- it turned nothing off at this spot, whatever it promised to. + inline constexpr float kInertSegmentDrawPercent = 1.0f; + // An IR quad is 6 vertices after decomposition, so this is "fewer than two quads per draw". + inline constexpr float kSubmissionBoundVerticesPerDraw = 12.0f; + + enum class Level + { + Info, + Warning, + }; + + const char* ToString(Level level); + + struct Finding + { + Level level = Level::Info; + std::string rule; // stable code, e.g. "attribution-gap" + std::string segment; // empty when the finding is about the run as a whole + std::string text; + }; + + std::vector Evaluate(const RunData& run, const std::vector& stats); +} diff --git a/src/source/Core/Utilities/Benchmark/BenchRecorder.cpp b/src/source/Core/Utilities/Benchmark/BenchRecorder.cpp new file mode 100644 index 0000000000..8eb4ad7411 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchRecorder.cpp @@ -0,0 +1,388 @@ +#include "stdafx.h" + +#include "BenchRecorder.h" + +#include "BenchEnvironment.h" +#include "BenchFindings.h" +#include "BenchReport.h" +#include "BenchScene.h" +#include "BenchStats.h" +#include "Core/Utilities/FrameProfiler.h" +#include "Core/Utilities/Log/ErrorReport.h" + +#include +#include +#include + +namespace Core::Benchmark +{ +namespace +{ + // Runs are written under the client's working directory, one directory per run. + constexpr const char* kRunsRootPath = "bench/runs"; + + // Pass indices whose time is already contained in another pass. Summing them into a frame + // total would count the same milliseconds twice. + bool IsNestedPass(FrameProfiler::Pass pass) + { + return pass == FrameProfiler::Pass::Skinning || pass == FrameProfiler::Pass::CharWait; + } + + std::string SanitizeForPath(const std::string& text) + { + std::string out; + for (char c : text) + { + const bool safe = (c >= 'a' && c <= 'z') || (c >= 'A' && c <= 'Z') || + (c >= '0' && c <= '9') || c == '.' || c == '-' || c == '_'; + if (safe) out += c; + else if (c == ' ') out += '-'; + } + return out; + } + + std::string LocalTimestampForId() + { + const std::time_t now = std::time(nullptr); + std::tm local = {}; +#if defined(_WIN32) + localtime_s(&local, &now); +#else + localtime_r(&now, &local); +#endif + char buffer[24]; + std::strftime(buffer, sizeof(buffer), "%Y%m%d_%H%M%S", &local); + return buffer; + } + + bool WriteTextFile(const std::filesystem::path& path, const std::string& contents) + { + std::ofstream file(path, std::ios::binary | std::ios::trunc); + if (!file) return false; + + file.write(contents.data(), (std::streamsize)contents.size()); + return file.good(); + } +} + +static_assert((int)FrameProfiler::Pass::Count_ <= kMaxPasses, + "FrameProfiler grew a pass -- raise Core::Benchmark::kMaxPasses to match"); +static_assert((int)FrameProfiler::Counter::Count_ <= kMaxCounters, + "FrameProfiler grew a counter -- raise Core::Benchmark::kMaxCounters to match"); + +Recorder& Recorder::Instance() +{ + static Recorder s_instance; + return s_instance; +} + +//============================================================================= +// Run planning +//============================================================================= + +bool Recorder::BuildPlan(const std::string& pattern, std::string& outMessage) +{ + const std::vector selected = Segments::Select(pattern); + if (selected.empty()) + { + outMessage = "no segment matches '" + pattern + "'"; + return false; + } + + const Segment* baseline = Segments::Find(kBaselineSegmentName); + if (!baseline) + { + outMessage = "the baseline segment is missing from the catalog"; + return false; + } + + // The baseline always opens the run: without it a subset run has nothing to read its + // segments against, and its numbers would only be comparable to another full run. + m_plan.clear(); + m_plan.push_back(PlannedSegment{ baseline, kBaselineSegmentName }); + + for (const Segment* segment : selected) + { + if (segment == baseline) continue; + m_plan.push_back(PlannedSegment{ segment, segment->name }); + } + + // ... and closes it, so drift across the run is measured rather than assumed away. Pointless + // when the baseline is the only thing being measured. + if (m_plan.size() > 1) + m_plan.push_back(PlannedSegment{ baseline, std::string(kBaselineSegmentName) + kDriftControlSuffix }); + + return true; +} + +bool Recorder::Start(const std::string& pattern, int repeats, int warmupFrames, int measureFrames, + std::string& outMessage) +{ + if (m_running) + { + outMessage = "a benchmark run is already in progress"; + return false; + } + + if (repeats < 1 || warmupFrames < 0 || measureFrames < 1) + { + outMessage = "repeats and measured frames must be at least 1"; + return false; + } + + if (!BuildPlan(pattern, outMessage)) return false; + + m_manifest = RunManifest{}; + m_manifest.label = m_label; + m_manifest.pattern = pattern; + m_manifest.repeats = repeats; + m_manifest.warmupFrames = warmupFrames; + m_manifest.measureFrames = measureFrames; + for (const PlannedSegment& planned : m_plan) m_manifest.segmentNames.push_back(planned.resultName); + + m_environment = Environment::Capture(); + m_segments.clear(); + m_events.clear(); + m_segmentIndex = 0; + m_running = true; + + const std::string suffix = SanitizeForPath(m_label); + m_runId = LocalTimestampForId() + (suffix.empty() ? "" : "_" + suffix); + + // The counters have to be on for the whole run whatever the overlay was doing, and back to + // what they were afterwards -- a run must not leave the client instrumented behind the + // user's back. + m_countersWereEnabled = FrameProfiler::g_CountersEnabled; + FrameProfiler::g_CountersEnabled = true; + m_configBeforeRun = Scene::CaptureCurrentConfig(); + m_lastFrameAt = std::chrono::steady_clock::now(); + + BeginSegment(); + outMessage = "benchmark started: " + std::to_string(m_plan.size()) + " segments x " + + std::to_string(repeats) + " repeats"; + return true; +} + +void Recorder::Abort() +{ + if (!m_running) return; + + m_currentRepeat.invalid = InvalidReason::Aborted; + m_events.push_back("run aborted by the user during " + m_plan[m_segmentIndex].resultName); + EndRepeat(); + Finish(RunStatus::Aborted); +} + +//============================================================================= +// Segment / repeat lifecycle +//============================================================================= + +void Recorder::BeginSegment() +{ + const PlannedSegment& planned = m_plan[m_segmentIndex]; + + SegmentSamples segment; + segment.name = planned.resultName; + segment.description = planned.definition->description; + segment.tags = Segments::TagsToString(planned.definition->tags); + m_segments.push_back(segment); + + m_repeatIndex = 0; + BeginRepeat(); +} + +void Recorder::BeginRepeat() +{ + // Re-applied per repeat, not per segment: it is the guard against a stray console command or + // another system having changed a toggle underneath the run. + Scene::ApplyConfig(m_plan[m_segmentIndex].definition->config); + + m_currentRepeat = RepeatSamples{}; + m_currentRepeat.repeatIndex = m_repeatIndex; + m_currentRepeat.frames.reserve((size_t)m_manifest.measureFrames); + m_warmupRemaining = m_manifest.warmupFrames; + m_skipNextFrame = true; +} + +void Recorder::EndRepeat() +{ + m_currentRepeat.warmupFramesDiscarded = m_manifest.warmupFrames - m_warmupRemaining; + + const bool tooFewFrames = (int)m_currentRepeat.frames.size() < m_manifest.measureFrames; + if (tooFewFrames && m_currentRepeat.invalid == InvalidReason::None) + m_currentRepeat.invalid = InvalidReason::TooFewFrames; + + m_segments.back().repeats.push_back(m_currentRepeat); + m_currentRepeat = RepeatSamples{}; +} + +void Recorder::EndSegment() +{ + m_segmentIndex++; + if (m_segmentIndex >= (int)m_plan.size()) + { + Finish(RunStatus::Completed); + return; + } + + BeginSegment(); +} + +//============================================================================= +// Per-frame recording +//============================================================================= + +float Recorder::ElapsedFrameMs() +{ + const auto now = std::chrono::steady_clock::now(); + const auto ns = std::chrono::duration_cast(now - m_lastFrameAt).count(); + m_lastFrameAt = now; + return (float)ns / 1.0e6f; +} + +// GPU ms comes out of FrameProfiler's query ring, which reports work submitted two frames ago -- +// the same reading the $glstats overlay shows. Over a 300-frame repeat the two-frame offset is +// immaterial; it is worth knowing about when reading a single row of frames.csv. +void Recorder::RecordFrame(float frameMs) +{ + FrameSample sample; + sample.frameMs = frameMs; + for (int p = 0; p < (int)FrameProfiler::Pass::Count_; p++) + { + const FrameProfiler::Pass pass = (FrameProfiler::Pass)p; + sample.cpuMs[p] = FrameProfiler::AccumulatorMs(pass); + sample.gpuMs[p] = FrameProfiler::GpuMs(pass); + + for (int c = 0; c < (int)FrameProfiler::Counter::Count_; c++) + m_currentRepeat.counters.perPass[p][c] += FrameProfiler::CounterValue(pass, (FrameProfiler::Counter)c); + } + + for (int c = 0; c < (int)FrameProfiler::Counter::Count_; c++) + m_currentRepeat.counters.total[c] += FrameProfiler::CounterValue((FrameProfiler::Counter)c); + + m_currentRepeat.frames.push_back(sample); +} + +void Recorder::Tick() +{ + if (!m_running) return; + + const float frameMs = ElapsedFrameMs(); + + // The frame a configuration change lands in is not a measurement of either configuration. + if (m_skipNextFrame) + { + m_skipNextFrame = false; + return; + } + + if (frameMs > kStallFrameMs && m_currentRepeat.invalid == InvalidReason::None) + { + m_currentRepeat.invalid = InvalidReason::Stalled; + m_events.push_back(m_plan[m_segmentIndex].resultName + " repeat " + + std::to_string(m_repeatIndex) + ": a " + std::to_string((int)frameMs) + + " ms frame -- the client was not running normally"); + } + + if (m_warmupRemaining > 0) + { + m_warmupRemaining--; + return; + } + + RecordFrame(frameMs); + if ((int)m_currentRepeat.frames.size() < m_manifest.measureFrames) return; + + EndRepeat(); + m_repeatIndex++; + if (m_repeatIndex < m_manifest.repeats) + { + BeginRepeat(); + return; + } + + EndSegment(); +} + +//============================================================================= +// Finishing and export +//============================================================================= + +RunData Recorder::BuildRunData(RunStatus status) const +{ + RunData run; + run.runId = m_runId; + run.manifest = m_manifest; + run.manifestHash = ComputeManifestHash(m_manifest); + run.environment = m_environment; + run.segments = m_segments; + run.events = m_events; + run.status = status; + + for (int p = 0; p < (int)FrameProfiler::Pass::Count_; p++) + { + run.passNames.push_back(FrameProfiler::kPassNames[p]); + run.passIsNested.push_back(IsNestedPass((FrameProfiler::Pass)p)); + } + for (int c = 0; c < (int)FrameProfiler::Counter::Count_; c++) + run.counterNames.push_back(FrameProfiler::kCounterNames[c]); + + return run; +} + +void Recorder::WriteExports(const RunData& run) +{ + const std::vector stats = Stats::SummarizeRun(run); + const std::vector findings = Findings::Evaluate(run, stats); + + const std::filesystem::path directory = std::filesystem::path(kRunsRootPath) / run.runId; + std::error_code error; + std::filesystem::create_directories(directory, error); + if (error) + { + g_ErrorReport.Write(L"[Benchmark] could not create the run directory: %hs\r\n", + error.message().c_str()); + return; + } + + const bool written = + WriteTextFile(directory / Report::kRunJsonFileName, Report::BuildRunJson(run, stats, findings)) && + WriteTextFile(directory / Report::kReportFileName, Report::BuildReportMarkdown(run, stats, findings)) && + WriteTextFile(directory / Report::kFramesCsvFileName, Report::BuildFramesCsv(run)) && + WriteTextFile(directory / Report::kPassesCsvFileName, Report::BuildPassesCsv(run)); + + if (!written) + { + g_ErrorReport.Write(L"[Benchmark] could not write every export for run %hs\r\n", run.runId.c_str()); + return; + } + + m_lastOutputPath = directory.string(); +} + +void Recorder::Finish(RunStatus status) +{ + m_running = false; + Scene::ApplyConfig(m_configBeforeRun); + FrameProfiler::g_CountersEnabled = m_countersWereEnabled; + + WriteExports(BuildRunData(status)); + + m_plan.clear(); + m_segments.clear(); +} + +std::string Recorder::StatusText() const +{ + if (!m_running) return std::string(); + + const std::string phase = (m_warmupRemaining > 0) + ? "warmup " + std::to_string(m_warmupRemaining) + : std::to_string(m_currentRepeat.frames.size()) + "/" + std::to_string(m_manifest.measureFrames); + + return "BENCH " + m_plan[m_segmentIndex].resultName + + " [" + std::to_string(m_segmentIndex + 1) + "/" + std::to_string(m_plan.size()) + "]" + + " repeat " + std::to_string(m_repeatIndex + 1) + "/" + std::to_string(m_manifest.repeats) + + " " + phase; +} +} diff --git a/src/source/Core/Utilities/Benchmark/BenchRecorder.h b/src/source/Core/Utilities/Benchmark/BenchRecorder.h new file mode 100644 index 0000000000..e7f7b72fee --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchRecorder.h @@ -0,0 +1,99 @@ +#pragma once + +#include +#include +#include + +#include "BenchSegment.h" +#include "BenchTypes.h" + +// Drives a benchmark run and writes its exports. One instance, owned by the render thread. +// +// A run is a list of segments, each measured `repeats` times. Every repeat discards a warmup +// window before it starts recording -- the first frames of a segment pay for shader compiles, +// texture uploads and streaming-ring growth, which is real hitching worth knowing about but is +// not the steady state a comparison is about. +// +// The baseline segment is measured first and again last, whatever the selection was, so drift +// across the run is a measured number rather than an assumption. See docs/benchmark.md. + +namespace Core::Benchmark +{ + class Recorder + { + public: + // Defaults chosen so a full run is a couple of minutes and a single-segment run is + // seconds. A repeat is a fixed frame count, never a fixed duration: a faster build must + // render the same frames, not more of them. + static constexpr int kDefaultRepeats = 3; + static constexpr int kDefaultWarmupFrames = 60; + static constexpr int kDefaultMeasureFrames = 300; + + // A frame this long did not measure the scene. Alt-tab, minimise and load hitches all + // land well above it, and no rendered frame legitimately does. + static constexpr float kStallFrameMs = 500.0f; + + static Recorder& Instance(); + + // Starts a run over the segments matching `pattern`. Returns false and fills `outMessage` + // when it cannot start (already running, or nothing matched). + bool Start(const std::string& pattern, int repeats, int warmupFrames, int measureFrames, + std::string& outMessage); + + // Ends the run early. Whatever was measured is still exported, marked aborted. + void Abort(); + + // Called once per frame, after the frame's passes have run and before FrameProfiler is + // reset. Cheap and branch-predictable when no run is active. + void Tick(); + + bool IsRunning() const { return m_running; } + + // One line for the overlay while a run is in progress. + std::string StatusText() const; + + void SetLabel(const std::string& label) { m_label = label; } + + // Directory the last finished run was written to, empty until one finishes. + const std::string& LastOutputPath() const { return m_lastOutputPath; } + + private: + struct PlannedSegment + { + const Segment* definition = nullptr; + std::string resultName; + }; + + bool BuildPlan(const std::string& pattern, std::string& outMessage); + void BeginSegment(); + void BeginRepeat(); + void RecordFrame(float frameMs); + void EndRepeat(); + void EndSegment(); + void Finish(RunStatus status); + void WriteExports(const RunData& run); + RunData BuildRunData(RunStatus status) const; + float ElapsedFrameMs(); + + bool m_running = false; + bool m_countersWereEnabled = false; + SceneConfig m_configBeforeRun; + + std::vector m_plan; + int m_segmentIndex = 0; + int m_repeatIndex = 0; + int m_warmupRemaining = 0; + bool m_skipNextFrame = false; // the frame that straddles a configuration change + + RunManifest m_manifest; + EnvironmentInfo m_environment; + std::vector m_segments; + std::vector m_events; + RepeatSamples m_currentRepeat; + + std::string m_label; + std::string m_runId; + std::string m_lastOutputPath; + std::chrono::steady_clock::time_point m_lastFrameAt; + }; +} diff --git a/src/source/Core/Utilities/Benchmark/BenchReport.cpp b/src/source/Core/Utilities/Benchmark/BenchReport.cpp new file mode 100644 index 0000000000..b4caf2eb96 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchReport.cpp @@ -0,0 +1,637 @@ +#include "BenchReport.h" + +#include +#include + +namespace Core::Benchmark::Report +{ +namespace +{ + // Fixed precision everywhere: two report.md files from two builds have to diff cleanly, and + // a float printed at whatever width it happens to need defeats that. + constexpr int kMsDecimals = 2; + constexpr int kFpsDecimals = 1; + constexpr int kPercentDecimals = 1; + constexpr int kCounterDecimals = 1; + + std::string Fixed(double value, int decimals) + { + char buffer[64]; + snprintf(buffer, sizeof(buffer), "%.*f", decimals, value); + return buffer; + } + + std::string JsonEscape(const std::string& text) + { + std::string out; + out.reserve(text.size() + 8); + for (char c : text) + { + switch (c) + { + case '"': out += "\\\""; break; + case '\\': out += "\\\\"; break; + case '\n': out += "\\n"; break; + case '\r': out += "\\r"; break; + case '\t': out += "\\t"; break; + default: + if ((unsigned char)c < 0x20) out += ' '; + else out += c; + } + } + return out; + } + + std::string JsonString(const std::string& key, const std::string& value, bool trailingComma = true) + { + return "\"" + key + "\": \"" + JsonEscape(value) + "\"" + (trailingComma ? "," : ""); + } + + std::string JsonNumber(const std::string& key, double value, int decimals, bool trailingComma = true) + { + return "\"" + key + "\": " + Fixed(value, decimals) + (trailingComma ? "," : ""); + } + + std::string JsonInt(const std::string& key, long long value, bool trailingComma = true) + { + return "\"" + key + "\": " + std::to_string(value) + (trailingComma ? "," : ""); + } + + std::string JsonBool(const std::string& key, bool value, bool trailingComma = true) + { + return "\"" + key + "\": " + (value ? "true" : "false") + (trailingComma ? "," : ""); + } + + // A CSV field is quoted only when it has to be, so the files stay readable in a terminal. + std::string CsvField(const std::string& text) + { + const bool needsQuotes = text.find_first_of(",\"\n") != std::string::npos; + if (!needsQuotes) return text; + + std::string out = "\""; + for (char c : text) + { + if (c == '"') out += '"'; + out += c; + } + out += '"'; + return out; + } + + void AppendRow(std::string& out, const std::string& label, const std::string& value) + { + out += "| " + label + " | " + value + " |\n"; + } + + std::string Yes(bool value) + { + return value ? "yes" : "no"; + } +} + +//============================================================================= +// frames.csv +//============================================================================= + +std::string BuildFramesCsv(const RunData& run) +{ + std::string out = "segment,repeat,frame,frame_ms"; + for (const std::string& pass : run.passNames) out += ",cpu_" + pass; + for (const std::string& pass : run.passNames) out += ",gpu_" + pass; + out += "\n"; + + const int passCount = (int)run.passNames.size(); + for (const SegmentSamples& segment : run.segments) + { + for (const RepeatSamples& repeat : segment.repeats) + { + for (size_t frameIndex = 0; frameIndex < repeat.frames.size(); frameIndex++) + { + const FrameSample& frame = repeat.frames[frameIndex]; + out += CsvField(segment.name) + "," + std::to_string(repeat.repeatIndex) + "," + + std::to_string(frameIndex) + "," + Fixed(frame.frameMs, kMsDecimals); + for (int p = 0; p < passCount; p++) out += "," + Fixed(frame.cpuMs[p], kMsDecimals); + for (int p = 0; p < passCount; p++) out += "," + Fixed(frame.gpuMs[p], kMsDecimals); + out += "\n"; + } + } + } + return out; +} + +//============================================================================= +// passes.csv +//============================================================================= + +namespace +{ + void AppendPassRow(std::string& out, const RunData& run, const SegmentSamples& segment, + const RepeatSamples& repeat, int passIndex) + { + const int frames = (int)repeat.frames.size(); + if (frames == 0) return; + + double cpuSum = 0.0, gpuSum = 0.0; + for (const FrameSample& frame : repeat.frames) + { + cpuSum += frame.cpuMs[passIndex]; + gpuSum += frame.gpuMs[passIndex]; + } + + out += CsvField(segment.name) + "," + std::to_string(repeat.repeatIndex) + "," + + CsvField(run.passNames[passIndex]) + "," + + Fixed(cpuSum / frames, kMsDecimals) + "," + Fixed(gpuSum / frames, kMsDecimals); + for (size_t c = 0; c < run.counterNames.size(); c++) + out += "," + Fixed((double)repeat.counters.perPass[passIndex][c] / frames, kCounterDecimals); + out += "\n"; + } + + // The per-repeat summary row. Its cpu_ms column carries the mean *frame* time rather than a + // pass time -- there is no such thing as a pass total once passes nest, and a column that + // silently double-counted Skinning would be worse than none. + void AppendTotalRow(std::string& out, const RunData& run, const SegmentSamples& segment, + const RepeatSamples& repeat) + { + const int frames = (int)repeat.frames.size(); + if (frames == 0) return; + + double frameMsSum = 0.0; + for (const FrameSample& frame : repeat.frames) frameMsSum += frame.frameMs; + + out += CsvField(segment.name) + "," + std::to_string(repeat.repeatIndex) + ",TOTAL," + + Fixed(frameMsSum / frames, kMsDecimals) + ",0.00"; + for (size_t c = 0; c < run.counterNames.size(); c++) + out += "," + Fixed((double)repeat.counters.total[c] / frames, kCounterDecimals); + out += "\n"; + } +} + +std::string BuildPassesCsv(const RunData& run) +{ + std::string out = "segment,repeat,pass,cpu_ms,gpu_ms"; + for (const std::string& counter : run.counterNames) out += "," + counter; + out += "\n"; + + for (const SegmentSamples& segment : run.segments) + { + for (const RepeatSamples& repeat : segment.repeats) + { + for (size_t p = 0; p < run.passNames.size(); p++) + AppendPassRow(out, run, segment, repeat, (int)p); + AppendTotalRow(out, run, segment, repeat); + } + } + return out; +} + +//============================================================================= +// report.md +//============================================================================= + +namespace +{ + void AppendMarkdownBanners(std::string& out, const RunData& run) + { + if (run.status == RunStatus::Aborted) + out += "> **Aborted run.** The measurements below are partial.\n\n"; + + if (run.environment.gitDirty) + out += "> **Uncommitted changes.** This run cannot be reproduced from the commit alone.\n\n"; + + if (run.environment.vsyncEffective) + out += "> **Vsync was on.** Frame times are pinned to the display refresh.\n\n"; + } + + void AppendIdentitySection(std::string& out, const RunData& run) + { + out += "## Identity\n\n| Field | Value |\n|---|---|\n"; + AppendRow(out, "Run id", run.runId); + AppendRow(out, "Label", run.manifest.label.empty() ? "(none)" : run.manifest.label); + AppendRow(out, "Started (UTC)", run.environment.timestampUtc); + AppendRow(out, "Commit", run.environment.gitDescribe.empty() ? "(unknown)" : run.environment.gitDescribe); + AppendRow(out, "Working tree", run.environment.gitDirty ? "dirty" : "clean"); + AppendRow(out, "Status", ToString(run.status)); + AppendRow(out, "Manifest hash", run.manifestHash); + out += "\n"; + } + + void AppendBuildSection(std::string& out, const EnvironmentInfo& env) + { + out += "## Build\n\n| Field | Value |\n|---|---|\n"; + AppendRow(out, "Configuration", env.buildConfig); + AppendRow(out, "Editor", env.buildEditor); + AppendRow(out, "Compiler", env.buildCompiler); + AppendRow(out, "Architecture", env.buildArch); + AppendRow(out, "Built", env.buildTimestamp); + out += "\n"; + } + + void AppendMachineSection(std::string& out, const EnvironmentInfo& env) + { + out += "## Machine\n\n| Field | Value |\n|---|---|\n"; + AppendRow(out, "OS", env.osVersion); + AppendRow(out, "CPU", env.cpu); + AppendRow(out, "Hardware threads", std::to_string(env.cpuThreads)); + AppendRow(out, "System memory", std::to_string(env.systemMemoryMB) + " MB"); + out += "\n"; + } + + void AppendGraphicsSection(std::string& out, const EnvironmentInfo& env) + { + out += "## Graphics\n\n| Field | Value |\n|---|---|\n"; + AppendRow(out, "GL vendor", env.glVendor); + AppendRow(out, "GL renderer", env.glRenderer); + AppendRow(out, "GL version", env.glVersion); + AppendRow(out, "GLSL version", env.glslVersion); + AppendRow(out, "Context obtained", + std::to_string(env.contextMajor) + "." + std::to_string(env.contextMinor)); + AppendRow(out, "Caps: buffer storage", Yes(env.capsBufferStorage)); + AppendRow(out, "Caps: vertex attrib binding", Yes(env.capsVertexAttribBinding)); + AppendRow(out, "Caps: program binary", Yes(env.capsProgramBinary)); + AppendRow(out, "Caps: timer query", Yes(env.capsTimerQuery)); + AppendRow(out, "UBO offset alignment", std::to_string(env.capsUboOffsetAlignment)); + AppendRow(out, "Max uniform block size", std::to_string(env.capsMaxUniformBlockSize)); + AppendRow(out, "Resolution", + std::to_string(env.windowWidth) + "x" + std::to_string(env.windowHeight)); + AppendRow(out, "Vsync requested / effective", + Yes(env.vsyncRequested) + " / " + Yes(env.vsyncEffective)); + AppendRow(out, "Target FPS", Fixed(env.targetFps, kFpsDecimals)); + AppendRow(out, "Map", env.mapName.empty() ? "(unknown)" : env.mapName); + out += "\n"; + } + + void AppendConfigSection(std::string& out, const RunManifest& manifest) + { + out += "## Run configuration\n\n| Field | Value |\n|---|---|\n"; + AppendRow(out, "Selection", manifest.pattern); + AppendRow(out, "Repeats", std::to_string(manifest.repeats)); + AppendRow(out, "Warmup frames", std::to_string(manifest.warmupFrames)); + AppendRow(out, "Measured frames", std::to_string(manifest.measureFrames)); + + std::string order; + for (const std::string& name : manifest.segmentNames) + { + if (!order.empty()) order += " -> "; + order += name; + } + AppendRow(out, "Segment order", order); + out += "\n"; + } + + // The pass carrying the most CPU time, ignoring passes contained in another pass (which would + // otherwise win by being counted twice) and the overlay's own measurement cost. + std::string DominantPass(const RunData& run, const Stats::SegmentStats& segment) + { + std::string best = "-"; + float bestMs = 0.0f; + for (size_t p = 0; p < run.passNames.size() && p < (size_t)kMaxPasses; p++) + { + const bool nested = (p < run.passIsNested.size()) && run.passIsNested[p]; + if (nested || run.passNames[p] == "Overlay") continue; + if (segment.passCpuMs[p] <= bestMs) continue; + + bestMs = segment.passCpuMs[p]; + best = run.passNames[p]; + } + return best + " " + Fixed(bestMs, kMsDecimals) + " ms"; + } + + void AppendSummarySection(std::string& out, const RunData& run, + const std::vector& stats) + { + out += "## Segment summary\n\n"; + out += "| Segment | Frames | Median ms | Mean FPS | 1% low FPS | p99 ms | Repeat spread | Dominant pass |\n"; + out += "|---|---:|---:|---:|---:|---:|---:|---|\n"; + + for (const Stats::SegmentStats& segment : stats) + { + out += "| " + segment.name + + " | " + std::to_string(segment.measuredFrames) + + " | " + Fixed(segment.frame.medianMs, kMsDecimals) + + " | " + Fixed(segment.frame.meanFps, kFpsDecimals) + + " | " + Fixed(segment.frame.onePercentLowFps, kFpsDecimals) + + " | " + Fixed(segment.frame.p99Ms, kMsDecimals) + + " | " + Fixed(segment.repeatSpreadPercent, kPercentDecimals) + "% | " + + DominantPass(run, segment) + " |\n"; + } + out += "\n"; + } + + void AppendPacingSection(std::string& out, const std::vector& stats) + { + out += "## Frame pacing\n\n"; + out += "A low mean frame time with a high mean delta is a stuttering frame stream, not a smooth one.\n\n"; + out += "| Segment | Mean delta ms | Slow frames | Longest slow run | Max ms |\n|---|---:|---:|---:|---:|\n"; + + for (const Stats::SegmentStats& segment : stats) + { + out += "| " + segment.name + + " | " + Fixed(segment.frame.pacingMeanAbsDeltaMs, kMsDecimals) + + " | " + std::to_string(segment.frame.slowFrameCount) + + " | " + std::to_string(segment.frame.longestSlowFrameRun) + + " | " + Fixed(segment.frame.maxMs, kMsDecimals) + " |\n"; + } + out += "\n"; + } +} + +namespace +{ + int CounterIndex(const RunData& run, const char* name) + { + for (size_t i = 0; i < run.counterNames.size(); i++) + if (run.counterNames[i] == name) return (int)i; + return -1; + } + + std::string CounterCell(const Stats::SegmentStats& segment, int passIndex, int counterIndex) + { + if (counterIndex < 0) return "-"; + return Fixed(segment.passCounterPerFrame[passIndex][counterIndex], kCounterDecimals); + } + + void AppendSegmentPassTable(std::string& out, const RunData& run, + const Stats::SegmentStats& segment) + { + const int drawIndex = CounterIndex(run, "DrawCalls"); + const int glIndex = CounterIndex(run, "GLCalls"); + + out += "### " + segment.name + "\n\n"; + out += "| Pass | CPU ms | GPU ms | Draws | GL calls |\n|---|---:|---:|---:|---:|\n"; + + for (size_t p = 0; p < run.passNames.size() && p < (size_t)kMaxPasses; p++) + { + const bool silent = segment.passCpuMs[p] == 0.0f && segment.passGpuMs[p] == 0.0f; + if (silent) continue; + + out += "| " + run.passNames[p] + + " | " + Fixed(segment.passCpuMs[p], kMsDecimals) + + " | " + Fixed(segment.passGpuMs[p], kMsDecimals) + + " | " + CounterCell(segment, (int)p, drawIndex) + + " | " + CounterCell(segment, (int)p, glIndex) + " |\n"; + } + + out += "| **frame** | " + Fixed(segment.frame.meanMs, kMsDecimals) + " | | | |\n"; + out += "| *unattributed* | " + Fixed(segment.unattributedMs, kMsDecimals) + + " (" + Fixed(segment.unattributedPercent, kPercentDecimals) + "%) | | | |\n\n"; + } + + void AppendBreakdownSection(std::string& out, const RunData& run, + const std::vector& stats) + { + out += "## Pass breakdown\n\n"; + out += "Per measured frame, averaged over the valid repeats. Nested passes (Skinning, CharWait) "; + out += "are contained in another pass and are excluded from the unattributed remainder.\n\n"; + + for (const Stats::SegmentStats& segment : stats) + AppendSegmentPassTable(out, run, segment); + } + + void AppendFindingsSection(std::string& out, const std::vector& findings) + { + out += "## Findings\n\n"; + if (findings.empty()) + { + out += "No rule fired.\n\n"; + return; + } + + out += "Each row is one named rule with a fixed threshold. A finding is an observation about "; + out += "this run, not a claim about a code change.\n\n"; + out += "| Level | Rule | Segment | Observation |\n|---|---|---|---|\n"; + for (const Findings::Finding& finding : findings) + { + out += std::string("| ") + Findings::ToString(finding.level) + + " | " + finding.rule + + " | " + (finding.segment.empty() ? "(run)" : finding.segment) + + " | " + finding.text + " |\n"; + } + out += "\n"; + } + + void AppendHealthSection(std::string& out, const RunData& run, + const std::vector& stats) + { + out += "## Health\n\n"; + out += "| Segment | Valid repeats | Discarded repeats | Measured frames |\n|---|---:|---:|---:|\n"; + for (const Stats::SegmentStats& segment : stats) + { + out += "| " + segment.name + + " | " + std::to_string(segment.validRepeats) + + " | " + std::to_string(segment.invalidRepeats) + + " | " + std::to_string(segment.measuredFrames) + " |\n"; + } + out += "\n"; + + if (run.events.empty()) return; + + out += "### Events\n\n"; + for (const std::string& event : run.events) out += "- " + event + "\n"; + out += "\n"; + } +} + +std::string BuildReportMarkdown(const RunData& run, + const std::vector& stats, + const std::vector& findings) +{ + std::string out = "# Benchmark run " + run.runId + "\n\n"; + + AppendMarkdownBanners(out, run); + AppendIdentitySection(out, run); + AppendBuildSection(out, run.environment); + AppendMachineSection(out, run.environment); + AppendGraphicsSection(out, run.environment); + AppendConfigSection(out, run.manifest); + AppendSummarySection(out, run, stats); + AppendPacingSection(out, stats); + AppendFindingsSection(out, findings); + AppendBreakdownSection(out, run, stats); + AppendHealthSection(out, run, stats); + + return out; +} + +//============================================================================= +// run.json -- the canonical artifact +//============================================================================= + +namespace +{ + void AppendJsonEnvironment(std::string& out, const EnvironmentInfo& env) + { + out += " \"environment\": {\n"; + out += " " + JsonString("timestampUtc", env.timestampUtc) + "\n"; + out += " " + JsonString("os", env.osVersion) + "\n"; + out += " " + JsonString("cpu", env.cpu) + "\n"; + out += " " + JsonInt("cpuThreads", env.cpuThreads) + "\n"; + out += " " + JsonInt("systemMemoryMB", (long long)env.systemMemoryMB) + "\n"; + out += " " + JsonString("glVendor", env.glVendor) + "\n"; + out += " " + JsonString("glRenderer", env.glRenderer) + "\n"; + out += " " + JsonString("glVersion", env.glVersion) + "\n"; + out += " " + JsonString("glslVersion", env.glslVersion) + "\n"; + out += " " + JsonInt("contextMajor", env.contextMajor) + "\n"; + out += " " + JsonInt("contextMinor", env.contextMinor) + "\n"; + out += " " + JsonBool("capsBufferStorage", env.capsBufferStorage) + "\n"; + out += " " + JsonBool("capsVertexAttribBinding", env.capsVertexAttribBinding) + "\n"; + out += " " + JsonBool("capsProgramBinary", env.capsProgramBinary) + "\n"; + out += " " + JsonBool("capsTimerQuery", env.capsTimerQuery) + "\n"; + out += " " + JsonInt("capsUboOffsetAlignment", env.capsUboOffsetAlignment) + "\n"; + out += " " + JsonInt("capsMaxUniformBlockSize", env.capsMaxUniformBlockSize) + "\n"; + out += " " + JsonString("buildConfig", env.buildConfig) + "\n"; + out += " " + JsonString("buildEditor", env.buildEditor) + "\n"; + out += " " + JsonString("buildCompiler", env.buildCompiler) + "\n"; + out += " " + JsonString("buildArch", env.buildArch) + "\n"; + out += " " + JsonString("buildTimestamp", env.buildTimestamp) + "\n"; + out += " " + JsonString("gitDescribe", env.gitDescribe) + "\n"; + out += " " + JsonBool("gitDirty", env.gitDirty) + "\n"; + out += " " + JsonInt("windowWidth", env.windowWidth) + "\n"; + out += " " + JsonInt("windowHeight", env.windowHeight) + "\n"; + out += " " + JsonBool("vsyncRequested", env.vsyncRequested) + "\n"; + out += " " + JsonBool("vsyncEffective", env.vsyncEffective) + "\n"; + out += " " + JsonNumber("targetFps", env.targetFps, kFpsDecimals) + "\n"; + out += " " + JsonString("map", env.mapName, false) + "\n"; + out += " },\n"; + } + + std::string JsonStringArray(const std::vector& values) + { + std::string out = "["; + for (size_t i = 0; i < values.size(); i++) + { + if (i > 0) out += ", "; + out += "\"" + JsonEscape(values[i]) + "\""; + } + return out + "]"; + } + + void AppendJsonManifest(std::string& out, const RunManifest& manifest) + { + out += " \"manifest\": {\n"; + out += " " + JsonString("label", manifest.label) + "\n"; + out += " " + JsonString("pattern", manifest.pattern) + "\n"; + out += " " + JsonInt("repeats", manifest.repeats) + "\n"; + out += " " + JsonInt("warmupFrames", manifest.warmupFrames) + "\n"; + out += " " + JsonInt("measureFrames", manifest.measureFrames) + "\n"; + out += " \"segments\": " + JsonStringArray(manifest.segmentNames) + "\n"; + out += " },\n"; + } + + std::string JsonNumberArray(const std::vector& values, int decimals) + { + std::string out = "["; + for (size_t i = 0; i < values.size(); i++) + { + if (i > 0) out += ", "; + out += Fixed(values[i], decimals); + } + return out + "]"; + } + + void AppendJsonTiming(std::string& out, const Stats::TimingStats& timing, const char* indent) + { + out += indent + JsonInt("frameCount", timing.frameCount) + "\n"; + out += indent + JsonNumber("meanMs", timing.meanMs, kMsDecimals) + "\n"; + out += indent + JsonNumber("medianMs", timing.medianMs, kMsDecimals) + "\n"; + out += indent + JsonNumber("p95Ms", timing.p95Ms, kMsDecimals) + "\n"; + out += indent + JsonNumber("p99Ms", timing.p99Ms, kMsDecimals) + "\n"; + out += indent + JsonNumber("minMs", timing.minMs, kMsDecimals) + "\n"; + out += indent + JsonNumber("maxMs", timing.maxMs, kMsDecimals) + "\n"; + out += indent + JsonNumber("stdDevMs", timing.stdDevMs, kMsDecimals) + "\n"; + out += indent + JsonNumber("meanFps", timing.meanFps, kFpsDecimals) + "\n"; + out += indent + JsonNumber("onePercentLowMs", timing.onePercentLowMs, kMsDecimals) + "\n"; + out += indent + JsonNumber("onePercentLowFps", timing.onePercentLowFps, kFpsDecimals) + "\n"; + out += indent + JsonNumber("pacingMeanAbsDeltaMs", timing.pacingMeanAbsDeltaMs, kMsDecimals) + "\n"; + out += indent + JsonInt("slowFrameCount", timing.slowFrameCount) + "\n"; + out += indent + JsonInt("longestSlowFrameRun", timing.longestSlowFrameRun) + "\n"; + out += std::string(indent) + "\"percentileCurveMs\": " + JsonNumberArray(timing.percentileCurveMs, kMsDecimals) + "\n"; + } + + void AppendJsonPasses(std::string& out, const RunData& run, const Stats::SegmentStats& segment) + { + const size_t passCount = std::min(run.passNames.size(), (size_t)kMaxPasses); + out += " \"passes\": [\n"; + for (size_t p = 0; p < passCount; p++) + { + out += " { " + JsonString("name", run.passNames[p]) + " " + + JsonNumber("cpuMs", segment.passCpuMs[p], kMsDecimals) + " " + + JsonNumber("gpuMs", segment.passGpuMs[p], kMsDecimals, false) + " }"; + out += (p + 1 < passCount) ? ",\n" : "\n"; + } + out += " ],\n"; + } + + void AppendJsonCounters(std::string& out, const RunData& run, const Stats::SegmentStats& segment) + { + const size_t counterCount = std::min(run.counterNames.size(), (size_t)kMaxCounters); + out += " \"countersPerFrame\": {\n"; + for (size_t c = 0; c < counterCount; c++) + { + const bool last = (c + 1 == counterCount); + out += " " + JsonNumber(run.counterNames[c], segment.counterPerFrame[c], + kCounterDecimals, !last) + "\n"; + } + out += " }\n"; + } + + void AppendJsonSegment(std::string& out, const RunData& run, + const Stats::SegmentStats& segment, bool last) + { + out += " {\n"; + out += " " + JsonString("name", segment.name) + "\n"; + out += " " + JsonInt("validRepeats", segment.validRepeats) + "\n"; + out += " " + JsonInt("invalidRepeats", segment.invalidRepeats) + "\n"; + out += " " + JsonNumber("repeatSpreadMs", segment.repeatSpreadMs, kMsDecimals) + "\n"; + out += " " + JsonNumber("repeatSpreadPercent", segment.repeatSpreadPercent, kPercentDecimals) + "\n"; + out += " \"repeatMedianMs\": " + JsonNumberArray(segment.repeatMedianMs, kMsDecimals) + ",\n"; + out += " " + JsonNumber("attributedCpuMs", segment.attributedCpuMs, kMsDecimals) + "\n"; + out += " " + JsonNumber("unattributedMs", segment.unattributedMs, kMsDecimals) + "\n"; + out += " " + JsonNumber("unattributedPercent", segment.unattributedPercent, kPercentDecimals) + "\n"; + out += " \"frame\": {\n"; + AppendJsonTiming(out, segment.frame, " "); + out += " },\n"; + AppendJsonPasses(out, run, segment); + AppendJsonCounters(out, run, segment); + out += last ? " }\n" : " },\n"; + } + + void AppendJsonFindings(std::string& out, const std::vector& findings) + { + out += " \"findings\": [\n"; + for (size_t i = 0; i < findings.size(); i++) + { + out += " { " + JsonString("level", Findings::ToString(findings[i].level)) + " " + + JsonString("rule", findings[i].rule) + " " + + JsonString("segment", findings[i].segment) + " " + + JsonString("text", findings[i].text, false) + " }"; + out += (i + 1 < findings.size()) ? ",\n" : "\n"; + } + out += " ]\n"; + } +} + +std::string BuildRunJson(const RunData& run, + const std::vector& stats, + const std::vector& findings) +{ + std::string out = "{\n"; + out += " " + JsonInt("schemaVersion", kSchemaVersion) + "\n"; + out += " " + JsonString("runId", run.runId) + "\n"; + out += " " + JsonString("manifestHash", run.manifestHash) + "\n"; + out += " " + JsonString("status", ToString(run.status)) + "\n"; + AppendJsonManifest(out, run.manifest); + AppendJsonEnvironment(out, run.environment); + out += " \"passNames\": " + JsonStringArray(run.passNames) + ",\n"; + out += " \"counterNames\": " + JsonStringArray(run.counterNames) + ",\n"; + out += " \"events\": " + JsonStringArray(run.events) + ",\n"; + + out += " \"segments\": [\n"; + for (size_t i = 0; i < stats.size(); i++) + AppendJsonSegment(out, run, stats[i], i + 1 == stats.size()); + out += " ],\n"; + + AppendJsonFindings(out, findings); + out += "}\n"; + return out; +} +} diff --git a/src/source/Core/Utilities/Benchmark/BenchReport.h b/src/source/Core/Utilities/Benchmark/BenchReport.h new file mode 100644 index 0000000000..dee08d2cb6 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchReport.h @@ -0,0 +1,48 @@ +#pragma once + +#include +#include + +#include "BenchFindings.h" +#include "BenchStats.h" +#include "BenchTypes.h" + +// Serializers for a finished run. Pure string building, so the exact bytes written to disk are +// unit-testable. +// +// run.json is the canonical artifact -- the one a comparison tool reads. The Markdown and the +// CSVs are views rendered from the same data. The Markdown is never hand-edited: the moment a +// report becomes something a human maintains, the whole thing has decayed back into the +// screenshot workflow it exists to replace. +// +// Everything here formats floats at a fixed precision and emits rows in a fixed order, so two +// report.md files from two builds diff cleanly against each other. + +namespace Core::Benchmark::Report +{ + inline constexpr const char* kRunJsonFileName = "run.json"; + inline constexpr const char* kReportFileName = "report.md"; + inline constexpr const char* kFramesCsvFileName = "frames.csv"; + inline constexpr const char* kPassesCsvFileName = "passes.csv"; + + // Bumped whenever a field changes meaning or disappears, so a comparison tool can refuse a + // run it would misread instead of quietly comparing the wrong columns. + inline constexpr int kSchemaVersion = 1; + + std::string BuildRunJson(const RunData& run, + const std::vector& stats, + const std::vector& findings); + + // One row per measured frame: identity, frame time, and per-pass CPU/GPU ms. No counter + // columns -- counters are near-deterministic for a fixed workload, so their per-segment + // totals in passes.csv carry the same information without 500 columns nobody reads. + std::string BuildFramesCsv(const RunData& run); + + // One row per segment x repeat x pass, plus a TOTAL row per repeat: pass timings and every + // GL counter, averaged per measured frame. + std::string BuildPassesCsv(const RunData& run); + + std::string BuildReportMarkdown(const RunData& run, + const std::vector& stats, + const std::vector& findings); +} diff --git a/src/source/Core/Utilities/Benchmark/BenchScene.cpp b/src/source/Core/Utilities/Benchmark/BenchScene.cpp new file mode 100644 index 0000000000..c2a3a83bb4 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchScene.cpp @@ -0,0 +1,37 @@ +#include "stdafx.h" + +#include "BenchScene.h" + +#include "Scenes/MainScene.h" +#include "UI/NewUI/NewUISystem.h" + +namespace Core::Benchmark::Scene +{ + SceneConfig CaptureCurrentConfig() + { + SceneConfig config; + config.disableEffects = IsEffectsDisabledDebug(); + config.disableAllEffectsOption = g_pOption && !g_pOption->GetRenderAllEffects(); + config.disableSprites = IsSpritesDisabledDebug(); + config.disableParticles = IsParticlesDisabledDebug(); + config.disableSkillEffectModels = IsSkillEffectModelsDisabledDebug(); + config.disableJoints = IsJointsDisabledDebug(); + config.disableBoids = IsBoidsDisabledDebug(); + config.disableWingShadow = IsWingShadowDisabledDebug(); + config.disableWingExtraLayers = IsWingExtraLayersDisabledDebug(); + return config; + } + + void ApplyConfig(const SceneConfig& config) + { + SetDisableEffects(config.disableEffects); + if (g_pOption) g_pOption->SetRenderAllEffects(!config.disableAllEffectsOption); + SetDisableSprites(config.disableSprites); + SetDisableParticles(config.disableParticles); + SetDisableSkillEffectModels(config.disableSkillEffectModels); + SetDisableJoints(config.disableJoints); + SetDisableBoids(config.disableBoids); + SetDisableWingShadow(config.disableWingShadow); + SetDisableWingExtraLayers(config.disableWingExtraLayers); + } +} diff --git a/src/source/Core/Utilities/Benchmark/BenchScene.h b/src/source/Core/Utilities/Benchmark/BenchScene.h new file mode 100644 index 0000000000..c4ae3577cd --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchScene.h @@ -0,0 +1,17 @@ +#pragma once + +#include "BenchSegment.h" + +// Applies a segment's scene configuration to the live client, and puts back what was there +// before. Kept apart from the catalog so the catalog stays pure data and linkable from tests. +// +// The restore path is the contamination guard: a segment that leaked its configuration into the +// next one would make the next one's numbers look like a change that never happened, silently. + +namespace Core::Benchmark::Scene +{ + // The effect toggles as they were before the run touched them. + SceneConfig CaptureCurrentConfig(); + + void ApplyConfig(const SceneConfig& config); +} diff --git a/src/source/Core/Utilities/Benchmark/BenchSegment.cpp b/src/source/Core/Utilities/Benchmark/BenchSegment.cpp new file mode 100644 index 0000000000..036608231e --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchSegment.cpp @@ -0,0 +1,160 @@ +#include "BenchSegment.h" + +namespace Core::Benchmark::Segments +{ +namespace +{ + // Written out longhand rather than built from a loop: the catalog is the specification of + // what a run measures, and it should be readable as a list. + const std::vector& Catalog() + { + static const std::vector s_segments = { + { kBaselineSegmentName, + "Everything on. The reference every other segment is read against, and the drift control.", + TagBaseline, SceneConfig{} }, + + { "fx.all.off", + "Every effect surface off, exactly as `$effects off` does it. Upper bound on what " + "effects cost here.", + TagEffects | TagSprites | TagParticles | TagJoints | TagModels, + [] { + SceneConfig c; + c.disableEffects = true; + c.disableAllEffectsOption = true; + // Joints are gated by neither of the two switches above (ZzzEffectJoint.cpp + // checks only its own flag), so "all off" has to say so explicitly or the + // segment quietly leaves the beam/tail path running. + c.disableJoints = true; + return c; + }() }, + + { "fx.sprites.off", + "RenderSprites() off. IR per-quad path.", + TagEffects | TagSprites, [] { SceneConfig c; c.disableSprites = true; return c; }() }, + + { "fx.particles.off", + "RenderParticles() off. The heaviest IR per-quad path in effect-dense frames.", + TagEffects | TagParticles, [] { SceneConfig c; c.disableParticles = true; return c; }() }, + + { "fx.joints.off", + "RenderJoints() off. Beam and tail-trail effects.", + TagEffects | TagJoints, [] { SceneConfig c; c.disableJoints = true; return c; }() }, + + { "fx.skillmodels.off", + "Skill effect models off, legacy impact effects still rendering.", + TagEffects | TagModels, [] { SceneConfig c; c.disableSkillEffectModels = true; return c; }() }, + + { "fx.boids.off", + "Ambient wildlife off. Always-on cost in town maps, independent of combat.", + TagWildlife, [] { SceneConfig c; c.disableBoids = true; return c; }() }, + + { "fx.wingshadow.off", + "The extra per-wing body shadow draw off.", + TagWings, [] { SceneConfig c; c.disableWingShadow = true; return c; }() }, + + { "fx.winglayers.off", + "Wing glow overlay passes off. Visibly changes the wing -- a measurement, not a fix.", + TagWings, [] { SceneConfig c; c.disableWingExtraLayers = true; return c; }() }, + }; + return s_segments; + } + + struct TagName + { + SegmentTag tag; + const char* name; + }; + + const TagName kTagNames[] = { + { TagBaseline, "baseline" }, + { TagEffects, "effects" }, + { TagSprites, "sprites" }, + { TagParticles, "particles" }, + { TagJoints, "joints" }, + { TagModels, "models" }, + { TagWildlife, "wildlife" }, + { TagWings, "wings" }, + }; + + bool HasTagNamed(uint32_t tags, const std::string& wanted) + { + for (const TagName& entry : kTagNames) + if (wanted == entry.name) return (tags & entry.tag) != 0; + return false; + } +} + +const std::vector& All() +{ + return Catalog(); +} + +const Segment* Find(const std::string& name) +{ + for (const Segment& segment : Catalog()) + if (name == segment.name) return &segment; + return nullptr; +} + +bool MatchesPattern(const std::string& name, const std::string& pattern) +{ + // Iterative glob with backtracking on the last '*' -- no recursion, no allocation. + size_t nameIndex = 0, patternIndex = 0; + size_t starIndex = std::string::npos, nameAtStar = 0; + + while (nameIndex < name.size()) + { + const bool literalMatch = patternIndex < pattern.size() && + (pattern[patternIndex] == '?' || pattern[patternIndex] == name[nameIndex]); + if (literalMatch) + { + nameIndex++; + patternIndex++; + continue; + } + + if (patternIndex < pattern.size() && pattern[patternIndex] == '*') + { + starIndex = patternIndex++; + nameAtStar = nameIndex; + continue; + } + + if (starIndex == std::string::npos) return false; + + // Backtrack: let the last '*' swallow one more character. + patternIndex = starIndex + 1; + nameIndex = ++nameAtStar; + } + + while (patternIndex < pattern.size() && pattern[patternIndex] == '*') patternIndex++; + return patternIndex == pattern.size(); +} + +std::vector Select(const std::string& pattern) +{ + std::vector selected; + const bool byTag = !pattern.empty() && pattern[0] == '#'; + const std::string tagName = byTag ? pattern.substr(1) : std::string(); + + for (const Segment& segment : Catalog()) + { + const bool matches = byTag ? HasTagNamed(segment.tags, tagName) + : MatchesPattern(segment.name, pattern); + if (matches) selected.push_back(&segment); + } + return selected; +} + +std::string TagsToString(uint32_t tags) +{ + std::string out; + for (const TagName& entry : kTagNames) + { + if ((tags & entry.tag) == 0) continue; + if (!out.empty()) out += ' '; + out += entry.name; + } + return out; +} +} diff --git a/src/source/Core/Utilities/Benchmark/BenchSegment.h b/src/source/Core/Utilities/Benchmark/BenchSegment.h new file mode 100644 index 0000000000..dadce3e29d --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchSegment.h @@ -0,0 +1,79 @@ +#pragma once + +#include +#include +#include + +#include "BenchTypes.h" + +// The catalog of benchmark segments and the selection logic over it. Pure data: applying a +// segment to the live scene is BenchScene's job, running one is BenchRecorder's. +// +// A segment is one named, self-contained scenario measured on its own, so a run says *where* a +// change had an effect instead of only whether the frame got faster. This first catalog varies +// the effect surfaces of whatever scene the client is currently showing -- it needs no scripted +// content, and the differences between the rows are the per-surface cost at that spot. Scripted +// scenes (spawned characters, camera paths, weather) are a separate, later addition. + +namespace Core::Benchmark +{ + // Tags exist for selection and for reading the report; a segment can carry several. + enum SegmentTag : uint32_t + { + TagBaseline = 1u << 0, + TagEffects = 1u << 1, + TagSprites = 1u << 2, + TagParticles = 1u << 3, + TagJoints = 1u << 4, + TagModels = 1u << 5, + TagWildlife = 1u << 6, + TagWings = 1u << 7, + }; + + // Which effect surfaces the segment switches off while it is measured. Mirrors the + // `$effects ...` console toggles (MainScene.h) one-for-one -- deliberately data, so the + // catalog stays linkable from a unit test. + struct SceneConfig + { + bool disableEffects = false; + // Mirrors the options window's "render all effects" switch, which `$effects off` turns + // off alongside SetDisableEffects. It is a separate flag because it is a separate gate: + // RenderSprites() and RenderParticles() early-return on this option and never look at + // SetDisableEffects at all, so a segment that sets only the latter leaves the two + // heaviest effect paths running. + bool disableAllEffectsOption = false; + bool disableSprites = false; + bool disableParticles = false; + bool disableSkillEffectModels = false; + bool disableJoints = false; + bool disableBoids = false; + bool disableWingShadow = false; + bool disableWingExtraLayers = false; + }; + + struct Segment + { + const char* name; + const char* description; + uint32_t tags; + SceneConfig config; + }; +} + +namespace Core::Benchmark::Segments +{ + const std::vector& All(); + + const Segment* Find(const std::string& name); + + // Glob match supporting '*' (any run of characters, including none). Case-sensitive; segment + // names are lowercase by convention. + bool MatchesPattern(const std::string& name, const std::string& pattern); + + // Segments whose name matches the glob, or whose tag list contains it when the pattern is + // written as "#tag". Returned in catalog order, which is the order they are measured in. + std::vector Select(const std::string& pattern); + + // Space-separated lowercase tag names, for the exports. + std::string TagsToString(uint32_t tags); +} diff --git a/src/source/Core/Utilities/Benchmark/BenchStats.cpp b/src/source/Core/Utilities/Benchmark/BenchStats.cpp new file mode 100644 index 0000000000..26e15d32f9 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchStats.cpp @@ -0,0 +1,242 @@ +#include "BenchStats.h" + +#include +#include + +namespace Core::Benchmark::Stats +{ +namespace +{ + float MsToFps(float ms) + { + return (ms > 0.0f) ? (1000.0f / ms) : 0.0f; + } + + // Nearest-rank percentile on an already sorted, non-empty vector. + float PercentileOfSorted(const std::vector& sorted, float fraction) + { + const size_t maxIndex = sorted.size() - 1; + const size_t index = (size_t)std::lround(fraction * (float)maxIndex); + return sorted[std::min(index, maxIndex)]; + } + + float MeanOf(const std::vector& values) + { + if (values.empty()) return 0.0f; + double sum = 0.0; + for (float v : values) sum += v; + return (float)(sum / (double)values.size()); + } + + float StdDevOf(const std::vector& values, float mean) + { + if (values.size() < 2) return 0.0f; + double sumSquares = 0.0; + for (float v : values) + { + const double d = (double)v - (double)mean; + sumSquares += d * d; + } + return (float)std::sqrt(sumSquares / (double)(values.size() - 1)); + } + + // Mean of the worst (slowest) share of frames, at least one frame. + float WorstFractionMean(const std::vector& sorted, float fraction) + { + const size_t count = std::max(1, (size_t)(sorted.size() * fraction)); + double sum = 0.0; + for (size_t i = sorted.size() - count; i < sorted.size(); i++) sum += sorted[i]; + return (float)(sum / (double)count); + } + + void FillPacing(const std::vector& frameTimesMs, TimingStats& out) + { + if (frameTimesMs.size() < 2) return; + + double deltaSum = 0.0; + for (size_t i = 1; i < frameTimesMs.size(); i++) + deltaSum += std::fabs((double)frameTimesMs[i] - (double)frameTimesMs[i - 1]); + out.pacingMeanAbsDeltaMs = (float)(deltaSum / (double)(frameTimesMs.size() - 1)); + + const float slowThresholdMs = out.medianMs * kSlowFrameMedianMultiple; + int currentRun = 0; + for (float ms : frameTimesMs) + { + if (ms <= slowThresholdMs) + { + currentRun = 0; + continue; + } + out.slowFrameCount++; + currentRun++; + out.longestSlowFrameRun = std::max(out.longestSlowFrameRun, currentRun); + } + } + + void FillPercentileCurve(const std::vector& sorted, TimingStats& out) + { + out.percentileCurveMs.reserve(kPercentileCurvePoints); + for (int i = 0; i < kPercentileCurvePoints; i++) + out.percentileCurveMs.push_back(PercentileOfSorted(sorted, (float)i / (float)(kPercentileCurvePoints - 1))); + } +} + +TimingStats Summarize(const std::vector& frameTimesMs) +{ + TimingStats out; + if (frameTimesMs.empty()) return out; + + std::vector sorted = frameTimesMs; + std::sort(sorted.begin(), sorted.end()); + + out.frameCount = (int)sorted.size(); + out.meanMs = MeanOf(sorted); + out.medianMs = PercentileOfSorted(sorted, 0.5f); + out.p95Ms = PercentileOfSorted(sorted, 0.95f); + out.p99Ms = PercentileOfSorted(sorted, 0.99f); + out.minMs = sorted.front(); + out.maxMs = sorted.back(); + out.stdDevMs = StdDevOf(sorted, out.meanMs); + out.meanFps = MsToFps(out.meanMs); + out.onePercentLowMs = WorstFractionMean(sorted, kLowPercentileFraction); + out.onePercentLowFps = MsToFps(out.onePercentLowMs); + + FillPacing(frameTimesMs, out); + FillPercentileCurve(sorted, out); + return out; +} + +namespace +{ + bool IsValid(const RepeatSamples& repeat) + { + return repeat.invalid == InvalidReason::None && !repeat.frames.empty(); + } + + void AccumulatePassMs(const SegmentSamples& segment, SegmentStats& out) + { + double cpuSum[kMaxPasses] = {}; + double gpuSum[kMaxPasses] = {}; + int frames = 0; + + for (const RepeatSamples& repeat : segment.repeats) + { + if (!IsValid(repeat)) continue; + for (const FrameSample& frame : repeat.frames) + { + for (int p = 0; p < kMaxPasses; p++) + { + cpuSum[p] += frame.cpuMs[p]; + gpuSum[p] += frame.gpuMs[p]; + } + } + frames += (int)repeat.frames.size(); + } + + if (frames == 0) return; + for (int p = 0; p < kMaxPasses; p++) + { + out.passCpuMs[p] = (float)(cpuSum[p] / frames); + out.passGpuMs[p] = (float)(gpuSum[p] / frames); + } + } + + void AccumulateCounters(const SegmentSamples& segment, SegmentStats& out) + { + int frames = 0; + for (const RepeatSamples& repeat : segment.repeats) + { + if (!IsValid(repeat)) continue; + for (int c = 0; c < kMaxCounters; c++) + { + out.counterPerFrame[c] += (double)repeat.counters.total[c]; + for (int p = 0; p < kMaxPasses; p++) + out.passCounterPerFrame[p][c] += (double)repeat.counters.perPass[p][c]; + } + frames += (int)repeat.frames.size(); + } + + if (frames == 0) return; + for (int c = 0; c < kMaxCounters; c++) + { + out.counterPerFrame[c] /= frames; + for (int p = 0; p < kMaxPasses; p++) + out.passCounterPerFrame[p][c] /= frames; + } + } + + void FillAttribution(SegmentStats& out, const std::vector& passIsNested) + { + for (int p = 0; p < kMaxPasses; p++) + { + const bool nested = ((size_t)p < passIsNested.size()) && passIsNested[p]; + if (!nested) out.attributedCpuMs += out.passCpuMs[p]; + } + + out.unattributedMs = out.frame.meanMs - out.attributedCpuMs; + if (out.frame.meanMs > 0.0f) + out.unattributedPercent = 100.0f * out.unattributedMs / out.frame.meanMs; + } + + void FillRepeatSpread(SegmentStats& out) + { + if (out.repeatMedianMs.size() < 2) return; + + const auto range = std::minmax_element(out.repeatMedianMs.begin(), out.repeatMedianMs.end()); + out.repeatSpreadMs = *range.second - *range.first; + + const float meanOfMedians = MeanOf(out.repeatMedianMs); + if (meanOfMedians > 0.0f) + out.repeatSpreadPercent = 100.0f * out.repeatSpreadMs / meanOfMedians; + } +} + +SegmentStats Summarize(const SegmentSamples& segment, const std::vector& passIsNested) +{ + SegmentStats out; + out.name = segment.name; + + std::vector pooledFrameTimes; + for (const RepeatSamples& repeat : segment.repeats) + { + if (!IsValid(repeat)) + { + out.invalidRepeats++; + continue; + } + + out.validRepeats++; + std::vector repeatFrameTimes; + repeatFrameTimes.reserve(repeat.frames.size()); + for (const FrameSample& frame : repeat.frames) repeatFrameTimes.push_back(frame.frameMs); + + out.repeatMedianMs.push_back(Summarize(repeatFrameTimes).medianMs); + pooledFrameTimes.insert(pooledFrameTimes.end(), repeatFrameTimes.begin(), repeatFrameTimes.end()); + } + + out.measuredFrames = (int)pooledFrameTimes.size(); + out.frame = Summarize(pooledFrameTimes); + + AccumulatePassMs(segment, out); + AccumulateCounters(segment, out); + FillAttribution(out, passIsNested); + FillRepeatSpread(out); + return out; +} + +std::vector SummarizeRun(const RunData& run) +{ + std::vector stats; + stats.reserve(run.segments.size()); + for (const SegmentSamples& segment : run.segments) + stats.push_back(Summarize(segment, run.passIsNested)); + return stats; +} + +int FindSegment(const std::vector& stats, const std::string& name) +{ + for (size_t i = 0; i < stats.size(); i++) + if (stats[i].name == name) return (int)i; + return -1; +} +} diff --git a/src/source/Core/Utilities/Benchmark/BenchStats.h b/src/source/Core/Utilities/Benchmark/BenchStats.h new file mode 100644 index 0000000000..5a1767c79a --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchStats.h @@ -0,0 +1,91 @@ +#pragma once + +#include +#include + +#include "BenchTypes.h" + +// Aggregation math for a benchmark run. Pure: no project dependencies, linkable from tests. +// +// The numbers here are deliberately more than a mean. A change can improve the average frame +// time and make pacing worse, and a mean alone will happily call that a win -- so the summary +// carries the distribution (percentile curve), the tail (1% low), and the pacing metrics +// side by side. See docs/benchmark.md. + +namespace Core::Benchmark::Stats +{ + // A frame counts as "slow" at this multiple of the segment's own median frame time. Relative + // rather than an absolute ms threshold so it means the same thing on a 30 FPS laptop and a + // 240 FPS desktop. + inline constexpr float kSlowFrameMedianMultiple = 2.0f; + + // Share of the frames that make up the "1% low" figure. + inline constexpr float kLowPercentileFraction = 0.01f; + + struct TimingStats + { + int frameCount = 0; + float meanMs = 0.0f; + float medianMs = 0.0f; + float p95Ms = 0.0f; + float p99Ms = 0.0f; + float minMs = 0.0f; + float maxMs = 0.0f; + float stdDevMs = 0.0f; + float meanFps = 0.0f; + // Mean of the worst 1% of frames -- the figure the $details overlay calls "1% Low". + float onePercentLowMs = 0.0f; + float onePercentLowFps = 0.0f; + // Frame pacing: mean absolute difference between consecutive frames. Low mean frame time + // with a high value here is a stuttering frame stream, not a smooth fast one. + float pacingMeanAbsDeltaMs = 0.0f; + int slowFrameCount = 0; + int longestSlowFrameRun = 0; + // Frame times at evenly spaced percentiles, ascending. kPercentileCurvePoints entries, + // or empty when there were no frames. + std::vector percentileCurveMs; + }; + + TimingStats Summarize(const std::vector& frameTimesMs); + + struct SegmentStats + { + std::string name; + int validRepeats = 0; + int invalidRepeats = 0; + int measuredFrames = 0; + + // Pooled over every valid repeat's frames. + TimingStats frame; + + // One median per valid repeat. The spread between them is the noise band a delta has to + // clear before it means anything -- a run-to-run difference smaller than this is not a + // result, which is exactly the trap GLP-29 fell into. + std::vector repeatMedianMs; + float repeatSpreadMs = 0.0f; + float repeatSpreadPercent = 0.0f; + + // Per measured frame, averaged over valid repeats. + float passCpuMs[kMaxPasses] = {}; + float passGpuMs[kMaxPasses] = {}; + double counterPerFrame[kMaxCounters] = {}; + double passCounterPerFrame[kMaxPasses][kMaxCounters] = {}; + + // Attribution check: pass CPU ms summed over the non-nested passes, against the measured + // frame time. A large remainder means real work is running outside every FRAME_PROFILE + // scope -- the blind spot GLP-24 found after it had already invalidated a phase of + // measurements. + float attributedCpuMs = 0.0f; + float unattributedMs = 0.0f; + float unattributedPercent = 0.0f; + }; + + // passIsNested marks passes contained in another pass, which must not be summed into the + // attribution total. A short or empty vector is treated as "nothing is nested". + SegmentStats Summarize(const SegmentSamples& segment, const std::vector& passIsNested); + + std::vector SummarizeRun(const RunData& run); + + // Index of the segment stats with the given name, or -1. + int FindSegment(const std::vector& stats, const std::string& name); +} diff --git a/src/source/Core/Utilities/Benchmark/BenchTypes.cpp b/src/source/Core/Utilities/Benchmark/BenchTypes.cpp new file mode 100644 index 0000000000..6ecb8db90d --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchTypes.cpp @@ -0,0 +1,59 @@ +#include "BenchTypes.h" + +#include + +namespace Core::Benchmark +{ + const char* ToString(InvalidReason reason) + { + switch (reason) + { + case InvalidReason::None: return "ok"; + case InvalidReason::Stalled: return "stalled"; + case InvalidReason::Aborted: return "aborted"; + case InvalidReason::TooFewFrames: return "too-few-frames"; + } + return "unknown"; + } + + namespace + { + // FNV-1a, 64-bit. Not a security hash -- it only has to change when the manifest changes. + constexpr uint64_t kFnvOffsetBasis = 1469598103934665603ull; + constexpr uint64_t kFnvPrime = 1099511628211ull; + + uint64_t Fnv1a(const std::string& text) + { + uint64_t hash = kFnvOffsetBasis; + for (char c : text) + { + hash ^= (uint64_t)(unsigned char)c; + hash *= kFnvPrime; + } + return hash; + } + } + + std::string ComputeManifestHash(const RunManifest& manifest) + { + std::string canonical; + canonical += std::to_string(manifest.repeats) + ';'; + canonical += std::to_string(manifest.warmupFrames) + ';'; + canonical += std::to_string(manifest.measureFrames) + ';'; + for (const std::string& name : manifest.segmentNames) canonical += name + ','; + + char buffer[24]; + snprintf(buffer, sizeof(buffer), "%016llx", (unsigned long long)Fnv1a(canonical)); + return buffer; + } + + const char* ToString(RunStatus status) + { + switch (status) + { + case RunStatus::Completed: return "completed"; + case RunStatus::Aborted: return "aborted"; + } + return "unknown"; + } +} diff --git a/src/source/Core/Utilities/Benchmark/BenchTypes.h b/src/source/Core/Utilities/Benchmark/BenchTypes.h new file mode 100644 index 0000000000..41ef086399 --- /dev/null +++ b/src/source/Core/Utilities/Benchmark/BenchTypes.h @@ -0,0 +1,165 @@ +#pragma once + +#include +#include +#include + +// Data model for a benchmark run, shared by the recorder (which fills it in) and the +// stats/findings/report layers (which read it). +// +// Deliberately free of any project dependency -- no FrameProfiler.h, no GL, no SDL. The +// recorder copies FrameProfiler's per-frame values into these plain structs, which keeps +// everything downstream of the copy linkable from a unit test. See docs/benchmark.md. + +namespace Core::Benchmark +{ + // Upper bound on the pass/counter dimensions copied out of FrameProfiler. Static-asserted + // against the real enum sizes in BenchRecorder.cpp, which is the only file that knows both. + inline constexpr int kMaxPasses = 32; + inline constexpr int kMaxCounters = 32; + + // Name of the segment every run starts and ends with, so drift across the run is measurable + // rather than assumed away -- a GPU is not the same GPU at minute 8 as at minute 0. Defined + // here rather than in the catalog because the exports and the findings both key off it. + inline constexpr const char* kBaselineSegmentName = "scene.full"; + + // Suffix on the result name of the closing re-measurement of the baseline, so it is a + // distinct row in the exports while pointing at the same segment definition. + inline constexpr const char* kDriftControlSuffix = "@end"; + + // Number of points the frame-time distribution is decimated to. Enough to plot a percentile + // curve (where stutter shows as a tail hockey-stick) without storing every frame twice. + inline constexpr int kPercentileCurvePoints = 101; + + // One measured frame. Warmup frames are counted but never stored. + struct FrameSample + { + float frameMs = 0.0f; + float cpuMs[kMaxPasses] = {}; + float gpuMs[kMaxPasses] = {}; + }; + + // GL counters summed over a repeat's measured frames. Counters are near-deterministic for a + // fixed workload, so per-segment sums carry the same information as per-frame values at a + // fraction of the width -- this is why frames.csv has no counter columns. + struct CounterTotals + { + uint64_t perPass[kMaxPasses][kMaxCounters] = {}; + uint64_t total[kMaxCounters] = {}; + }; + + // Why a repeat's numbers must not be trusted. Anything other than None makes the repeat + // invalid: it is still exported (so the reason is visible) but excluded from aggregation. + enum class InvalidReason + { + None, + Stalled, // a frame far longer than the run's own scale: alt-tab, minimise, or a + // load hitch. The OS was not running the client normally, so the repeat + // measures the interruption rather than the scene. + Aborted, // the run was stopped before this repeat finished + TooFewFrames, // ended with fewer measured frames than the manifest asked for + }; + + const char* ToString(InvalidReason reason); + + struct RepeatSamples + { + int repeatIndex = 0; + int warmupFramesDiscarded = 0; + std::vector frames; + CounterTotals counters; + InvalidReason invalid = InvalidReason::None; + }; + + struct SegmentSamples + { + std::string name; + std::string description; + std::string tags; // space-separated, as exported + std::vector repeats; + }; + + // What the run was asked to do. Hashed into RunData::manifestHash so two runs can be checked + // for comparability before their numbers are ever put side by side. + struct RunManifest + { + std::string label; // free-text, from `$bench label` + std::vector segmentNames; // in execution order + int repeats = 0; + int warmupFrames = 0; + int measureFrames = 0; + std::string pattern; // the selection the user typed + }; + + // Everything about the machine and build that makes numbers comparable (or not). Captured + // once at run start. Fields that could not be resolved stay empty rather than guessing. + struct EnvironmentInfo + { + std::string timestampUtc; + std::string osVersion; + std::string cpu; + int cpuThreads = 0; + uint64_t systemMemoryMB = 0; + + std::string glVendor; + std::string glRenderer; + std::string glVersion; + std::string glslVersion; + int contextMajor = 0; // the version the GLP-08 descending chain actually got + int contextMinor = 0; + bool capsBufferStorage = false; + bool capsVertexAttribBinding = false; + bool capsProgramBinary = false; + bool capsTimerQuery = false; + int capsUboOffsetAlignment = 0; + int capsMaxUniformBlockSize = 0; + + std::string buildConfig; // Debug / Release + std::string buildEditor; // Editor / NoEditor + std::string buildCompiler; + std::string buildArch; + std::string buildTimestamp; + std::string gitDescribe; // empty when not baked in + bool gitDirty = false; + + int windowWidth = 0; + int windowHeight = 0; + bool vsyncRequested = false; + bool vsyncEffective = false; + double targetFps = 0.0; + std::string mapName; + }; + + enum class RunStatus + { + Completed, + Aborted, + }; + + const char* ToString(RunStatus status); + + // Short stable fingerprint of everything that decides whether two runs measured the same + // thing. Two runs with different hashes are not comparable, however similar their tables + // look -- segment order alone changes the numbers, because a GPU is warmer at segment 9 + // than at segment 1. + std::string ComputeManifestHash(const RunManifest& manifest); + + // A run's whole result: what was asked for, what machine ran it, and every sample taken. + struct RunData + { + std::string runId; // directory name, e.g. 20260818_142233_glp09 + std::string manifestHash; + RunManifest manifest; + EnvironmentInfo environment; + std::vector segments; + std::vector passNames; + // True for a pass whose time is already contained in another pass (Skinning inside + // Objects/Characters/Items, CharWait inside Characters). Summing those into a frame total + // would double-count them, so the attribution check in BenchStats skips them. Filled by + // the recorder, which is the only place that knows FrameProfiler's nesting semantics. + std::vector passIsNested; + std::vector counterNames; + std::vector events; // warnings raised during the run, in order + RunStatus status = RunStatus::Completed; + }; +} diff --git a/src/source/Core/Utilities/BuildInfo.h b/src/source/Core/Utilities/BuildInfo.h new file mode 100644 index 0000000000..2f52c9a490 --- /dev/null +++ b/src/source/Core/Utilities/BuildInfo.h @@ -0,0 +1,62 @@ +#pragma once + +// Compile-time identity of the running binary: which configuration, compiler and architecture +// produced it, and when. Read by the $details overlay and by the benchmark exports, which both +// need to state what was measured -- a frame time without a build configuration next to it is +// not a result anybody can act on. +// +// The git fields are optional: the build system does not compute them, so a build script that +// wants them in the exports defines MU_GIT_DESCRIBE (and MU_GIT_DIRTY when the tree was not +// clean). Absent, the exports say "unknown" rather than inventing a commit. + +namespace Core::Build +{ + inline constexpr const char* kConfiguration = +#if defined(_DEBUG) || defined(DEBUG) + "Debug"; +#else + "Release"; +#endif + + inline constexpr const char* kEditor = +#ifdef _EDITOR + "Editor"; +#else + "NoEditor"; +#endif + + inline constexpr const char* kCompiler = +#if defined(__MINGW32__) || defined(__MINGW64__) + "MinGW"; +#elif defined(__clang__) + "Clang"; +#elif defined(_MSC_VER) + "MSVC"; +#elif defined(__GNUC__) + "GCC"; +#else + "Unknown"; +#endif + + inline constexpr const char* kArchitecture = +#if defined(_WIN64) || defined(__x86_64__) || defined(__aarch64__) + "x64"; +#else + "x86"; +#endif + + inline constexpr const char* kDate = __DATE__; + inline constexpr const char* kTime = __TIME__; + +#ifdef MU_GIT_DESCRIBE + inline constexpr const char* kGitDescribe = MU_GIT_DESCRIBE; +#else + inline constexpr const char* kGitDescribe = ""; +#endif + +#ifdef MU_GIT_DIRTY + inline constexpr bool kGitDirty = true; +#else + inline constexpr bool kGitDirty = false; +#endif +} diff --git a/src/source/Core/Utilities/FrameProfiler.h b/src/source/Core/Utilities/FrameProfiler.h index 79336ed5a5..ad2bb4b333 100644 --- a/src/source/Core/Utilities/FrameProfiler.h +++ b/src/source/Core/Utilities/FrameProfiler.h @@ -112,6 +112,13 @@ namespace FrameProfiler Count_ }; + inline constexpr const char* kCounterNames[(int)Counter::Count_] = { + "GLCalls", "DrawCalls", "BufferUpdates", "BufferOrphans", "ProgramBinds", "TextureBinds", + "UniformWrites", "UboSkips", + "IRDraws", "IRVertices", "IRBreakTexture", "IRBreakBlend", "IRBreakDepth", "IRBreakProgram", + "IRBreakUniform", "IRBreakMatrix", "IRBreakDraw", "IRBreakOther" + }; + // Per-[Pass][Counter] breakdown -- what tells you "terrain is 18,000 of the 23,000 GL // calls" in one reading. Attributed automatically via CurrentPass(), so hook sites never // need to know which pass they're running under. diff --git a/src/source/Core/Utilities/Log/muConsoleDebug.cpp b/src/source/Core/Utilities/Log/muConsoleDebug.cpp index 7e6ec9de3b..1bf5973d86 100644 --- a/src/source/Core/Utilities/Log/muConsoleDebug.cpp +++ b/src/source/Core/Utilities/Log/muConsoleDebug.cpp @@ -19,6 +19,7 @@ #include "Scenes/SceneCore.h" #include "Scenes/SceneManager.h" #include "Scenes/MainScene.h" +#include "Core/Utilities/Benchmark/BenchConsoleCommand.h" #include "UI/NewUI/NewUISystem.h" #ifdef _EDITOR @@ -85,6 +86,11 @@ void CmuConsoleDebug::UpdateMainScene() bool CmuConsoleDebug::CheckCommand(const std::wstring& strCommand) { + // Handled in its own translation unit -- the benchmark's command vocabulary is large enough + // that growing it inside this chain would bury everything else in here. + if (Core::Benchmark::Console::HandleCommand(strCommand)) + return true; + if (strCommand.compare(L"$fpscounter on") == 0) { SetShowFpsCounter(true); diff --git a/src/source/Render/RHI/RHI.cpp b/src/source/Render/RHI/RHI.cpp index e28a4aa9e6..0b755e4734 100644 --- a/src/source/Render/RHI/RHI.cpp +++ b/src/source/Render/RHI/RHI.cpp @@ -8,6 +8,7 @@ namespace RHI_GL_Impl { const RHI::Caps& GetCaps(); + const RHI::DriverInfo& GetDriverInfo(); bool Init(void* nativeWindowHandle, int width, int height); void Shutdown(); @@ -56,6 +57,11 @@ const Caps& GetCaps() return RHI_GL_Impl::GetCaps(); } +const DriverInfo& GetDriverInfo() +{ + return RHI_GL_Impl::GetDriverInfo(); +} + bool Init(void* nativeWindowHandle, int width, int height) { return RHI_GL_Impl::Init(nativeWindowHandle, width, height); diff --git a/src/source/Render/RHI/RHI.h b/src/source/Render/RHI/RHI.h index 4d43cc62cb..d63727b6f7 100644 --- a/src/source/Render/RHI/RHI.h +++ b/src/source/Render/RHI/RHI.h @@ -12,6 +12,7 @@ #include #include +#include namespace RHI { @@ -46,6 +47,20 @@ struct Caps { }; const Caps& GetCaps(); +// ---- Driver identification ---- +// The strings the driver reports about itself, captured once alongside the capability probe. +// Diagnostic only -- nothing branches on them -- but they are what makes a performance number +// attributable to a machine, so the benchmark exports and any bug report can name the GL +// implementation that produced it instead of "it was slow on my laptop". Lives here rather than +// at the call site because glGetString is a GL entry point, and those belong behind the RHI. +struct DriverInfo { + std::string vendor; + std::string renderer; + std::string version; + std::string shadingLanguageVersion; +}; +const DriverInfo& GetDriverInfo(); + // ---- Device/frame (implemented in RHI_GL) ---- bool Init(void* nativeWindowHandle, int width, int height); void Shutdown(); diff --git a/src/source/Render/RHI/RHI_GL.cpp b/src/source/Render/RHI/RHI_GL.cpp index f42b1731c2..0566263222 100644 --- a/src/source/Render/RHI/RHI_GL.cpp +++ b/src/source/Render/RHI/RHI_GL.cpp @@ -31,6 +31,7 @@ namespace { // ---- GLP-08: capability probe ---- Caps g_Caps; + DriverInfo g_DriverInfo; #ifndef APIENTRY #define APIENTRY @@ -73,11 +74,28 @@ namespace { return versionOrExtPresent && fnsResolved; } + // glGetString returns null on a lost or not-yet-current context; an empty field says + // "the driver did not tell us" rather than crashing a diagnostic path. + std::string GLString(GLenum name) + { + const GLubyte* value = glGetString(name); + return value ? std::string((const char*)value) : std::string(); + } + + void ProbeDriverInfo() + { + g_DriverInfo.vendor = GLString(GL_VENDOR); + g_DriverInfo.renderer = GLString(GL_RENDERER); + g_DriverInfo.version = GLString(GL_VERSION); + g_DriverInfo.shadingLanguageVersion = GLString(GL_SHADING_LANGUAGE_VERSION); + } + void ProbeCaps() { g_Caps = Caps{}; + ProbeDriverInfo(); - const char* versionStr = (const char*)glGetString(GL_VERSION); + const char* versionStr = g_DriverInfo.version.empty() ? nullptr : g_DriverInfo.version.c_str(); int major = 0, minor = 0; if (versionStr) sscanf(versionStr, "%d.%d", &major, &minor); g_Caps.glMajor = major; @@ -139,6 +157,11 @@ const Caps& GetCaps() return g_Caps; } +const DriverInfo& GetDriverInfo() +{ + return g_DriverInfo; +} + bool Init(void* /*nativeWindowHandle*/, int width, int height) { // nativeWindowHandle is unused on the GL backend -- the SDL-owned GL context diff --git a/src/source/Scenes/MainScene.cpp b/src/source/Scenes/MainScene.cpp index 747468f4c5..c59df2529e 100644 --- a/src/source/Scenes/MainScene.cpp +++ b/src/source/Scenes/MainScene.cpp @@ -397,6 +397,11 @@ void SetDisableEffects(bool disabled) g_bDisableEffectsDebug = disabled; } +bool IsEffectsDisabledDebug() +{ + return g_bDisableEffectsDebug; +} + // DXP-23 diagnostic toggles, finer-grained bisection -- see MainScene.h doc comments. static bool g_bDisableSpritesDebug = false; static bool g_bDisableParticlesDebug = false; diff --git a/src/source/Scenes/MainScene.h b/src/source/Scenes/MainScene.h index 52db3e7f13..890394a1c1 100644 --- a/src/source/Scenes/MainScene.h +++ b/src/source/Scenes/MainScene.h @@ -14,6 +14,7 @@ bool RenderMainScene(); // via $effects on/off (muConsoleDebug.cpp) -- not gated behind _EDITOR since the report came from a // Release NoEditor build. void SetDisableEffects(bool disabled); +bool IsEffectsDisabledDebug(); // DXP-23 diagnostic, finer-grained bisection: `$effects off` (above) confirmed effect rendering is // the dominant GPU cost during a multi-caster fight, but not WHICH effect system inside it -- these diff --git a/src/source/Scenes/SceneManager.cpp b/src/source/Scenes/SceneManager.cpp index e0db17760f..6829234051 100644 --- a/src/source/Scenes/SceneManager.cpp +++ b/src/source/Scenes/SceneManager.cpp @@ -10,6 +10,8 @@ #include "SceneManager.h" #include "Core/Utilities/FrameProfiler.h" #include "Core/Utilities/PlatformInfo.h" +#include "Core/Utilities/BuildInfo.h" +#include "Core/Utilities/Benchmark/BenchRecorder.h" #include "Render/Core/ImmediateRenderer.h" #include "Render/Shaders/PassthroughShader.h" #include "Render/Core/RenderConfig.h" @@ -94,11 +96,19 @@ void SetShowFpsCounter(bool enabled) } // GLP-01: independent of the two flags above -- $glstats can be shown alongside $details or -// $fpscounter, not just standalone. Also the single switch that gates FrameProfiler's counter/ -// GPU-timer increments themselves (FrameProfiler::g_CountersEnabled), so turning the overlay -// off also stops paying for the instrumentation. +// $fpscounter, not just standalone. Also switches FrameProfiler's counter/GPU-timer increments +// themselves on (FrameProfiler::g_CountersEnabled), so turning the overlay off also stops paying +// for the instrumentation. +// +// The overlay keeps its own flag because the counters have a second consumer: a benchmark run +// needs them on whether or not anyone asked to see them, and it must not switch a large text +// overlay on behind the user's back -- that overlay costs hundreds of draw calls per frame, in +// the middle of the measurement. +static bool g_bShowGLStatsOverlay = false; + void SetShowGLStats(bool enabled) { + g_bShowGLStatsOverlay = enabled; FrameProfiler::g_CountersEnabled = enabled; } @@ -115,6 +125,7 @@ static constexpr float THRESHOLD_60FPS_MS = 16.67f; // 60 FPS threshold static constexpr float THRESHOLD_40FPS_MS = 25.0f; // 40 FPS threshold static constexpr float DEBUG_TEXT_X = 10.0f; // debug overlay X position static constexpr int DEBUG_TEXT_Y_START = 26; // debug overlay Y start +static constexpr int BENCH_STATUS_TEXT_Y = 14; // benchmark progress line, above the overlays static constexpr int DEBUG_TEXT_LINE_HEIGHT = 10; // line spacing static constexpr float DEBUG_GRAPH_WIDTH = 200.0f; // frame graph width static constexpr float DEBUG_GRAPH_HEIGHT = 40.0f; // frame graph height @@ -542,38 +553,9 @@ static void RenderDebugInfo() // Compile-time build info: configuration, feature flags, compiler, arch, // and the binary's build timestamp. Useful for verifying which build is // actually running without having to check executable metadata. - constexpr const char* kBuildType = -#if defined(_DEBUG) || defined(DEBUG) - "Debug"; -#else - "Release"; -#endif - constexpr const char* kEditor = -#ifdef _EDITOR - "Editor"; -#else - "NoEditor"; -#endif - constexpr const char* kCompiler = -#if defined(__MINGW32__) || defined(__MINGW64__) - "MinGW"; -#elif defined(__clang__) - "Clang"; -#elif defined(_MSC_VER) - "MSVC"; -#elif defined(__GNUC__) - "GCC"; -#else - "Unknown"; -#endif - constexpr const char* kArch = -#if defined(_WIN64) || defined(__x86_64__) || defined(__aarch64__) - "x64"; -#else - "x86"; -#endif mu_swprintf(szLine, L"Build: %hs %hs %hs %hs %hs %hs", - kBuildType, kEditor, kCompiler, kArch, __DATE__, __TIME__); + Core::Build::kConfiguration, Core::Build::kEditor, Core::Build::kCompiler, + Core::Build::kArchitecture, Core::Build::kDate, Core::Build::kTime); g_pRenderText->RenderText((int)DEBUG_TEXT_X, y, szLine); y += DEBUG_TEXT_LINE_HEIGHT; // Runtime OS name and version (compile-time arch above doesn't capture which @@ -657,7 +639,7 @@ static void RenderDebugInfo() */ static void RenderGLStats() { - if (!FrameProfiler::g_CountersEnabled) + if (!g_bShowGLStatsOverlay || !FrameProfiler::g_CountersEnabled) return; BeginBitmap(); @@ -771,6 +753,31 @@ static void RenderGLStats() EndBitmap(); } +/** + * @brief Renders the one-line benchmark progress indicator while a $bench run is in flight. + * + * Always on during a run rather than behind its own toggle: a run reconfigures the scene and + * takes minutes, and a client that silently disables effects with no visible reason is a bug + * report waiting to happen. + */ +static void RenderBenchmarkStatus() +{ + const Core::Benchmark::Recorder& recorder = Core::Benchmark::Recorder::Instance(); + if (!recorder.IsRunning()) + return; + + const std::string status = recorder.StatusText(); + const std::wstring line(status.begin(), status.end()); + + BeginBitmap(); + g_pRenderText->SetFont(g_hFontBold); + g_pRenderText->SetBgColor(0, 0, 0, 160); + g_pRenderText->SetTextColor(255, 220, 120, 255); + g_pRenderText->RenderText((int)DEBUG_TEXT_X, BENCH_STATUS_TEXT_Y, line.c_str()); + g_pRenderText->SetFont(g_hFont); + EndBitmap(); +} + /** * @brief Renders a simple FPS counter overlay showing only current FPS. */ @@ -1203,8 +1210,14 @@ void MainScene(HDC hDC) RenderDebugInfo(); RenderGLStats(); RenderFpsCounter(); + RenderBenchmarkStatus(); UI::Reconnect::RenderDialog(); + // Reads this frame's accumulators, so it has to run before the reset below and after + // every other overlay -- the benchmark's own numbers include the cost of drawing + // them, tagged Overlay, exactly as the $glstats reading does. + Core::Benchmark::Recorder::Instance().Tick(); + // Once per frame, unconditionally -- see the comment at the end of RenderDebugInfo() // for why this can't live inside either overlay function. AdvanceGpuTimers() must run // after this frame's Terrain/Objects/Characters/Items/Effects/UI passes have all diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index e72b6f585c..eef674452b 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -50,6 +50,8 @@ function(mu_add_test) doctest_discover_tests(${MAT_NAME}) endfunction() +add_subdirectory(benchmark) + add_subdirectory(text) add_subdirectory(effects) diff --git a/tests/benchmark/CMakeLists.txt b/tests/benchmark/CMakeLists.txt new file mode 100644 index 0000000000..ec4ec7eab4 --- /dev/null +++ b/tests/benchmark/CMakeLists.txt @@ -0,0 +1,24 @@ +mu_add_test( + NAME test_bench_stats + SOURCES + test_bench_stats.cpp + ${CMAKE_SOURCE_DIR}/src/source/Core/Utilities/Benchmark/BenchStats.cpp + ${CMAKE_SOURCE_DIR}/src/source/Core/Utilities/Benchmark/BenchTypes.cpp +) + +mu_add_test( + NAME test_bench_segment + SOURCES + test_bench_segment.cpp + ${CMAKE_SOURCE_DIR}/src/source/Core/Utilities/Benchmark/BenchSegment.cpp +) + +mu_add_test( + NAME test_bench_report + SOURCES + test_bench_report.cpp + ${CMAKE_SOURCE_DIR}/src/source/Core/Utilities/Benchmark/BenchFindings.cpp + ${CMAKE_SOURCE_DIR}/src/source/Core/Utilities/Benchmark/BenchReport.cpp + ${CMAKE_SOURCE_DIR}/src/source/Core/Utilities/Benchmark/BenchStats.cpp + ${CMAKE_SOURCE_DIR}/src/source/Core/Utilities/Benchmark/BenchTypes.cpp +) diff --git a/tests/benchmark/test_bench_report.cpp b/tests/benchmark/test_bench_report.cpp new file mode 100644 index 0000000000..dc7591899f --- /dev/null +++ b/tests/benchmark/test_bench_report.cpp @@ -0,0 +1,304 @@ +#include "doctest.h" + +#include "Core/Utilities/Benchmark/BenchFindings.h" +#include "Core/Utilities/Benchmark/BenchReport.h" +#include "Core/Utilities/Benchmark/BenchStats.h" + +#include +#include + +using namespace Core::Benchmark; + +namespace +{ + int CountOccurrences(const std::string& haystack, const std::string& needle) + { + int count = 0; + for (size_t at = haystack.find(needle); at != std::string::npos; at = haystack.find(needle, at + needle.size())) + count++; + return count; + } + + bool HasRule(const std::vector& findings, const std::string& rule) + { + for (const Findings::Finding& finding : findings) + if (finding.rule == rule) return true; + return false; + } + + RepeatSamples MakeRepeat(int index, int frameCount, float frameMs) + { + RepeatSamples repeat; + repeat.repeatIndex = index; + for (int i = 0; i < frameCount; i++) + { + FrameSample sample; + sample.frameMs = frameMs; + sample.cpuMs[0] = frameMs * 0.5f; // Terrain + sample.gpuMs[0] = frameMs * 0.25f; + repeat.frames.push_back(sample); + } + repeat.counters.total[0] = (uint64_t)(100 * frameCount); + repeat.counters.perPass[0][0] = (uint64_t)(60 * frameCount); + return repeat; + } + + // A minimal but complete run: two segments, two repeats each, one pass carrying half the + // frame so the attribution remainder is a known 50%. + RunData MakeRun() + { + RunData run; + run.runId = "20260818_142233_test"; + run.manifest.label = "test"; + run.manifest.pattern = "*"; + run.manifest.repeats = 2; + run.manifest.warmupFrames = 30; + run.manifest.measureFrames = 10; + run.manifest.segmentNames = { "scene.full", "fx.particles.off" }; + run.manifestHash = ComputeManifestHash(run.manifest); + run.passNames = { "Terrain", "Skinning", "Present" }; + run.passIsNested = { false, true, false }; + run.counterNames = { "DrawCalls", "IRDraws", "IRVertices" }; + run.environment.buildConfig = "Release"; + run.environment.glRenderer = "Test Renderer"; + + for (const std::string& name : run.manifest.segmentNames) + { + SegmentSamples segment; + segment.name = name; + segment.repeats.push_back(MakeRepeat(0, 10, 10.0f)); + segment.repeats.push_back(MakeRepeat(1, 10, 10.0f)); + run.segments.push_back(segment); + } + return run; + } +} + +TEST_CASE("manifest hash changes with the segment order but not with the label") +{ + RunManifest a; + a.segmentNames = { "scene.full", "fx.particles.off" }; + a.repeats = 3; + + RunManifest reordered = a; + reordered.segmentNames = { "fx.particles.off", "scene.full" }; + + RunManifest relabelled = a; + relabelled.label = "something else"; + + CHECK(ComputeManifestHash(a) != ComputeManifestHash(reordered)); + CHECK(ComputeManifestHash(a) == ComputeManifestHash(relabelled)); + CHECK(ComputeManifestHash(a).size() == 16); +} + +TEST_CASE("frames.csv has one header plus one row per measured frame") +{ + const RunData run = MakeRun(); + const std::string csv = Report::BuildFramesCsv(run); + + // 2 segments x 2 repeats x 10 frames, plus the header. + CHECK(CountOccurrences(csv, "\n") == 41); + CHECK(csv.rfind("segment,repeat,frame,frame_ms,cpu_Terrain", 0) == 0); + CHECK(csv.find("cpu_Present") != std::string::npos); + CHECK(csv.find("gpu_Terrain") != std::string::npos); + // Counters belong in passes.csv, never per frame. + CHECK(csv.find("DrawCalls") == std::string::npos); +} + +TEST_CASE("passes.csv carries one row per pass plus a TOTAL row, per repeat") +{ + const RunData run = MakeRun(); + const std::string csv = Report::BuildPassesCsv(run); + + // 2 segments x 2 repeats x (3 passes + 1 total), plus the header. + CHECK(CountOccurrences(csv, "\n") == 17); + CHECK(CountOccurrences(csv, ",TOTAL,") == 4); + CHECK(csv.find("DrawCalls") != std::string::npos); + // 100 draw calls per frame, summed over 10 frames and reported per frame again. + CHECK(csv.find(",TOTAL,10.00,0.00,100.0") != std::string::npos); +} + +TEST_CASE("the report renders every section and is byte-identical for identical input") +{ + const RunData run = MakeRun(); + const std::vector stats = Stats::SummarizeRun(run); + const std::vector findings = Findings::Evaluate(run, stats); + + const std::string first = Report::BuildReportMarkdown(run, stats, findings); + const std::string second = Report::BuildReportMarkdown(run, stats, findings); + CHECK(first == second); + + CHECK(first.find("# Benchmark run 20260818_142233_test") != std::string::npos); + CHECK(first.find("## Identity") != std::string::npos); + CHECK(first.find("## Build") != std::string::npos); + CHECK(first.find("## Machine") != std::string::npos); + CHECK(first.find("## Graphics") != std::string::npos); + CHECK(first.find("## Run configuration") != std::string::npos); + CHECK(first.find("## Segment summary") != std::string::npos); + CHECK(first.find("## Frame pacing") != std::string::npos); + CHECK(first.find("## Findings") != std::string::npos); + CHECK(first.find("## Pass breakdown") != std::string::npos); + CHECK(first.find("## Health") != std::string::npos); + CHECK(first.find("Test Renderer") != std::string::npos); +} + +TEST_CASE("an aborted, dirty-tree run says so at the top of the report") +{ + RunData run = MakeRun(); + run.status = RunStatus::Aborted; + run.environment.gitDirty = true; + + const std::vector stats = Stats::SummarizeRun(run); + const std::string markdown = Report::BuildReportMarkdown(run, stats, Findings::Evaluate(run, stats)); + + CHECK(markdown.find("**Aborted run.**") != std::string::npos); + CHECK(markdown.find("**Uncommitted changes.**") != std::string::npos); +} + +TEST_CASE("run.json is well-formed and carries the schema version") +{ + const RunData run = MakeRun(); + const std::vector stats = Stats::SummarizeRun(run); + const std::string json = Report::BuildRunJson(run, stats, Findings::Evaluate(run, stats)); + + CHECK(json.rfind("{\n", 0) == 0); + CHECK(json.find("\"schemaVersion\": 1") != std::string::npos); + CHECK(json.find("\"manifestHash\"") != std::string::npos); + CHECK(json.find("\"percentileCurveMs\"") != std::string::npos); + CHECK(CountOccurrences(json, "{") == CountOccurrences(json, "}")); + CHECK(CountOccurrences(json, "[") == CountOccurrences(json, "]")); +} + +TEST_CASE("strings that would break the exports are escaped, not passed through") +{ + RunData run = MakeRun(); + run.manifest.label = "quote\" and \\ backslash"; + run.environment.glRenderer = "line\nbreak"; + + const std::vector stats = Stats::SummarizeRun(run); + const std::string json = Report::BuildRunJson(run, stats, {}); + + CHECK(json.find("quote\\\" and \\\\ backslash") != std::string::npos); + CHECK(json.find("line\\nbreak") != std::string::npos); +} + +TEST_CASE("attribution gap fires when frame time sits outside every pass") +{ + const RunData run = MakeRun(); + const std::vector stats = Stats::SummarizeRun(run); + + // Terrain is 5 ms of a 10 ms frame and Skinning is nested, so half the frame is unattributed. + CHECK(stats.front().unattributedPercent == doctest::Approx(50.0f)); + CHECK(HasRule(Findings::Evaluate(run, stats), "attribution-gap")); +} + +TEST_CASE("drift fires when the closing baseline differs from the opening one") +{ + RunData run = MakeRun(); + SegmentSamples driftControl; + driftControl.name = std::string(kBaselineSegmentName) + kDriftControlSuffix; + driftControl.repeats.push_back(MakeRepeat(0, 10, 12.0f)); + run.segments.push_back(driftControl); + + const std::vector stats = Stats::SummarizeRun(run); + CHECK(HasRule(Findings::Evaluate(run, stats), "drift")); +} + +TEST_CASE("drift stays quiet when the closing baseline matches") +{ + RunData run = MakeRun(); + SegmentSamples driftControl; + driftControl.name = std::string(kBaselineSegmentName) + kDriftControlSuffix; + driftControl.repeats.push_back(MakeRepeat(0, 10, 10.0f)); + run.segments.push_back(driftControl); + + const std::vector stats = Stats::SummarizeRun(run); + CHECK_FALSE(HasRule(Findings::Evaluate(run, stats), "drift")); +} + +TEST_CASE("submission-bound fires on many IR draws carrying almost no vertices") +{ + RunData run = MakeRun(); + for (RepeatSamples& repeat : run.segments.front().repeats) + { + repeat.counters.perPass[0][1] = 3000 * 10; // IRDraws over 10 frames + repeat.counters.perPass[0][2] = 3000 * 10 * 6; + } + + const std::vector stats = Stats::SummarizeRun(run); + CHECK(HasRule(Findings::Evaluate(run, stats), "submission-bound")); +} + +TEST_CASE("submission-bound stays quiet when batches are actually merging") +{ + RunData run = MakeRun(); + for (RepeatSamples& repeat : run.segments.front().repeats) + { + repeat.counters.perPass[0][1] = 200 * 10; + repeat.counters.perPass[0][2] = 200 * 10 * 600; + } + + const std::vector stats = Stats::SummarizeRun(run); + CHECK_FALSE(HasRule(Findings::Evaluate(run, stats), "submission-bound")); +} + +TEST_CASE("a discarded repeat is reported rather than silently averaged in") +{ + RunData run = MakeRun(); + run.segments.front().repeats[1].invalid = InvalidReason::Stalled; + + const std::vector stats = Stats::SummarizeRun(run); + CHECK(HasRule(Findings::Evaluate(run, stats), "invalid-repeats")); +} + +TEST_CASE("a segment that changed no draw calls is flagged as inert") +{ + // The failure this catches: a segment runs, produces a plausible timing, and is read as + // "what it disables is cheap" when in fact it disabled nothing at all. + RunData run = MakeRun(); + const std::vector stats = Stats::SummarizeRun(run); + + // Both segments in the fixture submit the same 100 draws/frame. + const std::vector findings = Findings::Evaluate(run, stats); + CHECK(HasRule(findings, "segment-inert")); + for (const Findings::Finding& finding : findings) + if (finding.rule == "segment-inert") CHECK(finding.segment == "fx.particles.off"); +} + +TEST_CASE("a segment that really removed work is not flagged as inert") +{ + RunData run = MakeRun(); + for (RepeatSamples& repeat : run.segments[1].repeats) + repeat.counters.total[0] /= 2; // half the draw calls of the baseline + + const std::vector stats = Stats::SummarizeRun(run); + CHECK_FALSE(HasRule(Findings::Evaluate(run, stats), "segment-inert")); +} + +TEST_CASE("the drift control is never itself called inert") +{ + RunData run = MakeRun(); + SegmentSamples driftControl; + driftControl.name = std::string(kBaselineSegmentName) + kDriftControlSuffix; + driftControl.repeats.push_back(MakeRepeat(0, 10, 10.0f)); + run.segments.push_back(driftControl); + + // Other rules may legitimately have something to say about it; "inert" must not, since it is + // a deliberate re-measurement of the baseline and identical draw counts are the point. + const std::vector stats = Stats::SummarizeRun(run); + for (const Findings::Finding& finding : Findings::Evaluate(run, stats)) + if (finding.rule == "segment-inert") + CHECK(finding.segment != std::string(kBaselineSegmentName) + kDriftControlSuffix); +} + +TEST_CASE("vsync and a dirty tree are flagged for the run as a whole") +{ + RunData run = MakeRun(); + run.environment.vsyncEffective = true; + run.environment.gitDirty = true; + + const std::vector stats = Stats::SummarizeRun(run); + const std::vector findings = Findings::Evaluate(run, stats); + CHECK(HasRule(findings, "vsync-on")); + CHECK(HasRule(findings, "dirty-tree")); +} diff --git a/tests/benchmark/test_bench_segment.cpp b/tests/benchmark/test_bench_segment.cpp new file mode 100644 index 0000000000..0ab6d43a22 --- /dev/null +++ b/tests/benchmark/test_bench_segment.cpp @@ -0,0 +1,110 @@ +#include "doctest.h" + +#include "Core/Utilities/Benchmark/BenchSegment.h" + +using namespace Core::Benchmark; + +TEST_CASE("the catalog starts with the baseline segment") +{ + REQUIRE(!Segments::All().empty()); + CHECK(std::string(Segments::All().front().name) == kBaselineSegmentName); + CHECK(Segments::All().front().tags == TagBaseline); +} + +TEST_CASE("the baseline segment disables nothing") +{ + const Segment* baseline = Segments::Find(kBaselineSegmentName); + REQUIRE(baseline != nullptr); + CHECK_FALSE(baseline->config.disableEffects); + CHECK_FALSE(baseline->config.disableParticles); + CHECK_FALSE(baseline->config.disableJoints); +} + +TEST_CASE("every non-baseline segment actually disables something") +{ + // A segment whose config is all-false is a segment that measures the baseline twice. The + // first catalog shipped with fx.all.off in exactly that state for the two heaviest paths. + for (const Segment& segment : Segments::All()) + { + if (std::string(segment.name) == kBaselineSegmentName) continue; + + const SceneConfig& c = segment.config; + const bool disablesSomething = + c.disableEffects || c.disableAllEffectsOption || c.disableSprites || + c.disableParticles || c.disableSkillEffectModels || c.disableJoints || + c.disableBoids || c.disableWingShadow || c.disableWingExtraLayers; + + INFO("segment: " << segment.name); + CHECK(disablesSomething); + } +} + +TEST_CASE("fx.all.off closes every gate, not just the one named after it") +{ + // RenderSprites()/RenderParticles() early-return on the options-window switch and never look + // at SetDisableEffects; RenderJoints() looks at neither. A segment promising "everything off" + // has to set all three or it silently leaves the heaviest paths running -- which is what the + // first run of this benchmark reported: 162 particle draws per frame under fx.all.off. + const Segment* all = Segments::Find("fx.all.off"); + REQUIRE(all != nullptr); + CHECK(all->config.disableEffects); + CHECK(all->config.disableAllEffectsOption); + CHECK(all->config.disableJoints); +} + +TEST_CASE("every segment name is unique") +{ + const std::vector& all = Segments::All(); + for (size_t i = 0; i < all.size(); i++) + for (size_t j = i + 1; j < all.size(); j++) + CHECK(std::string(all[i].name) != all[j].name); +} + +TEST_CASE("glob matching") +{ + CHECK(Segments::MatchesPattern("fx.particles.off", "*")); + CHECK(Segments::MatchesPattern("fx.particles.off", "fx.*")); + CHECK(Segments::MatchesPattern("fx.particles.off", "*.off")); + CHECK(Segments::MatchesPattern("fx.particles.off", "fx.*.off")); + CHECK(Segments::MatchesPattern("fx.particles.off", "fx.particles.off")); + CHECK_FALSE(Segments::MatchesPattern("fx.particles.off", "fx.")); + CHECK_FALSE(Segments::MatchesPattern("fx.particles.off", "scene.*")); + CHECK_FALSE(Segments::MatchesPattern("scene.full", "fx.*")); +} + +TEST_CASE("glob backtracking does not stop at the first candidate match") +{ + CHECK(Segments::MatchesPattern("aaab", "*ab")); + CHECK(Segments::MatchesPattern("abcabc", "*abc")); + CHECK_FALSE(Segments::MatchesPattern("abcabd", "*abc")); +} + +TEST_CASE("selection by pattern returns catalog order") +{ + const std::vector selected = Segments::Select("fx.*"); + REQUIRE(!selected.empty()); + for (const Segment* segment : selected) + CHECK(std::string(segment->name).rfind("fx.", 0) == 0); + + CHECK(Segments::Select("*").size() == Segments::All().size()); + CHECK(Segments::Select("nothing.matches.this").empty()); +} + +TEST_CASE("selection by tag") +{ + // Both the surface's own segment and fx.all.off, which now genuinely disables particles too. + const std::vector particles = Segments::Select("#particles"); + REQUIRE(particles.size() == 2); + CHECK(std::string(particles.front()->name) == "fx.all.off"); + CHECK(std::string(particles.back()->name) == "fx.particles.off"); + + CHECK(Segments::Select("#effects").size() > 1); + CHECK(Segments::Select("#nosuchtag").empty()); +} + +TEST_CASE("tags render as space-separated lowercase names") +{ + CHECK(Segments::TagsToString(TagBaseline) == "baseline"); + CHECK(Segments::TagsToString(TagEffects | TagParticles) == "effects particles"); + CHECK(Segments::TagsToString(0) == ""); +} diff --git a/tests/benchmark/test_bench_stats.cpp b/tests/benchmark/test_bench_stats.cpp new file mode 100644 index 0000000000..9e8bd4fe26 --- /dev/null +++ b/tests/benchmark/test_bench_stats.cpp @@ -0,0 +1,157 @@ +#include "doctest.h" + +#include "Core/Utilities/Benchmark/BenchStats.h" + +#include + +using namespace Core::Benchmark; + +namespace +{ + // A repeat with the given frame times, and nothing else set. + RepeatSamples MakeRepeat(int index, const std::vector& frameTimesMs) + { + RepeatSamples repeat; + repeat.repeatIndex = index; + for (float ms : frameTimesMs) + { + FrameSample sample; + sample.frameMs = ms; + repeat.frames.push_back(sample); + } + return repeat; + } + + std::vector ConstantFrames(int count, float ms) + { + return std::vector((size_t)count, ms); + } +} + +TEST_CASE("empty input produces a zeroed summary, not a division by zero") +{ + const Stats::TimingStats stats = Stats::Summarize({}); + CHECK(stats.frameCount == 0); + CHECK(stats.meanMs == 0.0f); + CHECK(stats.meanFps == 0.0f); + CHECK(stats.percentileCurveMs.empty()); +} + +TEST_CASE("constant frame stream: every percentile is the same value") +{ + const Stats::TimingStats stats = Stats::Summarize(ConstantFrames(100, 10.0f)); + CHECK(stats.frameCount == 100); + CHECK(stats.meanMs == doctest::Approx(10.0f)); + CHECK(stats.medianMs == doctest::Approx(10.0f)); + CHECK(stats.p99Ms == doctest::Approx(10.0f)); + CHECK(stats.meanFps == doctest::Approx(100.0f)); + CHECK(stats.stdDevMs == doctest::Approx(0.0f)); + CHECK(stats.pacingMeanAbsDeltaMs == doctest::Approx(0.0f)); + CHECK(stats.slowFrameCount == 0); + CHECK((int)stats.percentileCurveMs.size() == kPercentileCurvePoints); +} + +TEST_CASE("1% low averages the worst frames, not the mean") +{ + // 99 fast frames and one very slow one: the mean barely moves, the 1% low collapses. + std::vector frames = ConstantFrames(99, 10.0f); + frames.push_back(100.0f); + + const Stats::TimingStats stats = Stats::Summarize(frames); + CHECK(stats.meanMs == doctest::Approx(10.9f)); + CHECK(stats.onePercentLowMs == doctest::Approx(100.0f)); + CHECK(stats.onePercentLowFps == doctest::Approx(10.0f)); + CHECK(stats.maxMs == doctest::Approx(100.0f)); +} + +TEST_CASE("pacing separates a smooth stream from an alternating one with the same mean") +{ + const Stats::TimingStats smooth = Stats::Summarize(ConstantFrames(100, 10.0f)); + + std::vector alternating; + for (int i = 0; i < 100; i++) alternating.push_back((i % 2 == 0) ? 5.0f : 15.0f); + const Stats::TimingStats jittery = Stats::Summarize(alternating); + + CHECK(smooth.meanMs == doctest::Approx(jittery.meanMs)); + CHECK(smooth.pacingMeanAbsDeltaMs == doctest::Approx(0.0f)); + CHECK(jittery.pacingMeanAbsDeltaMs == doctest::Approx(10.0f)); +} + +TEST_CASE("slow frames are counted relative to the median, and consecutive ones are tracked") +{ + std::vector frames = ConstantFrames(10, 10.0f); + frames.push_back(30.0f); + frames.push_back(30.0f); + frames.push_back(30.0f); + frames.push_back(10.0f); + + const Stats::TimingStats stats = Stats::Summarize(frames); + CHECK(stats.slowFrameCount == 3); + CHECK(stats.longestSlowFrameRun == 3); +} + +TEST_CASE("invalid repeats are excluded from the segment aggregate") +{ + SegmentSamples segment; + segment.name = "scene.full"; + segment.repeats.push_back(MakeRepeat(0, ConstantFrames(10, 10.0f))); + + RepeatSamples discarded = MakeRepeat(1, ConstantFrames(10, 100.0f)); + discarded.invalid = InvalidReason::Stalled; + segment.repeats.push_back(discarded); + + const Stats::SegmentStats stats = Stats::Summarize(segment, {}); + CHECK(stats.validRepeats == 1); + CHECK(stats.invalidRepeats == 1); + CHECK(stats.measuredFrames == 10); + CHECK(stats.frame.medianMs == doctest::Approx(10.0f)); +} + +TEST_CASE("repeat spread reports the gap between repeat medians") +{ + SegmentSamples segment; + segment.name = "scene.full"; + segment.repeats.push_back(MakeRepeat(0, ConstantFrames(10, 10.0f))); + segment.repeats.push_back(MakeRepeat(1, ConstantFrames(10, 12.0f))); + + const Stats::SegmentStats stats = Stats::Summarize(segment, {}); + CHECK(stats.repeatMedianMs.size() == 2); + CHECK(stats.repeatSpreadMs == doctest::Approx(2.0f)); + CHECK(stats.repeatSpreadPercent == doctest::Approx(100.0f * 2.0f / 11.0f)); +} + +TEST_CASE("nested passes are excluded from the attribution total") +{ + SegmentSamples segment; + segment.name = "scene.full"; + + RepeatSamples repeat; + repeat.repeatIndex = 0; + FrameSample sample; + sample.frameMs = 10.0f; + sample.cpuMs[0] = 6.0f; // a top-level pass + sample.cpuMs[1] = 3.0f; // nested inside pass 0 -- already counted in its 6 ms + repeat.frames.push_back(sample); + segment.repeats.push_back(repeat); + + const std::vector nested = { false, true }; + const Stats::SegmentStats stats = Stats::Summarize(segment, nested); + CHECK(stats.attributedCpuMs == doctest::Approx(6.0f)); + CHECK(stats.unattributedMs == doctest::Approx(4.0f)); + CHECK(stats.unattributedPercent == doctest::Approx(40.0f)); +} + +TEST_CASE("counters are reported per measured frame") +{ + SegmentSamples segment; + segment.name = "scene.full"; + + RepeatSamples repeat = MakeRepeat(0, ConstantFrames(4, 10.0f)); + repeat.counters.total[0] = 400; + repeat.counters.perPass[2][0] = 200; + segment.repeats.push_back(repeat); + + const Stats::SegmentStats stats = Stats::Summarize(segment, {}); + CHECK(stats.counterPerFrame[0] == doctest::Approx(100.0)); + CHECK(stats.passCounterPerFrame[2][0] == doctest::Approx(50.0)); +}