| ... | @@ -1587,9 +1587,13 @@ fn spawnChildAndCollect( | ... | @@ -1587,9 +1587,13 @@ fn spawnChildAndCollect( |
| 1587 | }; | 1587 | }; |
| 1588 | | 1588 | |
| 1589 | if (run.stdio == .zig_test) { | 1589 | if (run.stdio == .zig_test) { |
| 1590 | var timer = try std.time.Timer.start(); | 1590 | const started: Io.Clock.Timestamp = try .now(io, .awake); |
| 1591 | defer run.step.result_duration_ns = timer.read(); | 1591 | const result = evalZigTest(run, spawn_options, options, fuzz_context) catch |err| switch (err) { |
| 1592 | try evalZigTest(run, spawn_options, options, fuzz_context); | 1592 | error.Canceled => |e| return e, |
| | 1593 | else => |e| e, |
| | 1594 | }; |
| | 1595 | run.step.result_duration_ns = @intCast((try started.untilNow(io)).raw.nanoseconds); |
| | 1596 | try result; |
| 1593 | return null; | 1597 | return null; |
| 1594 | } else { | 1598 | } else { |
| 1595 | const inherit = spawn_options.stdout == .inherit or spawn_options.stderr == .inherit; | 1599 | const inherit = spawn_options.stdout == .inherit or spawn_options.stderr == .inherit; |
| ... | @@ -1602,10 +1606,14 @@ fn spawnChildAndCollect( | ... | @@ -1602,10 +1606,14 @@ fn spawnChildAndCollect( |
| 1602 | } else .no_color; | 1606 | } else .no_color; |
| 1603 | defer if (inherit) io.unlockStderr(); | 1607 | defer if (inherit) io.unlockStderr(); |
| 1604 | try setColorEnvironmentVariables(run, environ_map, terminal_mode); | 1608 | try setColorEnvironmentVariables(run, environ_map, terminal_mode); |
| 1605 | var timer = try std.time.Timer.start(); | 1609 | |
| 1606 | const res = try evalGeneric(run, spawn_options); | 1610 | const started: Io.Clock.Timestamp = try .now(io, .awake); |
| 1607 | run.step.result_duration_ns = timer.read(); | 1611 | const result = evalGeneric(run, spawn_options) catch |err| switch (err) { |
| 1608 | return .{ .term = res.term, .stdout = res.stdout, .stderr = res.stderr }; | 1612 | error.Canceled => |e| return e, |
| | 1613 | else => |e| e, |
| | 1614 | }; |
| | 1615 | run.step.result_duration_ns = @intCast((try started.untilNow(io)).raw.nanoseconds); |
| | 1616 | return try result; |
| 1609 | } | 1617 | } |
| 1610 | } | 1618 | } |
| 1611 | | 1619 | |
| ... | @@ -1861,9 +1869,7 @@ fn waitZigTest( | ... | @@ -1861,9 +1869,7 @@ fn waitZigTest( |
| 1861 | | 1869 | |
| 1862 | var active_test_index: ?u32 = null; | 1870 | var active_test_index: ?u32 = null; |
| 1863 | | 1871 | |
| 1864 | // `null` means this host does not support `std.time.Timer`. This timer is `reset()` whenever we | 1872 | var last_update: Io.Clock.Timestamp = try .now(io, .awake); |
| 1865 | // change `active_test_index`, i.e. whenever a test starts or finishes. | | |
| 1866 | var timer: ?std.time.Timer = std.time.Timer.start() catch null; | | |
| 1867 | | 1873 | |
| 1868 | var coverage_id: ?u64 = null; | 1874 | var coverage_id: ?u64 = null; |
| 1869 | | 1875 | |
| ... | @@ -1871,16 +1877,27 @@ fn waitZigTest( | ... | @@ -1871,16 +1877,27 @@ fn waitZigTest( |
| 1871 | // test. For instance, if the test runner leaves this much time between us requesting a test to | 1877 | // test. For instance, if the test runner leaves this much time between us requesting a test to |
| 1872 | // start and it acknowledging the test starting, we terminate the child and raise an error. This | 1878 | // start and it acknowledging the test starting, we terminate the child and raise an error. This |
| 1873 | // *should* never happen, but could in theory be caused by some very unlucky IB in a test. | 1879 | // *should* never happen, but could in theory be caused by some very unlucky IB in a test. |
| 1874 | const response_timeout_ns: ?u64 = ns: { | 1880 | const response_timeout: ?Io.Clock.Duration = t: { |
| 1875 | if (fuzz_context != null) break :ns null; // don't timeout fuzz tests | 1881 | if (fuzz_context != null) break :t null; // don't timeout fuzz tests |
| 1876 | break :ns @max(options.unit_test_timeout_ns orelse 0, 60 * std.time.ns_per_s); | 1882 | const ns = @max(options.unit_test_timeout_ns orelse 0, 60 * std.time.ns_per_s); |
| | 1883 | break :t .{ .clock = .awake, .raw = .fromNanoseconds(ns) }; |
| 1877 | }; | 1884 | }; |
| | 1885 | const test_timeout: ?Io.Clock.Duration = if (options.unit_test_timeout_ns) |ns| .{ |
| | 1886 | .clock = .awake, |
| | 1887 | .raw = .fromNanoseconds(ns), |
| | 1888 | } else null; |
| 1878 | | 1889 | |
| 1879 | const stdout = multi_reader.reader(0); | 1890 | const stdout = multi_reader.reader(0); |
| 1880 | const stderr = multi_reader.reader(1); | 1891 | const stderr = multi_reader.reader(1); |
| 1881 | const Header = std.zig.Server.Message.Header; | 1892 | const Header = std.zig.Server.Message.Header; |
| 1882 | | 1893 | |
| 1883 | while (true) { | 1894 | while (true) { |
| | 1895 | const timeout: Io.Timeout = t: { |
| | 1896 | const opt_duration = if (active_test_index == null) response_timeout else test_timeout; |
| | 1897 | const duration = opt_duration orelse break :t .none; |
| | 1898 | break :t .{ .deadline = last_update.addDuration(duration) }; |
| | 1899 | }; |
| | 1900 | |
| 1884 | // This block is exited when `stdout` contains enough bytes for a `Header`. | 1901 | // This block is exited when `stdout` contains enough bytes for a `Header`. |
| 1885 | header_ready: { | 1902 | header_ready: { |
| 1886 | if (stdout.buffered().len >= @sizeOf(Header)) { | 1903 | if (stdout.buffered().len >= @sizeOf(Header)) { |
| ... | @@ -1888,65 +1905,33 @@ fn waitZigTest( | ... | @@ -1888,65 +1905,33 @@ fn waitZigTest( |
| 1888 | break :header_ready; | 1905 | break :header_ready; |
| 1889 | } | 1906 | } |
| 1890 | | 1907 | |
| 1891 | // Always `null` if `timer` is `null`. | | |
| 1892 | const opt_timeout_ns: ?u64 = ns: { | | |
| 1893 | if (timer == null) break :ns null; | | |
| 1894 | if (active_test_index == null) break :ns response_timeout_ns; | | |
| 1895 | break :ns options.unit_test_timeout_ns; | | |
| 1896 | }; | | |
| 1897 | | | |
| 1898 | const timeout: Io.Timeout = if (opt_timeout_ns) |timeout_ns| .{ .duration = .{ | | |
| 1899 | .raw = .fromNanoseconds(timeout_ns -| timer.?.read()), | | |
| 1900 | .clock = .awake, | | |
| 1901 | } } else .none; | | |
| 1902 | | | |
| 1903 | multi_reader.fill(64, timeout) catch |err| switch (err) { | 1908 | multi_reader.fill(64, timeout) catch |err| switch (err) { |
| 1904 | error.Timeout, error.EndOfStream => return .{ .no_poll = .{ | 1909 | error.Timeout => return .{ .timeout = .{ |
| 1905 | .active_test_index = active_test_index, | 1910 | .active_test_index = active_test_index, |
| 1906 | .ns_elapsed = if (timer) |*t| t.read() else 0, | 1911 | .ns_elapsed = @intCast((try last_update.untilNow(io)).raw.nanoseconds), |
| | 1912 | } }, |
| | 1913 | error.EndOfStream => return .{ .no_poll = .{ |
| | 1914 | .active_test_index = active_test_index, |
| | 1915 | .ns_elapsed = @intCast((try last_update.untilNow(io)).raw.nanoseconds), |
| 1907 | } }, | 1916 | } }, |
| 1908 | error.UnsupportedClock => { | | |
| 1909 | timer = null; | | |
| 1910 | continue; | | |
| 1911 | }, | | |
| 1912 | else => |e| return e, | 1917 | else => |e| return e, |
| 1913 | }; | 1918 | }; |
| 1914 | | 1919 | |
| 1915 | if (stdout.buffered().len >= @sizeOf(Header)) { | | |
| 1916 | // There wasn't a header before, but there is one after the `poll`. | | |
| 1917 | break :header_ready; | | |
| 1918 | } | | |
| 1919 | | | |
| 1920 | if (opt_timeout_ns) |timeout_ns| { | | |
| 1921 | const cur_ns = timer.?.read(); | | |
| 1922 | if (cur_ns >= timeout_ns) return .{ .timeout = .{ | | |
| 1923 | .active_test_index = active_test_index, | | |
| 1924 | .ns_elapsed = cur_ns, | | |
| 1925 | } }; | | |
| 1926 | } | | |
| 1927 | continue; | 1920 | continue; |
| 1928 | } | 1921 | } |
| 1929 | // There is definitely a header available now -- read it. | 1922 | // There is definitely a header available now -- read it. |
| 1930 | const header = stdout.takeStruct(Header, .little) catch unreachable; | 1923 | const header = stdout.takeStruct(Header, .little) catch unreachable; |
| 1931 | | 1924 | |
| 1932 | while (stdout.buffered().len < header.bytes_len) { | 1925 | while (stdout.buffered().len < header.bytes_len) { |
| 1933 | const timeout: Io.Timeout = t: { | | |
| 1934 | const t = if (timer) |*t| t else break :t .none; | | |
| 1935 | if (response_timeout_ns) |timeout_ns| break :t .{ .duration = .{ | | |
| 1936 | .raw = .fromNanoseconds(timeout_ns -| t.read()), | | |
| 1937 | .clock = .awake, | | |
| 1938 | } }; | | |
| 1939 | break :t .none; | | |
| 1940 | }; | | |
| 1941 | multi_reader.fill(64, timeout) catch |err| switch (err) { | 1926 | multi_reader.fill(64, timeout) catch |err| switch (err) { |
| 1942 | error.Timeout, error.EndOfStream => return .{ .no_poll = .{ | 1927 | error.Timeout => return .{ .timeout = .{ |
| 1943 | .active_test_index = active_test_index, | 1928 | .active_test_index = active_test_index, |
| 1944 | .ns_elapsed = if (timer) |*t| t.read() else 0, | 1929 | .ns_elapsed = @intCast((try last_update.untilNow(io)).raw.nanoseconds), |
| | 1930 | } }, |
| | 1931 | error.EndOfStream => return .{ .no_poll = .{ |
| | 1932 | .active_test_index = active_test_index, |
| | 1933 | .ns_elapsed = @intCast((try last_update.untilNow(io)).raw.nanoseconds), |
| 1945 | } }, | 1934 | } }, |
| 1946 | error.UnsupportedClock => { | | |
| 1947 | timer = null; | | |
| 1948 | continue; | | |
| 1949 | }, | | |
| 1950 | else => |e| return e, | 1935 | else => |e| return e, |
| 1951 | }; | 1936 | }; |
| 1952 | } | 1937 | } |
| ... | @@ -1991,13 +1976,13 @@ fn waitZigTest( | ... | @@ -1991,13 +1976,13 @@ fn waitZigTest( |
| 1991 | @memset(opt_metadata.*.?.ns_per_test, std.math.maxInt(u64)); | 1976 | @memset(opt_metadata.*.?.ns_per_test, std.math.maxInt(u64)); |
| 1992 | | 1977 | |
| 1993 | active_test_index = null; | 1978 | active_test_index = null; |
| 1994 | if (timer) |*t| t.reset(); | 1979 | last_update = try .now(io, .awake); |
| 1995 | | 1980 | |
| 1996 | requestNextTest(io, child.stdin.?, &opt_metadata.*.?, &sub_prog_node) catch |err| return .{ .write_failed = err }; | 1981 | requestNextTest(io, child.stdin.?, &opt_metadata.*.?, &sub_prog_node) catch |err| return .{ .write_failed = err }; |
| 1997 | }, | 1982 | }, |
| 1998 | .test_started => { | 1983 | .test_started => { |
| 1999 | active_test_index = opt_metadata.*.?.next_index - 1; | 1984 | active_test_index = opt_metadata.*.?.next_index - 1; |
| 2000 | if (timer) |*t| t.reset(); | 1985 | last_update = try .now(io, .awake); |
| 2001 | }, | 1986 | }, |
| 2002 | .test_results => { | 1987 | .test_results => { |
| 2003 | assert(fuzz_context == null); | 1988 | assert(fuzz_context == null); |
| ... | @@ -2040,7 +2025,10 @@ fn waitZigTest( | ... | @@ -2040,7 +2025,10 @@ fn waitZigTest( |
| 2040 | } | 2025 | } |
| 2041 | | 2026 | |
| 2042 | active_test_index = null; | 2027 | active_test_index = null; |
| 2043 | if (timer) |*t| md.ns_per_test[tr_hdr.index] = t.lap(); | 2028 | |
| | 2029 | const now: Io.Clock.Timestamp = try .now(io, .awake); |
| | 2030 | md.ns_per_test[tr_hdr.index] = @intCast(last_update.durationTo(now).raw.nanoseconds); |
| | 2031 | last_update = now; |
| 2044 | | 2032 | |
| 2045 | requestNextTest(io, child.stdin.?, md, &sub_prog_node) catch |err| return .{ .write_failed = err }; | 2033 | requestNextTest(io, child.stdin.?, md, &sub_prog_node) catch |err| return .{ .write_failed = err }; |
| 2046 | }, | 2034 | }, |