Merge pull request #25029 from mlugg/unit-test-timing

build system: unit test enhancements

Contributes towards https://github.com/ziglang/zig/issues/19821, but does not close it, since the timeout currently cannot be modified per unit test.

1 files changed, 72 insertions, 51 deletions

diff --git a/lib/std/Build/Step.zig b/lib/std/Build/Step.zig
index 6e7e9c4702..72eb66e530 100644
--- a/lib/std/Build/Step.zig
+++ b/lib/std/Build/Step.zig
@@ -56,6 +56,9 @@ result_cached: bool,
 result_duration_ns: ?u64,
 /// 0 means unavailable or not reported.
 result_peak_rss: usize,
+/// If the step is failed and this field is populated, this is the command which failed.
+/// This field may be populated even if the step succeeded.
+result_failed_command: ?[]const u8,
 test_results: TestResults,
 
 /// The return address associated with creation of this step that can be useful
@@ -63,18 +66,43 @@ test_results: TestResults,
 debug_stack_trace: std.builtin.StackTrace,
 
 pub const TestResults = struct {
-    fail_count: u32 = 0,
+    /// The total number of tests in the step. Every test has a "status" from the following:
+    /// * passed
+    /// * skipped
+    /// * failed cleanly
+    /// * crashed
+    /// * timed out
+    test_count: u32 = 0,
+
+    /// The number of tests which were skipped (`error.SkipZigTest`).
     skip_count: u32 = 0,
+    /// The number of tests which failed cleanly.
+    fail_count: u32 = 0,
+    /// The number of tests which terminated unexpectedly, i.e. crashed.
+    crash_count: u32 = 0,
+    /// The number of tests which timed out.
+    timeout_count: u32 = 0,
+
+    /// The number of detected memory leaks. The associated test may still have passed; indeed, *all*
+    /// individual tests may have passed. However, the step as a whole fails if any test has leaks.
     leak_count: u32 = 0,
+    /// The number of detected error logs. The associated test may still have passed; indeed, *all*
+    /// individual tests may have passed. However, the step as a whole fails if any test logs errors.
     log_err_count: u32 = 0,
-    test_count: u32 = 0,
 
     pub fn isSuccess(tr: TestResults) bool {
-        return tr.fail_count == 0 and tr.leak_count == 0 and tr.log_err_count == 0;
+        // all steps are success or skip
+        return tr.fail_count == 0 and
+            tr.crash_count == 0 and
+            tr.timeout_count == 0 and
+            // no (otherwise successful) step leaked memory or logged errors
+            tr.leak_count == 0 and
+            tr.log_err_count == 0;
     }
 
+    /// Computes the number of tests which passed from the other values.
     pub fn passCount(tr: TestResults) u32 {
-        return tr.test_count - tr.fail_count - tr.skip_count;
+        return tr.test_count - tr.skip_count - tr.fail_count - tr.crash_count - tr.timeout_count;
     }
 };
 
@@ -88,6 +116,8 @@ pub const MakeOptions = struct {
         // it currently breaks because `std.net.Address` doesn't work there. Work around for now.
         .wasm32 => void,
     },
+    /// If set, this is a timeout to enforce on all individual unit tests, in nanoseconds.
+    unit_test_timeout_ns: ?u64,
     /// Not to be confused with `Build.allocator`, which is an alias of `Build.graph.arena`.
     gpa: Allocator,
 };
@@ -230,6 +260,7 @@ pub fn init(options: StepOptions) Step {
         .result_cached = false,
         .result_duration_ns = null,
         .result_peak_rss = 0,
+        .result_failed_command = null,
         .test_results = .{},
     };
 }
@@ -243,6 +274,7 @@ pub fn make(s: *Step, options: MakeOptions) error{ MakeFailed, MakeSkipped }!voi
     var timer: ?std.time.Timer = t: {
         if (!s.owner.graph.time_report) break :t null;
         if (s.id == .compile) break :t null;
+        if (s.id == .run and s.cast(Run).?.stdio == .zig_test) break :t null;
         break :t std.time.Timer.start() catch @panic("--time-report not supported on this host");
     };
     const make_result = s.makeFn(s, options);
