[Bug]: The server log never records why a /ws connection closed#24280

opened1d agobyOonly21mil

Before submitting

  • I searched existing issues and did not find a duplicate.
  • I included enough detail to reproduce or investigate the problem.

Area

apps/server

Steps to reproduce

The close code, with a simulated close that runs the same way every time:

  1. Check out main and run vp i.
  2. Save the script below as apps/server/close-code-repro.mjs. It imports the effect version the server ships (4.0.5).
  3. In apps/server, run node close-code-repro.mjs.
js
1// Simulates a peer closing an RPC websocket and checks whether anything outside Effect's
2// RPC server can see the close code. Save in apps/server and run `node close-code-repro.mjs`.
3// 4001 and its reason are arbitrary test values; no T3 client sends them.
4import * as Effect from "effect/Effect";
5import * as Exit from "effect/Exit";
6import * as Socket from "effect/socket/Socket";
7import * as HttpServerRequest from "effect/http/HttpServerRequest";
8import * as RpcServer from "effect/rpc/RpcServer";
9import * as RpcSerialization from "effect/rpc/RpcSerialization";
10
11// A socket whose first read fails the way a peer close does.
12const closingSocket = Socket.make({
13 reader: Effect.succeed({
14 pull: Effect.fail(
15 new Socket.SocketError({
16 reason: new Socket.SocketCloseError({ code: 4001, closeReason: "client heartbeat timeout" }),
17 }),
18 ),
19 upgrade: () => Effect.void,
20 }),
21 writer: Effect.succeed({ write: () => Effect.void, writeAll: () => Effect.void }),
22});
23
24// Wraps the reader to keep the close error before the RPC server catches it.
25const observed = {};
26const observe = (socket) =>
27 Socket.make({
28 reader: Effect.map(socket.reader, (reader) => ({
29 ...reader,
30 pull: reader.pull.pipe(
31 Effect.tapError((error) =>
32 Effect.sync(() => {
33 if (error.reason._tag === "SocketCloseError") {
34 observed.code = error.reason.code;
35 observed.reason = error.reason.closeReason;
36 }
37 }),
38 ),
39 ),
40 })),
41 writer: socket.writer,
42 });
43
44const run = (wrap) =>
45 Effect.gen(function* () {
46 const { httpEffect } = yield* RpcServer.makeProtocolWithHttpEffectWebsocket;
47 const request = { upgrade: Effect.succeed(wrap(closingSocket)), headers: {} };
48 return yield* httpEffect.pipe(
49 Effect.provideService(HttpServerRequest.HttpServerRequest, request),
50 Effect.exit,
51 );
52 }).pipe(Effect.scoped, Effect.provide(RpcSerialization.layerJson));
53
54const exitLabel = (exit) => (Exit.isSuccess(exit) ? "Success" : "Failure");
55
56// Unwrapped, as ws.ts on main hands the request to the RPC server.
57const plain = await Effect.runPromise(run((socket) => socket));
58console.log(`unwrapped socket: httpEffect exit = ${exitLabel(plain)} | observed = ${JSON.stringify(observed)}`);
59const wrapped = await Effect.runPromise(run(observe));
60console.log(`wrapped reader: httpEffect exit = ${exitLabel(wrapped)} | observed = ${JSON.stringify(observed)}`);

Expected behavior

  • When a /ws connection ends, the server logs one line that says how it ended: a close frame with its code and reason, a dropped connection (1006), a session invalidation or a server shutdown. The line also gives how long the connection lasted, how long before the close the last frame arrived, and which client session, surface and address it was.

Actual behavior

  • The unwrapped run matches how ws.ts on main hands the connection to Effect's RPC server. It ends httpEffect with Success even though the reader failed with a simulated 4001 close. The RPC server catches every SocketCloseError its socket reader raises (Effect.catchReason("SocketError", "SocketCloseError", ...) in effect/rpc/RpcServer). The caller cannot tell a close from a clean end, and the code and reason never leave the RPC server. The wrapped run shows they are on the reader for a wrapper to keep. On the way out, the /ws handler in ws.ts calls sessions.markDisconnected and logs nothing.
  • The trace does not have the close code either. No server code on main reads SocketCloseError, and in #10193 the server trace showed only RPC spans interrupted by ClientAbort. Finding out why the socket closed took Chrome remote debugging in the renderer.

Impact

Minor bug or occasional failure

Version or commit

main @ eeda2cb2cd

Environment

Linux (Fedora 44), Node 24.22.0, effect 4.0.5

Logs or stack traces

shell
1$ node close-code-repro.mjs
2unwrapped socket: httpEffect exit = Success | observed = {}
3wrapped reader: httpEffect exit = Success | observed = {"code":4001,"reason":"client heartbeat timeout"}

Screenshots, recordings, or supporting files

No response

Workaround

None on the server. For a close, the client side has to capture it, as in #10193.

I have a fix with focused tests: it wraps the socket reader to keep the close code and logs one close line per connection. I can open it as a PR linked here once this is triaged.

Written with Claude Opus 5.5 in T3 Code Nightly.