From c5436c09abec0dec4f144acc99f7b9e7578920ea Mon Sep 17 00:00:00 2001 From: Jarred Sumner Date: Fri, 22 Dec 2023 03:00:24 +0100 Subject: [PATCH] Fix setInterval regression (#7776) * Fix setInterval regression * Add some comments * Add another test --------- Co-authored-by: Jarred Sumner <709451+Jarred-Sumner@users.noreply.github.com> --- src/bun.js/api/bun.zig | 50 ++++++++++++++----- test/harness.ts | 26 +++++++++- test/js/web/timers/setInterval-fixture.js | 15 ++++++ .../js/web/timers/setInterval-leak-fixture.js | 30 +++++++++++ test/js/web/timers/setInterval.test.js | 15 +++++- test/js/web/timers/setTimeout.test.js | 2 +- .../web/timers/setinterval-cancel-fixture.js | 27 ++++++++++ 7 files changed, 148 insertions(+), 17 deletions(-) create mode 100644 test/js/web/timers/setInterval-fixture.js create mode 100644 test/js/web/timers/setInterval-leak-fixture.js create mode 100644 test/js/web/timers/setinterval-cancel-fixture.js diff --git a/src/bun.js/api/bun.zig b/src/bun.js/api/bun.zig index 8b54d7290c..00444a07de 100644 --- a/src/bun.js/api/bun.zig +++ b/src/bun.js/api/bun.zig @@ -3437,6 +3437,7 @@ pub const Timer = struct { arguments.ensureStillAlive(); timeout.arguments = JSC.Strong.create(arguments, globalThis); } + timeout.timer.?.interval = this.interval; timeout.poll_ref.ref(vm); @@ -3518,13 +3519,23 @@ pub const Timer = struct { }, interval: i32 = -1, concurrent_task: JSC.ConcurrentTask = undefined, + scheduled_count: std.atomic.Value(u32) = std.atomic.Value(u32).init(0), pub const Pool = bun.HiveArray(TimerReference, 1024).Fallback; fn onRequest(req: *bun.io.Request) bun.io.Action { var this: *TimerReference = @fieldParentPtr(TimerReference, "request", req); - if (this.timer.state == .CANCELLED) { - this.deinit(); + + if (this.cancelled) { + // We must free this on the main thread + // deinit() is not thread-safe + // + // so we: + // + // 1) schedule a concurrent task to call `runFromJSThread` + // 2) in `runFromJSThread`, we call `deinit` if `cancelled` is true + // + this.event_loop.enqueueTaskConcurrent(this.concurrent_task.from(this, .manual_deinit)); return bun.io.Action{ .timer_cancelled = {}, }; @@ -3541,26 +3552,37 @@ pub const Timer = struct { return .{ .disarm = {} }; } + pub fn reschedule(this: *TimerReference) void { + this.request = .{ + .callback = &onRequest, + }; + this.schedule(this.interval); + } + pub fn runFromJSThread(this: *TimerReference) void { const timer_id = this.id; const vm = this.event_loop.virtual_machine; + _ = this.scheduled_count.fetchSub(1, .Monotonic); if (this.cancelled) { this.deinit(); return; } - if (Timeout.runFromConcurrentTask(timer_id, vm) and !this.cancelled) { - this.request = .{ - .callback = &onRequest, - }; - this.schedule(null); - } else { + + if (comptime Environment.allow_assert) + // If this is ever -1, it's invalid. + // It should always be at least 1. + std.debug.assert(this.interval > 0); + + if (!Timeout.runFromConcurrentTask(timer_id, vm, this, reschedule) or this.cancelled) { this.deinit(); } } pub fn deinit(this: *TimerReference) void { - this.event_loop.timerReferencePool().put(this); + if (this.scheduled_count.load(.Monotonic) == 0) + // Free it if there is no other scheduled job + this.event_loop.timerReferencePool().put(this); } pub fn create(event_loop: *JSC.EventLoop, id: ID) *TimerReference { @@ -3574,6 +3596,7 @@ pub const Timer = struct { pub fn schedule(this: *TimerReference, interval: ?i32) void { std.debug.assert(!this.cancelled); + _ = this.scheduled_count.fetchAdd(1, .Monotonic); this.timer.state = .PENDING; this.timer.next = msToTimespec(@intCast(@max(interval orelse this.interval, 1))); bun.io.Loop.get().schedule(&this.request); @@ -3633,7 +3656,7 @@ pub const Timer = struct { runWithIDAndVM(timer_id, vm); } - pub fn runFromConcurrentTask(timer_id: ID, vm: *JSC.VirtualMachine) bool { + pub fn runFromConcurrentTask(timer_id: ID, vm: *JSC.VirtualMachine, timer_ref: *TimerReference, comptime reschedule: fn (*TimerReference) void) bool { const repeats = timer_id.repeats(); var map = vm.timer.maps.get(timer_id.kind); @@ -3688,7 +3711,6 @@ pub const Timer = struct { .kind = timer_id.kind, }; - var reschedule = false; // This allows us to: // - free the memory before the job is run // - reuse the JSC.Strong @@ -3700,7 +3722,7 @@ pub const Timer = struct { } else { this.has_scheduled_job = true; map.put(vm.allocator, timer_id.id, this) catch {}; - reschedule = true; + reschedule(timer_ref); } // TODO: remove this memory allocation! @@ -3717,7 +3739,7 @@ pub const Timer = struct { job.perform(); - return reschedule; + return repeats; } pub fn runWithIDAndVM(timer_id: ID, vm: *JSC.VirtualMachine) void { @@ -3878,6 +3900,8 @@ pub const Timer = struct { ), }; + timeout.timer.?.interval = interval; + if (arguments_array_or_zero != .zero) { timeout.arguments = JSC.Strong.create(arguments_array_or_zero, globalThis); } diff --git a/test/harness.ts b/test/harness.ts index b65241b8e0..2e2c64eeaf 100644 --- a/test/harness.ts +++ b/test/harness.ts @@ -1,5 +1,5 @@ -import { gc as bunGC, unsafe, which } from "bun"; - +import { gc as bunGC, stdout, unsafe, which } from "bun"; +import { expect } from "bun:test"; export const bunEnv: any = { ...process.env, GITHUB_ACTIONS: "false", @@ -173,3 +173,25 @@ export function fakeNodeRun(dir: string, file: string | string[], env?: Record `Command ${cmds.join(" ")} failed:` + "\n" + result.stdout.toString("utf-8"), + }; + } + + return { + pass: true, + message: () => `Expected ${cmds.join(" ")} to fail`, + }; + }, +}); diff --git a/test/js/web/timers/setInterval-fixture.js b/test/js/web/timers/setInterval-fixture.js new file mode 100644 index 0000000000..f9da012686 --- /dev/null +++ b/test/js/web/timers/setInterval-fixture.js @@ -0,0 +1,15 @@ +var lastCall = performance.now(); +const delta = 16; +let tries = 100; +setInterval(() => { + const now = performance.now(); + console.log((now - lastCall) | 0, "ms since the last call"); + if (now - lastCall < ((delta / 2) | 0)) { + process.exit(1); + } + lastCall = now; + + if (--tries === 0) { + process.exit(0); + } +}, delta); diff --git a/test/js/web/timers/setInterval-leak-fixture.js b/test/js/web/timers/setInterval-leak-fixture.js new file mode 100644 index 0000000000..c0dcd4f063 --- /dev/null +++ b/test/js/web/timers/setInterval-leak-fixture.js @@ -0,0 +1,30 @@ +const huge = Array.from({ length: 1000000 }, () => 0); +huge.fill(0); +const delta = 1; +const initialRuns = 5_000_000; +let runs = initialRuns; +var initial = 0; + +const gc = typeof Bun !== "undefined" ? Bun.gc : typeof globalThis.gc !== "undefined" ? globalThis.gc : () => {}; + +function fn(huge) { + huge.length; + + if (runs === initialRuns) { + gc(true); + initial = process.memoryUsage.rss(); + console.log(this); + } + + if (--runs === 0) { + const kb = (process.memoryUsage.rss() - initial) / 1024; + console.log("Memory usage increase between timer runs:", kb | 0, "KB"); + if (kb > 1 * 1024) { + process.exit(1); + } + + process.exit(0); + } +} + +for (let i = 0; i < 50_000; i++) setInterval(fn, delta, huge); diff --git a/test/js/web/timers/setInterval.test.js b/test/js/web/timers/setInterval.test.js index 29e10ccbb0..b6cdbe2e5f 100644 --- a/test/js/web/timers/setInterval.test.js +++ b/test/js/web/timers/setInterval.test.js @@ -1,5 +1,6 @@ import { it, expect } from "bun:test"; - +import { join } from "path"; +import "harness"; it("setInterval", async () => { var counter = 0; var start; @@ -73,3 +74,15 @@ it("setInterval if refreshed before run, should reschedule to run later", done = timer.refresh(); }, 50); }); + +it("setInterval runs with at least the delay time", () => { + expect([`run`, join(import.meta.dir, "setInterval-fixture.js")]).toRun(); +}); + +it("setInterval doesn't leak memory", () => { + expect([`run`, join(import.meta.dir, "setInterval-leak-fixture.js")]).toRun(); +}, 30_000); + +it("setInterval doesn't run when cancelled after being scheduled", () => { + expect([`run`, join(import.meta.dir, "setInterval-cancel-fixture.js")]).toRun(); +}, 30_000); diff --git a/test/js/web/timers/setTimeout.test.js b/test/js/web/timers/setTimeout.test.js index 71019c97a8..38d2db9f6f 100644 --- a/test/js/web/timers/setTimeout.test.js +++ b/test/js/web/timers/setTimeout.test.js @@ -167,7 +167,7 @@ it("node.js timers/promises setTimeout propagates exceptions", async () => { } }); -it.skip("order of setTimeouts", done => { +it("order of setTimeouts", done => { var nums = []; var maybeDone = cb => { return () => { diff --git a/test/js/web/timers/setinterval-cancel-fixture.js b/test/js/web/timers/setinterval-cancel-fixture.js new file mode 100644 index 0000000000..4c5d58939e --- /dev/null +++ b/test/js/web/timers/setinterval-cancel-fixture.js @@ -0,0 +1,27 @@ +const huge = Array.from({ length: 1000000 }, () => 0); +huge.fill(0); +let hasRun = false; +const gc = typeof Bun !== "undefined" ? Bun.gc : typeof globalThis.gc !== "undefined" ? globalThis.gc : () => {}; + +var timers = new Array(50_000); + +function fn(huge) { + if (hasRun) { + console.error("Timer ran more than once after being cancelled."); + process.exit(1); + } + hasRun = true; + for (let i = 0; i < timers.length; i++) { + clearInterval(timers[i]); + } + timers.length = 0; + gc(true); + + setTimeout(() => { + console.log("RSS:", (process.memoryUsage.rss() / 1024 / 1024) | 0, "MB"); + process.exit(0); + }, 10); +} + +gc(true); +for (let i = 0; i < timers.length; i++) timers[i] = setInterval(fn, 1, huge);