Skip to content

[feature] lazy fork for work that outlives the response #398

Description

@benhid

Problem or motivation

When server-side work outlives the request (the client disconnects mid-stream while the work that produced the stream keeps running), the wide event is already sealed on response close, so the trailing writes (final usage, persistence, billing) get dropped:

// response already closed (logger sealed)
log.set({ stream: { totalUsage } }); // dropped: "Keys dropped: stream"

evlog already points at fork for this: the bindNodeResponseLifecycle doc (Express/NestJS) recommends req.log.fork(label, fn) for work that outlives the response ("resumable streams, post-response usage accounting"). So the direction is sanctioned; the issue is just that plain fork is heavier than needed (see Alternatives).

Context: this is a follow-up to #305, after #336 resolved it by sealing the wide event on response close. That's right for the HTTP record; this is the other side of that thread.

Proposed feature

log.maybeFork(label, fn): the same shape as fork, but it defers the decision. You wrap the work; on a normal request it stays a single event, and only the part that spills past the seal gets forked off into a second event.

await log.maybeFork("generation", async () => {
  await streamToClient(res);
  await persistTailAndBill();
});

Normal request: one event, no extra cost. Disconnect: the parent still seals at response close with real status/duration (a faithful HTTP record), and a child event carries just the tail.

A thrown error is recorded on the child (with status) exactly like a fork child.

Possible implementation (optional)

Arm the logger so that, once sealed, further set/error/warn/info route into a lazily-created child instead of being dropped, then flush that child when the callback settles (a no-op if nothing spilled).

Sketch of what I'm running (cleaned up from a patch against the built 2.19.2 chunks). In createLogger, a lazily-created child plus the post-seal divert:

let capturingLate = false, lateLabel = "late", lateChild = null;

function lateTarget() {
  if (!lateChild) {
    lateChild = createRequestLogger(
      { method: context.method, path: context.path, requestId: crypto.randomUUID() },
      { _deferDrain: true },
    );
    lateChild.set({ operation: lateLabel, _parentRequestId: context.requestId });
  }
  return lateChild;
}

// in set() (and error/warn/info), the post-emit branch:
if (emitted) {
  if (capturingLate) { lateTarget().set(data); return; } // divert instead of dropping
  warnPostEmit("log.set()", /* …keys dropped… */);       // unchanged default otherwise
  return;
}

// methods on the logger:
captureLate(label) { capturingLate = true; if (label) lateLabel = label; },
[SYMBOL_TAKE]() { const c = lateChild; lateChild = null; return c; }, // private handoff

And in attachForkToLogger, the public maybeFork plus the flush:

log.maybeFork = async (label, fn) => {
  parent.captureLate(label);
  try {
    return await fn();
  } catch (err) {
    // mirror fork's error handling so a throw lands on the late child, with status
    const error = err instanceof Error ? err : new Error(String(err));
    parent.error(error);
    parent.set({ status: extractErrorStatus(error) });
    throw err;
  } finally {
    await log.emitLate();
  }
};

log.emitLate = () => {
  const child = parent[SYMBOL_TAKE]?.(); // the late child, if one was created
  if (!child) return;                    // nothing spilled → no-op
  const event = child.emit();
  const ctx = child.getContext();
  if (event && (middlewareOptions.enrich || middlewareOptions.drain || getGlobalDrain())) {
    return runEnrichAndDrain(event, middlewareOptions, ctx, event.status ?? ctx.status);
  }
};

Used like this from a request handler:

try {
  await log.maybeFork("generation", async () => {
    const result = streamText({ model, messages });
    await pipeToResponse(result, res);
    await persistResult(result);
    log.set({ usage: result.totalUsage });
  });
} catch (err) {
  await refundOrCleanup();
}

It reuses machinery that already exists: the late child is created and emitted exactly like a fork child (forkBackgroundLogger does the same via createRequestLogger + set/error/emit), and routing one logger's writes into another mirrors withAuditMethods letting audit() delegate to set(). The only new piece is routing the parent's post-seal writes into the child.

Alternatives you’ve considered (optional)

  • Plain fork (the documented recommendation): works, but always creates a second event even when the request finishes cleanly before the seal, and swaps the AsyncLocalStorage scope, so the trailing work has to run inside the callback.
  • Silencing the post-emit warning: rejected. For a normal handler a post-seal write is a genuine bug signal, so the behavior has to be opt-in per request, not global.
  • Deferring emit until the body finishes (the fix: defer wide-event emit for streaming AI responses #367 approach): doesn't fit the Node path (NestJS/Express seal on res.finish, which already waits for the body) and only defers to body-end, whereas the work here outlives the response.

Metadata

Metadata

Assignees

No one assigned

    Labels

    enhancementNew feature or request

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions