From 48ea4142d14f9def81fb468528b1af91af1cadb4 Mon Sep 17 00:00:00 2001 From: ScepticalRabbit Date: Wed, 22 Jul 2026 20:43:14 +0100 Subject: [PATCH 1/6] Fixed bug in timing reports for .bench mode for multiple threads --- src/dev_support/benchcommon.zig | 2 +- src/dev_support/benchdicuq.zig | 36 ++++++++++++++++++++------ src/dev_support/benchstats.zig | 29 ++++++--------------- src/riley/zig/rasterengine_common.zig | 22 ++++++++++++++-- src/riley/zig/rasterreport.zig | 2 ++ src/riley/zig/report.zig | 21 ++++++++++----- src/riley/zig/riley.zig | 1 + src/riley/zig/validateinput.zig | 37 +++++++++++++++++++++++++++ 8 files changed, 112 insertions(+), 38 deletions(-) diff --git a/src/dev_support/benchcommon.zig b/src/dev_support/benchcommon.zig index 49179ec4..dbfae036 100644 --- a/src/dev_support/benchcommon.zig +++ b/src/dev_support/benchcommon.zig @@ -1356,7 +1356,7 @@ pub fn calcBenchmarkCSVValuesFromResult( const conv_ms = 1.0 / 1e6; const cam_inv_ms = result.cam_ms; const resolve_ms = result.resolve_ms; - const elem_loop_ms = result.raster_ms - cam_inv_ms - resolve_ms; + const elem_loop_ms = result.pipeline_times.elem_loop * conv_ms; return .{ .total_elems = @floatFromInt(result.total_elems), .vis_elems = @floatFromInt(result.vis_elems), diff --git a/src/dev_support/benchdicuq.zig b/src/dev_support/benchdicuq.zig index 18c9e41c..b85a179b 100644 --- a/src/dev_support/benchdicuq.zig +++ b/src/dev_support/benchdicuq.zig @@ -57,6 +57,7 @@ pub const DicuqFrameRow = struct { shaded_px: u64, geom_time_ms: F, cam_time_ms: F, + elem_loop_time_ms: F, resolve_time_ms: F, raster_time_ms: F, save_time_ms: F, @@ -77,6 +78,7 @@ pub const DicuqE2ERow = struct { shaded_px: u64, geom_time_ms: F, cam_time_ms: F, + elem_loop_time_ms: F, resolve_time_ms: F, raster_time_ms: F, save_time_ms: F, @@ -119,6 +121,7 @@ const DicuqFrameStatsRow = struct { shaded_px: F, geom_time_ms: F, cam_time_ms: F, + elem_loop_time_ms: F, resolve_time_ms: F, raster_time_ms: F, save_time_ms: F, @@ -138,6 +141,7 @@ const DicuqE2EStatsRow = struct { shaded_px: F, geom_time_ms: F, cam_time_ms: F, + elem_loop_time_ms: F, resolve_time_ms: F, raster_time_ms: F, save_time_ms: F, @@ -436,6 +440,8 @@ fn aggregateFrameTimes( capture.bench_log.frame_times.raster_loop; frame_times.cam_invert += capture.bench_log.frame_times.cam_invert; + frame_times.elem_loop += + capture.bench_log.frame_times.elem_loop; frame_times.scratch_resolve += capture.bench_log.frame_times.scratch_resolve; frame_times.save_frame += @@ -609,6 +615,7 @@ fn buildFrameRows( .shaded_px = capture.bench_log.total_shaded_px, .geom_time_ms = geom_time_ns / 1e6, .cam_time_ms = capture.bench_log.frame_times.cam_invert / 1e6, + .elem_loop_time_ms = capture.bench_log.frame_times.elem_loop / 1e6, .resolve_time_ms = capture.bench_log.frame_times.scratch_resolve / 1e6, .raster_time_ms = capture.bench_log.frame_times.raster_loop / 1e6, .save_time_ms = capture.bench_log.frame_times.save_frame / 1e6, @@ -641,6 +648,7 @@ fn buildE2ESummaryRow( e2e_ms: ?F, ) DicuqE2ERow { var geom_time_ms: F = 0.0; + var elem_loop_time_ms: F = 0.0; var raster_time_ms: F = 0.0; var save_time_ms: F = 0.0; var frame_time_ms: F = 0.0; @@ -657,6 +665,7 @@ fn buildE2ESummaryRow( } } geom_time_ms += frame_row.geom_time_ms; + elem_loop_time_ms += frame_row.elem_loop_time_ms; raster_time_ms += frame_row.raster_time_ms; save_time_ms += frame_row.save_time_ms; frame_time_ms += frame_row.frame_time_ms; @@ -712,6 +721,7 @@ fn buildE2ESummaryRow( } break :blk cam_sum; }, + .elem_loop_time_ms = elem_loop_time_ms, .resolve_time_ms = blk: { var res_sum: F = 0.0; for (frame_rows) |fr| { @@ -817,8 +827,7 @@ fn appendFrameRowsCSV( ); for (frame_rows) |frame_row| { - const elem_loop_ms = frame_row.raster_time_ms - - frame_row.cam_time_ms - frame_row.resolve_time_ms; + const elem_loop_ms = frame_row.elem_loop_time_ms; const row = try std.fmt.allocPrint( allocator, "{d},{s},{d},{d},{d},{d},{d},{d}," ++ @@ -881,8 +890,7 @@ fn appendE2ERowsCSV( else try allocator.dupe(u8, ""); defer allocator.free(e2e_tp_text); - const elem_loop_ms = e2e_row.raster_time_ms - - e2e_row.cam_time_ms - e2e_row.resolve_time_ms; + const elem_loop_ms = e2e_row.elem_loop_time_ms; const row = try std.fmt.allocPrint( allocator, @@ -960,6 +968,8 @@ fn calcFrameStatsRow( defer allocator.free(geom_vals); var cam_vals = try allocator.alloc(F, count); defer allocator.free(cam_vals); + var elem_loop_vals = try allocator.alloc(F, count); + defer allocator.free(elem_loop_vals); var resolve_vals = try allocator.alloc(F, count); defer allocator.free(resolve_vals); var raster_vals = try allocator.alloc(F, count); @@ -992,6 +1002,7 @@ fn calcFrameStatsRow( total_px_vals[ii] = @floatFromInt(frame_row.total_px); geom_vals[ii] = frame_row.geom_time_ms; cam_vals[ii] = frame_row.cam_time_ms; + elem_loop_vals[ii] = frame_row.elem_loop_time_ms; resolve_vals[ii] = frame_row.resolve_time_ms; raster_vals[ii] = frame_row.raster_time_ms; save_vals[ii] = frame_row.save_time_ms; @@ -1040,6 +1051,10 @@ fn calcFrameStatsRow( try calcFieldStats(allocator, cam_vals), kind, ), + .elem_loop_time_ms = selectDicuqStat( + try calcFieldStats(allocator, elem_loop_vals), + kind, + ), .resolve_time_ms = selectDicuqStat( try calcFieldStats(allocator, resolve_vals), kind, @@ -1114,6 +1129,8 @@ fn calcE2EStatsRow( defer allocator.free(geom_vals); var cam_vals = try allocator.alloc(F, count); defer allocator.free(cam_vals); + var elem_loop_vals = try allocator.alloc(F, count); + defer allocator.free(elem_loop_vals); var resolve_vals = try allocator.alloc(F, count); defer allocator.free(resolve_vals); var raster_vals = try allocator.alloc(F, count); @@ -1145,6 +1162,7 @@ fn calcE2EStatsRow( shaded_vals[rr] = @floatFromInt(row.shaded_px); geom_vals[rr] = row.geom_time_ms; cam_vals[rr] = row.cam_time_ms; + elem_loop_vals[rr] = row.elem_loop_time_ms; resolve_vals[rr] = row.resolve_time_ms; raster_vals[rr] = row.raster_time_ms; save_vals[rr] = row.save_time_ms; @@ -1195,6 +1213,10 @@ fn calcE2EStatsRow( try calcFieldStats(allocator, cam_vals), kind, ), + .elem_loop_time_ms = selectDicuqStat( + try calcFieldStats(allocator, elem_loop_vals), + kind, + ), .resolve_time_ms = selectDicuqStat( try calcFieldStats(allocator, resolve_vals), kind, @@ -1290,8 +1312,7 @@ fn appendFrameStatsRowsCSV( else try allocator.dupe(u8, ""); defer allocator.free(e2e_tp_text); - const elem_loop_ms = stats_row.raster_time_ms - - stats_row.cam_time_ms - stats_row.resolve_time_ms; + const elem_loop_ms = stats_row.elem_loop_time_ms; const row = try std.fmt.allocPrint( allocator, "{d},{s},{s},{d:.6},{d:.6},{d:.6},{d:.6}," ++ @@ -1371,8 +1392,7 @@ fn appendE2EStatsRowsCSV( else try allocator.dupe(u8, ""); defer allocator.free(e2e_tp_text); - const elem_loop_ms = stats_row.raster_time_ms - - stats_row.cam_time_ms - stats_row.resolve_time_ms; + const elem_loop_ms = stats_row.elem_loop_time_ms; const row = try std.fmt.allocPrint( allocator, "{s},{s},{d:.6},{d:.6},{d:.6},{d:.6}," ++ diff --git a/src/dev_support/benchstats.zig b/src/dev_support/benchstats.zig index 1260ea40..0e8ea43e 100644 --- a/src/dev_support/benchstats.zig +++ b/src/dev_support/benchstats.zig @@ -22,6 +22,7 @@ pub const CaseSamples = struct { geom_times: []F, raster_times: []F, cam_times: []F, + elem_loop_times: []F, resolve_times: []F, save_frame_times: []F, frame_times: []F, @@ -49,6 +50,7 @@ pub const CaseSamples = struct { .geom_times = try allocator.alloc(F, runs), .raster_times = try allocator.alloc(F, runs), .cam_times = try allocator.alloc(F, runs), + .elem_loop_times = try allocator.alloc(F, runs), .resolve_times = try allocator.alloc(F, runs), .save_frame_times = try allocator.alloc(F, runs), .frame_times = try allocator.alloc(F, runs), @@ -77,6 +79,7 @@ pub const CaseSamples = struct { allocator.free(self.geom_times); allocator.free(self.raster_times); allocator.free(self.cam_times); + allocator.free(self.elem_loop_times); allocator.free(self.resolve_times); allocator.free(self.save_frame_times); allocator.free(self.frame_times); @@ -105,6 +108,7 @@ pub const CaseSamples = struct { self.geom_times[rr] = result.geom_ms; self.raster_times[rr] = result.raster_ms; self.cam_times[rr] = result.cam_ms; + self.elem_loop_times[rr] = result.pipeline_times.elem_loop / 1e6; self.resolve_times[rr] = result.resolve_ms; self.save_frame_times[rr] = result.pipeline_times.save_frame / 1e6; @@ -140,26 +144,6 @@ pub const CaseSamples = struct { samp_cfg: ?texops.TextureSampleConfig, tex_func_case: ?common.TexFuncCase, ) !common.BenchStats { - const cam_median = (try common.calcMedianMAD( - allocator, - self.cam_times, - )).median; - const resolve_median = (try common.calcMedianMAD( - allocator, - self.resolve_times, - )).median; - const raster_median = (try common.calcMedianMAD( - allocator, - self.raster_times, - )).median; - const elem_loop_median = - raster_median - cam_median - resolve_median; - const elem_loop_zero: common.MedianMAD = .{ - .median = elem_loop_median, - .mad = 0, - .min = elem_loop_median, - .max = elem_loop_median, - }; return .{ .name = try allocator.dupe(u8, case_name), .mesh_type = mesh_type, @@ -198,7 +182,10 @@ pub const CaseSamples = struct { allocator, self.cam_times, ), - .elem_loop = elem_loop_zero, + .elem_loop = try common.calcMedianMAD( + allocator, + self.elem_loop_times, + ), .scratch_resolve = try common.calcMedianMAD( allocator, self.resolve_times, diff --git a/src/riley/zig/rasterengine_common.zig b/src/riley/zig/rasterengine_common.zig index 725f7b16..e1035867 100644 --- a/src/riley/zig/rasterengine_common.zig +++ b/src/riley/zig/rasterengine_common.zig @@ -631,8 +631,10 @@ fn rasterTileComm( ctx_rast.config.background_value, ); - const time_cam_start: ?Timestamp = - if (comptime report_mode != .off) + // Report aggregate worker-time for the overlap loop. Camera fill is timed + // separately and removed below so all three raster phases share one basis. + const time_elem_start: ?Timestamp = + if (comptime report_mode == .bench) Timestamp.now(io, .awake) else null; @@ -653,6 +655,11 @@ fn rasterTileComm( switch (mesh_ptr.mesh_type) { inline else => |geom_tag| { if (!camera_fill_ready and comptime geom_tag != .tri3opt) { + const time_cam_start: ?Timestamp = + if (comptime report_mode != .off) + Timestamp.now(io, .awake) + else + null; try fillTileIdealCent( ctx_rast, tile, @@ -1008,6 +1015,16 @@ fn rasterTileComm( } } + const elem_duration_ns: u64 = if (comptime report_mode == .bench) blk: { + const overlap_duration_ns: u64 = @intCast( + time_elem_start.?.durationTo( + Timestamp.now(io, .awake), + ).raw.nanoseconds, + ); + std.debug.assert(overlap_duration_ns >= cam_duration_ns); + break :blk overlap_duration_ns - cam_duration_ns; + } else 0; + const time_resolve_start: ?Timestamp = if (comptime report_mode != .off) Timestamp.now(io, .awake) @@ -1082,6 +1099,7 @@ fn rasterTileComm( shaded_px, overlaps.len, cam_duration_ns, + elem_duration_ns, resolve_duration_ns, ); } diff --git a/src/riley/zig/rasterreport.zig b/src/riley/zig/rasterreport.zig index eb81811f..d396eff9 100644 --- a/src/riley/zig/rasterreport.zig +++ b/src/riley/zig/rasterreport.zig @@ -43,6 +43,7 @@ pub inline fn finishTile( shaded_px: u64, elem_count: usize, cam_duration_ns: u64, + elem_duration_ns: u64, resolve_duration_ns: u64, ) void { const screen_px_x = @as( @@ -66,6 +67,7 @@ pub inline fn finishTile( ); ctx_report.recordCamTime(cam_duration_ns); + ctx_report.recordElemTime(elem_duration_ns); ctx_report.recordResolveTime(resolve_duration_ns); } diff --git a/src/riley/zig/report.zig b/src/riley/zig/report.zig index a6d3a1ae..e5e1dce3 100644 --- a/src/riley/zig/report.zig +++ b/src/riley/zig/report.zig @@ -36,6 +36,7 @@ pub const FrameTimes = struct { tile_overlap: F = 0, raster_loop: F = 0, cam_invert: F = 0, + elem_loop: F = 0, scratch_resolve: F = 0, save_frame: F = 0, active_time: F = 0, @@ -65,6 +66,7 @@ pub const BenchLog = struct { depth_tests_fail: u64 = 0, max_tile_elems: usize = 0, cam_time_ns: F = 0, + elem_time_ns: F = 0, resolve_time_ns: F = 0, }; @@ -265,6 +267,7 @@ pub fn reduceBenchLog(dst: *BenchLog, src: *const BenchLog) void { src.max_tile_elems, ); dst.cam_time_ns += src.cam_time_ns; + dst.elem_time_ns += src.elem_time_ns; dst.resolve_time_ns += src.resolve_time_ns; } @@ -1006,9 +1009,7 @@ pub const FullStatsLog = struct { self.bench.frame_times.cam_invert * conv; const resolve_ms = self.bench.frame_times.scratch_resolve * conv; - const elem_loop_ms = - self.bench.frame_times.raster_loop * conv - - cam_inv_ms - resolve_ms; + const elem_loop_ms = self.bench.frame_times.elem_loop * conv; try writer.print("Cam Invert Time = {d:.6} ms\n", .{ cam_inv_ms, }); @@ -1675,6 +1676,16 @@ pub fn ReportContext(comptime mode: ReportMode) type { } } + pub inline fn recordElemTime( + self: @This(), + elem_duration_ns: u64, + ) void { + if (self.bench()) |bench_log| { + bench_log.elem_time_ns += + @floatFromInt(elem_duration_ns); + } + } + pub inline fn recordResolveTime( self: @This(), resolve_duration_ns: u64, @@ -1824,9 +1835,7 @@ pub fn standardReport( frame_times.cam_invert * conv_units; const resolve_print_ms = frame_times.scratch_resolve * conv_units; - const elem_loop_print_ms = - frame_times.raster_loop * conv_units - - cam_inv_print_ms - resolve_print_ms; + const elem_loop_print_ms = frame_times.elem_loop * conv_units; try writer.print("Cam Invert Time = {d:.6} ms\n", .{ cam_inv_print_ms, }); diff --git a/src/riley/zig/riley.zig b/src/riley/zig/riley.zig index 2cf840f5..2941b9cf 100644 --- a/src/riley/zig/riley.zig +++ b/src/riley/zig/riley.zig @@ -1451,6 +1451,7 @@ fn rasterFrame( ); if (report.getBenchLog(report_mode, report_ptr)) |bench_log| { ctx.frame_times.cam_invert = bench_log.cam_time_ns; + ctx.frame_times.elem_loop = bench_log.elem_time_ns; ctx.frame_times.scratch_resolve = bench_log.resolve_time_ns; } } diff --git a/src/riley/zig/validateinput.zig b/src/riley/zig/validateinput.zig index c7e6dda4..8940e9b8 100644 --- a/src/riley/zig/validateinput.zig +++ b/src/riley/zig/validateinput.zig @@ -62,6 +62,14 @@ pub fn checkRenderInpsErr( if (render_group.workers == 0) { return error.InvalidRenderGroupWorkers; } + if (config.report == .full_stats and + @min( + render_group.workers, + config.max_raster_workers_per_job, + ) > 1) + { + return error.FullStatsRequiresSingleRasterWorker; + } } if (config.total_threads == 0) return error.InvalidTotalThreads; @@ -149,6 +157,12 @@ pub fn checkRenderInpsAssert( std.debug.assert(meshes.len > 0); for (render_groups) |render_group| { std.debug.assert(render_group.workers > 0); + if (config.report == .full_stats) { + std.debug.assert(@min( + render_group.workers, + config.max_raster_workers_per_job, + ) == 1); + } } std.debug.assert(config.total_threads > 0); @@ -445,3 +459,26 @@ fn checkCamInpAssert(cam_inp: cam.CameraInput) void { std.debug.assert(isValidDistortion(cam_inp.distortion)); std.debug.assert(isValidPsf(cam_inp.psf)); } + +test "full stats rejects multiple raster workers" { + const render_groups = [_]struct { workers: u16 }{ + .{ .workers = 2 }, + }; + const config = rastcfg.RasterConfig{ + .report = .full_stats, + .max_raster_workers_per_job = 2, + }; + + try std.testing.expectError( + error.FullStatsRequiresSingleRasterWorker, + checkRenderInpsErr( + &render_groups, + &[_]cam.CameraInput{}, + &[_]mo.MeshInput{}, + config, + null, + false, + null, + ), + ); +} From 2b0160a9406051833a6d18504830486193eab804 Mon Sep 17 00:00:00 2001 From: ScepticalRabbit Date: Wed, 22 Jul 2026 20:53:42 +0100 Subject: [PATCH 2/6] Removed empty test tripping the wrong error --- src/riley/zig/validateinput.zig | 23 ----------------------- 1 file changed, 23 deletions(-) diff --git a/src/riley/zig/validateinput.zig b/src/riley/zig/validateinput.zig index 8940e9b8..75a13ebd 100644 --- a/src/riley/zig/validateinput.zig +++ b/src/riley/zig/validateinput.zig @@ -459,26 +459,3 @@ fn checkCamInpAssert(cam_inp: cam.CameraInput) void { std.debug.assert(isValidDistortion(cam_inp.distortion)); std.debug.assert(isValidPsf(cam_inp.psf)); } - -test "full stats rejects multiple raster workers" { - const render_groups = [_]struct { workers: u16 }{ - .{ .workers = 2 }, - }; - const config = rastcfg.RasterConfig{ - .report = .full_stats, - .max_raster_workers_per_job = 2, - }; - - try std.testing.expectError( - error.FullStatsRequiresSingleRasterWorker, - checkRenderInpsErr( - &render_groups, - &[_]cam.CameraInput{}, - &[_]mo.MeshInput{}, - config, - null, - false, - null, - ), - ); -} From 77a79065d6c2429b100e4ab00b727fd6039b3775 Mon Sep 17 00:00:00 2001 From: ScepticalRabbit Date: Wed, 29 Jul 2026 09:57:47 +0100 Subject: [PATCH 3/6] Update to reporting block to make it easier to track long renders --- src/riley/zig/report.zig | 88 ++++++++++++++++++++++++----------- src/riley/zig/riley.zig | 14 ++++++ src/riley/zig/saveoverlap.zig | 5 ++ 3 files changed, 79 insertions(+), 28 deletions(-) diff --git a/src/riley/zig/report.zig b/src/riley/zig/report.zig index e5e1dce3..b48a63df 100644 --- a/src/riley/zig/report.zig +++ b/src/riley/zig/report.zig @@ -123,6 +123,7 @@ pub fn publishFrameResults( frame_idx: usize, cameras_num: usize, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, bench_capture: ?[]FrameBenchCapture, report_storage: *FrameReportStorage, frame_times: FrameTimes, @@ -142,6 +143,7 @@ pub fn publishFrameResults( frame_idx, cameras_num, out_dir, + out_dir_path, bench_capture, report_storage, frame_times, @@ -162,6 +164,7 @@ pub fn publishFrameResultsWithNodesPerElem( frame_idx: usize, cameras_num: usize, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, bench_capture: ?[]FrameBenchCapture, report_storage: *FrameReportStorage, frame_times: FrameTimes, @@ -214,6 +217,8 @@ pub fn publishFrameResultsWithNodesPerElem( frame_idx, camera_idx, frame_times, + config.raster_halo_px_override orelse camera.prep_psf.halo_px, + out_dir_path, total_elems_num, total_elems_in_image, nodes_per_elem, @@ -1738,6 +1743,8 @@ pub fn standardReport( frame_idx: usize, camera_idx: usize, frame_times: FrameTimes, + tile_halo_px: u16, + out_dir_path: ?[]const u8, total_elems: usize, vis_elems: usize, nodes_per_elem: F, @@ -1795,40 +1802,58 @@ pub fn standardReport( const total_elems_f = @as(F, @floatFromInt(total_elems)); const vis_pct = if (total_elems > 0) (vis_elems_f * 100.0 / total_elems_f) else 0; - try writer.print("Vis Elems = {d}\n", .{vis_elems}); - try writer.print("Total Elems = {d}\n", .{total_elems}); - try writer.print("Vis % = {d:.2}%\n", .{vis_pct}); - try writer.print("Total SubPx = {d:.0}\n", .{total_subpx}); - try writer.print("Shaded SubPx = {d:.0}\n", .{shaded_subpx}); - try writer.print("Shaded % = {d:.2}%\n", .{shaded_pct}); - try writer.print("{s}\n", .{print_break_inner}); + const tile_subpx = @as(usize, actual_tile_size) * camera.sub_sample; - try writer.print("Actual Tile Size = {d}x{d}\n", .{ + try writer.print("Camera Pixels = {d}x{d}\n", .{ + camera.pixels_num[0], + camera.pixels_num[1], + }); + try writer.print("Camera Distortion = {s}\n", .{ + @tagName(camera.distortion), + }); + try writer.print("Camera PSF = {s}\n", .{@tagName(camera.psf)}); + try writer.print("Camera Subsamples = {d}x{d}\n", .{ + camera.sub_sample, + camera.sub_sample, + }); + try writer.print("Tile Size Pixels = {d}x{d}\n", .{ actual_tile_size, actual_tile_size, }); - try writer.print("Setup Frame Buff = {d:.6} ms\n", .{ + try writer.print("Tile Size Subpixels = {d}x{d}\n", .{ tile_subpx, tile_subpx }); + try writer.print("Tile Halo Pixels = {d}\n", .{tile_halo_px}); + try writer.print("{s}\n", .{print_break_inner}); + + try writer.print("Vis Elems = {d}\n", .{vis_elems}); + try writer.print("Total Elems = {d}\n", .{total_elems}); + try writer.print("Vis % = {d:.2}%\n", .{vis_pct}); + try writer.print("Total SubPx = {d:.0}\n", .{total_subpx}); + try writer.print("Shaded SubPx = {d:.0}\n", .{shaded_subpx}); + try writer.print("Shaded % = {d:.2}%\n", .{shaded_pct}); + try writer.print("{s}\n", .{print_break_inner}); + + try writer.print("Setup Frame Buff = {d:.6} ms\n", .{ frame_times.setup_frame_buff * conv_units, }); - try writer.print("Prep Frame = {d:.6} ms\n", .{ + try writer.print("Prep Frame = {d:.6} ms\n", .{ frame_times.prepare_frame_context * conv_units, }); - try writer.print("Geometry Preparation = {d:.6} ms\n", .{ + try writer.print("Geometry Preparation = {d:.6} ms\n", .{ frame_times.geometry_prep * conv_units, }); - try writer.print(" Coord Ops = {d:.6} ms\n", .{ + try writer.print(" Coord Ops = {d:.6} ms\n", .{ frame_times.geom_coord_ops * conv_units, }); - try writer.print(" Cull Ops = {d:.6} ms\n", .{ + try writer.print(" Cull Ops = {d:.6} ms\n", .{ frame_times.geom_cull_ops * conv_units, }); - try writer.print(" Prep Hulls Shaders = {d:.6} ms\n", .{ + try writer.print(" Prep Hulls Shaders = {d:.6} ms\n", .{ frame_times.geom_prep_hulls_shaders * conv_units, }); - try writer.print(" Remap Inds = {d:.6} ms\n", .{ + try writer.print(" Remap Inds = {d:.6} ms\n", .{ frame_times.geom_remap_inds * conv_units, }); - try writer.print("Elem/Tile Overlap = {d:.6} ms\n", .{ + try writer.print("Elem/Tile Overlap = {d:.6} ms\n", .{ frame_times.tile_overlap * conv_units, }); const cam_inv_print_ms = @@ -1836,37 +1861,44 @@ pub fn standardReport( const resolve_print_ms = frame_times.scratch_resolve * conv_units; const elem_loop_print_ms = frame_times.elem_loop * conv_units; - try writer.print("Cam Invert Time = {d:.6} ms\n", .{ + try writer.print("Cam Invert Time = {d:.6} ms\n", .{ cam_inv_print_ms, }); - try writer.print("Elem Loop Time = {d:.6} ms\n", .{ + try writer.print("Elem Loop Time = {d:.6} ms\n", .{ elem_loop_print_ms, }); - try writer.print("Scratch Resolve Time = {d:.6} ms\n", .{ + try writer.print("Scratch Resolve Time = {d:.6} ms\n", .{ resolve_print_ms, }); - try writer.print("Raster loop time = {d:.6} ms\n", .{ + try writer.print("Raster Loop = {d:.6} ms\n", .{ frame_times.raster_loop * conv_units, }); - try writer.print("Save Time = {d:.6} ms\n", .{ + try writer.print("Save Frame = {d:.6} ms\n", .{ frame_times.save_frame * conv_units, }); try writer.print("{s}\n", .{print_break_inner}); - try writer.print("ACTIVE FRAME TIME = {d:.3} ms\n", .{ + try writer.print("ACTIVE FRAME TIME = {d:.3} ms\n", .{ frame_times.active_time * conv_units, }); - try writer.print("FRAME LATENCY = {d:.3} ms\n", .{ + try writer.print("FRAME LATENCY = {d:.3} ms\n", .{ frame_times.latency_time * conv_units, }); try writer.print("{s}\n", .{print_break_inner}); - try writer.print("Geom. Node Throughput = {d:.2} MNodes/s\n", .{mnodes_sec}); - try writer.print("Geom. Elem. Throughput = {d:.2} MElem/s\n", .{melems_sec}); - try writer.print("Subpx Raster Throughput = {d:.2} MSubPx/s\n", .{msubpx_sec}); - try writer.print("Raster Throughput = {d:.2} MPx/s\n", .{mpx_sec}); - try writer.print("Active Frame Throughput = {d:.2} MPx/s\n", .{frame_mpx_sec}); + try writer.print("Geom. Node Throughput = {d:.2} MNodes/s\n", .{mnodes_sec}); + try writer.print("Geom. Elem. Throughput = {d:.2} MElem/s\n", .{melems_sec}); + try writer.print("Subpx Raster Throughput = {d:.2} MSubPx/s\n", .{msubpx_sec}); + try writer.print("Raster Throughput = {d:.2} MPx/s\n", .{mpx_sec}); + try writer.print("Active Frame Throughput = {d:.2} MPx/s\n", .{frame_mpx_sec}); + try writer.print("{s}\n", .{print_break}); + try writer.print("Frame Output Path =\n", .{}); + if (out_dir_path) |path| { + try writer.print(" {s}\n", .{path}); + } else { + try writer.print(" not written (memory output)\n", .{}); + } try writer.print("{s}\n", .{print_break}); try writer.flush(); } diff --git a/src/riley/zig/riley.zig b/src/riley/zig/riley.zig index 2941b9cf..2f54c241 100644 --- a/src/riley/zig/riley.zig +++ b/src/riley/zig/riley.zig @@ -226,6 +226,7 @@ pub fn rasterReportInto( cams, config, out_dir, + out_dir_path, num_time, num_fields, mesh_static, @@ -240,6 +241,7 @@ pub fn rasterReportInto( cams, config, out_dir, + out_dir_path, num_time, num_fields, mesh_static, @@ -346,6 +348,7 @@ const OfflineDispatchShared = struct { cameras: []const cam.CameraPrepared, config: RasterConfig, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, num_time: usize, num_fields: u8, mesh_static: []const mo.MeshStatic, @@ -364,6 +367,7 @@ fn dispatchFrameJobsOffline( cameras: []const cam.CameraPrepared, config: RasterConfig, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, num_time: usize, num_fields: u8, mesh_static: []const mo.MeshStatic, @@ -377,6 +381,7 @@ fn dispatchFrameJobsOffline( .cameras = cameras, .config = config, .out_dir = out_dir, + .out_dir_path = out_dir_path, .num_time = num_time, .num_fields = num_fields, .mesh_static = mesh_static, @@ -456,6 +461,7 @@ fn processOfflineRenderGroupLoop( shared.cameras, shared.config, shared.out_dir, + shared.out_dir_path, shared.num_fields, shared.mesh_static, shared.nodal_global_scaling, @@ -497,6 +503,7 @@ const InOrderDispatchShared = struct { cameras: []const cam.CameraPrepared, config: RasterConfig, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, frame_idx: usize, num_fields: u8, mesh_static: []const mo.MeshStatic, @@ -516,6 +523,7 @@ fn dispatchFrameJobsInOrder( cameras: []const cam.CameraPrepared, config: RasterConfig, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, num_time: usize, num_fields: u8, mesh_static: []const mo.MeshStatic, @@ -533,6 +541,7 @@ fn dispatchFrameJobsInOrder( .cameras = cameras, .config = config, .out_dir = out_dir, + .out_dir_path = out_dir_path, .frame_idx = frame_idx, .num_fields = num_fields, .mesh_static = mesh_static, @@ -619,6 +628,7 @@ fn processInOrderRenderGroupLoop( shared.cameras, shared.config, shared.out_dir, + shared.out_dir_path, shared.num_fields, shared.mesh_static, shared.nodal_global_scaling, @@ -660,6 +670,7 @@ fn prepareJobBatch( cameras: []const cam.CameraPrepared, config: RasterConfig, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, num_fields: u8, mesh_static: []const mo.MeshStatic, nodal_global_scaling: []const ?imageops.ScalingParams, @@ -685,6 +696,7 @@ fn prepareJobBatch( .num_fields = num_fields, .config = config, .out_dir = out_dir, + .out_dir_path = out_dir_path, .mesh_static = mesh_static, .nodal_global_scaling = nodal_global_scaling, .images_arr = images_arr, @@ -1103,6 +1115,7 @@ fn runRasterAndSaveFrame( job.desc.frame_idx, job.desc.cameras_num, job.desc.out_dir, + job.desc.out_dir_path, job.desc.bench_capture, &job.ctx.report_storage, job.ctx.frame_times, @@ -1245,6 +1258,7 @@ const FrameJobDesc = struct { num_fields: u8, config: RasterConfig, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, mesh_static: []const mo.MeshStatic, nodal_global_scaling: []const ?imageops.ScalingParams, images_arr: ?*ndarray.NDArray(F), diff --git a/src/riley/zig/saveoverlap.zig b/src/riley/zig/saveoverlap.zig index a23c9192..41288f36 100644 --- a/src/riley/zig/saveoverlap.zig +++ b/src/riley/zig/saveoverlap.zig @@ -43,6 +43,7 @@ pub const SaveSlot = struct { num_fields: u8 = 0, pixels_num: [2]u32 = .{ 0, 0 }, out_dir: ?std.Io.Dir = null, + out_dir_path: ?[]const u8 = null, bench_capture: ?[]report.FrameBenchCapture = null, report_storage: FrameReportStorage = .{ .off = .{} }, frame_times: report.FrameTimes = .{}, @@ -252,6 +253,7 @@ pub const SaveOverlap = struct { job.desc.camera.pixels_num[1], }, .out_dir = job.desc.out_dir, + .out_dir_path = job.desc.out_dir_path, .bench_capture = job.desc.bench_capture, .frame_times = job.ctx.frame_times, .total_nodes_num = job.ctx.total_nodes_num, @@ -273,6 +275,7 @@ pub const RenderedFrameMeta = struct { cameras_num: usize, pixels_num: [2]u32, out_dir: ?std.Io.Dir, + out_dir_path: ?[]const u8, bench_capture: ?[]report.FrameBenchCapture, frame_times: report.FrameTimes, total_nodes_num: usize, @@ -455,6 +458,7 @@ pub fn publishRenderedSlot( slot.num_fields = @intCast(slot.frame_arr.dims[0]); slot.pixels_num = meta.pixels_num; slot.out_dir = meta.out_dir; + slot.out_dir_path = meta.out_dir_path; slot.bench_capture = meta.bench_capture; slot.report_storage = report_storage.*; report_storage.* = .{ .off = .{} }; @@ -526,6 +530,7 @@ pub fn completeSaveSlot( slot.frame_idx, slot.cameras_num, slot.out_dir, + slot.out_dir_path, slot.bench_capture, &slot.report_storage, slot.frame_times, From 4c8a8911fdc2a20f86b5ae0fef059d0036a13a2e Mon Sep 17 00:00:00 2001 From: ScepticalRabbit Date: Thu, 30 Jul 2026 08:08:12 +0100 Subject: [PATCH 4/6] Removed tile size from final summary --- src/riley/zig/report.zig | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/src/riley/zig/report.zig b/src/riley/zig/report.zig index b48a63df..990aa18e 100644 --- a/src/riley/zig/report.zig +++ b/src/riley/zig/report.zig @@ -1930,6 +1930,7 @@ pub fn printRenderSummary( cameras[0].sub_sample, cameras[0].prep_psf.halo_px, ); + _ = actual_tile_size; const total_frames = cameras.len * num_time; const total_render_ms = end_to_end_times.total_time / 1e6; @@ -1968,10 +1969,10 @@ pub fn printRenderSummary( print_break, print_break, }); - try writer.print("Actual Tile Size = {d}x{d}\n", .{ - actual_tile_size, - actual_tile_size, - }); + // try writer.print("Actual Tile Size = {d}x{d}\n", .{ + // actual_tile_size, + // actual_tile_size, + // }); try writer.print("Setup Time = {d:.3} ms\n", .{setup_ms}); // try writer.print("Setup other = {d:.3} ms\n", .{ // setup_other_ms, From ff12b32283acf113c2307a304bba1e8380aebf30 Mon Sep 17 00:00:00 2001 From: scepticalrabbit <121958155+ScepticalRabbit@users.noreply.github.com> Date: Thu, 20 Aug 2026 08:11:20 +0100 Subject: [PATCH 5/6] Update src/riley/zig/rasterengine_common.zig Co-authored-by: James Panayis --- src/riley/zig/rasterengine_common.zig | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/riley/zig/rasterengine_common.zig b/src/riley/zig/rasterengine_common.zig index e1035867..7a67848f 100644 --- a/src/riley/zig/rasterengine_common.zig +++ b/src/riley/zig/rasterengine_common.zig @@ -634,7 +634,7 @@ fn rasterTileComm( // Report aggregate worker-time for the overlap loop. Camera fill is timed // separately and removed below so all three raster phases share one basis. const time_elem_start: ?Timestamp = - if (comptime report_mode == .bench) + if (comptime report_mode != .off) Timestamp.now(io, .awake) else null; From 1bea664cb73066c5ad824a19887d6924fb63cedb Mon Sep 17 00:00:00 2001 From: James Panayis Date: Fri, 21 Aug 2026 16:19:42 +0100 Subject: [PATCH 6/6] Record elem loop time whenever report mode is not off --- src/riley/zig/rasterengine_common.zig | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/riley/zig/rasterengine_common.zig b/src/riley/zig/rasterengine_common.zig index 7a67848f..c4dedbe9 100644 --- a/src/riley/zig/rasterengine_common.zig +++ b/src/riley/zig/rasterengine_common.zig @@ -1015,7 +1015,7 @@ fn rasterTileComm( } } - const elem_duration_ns: u64 = if (comptime report_mode == .bench) blk: { + const elem_duration_ns: u64 = if (comptime report_mode != .off) blk: { const overlap_duration_ns: u64 = @intCast( time_elem_start.?.durationTo( Timestamp.now(io, .awake),