diff --git a/build.zig b/build.zig index 23132bd..73f481f 100644 --- a/build.zig +++ b/build.zig @@ -63,6 +63,7 @@ fn setupExamples(b: *std.Build, target: std.zig.CrossTarget, optimize: std.built "bubble_sort", "hooks", "json", + "memory_tracking", "parameterised", "progress", "sleep", diff --git a/examples/json.zig b/examples/json.zig index 577776d..71e345b 100644 --- a/examples/json.zig +++ b/examples/json.zig @@ -17,7 +17,14 @@ test "bench test json" { var bench = zbench.Benchmark.init(test_allocator, .{}); defer bench.deinit(); - try bench.add("My Benchmark 1", myBenchmark, .{ .iterations = 10 }); + try bench.add("My Benchmark 1", myBenchmark, .{ + .iterations = 10, + .track_allocations = false, + }); + try bench.add("My Benchmark 2", myBenchmark, .{ + .iterations = 10, + .track_allocations = true, + }); try stdout.writeAll("["); var iter = try bench.iterator(); diff --git a/examples/memory_tracking.zig b/examples/memory_tracking.zig new file mode 100644 index 0000000..21c41be --- /dev/null +++ b/examples/memory_tracking.zig @@ -0,0 +1,25 @@ +const std = @import("std"); +const zbench = @import("zbench"); + +fn myBenchmark(allocator: std.mem.Allocator) void { + for (0..2000) |_| { + const buf = allocator.alloc(u8, 512) catch @panic("OOM"); + defer allocator.free(buf); + } +} + +test "bench test basic" { + const stdout = std.io.getStdOut().writer(); + var bench = zbench.Benchmark.init(std.testing.allocator, .{ + .iterations = 64, + }); + defer bench.deinit(); + + try bench.add("My Benchmark 1", myBenchmark, .{}); + try bench.add("My Benchmark 2", myBenchmark, .{ + .track_allocations = true, + }); + + try stdout.writeAll("\n"); + try bench.run(stdout); +} diff --git a/util/runner.zig b/util/runner.zig index c3f46bf..9939a95 100644 --- a/util/runner.zig +++ b/util/runner.zig @@ -4,6 +4,8 @@ const expectEqSlices = std.testing.expectEqualSlices; pub const Error = @import("./runner/types.zig").Error; pub const Step = @import("./runner/types.zig").Step; +pub const AllocationReading = @import("./runner/types.zig").AllocationReading; +pub const AllocationReadings = @import("./runner/types.zig").AllocationReadings; pub const Reading = @import("./runner/types.zig").Reading; pub const Readings = @import("./runner/types.zig").Readings; @@ -45,12 +47,13 @@ const State = union(enum) { /// Number of timings still to be performed in the benchmark. iterations_remaining: usize, - /// Array of timings collected. - timings_ns: []u64, + /// Readings collected during the run. + readings: Readings, }; }; allocator: std.mem.Allocator, +track_allocations: bool, state: State, pub fn init( @@ -58,19 +61,26 @@ pub fn init( iterations: u16, max_iterations: u16, time_budget_ns: u64, + track_allocations: bool, ) Error!Runner { return if (iterations == 0) .{ .allocator = allocator, + .track_allocations = track_allocations, .state = .{ .preparing = .{ .max_iterations = max_iterations, .time_budget_ns = time_budget_ns, } }, } else .{ .allocator = allocator, + .track_allocations = track_allocations, .state = .{ .running = .{ .iterations_count = iterations, .iterations_remaining = iterations, - .timings_ns = try allocator.alloc(u64, iterations), + .readings = try Readings.init( + allocator, + iterations, + track_allocations, + ), } }, }; } @@ -101,15 +111,19 @@ pub fn next(self: *Runner, reading: Reading) Error!?Step { self.state = .{ .running = .{ .iterations_count = N, .iterations_remaining = N, - .timings_ns = try self.allocator.alloc(u64, N), + .readings = try Readings.init( + self.allocator, + N, + self.track_allocations, + ), } }; } return .more; }, .running => |*st| { if (0 < st.iterations_remaining) { - const i = st.timings_ns.len - st.iterations_remaining; - st.timings_ns[i] = reading.timing_ns; + const i = st.readings.iterations - st.iterations_remaining; + st.readings.set(i, reading); st.iterations_remaining -= 1; } return if (st.iterations_remaining == 0) null else .more; @@ -121,12 +135,13 @@ pub fn next(self: *Runner, reading: Reading) Error!?Step { /// complete, so get the timing results. pub fn finish(self: *Runner) Error!Readings { return switch (self.state) { - .preparing => .{ + .preparing => Readings{ + .allocator = self.allocator, + .iterations = 0, .timings_ns = &.{}, + .allocations = null, }, - .running => |st| .{ - .timings_ns = st.timings_ns, - }, + .running => |st| st.readings, }; } @@ -134,7 +149,7 @@ pub fn finish(self: *Runner) Error!Readings { pub fn abort(self: *Runner) void { return switch (self.state) { .preparing => {}, - .running => |st| self.allocator.free(st.timings_ns), + .running => |st| st.readings.deinit(), }; } @@ -157,33 +172,76 @@ pub fn status(self: Runner) Status { } test "Runner" { - var r = try Runner.init(std.testing.allocator, 0, 16384, 2e9); + var r = try Runner.init(std.testing.allocator, 0, 16384, 2e9, false); + { + errdefer r.abort(); + try expectEq(Step.more, try r.next(Reading.init(100_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(100_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(100_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, null))); + + try expectEq(Step.more, try r.next(Reading.init(100_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(400_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(100_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, null))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, null))); + try expectEq(@as(?Step, null), try r.next(Reading.init(400_000_000, null))); + } + const result = try r.finish(); + defer result.deinit(); + try expectEqSlices(u64, &.{ + 100_000_000, 200_000_000, 300_000_000, 400_000_000, + 100_000_000, 200_000_000, 300_000_000, 400_000_000, + }, result.timings_ns); +} + +test "Runner - memory tracking" { + var r = try Runner.init(std.testing.allocator, 0, 16384, 2e9, true); { errdefer r.abort(); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(Step.more, try r.next(Reading.init(200_000_000))); - try expectEq(@as(?Step, null), try r.next(Reading.init(200_000_000))); + try expectEq(Step.more, try r.next(Reading.init(100_000_000, .{ .max = 256, .count = 1 }))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, .{ .max = 256, .count = 1 }))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, .{ .max = 512, .count = 2 }))); + try expectEq(Step.more, try r.next(Reading.init(100_000_000, .{ .max = 512, .count = 2 }))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, .{ .max = 1024, .count = 4 }))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, .{ .max = 1024, .count = 4 }))); + try expectEq(Step.more, try r.next(Reading.init(100_000_000, .{ .max = 2048, .count = 8 }))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, .{ .max = 2045, .count = 8 }))); + try expectEq(Step.more, try r.next(Reading.init(300_000_000, .{ .max = 4096, .count = 16 }))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, .{ .max = 4096, .count = 16 }))); + try expectEq(Step.more, try r.next(Reading.init(200_000_000, .{ .max = 8192, .count = 32 }))); + + try expectEq(Step.more, try r.next(Reading.init(100, .{ .max = 1, .count = 2 }))); + try expectEq(Step.more, try r.next(Reading.init(200, .{ .max = 2, .count = 4 }))); + try expectEq(Step.more, try r.next(Reading.init(300, .{ .max = 4, .count = 8 }))); + try expectEq(Step.more, try r.next(Reading.init(400, .{ .max = 8, .count = 16 }))); + try expectEq(Step.more, try r.next(Reading.init(100, .{ .max = 16, .count = 32 }))); + try expectEq(Step.more, try r.next(Reading.init(200, .{ .max = 32, .count = 64 }))); + try expectEq(Step.more, try r.next(Reading.init(300, .{ .max = 64, .count = 128 }))); + try expectEq(@as(?Step, null), try r.next(Reading.init(400, .{ .max = 128, .count = 256 }))); } const result = try r.finish(); - defer std.testing.allocator.free(result.timings_ns); + defer result.deinit(); try expectEqSlices(u64, &.{ - 200_000_000, 200_000_000, 200_000_000, 200_000_000, - 200_000_000, 200_000_000, 200_000_000, 200_000_000, + 100, 200, 300, 400, 100, 200, 300, 400, }, result.timings_ns); + try expectEqSlices( + usize, + &.{ 1, 2, 4, 8, 16, 32, 64, 128 }, + result.allocations.?.maxes, + ); + try expectEqSlices( + usize, + &.{ 2, 4, 8, 16, 32, 64, 128, 256 }, + result.allocations.?.counts, + ); } diff --git a/util/runner/types.zig b/util/runner/types.zig index 61eb7a4..f09742a 100644 --- a/util/runner/types.zig +++ b/util/runner/types.zig @@ -6,14 +6,86 @@ pub const Step = enum { more }; pub const Reading = struct { timing_ns: u64, + allocation: ?AllocationReading, - pub fn init(timing_ns: u64) Reading { + pub fn init( + timing_ns: u64, + allocation: ?AllocationReading, + ) Reading { return .{ .timing_ns = timing_ns, + .allocation = allocation, }; } }; pub const Readings = struct { + allocator: std.mem.Allocator, + iterations: usize, timings_ns: []u64, + allocations: ?AllocationReadings, + + pub fn init( + allocator: std.mem.Allocator, + n: usize, + track_allocations: bool, + ) !Readings { + return Readings{ + .allocator = allocator, + .iterations = n, + .timings_ns = try allocator.alloc(u64, n), + .allocations = if (track_allocations) + try AllocationReadings.init(allocator, n) + else + null, + }; + } + + pub fn deinit(self: Readings) void { + self.allocator.free(self.timings_ns); + if (self.allocations) |allocs| allocs.deinit(self.allocator); + } + + pub fn set(self: *Readings, i: usize, reading: Reading) void { + self.timings_ns[i] = reading.timing_ns; + if (self.allocations) |allocs| { + if (reading.allocation) |x| { + allocs.maxes[i] = x.max; + allocs.counts[i] = x.count; + } else { + allocs.deinit(self.allocator); + self.allocations = null; + } + } + } + + pub fn sort(self: *Readings) void { + std.sort.heap(u64, self.timings_ns, {}, std.sort.asc(u64)); + if (self.allocations) |allocs| { + std.sort.heap(usize, allocs.maxes, {}, std.sort.asc(usize)); + std.sort.heap(usize, allocs.counts, {}, std.sort.asc(usize)); + } + } +}; + +pub const AllocationReading = struct { + max: usize, + count: usize, +}; + +pub const AllocationReadings = struct { + maxes: []usize, + counts: []usize, + + pub fn init(allocator: std.mem.Allocator, n: usize) !AllocationReadings { + return AllocationReadings{ + .maxes = try allocator.alloc(usize, n), + .counts = try allocator.alloc(usize, n), + }; + } + + pub fn deinit(self: AllocationReadings, allocator: std.mem.Allocator) void { + allocator.free(self.maxes); + allocator.free(self.counts); + } }; diff --git a/util/statistics.zig b/util/statistics.zig index b084a62..7be963b 100644 --- a/util/statistics.zig +++ b/util/statistics.zig @@ -1,5 +1,6 @@ const std = @import("std"); +/// Collect common statistical calculations together. pub fn Statistics(comptime T: type) type { return struct { total: T, diff --git a/util/tracking_allocator.zig b/util/tracking_allocator.zig new file mode 100644 index 0000000..9a43376 --- /dev/null +++ b/util/tracking_allocator.zig @@ -0,0 +1,88 @@ +const std = @import("std"); +const Allocator = std.mem.Allocator; + +const TrackingAllocator = @This(); + +parent_allocator: Allocator, +current_allocated: usize = 0, +max_allocated: usize = 0, +allocation_count: usize = 0, + +pub fn init(parent_allocator: Allocator) TrackingAllocator { + return .{ + .parent_allocator = parent_allocator, + }; +} + +pub fn allocator(self: *TrackingAllocator) Allocator { + return .{ + .ptr = self, + .vtable = &.{ + .alloc = alloc, + .resize = resize, + .free = free, + }, + }; +} + +pub fn maxAllocated(self: TrackingAllocator) usize { + return self.max_allocated; +} + +pub fn allocationCount(self: TrackingAllocator) usize { + return self.allocation_count; +} + +fn alloc( + ctx: *anyopaque, + len: usize, + log2_ptr_align: u8, + ra: usize, +) ?[*]u8 { + const self: *TrackingAllocator = @ptrCast(@alignCast(ctx)); + const result = self.parent_allocator.rawAlloc(len, log2_ptr_align, ra); + if (result) |_| { + self.allocation_count += 1; + self.current_allocated += len; + if (self.max_allocated < self.current_allocated) + self.max_allocated = self.current_allocated; + } + return result; +} + +fn resize( + ctx: *anyopaque, + buf: []u8, + log2_buf_align: u8, + new_len: usize, + ra: usize, +) bool { + const self: *TrackingAllocator = @ptrCast(@alignCast(ctx)); + const result = self.parent_allocator.rawResize(buf, log2_buf_align, new_len, ra); + if (result) { + self.allocation_count += 1; + if (buf.len < new_len) { + self.current_allocated += new_len - buf.len; + if (self.max_allocated < self.current_allocated) + self.max_allocated = self.current_allocated; + } else self.current_allocated -= buf.len - new_len; + } + return result; +} + +fn free( + ctx: *anyopaque, + buf: []u8, + log2_buf_align: u8, + ra: usize, +) void { + const self: *TrackingAllocator = @ptrCast(@alignCast(ctx)); + self.parent_allocator.rawFree(buf, log2_buf_align, ra); + self.current_allocated -= buf.len; +} + +/// This allocator is used in front of another allocator and tracks the maximum +/// memory usage on every call to the allocator. +pub fn trackingAllocator(parent_allocator: Allocator) TrackingAllocator { + return TrackingAllocator.init(parent_allocator); +} diff --git a/zbench.zig b/zbench.zig index 7d55a48..94f1e12 100644 --- a/zbench.zig +++ b/zbench.zig @@ -13,6 +13,9 @@ const Optional = @import("./util/optional.zig").Optional; const optional = @import("./util/optional.zig").optional; const platform = @import("./util/platform.zig"); const Runner = @import("./util/runner.zig"); +const Readings = Runner.Readings; +const AllocationReading = Runner.AllocationReading; +const TrackingAllocator = @import("./util/tracking_allocator.zig"); /// Hooks containing optional hooks for lifecycle events in benchmarking. /// Each field in this struct is a nullable function pointer. @@ -48,6 +51,10 @@ pub const Config = struct { /// This allows for custom setup and teardown operations, as well as fine-grained control /// over the environment in which benchmarks are run. hooks: Hooks = .{}, + + /// Track memory allocations made using the Allocator provided to + /// benchmarks. + track_allocations: bool = false, }; /// A benchmark definition. @@ -65,7 +72,21 @@ const Definition = struct { /// Run and time a benchmark function once, as well as running before and /// after hooks. fn run(self: Definition, allocator: std.mem.Allocator) !Runner.Reading { + // Put the implementation into another function so we can put a + // tracking allocator on the stack if requested. + if (self.config.track_allocations) { + var tracking = TrackingAllocator.init(allocator); + return self.runImpl(tracking.allocator(), &tracking); + } else return self.runImpl(allocator, null); + } + + fn runImpl( + self: Definition, + allocator: std.mem.Allocator, + tracking: ?*TrackingAllocator, + ) !Runner.Reading { if (self.config.hooks.before_each) |hook| hook(); + defer if (self.config.hooks.after_each) |hook| hook(); var t = try std.time.Timer.start(); @@ -75,6 +96,10 @@ const Definition = struct { } return Runner.Reading{ .timing_ns = t.read(), + .allocation = if (tracking) |trk| AllocationReading{ + .max = trk.maxAllocated(), + .count = trk.allocationCount(), + } else null, }; } }; @@ -184,6 +209,7 @@ pub const Benchmark = struct { config.iterations, config.max_iterations, config.time_budget_ns, + config.track_allocations, ); break :blk &self.runner.?; }; @@ -293,23 +319,24 @@ pub fn getSystemInfo() !platform.OsInfo { pub const Result = struct { allocator: std.mem.Allocator, name: []const u8, - timings_ns: []const u64, + readings: Readings, pub fn init( allocator: std.mem.Allocator, name: []const u8, readings: Runner.Readings, ) !Result { - std.sort.heap(u64, readings.timings_ns, {}, std.sort.asc(u64)); - return Result{ + var r = Result{ .allocator = allocator, .name = name, - .timings_ns = readings.timings_ns, + .readings = readings, }; + r.readings.sort(); + return r; } pub fn deinit(self: Result) void { - self.allocator.free(self.timings_ns); + self.readings.deinit(); } /// Formats and prints the benchmark result in a human readable format. @@ -318,12 +345,12 @@ pub const Result = struct { pub fn prettyPrint(self: Result, writer: anytype, colors: bool) !void { var buf: [128]u8 = undefined; - const s = Statistics(u64).init(self.timings_ns); + const s = Statistics(u64).init(self.readings.timings_ns); // Benchmark name, number of iterations, and total time try writer.print("{s:<22} ", .{self.name}); try setColor(colors, writer, Color.cyan); try writer.print("{d:<8} {s:<15}", .{ - self.timings_ns.len, + self.readings.iterations, std.fmt.fmtDuration(s.total), }); // Mean + standard deviation @@ -352,6 +379,41 @@ pub const Result = struct { // End of line try setColor(colors, writer, Color.reset); try writer.writeAll("\n"); + + if (self.readings.allocations) |allocs| { + const m = Statistics(usize).init(allocs.maxes); + // Benchmark name + const name = try std.fmt.bufPrint(&buf, "{s} [MEMORY]", .{ + self.name, + }); + try writer.print("{s:<46} ", .{name}); + // Mean + standard deviation + try setColor(colors, writer, Color.green); + try writer.print("{s:<23}", .{ + try std.fmt.bufPrint(&buf, "{:.3} ± {:.3}", .{ + std.fmt.fmtIntSizeBin(m.mean), + std.fmt.fmtIntSizeBin(m.stddev), + }), + }); + // Minimum and maximum + try setColor(colors, writer, Color.blue); + try writer.print("{s:<29}", .{ + try std.fmt.bufPrint(&buf, "({:.3} ... {:.3})", .{ + std.fmt.fmtIntSizeBin(m.min), + std.fmt.fmtIntSizeBin(m.max), + }), + }); + // Percentiles + try setColor(colors, writer, Color.cyan); + try writer.print("{:<10.3} {:<10.3} {:<10.3}", .{ + std.fmt.fmtIntSizeBin(m.percentiles.p75), + std.fmt.fmtIntSizeBin(m.percentiles.p99), + std.fmt.fmtIntSizeBin(m.percentiles.p995), + }); + // End of line + try setColor(colors, writer, Color.reset); + try writer.writeAll("\n"); + } } fn setColor(colors: bool, writer: anytype, color: Color) !void { @@ -359,16 +421,33 @@ pub const Result = struct { } pub fn writeJSON(self: Result, writer: anytype) !void { - const timings_ns_stats = Statistics(u64).init(self.timings_ns); - try writer.print( - \\{{ "name": "{s}", - \\ "timing_statistics": {}, "timings": {} }} - , - .{ - std.fmt.fmtSliceEscapeLower(self.name), - statistics.fmtJSON(u64, "nanoseconds", timings_ns_stats), - format.fmtJSONArray(u64, self.timings_ns), - }, - ); + const timings_ns_stats = Statistics(u64).init(self.readings.timings_ns); + if (self.readings.allocations) |allocs| { + const allocation_maxes_stats = Statistics(usize).init(allocs.maxes); + try writer.print( + \\{{ "name": "{s}", + \\ "timing_statistics": {}, "timings": {}, + \\ "max_allocation_statistics": {}, "max_allocations": {} }} + , + .{ + std.fmt.fmtSliceEscapeLower(self.name), + statistics.fmtJSON(u64, "nanoseconds", timings_ns_stats), + format.fmtJSONArray(u64, self.readings.timings_ns), + statistics.fmtJSON(usize, "bytes", allocation_maxes_stats), + format.fmtJSONArray(usize, allocs.maxes), + }, + ); + } else { + try writer.print( + \\{{ "name": "{s}", + \\ "timing_statistics": {}, "timings": {} }} + , + .{ + std.fmt.fmtSliceEscapeLower(self.name), + statistics.fmtJSON(u64, "nanoseconds", timings_ns_stats), + format.fmtJSONArray(u64, self.readings.timings_ns), + }, + ); + } } };