diff --git a/sdk/src/log-ship.ts b/sdk/src/log-ship.ts index dd000749..f7003fca 100644 --- a/sdk/src/log-ship.ts +++ b/sdk/src/log-ship.ts @@ -244,12 +244,23 @@ export const installLogShipper = ( } }; + // The most recent flush, so an explicit `flush()` can WAIT for a periodic one rather than hit + // the re-entry guard and return having sent nothing. That matters on the shutdown path: the + // runner flushes once more after its units' finalizers have run, and those last lines are the + // ones that say whether the shutdown was clean. The window is widest exactly when the host is + // slow — which is when the logs are worth most. + let inFlight: Promise = Promise.resolve(); + const runFlush = (): Promise => { + inFlight = flush(); + return inFlight; + }; + const timer = setInterval(() => { if (skipTicks > 0) { skipTicks -= 1; return; } - void flush(); + void runFlush(); }, options.intervalMs ?? 2_000); // The runner parks on its own keep-alive handle; this timer must not be what holds the process // open, or a runner with nothing to run would never exit. @@ -258,7 +269,9 @@ export const installLogShipper = ( return { flush: async () => { skipTicks = 0; - await flush(); + // `flush` never rejects (every path is caught); `.catch` only keeps that a guarantee. + await inFlight.catch(() => {}); + await runFlush(); }, stop: () => { stopped = true; diff --git a/sdk/test/log-ship.test.ts b/sdk/test/log-ship.test.ts index e289945b..a088db48 100644 --- a/sdk/test/log-ship.test.ts +++ b/sdk/test/log-ship.test.ts @@ -228,6 +228,51 @@ describe("shipping", () => { expect(all).toContain("during"); }); + test("an explicit flush waits for an in-flight one instead of no-opping", async () => { + // This is the shutdown path. The runner flushes once more after its units' finalizers have + // run, and those last lines are the ones that say whether the shutdown WAS clean. If a + // periodic flush happened to be mid-POST, an explicit flush that simply returned would + // leave them unsent — and the window is widest exactly when the host is slow, which is when + // the logs matter most. + let release: (() => void) | undefined; + const held = new Promise((r) => { + release = r; + }); + let arrived: (() => void) | undefined; + const received = new Promise((r) => { + arrived = r; + }); + let first = true; + const batches: Captured[] = []; + const server = Bun.serve({ + port: 0, + fetch: async (req) => { + batches.push((await req.json()) as Captured); + if (first) { + first = false; + arrived?.(); + await held; + } + return new Response(null, { status: 204 }); + }, + }); + stopHost = () => server.stop(true); + + await withShipper(`http://127.0.0.1:${server.port}`, async (shipper) => { + console.log("2026-08-03T10:11:12.345Z [x] first"); + const slow = shipper.flush(); + await received; + console.log("2026-08-03T10:11:12.345Z [x] shutdown line"); + release?.(); + // The shutdown flush: must not return until the tail is actually sent. + await shipper.flush(); + await slow; + }); + + const all = batches.flatMap((b) => b.entries.map((e) => e.msg)); + expect(all).toContain("shutdown line"); + }); + test("overlapping flushes do not double-send", async () => { // The timer can fire while a slow POST is still open. Two concurrent flushes would splice // disjoint batches out of one queue and deliver them out of order.