@@ -308,20 +340,20 @@ pub fn dump(step: *Step, w: *std.Io.Writer, tty_config: std.Io.tty.Config) void
     }
 }
 
-pub fn evalChildProcess(s: *Step, argv: []const []const u8) ![]u8 {
-    const run_result = try captureChildProcess(s, std.Progress.Node.none, argv);
-    try handleChildProcessTerm(s, run_result.term, null, argv);
-    return run_result.stdout;
-}
-
+/// Populates `s.result_failed_command`.
 pub fn captureChildProcess(
     s: *Step,
+    gpa: Allocator,
     progress_node: std.Progress.Node,
     argv: []const []const u8,
 ) !std.process.Child.RunResult {
     const arena = s.owner.allocator;
 
-    try handleChildProcUnsupported(s, null, argv);
+    // If an error occurs, it's happened in this command:
+    assert(s.result_failed_command == null);
+    s.result_failed_command = try allocPrintCmd(gpa, null, argv);
+
+    try handleChildProcUnsupported(s);
     try handleVerbose(s.owner, null, argv);
 
     const result = std.process.Child.run(.{
@@ -358,6 +390,7 @@ pub const ZigProcess = struct {
 
 /// Assumes that argv contains `--listen=-` and that the process being spawned
 /// is the zig compiler - the same version that compiled the build runner.
+/// Populates `s.result_failed_command`.
 pub fn evalZigProcess(
     s: *Step,
     argv: []const []const u8,
@@ -366,6 +399,10 @@ pub fn evalZigProcess(
     web_server: ?*Build.WebServer,
     gpa: Allocator,
 ) !?Path {
+    // If an error occurs, it's happened in this command:
+    assert(s.result_failed_command == null);
+    s.result_failed_command = try allocPrintCmd(gpa, null, argv);
+
     if (s.getZigProcess()) |zp| update: {
         assert(watch);
         if (std.Progress.have_ipc) if (zp.progress_ipc_fd) |fd| prog_node.setIpcFd(fd);
@@ -382,8 +419,9 @@ pub fn evalZigProcess(
             else => |e| return e,
         };
 
-        if (s.result_error_bundle.errorMessageCount() > 0)
+        if (s.result_error_bundle.errorMessageCount() > 0) {
             return s.fail("{d} compilation errors", .{s.result_error_bundle.errorMessageCount()});
+        }
 
         if (s.result_error_msgs.items.len > 0 and result == null) {
             // Crash detected.
@@ -392,7 +430,7 @@ pub fn evalZigProcess(
             };
             s.result_peak_rss = zp.child.resource_usage_statistics.getMaxRss() orelse 0;
             s.clearZigProcess(gpa);
-            try handleChildProcessTerm(s, term, null, argv);
+            try handleChildProcessTerm(s, term);
             return error.MakeFailed;
         }
 
@@ -402,7 +440,7 @@ pub fn evalZigProcess(
     const b = s.owner;
     const arena = b.allocator;
 
-    try handleChildProcUnsupported(s, null, argv);
+    try handleChildProcUnsupported(s);
     try handleVerbose(s.owner, null, argv);
 
     var child = std.process.Child.init(argv, arena);
@@ -456,16 +494,11 @@ pub fn evalZigProcess(
             else => {},
         };
 
-        try handleChildProcessTerm(s, term, null, argv);
+        try handleChildProcessTerm(s, term);
     }
 
-    // This is intentionally printed for failure on the first build but not for
-    // subsequent rebuilds.
     if (s.result_error_bundle.errorMessageCount() > 0) {
-        return s.fail("the following command failed with {d} compilation errors:\n{s}", .{
-            s.result_error_bundle.errorMessageCount(),
-            try allocPrintCmd(arena, null, argv),
-        });
+        return s.fail("{d} compilation errors", .{s.result_error_bundle.errorMessageCount()});
     }
 
     return result;
@@ -513,7 +546,6 @@ fn zigProcessUpdate(s: *Step, zp: *ZigProcess, watch: bool, web_server: ?*Build.
         const header = stdout.takeStruct(Header, .little) catch unreachable;
         while (stdout.buffered().len < header.bytes_len) if (!try zp.poller.poll()) break :poll;
         const body = stdout.take(header.bytes_len) catch unreachable;
-
         switch (header.tag) {
             .zig_version => {
                 if (!std.mem.eql(u8, builtin.zig_version_string, body)) {
@@ -669,54 +701,38 @@ pub fn handleVerbose2(
     }
 }
 
-pub inline fn handleChildProcUnsupported(
-    s: *Step,
-    opt_cwd: ?[]const u8,
-    argv: []const []const u8,
-) error{ OutOfMemory, MakeFailed }!void {
+/// Asserts that the caller has already populated `s.result_failed_command`.
+pub inline fn handleChildProcUnsupported(s: *Step) error{ OutOfMemory, MakeFailed }!void {
     if (!std.process.can_spawn) {
-        return s.fail(
-            "unable to execute the following command: host cannot spawn child processes\n{s}",
-            .{try allocPrintCmd(s.owner.allocator, opt_cwd, argv)},
-        );
+        return s.fail("unable to spawn process: host cannot spawn child processes", .{});
     }
 }
 
-pub fn handleChildProcessTerm(
-    s: *Step,
-    term: std.process.Child.Term,
-    opt_cwd: ?[]const u8,
-    argv: []const []const u8,
-) error{ MakeFailed, OutOfMemory }!void {
-    const arena = s.owner.allocator;
+/// Asserts that the caller has already populated `s.result_failed_command`.
+pub fn handleChildProcessTerm(s: *Step, term: std.process.Child.Term) error{ MakeFailed, OutOfMemory }!void {
+    assert(s.result_failed_command != null);
     switch (term) {
         .Exited => |code| {
             if (code != 0) {
-                return s.fail(
-                    "the following command exited with error code {d}:\n{s}",
-                    .{ code, try allocPrintCmd(arena, opt_cwd, argv) },
-                );
+                return s.fail("process exited with error code {d}", .{code});
             }
         },
         .Signal, .Stopped, .Unknown => {
-            return s.fail(
-                "the following command terminated unexpectedly:\n{s}",
-                .{try allocPrintCmd(arena, opt_cwd, argv)},
-            );
+            return s.fail("process terminated unexpectedly", .{});
         },
     }
 }
 
 pub fn allocPrintCmd(
-    arena: Allocator,
+    gpa: Allocator,
     opt_cwd: ?[]const u8,
     argv: []const []const u8,
 ) Allocator.Error![]u8 {
-    return allocPrintCmd2(arena, opt_cwd, null, argv);
+    return allocPrintCmd2(gpa, opt_cwd, null, argv);
 }
 
 pub fn allocPrintCmd2(
-    arena: Allocator,
+    gpa: Allocator,
     opt_cwd: ?[]const u8,
     opt_env: ?*const std.process.EnvMap,
     argv: []const []const u8,
@@ -756,11 +772,13 @@ pub fn allocPrintCmd2(
         }
     };
 
-    var aw: std.Io.Writer.Allocating = .init(arena);
+    var aw: std.Io.Writer.Allocating = .init(gpa);
+    defer aw.deinit();
     const writer = &aw.writer;
     if (opt_cwd) |cwd| writer.print("cd {s} && ", .{cwd}) catch return error.OutOfMemory;
     if (opt_env) |env| {
-        const process_env_map = std.process.getEnvMap(arena) catch std.process.EnvMap.init(arena);
+        var process_env_map = std.process.getEnvMap(gpa) catch std.process.EnvMap.init(gpa);
+        defer process_env_map.deinit();
         var it = env.iterator();
         while (it.next()) |entry| {
             const key = entry.key_ptr.*;
@@ -946,11 +964,14 @@ fn addWatchInputFromPath(step: *Step, path: Build.Cache.Path, basename: []const
 pub fn reset(step: *Step, gpa: Allocator) void {
     assert(step.state == .precheck_done);
 
+    if (step.result_failed_command) |cmd| gpa.free(cmd);
+
     step.result_error_msgs.clearRetainingCapacity();
     step.result_stderr = "";
     step.result_cached = false;
     step.result_duration_ns = null;
     step.result_peak_rss = 0;
+    step.result_failed_command = null;
     step.test_results = .{};
 
     step.result_error_bundle.deinit(gpa);