From 1ccf0c2e9cc6d89499d5e1ceacdc630010d5f50e Mon Sep 17 00:00:00 2001 From: Ashcon Partovi Date: Thu, 8 Feb 2024 17:52:58 -0800 Subject: [PATCH] Fix some errors not showing up in GitHub annotations (#8799) * Remove dead code now that `expect()` can be used outside of tests * Fix some errors not being rendered to GitHub annotations * [autofix.ci] apply automated fixes * Update jest.zig Try `execCallback` --------- Co-authored-by: autofix-ci[bot] <114827586+autofix-ci[bot]@users.noreply.github.com> --- src/bun.js/javascript.zig | 137 +++++++++++++++++++--- src/bun.js/test/jest.zig | 206 +++------------------------------ src/cli/test_command.zig | 7 +- test/cli/test/bun-test.test.ts | 47 +++++++- 4 files changed, 188 insertions(+), 209 deletions(-) diff --git a/src/bun.js/javascript.zig b/src/bun.js/javascript.zig index 231f064342..3fe2f59ef6 100644 --- a/src/bun.js/javascript.zig +++ b/src/bun.js/javascript.zig @@ -579,8 +579,6 @@ pub const VirtualMachine = struct { onUnhandledRejectionCtx: ?*anyopaque = null, unhandled_error_counter: usize = 0, - on_exception: ?*const OnException = null, - modules: ModuleLoader.AsyncModule.Queue = .{}, aggressive_garbage_collection: GCLevel = GCLevel.none, @@ -626,14 +624,6 @@ pub const VirtualMachine = struct { return this.debugger != null; } - pub fn setOnException(this: *VirtualMachine, callback: *const OnException) void { - this.on_exception = callback; - } - - pub fn clearOnException(this: *VirtualMachine) void { - this.on_exception = null; - } - const VMHolder = struct { pub threadlocal var vm: ?*VirtualMachine = null; }; @@ -2771,10 +2761,8 @@ pub const VirtualMachine = struct { this.had_errors = true; defer this.had_errors = prev_had_errors; - if (allow_side_effects) { - defer if (this.on_exception) |cb| { - cb(exception); - }; + if (allow_side_effects and Output.is_github_action) { + defer printGithubAnnotation(exception); } const line_numbers = exception.stack.source_lines_numbers[0..exception.stack.source_lines_len]; @@ -3007,6 +2995,127 @@ pub const VirtualMachine = struct { } } + // In Github Actions, emit an annotation that renders the error and location. + // https://docs.github.com/en/actions/using-workflows/workflow-commands-for-github-actions#setting-an-error-message + pub fn printGithubAnnotation(exception: *JSC.ZigException) void { + const name = exception.name; + const message = exception.message; + const frames = exception.stack.frames(); + const top_frame = if (frames.len > 0) frames[0] else null; + const dir = bun.getenvZ("GITHUB_WORKSPACE") orelse bun.fs.FileSystem.instance.top_level_dir; + const allocator = bun.default_allocator; + + var has_location = false; + + if (top_frame) |frame| { + if (!frame.position.isInvalid()) { + const source_url = frame.source_url.toUTF8(allocator); + defer source_url.deinit(); + const file = bun.path.relative(dir, source_url.slice()); + Output.printError("\n::error file={s},line={d},col={d},title=", .{ + file, + frame.position.line_start + 1, + frame.position.column_start, + }); + has_location = true; + } + } + + if (!has_location) { + Output.printError("\n::error title=", .{}); + } + + if (name.isEmpty() or name.eqlComptime("Error")) { + Output.printError("error", .{}); + } else { + Output.printError("{s}", .{name.githubAction()}); + } + + if (!message.isEmpty()) { + const message_slice = message.toUTF8(allocator); + defer message_slice.deinit(); + const msg = message_slice.slice(); + + var cursor: u32 = 0; + while (strings.indexOfNewlineOrNonASCIIOrANSI(msg, cursor)) |i| { + cursor = i + 1; + if (msg[i] == '\n') { + const first_line = bun.String.fromUTF8(msg[0..i]); + Output.printError(": {s}::", .{first_line.githubAction()}); + break; + } + } else { + Output.printError(": {s}::", .{message.githubAction()}); + } + + while (strings.indexOfNewlineOrNonASCIIOrANSI(msg, cursor)) |i| { + cursor = i + 1; + if (msg[i] == '\n') { + break; + } + } + + if (cursor > 0) { + const body = ZigString.init(msg[cursor..]); + Output.printError("{s}", .{body.githubAction()}); + } + } else { + Output.printError("::", .{}); + } + + // TODO: cleanup and refactor to use printStackTrace() + if (top_frame) |_| { + const vm = VirtualMachine.get(); + const origin = if (vm.is_from_devserver) &vm.origin else null; + + var i: i16 = 0; + while (i < frames.len) : (i += 1) { + const frame = frames[@as(usize, @intCast(i))]; + const source_url = frame.source_url.toUTF8(allocator); + defer source_url.deinit(); + const file = bun.path.relative(dir, source_url.slice()); + const func = frame.function_name.toUTF8(allocator); + + if (file.len == 0 and func.len == 0) continue; + + const has_name = std.fmt.count("{any}", .{frame.nameFormatter( + false, + )}) > 0; + + // %0A = escaped newline + if (has_name) { + Output.printError( + "%0A at {any} ({any})", + .{ + frame.nameFormatter(false), + frame.sourceURLFormatter( + file, + origin, + false, + false, + ), + }, + ); + } else { + Output.printError( + "%0A at {any}", + .{ + frame.sourceURLFormatter( + file, + origin, + false, + false, + ), + }, + ); + } + } + } + + Output.printError("\n", .{}); + Output.flush(); + } + extern fn Process__emitMessageEvent(global: *JSGlobalObject, value: JSValue) void; extern fn Process__emitDisconnectEvent(global: *JSGlobalObject) void; diff --git a/src/bun.js/test/jest.zig b/src/bun.js/test/jest.zig index 54b3a7c423..023d0ef247 100644 --- a/src/bun.js/test/jest.zig +++ b/src/bun.js/test/jest.zig @@ -78,9 +78,6 @@ pub const TestRunner = struct { has_pending_tests: bool = false, pending_test: ?*TestRunnerTask = null, - /// This silences TestNotRunningError when expect() is used to halt a running test. - did_pending_test_fail: bool = false, - snapshots: Snapshots, default_timeout_ms: u32 = 0, @@ -154,7 +151,6 @@ pub const TestRunner = struct { if (this.queue.readItem()) |task| { this.pending_test = task; this.has_pending_tests = true; - this.did_pending_test_fail = false; if (!task.run()) { this.has_pending_tests = false; this.pending_test = null; @@ -588,7 +584,7 @@ pub const TestScope = struct { debug("onReject", .{}); const arguments = callframe.arguments(2); const err = arguments.ptr[0]; - globalThis.bunVM().runErrorHandler(err, null); + globalThis.bunVM().onUnhandledError(globalThis, err); var task: *TestRunnerTask = arguments.ptr[1].asPromisePtr(TestRunnerTask); task.handleResult(.{ .fail = expect.active_test_expectation_counter.actual }, .promise); globalThis.bunVM().autoGarbageCollect(); @@ -623,7 +619,7 @@ pub const TestScope = struct { task.handleResult(.{ .pass = expect.active_test_expectation_counter.actual }, .callback); } else { debug("done(err)", .{}); - globalThis.bunVM().runErrorHandlerWithDedupe(err, null); + globalThis.bunVM().onUnhandledError(globalThis, err); task.handleResult(.{ .fail = expect.active_test_expectation_counter.actual }, .callback); } } else { @@ -643,7 +639,6 @@ pub const TestScope = struct { var vm = VirtualMachine.get(); const func = this.func; - Jest.runner.?.did_pending_test_fail = false; defer { for (this.func_arg) |arg| { arg.unprotect(); @@ -683,11 +678,7 @@ pub const TestScope = struct { initial_value = callJSFunctionForTestRunner(vm, vm.global, this.func, this.func_arg); if (initial_value.isAnyError()) { - if (!Jest.runner.?.did_pending_test_fail) { - // test failed unless it's a todo - Jest.runner.?.did_pending_test_fail = this.tag != .todo; - vm.runErrorHandler(initial_value, null); - } + vm.onUnhandledError(vm.global, initial_value); if (this.tag == .todo) { return .{ .todo = {} }; @@ -710,11 +701,7 @@ pub const TestScope = struct { } switch (promise.status(vm.global.vm())) { .Rejected => { - if (!Jest.runner.?.did_pending_test_fail) { - // test failed unless it's a todo - Jest.runner.?.did_pending_test_fail = this.tag != .todo; - vm.runErrorHandler(promise.result(vm.global.vm()), null); - } + vm.onUnhandledError(vm.global, promise.result(vm.global.vm())); if (this.tag == .todo) { return .{ .todo = {} }; @@ -888,7 +875,7 @@ pub const DescribeScope = struct { if (args.len > 0) { const err = args.ptr[0]; if (!err.isEmptyOrUndefinedOrNull()) { - ctx.bunVM().runErrorHandlerWithDedupe(err, null); + ctx.bunVM().onUnhandledError(ctx.bunVM().global, err); } } scope.done = true; @@ -921,13 +908,6 @@ pub const DescribeScope = struct { } } - const pending_test = Jest.runner.?.pending_test; - // forbid `expect()` within hooks - Jest.runner.?.pending_test = null; - const orig_did_pending_test_fail = Jest.runner.?.did_pending_test_fail; - - Jest.runner.?.did_pending_test_fail = false; - const vm = VirtualMachine.get(); var result: JSC.JSValue = switch (cb.getLength(globalObject)) { 0 => callJSFunctionForTestRunner(vm, globalObject, cb, &.{}), @@ -943,8 +923,6 @@ pub const DescribeScope = struct { ); const result = callJSFunctionForTestRunner(vm, globalObject, cb, &.{done_func}); if (result.toError()) |err| { - Jest.runner.?.pending_test = pending_test; - Jest.runner.?.did_pending_test_fail = orig_did_pending_test_fail; return err; } vm.waitFor(&this.done); @@ -961,8 +939,6 @@ pub const DescribeScope = struct { result = promise.result(globalObject.vm()); } - Jest.runner.?.pending_test = pending_test; - Jest.runner.?.did_pending_test_fail = orig_did_pending_test_fail; if (result.isAnyError()) return result; } @@ -989,13 +965,6 @@ pub const DescribeScope = struct { } } - const pending_test = Jest.runner.?.pending_test; - // forbid `expect()` within hooks - Jest.runner.?.pending_test = null; - const orig_did_pending_test_fail = Jest.runner.?.did_pending_test_fail; - - Jest.runner.?.did_pending_test_fail = false; - const vm = VirtualMachine.get(); // note: we do not support "done" callback in global hooks in the first release. var result: JSC.JSValue = callJSFunctionForTestRunner(vm, globalThis, cb, &.{}); @@ -1010,8 +979,6 @@ pub const DescribeScope = struct { result = promise.result(globalThis.vm()); } - Jest.runner.?.pending_test = pending_test; - Jest.runner.?.did_pending_test_fail = orig_did_pending_test_fail; if (result.isAnyError()) return result; } @@ -1101,12 +1068,12 @@ pub const DescribeScope = struct { switch (prom.status(globalObject.ptr().vm())) { JSPromise.Status.Fulfilled => {}, else => { - globalObject.bunVM().runErrorHandlerWithDedupe(prom.result(globalObject.ptr().vm()), null); + globalObject.bunVM().onUnhandledError(globalObject, prom.result(globalObject.ptr().vm())); return .undefined; }, } } else if (result.toError()) |err| { - globalObject.bunVM().runErrorHandlerWithDedupe(err, null); + globalObject.bunVM().onUnhandledError(globalObject, err); return .undefined; } } @@ -1133,7 +1100,8 @@ pub const DescribeScope = struct { var i: TestRunner.Test.ID = 0; if (this.shouldEvaluateScope()) { - if (this.runCallback(globalObject, .beforeAll)) |_| { + if (this.runCallback(globalObject, .beforeAll)) |err| { + globalObject.bunVM().onUnhandledError(globalObject, err); while (i < end) { Jest.runner.?.reportFailure(i + this.test_id_start, source.path.text, tests[i].label, 0, 0, this); i += 1; @@ -1178,7 +1146,7 @@ pub const DescribeScope = struct { if (!skipped) { if (this.runCallback(globalThis, .afterEach)) |err| { - globalThis.bunVM().runErrorHandler(err, null); + globalThis.bunVM().onUnhandledError(globalThis, err); } } @@ -1190,7 +1158,7 @@ pub const DescribeScope = struct { // Run the afterAll callbacks, in reverse order // unless there were no tests for this scope if (this.execCallback(globalThis, .afterAll)) |err| { - globalThis.bunVM().runErrorHandler(err, null); + globalThis.bunVM().onUnhandledError(globalThis, err); } } @@ -1275,19 +1243,7 @@ pub const TestRunnerTask = struct { fulfilled, }; - pub fn onUnhandledRejection(jsc_vm: *VirtualMachine, global: *JSC.JSGlobalObject, rejection: JSC.JSValue) void { - if (Jest.runner) |runner| { - if (runner.did_pending_test_fail and rejection.isException(global.vm())) { - if (rejection.toError()) |err| { - if (err.get(global, "name")) |name| { - if (name.isString() and name.getZigString(global).eqlComptime("TestNotRunningError")) { - return; - } - } - } - } - } - + pub fn onUnhandledRejection(jsc_vm: *VirtualMachine, _: *JSC.JSGlobalObject, rejection: JSC.JSValue) void { if (jsc_vm.last_reported_error_for_dedupe == rejection and rejection != .zero) { jsc_vm.last_reported_error_for_dedupe = .zero; } else { @@ -1339,17 +1295,14 @@ pub const TestRunnerTask = struct { } jsc_vm.onUnhandledRejectionCtx = this; - if (Output.is_github_action) { - jsc_vm.setOnException(printGithubAnnotation); - } if (this.needs_before_each) { this.needs_before_each = false; const label = test_.label; if (this.describe.runCallback(globalThis, .beforeEach)) |err| { + jsc_vm.onUnhandledError(globalThis, err); Jest.runner.?.reportFailure(test_id, this.source_file_path, label, 0, 0, this.describe); - jsc_vm.runErrorHandler(err, null); return false; } } @@ -1385,9 +1338,6 @@ pub const TestRunnerTask = struct { } pub fn handleResult(this: *TestRunnerTask, result: Result, comptime from: @Type(.EnumLiteral)) void { - if (result == .fail) - Jest.runner.?.did_pending_test_fail = true; - switch (comptime from) { .promise => { if (comptime Environment.allow_assert) std.debug.assert(this.promise_state == .pending); @@ -1427,10 +1377,12 @@ pub const TestRunnerTask = struct { const test_ = this.describe.tests.items[test_id]; var describe = this.describe; describe.tests.items[test_id] = test_; + if (comptime from == .timeout) { - Output.prettyErrorln("Timeout: test {} timed out after {d}ms", .{ bun.fmt.quote(test_.label), test_.timeout_millis }); - Output.flush(); + const err = this.globalThis.createErrorInstance("Test {} timed out after {d}ms", .{ bun.fmt.quote(test_.label), test_.timeout_millis }); + this.globalThis.bunVM().onUnhandledError(this.globalThis, err); } + processTestResult(this, this.globalThis, result, test_, test_id, describe); } @@ -1481,13 +1433,12 @@ pub const TestRunnerTask = struct { } fn deinit(this: *TestRunnerTask) void { - var vm = JSC.VirtualMachine.get(); + const vm = JSC.VirtualMachine.get(); if (vm.onUnhandledRejectionCtx) |ctx| { if (ctx == @as(*anyopaque, @ptrCast(this))) { vm.onUnhandledRejectionCtx = null; } } - vm.clearOnException(); this.ref.unref(vm); @@ -1702,127 +1653,6 @@ inline fn createIfScope( return JSC.NewFunction(globalThis, name, 2, call, false); } -// In Github Actions, emit an annotation that renders the error and location. -// https://docs.github.com/en/actions/using-workflows/workflow-commands-for-github-actions#setting-an-error-message -pub fn printGithubAnnotation(exception: *JSC.ZigException) void { - const name = exception.name; - const message = exception.message; - const frames = exception.stack.frames(); - const top_frame = if (frames.len > 0) frames[0] else null; - const dir = bun.getenvZ("GITHUB_WORKSPACE") orelse bun.fs.FileSystem.instance.top_level_dir; - const allocator = bun.default_allocator; - - var has_location = false; - - if (top_frame) |frame| { - if (!frame.position.isInvalid()) { - const source_url = frame.source_url.toUTF8(allocator); - defer source_url.deinit(); - const file = bun.path.relative(dir, source_url.slice()); - Output.printError("\n::error file={s},line={d},col={d},title=", .{ - file, - frame.position.line_start + 1, - frame.position.column_start, - }); - has_location = true; - } - } - - if (!has_location) { - Output.printError("\n::error title=", .{}); - } - - if (name.isEmpty() or name.eqlComptime("Error")) { - Output.printError("error", .{}); - } else { - Output.printError("{s}", .{name.githubAction()}); - } - - if (!message.isEmpty()) { - const message_slice = message.toUTF8(allocator); - defer message_slice.deinit(); - const msg = message_slice.slice(); - - var cursor: u32 = 0; - while (strings.indexOfNewlineOrNonASCIIOrANSI(msg, cursor)) |i| { - cursor = i + 1; - if (msg[i] == '\n') { - const first_line = bun.String.fromUTF8(msg[0..i]); - Output.printError(": {s}::", .{first_line.githubAction()}); - break; - } - } else { - Output.printError(": {s}::", .{message.githubAction()}); - } - - while (strings.indexOfNewlineOrNonASCIIOrANSI(msg, cursor)) |i| { - cursor = i + 1; - if (msg[i] == '\n') { - break; - } - } - - if (cursor > 0) { - const body = ZigString.init(msg[cursor..]); - Output.printError("{s}", .{body.githubAction()}); - } - } else { - Output.printError("::", .{}); - } - - // TODO: cleanup and refactor to use printStackTrace() - if (top_frame) |_| { - const vm = VirtualMachine.get(); - const origin = if (vm.is_from_devserver) &vm.origin else null; - - var i: i16 = 0; - while (i < frames.len) : (i += 1) { - const frame = frames[@as(usize, @intCast(i))]; - const source_url = frame.source_url.toUTF8(allocator); - defer source_url.deinit(); - const file = bun.path.relative(dir, source_url.slice()); - const func = frame.function_name.toUTF8(allocator); - - if (file.len == 0 and func.len == 0) continue; - - const has_name = std.fmt.count("{any}", .{frame.nameFormatter( - false, - )}) > 0; - - // %0A = escaped newline - if (has_name) { - Output.printError( - "%0A at {any} ({any})", - .{ - frame.nameFormatter(false), - frame.sourceURLFormatter( - file, - origin, - false, - false, - ), - }, - ); - } else { - Output.printError( - "%0A at {any}", - .{ - frame.sourceURLFormatter( - file, - origin, - false, - false, - ), - }, - ); - } - } - } - - Output.printError("\n", .{}); - Output.flush(); -} - fn consumeArg( globalThis: *JSC.JSGlobalObject, should_write: bool, diff --git a/src/cli/test_command.zig b/src/cli/test_command.zig index e4e6c13929..dca5a1fef4 100644 --- a/src/cli/test_command.zig +++ b/src/cli/test_command.zig @@ -1025,8 +1025,7 @@ pub const TestCommand = struct { switch (promise.status(vm.global.vm())) { .Rejected => { - const result = promise.result(vm.global.vm()); - vm.runErrorHandler(result, null); + vm.onUnhandledError(vm.global, promise.result(vm.global.vm())); reporter.summary.fail += 1; if (reporter.jest.bail == reporter.summary.fail) { @@ -1110,8 +1109,8 @@ pub const TestCommand = struct { if (is_last) { if (jest.Jest.runner != null) { - if (jest.DescribeScope.runGlobalCallbacks(vm.global, .afterAll)) |after| { - vm.global.bunVM().runErrorHandler(after, null); + if (jest.DescribeScope.runGlobalCallbacks(vm.global, .afterAll)) |err| { + vm.onUnhandledError(vm.global, err); } } } diff --git a/test/cli/test/bun-test.test.ts b/test/cli/test/bun-test.test.ts index f0f82deee1..f835d1ee00 100644 --- a/test/cli/test/bun-test.test.ts +++ b/test/cli/test/bun-test.test.ts @@ -493,11 +493,22 @@ describe("bun test", () => { }); expect(stderr).not.toContain("::error"); }); - test("should annotate errors when enabled", () => { + test("should annotate errors in the global scope", () => { const stderr = runTest({ input: ` - import { test, expect } from "bun:test"; - test("fail", () => { + throw new Error(); + `, + env: { + GITHUB_ACTIONS: "true", + }, + }); + expect(stderr).toMatch(/::error file=.*,line=\d+,col=\d+,title=error::/); + }); + test.each(["test", "describe"])("should annotate errors in a %s scope", type => { + const stderr = runTest({ + input: ` + import { ${type} } from "bun:test"; + ${type}("fail", () => { throw new Error(); }); `, @@ -507,6 +518,21 @@ describe("bun test", () => { }); expect(stderr).toMatch(/::error file=.*,line=\d+,col=\d+,title=error::/); }); + test.each(["beforeAll", "beforeEach", "afterEach", "afterAll"])("should annotate errors in a %s callback", type => { + const stderr = runTest({ + input: ` + import { test, ${type} } from "bun:test"; + ${type}(() => { + throw new Error(); + }); + test("test", () => {}); + `, + env: { + GITHUB_ACTIONS: "true", + }, + }); + expect(stderr).toMatch(/::error file=.*,line=\d+,col=\d+,title=error::/); + }); test("should annotate errors with escaped strings", () => { const stderr = runTest({ input: ` @@ -539,6 +565,21 @@ describe("bun test", () => { }); expect(stderr).toMatch(/::error title=error: Oops!::/); }); + test("should annotate a test timeout", () => { + const stderr = runTest({ + input: ` + import { test } from "bun:test"; + test("time out", async () => { + await Bun.sleep(1000); + }, { timeout: 1 }); + `, + env: { + FORCE_COLOR: "1", + GITHUB_ACTIONS: "true", + }, + }); + expect(stderr).toMatch(/::error title=error: Test \"time out\" timed out after \d+ms::/); + }); }); describe(".each", () => { test("should run tests with test.each", () => {