Skip to content

fix(socketio): clear the 5s emit timer on acknowledgement - #410

Open
RobertoReale wants to merge 1 commit into
overleaf-workshop:masterfrom
RobertoReale:fix/emit-timeout-timer-leak
Open

fix(socketio): clear the 5s emit timer on acknowledgement#410
RobertoReale wants to merge 1 commit into
overleaf-workshop:masterfrom
RobertoReale:fix/emit-timeout-timer-leak

Conversation

@RobertoReale

Copy link
Copy Markdown

Fixes #405

Problem

The promisified emit starts a 5 s timer per call and never clears it:

const timeoutPromise = new Promise((_, reject) => {
    setTimeout(() => { reject('timeout'); }, 5000);   // never cleared
});

When the acknowledgement arrives the race is already settled, so the late reject is a no-op and nothing is visible — but a timer stays pending for 5 s after every emit and still runs its callback. On a path that runs continuously while editing (joinDoc, applyOtUpdate, clientTracking.*) that is one live timer per call, and it makes the timeout impossible to instrument: adding any log to that callback reports a failure for every successful call, 5 s late. That is exactly what happened while I was debugging this extension — the console filled with 'applyOtUpdate' timed out after 5s for saves that had been acknowledged in ~150 ms and had already appeared on overleaf.com.

Two related points, both in the same few lines:

  • init() replaces this.socket when the handshake scheme changes (v1 → v2 on overleaf.com). A call emitted on the previous socket can never be acknowledged, so its timer always fires even though the call was abandoned by design; binding the call to the socket it was emitted on tells the two cases apart.
  • when the server rejects an emit, the raw payload is passed on and VS Code renders it as Unable to write file ... ([object Object]), hiding the actual message.

Change

  • clearTimeout in the acknowledgement callback;
  • capture socketAtEmit and emit on it, so a timeout on a socket that has since been replaced is not reported as a failure;
  • log a rejected emit through a small stringifyError helper (name/code/message, falling back to JSON), instead of letting [object Object] reach the user.

Verification

Against overleaf.com with 0.15.10 + this patch, tracing socket.io 0.9 packets: every emit that asks for an ack (5:<id>+::…) gets its ack ackId=<id> back, and no timeout is logged any more — before the fix the same session produced ~20 spurious timeout lines. The one call that legitimately never completes (the joinProject queued on the v1 socket that overleaf.com rejects) is now silent instead of printing an error.

Every promisified `emit` starts a 5s timer and never clears it. The race is
already settled when the acknowledgement arrives, so the late `reject` is a
no-op, but the timer stays pending for 5s after *every* call and still runs
its callback — which makes it impossible to report timeouts without also
reporting calls that succeeded.

Also:
- bind the call to the socket it was emitted on: `init()` replaces
  `this.socket` when the handshake scheme changes, and a call left on the old
  socket can never be acknowledged, so its timeout is expected and must not be
  logged as a failure;
- log rejected emits through `stringifyError`, so a server-side error object
  no longer reaches the user as `Unable to write file ... ([object Object])`.
@RobertoReale
RobertoReale force-pushed the fix/emit-timeout-timer-leak branch from 1743e99 to f8d4e63 Compare August 19, 2026 08:22
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Promisified emit never clears its 5s timeout timer (one leaked timer per emit)

1 participant