From 92fa66e026d17108f5a1140bc9a54ab3c34c6bda Mon Sep 17 00:00:00 2001 From: foxnne Date: Wed, 14 Oct 2026 12:25:47 -0500 Subject: [PATCH] core: the profiler counts GPU targets made per frame The profiler timed fizzy's work and the backend's submit, but not what a frame asks the driver to allocate. A window-tall frost on Safari remade ~5 render targets a frame and ran at 66 fps while the profiler said 1.2 ms of work. Now each backend keeps running totals of textures made, targets made, both destroyed, and target switches; the profiler takes the difference each frame and shows it per frame, per history frame, and per hitch. Co-Authored-By: Claude Opus 5.5 --- backend/src/GpuRenderer.zig | 3 + backend/src/Health.zig | 5 ++ backend/src/SDLBackend.zig | 6 ++ core/profile.zig | 97 +++++++++++++++++++++++------- core/profile/Gpu.zig | 86 ++++++++++++++++++++++++++ core/profile/Lookback.zig | 34 ++++++++++- plugins/devtools/src/Dashboard.zig | 26 +++++++- src/Entry.zig | 13 +++- src/backend/WebBackend.zig | 29 ++++++++- 9 files changed, 269 insertions(+), 30 deletions(-) create mode 100644 core/profile/Gpu.zig diff --git a/backend/src/GpuRenderer.zig b/backend/src/GpuRenderer.zig index 64055e837..87eccb081 100644 --- a/backend/src/GpuRenderer.zig +++ b/backend/src/GpuRenderer.zig @@ -1017,6 +1017,7 @@ pub fn textureCreate(self: *GpuRenderer, pixels: [*]const u8, options: dvui.Text .sampler = self.samplerFor(options.interpolation, options.wrap_u, options.wrap_v), }; try self.upload(tex, pixels, options.format, options.width, 0, 0, options.width, options.height); + health.counts.textures += 1; return .{ .ptr = tex, .width = options.width, .height = options.height, .format = options.format, .interpolation = options.interpolation, .wrap_u = options.wrap_u, .wrap_v = options.wrap_v }; } @@ -1093,6 +1094,7 @@ pub fn textureCreateTarget(self: *GpuRenderer, options: dvui.Texture.CreateOptio // Starts transparent (`Texture.Target.create`). .needs_clear = true, }; + health.counts.targets += 1; return .{ .ptr = tex, .width = options.width, .height = options.height, .format = options.format, .interpolation = options.interpolation, .wrap_u = .clamp, .wrap_v = .clamp }; } @@ -1119,6 +1121,7 @@ pub fn textureDestroy(self: *GpuRenderer, ptr: *anyopaque) void { // Released once the command buffers using it are done (SDL defers it). c.SDL_ReleaseGPUTexture(self.device, tex.texture); self.tex_pool.destroy(tex); + health.counts.destroyed += 1; } pub fn readPixels(self: *GpuRenderer, rect: dvui.Rect.Physical, pixels_out: [*]u8) !void { diff --git a/backend/src/Health.zig b/backend/src/Health.zig index 265125e45..57c0c8c02 100644 --- a/backend/src/Health.zig +++ b/backend/src/Health.zig @@ -70,6 +70,11 @@ pub const Counts = struct { target_switches: u32 = 0, /// Texture creations and updates uploaded. uploads: u32 = 0, + /// Textures made from pixels, render targets made, and either destroyed: GPU allocations, + /// which a frame that only draws makes none of (the profiler's `core.profile.Gpu`). + textures: u32 = 0, + targets: u32 = 0, + destroyed: u32 = 0, fn add(a: *Counts, b: Counts) void { inline for (std.meta.fields(Counts)) |f| @field(a, f.name) +|= @field(b, f.name); diff --git a/backend/src/SDLBackend.zig b/backend/src/SDLBackend.zig index 954b17fe0..1eebc977e 100644 --- a/backend/src/SDLBackend.zig +++ b/backend/src/SDLBackend.zig @@ -355,6 +355,12 @@ pub var frame_ended_hook: ?*const fn (end_micros: ?u32) bool = null; /// whether or not anyone reads them; reading them sorts the frame times and asks SDL (and AppKit) /// for their windows, so it is for a run's end or a once-a-second readout, not every frame. Main /// thread. +/// What every frame so far asked the GPU for, summed (`Health.total`): the profiler reads its +/// textures, targets and target switches at each frame's start (`core.profile.Gpu`). +pub fn gpuTotals() Health.Counts { + return Health.current.total; +} + pub fn health() Health.Snapshot { var s = Health.current.snapshot(); var n: c_int = 0; diff --git a/core/profile.zig b/core/profile.zig index 77f5331a3..42979ad6b 100644 --- a/core/profile.zig +++ b/core/profile.zig @@ -33,11 +33,13 @@ pub const FrameCauses = @import("profile/FrameCauses.zig"); /// Spans on any thread, each occurrence kept, while the profiler records (`span`, `spans`, /// `writeTrace`). pub const Spans = @import("profile/Spans.zig"); +/// What a frame asked the GPU to make and unmake, counted by the backend (`hostFrameBegin`). +pub const Gpu = @import("profile/Gpu.zig"); /// Bumped whenever `Profiler`'s layout changes. Part of the key the host publishes it under /// (`publish_key`), so a plugin built against another layout finds none and records nothing: the /// `abi` field it would check sits wherever its own layout put it, which a reordered struct moves. -pub const abi: u32 = 4; +pub const abi: u32 = 5; pub const max_entries = 1024; const max_depth = 48; @@ -89,6 +91,10 @@ pub const FrameStats = struct { worst_work_ns: u64 = 0, fps: f64 = 0, frames: u32 = 0, + /// Textures and render targets made and destroyed, and target switches, per frame: GPU work + /// no scope times, which can cost far more than the frame's own (`Gpu`). Null where the + /// backend does not count it. + gpu: ?Gpu.PerFrame = null, /// Pointer moves (mouse or touch) the app was given, per second (`countInput`). Where frames /// are drawn only when there is input, the frame rate can be no better than this. inputs_per_s: f64 = 0, @@ -111,6 +117,8 @@ pub const Profiler = struct { /// calls in it. history_work: [history_len]u32 = @splat(0), history_submit: [history_len]u32 = @splat(0), + /// Each frame's GPU counts, landed like its submit. + history_gpu: [history_len]Gpu = @splat(.{}), history_ns: [history_len][max_entries]u32 = @splat(@splat(0)), history_calls: [history_len][max_entries]u16 = @splat(@splat(0)), history_head: usize = 0, @@ -138,6 +146,12 @@ pub const Profiler = struct { win_submit_ns: u64 = 0, win_submit_frames: u32 = 0, win_inputs: u64 = 0, + win_gpu: Gpu.Sum = .{}, + /// The backend's GPU totals at the last frame's start, for the next frame's difference. Kept + /// whether or not the frame records, so the first recorded frame counts only itself. + gpu_total: ?Gpu = null, + /// When the last recorded frame ended, the time it is kept under as a hitch (`Lookback`). + recorded_at_ns: i128 = 0, /// This frame's pointer moves (`countInput`). frame_inputs: u32 = 0, /// The history slot the last frame was recorded in, for its submit to land in when the @@ -158,6 +172,7 @@ pub const Profiler = struct { self.win_submit_ns = 0; self.win_submit_frames = 0; self.win_inputs = 0; + self.win_gpu = .{}; self.frame_inputs = 0; self.recorded_slot = null; self.stats = .{}; @@ -165,18 +180,19 @@ pub const Profiler = struct { self.history_filled = 0; self.history_work = @splat(0); self.history_submit = @splat(0); + self.history_gpu = @splat(.{}); for (&self.history_ns) |*h| h.* = @splat(0); for (&self.history_calls) |*h| h.* = @splat(0); if (host_lookback) |lb| lb.reset(); } - /// The frame `ago` frames back (0 the latest recorded): its work, its submit (0 until the - /// next frame reports it), and entries' times and calls, indexed as `slice`. Null past what - /// the history holds. - pub fn historyFrame(self: *Profiler, ago: usize) ?struct { work_ns: u32, submit_ns: u32, ns: []const u32, calls: []const u16 } { + /// The frame `ago` frames back (0 the latest recorded): its work, its submit and GPU counts + /// (0 until the next frame reports them), and entries' times and calls, indexed as `slice`. + /// Null past what the history holds. + pub fn historyFrame(self: *Profiler, ago: usize) ?struct { work_ns: u32, submit_ns: u32, gpu: Gpu, ns: []const u32, calls: []const u16 } { if (ago >= self.history_filled) return null; const slot = (self.history_head + history_len - 1 - ago) % history_len; - return .{ .work_ns = self.history_work[slot], .submit_ns = self.history_submit[slot], .ns = self.history_ns[slot][0..self.count], .calls = self.history_calls[slot][0..self.count] }; + return .{ .work_ns = self.history_work[slot], .submit_ns = self.history_submit[slot], .gpu = self.history_gpu[slot], .ns = self.history_ns[slot][0..self.count], .calls = self.history_calls[slot][0..self.count] }; } pub fn slice(self: *Profiler) []Entry { @@ -248,7 +264,7 @@ pub const Profiler = struct { self.frame_inputs +|= n; } - fn frameBegin(self: *Profiler, prev_submit_ns: ?u64) void { + fn frameBegin(self: *Profiler, prev_submit_ns: ?u64, gpu_total: ?Gpu) void { const t = now(); self.active = self.enabled or t < self.wanted_until_ns; if (self.prev_frame_start != 0 and self.active and !self.paused) { @@ -260,6 +276,16 @@ pub const Profiler = struct { self.win_submit_ns += ns; self.win_submit_frames += 1; }; + // So do its GPU counts: the backend's totals since the frame before's start. + if (gpu_total) |total| { + if (self.recorded_slot) |slot| if (self.gpu_total) |prev| { + const g = total.since(prev); + self.history_gpu[slot] = g; + self.win_gpu.add(g); + if (host_lookback) |lb| lb.noteGpu(self.recorded_at_ns, g); + }; + self.gpu_total = total; + } self.recorded_slot = null; self.prev_frame_start = t; self.frame_start = t; @@ -283,7 +309,9 @@ pub const Profiler = struct { const slot = self.history_head; self.history_work[slot] = @intCast(@min(work, std.math.maxInt(u32))); self.history_submit[slot] = 0; + self.history_gpu[slot] = .{}; self.recorded_slot = slot; + self.recorded_at_ns = t; for (self.slice(), 0..) |e, i| { self.history_ns[slot][i] = @intCast(@min(e.frame_ns, std.math.maxInt(u32))); self.history_calls[slot][i] = @intCast(@min(e.frame_calls, std.math.maxInt(u16))); @@ -318,6 +346,7 @@ pub const Profiler = struct { .fps = @as(f64, @floatFromInt(self.win_frames)) / (elapsed / std.time.ns_per_s), .frames = self.win_frames, .inputs_per_s = @as(f64, @floatFromInt(self.win_inputs)) / (elapsed / std.time.ns_per_s), + .gpu = self.win_gpu.perFrame(), }; if (host_lookback) |lb| lb.foldWindow(.{ .end_ns = t, @@ -343,6 +372,7 @@ pub const Profiler = struct { self.win_submit_ns = 0; self.win_submit_frames = 0; self.win_inputs = 0; + self.win_gpu = .{}; } }; @@ -515,10 +545,11 @@ pub fn host() *Profiler { /// Host only, at the start of every frame, before anything is timed: start the frame, and /// publish the profiler to the plugins through the shared window. `prev_submit_ns` is how long /// the backend took to end the last frame after fizzy's part of it (`FrameStats.submit_ns`), -/// where the backend measures that. -pub fn hostFrameBegin(prev_submit_ns: ?u64) void { +/// where the backend measures that; `gpu_total` the backend's running GPU totals (`Gpu`), where +/// it counts them. +pub fn hostFrameBegin(prev_submit_ns: ?u64, gpu_total: ?Gpu) void { is_host = true; - host_profiler.frameBegin(prev_submit_ns); + host_profiler.frameBegin(prev_submit_ns, gpu_total); dvui.dataSet(null, publish_id, publish_key, @as(usize, @intFromPtr(&host_profiler))); if (host_lookback == null and host_profiler.active) host_lookback = Lookback.create(std.heap.page_allocator, max_entries) catch null; if (host_lookback) |lb| dvui.dataSet(null, publish_id, lookback_key, @as(usize, @intFromPtr(lb))); @@ -657,6 +688,7 @@ pub fn report(p: *const Profiler, w: *std.Io.Writer, opts: ReportOptions) std.Io st.fps, millis(st.interval_ns), millis(st.work_ns), millis(@floatFromInt(st.worst_work_ns)), }); if (st.submit_ns) |sub| try w.print(".submit_ms = {d:.3}, ", .{millis(sub)}); + if (st.gpu) |g| try w.print(".gpu = .{{ .textures = {d:.2}, .targets = {d:.2}, .destroyed = {d:.2}, .target_switches = {d:.2} }}, ", .{ g.textures, g.targets, g.destroyed, g.target_switches }); try w.print(".frames = {d}, .inputs_per_s = {d:.1} }},\n", .{ st.frames, st.inputs_per_s }); // Each owner's own time: the self time of every scope it owns. @@ -768,8 +800,8 @@ fn writeHitches(p: *const Profiler, lb: *const Lookback, w: *std.Io.Writer, opts return ss[a] > ss[b]; } }.lt); - try w.print(" .{{ .ago_s = {d:.1}, .work_ms = {d:.3}, .top = .{{\n", .{ - @as(f64, @floatFromInt(t - h.at_ns)) / std.time.ns_per_s, millis(@floatFromInt(h.work_ns)), + try w.print(" .{{ .ago_s = {d:.1}, .work_ms = {d:.3}, .gpu = .{{ .textures = {d}, .targets = {d}, .destroyed = {d}, .target_switches = {d} }}, .top = .{{\n", .{ + @as(f64, @floatFromInt(t - h.at_ns)) / std.time.ns_per_s, millis(@floatFromInt(h.work_ns)), h.gpu.textures, h.gpu.targets, h.gpu.destroyed, h.gpu.target_switches, }); for (order[0..@min(n, opts.top)]) |i| { if (millis(@floatFromInt(self_ns[i])) < opts.min_ms) break; @@ -813,7 +845,7 @@ test "a report says what each owner and scope cost, as ZON that reads back" { var p: Profiler = .{ .wanted_until_ns = std.math.maxInt(i96) }; // Two frames a window apart, so the second publishes averages. for (0..2) |_| { - p.frameBegin(null); + p.frameBegin(null, null); const outer = p.open("fizzy", "draw").?; const inner = p.open("text", "surface").?; const until = now() + 2 * std.time.ns_per_ms; @@ -829,7 +861,7 @@ test "a report says what each owner and scope cost, as ZON that reads back" { const text = w.buffered(); const Report = struct { - frame: struct { fps: f64, interval_ms: f64, work_ms: f64, worst_work_ms: f64, submit_ms: ?f64 = null, frames: u32, inputs_per_s: f64 }, + frame: struct { fps: f64, interval_ms: f64, work_ms: f64, worst_work_ms: f64, submit_ms: ?f64 = null, gpu: ?Gpu.PerFrame = null, frames: u32, inputs_per_s: f64 }, owners: []const struct { owner: []const u8, self_ms: f64 }, scopes: []const struct { owner: []const u8, name: []const u8, avg_ms: f64, self_ms: f64, max_ms: f64, calls: f64, parent: ?u16 = null }, }; @@ -847,16 +879,16 @@ test "a report says what each owner and scope cost, as ZON that reads back" { test "nothing records unless the window is open or someone asked" { dvui.io = std.testing.io; var p: Profiler = .{}; - p.frameBegin(null); + p.frameBegin(null, null); try std.testing.expect(!p.active); p.wanted_until_ns = now() + std.time.ns_per_s; - p.frameBegin(null); + p.frameBegin(null, null); try std.testing.expect(p.active); } test "scopes nest, and a frame's time folds into the window's averages" { var p: Profiler = .{ .enabled = true }; - p.frameBegin(null); + p.frameBegin(null, null); const a = p.open("pixi", "draw").?; const b = p.open("pixi", "bubbles").?; p.close(b); @@ -874,7 +906,7 @@ test "scopes nest, and a frame's time folds into the window's averages" { test "a scope whose end was skipped does not strand the ones after it" { var p: Profiler = .{ .enabled = true }; - p.frameBegin(null); + p.frameBegin(null, null); const a = p.open("fizzy", "frame").?; _ = p.open("x", "lost").?; // never closed p.close(a); @@ -883,18 +915,39 @@ test "a scope whose end was skipped does not strand the ones after it" { test "a frame's submit lands in its own slot when the next frame begins" { var p: Profiler = .{ .enabled = true }; - p.frameBegin(null); + p.frameBegin(null, null); p.countInput(3); p.frameEnd(); try std.testing.expectEqual(@as(u32, 0), p.historyFrame(0).?.submit_ns); - p.frameBegin(5 * std.time.ns_per_ms); + p.frameBegin(5 * std.time.ns_per_ms, null); try std.testing.expectEqual(@as(u32, 5 * std.time.ns_per_ms), p.historyFrame(0).?.submit_ns); try std.testing.expectEqual(@as(u64, 3), p.win_inputs); // Paused, a frame is not recorded and its submit goes nowhere. p.frameEnd(); p.paused = true; - p.frameBegin(null); + p.frameBegin(null, null); p.frameEnd(); - p.frameBegin(7 * std.time.ns_per_ms); + p.frameBegin(7 * std.time.ns_per_ms, null); try std.testing.expectEqual(@as(u32, 0), p.historyFrame(0).?.submit_ns); } + +test "a frame's GPU counts land in its own slot and the window's average, not before it records" { + dvui.io = std.testing.io; + var p: Profiler = .{}; + // Closed: the totals are followed, nothing is kept. + p.frameBegin(null, .{ .targets = 100 }); + p.frameEnd(); + p.enabled = true; + p.frameBegin(null, .{ .targets = 103 }); + p.frameEnd(); + try std.testing.expectEqual(@as(u32, 0), p.historyFrame(0).?.gpu.targets); + // The frame recorded made 4 targets and switched 6 times, counted as the next one begins. + p.frameBegin(null, .{ .targets = 107, .target_switches = 6 }); + try std.testing.expectEqual(@as(u32, 4), p.historyFrame(0).?.gpu.targets); + try std.testing.expectEqual(@as(u32, 6), p.historyFrame(0).?.gpu.target_switches); + p.frameEnd(); + p.frameBegin(null, .{ .targets = 107, .target_switches = 6 }); + p.win_start -= window_ns; + p.frameEnd(); + try std.testing.expectEqual(@as(f64, 2), p.stats.gpu.?.targets); +} diff --git a/core/profile/Gpu.zig b/core/profile/Gpu.zig new file mode 100644 index 000000000..f9966a4aa --- /dev/null +++ b/core/profile/Gpu.zig @@ -0,0 +1,86 @@ +//! What a frame asked the GPU to make and unmake: textures, render targets, and the switches +//! between targets. Each costs little to ask for and can cost a great deal where the driver does +//! it (WebGL on Safari's ANGLE over Metal recreates a framebuffer in milliseconds), none of it +//! inside any scope the profiler times — so the profiler counts it rather than times it. +//! +//! The backend counts, where every image's textures pass (`dvui.textureCreate` and +//! `Texture.Target.create` from the host and every plugin end up in the host's backend): running +//! totals that only grow, an integer add beside each call into the GPU. The profiler reads them at +//! each frame's start (`core.profile.hostFrameBegin`) and keeps the difference as the last frame's. +//! The same struct is both: a backend's totals, wrapping, and a frame's counts (`since`). +//! +//! std-only, so it tests with `Lookback`. +const Gpu = @This(); + +const std = @import("std"); + +/// Textures made from pixels (`textureCreate`). +textures: u32 = 0, +/// Render targets made (`textureCreateTarget`). +targets: u32 = 0, +/// Textures and targets destroyed. +destroyed: u32 = 0, +/// Times drawing moved from one target (or the window) to another. +target_switches: u32 = 0, + +/// The counts from totals `prev` to totals `self`: what was asked in between. Wraps, as the +/// totals do. +pub fn since(self: Gpu, prev: Gpu) Gpu { + var out: Gpu = .{}; + inline for (std.meta.fields(Gpu)) |f| @field(out, f.name) = @field(self, f.name) -% @field(prev, f.name); + return out; +} + +/// Any texture or target made or destroyed: what costs the driver an allocation. +pub fn allocates(self: Gpu) bool { + return self.textures != 0 or self.targets != 0 or self.destroyed != 0; +} + +/// Counts summed over many frames, for their average (`perFrame`). +pub const Sum = struct { + textures: u64 = 0, + targets: u64 = 0, + destroyed: u64 = 0, + target_switches: u64 = 0, + frames: u32 = 0, + + pub fn add(self: *Sum, g: Gpu) void { + inline for (std.meta.fields(Gpu)) |f| @field(self, f.name) += @field(g, f.name); + self.frames += 1; + } + + /// Each count per frame; null when no frame was counted. + pub fn perFrame(self: Sum) ?PerFrame { + if (self.frames == 0) return null; + const n: f64 = @floatFromInt(self.frames); + var out: PerFrame = .{}; + inline for (std.meta.fields(Gpu)) |f| @field(out, f.name) = @as(f64, @floatFromInt(@field(self, f.name))) / n; + return out; + } +}; + +/// Counts per frame, averaged. +pub const PerFrame = struct { + textures: f64 = 0, + targets: f64 = 0, + destroyed: f64 = 0, + target_switches: f64 = 0, +}; + +test "a frame's counts are the totals' difference, across a wrap" { + const prev: Gpu = .{ .textures = std.math.maxInt(u32), .targets = 3 }; + const now: Gpu = .{ .textures = 1, .targets = 8, .target_switches = 4 }; + const d = now.since(prev); + try std.testing.expectEqual(@as(u32, 2), d.textures); + try std.testing.expectEqual(@as(u32, 5), d.targets); + try std.testing.expect(d.allocates()); + try std.testing.expect(!(Gpu{ .target_switches = 9 }).allocates()); + + var sum: Sum = .{}; + try std.testing.expectEqual(@as(?PerFrame, null), sum.perFrame()); + sum.add(.{ .targets = 5 }); + sum.add(.{ .targets = 4, .target_switches = 2 }); + const pf = sum.perFrame().?; + try std.testing.expectEqual(@as(f64, 4.5), pf.targets); + try std.testing.expectEqual(@as(f64, 1), pf.target_switches); +} diff --git a/core/profile/Lookback.zig b/core/profile/Lookback.zig index b97a9cfa6..c153d019f 100644 --- a/core/profile/Lookback.zig +++ b/core/profile/Lookback.zig @@ -10,10 +10,11 @@ const Lookback = @This(); const std = @import("std"); +const Gpu = @import("Gpu.zig"); /// Bumped whenever the layout changes: part of the key the profiler publishes it under, so a /// plugin built against another layout finds none. -pub const abi: u32 = 1; +pub const abi: u32 = 2; /// Half-second windows kept: 30 seconds. pub const windows = 60; /// Frames over budget kept, the newest replacing the oldest. @@ -57,6 +58,9 @@ pub const Hitch = struct { work_ns: u64 = 0, /// How many entries it recorded (the profiler's count then). count: u16 = 0, + /// What it asked the GPU to make and unmake, its submit included: known only once the next + /// frame has begun (`noteGpu`), zero until then. + gpu: Gpu = .{}, }; pub fn create(gpa: std.mem.Allocator, entries: usize) error{OutOfMemory}!*Lookback { @@ -145,6 +149,14 @@ pub fn noteFrame(self: *Lookback, at_ns: i128, work_ns: u64, ns: []const u32, ca self.hitch_filled = @min(self.hitch_filled + 1, hitches_kept); } +/// The GPU counts of the frame that ended at `at_ns`, now that the next one has begun: kept with +/// it if it was kept as a hitch (the newest), dropped otherwise. +pub fn noteGpu(self: *Lookback, at_ns: i128, gpu: Gpu) void { + if (self.hitch_filled == 0) return; + const newest = &self.hitch[(self.hitch_head + hitches_kept - 1) % hitches_kept]; + if (newest.at_ns == at_ns) newest.gpu = gpu; +} + /// An entry's cost per frame over a span of windows. pub const Cost = struct { avg_ns: f64 = 0, @@ -203,12 +215,12 @@ pub fn costs(self: *const Lookback, ms: u32, out: []Cost) Span { } /// A kept hitch, `ago` back (0 the newest): its frame's work, and each entry's time and calls. -pub fn hitchAt(self: *const Lookback, ago: usize) ?struct { at_ns: i128, work_ns: u64, ns: []const u32, calls: []const u16 } { +pub fn hitchAt(self: *const Lookback, ago: usize) ?struct { at_ns: i128, work_ns: u64, gpu: Gpu, ns: []const u32, calls: []const u16 } { if (ago >= self.hitch_filled) return null; const slot = (self.hitch_head + hitches_kept - 1 - ago) % hitches_kept; const h = self.hitch[slot]; const at = slot * self.entries; - return .{ .at_ns = h.at_ns, .work_ns = h.work_ns, .ns = self.hitch_ns[at..][0..h.count], .calls = self.hitch_calls[at..][0..h.count] }; + return .{ .at_ns = h.at_ns, .work_ns = h.work_ns, .gpu = h.gpu, .ns = self.hitch_ns[at..][0..h.count], .calls = self.hitch_calls[at..][0..h.count] }; } fn clamp32(v: u64) u32 { @@ -270,3 +282,19 @@ test "only frames over budget are kept as hitches, newest first" { lb.reset(); try std.testing.expectEqual(@as(?@TypeOf(h), null), lb.hitchAt(0)); } + +test "a hitch keeps the GPU counts its frame reports late, and no other frame's" { + const lb = try create(std.testing.allocator, 1); + defer lb.destroy(); + lb.budget_ns = 10; + lb.noteFrame(5, 20, &.{1}, &.{1}); + lb.noteGpu(5, .{ .targets = 6 }); + // A frame under budget is not kept, and its counts do not land on the hitch before it. + lb.noteFrame(6, 1, &.{1}, &.{1}); + lb.noteGpu(6, .{ .targets = 9 }); + try std.testing.expectEqual(@as(u32, 6), lb.hitchAt(0).?.gpu.targets); +} + +test { + _ = Gpu; +} diff --git a/plugins/devtools/src/Dashboard.zig b/plugins/devtools/src/Dashboard.zig index 6b1bf0739..20d059ddc 100644 --- a/plugins/devtools/src/Dashboard.zig +++ b/plugins/devtools/src/Dashboard.zig @@ -194,12 +194,14 @@ fn drawStats(p: *profile.Profiler) void { run.stat("frame", "{d}", .{-@as(i64, @intCast(ago))}, ""); run.stat("work", "{d:>6.2}", .{ms(@floatFromInt(f.work_ns))}, "ms"); if (s.submit_ns != null) run.stat("submit", "{d:>6.2}", .{ms(@floatFromInt(f.submit_ns))}, "ms"); + if (s.gpu != null) run.gpuMade(f.gpu); run.note(if (locked != null) "locked" else "under the pointer"); return; }; if (picked_last.held) |h| { run.stat("hitch", "{d:.0}", .{secondsAgo(h.at_ns)}, "s ago"); run.stat("work", "{d:>6.2}", .{ms(@floatFromInt(h.work_ns))}, "ms"); + if (s.gpu != null) run.gpuMade(h.gpu); return; } run.stat("", "{d:>3.0}", .{s.fps}, "fps"); @@ -207,6 +209,12 @@ fn drawStats(p: *profile.Profiler) void { run.stat("work", "{d:>6.2}", .{ms(s.work_ns)}, "ms"); if (s.submit_ns) |ns| run.stat("submit", "{d:>6.2}", .{ms(ns)}, "ms"); run.stat("worst", "{d:>6.2}", .{ms(@floatFromInt(s.worst_work_ns))}, "ms"); + // What no scope times: GPU allocations, which a frame that only draws makes none of. + if (s.gpu) |g| { + run.stat("textures", "{d:>4.1}", .{g.textures}, "/f"); + run.stat("targets", "{d:>4.1}", .{g.targets}, "/f"); + run.stat("switches", "{d:>4.1}", .{g.target_switches}, "/f"); + } run.stat("input", "{d:>3.0}", .{s.inputs_per_s}, "/s"); run.stat("", "{d:>3}", .{s.frames}, "frames"); } @@ -225,6 +233,14 @@ const Runs = struct { self.tl.addText(" ", .{ .font = mono }); } + /// One frame's GPU allocations, said only when there were any: "made 6 targets". + fn gpuMade(self: Runs, g: profile.Gpu) void { + if (g.textures > 0) self.stat("made", "{d}", .{g.textures}, "textures"); + if (g.targets > 0) self.stat("made", "{d}", .{g.targets}, "targets"); + if (g.destroyed > 0) self.stat("destroyed", "{d}", .{g.destroyed}, ""); + self.stat("switches", "{d}", .{g.target_switches}, ""); + } + fn note(self: Runs, text: []const u8) void { self.tl.addText(text, .{ .font = dvui.Font.theme(.mono), .color_text = .{ .color = dvui.themeGet().color(.control, .text).opacity(0.6) } }); } @@ -392,7 +408,7 @@ fn secondsAgo(at_ns: i128) f64 { return @as(f64, @floatFromInt(core.perf.nanoTimestamp() - at_ns)) / std.time.ns_per_s; } -const Held = struct { at_ns: i128, work_ns: u64, ns: []const u32, calls: []const u16 }; +const Held = struct { at_ns: i128, work_ns: u64, gpu: profile.Gpu, ns: []const u32, calls: []const u16 }; /// The kept hitches as a row of chips, newest first, each saying when and how long; a click holds /// one (and another click lets it go). The held one, while it is still kept. @@ -401,7 +417,7 @@ fn heldHitch() ?Held { const lb = profile.lookback() orelse return null; var ago: usize = 0; while (lb.hitchAt(ago)) |h| : (ago += 1) { - if (h.at_ns == at) return .{ .at_ns = h.at_ns, .work_ns = h.work_ns, .ns = h.ns, .calls = h.calls }; + if (h.at_ns == at) return .{ .at_ns = h.at_ns, .work_ns = h.work_ns, .gpu = h.gpu, .ns = h.ns, .calls = h.calls }; } // Fell out of the list: let it go. held_hitch = null; @@ -427,7 +443,11 @@ fn drawHitchChips() void { var ago: usize = 0; while (lb.hitchAt(ago)) |h| : (ago += 1) { const is_held = held_hitch != null and held_hitch.? == h.at_ns; - const text = std.fmt.bufPrint(&buf, "{d:.0} s ago · {d:.1} ms", .{ secondsAgo(h.at_ns), @as(f64, @floatFromInt(h.work_ns)) / std.time.ns_per_ms }) catch ""; + const made = h.gpu.textures + h.gpu.targets; + const text = (if (made > 0) + std.fmt.bufPrint(&buf, "{d:.0} s ago · {d:.1} ms · made {d}", .{ secondsAgo(h.at_ns), @as(f64, @floatFromInt(h.work_ns)) / std.time.ns_per_ms, made }) + else + std.fmt.bufPrint(&buf, "{d:.0} s ago · {d:.1} ms", .{ secondsAgo(h.at_ns), @as(f64, @floatFromInt(h.work_ns)) / std.time.ns_per_ms })) catch ""; if (dvui.button(@src(), text, .{}, .{ .id_extra = ago, .style = if (is_held) .highlight else .control, .margin = .all(2), .padding = .{ .x = 6, .w = 6, .y = 2, .h = 2 } })) { held_hitch = if (is_held) null else h.at_ns; } diff --git a/src/Entry.zig b/src/Entry.zig index 292be1000..0708f394c 100644 --- a/src/Entry.zig +++ b/src/Entry.zig @@ -473,7 +473,7 @@ pub fn AppFrame() !dvui.App.Result { // dvui's refresh records, while someone reads them: the profiler, as frame causes, or a // `FIZZY_LOG_REFRESH` run. _ = dvui.debug.logRefresh(refresh_log_active or fizzy.core.profile.recordingCauses()); - fizzy.core.profile.hostFrameBegin(lastSubmitNs()); + fizzy.core.profile.hostFrameBegin(lastSubmitNs(), gpuTotals()); defer fizzy.core.profile.hostFrameEnd(); revealOnceDrawn(false); defer revealOnceDrawn(true); @@ -499,6 +499,17 @@ fn lastSubmitNs() ?u64 { return null; } +/// The backend's running GPU totals — textures and targets made and destroyed, target switches — +/// as the profiler counts them (`core.profile.Gpu`), where the backend keeps them. Every image's +/// textures pass through the host's backend, so these cover the plugins' too. +fn gpuTotals() ?fizzy.core.profile.Gpu { + if (comptime !@hasDecl(dvui.backend, "gpuTotals")) return null; + const t = dvui.backend.gpuTotals(); + var out: fizzy.core.profile.Gpu = .{}; + inline for (std.meta.fields(fizzy.core.profile.Gpu)) |f| @field(out, f.name) = @truncate(@field(t, f.name)); + return out; +} + /// One run of the app's frame. fn frameOnce() !dvui.App.Result { // First, before anything reads `dvui.events()` or the frame target binds: a playing demo adds diff --git a/src/backend/WebBackend.zig b/src/backend/WebBackend.zig index 7cf3fddc2..fc3a0675b 100644 --- a/src/backend/WebBackend.zig +++ b/src/backend/WebBackend.zig @@ -74,6 +74,25 @@ pub var last_submit_ns: u64 = 0; /// frame now whatever `end` said. fizzy's `automation` service uses it: it notes whether dvui /// went quiet (`settled`), and runs one more frame when a caller was told "not yet", so the caller /// sees the answer change without asking for frames itself. +/// What the backend has asked WebGL to make and unmake since it started: textures from pixels, +/// render targets (each a texture, and a framebuffer once drawn into), either destroyed, and the +/// switches between targets. Running totals, an integer add beside each call into `web.js`; the +/// profiler reads them each frame (`gpuTotals`, `core.profile.Gpu`). Every image's textures — +/// the plugins' side modules' too — are made here. +const GpuTotals = struct { + textures: u32 = 0, + targets: u32 = 0, + destroyed: u32 = 0, + target_switches: u32 = 0, +}; +var gpu_totals: GpuTotals = .{}; +/// The target the stream draws into, for counting switches: 0 the screen. +var gpu_target: usize = 0; + +pub fn gpuTotals() GpuTotals { + return gpu_totals; +} + pub var frame_ended_hook: ?*const fn (end_micros: ?u32) bool = null; pub var win: dvui.Window = undefined; @@ -735,6 +754,7 @@ pub fn begin(_: *WebBackend, arena_in: std.mem.Allocator) !void { batch = .{}; // `web.js` starts every frame on the screen, in dvui's own program. target_is_fb = false; + gpu_target = 0; program = null; blend_override = null; } @@ -950,6 +970,7 @@ pub fn textureCreate(_: *WebBackend, pixels: [*]const u8, options: dvui.Texture. }; const id = wasm.wasm_textureCreate(pixels, options.width, options.height, wasm_interp, wasm_wrap_u, wasm_wrap_v); + gpu_totals.textures +%= 1; return dvui.Texture{ .ptr = @ptrFromInt(id), .width = options.width, @@ -1015,6 +1036,7 @@ pub fn textureCreateTarget(_: *WebBackend, options: dvui.Texture.CreateOptions) wasm.wasm_textureCreatePreciseTarget(options.width, options.height, wasm_interp, wasm_wrap_u, wasm_wrap_v) else wasm.wasm_textureCreateTarget(options.width, options.height, wasm_interp, wasm_wrap_u, wasm_wrap_v); + gpu_totals.targets +%= 1; return dvui.TextureTarget{ .ptr = @ptrFromInt(id), .width = options.width, @@ -1043,8 +1065,11 @@ pub fn textureFromTargetTemp(_: *WebBackend, texture: dvui.TextureTarget) !dvui. } pub fn renderTarget(_: *WebBackend, texture: ?dvui.TextureTarget) !void { - try marker(Command.switch_target, if (texture) |tex| @intCast(@intFromPtr(tex.ptr)) else 0); + const id: usize = if (texture) |tex| @intFromPtr(tex.ptr) else 0; + try marker(Command.switch_target, @intCast(id)); target_is_fb = texture != null; + if (id != gpu_target) gpu_totals.target_switches +%= 1; + gpu_target = id; } pub fn textureReadTarget(_: *WebBackend, texture: dvui.TextureTarget, pixels_out: [*]u8) !void { @@ -1056,12 +1081,14 @@ pub fn textureDestroy(_: *WebBackend, texture: dvui.Texture) void { if (pendingUses(@intCast(@intFromPtr(texture.ptr)))) flushBatch(); _ = blends.remove(@intFromPtr(texture.ptr)); wasm.wasm_textureDestroy(@intCast(@intFromPtr(texture.ptr))); + gpu_totals.destroyed +%= 1; } pub fn textureDestroyTarget(_: *WebBackend, texture: dvui.Texture.Target) void { if (pendingUses(@intCast(@intFromPtr(texture.ptr)))) flushBatch(); _ = blends.remove(@intFromPtr(texture.ptr)); wasm.wasm_textureDestroy(@intCast(@intFromPtr(texture.ptr))); + gpu_totals.destroyed +%= 1; } pub fn textInputRect(_: *WebBackend, rect: ?dvui.Rect.Natural) void {