diff --git a/docs/evidence/windows-profiler-integrity-v1.md b/docs/evidence/windows-profiler-integrity-v1.md new file mode 100644 index 00000000..ae253f06 --- /dev/null +++ b/docs/evidence/windows-profiler-integrity-v1.md @@ -0,0 +1,105 @@ +# Windows GPU profiler integrity + +## Result and scope + +The Windows Radeon 760M/Vulkan profiler returned the previous frame's query +values, including stale buffer contents in the first frame. Submitting the +readback copy after the renderer's query-resolve submission repairs that +behavior. An independent resolve of the same query events matches the reported +current frame from its first sample. + +This is observed with wgpu 29.0.1 and AMD driver 24.12.1 (LLPC). The evidence +identifies resolve-to-copy visibility/order behavior on this configuration; it +does not establish an upstream driver or library defect. The fix retains the +existing blocking map and adds one profiler-only copy submission. Normal +rendering with profiling disabled is unaffected. + +## Diagnosis and controls + +The initial timing-only regression records four frames with each of three fresh +profilers. Against production source `64d5eed`, all 12 samples mismatch the +independent query values. For example, expected frame durations start at +53.72, 53.96, 68.52, and 53.84 microseconds; the old profiler reports 0, 53.72, +53.96, and 68.52. Recreating the profiler can reuse the preceding instance's +last buffer contents. The fixed implementation passes the same comparison. + +Diagnostic captures distinguish the stages: + +- Mapping and polling both report success even when the normal readback is stale. +- A later independent copy of the resolve buffer has the current query values. +- Re-reading the normal readback retains the old values. +- Explicit zero initialization only makes the first bad sample zero; it does + not remove the one-frame delay. +- Moving the copy into the following queue submission makes the two captures + equal without an additional CPU wait. + +`current-frame-before.log` and `current-frame-before-test.rs` retain the initial +negative control. The final GPU regression also verifies reporting coverage +and rejects a reserved but unresolved frame. Temporary diagnostic instrumentation +is retained in the evidence directory and is absent from production. + +## Reporting changes + +Map or poll failures no longer read an unmapped buffer. Missing resolves, +backwards query pairs, invalid timestamp periods, and exhausted query budgets +produce incomplete frames. Rolling pass means drop unavailable latest samples +and no longer reuse overwritten ring entries or average missing samples as zero. + +The native report distinguishes timestamp capability from valid measurement +coverage using `timing_window_frames`, `gpu_timing_valid_frames`, and +`gpu_timing_valid`. GPU aggregates exclude incomplete frames; the qualification +runner rejects an incomplete or unverified window. The window is the most recent +120 frames at most, not an all-session percentile claim. Non-finite timing, +timestep, render-scale, and hard-budget numbers also fail qualification. +Existing telemetry without coverage fields needs recapture for timing acceptance. + +## Validation + +The complete shared release suite passed on the physical Radeon/Vulkan adapter: +487 library tests, 90 golden tests, device startup, four focused PT temporal +tests, and the remaining enabled runtime/invariance suites. There were no test +failures. Existing exclusions remain: one library ignore, four golden ignores, +two documentation ignores, and external-input early returns (two Bistro golden +cases plus detailed virtual geometry, large virtual stress, and full Bistro +visibility fixtures). These returns do not qualify those external scenes. + +The repository contracts, lint lane, and quality-contract lane also passed, +including 25 quality-runner unit tests. The current-frame GPU regression also +passes on the Radeon through DX12. The regression compares actual query +events instead of imposing a GPU-duration threshold. The new SSGI measurement +assertion requires all 120 measured GPU frames to be complete. + +## Corrected SSGI comparison + +Both frozen executables use the corrected profiler and identical fixture code. +Only the two SSGI shader source files differ, using the same before/after shader +snapshots as the earlier stationary-SSGI report. Each resolution has five +alternating process pairs, with 24 warm-up and 120 measured frames. No local +build or other GPU test runs during the measurement sequence. The reported +cost is the sum of the five probe passes; blocking instrumentation means these +figures do not establish uninstrumented frame throughput. + +| Resolution | Before median (range), ms | After median (range), ms | Median delta | +| --- | --- | --- | --- | +| 256 | 0.098082 (0.097440-0.101088) | 0.106680 (0.100892-0.107854) | +0.008598 ms | +| 1280x720 | 0.396267 (0.387516-0.397251) | 0.439799 (0.431261-0.440850) | +0.043532 ms | + +The old shader's stationary-image assertion still fails; these failures are +retained as controls. The fixed shader passes, and all timing windows on both +sides contain 120 complete frames. The earlier SSGI timing table predates this +profiler correction and is superseded by this comparison. Its image evidence +and the outstanding HD TAA-jitter failure are independent of timestamp readback. + +## Evidence and remaining work + +Raw commands, logs, source snapshots, frozen executables, timing records, and +SHA-256 receipts are published with the +[profiler evidence prerelease](https://github.com/Bloom-Engine/engine/releases/tag/quality-evidence-profiler-windows-vulkan-20260910). +The source branch is `codex/windows-profiler-integrity`, based on #155 at +`64d5eedd71e4249edfef8977af9c0e4a944753d3`; the release tag identifies the final +report commit and its archive manifest hashes every retained file. + +This closes the observed current-frame readback defect on the tested adapter. +The two Windows portable-image discrepancies, HD temporal stability, the +representative scene/performance corpus, and other hardware/platform acceptance +remain open. No image baseline, visual threshold, or performance budget changes. diff --git a/docs/evidence/windows-ssgi-stationary-v1.md b/docs/evidence/windows-ssgi-stationary-v1.md index 5ec619e5..31fa7305 100644 --- a/docs/evidence/windows-ssgi-stationary-v1.md +++ b/docs/evidence/windows-ssgi-stationary-v1.md @@ -51,6 +51,10 @@ updating the two shader-source assertions for repeated phase validation. ## Isolated GPU timing +The figures in this section predate the profiler readback correction. The +[corrected comparison](windows-profiler-integrity-v1.md) supersedes them for +timing qualification; the image evidence elsewhere in this report is retained. + Five alternating before/after process pairs per size, each with 24 warm-up and 120 profiled frames. No other local GPU test ran concurrently. These figures cover the sum of five probe passes, not complete frame time. Profiling uses @@ -74,8 +78,10 @@ retained. These measurements do not establish a different adapter's budget. 0.97931148 before and 0.97931067 after. Both shaders pass this check at 256 square. The HD failure predates this fix and remains open; the static HD pass is not a claim that HD temporal qualification is complete. -- The combined golden batch emitted invalid GPU timestamp totals. Its timing is - excluded from this comparison; profiler reliability still needs investigation. +- The combined golden batch emitted invalid GPU timestamp totals. The later + [profiler investigation](windows-profiler-integrity-v1.md) identifies a + one-frame readback delay and repairs it; both SSGI shader variants have been + measured again with that correction. - The two portable-baseline Windows discrepancies, representative Bistro motion, other backends, and named RTX 4080 acceptance remain open. diff --git a/docs/evidence/windows-transmitted-shadow-inverse-vp-v1.md b/docs/evidence/windows-transmitted-shadow-inverse-vp-v1.md new file mode 100644 index 00000000..b38dd038 --- /dev/null +++ b/docs/evidence/windows-transmitted-shadow-inverse-vp-v1.md @@ -0,0 +1,39 @@ +# Transmitted-shadow inverse camera matrix correction + +The transmitted-shadow resolve uploaded the CPU inverse view-projection matrix +without converting its storage layout for WGSL matrix-vector multiplication. +Receiver positions were reconstructed in the wrong world coordinates, so the +pass missed the actual glass shadow and could tint unrelated boundary pixels. +The upload now transposes the inverse matrix, matching SSR, PT, and fog. + +This defect surfaced in #156's macOS shared-test lane at `73e6945`: the profiler +regression passed, but the colored-shadow test failed with RGB losses +`(2345, 7628, 406)`. The original test included asynchronous GI, which could +switch from screen-space tracing to SDF tracing between its two short captures. +GI is now disabled in this direct-shadow fixture, and failed captures are +retained automatically. Its camera, light, material, frame counts, and assertions +remain unchanged. + +The isolated fixture fails reproducibly on Radeon/Vulkan before the matrix +correction: RGB losses are `(19510, 37818, 966)`. Correcting the upload produces +a visible shadow on the floor beneath the glass, with 3,217 affected pixels +and losses `(99060, 70446, 471)`. The existing cyan-transmittance assertion passes. +A wrong-color control swaps the authored red and green attenuation values: +losses become `(68302, 95675, 656)` and the same assertion rejects it. The +temporary control is reverted. No approved image or assertion threshold changes. + +An intermediate diagnostic also tested an oblique light and a constant resolve +strength. Those variants are retained as diagnostic evidence and are absent +from the final change. The production correction is one matrix transpose; +resource counts, pass structure, and shadow-map resolution are unchanged. + +The local command is `cargo test --release --manifest-path native/shared/Cargo.toml +--test golden_render physical_transmission_casts_a_bounded_colored_directional_shadow +-- --nocapture`, with `WGPU_BACKEND=vulkan` and `BLOOM_REQUIRE_GPU=1`. + +Raw logs, before/after PNGs, the wrong-color control, and source changes are +retained under `tools/quality/out/windows-engine-plan/profiler-integrity/colored-shadow-stage/` +and published with the [#156 evidence prerelease](https://github.com/Bloom-Engine/engine/releases/tag/quality-evidence-profiler-windows-vulkan-20260910). +The initial profiler ZIP remains pinned to `73e6945`; the shadow follow-up +archive records its own source revision and hash manifest. Hosted validation +must be assessed against the follow-up PR head. diff --git a/docs/windows-engine-plan.md b/docs/windows-engine-plan.md index 22eadad2..ad801035 100644 --- a/docs/windows-engine-plan.md +++ b/docs/windows-engine-plan.md @@ -14,10 +14,10 @@ first nine-scene Radeon evidence are in draft PR #154. Follow-up work starts at | Work | Required completion evidence | Current state | | --- | --- | --- | -| #127 Vulkan PT correctness | Three deterministic progressive and motion runs, both negative controls, finite intermediates, reset/lighting/rigid-motion checks, retained report | Canonical hardware gate, all four focused temporal tests, and CPU reference sanity check pass on Radeon/Vulkan; [report retained](evidence/issue-127-windows-vulkan-v1.md), archive publication pending | +| #127 Vulkan PT correctness | Three deterministic progressive and motion runs, both negative controls, finite intermediates, reset/lighting/rigid-motion checks, retained report | Canonical hardware gate, all four focused temporal tests, and CPU reference sanity check pass on Radeon/Vulkan; [report](evidence/issue-127-windows-vulkan-v1.md) and [raw evidence](https://github.com/Bloom-Engine/engine/releases/tag/quality-evidence-155-windows-vulkan-20260910) published | | #128 Windows image discrepancies | Identify the first incorrect stage or document a reviewed backend-specific baseline decision; rerun the full strict corpus and reproducibility checks | Sponza and skinned/alpha still fail against portable baselines; original baseline source reproduces both failures | -| #135 / #149 temporal reconstruction | Enforced motion/producer/quality-preset corpus, representative scenes, fractional/native and frozen A/B timing, memory/resize checks, platform evidence | Device lifetime and resource gates repaired; [stationary SSGI fix](evidence/windows-ssgi-stationary-v1.md) passes 89 golden tests with 4 ignored and 2 optional external-input skips; complete-phase/lighting control and frozen A/B recorded. Existing HD TAA-jitter failure and invalid batch timestamps remain open | -| #140 integration gates | Same required local/hosted lanes pass on exact source; release package startup and all-example evidence | Local contracts, formatting, and 484 shared tests pass. Hosted CI passes all mobile target builds, native/web builds, and browser startup. Metal texture-byte counter availability was the last failure; its repair and final source are awaiting CI | +| #135 / #149 temporal reconstruction | Enforced motion/producer/quality-preset corpus, representative scenes, fractional/native and frozen A/B timing, memory/resize checks, platform evidence | Device lifetime and resource gates repaired; [stationary SSGI fix](evidence/windows-ssgi-stationary-v1.md) and [profiler correction](evidence/windows-profiler-integrity-v1.md) pass 90 golden tests with 4 ignored and 2 optional external-input skips. Complete-phase/lighting control and corrected frozen A/B recorded. HD TAA-jitter and the full representative corpus remain open | +| #140 integration gates | Same required local/hosted lanes pass on exact source; release package startup and all-example evidence | All 23 hosted checks pass at #155 source `64d5eed`, including macOS shared/golden tests, all mobile target builds, native/web builds, and browser startup. Scheduled physical-hardware checks, all-example compilation, and release-install acceptance remain separate requirements | | #138 capability fallback | Actual constrained-adapter startup and relevant forced-tier corpus, truthful capability outputs | Existing implementation/evidence preserved; physical constrained-limit acceptance still needs proof | | PR integration | Reviewable changes, passing required checks, full issue evidence, merge-ready rendering branch | #147, #154, and follow-up [#155](https://github.com/Bloom-Engine/engine/pull/155) remain drafts; no merge performed | @@ -54,11 +54,23 @@ audit are saved in `tools/quality/out/windows-engine-plan/plan-requirements.json ## Current next steps -1. Retain the stationary software-SSGI evidence with the final #155 source. The - previous shader fails the new regression; the fix passes at measured cost. -2. Obtain passing hosted checks for the final #155 source and retain the exact - commits and run links. The combined golden batch also exposed invalid GPU - timestamp totals; investigate those before accepting batch timing evidence. -3. Resume the two Windows portable-baseline discrepancies and the representative - temporal/geometry corpus, then continue the engine work retained above. - Hardware-specific acceptance remains open while local work progresses. +1. #155 source `64d5eed` has passing hosted checks and published evidence. The + archive SHA-256 is `de9c1beca73bfcf60bf79d3a612b72c072f726f6272576a7f0f60ffdbc7ce25d`. + CI run URLs and conclusions are in its separate `pr155-checks-64d5eed.json` + release asset. No draft PR has been merged. +2. The [profiler correction](evidence/windows-profiler-integrity-v1.md) on + `codex/windows-profiler-integrity` passes local contracts, lint, the quality + lane, and the complete shared suite. Its current-frame regression rejects + all 12 old Vulkan samples and passes with the correction on Vulkan and DX12. + Corrected SSGI timing covers 20 isolated runs, each with 120 complete GPU + frames. Hosted Metal also passes the profiler regression. Its colored-shadow + failure exposed an [inverse-matrix upload defect](evidence/windows-transmitted-shadow-inverse-vp-v1.md); + the correction passes the isolated local check and rejects the wrong-color + control. Hosted CI must qualify this follow-up's exact source before integration. +3. Diagnose Sponza and skinned/alpha against the portable baselines, then repair + HD temporal stability and complete the representative temporal/geometry + corpus. Recapture affected timing evidence with explicit coverage fields. +4. Continue starter/all-example and release-install checks, asset/world streaming, + schema-generated APIs, components, and runtime UI against each issue's full + acceptance criteria. Hardware-specific acceptance remains open while local + work progresses. diff --git a/native/shared/src/profiler.rs b/native/shared/src/profiler.rs index e0009cba..80316ba2 100644 --- a/native/shared/src/profiler.rs +++ b/native/shared/src/profiler.rs @@ -54,12 +54,16 @@ pub struct Profiler { query_set: Option, resolve_buffer: Option, readback_buffer: Option, + gpu_queue: Option, timestamp_period_ns: f32, next_query: u32, // label -> (begin_index, end_index) pending_gpu: Vec<(&'static str, u32, u32)>, /// One-shot warning guard for GPU timestamp-pair exhaustion. budget_warned: bool, + gpu_queries_resolved: bool, + frame_gpu_exhausted: bool, + frame_gpu_complete: bool, /// Phase 8 — last `ROLLING_FRAMES` frame totals (sum of all /// samples in `frame` at frame_end), in microseconds. Ring @@ -67,14 +71,14 @@ pub struct Profiler { /// `bloom_profiler_frame_history` and render a bar chart. frame_total_cpu_us: [f64; ROLLING_FRAMES], frame_total_gpu_us: [f64; ROLLING_FRAMES], + frame_gpu_valid: [bool; ROLLING_FRAMES], histogram_idx: usize, histogram_filled: usize, } struct RollingStats { cpu: [f64; ROLLING_FRAMES], - gpu: [f64; ROLLING_FRAMES], - has_gpu: bool, + gpu: [Option; ROLLING_FRAMES], idx: usize, filled: usize, /// Frame index of the most recent sample. A pass that stops running @@ -114,6 +118,16 @@ fn quality_stats_ms(values_us: impl Iterator) -> QualityStats { max: *values.last().unwrap_or(&0.0), } } +fn gpu_duration_us(begin: u64, end: u64, period_ns: f32) -> Option { + if !period_ns.is_finite() || period_ns <= 0.0 { + return None; + } + // Equal timestamps are a legitimate sub-tick duration. Backwards pairs + // cannot be measured without the backend's timestamp wraparound width. + let duration = end.checked_sub(begin)? as f64 * f64::from(period_ns) / 1000.0; + duration.is_finite().then_some(duration) +} + fn push_json_string(out: &mut String, value: &str) { out.push('"'); for c in value.chars() { @@ -141,8 +155,7 @@ impl RollingStats { fn new() -> Self { Self { cpu: [0.0; ROLLING_FRAMES], - gpu: [0.0; ROLLING_FRAMES], - has_gpu: false, + gpu: [None; ROLLING_FRAMES], idx: 0, filled: 0, last_frame: 0, @@ -150,10 +163,7 @@ impl RollingStats { } fn push(&mut self, cpu: f64, gpu: Option) { self.cpu[self.idx] = cpu; - if let Some(g) = gpu { - self.gpu[self.idx] = g; - self.has_gpu = true; - } + self.gpu[self.idx] = gpu.filter(|g| g.is_finite() && *g >= 0.0); self.idx = (self.idx + 1) % ROLLING_FRAMES; self.filled = (self.filled + 1).min(ROLLING_FRAMES); } @@ -165,11 +175,13 @@ impl RollingStats { sum / self.filled as f64 } fn avg_gpu(&self) -> Option { - if !self.has_gpu || self.filled == 0 { + if self.filled == 0 { return None; } - let sum: f64 = self.gpu.iter().take(self.filled).sum(); - Some(sum / self.filled as f64) + // A failed latest sample must not display an older measurement. + self.gpu[(self.idx + ROLLING_FRAMES - 1) % ROLLING_FRAMES]?; + let values = self.gpu.iter().take(self.filled).flatten(); + Some(values.clone().sum::() / values.count() as f64) } } @@ -185,12 +197,17 @@ impl Profiler { query_set: None, resolve_buffer: None, readback_buffer: None, + gpu_queue: None, timestamp_period_ns: 1.0, next_query: 0, pending_gpu: Vec::new(), budget_warned: false, + gpu_queries_resolved: false, + frame_gpu_exhausted: false, + frame_gpu_complete: false, frame_total_cpu_us: [0.0; ROLLING_FRAMES], frame_total_gpu_us: [0.0; ROLLING_FRAMES], + frame_gpu_valid: [false; ROLLING_FRAMES], histogram_idx: 0, histogram_filled: 0, } @@ -223,6 +240,7 @@ impl Profiler { self.query_set = Some(query_set); self.resolve_buffer = Some(resolve_buffer); self.readback_buffer = Some(readback_buffer); + self.gpu_queue = Some(queue.clone()); self.timestamp_period_ns = queue.get_timestamp_period(); self.gpu_enabled = true; } @@ -234,8 +252,16 @@ impl Profiler { // until the rolling window refills and skew the first seconds // of every new session. self.rolling.clear(); + self.frame.clear(); + self.open_cpu.clear(); + self.next_query = 0; + self.pending_gpu.clear(); + self.gpu_queries_resolved = false; + self.frame_gpu_exhausted = false; + self.frame_gpu_complete = false; self.frame_total_cpu_us = [0.0; ROLLING_FRAMES]; self.frame_total_gpu_us = [0.0; ROLLING_FRAMES]; + self.frame_gpu_valid = [false; ROLLING_FRAMES]; self.histogram_idx = 0; self.histogram_filled = 0; } @@ -283,6 +309,7 @@ impl Profiler { } self.query_set.as_ref()?; if self.next_query + 2 > MAX_GPU_PAIRS * 2 { + self.frame_gpu_exhausted = true; if !self.budget_warned { self.budget_warned = true; eprintln!( @@ -295,6 +322,7 @@ impl Profiler { let begin = self.next_query; let end = self.next_query + 1; self.next_query += 2; + self.gpu_queries_resolved = false; self.pending_gpu.push((label, begin, end)); Some((begin, end)) } @@ -333,8 +361,9 @@ impl Profiler { }) } - /// Resolve any pending GPU queries into the readback buffer. Call once - /// per frame, after all passes are encoded and before submit. + /// Resolve pending GPU queries into the resolve buffer. Call once + /// per frame, after all passes are encoded and before submit. The host + /// copy is submitted by `frame_end` after this command buffer is submitted. pub fn resolve(&mut self, encoder: &mut wgpu::CommandEncoder) { if !self.enabled || !self.gpu_enabled || self.next_query == 0 { return; @@ -343,10 +372,7 @@ impl Profiler { return; }; encoder.resolve_query_set(qs, 0..self.next_query, resolve, 0); - if let Some(readback) = &self.readback_buffer { - let byte_count = (self.next_query as u64) * 8; - encoder.copy_buffer_to_buffer(resolve, 0, readback, 0, byte_count); - } + self.gpu_queries_resolved = true; } /// End-of-frame bookkeeping. Resolves this frame's GPU timestamps via @@ -360,55 +386,78 @@ impl Profiler { self.open_cpu.clear(); self.next_query = 0; self.pending_gpu.clear(); + self.gpu_queries_resolved = false; + self.frame_gpu_exhausted = false; + self.frame_gpu_complete = false; return; } - if self.gpu_enabled && self.next_query > 0 { - if let Some(readback) = &self.readback_buffer { - let byte_count = (self.next_query as u64) * 8; - let slice = readback.slice(0..byte_count); - slice.map_async(wgpu::MapMode::Read, |_| {}); - let _ = device.poll(wgpu::PollType::Wait { - submission_index: None, - timeout: None, + self.frame_gpu_complete = false; + for (label, _, _) in &self.pending_gpu { + if !self.frame.iter().any(|s| s.label == *label) { + self.frame.push(FrameSample { + label, + cpu_us: 0.0, + gpu_us: None, }); - let data = slice.get_mapped_range().to_vec(); - readback.unmap(); - let period = self.timestamp_period_ns as f64; - let mut by_label: HashMap<&'static str, f64> = HashMap::new(); + } + } + if self.gpu_enabled && self.gpu_queries_resolved && self.next_query > 0 { + if let Some(data) = self.read_gpu_timestamps(device) { + let mut by_label: HashMap<&'static str, Option> = HashMap::new(); + self.frame_gpu_complete = !self.frame_gpu_exhausted; for (label, b, e) in &self.pending_gpu { let bo = (*b as usize) * 8; let eo = (*e as usize) * 8; - if eo + 8 > data.len() { - continue; - } let bt = u64::from_le_bytes(data[bo..bo + 8].try_into().unwrap()); let et = u64::from_le_bytes(data[eo..eo + 8].try_into().unwrap()); - if et <= bt { - continue; - } - let us = (et - bt) as f64 * period / 1000.0; - *by_label.entry(*label).or_insert(0.0) += us; + let us = gpu_duration_us(bt, et, self.timestamp_period_ns); + self.frame_gpu_complete &= us.is_some(); + let total = by_label.entry(*label).or_insert(Some(0.0)); + *total = total.zip(us).map(|(sum, us)| sum + us); } for s in self.frame.iter_mut() { if let Some(us) = by_label.remove(s.label) { - s.gpu_us = Some(us); + s.gpu_us = us; } } - // GPU samples without a CPU counterpart — record them too. - for (label, us) in by_label { - self.frame.push(FrameSample { - label, - cpu_us: 0.0, - gpu_us: Some(us), - }); - } } } self.frame_end_cpu(); } + fn read_gpu_timestamps(&self, device: &wgpu::Device) -> Option> { + let readback = self.readback_buffer.as_ref()?; + let byte_count = u64::from(self.next_query) * 8; + // On Windows/Radeon Vulkan, resolving and copying in one encoder + // returned the previous frame's queries, with stale data on frame zero. + // Submit the copy after the renderer submits the resolve. This only + // runs while profiling and adds no render pass or additional CPU wait. + let mut encoder = device.create_command_encoder(&wgpu::CommandEncoderDescriptor { + label: Some("bloom_profiler_readback_copy"), + }); + encoder.copy_buffer_to_buffer(self.resolve_buffer.as_ref()?, 0, readback, 0, byte_count); + self.gpu_queue.as_ref()?.submit([encoder.finish()]); + let slice = readback.slice(0..byte_count); + let (tx, rx) = std::sync::mpsc::channel(); + slice.map_async(wgpu::MapMode::Read, move |result| { + let _ = tx.send(result); + }); + let completed = device.poll(wgpu::PollType::Wait { + submission_index: None, + timeout: None, + }); + let data = if completed.is_ok() && matches!(rx.try_recv(), Ok(Ok(()))) { + Some(slice.get_mapped_range().to_vec()) + } else { + None + }; + // Also cancels a still-pending map on backends without blocking poll. + readback.unmap(); + data + } + /// CPU-only end-of-frame: histogram update + drain into rolling. /// Split out so tests don't need a wgpu::Device. Production /// callers go through `frame_end` which handles GPU readback @@ -427,6 +476,7 @@ impl Profiler { } self.frame_total_cpu_us[self.histogram_idx] = frame_cpu; self.frame_total_gpu_us[self.histogram_idx] = frame_gpu; + self.frame_gpu_valid[self.histogram_idx] = self.frame_gpu_complete; self.histogram_idx = (self.histogram_idx + 1) % ROLLING_FRAMES; self.histogram_filled = (self.histogram_filled + 1).min(ROLLING_FRAMES); @@ -446,6 +496,9 @@ impl Profiler { self.open_cpu.clear(); self.next_query = 0; self.pending_gpu.clear(); + self.gpu_queries_resolved = false; + self.frame_gpu_exhausted = false; + self.frame_gpu_complete = false; self.frame_count = self.frame_count.wrapping_add(1); } @@ -566,9 +619,22 @@ impl Profiler { ) -> String { let history = self.frame_history(); let cpu = quality_stats_ms(history.iter().map(|(cpu, _)| *cpu)); - let gpu = quality_stats_ms(history.iter().map(|(_, gpu)| *gpu)); + let valid_gpu_frames = self + .frame_gpu_valid + .iter() + .take(history.len()) + .filter(|v| **v) + .count(); + let gpu = quality_stats_ms( + self.frame_total_gpu_us + .iter() + .zip(&self.frame_gpu_valid) + .take(history.len()) + .filter_map(|(us, valid)| valid.then_some(*us)), + ); + let gpu_timing_valid = !history.is_empty() && valid_gpu_frames == history.len(); let rows = self.snapshot(); - let gpu_timestamps = rows.iter().any(|(_, _, gpu)| gpu.is_some()); + let gpu_timestamps = self.gpu_enabled; let mode_name = match present_mode { 0 => "fifo", 1 => "mailbox", @@ -616,6 +682,9 @@ impl Profiler { let _ = writeln!(out, " \"gpu_frame_p95_ms\":{:.6},", gpu.p95); let _ = writeln!(out, " \"gpu_frame_max_ms\":{:.6},", gpu.max); let _ = writeln!(out, " \"gpu_timestamps_available\":{gpu_timestamps},"); + let _ = writeln!(out, " \"timing_window_frames\":{},", history.len()); + let _ = writeln!(out, " \"gpu_timing_valid_frames\":{valid_gpu_frames},"); + let _ = writeln!(out, " \"gpu_timing_valid\":{gpu_timing_valid},"); let _ = writeln!(out, " \"vram_peak_mb\":null,"); out.push_str(" \"passes\":["); for (i, (label, cpu_us, gpu_us)) in rows.iter().enumerate() { @@ -647,6 +716,80 @@ impl Profiler { mod tests { use super::*; + #[test] + fn unavailable_gpu_samples_do_not_reuse_or_dilute_old_timings() { + let mut stats = RollingStats::new(); + stats.push(1.0, Some(20.0)); + assert_eq!(stats.avg_gpu(), Some(20.0)); + stats.push(1.0, None); + assert_eq!(stats.avg_gpu(), None); + stats.push(1.0, Some(40.0)); + assert_eq!(stats.avg_gpu(), Some(30.0)); + for _ in 0..ROLLING_FRAMES { + stats.push(1.0, None); + } + assert_eq!(stats.avg_gpu(), None); + stats.push(1.0, Some(10.0)); + assert_eq!(stats.avg_gpu(), Some(10.0)); + for invalid in [f64::NAN, f64::INFINITY, -1.0] { + stats.push(1.0, Some(invalid)); + assert_eq!(stats.avg_gpu(), None); + } + } + + #[test] + fn gpu_duration_rejects_backwards_pairs_and_invalid_periods() { + assert_eq!(gpu_duration_us(100, 200, 10.0), Some(1.0)); + assert_eq!(gpu_duration_us(100, 100, 10.0), Some(0.0)); + assert_eq!(gpu_duration_us(200, 100, 10.0), None); + for invalid in [f32::NAN, f32::INFINITY, -1.0, 0.0] { + assert_eq!(gpu_duration_us(100, 200, invalid), None); + } + } + + #[test] + fn quality_report_exposes_incomplete_gpu_windows_until_they_expire() { + let mut p = Profiler::new(); + p.set_enabled(true); + p.gpu_enabled = true; + for valid in [true, false, true] { + p.frame_gpu_complete = valid; + p.frame.push(FrameSample { + label: "gpu-pass", + cpu_us: 100.0, + gpu_us: valid.then_some(2_000.0), + }); + p.frame_end_cpu(); + } + let report = |p: &mut Profiler| { + p.quality_report_json(3, 60, 120, 1.0 / 60.0, 3, 1.0, 250.0, "{}", "{}") + }; + let json = report(&mut p); + assert!(json.contains("\"gpu_timestamps_available\":true")); + assert!(json.contains("\"timing_window_frames\":3")); + assert!(json.contains("\"gpu_timing_valid_frames\":2")); + assert!(json.contains("\"gpu_timing_valid\":false")); + assert!(json.contains("\"gpu_frame_mean_ms\":2.000000")); + for _ in 0..ROLLING_FRAMES { + p.frame_gpu_complete = true; + p.frame.push(FrameSample { + label: "gpu-pass", + cpu_us: 100.0, + gpu_us: Some(3_000.0), + }); + p.frame_end_cpu(); + } + let json = report(&mut p); + assert!(json.contains("\"gpu_timing_valid_frames\":120")); + assert!(json.contains("\"gpu_timing_valid\":true")); + assert!(json.contains("\"gpu_frame_mean_ms\":3.000000")); + p.set_enabled(false); + p.set_enabled(true); + let json = report(&mut p); + assert!(json.contains("\"timing_window_frames\":0")); + assert!(json.contains("\"gpu_timing_valid\":false")); + } + /// Drive the profiler through `frame_end` purely on the CPU /// side (gpu_enabled stays false). Each "frame" pushes a single /// sample with the given cpu_us so the histogram totals are diff --git a/native/shared/src/renderer/transmitted_shadows.rs b/native/shared/src/renderer/transmitted_shadows.rs index e140bed7..7808b878 100644 --- a/native/shared/src/renderer/transmitted_shadows.rs +++ b/native/shared/src/renderer/transmitted_shadows.rs @@ -1354,7 +1354,8 @@ impl Renderer { return; }; let uniforms = TransmittedShadowResolveUniforms { - inv_vp: self.current_inv_vp_matrix, + // Match SSR/PT: the CPU inverse is transposed relative to WGSL M*v. + inv_vp: mat4_transpose(self.current_inv_vp_matrix), cascade_vps: self.shadow_map.light_vps, camera_pos: [ self.current_camera_pos[0], diff --git a/native/shared/tests/golden_render.rs b/native/shared/tests/golden_render.rs index c2db6366..49095507 100644 --- a/native/shared/tests/golden_render.rs +++ b/native/shared/tests/golden_render.rs @@ -42,6 +42,8 @@ mod layered_pbr_parity; mod lighting_upload; #[path = "golden_render/motion_producer_audit.rs"] mod motion_producer_audit; +#[path = "golden_render/profiler_integrity.rs"] +mod profiler_integrity; #[path = "golden_render/quality_presets.rs"] mod quality_presets; #[path = "golden_render/temporal_history.rs"] @@ -1121,6 +1123,9 @@ fn physical_transmission_casts_a_bounded_colored_directional_shadow() { return; }; eng.renderer.set_shadows_enabled(true); + // Compare direct-light attenuation. A background SDF bake can switch GI + // backends between these short captures and change unrelated RGB lighting. + eng.renderer.set_ssgi_enabled(false); let transform = |scale: [f32; 3], translation: [f32; 3]| -> [[f32; 4]; 4] { [ @@ -1188,13 +1193,19 @@ fn physical_transmission_casts_a_bounded_colored_directional_shadow() { green_loss += u64::from(green); blue_loss += u64::from(blue); } + let sufficient_receiver = affected > 50; + let correct_tint = red_loss > green_loss && green_loss > blue_loss.saturating_mul(2); + if diagnostics_enabled() || !sufficient_receiver || !correct_tint { + write_diagnostic_capture("physical-colored-shadow", "unshadowed", W, H, &unshadowed); + write_diagnostic_capture("physical-colored-shadow", "colored", W, H, &colored); + } assert!( - affected > 50, + sufficient_receiver, "enabling the glass caster did not produce a bounded receiver region \ (affected={affected})" ); assert!( - red_loss > green_loss && green_loss > blue_loss.saturating_mul(2), + correct_tint, "shadow did not preserve authored cyan transmittance: \ losses rgb=({red_loss},{green_loss},{blue_loss})" ); diff --git a/native/shared/tests/golden_render/profiler_integrity.rs b/native/shared/tests/golden_render/profiler_integrity.rs new file mode 100644 index 00000000..85d8125d --- /dev/null +++ b/native/shared/tests/golden_render/profiler_integrity.rs @@ -0,0 +1,154 @@ +use super::*; +use bloom_shared::profiler::Profiler; + +fn resolved_pair(device: &wgpu::Device, queue: &wgpu::Queue, queries: &wgpu::QuerySet) -> [u64; 2] { + let resolved = device.create_buffer(&wgpu::BufferDescriptor { + label: Some("timestamp-reference-resolve"), + size: 16, + usage: wgpu::BufferUsages::QUERY_RESOLVE | wgpu::BufferUsages::COPY_SRC, + mapped_at_creation: false, + }); + let staging = device.create_buffer(&wgpu::BufferDescriptor { + label: Some("timestamp-reference-readback"), + size: 16, + usage: wgpu::BufferUsages::COPY_DST | wgpu::BufferUsages::MAP_READ, + mapped_at_creation: false, + }); + // Resolve the same recorded events again, after the measured submission. + // Keep its host copy in a subsequent submission as an independent oracle. + let mut encoder = device.create_command_encoder(&Default::default()); + encoder.resolve_query_set(queries, 0..2, &resolved, 0); + queue.submit([encoder.finish()]); + let mut encoder = device.create_command_encoder(&Default::default()); + encoder.copy_buffer_to_buffer(&resolved, 0, &staging, 0, 16); + queue.submit([encoder.finish()]); + let slice = staging.slice(..); + let (tx, rx) = std::sync::mpsc::channel(); + slice.map_async(wgpu::MapMode::Read, move |result| tx.send(result).unwrap()); + device + .poll(wgpu::PollType::Wait { + submission_index: None, + timeout: None, + }) + .expect("timestamp reference completion"); + rx.recv().unwrap().expect("timestamp reference map"); + let bytes = slice.get_mapped_range(); + let pair = [ + u64::from_le_bytes(bytes[0..8].try_into().unwrap()), + u64::from_le_bytes(bytes[8..16].try_into().unwrap()), + ]; + drop(bytes); + staging.unmap(); + pair +} + +#[test] +fn profiler_reports_the_current_gpu_frame_from_its_first_sample() { + let Some(eng) = try_engine() else { + eprintln!("skip: no GPU adapter"); + return; + }; + let device = &eng.renderer.device; + let queue = &eng.renderer.queue; + if !device.features().contains(wgpu::Features::TIMESTAMP_QUERY) { + eprintln!("skip: timestamp-query feature unavailable"); + return; + } + let target = device.create_texture(&wgpu::TextureDescriptor { + label: Some("timestamp-frame-fixture"), + size: wgpu::Extent3d { + width: 1024, + height: 1024, + depth_or_array_layers: 1, + }, + mip_level_count: 1, + sample_count: 1, + dimension: wgpu::TextureDimension::D2, + format: wgpu::TextureFormat::Rgba8Unorm, + usage: wgpu::TextureUsages::RENDER_ATTACHMENT, + view_formats: &[], + }); + let view = target.create_view(&Default::default()); + let mut mismatches = 0; + for generation in 0..3 { + let mut profiler = Profiler::new(); + profiler.init_gpu(device, queue); + profiler.set_enabled(true); + for frame in 0..4 { + let mut encoder = device.create_command_encoder(&Default::default()); + { + let _pass = encoder.begin_render_pass(&wgpu::RenderPassDescriptor { + label: Some("timestamp-frame-fixture"), + color_attachments: &[Some(wgpu::RenderPassColorAttachment { + view: &view, + depth_slice: None, + resolve_target: None, + ops: wgpu::Operations { + load: wgpu::LoadOp::Clear(wgpu::Color { + r: f64::from(frame) / 4.0, + g: 0.2, + b: 0.6, + a: 1.0, + }), + store: wgpu::StoreOp::Store, + }, + })], + timestamp_writes: profiler.pass_timestamp_writes("current-frame"), + ..Default::default() + }); + } + profiler.resolve(&mut encoder); + queue.submit([encoder.finish()]); + profiler.frame_end(device); + + let pair = resolved_pair(device, queue, profiler.query_set().unwrap()); + assert!( + pair[0] > 0 && pair[1] > pair[0], + "invalid independent query pair: {pair:?}" + ); + let expected_us = + (pair[1] - pair[0]) as f64 * f64::from(queue.get_timestamp_period()) / 1000.0; + let reported_us = profiler.frame_history().last().unwrap().1; + if reported_us != expected_us { + mismatches += 1; + eprintln!("timestamp mismatch generation={generation} frame={frame} expected_us={expected_us} reported_us={reported_us}"); + } + let report: serde_json::Value = serde_json::from_str(&profiler.quality_report_json( + 3, + 0, + frame + 1, + 1.0 / 60.0, + 3, + 1.0, + 1.0, + "{}", + "{}", + )) + .unwrap(); + assert_eq!(report["gpu_timing_valid"], true); + assert_eq!(report["gpu_timing_valid_frames"], frame + 1); + } + // A reserved but unresolved frame cannot reuse the last valid result. + profiler.reserve_gpu_pair("current-frame"); + profiler.frame_end(device); + assert_eq!(profiler.snapshot()[0].2, None); + let report: serde_json::Value = serde_json::from_str(&profiler.quality_report_json( + 3, + 0, + 5, + 1.0 / 60.0, + 3, + 1.0, + 1.0, + "{}", + "{}", + )) + .unwrap(); + assert_eq!(report["gpu_timing_valid"], false); + assert_eq!(report["gpu_timing_valid_frames"], 4); + } + assert_eq!( + mismatches, 0, + "profiler reported stale or uninitialized GPU frame data" + ); +} diff --git a/native/shared/tests/golden_render/ssgi_quality.rs b/native/shared/tests/golden_render/ssgi_quality.rs index 3e57d67f..3dd33d84 100644 --- a/native/shared/tests/golden_render/ssgi_quality.rs +++ b/native/shared/tests/golden_render/ssgi_quality.rs @@ -559,6 +559,23 @@ fn ssgi_hiz_immediate_scene_produces_finite_indirect_radiance() { for _ in 0..120 { capture(&mut eng); } + let timing_report: serde_json::Value = serde_json::from_str(&eng.profiler.quality_report_json( + 3, + 24, + 120, + 1.0 / 60.0, + 3, + 1.0, + 0.0, + "{}", + "{}", + )) + .expect("SSGI fixture timing statistics"); + if eng.profiler.has_gpu() { + assert_eq!(timing_report["gpu_timing_valid"], true); + assert_eq!(timing_report["gpu_timing_valid_frames"], 120); + eprintln!("ssgi-profile complete_gpu_frames=120"); + } let probe_gpu_us = eng .profiler .snapshot() diff --git a/tools/quality/README.md b/tools/quality/README.md index 074204c3..a75e99cd 100644 --- a/tools/quality/README.md +++ b/tools/quality/README.md @@ -228,6 +228,18 @@ on Retina/window scaling, desktop compositing, or vsync. The engine reports and GPU timestamp availability. Hard performance runners reject telemetry that cannot prove these properties. +GPU timing reports distinguish adapter support (`gpu_timestamps_available`) +from complete measurements (`gpu_timing_valid`). `timing_window_frames` is the +number of retained frame samples, up to the profiler's 120-frame window; +`gpu_timing_valid_frames` counts frames whose reserved queries were all resolved +and read successfully without exhausting the query budget. A missing resolve, +failed readback, backwards timestamp pair, or invalid timestamp period makes +that frame incomplete. Incomplete frames are excluded from GPU aggregate +statistics, and qualification rejects an incomplete or unverified window. +CPU/GPU timings, timestep, render scale, and hard-budget measurements must be +finite numbers. Existing reports without the GPU validity fields need a new +capture before they can serve as timing qualification. + The measured window is intentionally sustained (240–300 frames after 120–180 warm-up frames). Shorter windows were rejected because scheduler spikes dominated p95. Capture and PNG encoding happen after measurement. diff --git a/tools/quality/run.py b/tools/quality/run.py index 164acdb9..081eb5d1 100644 --- a/tools/quality/run.py +++ b/tools/quality/run.py @@ -14,6 +14,7 @@ import hashlib import html import json +import math import os import platform import shlex @@ -89,6 +90,9 @@ "present_mode_code", "uncapped", "gpu_timestamps_available", + "timing_window_frames", + "gpu_timing_valid_frames", + "gpu_timing_valid", "warmup_excluded", "shader_compilation_excluded", "adapter", @@ -748,7 +752,7 @@ def validate_manifest(manifest: Mapping[str, Any]) -> None: "max_gpu_p95_absolute_delta_ms", ): value = reproducibility.get(key) - if not isinstance(value, (int, float)) or value < 0: + if not finite_nonnegative_number(value): raise QualityError(f"reproducibility.{key} must be a non-negative number") fault_controls = manifest.get("negative_control", []) if not isinstance(fault_controls, list): @@ -1083,6 +1087,10 @@ def steady_state_renderer_failures(renderer_paths: Mapping[str, Any]) -> list[st return failures +def finite_nonnegative_number(value: Any) -> bool: + return type(value) in (int, float) and math.isfinite(value) and value >= 0 + + def telemetry_contract_failures( case: Mapping[str, Any], telemetry: Mapping[str, Any] | None ) -> list[str]: @@ -1097,7 +1105,7 @@ def telemetry_contract_failures( f"telemetry {key} {telemetry.get(key)!r} != requested {case.get(key)!r}" ) observed_step = telemetry.get("fixed_timestep") - if not isinstance(observed_step, (int, float)) or abs( + if not finite_nonnegative_number(observed_step) or abs( float(observed_step) - float(case["fixed_timestep"]) ) > 1e-6: failures.append( @@ -1111,7 +1119,7 @@ def telemetry_contract_failures( f"!= requested {expected_preset!r}" ) observed_scale = telemetry.get("render_scale") - if not isinstance(observed_scale, (int, float)) or abs( + if not finite_nonnegative_number(observed_scale) or abs( float(observed_scale) - float(case["render_scale"]) ) > 1e-6: failures.append( @@ -1136,12 +1144,23 @@ def telemetry_contract_failures( failures.extend(steady_state_renderer_failures(renderer_paths)) for key in ("cpu_frame_mean_ms", "cpu_frame_p95_ms", "measurement_wall_ms"): value = telemetry.get(key) - if not isinstance(value, (int, float)) or value < 0: + if not finite_nonnegative_number(value): failures.append(f"telemetry {key} is unavailable") if telemetry.get("gpu_timestamps_available", False): + window = telemetry.get("timing_window_frames") + valid = telemetry.get("gpu_timing_valid_frames") + if ( + telemetry.get("gpu_timing_valid") is not True + or type(window) is not int + or type(valid) is not int + or window <= 0 + or window > case["measured_frames"] + or valid != window + ): + failures.append("telemetry GPU timing window is incomplete or unverified") for key in ("gpu_frame_mean_ms", "gpu_frame_p95_ms"): value = telemetry.get(key) - if not isinstance(value, (int, float)) or value < 0: + if not finite_nonnegative_number(value): failures.append(f"telemetry {key} is unavailable despite GPU timestamps") passes = telemetry.get("passes") if not isinstance(passes, list) or not passes: @@ -1300,7 +1319,7 @@ def performance_failures( if limit is None: continue measured = telemetry.get(measured_key) - if measured is None: + if not finite_nonnegative_number(measured): failures.append(f"{measured_key} unavailable for hard budget {budget_key}") elif float(measured) > float(limit): failures.append(f"{measured_key} {float(measured):.4f} > {float(limit):.4f}") diff --git a/tools/quality/test_run.py b/tools/quality/test_run.py index 54d8413b..b0ddacd4 100644 --- a/tools/quality/test_run.py +++ b/tools/quality/test_run.py @@ -613,6 +613,49 @@ def test_telemetry_contract_rejects_vsync_and_wrong_frame_count(self) -> None: self.assertTrue(any("measured_frames" in item for item in failures)) self.assertTrue(any("uncapped" in item for item in failures)) + def test_telemetry_rejects_incomplete_gpu_windows_and_nonfinite_times(self) -> None: + case = {"fixed_timestep": 1 / 60, "warmup_frames": 60, + "measured_frames": 120, "render_scale": 1.0} + telemetry = { + "schema": "bloom-quality-telemetry-v1", **case, + "uncapped": True, "warmup_excluded": True, + "shader_compilation_excluded": True, + "gpu_timestamps_available": True, + "timing_window_frames": 120, "gpu_timing_valid_frames": 120, + "gpu_timing_valid": True, + "adapter": {"availability": "reported"}, "renderer_paths": {}, + "cpu_frame_mean_ms": 1.0, "cpu_frame_p95_ms": 1.2, + "gpu_frame_mean_ms": 2.0, "gpu_frame_p95_ms": 2.4, + "measurement_wall_ms": 300.0, "passes": [{"label": "render"}], + } + with (mock.patch.object(quality, "capability_snapshot_failures", return_value=[]), + mock.patch.object(quality, "steady_state_renderer_failures", return_value=[])): + self.assertEqual(quality.telemetry_contract_failures(case, telemetry), []) + for updates in ( + {"gpu_timing_valid": False}, + {"gpu_timing_valid": None}, + {"gpu_timing_valid_frames": 119}, + {"timing_window_frames": 0, "gpu_timing_valid_frames": 0}, + {"timing_window_frames": True, "gpu_timing_valid_frames": True}, + ): + with self.subTest(updates=updates): + failures = quality.telemetry_contract_failures(case, telemetry | updates) + self.assertIn("telemetry GPU timing window is incomplete or unverified", failures) + for key in ("cpu_frame_mean_ms", "cpu_frame_p95_ms", "measurement_wall_ms", + "gpu_frame_mean_ms", "gpu_frame_p95_ms", "fixed_timestep", "render_scale"): + for invalid in (float("nan"), float("inf"), -1.0, True): + with self.subTest(key=key, invalid=invalid): + failures = quality.telemetry_contract_failures(case, telemetry | {key: invalid}) + self.assertTrue(any(key in failure for failure in failures)) + + def test_hard_budget_rejects_nonfinite_measurements(self) -> None: + case = {"budgets": {"machine_class": "test", "max_gpu_frame_p95_ms": 10.0}} + machine = {"id": "test", "hard_gate": True, "hard_metrics": ["gpu"]} + for value in (float("nan"), float("inf"), -1.0, True, "5"): + with self.subTest(value=value): + failures = quality.performance_failures(case, {"gpu_frame_p95_ms": value}, machine) + self.assertIn("gpu_frame_p95_ms unavailable for hard budget max_gpu_frame_p95_ms", failures) + class QualificationFailureOrderingTests(unittest.TestCase): def test_missing_baseline_does_not_suppress_runtime_contracts(self) -> None: