From 7e7d7875b9af97bd04ca03a98b2e4188d57e3c13 Mon Sep 17 00:00:00 2001 From: mlugg Date: Thu, 21 Aug 2025 13:44:43 +0100 Subject: std.Build: implement unit test timeouts For now, there is a flag to `zig build` called `--test-timeout-ms` which accepts a value in milliseconds. If the execution time of any individual unit test exceeds that number of milliseconds, the test is terminated and marked as timed out. In the future, we may want to increase the granularity of this feature by allowing timeouts to be specified per-step or even per-test. However, a global option is actually very useful. In particular, it can be used in CI scripts to ensure that no individual unit test exceeds some reasonable limit (e.g. 60 seconds) without having to assign limits to every individual test step in the build script. Also, individual unit test durations are now shown in the time report web interface -- this was fairly trivial to add since we're timing tests (to check for timeouts) anyway. This commit makes progress on #19821, but does not close it, because that proposal includes a more sophisticated mechanism for setting timeouts. Co-Authored-By: David Rubin --- lib/std/Build/Step/Run.zig | 194 +++++++++++++++++++++++++++++++++++++++------ 1 file changed, 169 insertions(+), 25 deletions(-) (limited to 'lib/std/Build/Step') diff --git a/lib/std/Build/Step/Run.zig b/lib/std/Build/Step/Run.zig index e6ee5ad233..a001976441 100644 --- a/lib/std/Build/Step/Run.zig +++ b/lib/std/Build/Step/Run.zig @@ -756,7 +756,6 @@ const IndexedOutput = struct { output: *Output, }; fn make(step: *Step, options: Step.MakeOptions) !void { - const prog_node = options.progress_node; const b = step.owner; const arena = b.allocator; const run: *Run = @fieldParentPtr("step", step); @@ -964,7 +963,7 @@ fn make(step: *Step, options: Step.MakeOptions) !void { b.fmt("{s}{s}", .{ placeholder.output.prefix, arg_output_path }); } - try runCommand(run, argv_list.items, has_side_effects, output_dir_path, prog_node, null); + try runCommand(run, argv_list.items, has_side_effects, output_dir_path, options, null); if (!has_side_effects) try step.writeManifestAndWatch(&man); return; }; @@ -997,7 +996,7 @@ fn make(step: *Step, options: Step.MakeOptions) !void { }); } - try runCommand(run, argv_list.items, has_side_effects, tmp_dir_path, prog_node, null); + try runCommand(run, argv_list.items, has_side_effects, tmp_dir_path, options, null); const dep_file_dir = std.fs.cwd(); const dep_file_basename = dep_output_file.generated_file.getPath2(b, step); @@ -1115,7 +1114,14 @@ pub fn rerunInFuzzMode( const has_side_effects = false; const rand_int = std.crypto.random.int(u64); const tmp_dir_path = "tmp" ++ fs.path.sep_str ++ std.fmt.hex(rand_int); - try runCommand(run, argv_list.items, has_side_effects, tmp_dir_path, prog_node, .{ + try runCommand(run, argv_list.items, has_side_effects, tmp_dir_path, .{ + .progress_node = prog_node, + .thread_pool = undefined, // not used by `runCommand` + .watch = undefined, // not used by `runCommand` + .web_server = null, // only needed for time reports + .unit_test_timeout_ns = null, // don't time out fuzz tests for now + .gpa = undefined, // not used by `runCommand` + }, .{ .unit_test_index = unit_test_index, .fuzz = fuzz, }); @@ -1196,7 +1202,7 @@ fn runCommand( argv: []const []const u8, has_side_effects: bool, output_dir_path: []const u8, - prog_node: std.Progress.Node, + options: Step.MakeOptions, fuzz_context: ?FuzzContext, ) !void { const step = &run.step; @@ -1218,7 +1224,7 @@ fn runCommand( var env_map = run.env_map orelse &b.graph.env_map; - const result = spawnChildAndCollect(run, argv, env_map, has_side_effects, prog_node, fuzz_context) catch |err| term: { + const result = spawnChildAndCollect(run, argv, env_map, has_side_effects, options, fuzz_context) catch |err| term: { // InvalidExe: cpu arch mismatch // FileNotFound: can happen with a wrong dynamic linker path if (err == error.InvalidExe or err == error.FileNotFound) interpret: { @@ -1357,7 +1363,7 @@ fn runCommand( try Step.handleVerbose2(step.owner, cwd, run.env_map, interp_argv.items); - break :term spawnChildAndCollect(run, interp_argv.items, env_map, has_side_effects, prog_node, fuzz_context) catch |e| { + break :term spawnChildAndCollect(run, interp_argv.items, env_map, has_side_effects, options, fuzz_context) catch |e| { if (!run.failing_to_execute_foreign_is_an_error) return error.MakeSkipped; return step.fail("unable to spawn interpreter {s}: {s}", .{ @@ -1372,8 +1378,14 @@ fn runCommand( step.result_duration_ns = result.elapsed_ns; step.result_peak_rss = result.peak_rss; step.test_results = result.stdio.test_results; - if (result.stdio.test_metadata) |tm| + if (result.stdio.test_metadata) |tm| { run.cached_test_metadata = tm.toCachedTestMetadata(); + if (options.web_server) |ws| ws.updateTimeReportRunTest( + run, + &run.cached_test_metadata.?, + tm.ns_per_test, + ); + } const final_argv = if (interp_argv.items.len == 0) argv else interp_argv.items; @@ -1558,7 +1570,7 @@ fn spawnChildAndCollect( argv: []const []const u8, env_map: *EnvMap, has_side_effects: bool, - prog_node: std.Progress.Node, + options: Step.MakeOptions, fuzz_context: ?FuzzContext, ) !ChildProcResult { const b = run.step.owner; @@ -1604,7 +1616,7 @@ fn spawnChildAndCollect( const inherit = child.stdout_behavior == .Inherit or child.stderr_behavior == .Inherit; if (run.stdio != .zig_test and !run.disable_zig_progress and !inherit) { - child.progress_node = prog_node; + child.progress_node = options.progress_node; } const term, const result, const elapsed_ns = t: { @@ -1622,7 +1634,7 @@ fn spawnChildAndCollect( var timer = try std.time.Timer.start(); const result = if (run.stdio == .zig_test) - try evalZigTest(run, &child, prog_node, fuzz_context) + try evalZigTest(run, &child, options, fuzz_context) else try evalGeneric(run, &child); @@ -1647,13 +1659,15 @@ const StdIoResult = struct { fn evalZigTest( run: *Run, child: *std.process.Child, - prog_node: std.Progress.Node, + options: Step.MakeOptions, fuzz_context: ?FuzzContext, ) !StdIoResult { const gpa = run.step.owner.allocator; const arena = run.step.owner.allocator; - var poller = std.Io.poll(gpa, enum { stdout, stderr }, .{ + const PollEnum = enum { stdout, stderr }; + + var poller = std.Io.poll(gpa, PollEnum, .{ .stdout = child.stdout.?, .stderr = child.stderr.?, }); @@ -1692,21 +1706,126 @@ fn evalZigTest( var fail_count: u32 = 0; var skip_count: u32 = 0; var leak_count: u32 = 0; + var timeout_count: u32 = 0; var test_count: u32 = 0; var log_err_count: u32 = 0; var metadata: ?TestMetadata = null; var coverage_id: ?u64 = null; + var test_is_running = false; + + // String allocated into `gpa`. Owned by this function while it runs, then moved to the `Step`. + var result_stderr: []u8 = &.{}; + defer run.step.result_stderr = result_stderr; + + // `null` means this host does not support `std.time.Timer`. This timer is `reset()` whenever we + // toggle `test_is_running`, i.e. whenever a test starts or finishes. + var timer: ?std.time.Timer = std.time.Timer.start() catch t: { + std.log.warn("std.time.Timer not supported on host; test timeouts will be ignored", .{}); + break :t null; + }; + var sub_prog_node: ?std.Progress.Node = null; defer if (sub_prog_node) |n| n.end(); - const stdout = poller.reader(.stdout); - const stderr = poller.reader(.stderr); + // This timeout is used when we're waiting on the test runner itself rather than a user-specified + // test. For instance, if the test runner leaves this much time between us requesting a test to + // start and it acknowledging the test starting, we terminate the child and raise an error. This + // *should* never happen, but could in theory be caused by some very unlucky IB in a test. + const response_timeout_ns = 30 * std.time.ns_per_s; + const any_write_failed = first_write_failed or poll: while (true) { + // These are scoped inside the loop because we sometimes respawn the child and recreate + // `poller` which invaldiates these readers. + const stdout = poller.reader(.stdout); + const stderr = poller.reader(.stderr); + const Header = std.zig.Server.Message.Header; - while (stdout.buffered().len < @sizeOf(Header)) if (!try poller.poll()) break :poll false; + + // This block is exited when `stdout` contains enough bytes for a `Header`. + header_ready: { + if (stdout.buffered().len >= @sizeOf(Header)) { + // We already have one, no need to poll! + break :header_ready; + } + + // Always `null` if `timer` is `null`. + const opt_timeout_ns: ?u64 = ns: { + if (timer == null) break :ns null; + if (!test_is_running) break :ns response_timeout_ns; + break :ns options.unit_test_timeout_ns; + }; + + if (opt_timeout_ns) |timeout_ns| { + const remaining_ns = timeout_ns -| timer.?.read(); + if (!try poller.pollTimeout(remaining_ns)) break :poll false; + } else { + if (!try poller.poll()) break :poll false; + } + + if (stdout.buffered().len >= @sizeOf(Header)) { + // There wasn't a header before, but there is one after the `poll`. + break :header_ready; + } + + const timeout_ns = opt_timeout_ns orelse continue; + const cur_ns = timer.?.read(); + if (cur_ns < timeout_ns) continue; + + // There was a timeout. + + if (!test_is_running) { + // The child stopped responding while *not* running a test. To avoid getting into + // a loop if something's broken, don't retry; just report an error and stop. + try run.step.addError("test runner failed to respond for {D}", .{cur_ns}); + break :poll false; + } + + // A test has probably just gotten stuck. We'll report an error, then just kill the + // child and continue with the next test in the list. + + const md = &metadata.?; + const test_index = md.next_index - 1; + + timeout_count += 1; + try run.step.addError( + "'{s}' timed out after {D}", + .{ md.testName(test_index), cur_ns }, + ); + if (stderr.buffered().len > 0) { + const new_bytes = stderr.buffered(); + const old_len = result_stderr.len; + result_stderr = try gpa.realloc(result_stderr, old_len + new_bytes.len); + @memcpy(result_stderr[old_len..], new_bytes); + } + + _ = try child.kill(); + // Respawn the test runner. There's a double-cleanup if this fails, but that's + // fine because our caller's `kill` will just return `error.AlreadyTerminated`. + try child.spawn(); + try child.waitForSpawn(); + + // After respawning the child, we must update the poller's streams. + poller.deinit(); + poller = std.Io.poll(gpa, PollEnum, .{ + .stdout = child.stdout.?, + .stderr = child.stderr.?, + }); + + test_is_running = false; + md.ns_per_test[test_index] = timer.?.lap(); + + requestNextTest(child.stdin.?, md, &sub_prog_node) catch |err| { + try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); + break :poll true; + }; + + continue :poll; // continue work with the new (respawned) child + } + // There is definitely a header available now -- read it. const header = stdout.takeStruct(Header, .little) catch unreachable; + while (stdout.buffered().len < header.bytes_len) if (!try poller.poll()) break :poll false; const body = stdout.take(header.bytes_len) catch unreachable; switch (header.tag) { @@ -1720,6 +1839,12 @@ fn evalZigTest( }, .test_metadata => { assert(fuzz_context == null); + + // `metadata` would only be populated if we'd already seen a `test_metadata`, but we + // only request it once (and importantly, we don't re-request it if we kill and + // restart the test runner). + assert(metadata == null); + const TmHdr = std.zig.Server.Message.TestMetadata; const tm_hdr = @as(*align(1) const TmHdr, @ptrCast(body)); test_count = tm_hdr.tests_len; @@ -1730,32 +1855,42 @@ fn evalZigTest( const names = std.mem.bytesAsSlice(u32, names_bytes); const expected_panic_msgs = std.mem.bytesAsSlice(u32, expected_panic_msgs_bytes); + const names_aligned = try arena.alloc(u32, names.len); for (names_aligned, names) |*dest, src| dest.* = src; const expected_panic_msgs_aligned = try arena.alloc(u32, expected_panic_msgs.len); for (expected_panic_msgs_aligned, expected_panic_msgs) |*dest, src| dest.* = src; - prog_node.setEstimatedTotalItems(names.len); + options.progress_node.setEstimatedTotalItems(names.len); metadata = .{ .string_bytes = try arena.dupe(u8, string_bytes), + .ns_per_test = try arena.alloc(u64, test_count), .names = names_aligned, .expected_panic_msgs = expected_panic_msgs_aligned, .next_index = 0, - .prog_node = prog_node, + .prog_node = options.progress_node, }; + @memset(metadata.?.ns_per_test, std.math.maxInt(u64)); + + test_is_running = false; + if (timer) |*t| t.reset(); requestNextTest(child.stdin.?, &metadata.?, &sub_prog_node) catch |err| { try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); break :poll true; }; }, + .test_started => { + test_is_running = true; + if (timer) |*t| t.reset(); + }, .test_results => { assert(fuzz_context == null); - const md = metadata.?; + const md = &metadata.?; const TrHdr = std.zig.Server.Message.TestResults; - const tr_hdr = @as(*align(1) const TrHdr, @ptrCast(body)); + const tr_hdr: *align(1) const TrHdr = @ptrCast(body); fail_count +|= @intFromBool(tr_hdr.flags.fail); skip_count +|= @intFromBool(tr_hdr.flags.skip); leak_count +|= @intFromBool(tr_hdr.flags.leak); @@ -1764,7 +1899,7 @@ fn evalZigTest( if (tr_hdr.flags.fuzz) try run.fuzz_tests.append(gpa, tr_hdr.index); if (tr_hdr.flags.fail or tr_hdr.flags.leak or tr_hdr.flags.log_err_count > 0) { - const name = std.mem.sliceTo(md.string_bytes[md.names[tr_hdr.index]..], 0); + const name = std.mem.sliceTo(md.testName(tr_hdr.index), 0); const stderr_contents = stderr.buffered(); stderr.toss(stderr_contents.len); const msg = std.mem.trim(u8, stderr_contents, "\n"); @@ -1783,7 +1918,10 @@ fn evalZigTest( } } - requestNextTest(child.stdin.?, &metadata.?, &sub_prog_node) catch |err| { + test_is_running = false; + if (timer) |*t| md.ns_per_test[tr_hdr.index] = t.lap(); + + requestNextTest(child.stdin.?, md, &sub_prog_node) catch |err| { try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); break :poll true; }; @@ -1831,9 +1969,12 @@ fn evalZigTest( while (try poller.poll()) {} } - const stderr_contents = std.mem.trim(u8, stderr.buffered(), "\n"); - if (stderr_contents.len > 0) { - run.step.result_stderr = try arena.dupe(u8, stderr_contents); + const stderr = poller.reader(.stderr); + if (stderr.buffered().len > 0) { + const new_bytes = stderr.buffered(); + const old_len = result_stderr.len; + result_stderr = try gpa.realloc(result_stderr, old_len + new_bytes.len); + @memcpy(result_stderr[old_len..], new_bytes); } // Send EOF to stdin. @@ -1848,6 +1989,7 @@ fn evalZigTest( .fail_count = fail_count, .skip_count = skip_count, .leak_count = leak_count, + .timeout_count = timeout_count, .log_err_count = log_err_count, }, .test_metadata = metadata, @@ -1856,6 +1998,7 @@ fn evalZigTest( const TestMetadata = struct { names: []const u32, + ns_per_test: []u64, expected_panic_msgs: []const u32, string_bytes: []const u8, next_index: u32, @@ -1896,6 +2039,7 @@ fn requestNextTest(in: fs.File, metadata: *TestMetadata, sub_prog_node: *?std.Pr try sendRunTestMessage(in, .run_test, i); return; } else { + metadata.next_index = std.math.maxInt(u32); // indicate that all tests are done try sendMessage(in, .exit); } } -- cgit v1.2.3 From e4456d03f3642c4d0e19176aa09dbc12099e7a4c Mon Sep 17 00:00:00 2001 From: mlugg Date: Tue, 26 Aug 2025 15:34:53 +0100 Subject: std.Build.Step.Run: many enhancements This is a major refactor to `Step.Run` which adds new functionality, primarily to the execution of Zig tests. * All tests are run, even if a test crashes. This happens through the same mechanism as timeouts where the test processes is repeatedly respawned as needed. * The build status output is more precise. For each unit test, it differentiates pass, skip, fail, crash, and timeout. Memory leaks are reported separately, as they do not indicate a test's "status", but are rather an additional property (a test with leaks may still pass!). * The number of memory leaks is tracked and reported, both per-test and for a whole `Run` step. * Reporting is made clearer when a step is failed solely due to error logs (`std.log.err`) where every unit test passed. --- lib/compiler/build_runner.zig | 110 ++++--- lib/compiler/test_runner.zig | 27 +- lib/std/Build/Step.zig | 34 ++- lib/std/Build/Step/Run.zig | 611 +++++++++++++++++++++------------------ lib/std/heap/debug_allocator.zig | 26 +- lib/std/zig/Server.zig | 13 +- 6 files changed, 465 insertions(+), 356 deletions(-) (limited to 'lib/std/Build/Step') diff --git a/lib/compiler/build_runner.zig b/lib/compiler/build_runner.zig index 5bd71d0c5c..f87a121993 100644 --- a/lib/compiler/build_runner.zig +++ b/lib/compiler/build_runner.zig @@ -735,11 +735,12 @@ fn runStepNames( assert(run.memory_blocked_steps.items.len == 0); + var test_pass_count: usize = 0; var test_skip_count: usize = 0; var test_fail_count: usize = 0; - var test_pass_count: usize = 0; - var test_leak_count: usize = 0; + var test_crash_count: usize = 0; var test_timeout_count: usize = 0; + var test_count: usize = 0; var success_count: usize = 0; @@ -749,11 +750,12 @@ fn runStepNames( var total_compile_errors: usize = 0; for (step_stack.keys()) |s| { - test_fail_count += s.test_results.fail_count; + test_pass_count += s.test_results.passCount(); test_skip_count += s.test_results.skip_count; - test_leak_count += s.test_results.leak_count; + test_fail_count += s.test_results.fail_count; + test_crash_count += s.test_results.crash_count; test_timeout_count += s.test_results.timeout_count; - test_pass_count += s.test_results.passCount(); + test_count += s.test_results.test_count; switch (s.state) { @@ -822,6 +824,9 @@ fn runStepNames( f.waitAndPrintReport(); } + // Every test has a state + assert(test_pass_count + test_skip_count + test_fail_count + test_crash_count + test_timeout_count == test_count); + // A proper command line application defaults to silently succeeding. // The user may request verbose mode if they have a different preference. const failures_only = switch (run.summary) { @@ -844,14 +849,16 @@ fn runStepNames( w.writeAll("\nBuild Summary:") catch {}; ttyconf.setColor(w, .reset) catch {}; w.print(" {d}/{d} steps succeeded", .{ success_count, total_count }) catch {}; - if (skipped_count > 0) w.print("; {d} skipped", .{skipped_count}) catch {}; - if (failure_count > 0) w.print("; {d} failed", .{failure_count}) catch {}; - - if (test_count > 0) w.print("; {d}/{d} tests passed", .{ test_pass_count, test_count }) catch {}; - if (test_skip_count > 0) w.print("; {d} skipped", .{test_skip_count}) catch {}; - if (test_fail_count > 0) w.print("; {d} failed", .{test_fail_count}) catch {}; - if (test_leak_count > 0) w.print("; {d} leaked", .{test_leak_count}) catch {}; - if (test_timeout_count > 0) w.print("; {d} timed out", .{test_timeout_count}) catch {}; + if (skipped_count > 0) w.print(", {d} skipped", .{skipped_count}) catch {}; + if (failure_count > 0) w.print(", {d} failed", .{failure_count}) catch {}; + + if (test_count > 0) { + w.print("; {d}/{d} tests passed", .{ test_pass_count, test_count }) catch {}; + if (test_skip_count > 0) w.print(", {d} skipped", .{test_skip_count}) catch {}; + if (test_fail_count > 0) w.print(", {d} failed", .{test_fail_count}) catch {}; + if (test_crash_count > 0) w.print(", {d} crashed", .{test_crash_count}) catch {}; + if (test_timeout_count > 0) w.print(", {d} timed out", .{test_timeout_count}) catch {}; + } w.writeAll("\n") catch {}; @@ -961,11 +968,16 @@ fn printStepStatus( try stderr.writeAll(" cached"); } else if (s.test_results.test_count > 0) { const pass_count = s.test_results.passCount(); + assert(s.test_results.test_count == pass_count + s.test_results.skip_count); try stderr.print(" {d} passed", .{pass_count}); if (s.test_results.skip_count > 0) { + try ttyconf.setColor(stderr, .white); + try stderr.writeAll(", "); try ttyconf.setColor(stderr, .yellow); - try stderr.print(" {d} skipped", .{s.test_results.skip_count}); + try stderr.print("{d} skipped", .{s.test_results.skip_count}); } + try ttyconf.setColor(stderr, .white); + try stderr.print(" ({d} total)", .{s.test_results.test_count}); } else { try stderr.writeAll(" success"); } @@ -1031,41 +1043,64 @@ fn printStepFailure( s.result_error_bundle.errorMessageCount(), }); } else if (!s.test_results.isSuccess()) { - try stderr.print(" {d}/{d} passed", .{ - s.test_results.passCount(), s.test_results.test_count, - }); - if (s.test_results.fail_count > 0) { + // These first values include all of the test "statuses". Every test is either passsed, + // skipped, failed, crashed, or timed out. + try ttyconf.setColor(stderr, .green); + try stderr.print(" {d} passed", .{s.test_results.passCount()}); + try ttyconf.setColor(stderr, .white); + if (s.test_results.skip_count > 0) { try stderr.writeAll(", "); - try ttyconf.setColor(stderr, .red); - try stderr.print("{d} failed", .{ - s.test_results.fail_count, - }); + try ttyconf.setColor(stderr, .yellow); + try stderr.print("{d} skipped", .{s.test_results.skip_count}); try ttyconf.setColor(stderr, .white); } - if (s.test_results.skip_count > 0) { + if (s.test_results.fail_count > 0) { try stderr.writeAll(", "); - try ttyconf.setColor(stderr, .yellow); - try stderr.print("{d} skipped", .{ - s.test_results.skip_count, - }); + try ttyconf.setColor(stderr, .red); + try stderr.print("{d} failed", .{s.test_results.fail_count}); try ttyconf.setColor(stderr, .white); } - if (s.test_results.leak_count > 0) { + if (s.test_results.crash_count > 0) { try stderr.writeAll(", "); try ttyconf.setColor(stderr, .red); - try stderr.print("{d} leaked", .{ - s.test_results.leak_count, - }); + try stderr.print("{d} crashed", .{s.test_results.crash_count}); try ttyconf.setColor(stderr, .white); } if (s.test_results.timeout_count > 0) { try stderr.writeAll(", "); try ttyconf.setColor(stderr, .red); - try stderr.print("{d} timed out", .{ - s.test_results.timeout_count, - }); + try stderr.print("{d} timed out", .{s.test_results.timeout_count}); + try ttyconf.setColor(stderr, .white); + } + try stderr.print(" ({d} total)", .{s.test_results.test_count}); + + // Memory leaks are intentionally written after the total, because is isn't a test *status*, + // but just a flag that any tests -- even passed ones -- can have. We also use a different + // separator, so it looks like: + // 2 passed, 1 skipped, 2 failed (5 total); 2 leaks + if (s.test_results.leak_count > 0) { + try stderr.writeAll("; "); + try ttyconf.setColor(stderr, .red); + try stderr.print("{d} leaks", .{s.test_results.leak_count}); try ttyconf.setColor(stderr, .white); } + + // It's usually not helpful to know how many error logs there were because they tend to + // just come with other errors (e.g. crashes and leaks print stack traces, and clean + // failures print error traces). So only mention them if they're the only thing causing + // the failure. + const show_err_logs: bool = show: { + var alt_results = s.test_results; + alt_results.log_err_count = 0; + break :show alt_results.isSuccess(); + }; + if (show_err_logs) { + try stderr.writeAll("; "); + try ttyconf.setColor(stderr, .red); + try stderr.print("{d} error logs", .{s.test_results.log_err_count}); + try ttyconf.setColor(stderr, .white); + } + try stderr.writeAll("\n"); } else if (s.result_error_msgs.items.len > 0) { try ttyconf.setColor(stderr, .red); @@ -1400,7 +1435,12 @@ pub fn printErrorMessages( try ttyconf.setColor(stderr, .red); try stderr.writeAll("error: "); try ttyconf.setColor(stderr, .reset); - try stderr.writeAll(msg); + // If the message has multiple lines, indent the non-initial ones to align them with the 'error:' text. + var it = std.mem.splitScalar(u8, msg, '\n'); + try stderr.writeAll(it.first()); + while (it.next()) |line| { + try stderr.print("\n {s}", .{line}); + } try stderr.writeAll("\n"); } } diff --git a/lib/compiler/test_runner.zig b/lib/compiler/test_runner.zig index 7425356c37..adb3e9e90a 100644 --- a/lib/compiler/test_runner.zig +++ b/lib/compiler/test_runner.zig @@ -132,34 +132,39 @@ fn mainServer() !void { log_err_count = 0; const index = try server.receiveBody_u32(); const test_fn = builtin.test_functions[index]; - var fail = false; - var skip = false; is_fuzz_test = false; // let the build server know we're starting the test now try server.serveStringMessage(.test_started, &.{}); - test_fn.func() catch |err| switch (err) { - error.SkipZigTest => skip = true, - else => { - fail = true; + const TestResults = std.zig.Server.Message.TestResults; + const status: TestResults.Status = if (test_fn.func()) |v| s: { + v; + break :s .pass; + } else |err| switch (err) { + error.SkipZigTest => .skip, + else => s: { if (@errorReturnTrace()) |trace| { std.debug.dumpStackTrace(trace); } + break :s .fail; }, }; - const leak = testing.allocator_instance.deinit() == .leak; + const leak_count = testing.allocator_instance.detectLeaks(); + testing.allocator_instance.deinitWithoutLeakChecks(); try server.serveTestResults(.{ .index = index, .flags = .{ - .fail = fail, - .skip = skip, - .leak = leak, + .status = status, .fuzz = is_fuzz_test, .log_err_count = std.math.lossyCast( - @FieldType(std.zig.Server.Message.TestResults.Flags, "log_err_count"), + @FieldType(TestResults.Flags, "log_err_count"), log_err_count, ), + .leak_count = std.math.lossyCast( + @FieldType(TestResults.Flags, "leak_count"), + leak_count, + ), }, }); }, diff --git a/lib/std/Build/Step.zig b/lib/std/Build/Step.zig index 29b2d2ce94..7b72d9a825 100644 --- a/lib/std/Build/Step.zig +++ b/lib/std/Build/Step.zig @@ -63,19 +63,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, - leak_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 and tr.timeout_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 - tr.timeout_count; + return tr.test_count - tr.skip_count - tr.fail_count - tr.crash_count - tr.timeout_count; } }; diff --git a/lib/std/Build/Step/Run.zig b/lib/std/Build/Step/Run.zig index a001976441..39eb276b48 100644 --- a/lib/std/Build/Step/Run.zig +++ b/lib/std/Build/Step/Run.zig @@ -630,6 +630,8 @@ pub fn addCheck(run: *Run, new_check: StdIo.Check) void { pub fn captureStdErr(run: *Run, options: CapturedStdIo.Options) std.Build.LazyPath { assert(run.stdio != .inherit); + assert(run.stdio != .zig_test); + const b = run.step.owner; if (run.captured_stderr) |captured| return .{ .generated = .{ .file = &captured.output.generated_file } }; @@ -649,6 +651,8 @@ pub fn captureStdErr(run: *Run, options: CapturedStdIo.Options) std.Build.LazyPa pub fn captureStdOut(run: *Run, options: CapturedStdIo.Options) std.Build.LazyPath { assert(run.stdio != .inherit); + assert(run.stdio != .zig_test); + const b = run.step.owner; if (run.captured_stdout) |captured| return .{ .generated = .{ .file = &captured.output.generated_file } }; @@ -1224,7 +1228,7 @@ fn runCommand( var env_map = run.env_map orelse &b.graph.env_map; - const result = spawnChildAndCollect(run, argv, env_map, has_side_effects, options, fuzz_context) catch |err| term: { + const opt_generic_result = spawnChildAndCollect(run, argv, env_map, has_side_effects, options, fuzz_context) catch |err| term: { // InvalidExe: cpu arch mismatch // FileNotFound: can happen with a wrong dynamic linker path if (err == error.InvalidExe or err == error.FileNotFound) interpret: { @@ -1365,34 +1369,34 @@ fn runCommand( break :term spawnChildAndCollect(run, interp_argv.items, env_map, has_side_effects, options, fuzz_context) catch |e| { if (!run.failing_to_execute_foreign_is_an_error) return error.MakeSkipped; - + if (e == error.MakeFailed) return error.MakeFailed; // error already reported return step.fail("unable to spawn interpreter {s}: {s}", .{ interp_argv.items[0], @errorName(e), }); }; } + if (err == error.MakeFailed) return error.MakeFailed; // error already reported return step.fail("failed to spawn and capture stdio from {s}: {s}", .{ argv[0], @errorName(err) }); }; - step.result_duration_ns = result.elapsed_ns; - step.result_peak_rss = result.peak_rss; - step.test_results = result.stdio.test_results; - if (result.stdio.test_metadata) |tm| { - run.cached_test_metadata = tm.toCachedTestMetadata(); - if (options.web_server) |ws| ws.updateTimeReportRunTest( - run, - &run.cached_test_metadata.?, - tm.ns_per_test, - ); - } - const final_argv = if (interp_argv.items.len == 0) argv else interp_argv.items; - if (fuzz_context != null) { - try step.handleChildProcessTerm(result.term, cwd, final_argv); + const generic_result = opt_generic_result orelse { + assert(run.stdio == .zig_test); + // Specific errors have already been reported. All we need to do is detect those and + // report the general "test failed" error, which includes the command argv. + if (!step.test_results.isSuccess() or step.result_error_msgs.items.len > 0) { + return step.fail( + "the following test command failed:\n{s}", + .{try Step.allocPrintCmd(arena, cwd, final_argv)}, + ); + } return; - } + }; + + assert(fuzz_context == null); + assert(run.stdio != .zig_test); // Capture stdout and stderr to GeneratedFile objects. const Stream = struct { @@ -1402,11 +1406,11 @@ fn runCommand( for ([_]Stream{ .{ .captured = run.captured_stdout, - .bytes = result.stdio.stdout, + .bytes = generic_result.stdout, }, .{ .captured = run.captured_stderr, - .bytes = result.stdio.stderr, + .bytes = generic_result.stderr, }, }) |stream| { if (stream.captured) |captured| { @@ -1436,9 +1440,10 @@ fn runCommand( } switch (run.stdio) { + .zig_test => unreachable, .check => |checks| for (checks.items) |check| switch (check) { .expect_stderr_exact => |expected_bytes| { - if (!mem.eql(u8, expected_bytes, result.stdio.stderr.?)) { + if (!mem.eql(u8, expected_bytes, generic_result.stderr.?)) { return step.fail( \\ \\========= expected this stderr: ========= @@ -1449,13 +1454,13 @@ fn runCommand( \\{s} , .{ expected_bytes, - result.stdio.stderr.?, + generic_result.stderr.?, try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_stderr_match => |match| { - if (mem.indexOf(u8, result.stdio.stderr.?, match) == null) { + if (mem.indexOf(u8, generic_result.stderr.?, match) == null) { return step.fail( \\ \\========= expected to find in stderr: ========= @@ -1466,13 +1471,13 @@ fn runCommand( \\{s} , .{ match, - result.stdio.stderr.?, + generic_result.stderr.?, try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_stdout_exact => |expected_bytes| { - if (!mem.eql(u8, expected_bytes, result.stdio.stdout.?)) { + if (!mem.eql(u8, expected_bytes, generic_result.stdout.?)) { return step.fail( \\ \\========= expected this stdout: ========= @@ -1483,13 +1488,13 @@ fn runCommand( \\{s} , .{ expected_bytes, - result.stdio.stdout.?, + generic_result.stdout.?, try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_stdout_match => |match| { - if (mem.indexOf(u8, result.stdio.stdout.?, match) == null) { + if (mem.indexOf(u8, generic_result.stdout.?, match) == null) { return step.fail( \\ \\========= expected to find in stdout: ========= @@ -1500,69 +1505,45 @@ fn runCommand( \\{s} , .{ match, - result.stdio.stdout.?, + generic_result.stdout.?, try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_term => |expected_term| { - if (!termMatches(expected_term, result.term)) { + if (!termMatches(expected_term, generic_result.term)) { return step.fail("the following command {f} (expected {f}):\n{s}", .{ - fmtTerm(result.term), + fmtTerm(generic_result.term), fmtTerm(expected_term), try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, }, - .zig_test => { - const prefix: []const u8 = p: { - if (result.stdio.test_metadata) |tm| { - if (tm.next_index > 0 and tm.next_index <= tm.names.len) { - const name = tm.testName(tm.next_index - 1); - break :p b.fmt("while executing test '{s}', ", .{name}); - } - } - break :p ""; - }; - const expected_term: std.process.Child.Term = .{ .Exited = 0 }; - if (!termMatches(expected_term, result.term)) { - return step.fail("{s}the following command {f} (expected {f}):\n{s}", .{ - prefix, - fmtTerm(result.term), - fmtTerm(expected_term), - try Step.allocPrintCmd(arena, cwd, final_argv), - }); - } - if (!result.stdio.test_results.isSuccess()) { - return step.fail( - "{s}the following test command failed:\n{s}", - .{ prefix, try Step.allocPrintCmd(arena, cwd, final_argv) }, - ); - } - }, else => { // On failure, print stderr if captured. - const bad_exit = switch (result.term) { + const bad_exit = switch (generic_result.term) { .Exited => |code| code != 0, .Signal, .Stopped, .Unknown => true, }; - if (bad_exit) if (result.stdio.stderr) |err| { + if (bad_exit) if (generic_result.stderr) |err| { try step.addError("stderr:\n{s}", .{err}); }; - try step.handleChildProcessTerm(result.term, cwd, final_argv); + try step.handleChildProcessTerm(generic_result.term, cwd, final_argv); }, } } -const ChildProcResult = struct { +const EvalZigTestResult = struct { + test_results: Step.TestResults, + test_metadata: ?TestMetadata, +}; +const EvalGenericResult = struct { term: std.process.Child.Term, - elapsed_ns: u64, - peak_rss: usize, - - stdio: StdIoResult, + stdout: ?[]const u8, + stderr: ?[]const u8, }; fn spawnChildAndCollect( @@ -1572,7 +1553,7 @@ fn spawnChildAndCollect( has_side_effects: bool, options: Step.MakeOptions, fuzz_context: ?FuzzContext, -) !ChildProcResult { +) !?EvalGenericResult { const b = run.step.owner; const arena = b.allocator; @@ -1613,121 +1594,237 @@ fn spawnChildAndCollect( child.stdin_behavior = .Pipe; } - const inherit = child.stdout_behavior == .Inherit or child.stderr_behavior == .Inherit; - - if (run.stdio != .zig_test and !run.disable_zig_progress and !inherit) { - child.progress_node = options.progress_node; - } - - const term, const result, const elapsed_ns = t: { + if (run.stdio == .zig_test) { + var timer = try std.time.Timer.start(); + const res = try evalZigTest(run, &child, options, fuzz_context); + run.step.result_duration_ns = timer.read(); + run.step.test_results = res.test_results; + if (res.test_metadata) |tm| { + run.cached_test_metadata = tm.toCachedTestMetadata(); + if (options.web_server) |ws| ws.updateTimeReportRunTest( + run, + &run.cached_test_metadata.?, + tm.ns_per_test, + ); + } + return null; + } else { + const inherit = child.stdout_behavior == .Inherit or child.stderr_behavior == .Inherit; + if (!run.disable_zig_progress and !inherit) { + child.progress_node = options.progress_node; + } if (inherit) std.debug.lockStdErr(); defer if (inherit) std.debug.unlockStdErr(); + var timer = try std.time.Timer.start(); + const res = try evalGeneric(run, &child); + run.step.result_duration_ns = timer.read(); + return .{ .term = res.term, .stdout = res.stdout, .stderr = res.stderr }; + } +} + +const StdioPollEnum = enum { stdout, stderr }; + +fn evalZigTest( + run: *Run, + child: *std.process.Child, + options: Step.MakeOptions, + fuzz_context: ?FuzzContext, +) !EvalZigTestResult { + const gpa = run.step.owner.allocator; + const arena = run.step.owner.allocator; + + // We will update this every time a child runs. + run.step.result_peak_rss = 0; + + var result: EvalZigTestResult = .{ + .test_results = .{ + .test_count = 0, + .skip_count = 0, + .fail_count = 0, + .crash_count = 0, + .timeout_count = 0, + .leak_count = 0, + .log_err_count = 0, + }, + .test_metadata = null, + }; + while (true) { try child.spawn(); - errdefer { + var poller = std.Io.poll(gpa, StdioPollEnum, .{ + .stdout = child.stdout.?, + .stderr = child.stderr.?, + }); + var child_killed = false; + defer if (!child_killed) { _ = child.kill() catch {}; - } + poller.deinit(); + run.step.result_peak_rss = @max( + run.step.result_peak_rss, + child.resource_usage_statistics.getMaxRss() orelse 0, + ); + }; - // We need to report `error.InvalidExe` *now* if applicable. try child.waitForSpawn(); - var timer = try std.time.Timer.start(); + switch (try pollZigTest( + run, + child, + options, + fuzz_context, + &poller, + &result.test_metadata, + &result.test_results, + )) { + .write_failed => |err| { + // The runner unexpectedly closed a stdio pipe, which means a crash. Make sure we've captured + // all available stderr to make our error output as useful as possible. + while (try poller.poll()) {} + run.step.result_stderr = try arena.dupe(u8, poller.reader(.stderr).buffered()); + + // Clean up everything and wait for the child to exit. + child.stdin.?.close(); + child.stdin = null; + poller.deinit(); + child_killed = true; + const term = try child.wait(); + run.step.result_peak_rss = @max( + run.step.result_peak_rss, + child.resource_usage_statistics.getMaxRss() orelse 0, + ); - const result = if (run.stdio == .zig_test) - try evalZigTest(run, &child, options, fuzz_context) - else - try evalGeneric(run, &child); + try run.step.addError("unable to write stdin ({t}); test process unexpectedly {f}", .{ err, fmtTerm(term) }); + return result; + }, + .no_poll => |no_poll| { + // This might be a success (we requested exit and the child dutifully closed stdout) or + // a crash of some kind. Either way, the child will terminate by itself -- wait for it. + const stderr_owned = try arena.dupe(u8, poller.reader(.stderr).buffered()); + poller.reader(.stderr).tossBuffered(); + + // Clean up everything and wait for the child to exit. + child.stdin.?.close(); + child.stdin = null; + poller.deinit(); + child_killed = true; + const term = try child.wait(); + run.step.result_peak_rss = @max( + run.step.result_peak_rss, + child.resource_usage_statistics.getMaxRss() orelse 0, + ); - break :t .{ try child.wait(), result, timer.read() }; - }; + if (no_poll.active_test_index) |test_index| { + // A test was running, so this is definitely a crash. Report it against that + // test, and continue to the next test. + result.test_metadata.?.ns_per_test[test_index] = no_poll.ns_elapsed; + result.test_results.crash_count += 1; + try run.step.addError("'{s}' {f}{s}{s}", .{ + result.test_metadata.?.testName(test_index), + fmtTerm(term), + if (stderr_owned.len != 0) " with stderr:\n" else "", + std.mem.trim(u8, stderr_owned, "\n"), + }); + continue; + } - return .{ - .stdio = result, - .term = term, - .elapsed_ns = elapsed_ns, - .peak_rss = child.resource_usage_statistics.getMaxRss() orelse 0, - }; + // Report an error if the child terminated uncleanly or if we were still trying to run more tests. + run.step.result_stderr = stderr_owned; + const tests_done = result.test_metadata != null and result.test_metadata.?.next_index == std.math.maxInt(u32); + if (!tests_done or !termMatches(.{ .Exited = 0 }, term)) { + try run.step.addError("test process unexpectedly {f}", .{fmtTerm(term)}); + } + return result; + }, + .timeout => |timeout| { + const stderr = poller.reader(.stderr).buffered(); + poller.reader(.stderr).tossBuffered(); + if (timeout.active_test_index) |test_index| { + // A test was running. Report the timeout against that test, and continue on to + // the next test. + result.test_metadata.?.ns_per_test[test_index] = timeout.ns_elapsed; + result.test_results.timeout_count += 1; + try run.step.addError("'{s}' timed out after {D}{s}{s}", .{ + result.test_metadata.?.testName(test_index), + timeout.ns_elapsed, + if (stderr.len != 0) " with stderr:\n" else "", + std.mem.trim(u8, stderr, "\n"), + }); + continue; + } + // Just log an error and let the child be killed. + run.step.result_stderr = try arena.dupe(u8, stderr); + return run.step.fail("test runner failed to respond for {D}", .{timeout.ns_elapsed}); + }, + } + comptime unreachable; + } } -const StdIoResult = struct { - stdout: ?[]const u8, - stderr: ?[]const u8, - test_results: Step.TestResults, - test_metadata: ?TestMetadata, -}; - -fn evalZigTest( +/// Polls stdout of a Zig test process until a termination condition is reached: +/// * A write fails, indicating the child unexpectedly closed stdin +/// * A test (or a response from the test runner) times out +/// * `poll` fails, indicating the child closed stdout and stderr +fn pollZigTest( run: *Run, child: *std.process.Child, options: Step.MakeOptions, fuzz_context: ?FuzzContext, -) !StdIoResult { + poller: *std.Io.Poller(StdioPollEnum), + opt_metadata: *?TestMetadata, + results: *Step.TestResults, +) !union(enum) { + write_failed: anyerror, + no_poll: struct { + active_test_index: ?u32, + ns_elapsed: u64, + }, + timeout: struct { + active_test_index: ?u32, + ns_elapsed: u64, + }, +} { const gpa = run.step.owner.allocator; const arena = run.step.owner.allocator; - const PollEnum = enum { stdout, stderr }; - - var poller = std.Io.poll(gpa, PollEnum, .{ - .stdout = child.stdout.?, - .stderr = child.stderr.?, - }); - defer poller.deinit(); + var sub_prog_node: ?std.Progress.Node = null; + defer if (sub_prog_node) |n| n.end(); - // If this is `true`, we avoid ever entering the polling loop below, because the stdin pipe has - // somehow already closed; instead, we go straight to capturing stderr in case it has anything - // useful. - const first_write_failed = if (fuzz_context) |fctx| failed: { - switch (fctx.fuzz.mode) { + if (fuzz_context) |ctx| { + assert(opt_metadata.* == null); // fuzz processes are never restarted + switch (ctx.fuzz.mode) { .forever => { - const instance_id = 0; // will be used by mutiprocess forever fuzzing - sendRunFuzzTestMessage(child.stdin.?, fctx.unit_test_index, .forever, instance_id) catch |err| { - try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); - break :failed true; - }; - break :failed false; + sendRunFuzzTestMessage( + child.stdin.?, + ctx.unit_test_index, + .forever, + 0, // instance ID; will be used by multiprocess forever fuzzing in the future + ) catch |err| return .{ .write_failed = err }; }, .limit => |limit| { - sendRunFuzzTestMessage(child.stdin.?, fctx.unit_test_index, .iterations, limit.amount) catch |err| { - try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); - break :failed true; - }; - break :failed false; + sendRunFuzzTestMessage( + child.stdin.?, + ctx.unit_test_index, + .iterations, + limit.amount, + ) catch |err| return .{ .write_failed = err }; }, } - } else failed: { + } else if (opt_metadata.*) |*md| { + // Previous unit test process died or was killed; we're continuing where it left off + requestNextTest(child.stdin.?, md, &sub_prog_node) catch |err| return .{ .write_failed = err }; + } else { + // Running unit tests normally run.fuzz_tests.clearRetainingCapacity(); - sendMessage(child.stdin.?, .query_test_metadata) catch |err| { - try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); - break :failed true; - }; - break :failed false; - }; - - var fail_count: u32 = 0; - var skip_count: u32 = 0; - var leak_count: u32 = 0; - var timeout_count: u32 = 0; - var test_count: u32 = 0; - var log_err_count: u32 = 0; - - var metadata: ?TestMetadata = null; - var coverage_id: ?u64 = null; - - var test_is_running = false; + sendMessage(child.stdin.?, .query_test_metadata) catch |err| return .{ .write_failed = err }; + } - // String allocated into `gpa`. Owned by this function while it runs, then moved to the `Step`. - var result_stderr: []u8 = &.{}; - defer run.step.result_stderr = result_stderr; + var active_test_index: ?u32 = null; // `null` means this host does not support `std.time.Timer`. This timer is `reset()` whenever we - // toggle `test_is_running`, i.e. whenever a test starts or finishes. - var timer: ?std.time.Timer = std.time.Timer.start() catch t: { - std.log.warn("std.time.Timer not supported on host; test timeouts will be ignored", .{}); - break :t null; - }; + // change `active_test_index`, i.e. whenever a test starts or finishes. + var timer: ?std.time.Timer = std.time.Timer.start() catch null; - var sub_prog_node: ?std.Progress.Node = null; - defer if (sub_prog_node) |n| n.end(); + var coverage_id: ?u64 = null; // This timeout is used when we're waiting on the test runner itself rather than a user-specified // test. For instance, if the test runner leaves this much time between us requesting a test to @@ -1735,12 +1832,10 @@ fn evalZigTest( // *should* never happen, but could in theory be caused by some very unlucky IB in a test. const response_timeout_ns = 30 * std.time.ns_per_s; - const any_write_failed = first_write_failed or poll: while (true) { - // These are scoped inside the loop because we sometimes respawn the child and recreate - // `poller` which invaldiates these readers. - const stdout = poller.reader(.stdout); - const stderr = poller.reader(.stderr); + const stdout = poller.reader(.stdout); + const stderr = poller.reader(.stderr); + while (true) { const Header = std.zig.Server.Message.Header; // This block is exited when `stdout` contains enough bytes for a `Header`. @@ -1753,15 +1848,21 @@ fn evalZigTest( // Always `null` if `timer` is `null`. const opt_timeout_ns: ?u64 = ns: { if (timer == null) break :ns null; - if (!test_is_running) break :ns response_timeout_ns; + if (active_test_index == null) break :ns response_timeout_ns; break :ns options.unit_test_timeout_ns; }; if (opt_timeout_ns) |timeout_ns| { const remaining_ns = timeout_ns -| timer.?.read(); - if (!try poller.pollTimeout(remaining_ns)) break :poll false; + if (!try poller.pollTimeout(remaining_ns)) return .{ .no_poll = .{ + .active_test_index = active_test_index, + .ns_elapsed = if (timer) |*t| t.read() else 0, + } }; } else { - if (!try poller.poll()) break :poll false; + if (!try poller.poll()) return .{ .no_poll = .{ + .active_test_index = active_test_index, + .ns_elapsed = if (timer) |*t| t.read() else 0, + } }; } if (stdout.buffered().len >= @sizeOf(Header)) { @@ -1769,73 +1870,29 @@ fn evalZigTest( break :header_ready; } - const timeout_ns = opt_timeout_ns orelse continue; - const cur_ns = timer.?.read(); - if (cur_ns < timeout_ns) continue; - - // There was a timeout. - - if (!test_is_running) { - // The child stopped responding while *not* running a test. To avoid getting into - // a loop if something's broken, don't retry; just report an error and stop. - try run.step.addError("test runner failed to respond for {D}", .{cur_ns}); - break :poll false; - } - - // A test has probably just gotten stuck. We'll report an error, then just kill the - // child and continue with the next test in the list. - - const md = &metadata.?; - const test_index = md.next_index - 1; - - timeout_count += 1; - try run.step.addError( - "'{s}' timed out after {D}", - .{ md.testName(test_index), cur_ns }, - ); - if (stderr.buffered().len > 0) { - const new_bytes = stderr.buffered(); - const old_len = result_stderr.len; - result_stderr = try gpa.realloc(result_stderr, old_len + new_bytes.len); - @memcpy(result_stderr[old_len..], new_bytes); + if (opt_timeout_ns) |timeout_ns| { + const cur_ns = timer.?.read(); + if (cur_ns >= timeout_ns) return .{ .timeout = .{ + .active_test_index = active_test_index, + .ns_elapsed = cur_ns, + } }; } - - _ = try child.kill(); - // Respawn the test runner. There's a double-cleanup if this fails, but that's - // fine because our caller's `kill` will just return `error.AlreadyTerminated`. - try child.spawn(); - try child.waitForSpawn(); - - // After respawning the child, we must update the poller's streams. - poller.deinit(); - poller = std.Io.poll(gpa, PollEnum, .{ - .stdout = child.stdout.?, - .stderr = child.stderr.?, - }); - - test_is_running = false; - md.ns_per_test[test_index] = timer.?.lap(); - - requestNextTest(child.stdin.?, md, &sub_prog_node) catch |err| { - try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); - break :poll true; - }; - - continue :poll; // continue work with the new (respawned) child + continue; } // There is definitely a header available now -- read it. const header = stdout.takeStruct(Header, .little) catch unreachable; - while (stdout.buffered().len < header.bytes_len) if (!try poller.poll()) break :poll false; + while (stdout.buffered().len < header.bytes_len) if (!try poller.poll()) return .{ .no_poll = .{ + .active_test_index = active_test_index, + .ns_elapsed = if (timer) |*t| t.read() else 0, + } }; const body = stdout.take(header.bytes_len) catch unreachable; switch (header.tag) { .zig_version => { - if (!std.mem.eql(u8, builtin.zig_version_string, body)) { - return run.step.fail( - "zig version mismatch build runner vs compiler: '{s}' vs '{s}'", - .{ builtin.zig_version_string, body }, - ); - } + if (!std.mem.eql(u8, builtin.zig_version_string, body)) return run.step.fail( + "zig version mismatch build runner vs compiler: '{s}' vs '{s}'", + .{ builtin.zig_version_string, body }, + ); }, .test_metadata => { assert(fuzz_context == null); @@ -1843,14 +1900,14 @@ fn evalZigTest( // `metadata` would only be populated if we'd already seen a `test_metadata`, but we // only request it once (and importantly, we don't re-request it if we kill and // restart the test runner). - assert(metadata == null); + assert(opt_metadata.* == null); const TmHdr = std.zig.Server.Message.TestMetadata; - const tm_hdr = @as(*align(1) const TmHdr, @ptrCast(body)); - test_count = tm_hdr.tests_len; + const tm_hdr: *align(1) const TmHdr = @ptrCast(body); + results.test_count = tm_hdr.tests_len; - const names_bytes = body[@sizeOf(TmHdr)..][0 .. test_count * @sizeOf(u32)]; - const expected_panic_msgs_bytes = body[@sizeOf(TmHdr) + names_bytes.len ..][0 .. test_count * @sizeOf(u32)]; + const names_bytes = body[@sizeOf(TmHdr)..][0 .. results.test_count * @sizeOf(u32)]; + const expected_panic_msgs_bytes = body[@sizeOf(TmHdr) + names_bytes.len ..][0 .. results.test_count * @sizeOf(u32)]; const string_bytes = body[@sizeOf(TmHdr) + names_bytes.len + expected_panic_msgs_bytes.len ..][0..tm_hdr.string_bytes_len]; const names = std.mem.bytesAsSlice(u32, names_bytes); @@ -1863,68 +1920,70 @@ fn evalZigTest( for (expected_panic_msgs_aligned, expected_panic_msgs) |*dest, src| dest.* = src; options.progress_node.setEstimatedTotalItems(names.len); - metadata = .{ + opt_metadata.* = .{ .string_bytes = try arena.dupe(u8, string_bytes), - .ns_per_test = try arena.alloc(u64, test_count), + .ns_per_test = try arena.alloc(u64, results.test_count), .names = names_aligned, .expected_panic_msgs = expected_panic_msgs_aligned, .next_index = 0, .prog_node = options.progress_node, }; - @memset(metadata.?.ns_per_test, std.math.maxInt(u64)); + @memset(opt_metadata.*.?.ns_per_test, std.math.maxInt(u64)); - test_is_running = false; + active_test_index = null; if (timer) |*t| t.reset(); - requestNextTest(child.stdin.?, &metadata.?, &sub_prog_node) catch |err| { - try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); - break :poll true; - }; + requestNextTest(child.stdin.?, &opt_metadata.*.?, &sub_prog_node) catch |err| return .{ .write_failed = err }; }, .test_started => { - test_is_running = true; + active_test_index = opt_metadata.*.?.next_index - 1; if (timer) |*t| t.reset(); }, .test_results => { assert(fuzz_context == null); - const md = &metadata.?; + const md = &opt_metadata.*.?; const TrHdr = std.zig.Server.Message.TestResults; const tr_hdr: *align(1) const TrHdr = @ptrCast(body); - fail_count +|= @intFromBool(tr_hdr.flags.fail); - skip_count +|= @intFromBool(tr_hdr.flags.skip); - leak_count +|= @intFromBool(tr_hdr.flags.leak); - log_err_count +|= tr_hdr.flags.log_err_count; + assert(tr_hdr.index == active_test_index); + + switch (tr_hdr.flags.status) { + .pass => {}, + .skip => results.skip_count +|= 1, + .fail => results.fail_count +|= 1, + } + const leak_count = tr_hdr.flags.leak_count; + const log_err_count = tr_hdr.flags.log_err_count; + results.leak_count +|= leak_count; + results.log_err_count +|= log_err_count; if (tr_hdr.flags.fuzz) try run.fuzz_tests.append(gpa, tr_hdr.index); - if (tr_hdr.flags.fail or tr_hdr.flags.leak or tr_hdr.flags.log_err_count > 0) { + if (tr_hdr.flags.status == .fail) { const name = std.mem.sliceTo(md.testName(tr_hdr.index), 0); - const stderr_contents = stderr.buffered(); - stderr.toss(stderr_contents.len); - const msg = std.mem.trim(u8, stderr_contents, "\n"); - const label = if (tr_hdr.flags.fail) - "failed" - else if (tr_hdr.flags.leak) - "leaked" - else if (tr_hdr.flags.log_err_count > 0) - "logged errors" - else - unreachable; - if (msg.len > 0) { - try run.step.addError("'{s}' {s}: {s}", .{ name, label, msg }); + const stderr_bytes = std.mem.trim(u8, stderr.buffered(), "\n"); + stderr.tossBuffered(); + if (stderr_bytes.len == 0) { + try run.step.addError("'{s}' failed without output", .{name}); } else { - try run.step.addError("'{s}' {s}", .{ name, label }); + try run.step.addError("'{s}' failed:\n{s}", .{ name, stderr_bytes }); } + } else if (leak_count > 0) { + const name = std.mem.sliceTo(md.testName(tr_hdr.index), 0); + const stderr_bytes = std.mem.trim(u8, stderr.buffered(), "\n"); + stderr.tossBuffered(); + try run.step.addError("'{s}' leaked {d} allocations:\n{s}", .{ name, leak_count, stderr_bytes }); + } else if (log_err_count > 0) { + const name = std.mem.sliceTo(md.testName(tr_hdr.index), 0); + const stderr_bytes = std.mem.trim(u8, stderr.buffered(), "\n"); + stderr.tossBuffered(); + try run.step.addError("'{s}' logged {d} errors:\n{s}", .{ name, log_err_count, stderr_bytes }); } - test_is_running = false; + active_test_index = null; if (timer) |*t| md.ns_per_test[tr_hdr.index] = t.lap(); - requestNextTest(child.stdin.?, md, &sub_prog_node) catch |err| { - try run.step.addError("unable to write stdin: {s}", .{@errorName(err)}); - break :poll true; - }; + requestNextTest(child.stdin.?, md, &sub_prog_node) catch |err| return .{ .write_failed = err }; }, .coverage_id => { const fuzz = fuzz_context.?.fuzz; @@ -1961,39 +2020,7 @@ fn evalZigTest( }, else => {}, // ignore other messages } - }; - - if (any_write_failed) { - // The compiler unexpectedly closed stdin; something is very wrong and has probably crashed. - // We want to make sure we've captured all of stderr so that it's logged below. - while (try poller.poll()) {} } - - const stderr = poller.reader(.stderr); - if (stderr.buffered().len > 0) { - const new_bytes = stderr.buffered(); - const old_len = result_stderr.len; - result_stderr = try gpa.realloc(result_stderr, old_len + new_bytes.len); - @memcpy(result_stderr[old_len..], new_bytes); - } - - // Send EOF to stdin. - child.stdin.?.close(); - child.stdin = null; - - return .{ - .stdout = null, - .stderr = null, - .test_results = .{ - .test_count = test_count, - .fail_count = fail_count, - .skip_count = skip_count, - .leak_count = leak_count, - .timeout_count = timeout_count, - .log_err_count = log_err_count, - }, - .test_metadata = metadata, - }; } const TestMetadata = struct { @@ -2077,10 +2104,15 @@ fn sendRunFuzzTestMessage( try file.writeAll(full_msg); } -fn evalGeneric(run: *Run, child: *std.process.Child) !StdIoResult { +fn evalGeneric(run: *Run, child: *std.process.Child) !EvalGenericResult { const b = run.step.owner; const arena = b.allocator; + try child.spawn(); + errdefer _ = child.kill() catch {}; + + try child.waitForSpawn(); + switch (run.stdin) { .bytes => |bytes| { child.stdin.?.writeAll(bytes) catch |err| { @@ -2170,11 +2202,12 @@ fn evalGeneric(run: *Run, child: *std.process.Child) !StdIoResult { } }; + run.step.result_peak_rss = child.resource_usage_statistics.getMaxRss() orelse 0; + return .{ + .term = try child.wait(), .stdout = stdout_bytes, .stderr = stderr_bytes, - .test_results = .{}, - .test_metadata = null, }; } diff --git a/lib/std/heap/debug_allocator.zig b/lib/std/heap/debug_allocator.zig index fe512f03d6..38b9303479 100644 --- a/lib/std/heap/debug_allocator.zig +++ b/lib/std/heap/debug_allocator.zig @@ -421,10 +421,10 @@ pub fn DebugAllocator(comptime config: Config) type { return usedBitsCount(slot_count) * @sizeOf(usize); } - fn detectLeaksInBucket(bucket: *BucketHeader, size_class_index: usize, used_bits_count: usize) bool { + fn detectLeaksInBucket(bucket: *BucketHeader, size_class_index: usize, used_bits_count: usize) usize { const size_class = @as(usize, 1) << @as(Log2USize, @intCast(size_class_index)); const slot_count = slot_counts[size_class_index]; - var leaks = false; + var leaks: usize = 0; for (0..used_bits_count) |used_bits_byte| { const used_int = bucket.usedBits(used_bits_byte).*; if (used_int != 0) { @@ -437,7 +437,7 @@ pub fn DebugAllocator(comptime config: Config) type { const page_addr = @intFromPtr(bucket) & ~(page_size - 1); const addr = page_addr + slot_index * size_class; log.err("memory address 0x{x} leaked: {f}", .{ addr, stack_trace }); - leaks = true; + leaks += 1; } } } @@ -445,16 +445,16 @@ pub fn DebugAllocator(comptime config: Config) type { return leaks; } - /// Emits log messages for leaks and then returns whether there were any leaks. - pub fn detectLeaks(self: *Self) bool { - var leaks = false; + /// Emits log messages for leaks and then returns the number of detected leaks (0 if no leaks were detected). + pub fn detectLeaks(self: *Self) usize { + var leaks: usize = 0; for (self.buckets, 0..) |init_optional_bucket, size_class_index| { var optional_bucket = init_optional_bucket; const slot_count = slot_counts[size_class_index]; const used_bits_count = usedBitsCount(slot_count); while (optional_bucket) |bucket| { - leaks = detectLeaksInBucket(bucket, size_class_index, used_bits_count) or leaks; + leaks += detectLeaksInBucket(bucket, size_class_index, used_bits_count); optional_bucket = bucket.prev; } } @@ -466,7 +466,7 @@ pub fn DebugAllocator(comptime config: Config) type { log.err("memory address 0x{x} leaked: {f}", .{ @intFromPtr(large_alloc.bytes.ptr), stack_trace, }); - leaks = true; + leaks += 1; } return leaks; } @@ -498,11 +498,17 @@ pub fn DebugAllocator(comptime config: Config) type { /// Returns `std.heap.Check.leak` if there were leaks; `std.heap.Check.ok` otherwise. pub fn deinit(self: *Self) std.heap.Check { - const leaks = if (config.safety) self.detectLeaks() else false; + const leaks: usize = if (config.safety) self.detectLeaks() else 0; + self.deinitWithoutLeakChecks(); + return if (leaks == 0) .ok else .leak; + } + + /// Like `deinit`, but does not check for memory leaks. This is useful if leaks have already + /// been detected manually with `detectLeaks` to avoid reporting them for a second time. + pub fn deinitWithoutLeakChecks(self: *Self) void { if (config.retain_metadata) self.freeRetainedMetadata(); self.large_allocations.deinit(self.backing_allocator); self.* = undefined; - return if (leaks) .leak else .ok; } fn collectStackTrace(first_trace_addr: usize, addr_buf: *[stack_n]usize) void { diff --git a/lib/std/zig/Server.zig b/lib/std/zig/Server.zig index 95cec24a29..ffc596e8dc 100644 --- a/lib/std/zig/Server.zig +++ b/lib/std/zig/Server.zig @@ -96,15 +96,16 @@ pub const Message = struct { pub const TestResults = extern struct { index: u32, - flags: Flags, + flags: Flags align(4), - pub const Flags = packed struct(u32) { - fail: bool, - skip: bool, - leak: bool, + pub const Flags = packed struct(u64) { + status: Status, fuzz: bool, - log_err_count: u28 = 0, + log_err_count: u30, + leak_count: u31, }; + + pub const Status = enum(u2) { pass, fail, skip }; }; /// Trailing is the same as in `std.Build.abi.time_report.CompileResult`, excluding `step_name`. -- cgit v1.2.3 From a388a8e5a7193831a349f6d00e04bd15211a931f Mon Sep 17 00:00:00 2001 From: mlugg Date: Tue, 26 Aug 2025 16:28:42 +0100 Subject: std.Build: separate errors from failed commands Recording the command in a separate field will give the build runner more freedom to choose how and when the command should be printed. --- lib/compiler/build_runner.zig | 8 ++++ lib/std/Build.zig | 18 +-------- lib/std/Build/Step.zig | 86 ++++++++++++++++++++----------------------- lib/std/Build/Step/Fmt.zig | 4 +- lib/std/Build/Step/Run.zig | 54 ++++++++++----------------- 5 files changed, 71 insertions(+), 99 deletions(-) (limited to 'lib/std/Build/Step') diff --git a/lib/compiler/build_runner.zig b/lib/compiler/build_runner.zig index f87a121993..5df77014b5 100644 --- a/lib/compiler/build_runner.zig +++ b/lib/compiler/build_runner.zig @@ -1443,6 +1443,14 @@ pub fn printErrorMessages( } try stderr.writeAll("\n"); } + + if (failing_step.result_failed_command) |cmd_str| { + try ttyconf.setColor(stderr, .red); + try stderr.writeAll("failed command: "); + try ttyconf.setColor(stderr, .reset); + try stderr.writeAll(cmd_str); + try stderr.writeByte('\n'); + } } fn printSteps(builder: *std.Build, w: *Writer) !void { diff --git a/lib/std/Build.zig b/lib/std/Build.zig index 5a5bce5127..c13b137ff6 100644 --- a/lib/std/Build.zig +++ b/lib/std/Build.zig @@ -1594,20 +1594,6 @@ pub fn validateUserInputDidItFail(b: *Build) bool { return b.invalid_user_input; } -fn allocPrintCmd(gpa: Allocator, opt_cwd: ?[]const u8, argv: []const []const u8) error{OutOfMemory}![]u8 { - var buf: ArrayList(u8) = .empty; - if (opt_cwd) |cwd| try buf.print(gpa, "cd {s} && ", .{cwd}); - for (argv) |arg| { - try buf.print(gpa, "{s} ", .{arg}); - } - return buf.toOwnedSlice(gpa); -} - -fn printCmd(ally: Allocator, cwd: ?[]const u8, argv: []const []const u8) void { - const text = allocPrintCmd(ally, cwd, argv) catch @panic("OOM"); - std.debug.print("{s}\n", .{text}); -} - /// This creates the install step and adds it to the dependencies of the /// top-level install step, using all the default options. /// See `addInstallArtifact` for a more flexible function. @@ -1857,14 +1843,14 @@ pub fn runAllowFail( pub fn run(b: *Build, argv: []const []const u8) []u8 { if (!process.can_spawn) { std.debug.print("unable to spawn the following command: cannot spawn child process\n{s}\n", .{ - try allocPrintCmd(b.allocator, null, argv), + try Step.allocPrintCmd(b.allocator, null, argv), }); process.exit(1); } var code: u8 = undefined; return b.runAllowFail(argv, &code, .Inherit) catch |err| { - const printed_cmd = allocPrintCmd(b.allocator, null, argv) catch @panic("OOM"); + const printed_cmd = Step.allocPrintCmd(b.allocator, null, argv) catch @panic("OOM"); std.debug.print("unable to spawn the following command: {s}\n{s}\n", .{ @errorName(err), printed_cmd, }); diff --git a/lib/std/Build/Step.zig b/lib/std/Build/Step.zig index 7b72d9a825..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 @@ -257,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 = .{}, }; } @@ -336,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(.{ @@ -386,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, @@ -394,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); @@ -410,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. @@ -420,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; } @@ -430,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); @@ -484,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; @@ -696,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, @@ -783,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.*; @@ -973,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); diff --git a/lib/std/Build/Step/Fmt.zig b/lib/std/Build/Step/Fmt.zig index a364dfa6f4..5adebdc454 100644 --- a/lib/std/Build/Step/Fmt.zig +++ b/lib/std/Build/Step/Fmt.zig @@ -67,7 +67,7 @@ fn make(step: *Step, options: Step.MakeOptions) !void { argv.appendAssumeCapacity(b.pathFromRoot(p)); } - const run_result = try step.captureChildProcess(prog_node, argv.items); + const run_result = try step.captureChildProcess(options.gpa, prog_node, argv.items); if (fmt.check) switch (run_result.term) { .Exited => |code| if (code != 0 and run_result.stdout.len != 0) { var it = std.mem.tokenizeScalar(u8, run_result.stdout, '\n'); @@ -77,5 +77,5 @@ fn make(step: *Step, options: Step.MakeOptions) !void { }, else => {}, }; - try step.handleChildProcessTerm(run_result.term, null, argv.items); + try step.handleChildProcessTerm(run_result.term); } diff --git a/lib/std/Build/Step/Run.zig b/lib/std/Build/Step/Run.zig index 39eb276b48..52d1a72649 100644 --- a/lib/std/Build/Step/Run.zig +++ b/lib/std/Build/Step/Run.zig @@ -1212,10 +1212,11 @@ fn runCommand( const step = &run.step; const b = step.owner; const arena = b.allocator; + const gpa = options.gpa; const cwd: ?[]const u8 = if (run.cwd) |lazy_cwd| lazy_cwd.getPath2(b, step) else null; - try step.handleChildProcUnsupported(cwd, argv); + try step.handleChildProcUnsupported(); try Step.handleVerbose2(step.owner, cwd, run.env_map, argv); const allow_skip = switch (run.stdio) { @@ -1365,6 +1366,8 @@ fn runCommand( run.addPathForDynLibs(exe); } + gpa.free(step.result_failed_command.?); + step.result_failed_command = null; try Step.handleVerbose2(step.owner, cwd, run.env_map, interp_argv.items); break :term spawnChildAndCollect(run, interp_argv.items, env_map, has_side_effects, options, fuzz_context) catch |e| { @@ -1380,18 +1383,11 @@ fn runCommand( return step.fail("failed to spawn and capture stdio from {s}: {s}", .{ argv[0], @errorName(err) }); }; - const final_argv = if (interp_argv.items.len == 0) argv else interp_argv.items; - const generic_result = opt_generic_result orelse { assert(run.stdio == .zig_test); - // Specific errors have already been reported. All we need to do is detect those and - // report the general "test failed" error, which includes the command argv. - if (!step.test_results.isSuccess() or step.result_error_msgs.items.len > 0) { - return step.fail( - "the following test command failed:\n{s}", - .{try Step.allocPrintCmd(arena, cwd, final_argv)}, - ); - } + // Specific errors have already been reported, and test results are populated. All we need + // to do is report step failure if any test failed. + if (!step.test_results.isSuccess()) return error.MakeFailed; return; }; @@ -1445,93 +1441,77 @@ fn runCommand( .expect_stderr_exact => |expected_bytes| { if (!mem.eql(u8, expected_bytes, generic_result.stderr.?)) { return step.fail( - \\ \\========= expected this stderr: ========= \\{s} \\========= but found: ==================== \\{s} - \\========= from the following command: === - \\{s} , .{ expected_bytes, generic_result.stderr.?, - try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_stderr_match => |match| { if (mem.indexOf(u8, generic_result.stderr.?, match) == null) { return step.fail( - \\ \\========= expected to find in stderr: ========= \\{s} \\========= but stderr does not contain it: ===== \\{s} - \\========= from the following command: ========= - \\{s} , .{ match, generic_result.stderr.?, - try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_stdout_exact => |expected_bytes| { if (!mem.eql(u8, expected_bytes, generic_result.stdout.?)) { return step.fail( - \\ \\========= expected this stdout: ========= \\{s} \\========= but found: ==================== \\{s} - \\========= from the following command: === - \\{s} , .{ expected_bytes, generic_result.stdout.?, - try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_stdout_match => |match| { if (mem.indexOf(u8, generic_result.stdout.?, match) == null) { return step.fail( - \\ \\========= expected to find in stdout: ========= \\{s} \\========= but stdout does not contain it: ===== \\{s} - \\========= from the following command: ========= - \\{s} , .{ match, generic_result.stdout.?, - try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, .expect_term => |expected_term| { if (!termMatches(expected_term, generic_result.term)) { - return step.fail("the following command {f} (expected {f}):\n{s}", .{ + return step.fail("process {f} (expected {f})", .{ fmtTerm(generic_result.term), fmtTerm(expected_term), - try Step.allocPrintCmd(arena, cwd, final_argv), }); } }, }, else => { - // On failure, print stderr if captured. + // On failure, report captured stderr like normal standard error output. const bad_exit = switch (generic_result.term) { .Exited => |code| code != 0, .Signal, .Stopped, .Unknown => true, }; + if (bad_exit) { + if (generic_result.stderr) |bytes| { + run.step.result_stderr = bytes; + } + } - if (bad_exit) if (generic_result.stderr) |err| { - try step.addError("stderr:\n{s}", .{err}); - }; - - try step.handleChildProcessTerm(generic_result.term, cwd, final_argv); + try step.handleChildProcessTerm(generic_result.term); }, } } @@ -1594,6 +1574,10 @@ fn spawnChildAndCollect( child.stdin_behavior = .Pipe; } + // If an error occurs, it's caused by this command: + assert(run.step.result_failed_command == null); + run.step.result_failed_command = try Step.allocPrintCmd(options.gpa, child.cwd, argv); + if (run.stdio == .zig_test) { var timer = try std.time.Timer.start(); const res = try evalZigTest(run, &child, options, fuzz_context); -- cgit v1.2.3 From a7251e41914c5b24c27ed2669fce2a802a052c05 Mon Sep 17 00:00:00 2001 From: mlugg Date: Sat, 13 Sep 2025 16:22:44 +0100 Subject: ci: bump unit test timeouts --- ci/riscv64-linux-debug.sh | 2 +- ci/riscv64-linux-release.sh | 2 +- ci/x86_64-linux-debug-llvm.sh | 2 +- ci/x86_64-linux-debug.sh | 2 +- ci/x86_64-linux-release.sh | 2 +- ci/x86_64-windows-debug.ps1 | 2 +- ci/x86_64-windows-release.ps1 | 2 +- lib/std/Build/Step/Run.zig | 2 +- 8 files changed, 8 insertions(+), 8 deletions(-) (limited to 'lib/std/Build/Step') diff --git a/ci/riscv64-linux-debug.sh b/ci/riscv64-linux-debug.sh index f8bc19dd9a..98bc72a439 100755 --- a/ci/riscv64-linux-debug.sh +++ b/ci/riscv64-linux-debug.sh @@ -52,4 +52,4 @@ stage3-debug/bin/zig build test-cases test-modules test-unit test-c-abi test-sta -Dtarget=native-native-musl \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 60_000 + --test-timeout-ms 120_000 diff --git a/ci/riscv64-linux-release.sh b/ci/riscv64-linux-release.sh index 03e4d08fc9..4622277699 100755 --- a/ci/riscv64-linux-release.sh +++ b/ci/riscv64-linux-release.sh @@ -52,4 +52,4 @@ stage3-release/bin/zig build test-cases test-modules test-unit test-c-abi test-s -Dtarget=native-native-musl \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 60_000 + --test-timeout-ms 120_000 diff --git a/ci/x86_64-linux-debug-llvm.sh b/ci/x86_64-linux-debug-llvm.sh index ce83ce3ed3..560ca74ead 100755 --- a/ci/x86_64-linux-debug-llvm.sh +++ b/ci/x86_64-linux-debug-llvm.sh @@ -62,4 +62,4 @@ stage3-debug/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 60_000 + --test-timeout-ms 240_000 diff --git a/ci/x86_64-linux-debug.sh b/ci/x86_64-linux-debug.sh index b402396a1d..663c8f834a 100755 --- a/ci/x86_64-linux-debug.sh +++ b/ci/x86_64-linux-debug.sh @@ -62,4 +62,4 @@ stage3-debug/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 60_000 + --test-timeout-ms 240_000 diff --git a/ci/x86_64-linux-release.sh b/ci/x86_64-linux-release.sh index b7b593a0c8..fb91d69330 100755 --- a/ci/x86_64-linux-release.sh +++ b/ci/x86_64-linux-release.sh @@ -64,7 +64,7 @@ stage3-release/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 60_000 + --test-timeout-ms 240_000 # Ensure that stage3 and stage4 are byte-for-byte identical. stage3-release/bin/zig build \ diff --git a/ci/x86_64-windows-debug.ps1 b/ci/x86_64-windows-debug.ps1 index 445a55f35e..516a8e3444 100644 --- a/ci/x86_64-windows-debug.ps1 +++ b/ci/x86_64-windows-debug.ps1 @@ -60,7 +60,7 @@ Write-Output "Main test suite..." -Dskip-non-native ` -Dskip-release ` -Denable-symlinks-windows ` - --test-timeout-ms 60_000 + --test-timeout-ms 240_000 CheckLastExitCode Write-Output "Build x86_64-windows-msvc behavior tests using the C backend..." diff --git a/ci/x86_64-windows-release.ps1 b/ci/x86_64-windows-release.ps1 index 226e2d8ea1..80568eeb37 100644 --- a/ci/x86_64-windows-release.ps1 +++ b/ci/x86_64-windows-release.ps1 @@ -59,7 +59,7 @@ Write-Output "Main test suite..." -Dstatic-llvm ` -Dskip-non-native ` -Denable-symlinks-windows ` - --test-timeout-ms 60_000 + --test-timeout-ms 240_000 CheckLastExitCode # Ensure that stage3 and stage4 are byte-for-byte identical. diff --git a/lib/std/Build/Step/Run.zig b/lib/std/Build/Step/Run.zig index 52d1a72649..9a3c1f7906 100644 --- a/lib/std/Build/Step/Run.zig +++ b/lib/std/Build/Step/Run.zig @@ -1814,7 +1814,7 @@ fn pollZigTest( // test. For instance, if the test runner leaves this much time between us requesting a test to // start and it acknowledging the test starting, we terminate the child and raise an error. This // *should* never happen, but could in theory be caused by some very unlucky IB in a test. - const response_timeout_ns = 30 * std.time.ns_per_s; + const response_timeout_ns = options.unit_test_timeout_ns orelse 60 * std.time.ns_per_s; const stdout = poller.reader(.stdout); const stderr = poller.reader(.stderr); -- cgit v1.2.3 From 50056a5b3ad29695c795534cebbd031408633813 Mon Sep 17 00:00:00 2001 From: Matthew Lugg Date: Tue, 14 Oct 2025 23:01:13 +0100 Subject: compiler: rename `--test-timeout-ms` to `--test-timeout` The unit can now be specified in the argument. --- ci/aarch64-linux-debug.sh | 2 +- ci/aarch64-linux-release.sh | 2 +- ci/aarch64-macos-debug.sh | 2 +- ci/aarch64-macos-release.sh | 2 +- ci/aarch64-windows.ps1 | 2 +- ci/loongarch64-linux-debug.sh | 2 +- ci/loongarch64-linux-release.sh | 2 +- ci/riscv64-linux-debug.sh | 2 +- ci/riscv64-linux-release.sh | 2 +- ci/x86_64-freebsd-debug.sh | 2 +- ci/x86_64-freebsd-release.sh | 2 +- ci/x86_64-linux-debug-llvm.sh | 2 +- ci/x86_64-linux-debug.sh | 2 +- ci/x86_64-linux-release.sh | 2 +- ci/x86_64-windows-debug.ps1 | 2 +- ci/x86_64-windows-release.ps1 | 2 +- lib/compiler/build_runner.zig | 51 ++++++++++++++++++++++++++++++----------- lib/std/Build/Step/Run.zig | 2 +- 18 files changed, 55 insertions(+), 30 deletions(-) (limited to 'lib/std/Build/Step') diff --git a/ci/aarch64-linux-debug.sh b/ci/aarch64-linux-debug.sh index 00cf48f513..29c815e816 100755 --- a/ci/aarch64-linux-debug.sh +++ b/ci/aarch64-linux-debug.sh @@ -51,7 +51,7 @@ stage3-debug/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 60_000 + --test-timeout 60s stage3-debug/bin/zig build \ --prefix stage4-debug \ diff --git a/ci/aarch64-linux-release.sh b/ci/aarch64-linux-release.sh index f0a341d962..26547d8b41 100755 --- a/ci/aarch64-linux-release.sh +++ b/ci/aarch64-linux-release.sh @@ -51,7 +51,7 @@ stage3-release/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 60_000 + --test-timeout 60s # Ensure that stage3 and stage4 are byte-for-byte identical. stage3-release/bin/zig build \ diff --git a/ci/aarch64-macos-debug.sh b/ci/aarch64-macos-debug.sh index 787df10de4..4afff42269 100755 --- a/ci/aarch64-macos-debug.sh +++ b/ci/aarch64-macos-debug.sh @@ -47,4 +47,4 @@ stage3-debug/bin/zig build test docs \ -Dstatic-llvm \ -Dskip-non-native \ --search-prefix "$PREFIX" \ - --test-timeout-ms 60_000 + --test-timeout 60s diff --git a/ci/aarch64-macos-release.sh b/ci/aarch64-macos-release.sh index 872a2f4ee7..8ddbe9773d 100755 --- a/ci/aarch64-macos-release.sh +++ b/ci/aarch64-macos-release.sh @@ -47,7 +47,7 @@ stage3-release/bin/zig build test docs \ -Dstatic-llvm \ -Dskip-non-native \ --search-prefix "$PREFIX" \ - --test-timeout-ms 60_000 + --test-timeout 60s # Ensure that stage3 and stage4 are byte-for-byte identical. stage3-release/bin/zig build \ diff --git a/ci/aarch64-windows.ps1 b/ci/aarch64-windows.ps1 index 4f52bd3f81..8720c7004d 100644 --- a/ci/aarch64-windows.ps1 +++ b/ci/aarch64-windows.ps1 @@ -59,7 +59,7 @@ Write-Output "Main test suite..." -Dstatic-llvm ` -Dskip-non-native ` -Denable-symlinks-windows ` - --test-timeout-ms 60_000 + --test-timeout 60s CheckLastExitCode # Ensure that stage3 and stage4 are byte-for-byte identical. diff --git a/ci/loongarch64-linux-debug.sh b/ci/loongarch64-linux-debug.sh index 47312bbde2..a2f1126f4f 100755 --- a/ci/loongarch64-linux-debug.sh +++ b/ci/loongarch64-linux-debug.sh @@ -51,7 +51,7 @@ stage3-debug/bin/zig build test docs \ -Dtarget=native-native-musl \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 120_000 + --test-timeout 2m stage3-debug/bin/zig build \ --prefix stage4-debug \ diff --git a/ci/loongarch64-linux-release.sh b/ci/loongarch64-linux-release.sh index 62a5350285..2cb6229d9b 100755 --- a/ci/loongarch64-linux-release.sh +++ b/ci/loongarch64-linux-release.sh @@ -51,7 +51,7 @@ stage3-release/bin/zig build test docs \ -Dtarget=native-native-musl \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 120_000 + --test-timeout 2m # Ensure that stage3 and stage4 are byte-for-byte identical. stage3-release/bin/zig build \ diff --git a/ci/riscv64-linux-debug.sh b/ci/riscv64-linux-debug.sh index 98bc72a439..84a82be8dc 100755 --- a/ci/riscv64-linux-debug.sh +++ b/ci/riscv64-linux-debug.sh @@ -52,4 +52,4 @@ stage3-debug/bin/zig build test-cases test-modules test-unit test-c-abi test-sta -Dtarget=native-native-musl \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 120_000 + --test-timeout 2m diff --git a/ci/riscv64-linux-release.sh b/ci/riscv64-linux-release.sh index 4622277699..1aa31a6f8a 100755 --- a/ci/riscv64-linux-release.sh +++ b/ci/riscv64-linux-release.sh @@ -52,4 +52,4 @@ stage3-release/bin/zig build test-cases test-modules test-unit test-c-abi test-s -Dtarget=native-native-musl \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 120_000 + --test-timeout 2m diff --git a/ci/x86_64-freebsd-debug.sh b/ci/x86_64-freebsd-debug.sh index ffc6d55226..9440af5e02 100755 --- a/ci/x86_64-freebsd-debug.sh +++ b/ci/x86_64-freebsd-debug.sh @@ -52,7 +52,7 @@ stage3-debug/bin/zig build test docs \ -Dskip-macos \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 60_000 + --test-timeout 60s stage3-debug/bin/zig build \ --prefix stage4-debug \ diff --git a/ci/x86_64-freebsd-release.sh b/ci/x86_64-freebsd-release.sh index 09048d1e22..7f67e757ba 100755 --- a/ci/x86_64-freebsd-release.sh +++ b/ci/x86_64-freebsd-release.sh @@ -52,7 +52,7 @@ stage3-release/bin/zig build test docs \ -Dskip-macos \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ - --test-timeout-ms 60_000 + --test-timeout 60s # Ensure that stage3 and stage4 are byte-for-byte identical. stage3-release/bin/zig build \ diff --git a/ci/x86_64-linux-debug-llvm.sh b/ci/x86_64-linux-debug-llvm.sh index 560ca74ead..7eae6a355f 100755 --- a/ci/x86_64-linux-debug-llvm.sh +++ b/ci/x86_64-linux-debug-llvm.sh @@ -62,4 +62,4 @@ stage3-debug/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 240_000 + --test-timeout 4m diff --git a/ci/x86_64-linux-debug.sh b/ci/x86_64-linux-debug.sh index 663c8f834a..c9693bc1a7 100755 --- a/ci/x86_64-linux-debug.sh +++ b/ci/x86_64-linux-debug.sh @@ -62,4 +62,4 @@ stage3-debug/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 240_000 + --test-timeout 4m diff --git a/ci/x86_64-linux-release.sh b/ci/x86_64-linux-release.sh index fb91d69330..725bae0510 100755 --- a/ci/x86_64-linux-release.sh +++ b/ci/x86_64-linux-release.sh @@ -64,7 +64,7 @@ stage3-release/bin/zig build test docs \ --search-prefix "$PREFIX" \ --zig-lib-dir "$PWD/../lib" \ -Denable-superhtml \ - --test-timeout-ms 240_000 + --test-timeout 4m # Ensure that stage3 and stage4 are byte-for-byte identical. stage3-release/bin/zig build \ diff --git a/ci/x86_64-windows-debug.ps1 b/ci/x86_64-windows-debug.ps1 index 516a8e3444..873d3d5ff1 100644 --- a/ci/x86_64-windows-debug.ps1 +++ b/ci/x86_64-windows-debug.ps1 @@ -60,7 +60,7 @@ Write-Output "Main test suite..." -Dskip-non-native ` -Dskip-release ` -Denable-symlinks-windows ` - --test-timeout-ms 240_000 + --test-timeout 4m CheckLastExitCode Write-Output "Build x86_64-windows-msvc behavior tests using the C backend..." diff --git a/ci/x86_64-windows-release.ps1 b/ci/x86_64-windows-release.ps1 index 80568eeb37..f925894138 100644 --- a/ci/x86_64-windows-release.ps1 +++ b/ci/x86_64-windows-release.ps1 @@ -59,7 +59,7 @@ Write-Output "Main test suite..." -Dstatic-llvm ` -Dskip-non-native ` -Denable-symlinks-windows ` - --test-timeout-ms 240_000 + --test-timeout 4m CheckLastExitCode # Ensure that stage3 and stage4 are byte-for-byte identical. diff --git a/lib/compiler/build_runner.zig b/lib/compiler/build_runner.zig index 90bc591469..374bfa6ed3 100644 --- a/lib/compiler/build_runner.zig +++ b/lib/compiler/build_runner.zig @@ -108,7 +108,7 @@ pub fn main() !void { var summary: ?Summary = null; var max_rss: u64 = 0; var skip_oom_steps = false; - var test_timeout_ms: ?u64 = null; + var test_timeout_ns: ?u64 = null; var color: Color = .auto; var help_menu = false; var steps_menu = false; @@ -189,14 +189,41 @@ pub fn main() !void { }; } else if (mem.eql(u8, arg, "--skip-oom-steps")) { skip_oom_steps = true; - } else if (mem.eql(u8, arg, "--test-timeout-ms")) { - const millis_str = nextArgOrFatal(args, &arg_idx); - test_timeout_ms = std.fmt.parseInt(u64, millis_str, 10) catch |err| { - std.debug.print("invalid millisecond count: '{s}': {s}\n", .{ - millis_str, @errorName(err), - }); - process.exit(1); + } else if (mem.eql(u8, arg, "--test-timeout")) { + const units: []const struct { []const u8, u64 } = &.{ + .{ "ns", 1 }, + .{ "nanosecond", 1 }, + .{ "us", std.time.ns_per_us }, + .{ "microsecond", std.time.ns_per_us }, + .{ "ms", std.time.ns_per_ms }, + .{ "millisecond", std.time.ns_per_ms }, + .{ "s", std.time.ns_per_s }, + .{ "second", std.time.ns_per_s }, + .{ "m", std.time.ns_per_min }, + .{ "minute", std.time.ns_per_min }, + .{ "h", std.time.ns_per_hour }, + .{ "hour", std.time.ns_per_hour }, }; + const timeout_str = nextArgOrFatal(args, &arg_idx); + const num_end_idx = std.mem.findLastNone(u8, timeout_str, "abcdefghijklmnopqrstuvwxyz") orelse fatal( + "invalid timeout '{s}': expected unit (ns, us, ms, s, m, h)", + .{timeout_str}, + ); + const num_str = timeout_str[0 .. num_end_idx + 1]; + const unit_str = timeout_str[num_end_idx + 1 ..]; + const unit_factor: f64 = for (units) |unit_and_factor| { + if (std.mem.eql(u8, unit_str, unit_and_factor[0])) { + break @floatFromInt(unit_and_factor[1]); + } + } else fatal( + "invalid timeout '{s}': invalid unit '{s}' (expected ns, us, ms, s, m, h)", + .{ timeout_str, unit_str }, + ); + const num_parsed = std.fmt.parseFloat(f64, num_str) catch |err| fatal( + "invalid timeout '{s}': invalid number '{s}' ({t})", + .{ timeout_str, num_str, err }, + ); + test_timeout_ns = std.math.lossyCast(u64, unit_factor * num_parsed); } else if (mem.eql(u8, arg, "--search-prefix")) { const search_prefix = nextArgOrFatal(args, &arg_idx); builder.addSearchPrefix(search_prefix); @@ -480,10 +507,7 @@ pub fn main() !void { .max_rss_is_default = false, .max_rss_mutex = .{}, .skip_oom_steps = skip_oom_steps, - .unit_test_timeout_ns = ns: { - const ms = test_timeout_ms orelse break :ns null; - break :ns std.math.mul(u64, ms, std.time.ns_per_ms) catch null; - }, + .unit_test_timeout_ns = test_timeout_ns, .watch = watch, .web_server = undefined, // set after `prepare` @@ -1584,7 +1608,8 @@ fn printUsage(b: *std.Build, w: *Writer) !void { \\ -j Limit concurrent jobs (default is to use all CPU cores) \\ --maxrss Limit memory usage (default is to use available memory) \\ --skip-oom-steps Instead of failing, skip steps that would exceed --maxrss - \\ --test-timeout-ms Limit execution time of unit tests, terminating if exceeded + \\ --test-timeout Limit execution time of unit tests, terminating if exceeded. + \\ The timeout must include a unit: ns, us, ms, s, m, h \\ --fetch[=mode] Fetch dependency tree (optionally choose laziness) and exit \\ needed (Default) Lazy dependencies are fetched as needed \\ all Lazy dependencies are always fetched diff --git a/lib/std/Build/Step/Run.zig b/lib/std/Build/Step/Run.zig index 9a3c1f7906..cd29262612 100644 --- a/lib/std/Build/Step/Run.zig +++ b/lib/std/Build/Step/Run.zig @@ -1814,7 +1814,7 @@ fn pollZigTest( // test. For instance, if the test runner leaves this much time between us requesting a test to // start and it acknowledging the test starting, we terminate the child and raise an error. This // *should* never happen, but could in theory be caused by some very unlucky IB in a test. - const response_timeout_ns = options.unit_test_timeout_ns orelse 60 * std.time.ns_per_s; + const response_timeout_ns = @max(options.unit_test_timeout_ns orelse 0, 60 * std.time.ns_per_s); const stdout = poller.reader(.stdout); const stderr = poller.reader(.stderr); -- cgit v1.2.3