From 1c8350bf40210755dc9c1d556d78b6fe45da1a76 Mon Sep 17 00:00:00 2001 From: robobun Date: Thu, 30 Apr 2026 22:16:39 +0000 Subject: [PATCH 01/13] console.timeEnd/timeLog: apply console.group indentation Timer output bypassed the indentation stack maintained by console.group() because timeEnd/timeLog write through Output.printElapsed directly without consulting console.default_indent. Ordinary console.log goes through messageWithTypeAndLevel_, which forwards default_indent into FormatOptions. Write the indentation (2 spaces per group depth) before the elapsed-time prefix in both timeEnd and timeLog, and propagate the indent into the timeLog argument formatter so multi-line objects also nest correctly. Fixes #30017 --- src/jsc/ConsoleObject.zig | 23 ++++++++++- test/js/web/console/console-timeLog.test.ts | 46 +++++++++++++++++++++ 2 files changed, 67 insertions(+), 2 deletions(-) diff --git a/src/jsc/ConsoleObject.zig b/src/jsc/ConsoleObject.zig index 2489ea14ea0..0c0412a3839 100644 --- a/src/jsc/ConsoleObject.zig +++ b/src/jsc/ConsoleObject.zig @@ -3623,6 +3623,18 @@ const PendingTimers = std.AutoHashMap(u64, ?std.time.Timer); threadlocal var pending_time_logs: PendingTimers = undefined; threadlocal var pending_time_logs_loaded = false; +/// Writes `indent` levels (2 spaces each) to the same stderr stream used by +/// Output.printElapsed, so timer output nests inside the active console.group(). +fn printTimerIndent(indent: u16) void { + const spaces_buf = [_]u8{' '} ** 64; + var remaining: u32 = indent; + while (remaining > 0) { + const chunk: u8 = @min(32, remaining); + Output.printError("{s}", .{spaces_buf[0 .. chunk * 2]}); + remaining -|= chunk; + } +} + pub fn time( // console _: *ConsoleObject, @@ -3647,7 +3659,7 @@ pub fn timeEnd( // console _: *ConsoleObject, // global - _: *JSGlobalObject, + global: *JSGlobalObject, chars: [*]const u8, len: usize, ) callconv(jsc.conv) void { @@ -3658,6 +3670,9 @@ pub fn timeEnd( const id = bun.hash(chars[0..len]); const result = (pending_time_logs.fetchPut(id, null) catch null) orelse return; var value: std.time.Timer = result.value orelse return; + // Match console.group() indentation so output nests inside the active group, + // per the WHATWG Console spec. + printTimerIndent(global.bunVM().console.default_indent); // get the duration in microseconds // then display it in milliseconds Output.printElapsed(@as(f64, @floatFromInt(value.read() / std.time.ns_per_us)) / std.time.us_per_ms); @@ -3688,6 +3703,9 @@ pub fn timeLog( const id = bun.hash(chars[0..len]); var value: std.time.Timer = (pending_time_logs.get(id) orelse return) orelse return; + // Match console.group() indentation so output nests inside the active group, + // per the WHATWG Console spec. + printTimerIndent(global.bunVM().console.default_indent); // get the duration in microseconds // then display it in milliseconds Output.printElapsed(@as(f64, @floatFromInt(value.read() / std.time.ns_per_us)) / std.time.us_per_ms); @@ -3697,6 +3715,7 @@ pub fn timeLog( } Output.flush(); + const console = global.bunVM().console; // print the arguments var fmt = ConsoleObject.Formatter{ .remaining_values = &[_]JSValue{}, @@ -3707,10 +3726,10 @@ pub fn timeLog( const cli_context = CLI.get(); break :blk cli_context.runtime_options.console_depth orelse DEFAULT_CONSOLE_LOG_DEPTH; }, + .indent = console.default_indent, .stack_check = bun.StackCheck.init(), .can_throw_stack_overflow = true, }; - const console = global.bunVM().console; const writer = console.error_writer; const Writer = @TypeOf(writer); for (args[0..args_len]) |arg| { diff --git a/test/js/web/console/console-timeLog.test.ts b/test/js/web/console/console-timeLog.test.ts index eac97b05ed6..c2cb258d191 100644 --- a/test/js/web/console/console-timeLog.test.ts +++ b/test/js/web/console/console-timeLog.test.ts @@ -19,3 +19,49 @@ it("should log to console correctly", async () => { expect(outText.replace(/^\[.+?s\] /gm, "")).toBe(expectedText.replace(/^\[.+?s\] /gm, "")); }); + +// https://github.com/oven-sh/bun/issues/30017 — console.timeEnd()/timeLog() +// must apply console.group() indentation per the WHATWG Console spec. +it("console.timeEnd / timeLog respect console.group indentation", async () => { + const src = ` + console.time("top"); + console.timeEnd("top"); + + console.group("a"); + console.time("t1"); + console.timeEnd("t1"); + console.group("b"); + console.time("t2"); + console.timeLog("t2", "msg"); + console.timeLog("t2", { x: 1, y: 2 }); + console.timeEnd("t2"); + console.groupEnd(); + console.groupEnd(); + `; + await using proc = Bun.spawn({ + cmd: [bunExe(), "-e", src], + env: bunEnv, + stdin: "ignore", + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(exitCode).toBe(0); + // Group labels go to stdout; timer output goes to stderr. + expect(stdout.replaceAll("\r\n", "\n")).toBe("a\n b\n"); + // Strip the elapsed-time prefix so the stderr check focuses on indentation. + const normalized = stderr.replaceAll("\r\n", "\n").replace(/\[.+?m?s\] /g, ""); + expect(normalized).toBe( + [ + "top", // no group → no indent + " t1", // inside one group → 2 spaces + " t2 msg", // inside nested group → 4 spaces + " t2 {", // multi-line object opens at nested indent + " x: 1,", // inner fields indented by group depth + object depth + " y: 2,", + " }", + " t2", + "", + ].join("\n"), + ); +}); From e3b10872dfdd8e18616fdedbd4d08231ae682910 Mon Sep 17 00:00:00 2001 From: robobun Date: Thu, 30 Apr 2026 22:33:02 +0000 Subject: [PATCH 02/13] simplify printTimerIndent loop (clarity, no behavior change) --- src/jsc/ConsoleObject.zig | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/src/jsc/ConsoleObject.zig b/src/jsc/ConsoleObject.zig index 0c0412a3839..aaa174ae7c0 100644 --- a/src/jsc/ConsoleObject.zig +++ b/src/jsc/ConsoleObject.zig @@ -3626,12 +3626,12 @@ threadlocal var pending_time_logs_loaded = false; /// Writes `indent` levels (2 spaces each) to the same stderr stream used by /// Output.printElapsed, so timer output nests inside the active console.group(). fn printTimerIndent(indent: u16) void { - const spaces_buf = [_]u8{' '} ** 64; - var remaining: u32 = indent; + const spaces_chunk = " " ** 64; + var remaining: usize = @as(usize, indent) * 2; while (remaining > 0) { - const chunk: u8 = @min(32, remaining); - Output.printError("{s}", .{spaces_buf[0 .. chunk * 2]}); - remaining -|= chunk; + const n = @min(spaces_chunk.len, remaining); + Output.printError("{s}", .{spaces_chunk[0..n]}); + remaining -= n; } } From 9bee60052e1ad896e05160b0488c1fdbd0fcb86f Mon Sep 17 00:00:00 2001 From: robobun Date: Thu, 30 Apr 2026 22:53:16 +0000 Subject: [PATCH 03/13] test: assert exit code last per CLAUDE.md convention --- test/js/web/console/console-timeLog.test.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/test/js/web/console/console-timeLog.test.ts b/test/js/web/console/console-timeLog.test.ts index c2cb258d191..8778c25b21d 100644 --- a/test/js/web/console/console-timeLog.test.ts +++ b/test/js/web/console/console-timeLog.test.ts @@ -46,7 +46,6 @@ it("console.timeEnd / timeLog respect console.group indentation", async () => { stderr: "pipe", }); const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - expect(exitCode).toBe(0); // Group labels go to stdout; timer output goes to stderr. expect(stdout.replaceAll("\r\n", "\n")).toBe("a\n b\n"); // Strip the elapsed-time prefix so the stderr check focuses on indentation. @@ -64,4 +63,6 @@ it("console.timeEnd / timeLog respect console.group indentation", async () => { "", ].join("\n"), ); + // Assert the exit code last for more useful failure diagnostics. + expect(exitCode).toBe(0); }); From b1857248cb97ee7e1f3d987fb326a8c71774f5f0 Mon Sep 17 00:00:00 2001 From: robobun Date: Thu, 30 Apr 2026 23:26:21 +0000 Subject: [PATCH 04/13] retrigger CI From 9ee374703535499049767a52be049a24015f3c15 Mon Sep 17 00:00:00 2001 From: robobun Date: Fri, 1 May 2026 00:01:21 +0000 Subject: [PATCH 05/13] retrigger CI (flake in test/bake/dev-and-prod hmr rapid edits on Windows ARM64, unrelated to fix) From ac80357484c3b1e65465ff7f418b887b276ebe96 Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 12:30:07 +0000 Subject: [PATCH 06/13] =?UTF-8?q?retrigger=20CI=20(build=20#51012=20expire?= =?UTF-8?q?d=20=E2=80=94=20pipeline=20agent=20outage,=20infra=20recovered)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit From 86a06d1f57a9ff8b0f3cd0412db246eb2f039115 Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 14:14:15 +0000 Subject: [PATCH 07/13] retrigger CI (build #51215 hit another agent-expiration wave) From f2044a6af91729f8d4f53fb64096b614093fc5c9 Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 14:39:04 +0000 Subject: [PATCH 08/13] retrigger gate (previous run hit .git/index.lock from stale container state) From 7c60dd0f7ed9ea5ee0868313173666eca4a71c35 Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 15:37:51 +0000 Subject: [PATCH 09/13] retrigger CI (Windows ARM64 flake in hot.test.ts sourcemap and http-emit-close, unrelated to fix) From a593c0013eb66b320b125c2f011a701737c4917e Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 16:06:21 +0000 Subject: [PATCH 10/13] timeLog: deinit Formatter to release Visited.Pool node The Formatter literal in timeLog() was never released. When timeLog is called with an object/array argument, printAs() acquires a Visited.Pool node that only Formatter.deinit() returns, leaking one ObjectPool node + backing HashMap per call. Matches the pattern in format2(). --- src/jsc/ConsoleObject.zig | 1 + 1 file changed, 1 insertion(+) diff --git a/src/jsc/ConsoleObject.zig b/src/jsc/ConsoleObject.zig index aaa174ae7c0..92cd98f32b3 100644 --- a/src/jsc/ConsoleObject.zig +++ b/src/jsc/ConsoleObject.zig @@ -3730,6 +3730,7 @@ pub fn timeLog( .stack_check = bun.StackCheck.init(), .can_throw_stack_overflow = true, }; + defer fmt.deinit(); const writer = console.error_writer; const Writer = @TypeOf(writer); for (args[0..args_len]) |arg| { From 6a9ce622ca756425d0d500d99736879cb8ec79a8 Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 18:29:50 +0000 Subject: [PATCH 11/13] retrigger CI (build #51343 caught in pipeline-wide agent expiration; infra recovering) From 15d199776bbd540ac1bb7037b9aa7f40b571e774 Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 19:15:31 +0000 Subject: [PATCH 12/13] retrigger CI (Windows ARM64 shard 7 flake: test-http-should-emit-close timeout, unrelated) From ac4bf0afa29e0d027a7e6098cb217b4070e0e54a Mon Sep 17 00:00:00 2001 From: robobun Date: Mon, 4 May 2026 19:46:29 +0000 Subject: [PATCH 13/13] retrigger CI (win-aarch64-11 shard7 test-http flake ~50% rate across recent PRs)