[Bug]: The server log never records why a /ws connection closed#24280
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:
- Check out
mainand runvp i. - Save the script below as
apps/server/close-code-repro.mjs. It imports theeffectversion the server ships (4.0.5). - In
apps/server, runnode 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. |
| 4 | import * as Effect from "effect/Effect"; |
| 5 | import * as Exit from "effect/Exit"; |
| 6 | import * as Socket from "effect/socket/Socket"; |
| 7 | import * as HttpServerRequest from "effect/http/HttpServerRequest"; |
| 8 | import * as RpcServer from "effect/rpc/RpcServer"; |
| 9 | import * as RpcSerialization from "effect/rpc/RpcSerialization"; |
| 10 | |
| 11 | // A socket whose first read fails the way a peer close does. |
| 12 | const 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. |
| 25 | const observed = {}; |
| 26 | const 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 | |
| 44 | const 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 | |
| 54 | const exitLabel = (exit) => (Exit.isSuccess(exit) ? "Success" : "Failure"); |
| 55 | |
| 56 | // Unwrapped, as ws.ts on main hands the request to the RPC server. |
| 57 | const plain = await Effect.runPromise(run((socket) => socket)); |
| 58 | console.log(`unwrapped socket: httpEffect exit = ${exitLabel(plain)} | observed = ${JSON.stringify(observed)}`); |
| 59 | const wrapped = await Effect.runPromise(run(observe)); |
| 60 | console.log(`wrapped reader: httpEffect exit = ${exitLabel(wrapped)} | observed = ${JSON.stringify(observed)}`); |
Expected behavior
- When a
/wsconnection 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.tsonmainhands the connection to Effect's RPC server. It endshttpEffectwith Success even though the reader failed with a simulated 4001 close. The RPC server catches everySocketCloseErrorits socket reader raises (Effect.catchReason("SocketError", "SocketCloseError", ...)ineffect/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/wshandler inws.tscallssessions.markDisconnectedand logs nothing. - The trace does not have the close code either. No server code on
mainreadsSocketCloseError, and in #10193 the server trace showed only RPC spans interrupted byClientAbort. 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 |
| 2 | unwrapped socket: httpEffect exit = Success | observed = {} |
| 3 | wrapped 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.