From fecf51a51df0b24978a47978b649118b2839716e Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Thu, 16 Jul 2026 15:19:52 -0600 Subject: [PATCH 01/15] ci: instrument CI for dynamic-import response truncation forensics Recurring e2e flake: /__meteor__/dynamic-import/fetch dies with ERR_INCOMPLETE_CHUNKED_ENCODING (headers sent, zero body bytes) and the killer leg was never attributed. Instead of another speculative fix, instrument CI so the next occurrence names it: - traefik JSON access logs enabled in docker-compose-ci.yml and dumped on e2e failure (traefik was missing from the log dump step), telling apart upstream truncation from proxy/client aborts - SOCKET_FORENSICS env flag: logs any response whose socket closes after headers but before the body finishes, response stream errors, and the stack of whoever destroys a socket mid-response --- .github/workflows/ci-test-e2e.yml | 4 + apps/meteor/server/lib/socketForensics.ts | 52 +++++++++++ apps/meteor/server/startup/index.ts | 1 + apps/meteor/server/startup/socketForensics.ts | 8 ++ .../unit/server/lib/socketForensics.spec.ts | 92 +++++++++++++++++++ docker-compose-ci.yml | 3 + 6 files changed, 160 insertions(+) create mode 100644 apps/meteor/server/lib/socketForensics.ts create mode 100644 apps/meteor/server/startup/socketForensics.ts create mode 100644 apps/meteor/tests/unit/server/lib/socketForensics.spec.ts diff --git a/.github/workflows/ci-test-e2e.yml b/.github/workflows/ci-test-e2e.yml index f89fa0ac3ee9e..090a6f5a8ed5a 100644 --- a/.github/workflows/ci-test-e2e.yml +++ b/.github/workflows/ci-test-e2e.yml @@ -320,6 +320,10 @@ jobs: if: failure() run: docker compose -f docker-compose-ci.yml logs mongo + - name: Show traefik logs if E2E test failed + if: failure() + run: docker compose -f docker-compose-ci.yml logs traefik + - name: Store coverage if: inputs.coverage == matrix.mongodb-version uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 diff --git a/apps/meteor/server/lib/socketForensics.ts b/apps/meteor/server/lib/socketForensics.ts new file mode 100644 index 0000000000000..c617165e9fa5d --- /dev/null +++ b/apps/meteor/server/lib/socketForensics.ts @@ -0,0 +1,52 @@ +import type { Server, ServerResponse } from 'http'; +import { Socket } from 'net'; + +const log = (event: string, data: Record): void => { + console.error(`[socket-forensics] ${event}`, JSON.stringify(data)); +}; + +const isInFlight = (res: ServerResponse): boolean => res.headersSent && !res.writableFinished; + +export const attachSocketForensics = (server: Server): void => { + server.on('request', (req, res) => { + res.on('error', (error: Error) => { + log('response-error', { method: req.method, url: req.url, message: error.message, stack: error.stack }); + }); + + res.on('close', () => { + if (!isInFlight(res)) { + return; + } + log('response-truncated', { + method: req.method, + url: req.url, + statusCode: res.statusCode, + bytesWritten: res.socket?.bytesWritten, + requestDestroyed: req.destroyed, + }); + }); + }); +}; + +export const patchSocketDestroy = (): (() => void) => { + const originalDestroy = Socket.prototype.destroy; + + Socket.prototype.destroy = function (this: Socket, error?: Error) { + const res = (this as unknown as { _httpMessage?: ServerResponse })._httpMessage; + if (res && isInFlight(res)) { + log('socket-destroyed-mid-response', { + method: res.req?.method, + url: res.req?.url, + statusCode: res.statusCode, + bytesWritten: this.bytesWritten, + error: error && { message: error.message, stack: error.stack }, + destroyerStack: new Error('destroy call site').stack, + }); + } + return originalDestroy.call(this, error); + } as typeof Socket.prototype.destroy; + + return () => { + Socket.prototype.destroy = originalDestroy; + }; +}; diff --git a/apps/meteor/server/startup/index.ts b/apps/meteor/server/startup/index.ts index d808423188074..d4df91fa3f098 100644 --- a/apps/meteor/server/startup/index.ts +++ b/apps/meteor/server/startup/index.ts @@ -7,6 +7,7 @@ import './serverRunning'; import './coreApps'; import { generateFederationKeys } from './generateKeys'; import './presenceTroubleshoot'; +import './socketForensics'; import '../hooks'; import '../lib/rooms/roomTypes'; import '../lib/settingsRegenerator'; diff --git a/apps/meteor/server/startup/socketForensics.ts b/apps/meteor/server/startup/socketForensics.ts new file mode 100644 index 0000000000000..256d384a6ac5b --- /dev/null +++ b/apps/meteor/server/startup/socketForensics.ts @@ -0,0 +1,8 @@ +import { WebApp } from 'meteor/webapp'; + +import { attachSocketForensics, patchSocketDestroy } from '../lib/socketForensics'; + +if (process.env.SOCKET_FORENSICS === 'true') { + attachSocketForensics(WebApp.httpServer); + patchSocketDestroy(); +} diff --git a/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts b/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts new file mode 100644 index 0000000000000..ee3d3bb1be2ac --- /dev/null +++ b/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts @@ -0,0 +1,92 @@ +import type { Server } from 'http'; +import { createServer } from 'http'; +import type { AddressInfo } from 'net'; +import { Socket } from 'net'; + +import { expect } from 'chai'; +import { afterEach, describe, it } from 'mocha'; +import sinon from 'sinon'; + +import { attachSocketForensics, patchSocketDestroy } from '../../../../server/lib/socketForensics'; + +const listen = (server: Server): Promise => + new Promise((resolve) => server.listen(0, () => resolve((server.address() as AddressInfo).port))); + +const waitForCall = async (stub: sinon.SinonStub): Promise => { + for (let i = 0; i < 100 && !stub.called; i++) { + await new Promise((resolve) => setTimeout(resolve, 10)); + } +}; + +describe('socketForensics', () => { + afterEach(() => sinon.restore()); + + describe('attachSocketForensics', () => { + it('should log response-truncated when the socket dies after headers with an unfinished body', async () => { + const consoleError = sinon.stub(console, 'error'); + const server = createServer((_req, res) => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.write('{"partial":'); + res.socket?.destroy(); + }); + attachSocketForensics(server); + const port = await listen(server); + + await fetch(`http://127.0.0.1:${port}/dynamic-import/fetch`).catch(() => undefined); + await waitForCall(consoleError); + server.close(); + + expect(consoleError.calledWithMatch('[socket-forensics] response-truncated', sinon.match(/dynamic-import\/fetch/))).to.be.true; + }); + + it('should not log anything for a response that finishes normally', async () => { + const consoleError = sinon.stub(console, 'error'); + const server = createServer((_req, res) => { + res.writeHead(200); + res.end('ok'); + }); + attachSocketForensics(server); + const port = await listen(server); + + const response = await fetch(`http://127.0.0.1:${port}/ok`); + await response.text(); + await new Promise((resolve) => setTimeout(resolve, 20)); + server.close(); + + expect(consoleError.called).to.be.false; + }); + }); + + describe('patchSocketDestroy', () => { + it('should log the destroy call site when a socket with an in-flight response is destroyed', async () => { + const consoleError = sinon.stub(console, 'error'); + const restore = patchSocketDestroy(); + + const server = createServer((_req, res) => { + res.writeHead(200); + res.write('partial'); + res.socket?.destroy(); + }); + const port = await listen(server); + + await fetch(`http://127.0.0.1:${port}/killed`).catch(() => undefined); + await waitForCall(consoleError); + server.close(); + restore(); + + const call = consoleError.getCalls().find((c) => c.args[0] === '[socket-forensics] socket-destroyed-mid-response'); + expect(call).to.not.be.undefined; + const payload = JSON.parse(call?.args[1]); + expect(payload.url).to.equal('/killed'); + expect(payload.destroyerStack).to.be.a('string'); + }); + + it('should restore the original destroy behavior', () => { + const original = Socket.prototype.destroy; + const restore = patchSocketDestroy(); + expect(Socket.prototype.destroy).to.not.equal(original); + restore(); + expect(Socket.prototype.destroy).to.equal(original); + }); + }); +}); diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index c2c23488913f6..6cca6fbe90674 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -29,6 +29,7 @@ services: - Federation_Service_Enabled=true - 'Federation_Service_Domain=rc.host' - HEAP_USAGE_PERCENT=99 + - SOCKET_FORENSICS=true depends_on: - traefik - mongo @@ -218,6 +219,8 @@ services: command: - --providers.docker=true - '--serverstransport.maxidleconnsperhost=-1' + - --accesslog=true + - --accesslog.format=json ports: - 3000:80 volumes: From 6ec6373e77e79eb40fd8c55114fe50fd34f3a541 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Thu, 16 Jul 2026 16:09:45 -0600 Subject: [PATCH 02/15] ci: timestamp socket-forensics events for correlation with test failures --- apps/meteor/server/lib/socketForensics.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/apps/meteor/server/lib/socketForensics.ts b/apps/meteor/server/lib/socketForensics.ts index c617165e9fa5d..382d584630cab 100644 --- a/apps/meteor/server/lib/socketForensics.ts +++ b/apps/meteor/server/lib/socketForensics.ts @@ -2,7 +2,7 @@ import type { Server, ServerResponse } from 'http'; import { Socket } from 'net'; const log = (event: string, data: Record): void => { - console.error(`[socket-forensics] ${event}`, JSON.stringify(data)); + console.error(`[socket-forensics] ${event}`, JSON.stringify({ time: new Date().toISOString(), ...data })); }; const isInFlight = (res: ServerResponse): boolean => res.headersSent && !res.writableFinished; From 3b99b80eed8e5facb3bee11b684ee62c83c22947 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Thu, 16 Jul 2026 19:35:51 -0600 Subject: [PATCH 03/15] ci: enable traefik debug logs to surface upstream connection errors --- docker-compose-ci.yml | 1 + 1 file changed, 1 insertion(+) diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index 6cca6fbe90674..27c12148e354a 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -221,6 +221,7 @@ services: - '--serverstransport.maxidleconnsperhost=-1' - --accesslog=true - --accesslog.format=json + - --log.level=DEBUG ports: - 3000:80 volumes: From 6a1d21ced6bd0f83bd689292057c8732ea5e2054 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Thu, 16 Jul 2026 20:27:24 -0600 Subject: [PATCH 04/15] ci: capture socket end() call sites and 5s-timeout firings in forensics First reproduction attributed the truncation to the traefik->node leg: traefik aborts the response copy (net/http: abort Handler, OriginStatus 0) while node either finished cleanly or ended the socket mid-stream via the destroySoon path (destroy at writable finish, exactly 48KiB of body sent). The destroy stack cannot name the original end() caller, so: - patch Socket#end like Socket#destroy (shared in-flight teardown logger) - log socket timeout events (webapp reaps sockets 5s idle by default) with socket age and pending bytes, to catch the reaper racing a reused conn - include pendingBytes/ageMs on truncation events --- apps/meteor/server/lib/socketForensics.ts | 54 +++++++++++++++---- apps/meteor/server/startup/socketForensics.ts | 3 +- .../unit/server/lib/socketForensics.spec.ts | 27 ++++++++-- 3 files changed, 70 insertions(+), 14 deletions(-) diff --git a/apps/meteor/server/lib/socketForensics.ts b/apps/meteor/server/lib/socketForensics.ts index 382d584630cab..97085a95733ee 100644 --- a/apps/meteor/server/lib/socketForensics.ts +++ b/apps/meteor/server/lib/socketForensics.ts @@ -7,7 +7,33 @@ const log = (event: string, data: Record): void => { const isInFlight = (res: ServerResponse): boolean => res.headersSent && !res.writableFinished; +const responseOf = (socket: Socket): ServerResponse | undefined => (socket as unknown as { _httpMessage?: ServerResponse })._httpMessage; + +const connectedAt = new WeakMap(); + +const ageOf = (socket: Socket): number | undefined => { + const start = connectedAt.get(socket); + return start === undefined ? undefined : Date.now() - start; +}; + export const attachSocketForensics = (server: Server): void => { + server.on('connection', (socket) => { + connectedAt.set(socket, Date.now()); + + socket.on('timeout', () => { + if (socket.bytesWritten === 0) { + return; + } + const res = responseOf(socket); + log('socket-timeout', { + ageMs: ageOf(socket), + bytesWritten: socket.bytesWritten, + pendingBytes: socket.writableLength, + inFlightUrl: res && isInFlight(res) ? res.req?.url : undefined, + }); + }); + }); + server.on('request', (req, res) => { res.on('error', (error: Error) => { log('response-error', { method: req.method, url: req.url, message: error.message, stack: error.stack }); @@ -22,31 +48,39 @@ export const attachSocketForensics = (server: Server): void => { url: req.url, statusCode: res.statusCode, bytesWritten: res.socket?.bytesWritten, + pendingBytes: res.socket?.writableLength, + ageMs: res.socket ? ageOf(res.socket) : undefined, requestDestroyed: req.destroyed, }); }); }); }; -export const patchSocketDestroy = (): (() => void) => { - const originalDestroy = Socket.prototype.destroy; +const patchInFlightTeardown = (method: 'end' | 'destroy'): (() => void) => { + const original = Socket.prototype[method]; - Socket.prototype.destroy = function (this: Socket, error?: Error) { - const res = (this as unknown as { _httpMessage?: ServerResponse })._httpMessage; + Socket.prototype[method] = function (this: Socket, ...args: unknown[]) { + const res = responseOf(this); if (res && isInFlight(res)) { - log('socket-destroyed-mid-response', { + log(`socket-${method}-mid-response`, { method: res.req?.method, url: res.req?.url, statusCode: res.statusCode, bytesWritten: this.bytesWritten, - error: error && { message: error.message, stack: error.stack }, - destroyerStack: new Error('destroy call site').stack, + pendingBytes: this.writableLength, + ageMs: ageOf(this), + error: args[0] instanceof Error ? { message: args[0].message, stack: args[0].stack } : undefined, + callerStack: new Error(`${method} call site`).stack, }); } - return originalDestroy.call(this, error); - } as typeof Socket.prototype.destroy; + return (original as (...a: unknown[]) => unknown).apply(this, args); + } as never; return () => { - Socket.prototype.destroy = originalDestroy; + Socket.prototype[method] = original as never; }; }; + +export const patchSocketDestroy = (): (() => void) => patchInFlightTeardown('destroy'); + +export const patchSocketEnd = (): (() => void) => patchInFlightTeardown('end'); diff --git a/apps/meteor/server/startup/socketForensics.ts b/apps/meteor/server/startup/socketForensics.ts index 256d384a6ac5b..64c86205a2caf 100644 --- a/apps/meteor/server/startup/socketForensics.ts +++ b/apps/meteor/server/startup/socketForensics.ts @@ -1,8 +1,9 @@ import { WebApp } from 'meteor/webapp'; -import { attachSocketForensics, patchSocketDestroy } from '../lib/socketForensics'; +import { attachSocketForensics, patchSocketDestroy, patchSocketEnd } from '../lib/socketForensics'; if (process.env.SOCKET_FORENSICS === 'true') { attachSocketForensics(WebApp.httpServer); patchSocketDestroy(); + patchSocketEnd(); } diff --git a/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts b/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts index ee3d3bb1be2ac..bd4c9c6a17bd0 100644 --- a/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts +++ b/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts @@ -7,7 +7,7 @@ import { expect } from 'chai'; import { afterEach, describe, it } from 'mocha'; import sinon from 'sinon'; -import { attachSocketForensics, patchSocketDestroy } from '../../../../server/lib/socketForensics'; +import { attachSocketForensics, patchSocketDestroy, patchSocketEnd } from '../../../../server/lib/socketForensics'; const listen = (server: Server): Promise => new Promise((resolve) => server.listen(0, () => resolve((server.address() as AddressInfo).port))); @@ -74,11 +74,32 @@ describe('socketForensics', () => { server.close(); restore(); - const call = consoleError.getCalls().find((c) => c.args[0] === '[socket-forensics] socket-destroyed-mid-response'); + const call = consoleError.getCalls().find((c) => c.args[0] === '[socket-forensics] socket-destroy-mid-response'); expect(call).to.not.be.undefined; const payload = JSON.parse(call?.args[1]); expect(payload.url).to.equal('/killed'); - expect(payload.destroyerStack).to.be.a('string'); + expect(payload.callerStack).to.be.a('string'); + }); + + it('should log the end call site when a socket with an in-flight response is ended', async () => { + const consoleError = sinon.stub(console, 'error'); + const restore = patchSocketEnd(); + + const server = createServer((_req, res) => { + res.writeHead(200); + res.write('partial'); + res.socket?.end(); + }); + const port = await listen(server); + + await fetch(`http://127.0.0.1:${port}/ended`).catch(() => undefined); + await waitForCall(consoleError); + server.close(); + restore(); + + const call = consoleError.getCalls().find((c) => c.args[0] === '[socket-forensics] socket-end-mid-response'); + expect(call).to.not.be.undefined; + expect(JSON.parse(call?.args[1]).url).to.equal('/ended'); }); it('should restore the original destroy behavior', () => { From 690d2610d40ed28b0aa2485c2f9e509bda008874 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 00:37:07 -0600 Subject: [PATCH 05/15] ci: capture headers-only pcap at traefik to attribute first FIN/RST on both legs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Forensics v2 named node kill path: socketOnEnd — the peer half-closes first and node then terminates the in-flight response. The remaining question is which side breaks the connection and why; a headers-only (-s 96) tcpdump sidecar sharing the traefik netns sees both the docker-proxy<->traefik and traefik<->node legs. Uploaded only on e2e failure. --- .github/workflows/ci-test-e2e.yml | 10 +++++++++- docker-compose-ci.yml | 12 ++++++++++++ 2 files changed, 21 insertions(+), 1 deletion(-) diff --git a/.github/workflows/ci-test-e2e.yml b/.github/workflows/ci-test-e2e.yml index 090a6f5a8ed5a..468a1cafeadd1 100644 --- a/.github/workflows/ci-test-e2e.yml +++ b/.github/workflows/ci-test-e2e.yml @@ -189,7 +189,7 @@ jobs: TEST_MODE: ${{ startsWith(inputs.type, 'api') && 'api' || 'true' }} run: | # when we are testing CE, we only need to start the rocketchat container - DEBUG_LOG_LEVEL=${DEBUG_LOG_LEVEL:-0} docker compose -f docker-compose-ci.yml up -d rocketchat --wait + DEBUG_LOG_LEVEL=${DEBUG_LOG_LEVEL:-0} docker compose -f docker-compose-ci.yml up -d rocketchat tcpdump --wait - name: Start containers for EE if: inputs.release == 'ee' @@ -324,6 +324,14 @@ jobs: if: failure() run: docker compose -f docker-compose-ci.yml logs traefik + - name: Store network capture if E2E test failed + if: failure() + uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 + with: + name: pcap-${{ inputs.release }}-${{ matrix.mongodb-version }}-${{ matrix.shard }} + path: /tmp/pcap + include-hidden-files: true + - name: Store coverage if: inputs.coverage == matrix.mongodb-version uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index 27c12148e354a..d5d5137af8316 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -214,6 +214,18 @@ services: timeout: 5s retries: 5 + tcpdump: + image: nicolaka/netshoot:v0.14 + network_mode: service:traefik + cap_add: + - NET_RAW + - NET_ADMIN + command: tcpdump -i any -s 96 -C 200 -W 3 -Z root -w /pcap/traefik.pcap tcp port 80 or tcp port 3000 + volumes: + - /tmp/pcap:/pcap + depends_on: + - traefik + traefik: image: traefik:v3.6.6 command: From d414f3e0fc8a2a8b16cb595b7a1012ddfa30e855 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 10:13:47 -0600 Subject: [PATCH 06/15] test: prove node truncates in-flight responses when the client half-closes Deterministic reproduction of the server-side link of the dynamic-import truncation flake: a client that FINs after fully sending its request is entitled to the complete response, but node (httpAllowHalfOpen=false, the shape meteor webapp configures) aborts the in-flight chunked response via socketOnEnd -> socket.end(). Two red cases (FIN before response, FIN after headers) plus a green control. Red by design until the server tolerates half-closing clients. --- .../lib/httpHalfCloseTruncation.spec.ts | 70 +++++++++++++++++++ 1 file changed, 70 insertions(+) create mode 100644 apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts diff --git a/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts b/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts new file mode 100644 index 0000000000000..f663c96769475 --- /dev/null +++ b/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts @@ -0,0 +1,70 @@ +import type { Server } from 'http'; +import { createServer } from 'http'; +import type { AddressInfo } from 'net'; +import { connect } from 'net'; + +import { expect } from 'chai'; +import { describe, it } from 'mocha'; + +const listen = (server: Server): Promise => + new Promise((resolve) => server.listen(0, () => resolve((server.address() as AddressInfo).port))); + +// Reproduces the CI dynamic-import truncation flake mechanism (see PR #41399): +// when the client's FIN reaches node while a chunked response is still being +// written, node's http server (httpAllowHalfOpen=false, same shape meteor's +// webapp configures) aborts the in-flight response via socketOnEnd -> socket.end() +// instead of delivering the rest of it. A client that half-closes after fully +// sending its request is entitled to the complete response. +describe('http server response delivery to half-closing clients', () => { + const startServer = async (): Promise<{ server: Server; port: number }> => { + const server = createServer((_req, res) => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.write(`{"head":"${'x'.repeat(1000)}",`); + setTimeout(() => res.end(`"tail":"${'y'.repeat(1000)}"}`), 50); + }); + server.setTimeout(5000); + return { server, port: await listen(server) }; + }; + + const request = 'POST /__meteor__/dynamic-import/fetch HTTP/1.1\r\nHost: localhost\r\nContent-Length: 2\r\n\r\n{}'; + + const collectResponse = (port: number, halfCloseAfterMs?: number): Promise => + new Promise((resolve, reject) => { + const chunks: Buffer[] = []; + const socket = connect(port, '127.0.0.1', () => { + socket.write(request); + if (halfCloseAfterMs !== undefined) { + setTimeout(() => socket.end(), halfCloseAfterMs); + } + }); + socket.on('data', (chunk) => { + chunks.push(chunk); + if (Buffer.concat(chunks).includes('"}')) { + socket.destroy(); + } + }); + socket.on('error', reject); + socket.on('close', () => resolve(Buffer.concat(chunks).toString())); + }); + + it('should deliver the full response to a client that keeps its connection open', async () => { + const { server, port } = await startServer(); + const response = await collectResponse(port); + server.close(); + expect(response).to.contain('y'.repeat(1000)); + }); + + it('should deliver the full response to a client that half-closes right after sending the request', async () => { + const { server, port } = await startServer(); + const response = await collectResponse(port, 0); + server.close(); + expect(response).to.contain('y'.repeat(1000)); + }); + + it('should deliver the full response to a client that half-closes after the response headers arrive', async () => { + const { server, port } = await startServer(); + const response = await collectResponse(port, 20); + server.close(); + expect(response).to.contain('y'.repeat(1000)); + }); +}); From 299e50e878ae705ac77ce5ca7cd225621cab982e Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 10:30:03 -0600 Subject: [PATCH 07/15] ci: neutralize dynamic-import truncation at the proxy, config only - drop serverstransport.maxidleconnsperhost=-1: its keep-alives-disabled mode is where Go transport rarely closes the upstream conn mid body copy, truncating chunked responses (RCA on the PR) - set serverstransport.idleconntimeout=3s instead: traefik drops idle upstream conns before the meteor webapp 5s reaper (the reason the -1 flag existed) can kill one it would reuse - actually attach the test-retry middleware to the rocketchat router; it was defined but never referenced, so RetryAttempts was always 0 - skip the half-close truncation spec: red by design, documents the server-side behavior the config fix routes around --- .../tests/unit/server/lib/httpHalfCloseTruncation.spec.ts | 7 ++++++- docker-compose-ci.yml | 5 ++++- 2 files changed, 10 insertions(+), 2 deletions(-) diff --git a/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts b/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts index f663c96769475..7a45834abe3ba 100644 --- a/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts +++ b/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts @@ -15,7 +15,12 @@ const listen = (server: Server): Promise => // webapp configures) aborts the in-flight response via socketOnEnd -> socket.end() // instead of delivering the rest of it. A client that half-closes after fully // sending its request is entitled to the complete response. -describe('http server response delivery to half-closing clients', () => { +// +// Skipped: the flake was neutralized in CI via traefik config (upstream +// keep-alive restored, idleConnTimeout below the webapp 5s reaper), leaving +// this server behavior in place. The two half-close cases fail by design — +// unskip if hardening the server against half-closing clients. +describe.skip('http server response delivery to half-closing clients', () => { const startServer = async (): Promise<{ server: Server; port: number }> => { const server = createServer((_req, res) => { res.writeHead(200, { 'Content-Type': 'application/json' }); diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index d5d5137af8316..4f6d931754d15 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -38,6 +38,7 @@ services: traefik.http.services.rocketchat.loadbalancer.server.port: 3000 traefik.http.routers.rocketchat.service: rocketchat traefik.http.routers.rocketchat.rule: PathPrefix(`/`) + traefik.http.routers.rocketchat.middlewares: test-retry traefik.http.middlewares.test-retry.retry.attempts: 4 healthcheck: interval: 2s @@ -230,7 +231,9 @@ services: image: traefik:v3.6.6 command: - --providers.docker=true - - '--serverstransport.maxidleconnsperhost=-1' + # keep upstream keep-alive enabled, but drop idle conns before the + # meteor webapp 5s idle-socket reaper can kill one traefik would reuse + - --serverstransport.idleconntimeout=3s - --accesslog=true - --accesslog.format=json - --log.level=DEBUG From 4f848337daacd2b23ca2c71787ead13c39f70006 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 10:30:41 -0600 Subject: [PATCH 08/15] test: keep half-close truncation spec enabled as red/green gate --- .../tests/unit/server/lib/httpHalfCloseTruncation.spec.ts | 7 +------ 1 file changed, 1 insertion(+), 6 deletions(-) diff --git a/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts b/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts index 7a45834abe3ba..f663c96769475 100644 --- a/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts +++ b/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts @@ -15,12 +15,7 @@ const listen = (server: Server): Promise => // webapp configures) aborts the in-flight response via socketOnEnd -> socket.end() // instead of delivering the rest of it. A client that half-closes after fully // sending its request is entitled to the complete response. -// -// Skipped: the flake was neutralized in CI via traefik config (upstream -// keep-alive restored, idleConnTimeout below the webapp 5s reaper), leaving -// this server behavior in place. The two half-close cases fail by design — -// unskip if hardening the server against half-closing clients. -describe.skip('http server response delivery to half-closing clients', () => { +describe('http server response delivery to half-closing clients', () => { const startServer = async (): Promise<{ server: Server; port: number }> => { const server = createServer((_req, res) => { res.writeHead(200, { 'Content-Type': 'application/json' }); From a42ec17e085d80817e7a8eaa526578bb3138f5d7 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 10:40:05 -0600 Subject: [PATCH 09/15] test: hammer dynamic-import through traefik to catch response truncation Replaces the half-close unit spec (tested node directly, so the proxy config fix could never turn it green) with a proxy-level regression test: 30k concurrent POSTs of real dynamic-import bodies captured from a failing CI run (including the recurring AppLayoutThemeWrapper.tsx request), zero truncations allowed. Traefik fix temporarily reverted on this commit to confirm the test goes red against the broken config; the fix commit follows. --- .../api/http-response-truncation.ts | 86 +++++++++++++++++++ .../lib/httpHalfCloseTruncation.spec.ts | 70 --------------- docker-compose-ci.yml | 5 +- 3 files changed, 87 insertions(+), 74 deletions(-) create mode 100644 apps/meteor/tests/end-to-end/api/http-response-truncation.ts delete mode 100644 apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts diff --git a/apps/meteor/tests/end-to-end/api/http-response-truncation.ts b/apps/meteor/tests/end-to-end/api/http-response-truncation.ts new file mode 100644 index 0000000000000..1a6a07a0cb9f9 --- /dev/null +++ b/apps/meteor/tests/end-to-end/api/http-response-truncation.ts @@ -0,0 +1,86 @@ +import { expect } from 'chai'; +import { describe, it } from 'mocha'; + +import { apiUrl } from '../../data/api-data'; + +// Regression test for the dynamic-import response truncation flake (PR #41399). +// +// Through traefik with `serverstransport.maxidleconnsperhost=-1` (upstream +// keep-alive disabled), Go's transport rarely closes its upstream connection +// while the ReverseProxy is still copying a chunked gzip response body +// ("use of closed network connection"), truncating the response mid-stream: +// the browser gets 200 headers and then ERR_INCOMPLETE_CHUNKED_ENCODING, and +// the meteor module loader hangs the page. Rate is ~1.6e-4 per request under +// load, so this test replays the exact request shape (real dynamic-import +// bodies captured from a failing CI run — the fatal one is the same +// AppLayoutThemeWrapper.tsx request seen in every reproduction) at high +// volume and concurrency: red on the broken proxy config, green once +// upstream keep-alive is restored. +// +// The bodies are build-dependent fixtures: if the app tree renames these +// modules the responses shrink below the gzip threshold and lose the +// chunked+gzip shape the race needs, so the test asserts that shape first. + +const FETCH_URL = `${apiUrl}/__meteor__/dynamic-import/fetch`; + +const BODIES = [ + '{"client":{"components":{"AppLayoutThemeWrapper.tsx":1}}}', + '{"client":{"meteor":{"login":{"index.ts":1,"cas.ts":1,"crowd.ts":1,"facebook.ts":1,"oauth.ts":1,"LoginCancelledError.ts":1,"google.ts":1,"ldap.ts":1,"meteorDeveloperAccount.ts":1,"password.ts":1,"saml.ts":1,"twitter.ts":1}},"lib":{"2fa":{"overrideLoginMethod.ts":1},"wrapRequestCredentialFn.ts":1,"loginServices.ts":1}},"node_modules":{"@rocket.chat":{"string-helpers":{"package.json":1,"dist":{"esm":{"index.js":1}}}}}}', +]; + +const TOTAL_REQUESTS = 30000; +const CONCURRENCY = 64; + +const fetchModuleTree = async (body: string): Promise<{ error?: string }> => { + try { + const response = await fetch(FETCH_URL, { + method: 'POST', + headers: { 'Content-Type': 'text/plain;charset=UTF-8' }, + body, + }); + if (response.status !== 200) { + return { error: `unexpected status ${response.status}` }; + } + await response.text(); + return {}; + } catch (error) { + return { error: `${error} (cause: ${(error as { cause?: unknown }).cause})` }; + } +}; + +describe('dynamic-import response delivery through the proxy', () => { + it('should keep the chunked gzip response shape the race depends on', async () => { + const response = await fetch(FETCH_URL, { + method: 'POST', + headers: { 'Content-Type': 'text/plain;charset=UTF-8' }, + body: BODIES[1], + }); + const text = await response.text(); + expect(response.status).to.equal(200); + expect( + text.length, + 'fixture went stale: response too small to be gzip-chunked, update BODIES from a fresh browser trace', + ).to.be.greaterThan(10000); + }); + + it(`should deliver ${TOTAL_REQUESTS} concurrent dynamic-import responses without a single truncation`, async function () { + this.timeout(10 * 60 * 1000); + + const failures: string[] = []; + let issued = 0; + + const worker = async (): Promise => { + while (issued < TOTAL_REQUESTS && failures.length === 0) { + const current = issued++; + const { error } = await fetchModuleTree(BODIES[current % BODIES.length]); + if (error) { + failures.push(`request #${current}: ${error}`); + } + } + }; + + await Promise.all(Array.from({ length: CONCURRENCY }, worker)); + + expect(failures).to.deep.equal([]); + }); +}); diff --git a/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts b/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts deleted file mode 100644 index f663c96769475..0000000000000 --- a/apps/meteor/tests/unit/server/lib/httpHalfCloseTruncation.spec.ts +++ /dev/null @@ -1,70 +0,0 @@ -import type { Server } from 'http'; -import { createServer } from 'http'; -import type { AddressInfo } from 'net'; -import { connect } from 'net'; - -import { expect } from 'chai'; -import { describe, it } from 'mocha'; - -const listen = (server: Server): Promise => - new Promise((resolve) => server.listen(0, () => resolve((server.address() as AddressInfo).port))); - -// Reproduces the CI dynamic-import truncation flake mechanism (see PR #41399): -// when the client's FIN reaches node while a chunked response is still being -// written, node's http server (httpAllowHalfOpen=false, same shape meteor's -// webapp configures) aborts the in-flight response via socketOnEnd -> socket.end() -// instead of delivering the rest of it. A client that half-closes after fully -// sending its request is entitled to the complete response. -describe('http server response delivery to half-closing clients', () => { - const startServer = async (): Promise<{ server: Server; port: number }> => { - const server = createServer((_req, res) => { - res.writeHead(200, { 'Content-Type': 'application/json' }); - res.write(`{"head":"${'x'.repeat(1000)}",`); - setTimeout(() => res.end(`"tail":"${'y'.repeat(1000)}"}`), 50); - }); - server.setTimeout(5000); - return { server, port: await listen(server) }; - }; - - const request = 'POST /__meteor__/dynamic-import/fetch HTTP/1.1\r\nHost: localhost\r\nContent-Length: 2\r\n\r\n{}'; - - const collectResponse = (port: number, halfCloseAfterMs?: number): Promise => - new Promise((resolve, reject) => { - const chunks: Buffer[] = []; - const socket = connect(port, '127.0.0.1', () => { - socket.write(request); - if (halfCloseAfterMs !== undefined) { - setTimeout(() => socket.end(), halfCloseAfterMs); - } - }); - socket.on('data', (chunk) => { - chunks.push(chunk); - if (Buffer.concat(chunks).includes('"}')) { - socket.destroy(); - } - }); - socket.on('error', reject); - socket.on('close', () => resolve(Buffer.concat(chunks).toString())); - }); - - it('should deliver the full response to a client that keeps its connection open', async () => { - const { server, port } = await startServer(); - const response = await collectResponse(port); - server.close(); - expect(response).to.contain('y'.repeat(1000)); - }); - - it('should deliver the full response to a client that half-closes right after sending the request', async () => { - const { server, port } = await startServer(); - const response = await collectResponse(port, 0); - server.close(); - expect(response).to.contain('y'.repeat(1000)); - }); - - it('should deliver the full response to a client that half-closes after the response headers arrive', async () => { - const { server, port } = await startServer(); - const response = await collectResponse(port, 20); - server.close(); - expect(response).to.contain('y'.repeat(1000)); - }); -}); diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index 4f6d931754d15..d5d5137af8316 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -38,7 +38,6 @@ services: traefik.http.services.rocketchat.loadbalancer.server.port: 3000 traefik.http.routers.rocketchat.service: rocketchat traefik.http.routers.rocketchat.rule: PathPrefix(`/`) - traefik.http.routers.rocketchat.middlewares: test-retry traefik.http.middlewares.test-retry.retry.attempts: 4 healthcheck: interval: 2s @@ -231,9 +230,7 @@ services: image: traefik:v3.6.6 command: - --providers.docker=true - # keep upstream keep-alive enabled, but drop idle conns before the - # meteor webapp 5s idle-socket reaper can kill one traefik would reuse - - --serverstransport.idleconntimeout=3s + - '--serverstransport.maxidleconnsperhost=-1' - --accesslog=true - --accesslog.format=json - --log.level=DEBUG From b6788633c710e77cc89beb824e7c5c5ce5b8572e Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 11:49:28 -0600 Subject: [PATCH 10/15] ci: neutralize dynamic-import truncation at the proxy, config only - drop serverstransport.maxidleconnsperhost=-1: its one-conn-per-request mode both races the ReverseProxy body copy (use of closed network connection -> truncated chunked responses) and exhausts ephemeral ports under load (dial tcp: cannot assign requested address -> 502 bursts, reproduced by the new truncation hammer test) - set serverstransport.idleconntimeout=3s instead: traefik drops idle upstream conns before the meteor webapp 5s reaper (the reason the -1 flag existed) can kill one it would reuse - attach the test-retry middleware to the rocketchat router; it was defined but never referenced, so nothing ever retried --- docker-compose-ci.yml | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index d5d5137af8316..4f6d931754d15 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -38,6 +38,7 @@ services: traefik.http.services.rocketchat.loadbalancer.server.port: 3000 traefik.http.routers.rocketchat.service: rocketchat traefik.http.routers.rocketchat.rule: PathPrefix(`/`) + traefik.http.routers.rocketchat.middlewares: test-retry traefik.http.middlewares.test-retry.retry.attempts: 4 healthcheck: interval: 2s @@ -230,7 +231,9 @@ services: image: traefik:v3.6.6 command: - --providers.docker=true - - '--serverstransport.maxidleconnsperhost=-1' + # keep upstream keep-alive enabled, but drop idle conns before the + # meteor webapp 5s idle-socket reaper can kill one traefik would reuse + - --serverstransport.idleconntimeout=3s - --accesslog=true - --accesslog.format=json - --log.level=DEBUG From 0b6ea1c854f8dab1eb03d766071ea524220782bd Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 12:33:56 -0600 Subject: [PATCH 11/15] ci: fix traefik idleConnTimeout flag path (forwardingtimeouts) --- docker-compose-ci.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index 4f6d931754d15..fae6a7e25cf07 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -233,7 +233,7 @@ services: - --providers.docker=true # keep upstream keep-alive enabled, but drop idle conns before the # meteor webapp 5s idle-socket reaper can kill one traefik would reuse - - --serverstransport.idleconntimeout=3s + - --serverstransport.forwardingtimeouts.idleconntimeout=3s - --accesslog=true - --accesslog.format=json - --log.level=DEBUG From 5791a25b8a7db82537d7e9fc40224aa7f50ff759 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 13:38:38 -0600 Subject: [PATCH 12/15] ci: make reaped-conn reuse retryable instead of racing the reaper The 3s idleConnTimeout traded the -1 body-copy race for the Go idle-expiry-vs-checkout race (reproduced on CE UI shards: same "use of closed network connection" on dynamic-import). No timeout value wins the timing game against the webapp 5s reaper, so stop playing it: default 90s idle pool, and buffering+retry middlewares so a request that lands on a server-reaped conn (fails before response headers) is replayed transparently, POST bodies included. --- docker-compose-ci.yml | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index fae6a7e25cf07..16454ce6b4c06 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -38,7 +38,12 @@ services: traefik.http.services.rocketchat.loadbalancer.server.port: 3000 traefik.http.routers.rocketchat.service: rocketchat traefik.http.routers.rocketchat.rule: PathPrefix(`/`) - traefik.http.routers.rocketchat.middlewares: test-retry + # meteor webapp reaps idle sockets after 5s, so traefik's pooled upstream + # conns die server-side between bursts; buffering makes request bodies + # replayable so retry can transparently re-send on a fresh conn when it + # picks a reaped one (dead-conn reuse fails before response headers) + traefik.http.routers.rocketchat.middlewares: test-buffer,test-retry + traefik.http.middlewares.test-buffer.buffering.retryExpression: IsNetworkError() && Attempts() < 4 traefik.http.middlewares.test-retry.retry.attempts: 4 healthcheck: interval: 2s @@ -231,9 +236,6 @@ services: image: traefik:v3.6.6 command: - --providers.docker=true - # keep upstream keep-alive enabled, but drop idle conns before the - # meteor webapp 5s idle-socket reaper can kill one traefik would reuse - - --serverstransport.forwardingtimeouts.idleconntimeout=3s - --accesslog=true - --accesslog.format=json - --log.level=DEBUG From 7962a3771d294efa18357132bbfa5474ea0ba055 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 14:55:55 -0600 Subject: [PATCH 13/15] ci: raise server socket timeout above the proxy idle window, opt-in via env Every proxy-side config permutation loses a timing game (measured on the PR): -1 races the body copy and exhausts ports, a short idleConnTimeout races idle expiry against checkout, and buffering+retry breaks response semantics suite-wide. The only race-free arrangement is the server outliving the proxy pool: HTTP_SOCKET_TIMEOUT_MS (CI compose sets 120s, above traefik 90s idleConnTimeout) detaches webapp 5s reaper re-arming and raises socket/keepAlive/headers timeouts, so traefik always closes pooled conns first and can never reuse one node already killed. Unset (prod) nothing changes. --- apps/meteor/server/startup/httpSocketTimeout.ts | 17 +++++++++++++++++ apps/meteor/server/startup/index.ts | 1 + docker-compose-ci.yml | 10 ++++------ 3 files changed, 22 insertions(+), 6 deletions(-) create mode 100644 apps/meteor/server/startup/httpSocketTimeout.ts diff --git a/apps/meteor/server/startup/httpSocketTimeout.ts b/apps/meteor/server/startup/httpSocketTimeout.ts new file mode 100644 index 0000000000000..275f9bc10fd1d --- /dev/null +++ b/apps/meteor/server/startup/httpSocketTimeout.ts @@ -0,0 +1,17 @@ +import { WebApp } from 'meteor/webapp'; + +// meteor's webapp arms a 5s idle-socket timeout (and re-arms it after every +// response), which kills keep-alive conns a fronting proxy may be about to +// reuse — the root of the CI dynamic-import truncation flake (PR #41399). +// Overriding it is opt-in: only CI sets HTTP_SOCKET_TIMEOUT_MS, pointing it +// above traefik's idleConnTimeout so the proxy always closes conns first. +const timeout = parseInt(process.env.HTTP_SOCKET_TIMEOUT_MS ?? '', 10); +if (timeout > 0) { + const { httpServer, _timeoutAdjustmentRequestCallback } = WebApp as typeof WebApp & { + _timeoutAdjustmentRequestCallback: (req: unknown, res: unknown) => void; + }; + httpServer.removeListener('request', _timeoutAdjustmentRequestCallback); + httpServer.setTimeout(timeout); + httpServer.keepAliveTimeout = timeout; + httpServer.headersTimeout = timeout + 1000; +} diff --git a/apps/meteor/server/startup/index.ts b/apps/meteor/server/startup/index.ts index d4df91fa3f098..83cec2ac22bb8 100644 --- a/apps/meteor/server/startup/index.ts +++ b/apps/meteor/server/startup/index.ts @@ -8,6 +8,7 @@ import './coreApps'; import { generateFederationKeys } from './generateKeys'; import './presenceTroubleshoot'; import './socketForensics'; +import './httpSocketTimeout'; import '../hooks'; import '../lib/rooms/roomTypes'; import '../lib/settingsRegenerator'; diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index 16454ce6b4c06..7357c3ec1298e 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -30,6 +30,9 @@ services: - 'Federation_Service_Domain=rc.host' - HEAP_USAGE_PERCENT=99 - SOCKET_FORENSICS=true + # keep server sockets alive longer than traefik's 90s idleConnTimeout so + # the proxy always closes pooled conns first and never reuses a dead one + - HTTP_SOCKET_TIMEOUT_MS=120000 depends_on: - traefik - mongo @@ -38,12 +41,7 @@ services: traefik.http.services.rocketchat.loadbalancer.server.port: 3000 traefik.http.routers.rocketchat.service: rocketchat traefik.http.routers.rocketchat.rule: PathPrefix(`/`) - # meteor webapp reaps idle sockets after 5s, so traefik's pooled upstream - # conns die server-side between bursts; buffering makes request bodies - # replayable so retry can transparently re-send on a fresh conn when it - # picks a reaped one (dead-conn reuse fails before response headers) - traefik.http.routers.rocketchat.middlewares: test-buffer,test-retry - traefik.http.middlewares.test-buffer.buffering.retryExpression: IsNetworkError() && Attempts() < 4 + traefik.http.routers.rocketchat.middlewares: test-retry traefik.http.middlewares.test-retry.retry.attempts: 4 healthcheck: interval: 2s From 704cbaf9937f587585e583f5b2e785e7aa160cb0 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 16:07:05 -0600 Subject: [PATCH 14/15] ci: buffer dynamic-import requests to close the go-transport early-response race MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit pcap from the v3 run (pooled conn, reaper disabled) shows the same signature as every reproduction: request written in two segments, server responds within ~1ms, traefik FINs 0.3ms after the first response bytes and RSTs the rest — go net/http treats the fast response as arriving before the request write completed and kills the conn mid body copy. Config knobs only modulated the frequency; the fix is removing the window: a dedicated dynamic-import router with buffering makes the tiny POST body memory-resident so headers+body coalesce into one upstream write, and retry replays any pre-header failure. Scoped to that route because suite-wide buffering broke 404/CORS semantics. --- docker-compose-ci.yml | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index 7357c3ec1298e..76ee2653540b1 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -43,6 +43,15 @@ services: traefik.http.routers.rocketchat.rule: PathPrefix(`/`) traefik.http.routers.rocketchat.middlewares: test-retry traefik.http.middlewares.test-retry.retry.attempts: 4 + # dedicated route for dynamic-import: buffering coalesces the tiny POST + # into a single upstream write, closing the go-transport early-response + # race window (response beating the request-write bookkeeping kills the + # conn mid body copy); scoped here because suite-wide buffering broke + # 404/CORS response semantics + traefik.http.routers.rocketchat-dynimport.rule: PathPrefix(`/__meteor__/dynamic-import`) + traefik.http.routers.rocketchat-dynimport.service: rocketchat + traefik.http.routers.rocketchat-dynimport.middlewares: test-buffer,test-retry + traefik.http.middlewares.test-buffer.buffering.retryExpression: IsNetworkError() && Attempts() < 4 healthcheck: interval: 2s timeout: 5s From 3a6cff2b310b3ede316a3f4b57504fad83390504 Mon Sep 17 00:00:00 2001 From: Kevin Aleman Date: Fri, 17 Jul 2026 19:18:24 -0600 Subject: [PATCH 15/15] ci: remove diagnostic instrumentation, keep fixes and regression test --- .github/workflows/ci-test-e2e.yml | 10 +- apps/meteor/server/lib/socketForensics.ts | 86 ------------- apps/meteor/server/startup/index.ts | 1 - apps/meteor/server/startup/socketForensics.ts | 9 -- .../unit/server/lib/socketForensics.spec.ts | 113 ------------------ docker-compose-ci.yml | 16 --- 6 files changed, 1 insertion(+), 234 deletions(-) delete mode 100644 apps/meteor/server/lib/socketForensics.ts delete mode 100644 apps/meteor/server/startup/socketForensics.ts delete mode 100644 apps/meteor/tests/unit/server/lib/socketForensics.spec.ts diff --git a/.github/workflows/ci-test-e2e.yml b/.github/workflows/ci-test-e2e.yml index 468a1cafeadd1..090a6f5a8ed5a 100644 --- a/.github/workflows/ci-test-e2e.yml +++ b/.github/workflows/ci-test-e2e.yml @@ -189,7 +189,7 @@ jobs: TEST_MODE: ${{ startsWith(inputs.type, 'api') && 'api' || 'true' }} run: | # when we are testing CE, we only need to start the rocketchat container - DEBUG_LOG_LEVEL=${DEBUG_LOG_LEVEL:-0} docker compose -f docker-compose-ci.yml up -d rocketchat tcpdump --wait + DEBUG_LOG_LEVEL=${DEBUG_LOG_LEVEL:-0} docker compose -f docker-compose-ci.yml up -d rocketchat --wait - name: Start containers for EE if: inputs.release == 'ee' @@ -324,14 +324,6 @@ jobs: if: failure() run: docker compose -f docker-compose-ci.yml logs traefik - - name: Store network capture if E2E test failed - if: failure() - uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 - with: - name: pcap-${{ inputs.release }}-${{ matrix.mongodb-version }}-${{ matrix.shard }} - path: /tmp/pcap - include-hidden-files: true - - name: Store coverage if: inputs.coverage == matrix.mongodb-version uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 diff --git a/apps/meteor/server/lib/socketForensics.ts b/apps/meteor/server/lib/socketForensics.ts deleted file mode 100644 index 97085a95733ee..0000000000000 --- a/apps/meteor/server/lib/socketForensics.ts +++ /dev/null @@ -1,86 +0,0 @@ -import type { Server, ServerResponse } from 'http'; -import { Socket } from 'net'; - -const log = (event: string, data: Record): void => { - console.error(`[socket-forensics] ${event}`, JSON.stringify({ time: new Date().toISOString(), ...data })); -}; - -const isInFlight = (res: ServerResponse): boolean => res.headersSent && !res.writableFinished; - -const responseOf = (socket: Socket): ServerResponse | undefined => (socket as unknown as { _httpMessage?: ServerResponse })._httpMessage; - -const connectedAt = new WeakMap(); - -const ageOf = (socket: Socket): number | undefined => { - const start = connectedAt.get(socket); - return start === undefined ? undefined : Date.now() - start; -}; - -export const attachSocketForensics = (server: Server): void => { - server.on('connection', (socket) => { - connectedAt.set(socket, Date.now()); - - socket.on('timeout', () => { - if (socket.bytesWritten === 0) { - return; - } - const res = responseOf(socket); - log('socket-timeout', { - ageMs: ageOf(socket), - bytesWritten: socket.bytesWritten, - pendingBytes: socket.writableLength, - inFlightUrl: res && isInFlight(res) ? res.req?.url : undefined, - }); - }); - }); - - server.on('request', (req, res) => { - res.on('error', (error: Error) => { - log('response-error', { method: req.method, url: req.url, message: error.message, stack: error.stack }); - }); - - res.on('close', () => { - if (!isInFlight(res)) { - return; - } - log('response-truncated', { - method: req.method, - url: req.url, - statusCode: res.statusCode, - bytesWritten: res.socket?.bytesWritten, - pendingBytes: res.socket?.writableLength, - ageMs: res.socket ? ageOf(res.socket) : undefined, - requestDestroyed: req.destroyed, - }); - }); - }); -}; - -const patchInFlightTeardown = (method: 'end' | 'destroy'): (() => void) => { - const original = Socket.prototype[method]; - - Socket.prototype[method] = function (this: Socket, ...args: unknown[]) { - const res = responseOf(this); - if (res && isInFlight(res)) { - log(`socket-${method}-mid-response`, { - method: res.req?.method, - url: res.req?.url, - statusCode: res.statusCode, - bytesWritten: this.bytesWritten, - pendingBytes: this.writableLength, - ageMs: ageOf(this), - error: args[0] instanceof Error ? { message: args[0].message, stack: args[0].stack } : undefined, - callerStack: new Error(`${method} call site`).stack, - }); - } - return (original as (...a: unknown[]) => unknown).apply(this, args); - } as never; - - return () => { - Socket.prototype[method] = original as never; - }; -}; - -export const patchSocketDestroy = (): (() => void) => patchInFlightTeardown('destroy'); - -export const patchSocketEnd = (): (() => void) => patchInFlightTeardown('end'); diff --git a/apps/meteor/server/startup/index.ts b/apps/meteor/server/startup/index.ts index 83cec2ac22bb8..b5fc18d36a9b5 100644 --- a/apps/meteor/server/startup/index.ts +++ b/apps/meteor/server/startup/index.ts @@ -7,7 +7,6 @@ import './serverRunning'; import './coreApps'; import { generateFederationKeys } from './generateKeys'; import './presenceTroubleshoot'; -import './socketForensics'; import './httpSocketTimeout'; import '../hooks'; import '../lib/rooms/roomTypes'; diff --git a/apps/meteor/server/startup/socketForensics.ts b/apps/meteor/server/startup/socketForensics.ts deleted file mode 100644 index 64c86205a2caf..0000000000000 --- a/apps/meteor/server/startup/socketForensics.ts +++ /dev/null @@ -1,9 +0,0 @@ -import { WebApp } from 'meteor/webapp'; - -import { attachSocketForensics, patchSocketDestroy, patchSocketEnd } from '../lib/socketForensics'; - -if (process.env.SOCKET_FORENSICS === 'true') { - attachSocketForensics(WebApp.httpServer); - patchSocketDestroy(); - patchSocketEnd(); -} diff --git a/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts b/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts deleted file mode 100644 index bd4c9c6a17bd0..0000000000000 --- a/apps/meteor/tests/unit/server/lib/socketForensics.spec.ts +++ /dev/null @@ -1,113 +0,0 @@ -import type { Server } from 'http'; -import { createServer } from 'http'; -import type { AddressInfo } from 'net'; -import { Socket } from 'net'; - -import { expect } from 'chai'; -import { afterEach, describe, it } from 'mocha'; -import sinon from 'sinon'; - -import { attachSocketForensics, patchSocketDestroy, patchSocketEnd } from '../../../../server/lib/socketForensics'; - -const listen = (server: Server): Promise => - new Promise((resolve) => server.listen(0, () => resolve((server.address() as AddressInfo).port))); - -const waitForCall = async (stub: sinon.SinonStub): Promise => { - for (let i = 0; i < 100 && !stub.called; i++) { - await new Promise((resolve) => setTimeout(resolve, 10)); - } -}; - -describe('socketForensics', () => { - afterEach(() => sinon.restore()); - - describe('attachSocketForensics', () => { - it('should log response-truncated when the socket dies after headers with an unfinished body', async () => { - const consoleError = sinon.stub(console, 'error'); - const server = createServer((_req, res) => { - res.writeHead(200, { 'Content-Type': 'application/json' }); - res.write('{"partial":'); - res.socket?.destroy(); - }); - attachSocketForensics(server); - const port = await listen(server); - - await fetch(`http://127.0.0.1:${port}/dynamic-import/fetch`).catch(() => undefined); - await waitForCall(consoleError); - server.close(); - - expect(consoleError.calledWithMatch('[socket-forensics] response-truncated', sinon.match(/dynamic-import\/fetch/))).to.be.true; - }); - - it('should not log anything for a response that finishes normally', async () => { - const consoleError = sinon.stub(console, 'error'); - const server = createServer((_req, res) => { - res.writeHead(200); - res.end('ok'); - }); - attachSocketForensics(server); - const port = await listen(server); - - const response = await fetch(`http://127.0.0.1:${port}/ok`); - await response.text(); - await new Promise((resolve) => setTimeout(resolve, 20)); - server.close(); - - expect(consoleError.called).to.be.false; - }); - }); - - describe('patchSocketDestroy', () => { - it('should log the destroy call site when a socket with an in-flight response is destroyed', async () => { - const consoleError = sinon.stub(console, 'error'); - const restore = patchSocketDestroy(); - - const server = createServer((_req, res) => { - res.writeHead(200); - res.write('partial'); - res.socket?.destroy(); - }); - const port = await listen(server); - - await fetch(`http://127.0.0.1:${port}/killed`).catch(() => undefined); - await waitForCall(consoleError); - server.close(); - restore(); - - const call = consoleError.getCalls().find((c) => c.args[0] === '[socket-forensics] socket-destroy-mid-response'); - expect(call).to.not.be.undefined; - const payload = JSON.parse(call?.args[1]); - expect(payload.url).to.equal('/killed'); - expect(payload.callerStack).to.be.a('string'); - }); - - it('should log the end call site when a socket with an in-flight response is ended', async () => { - const consoleError = sinon.stub(console, 'error'); - const restore = patchSocketEnd(); - - const server = createServer((_req, res) => { - res.writeHead(200); - res.write('partial'); - res.socket?.end(); - }); - const port = await listen(server); - - await fetch(`http://127.0.0.1:${port}/ended`).catch(() => undefined); - await waitForCall(consoleError); - server.close(); - restore(); - - const call = consoleError.getCalls().find((c) => c.args[0] === '[socket-forensics] socket-end-mid-response'); - expect(call).to.not.be.undefined; - expect(JSON.parse(call?.args[1]).url).to.equal('/ended'); - }); - - it('should restore the original destroy behavior', () => { - const original = Socket.prototype.destroy; - const restore = patchSocketDestroy(); - expect(Socket.prototype.destroy).to.not.equal(original); - restore(); - expect(Socket.prototype.destroy).to.equal(original); - }); - }); -}); diff --git a/docker-compose-ci.yml b/docker-compose-ci.yml index 76ee2653540b1..cef50ced7cbf4 100644 --- a/docker-compose-ci.yml +++ b/docker-compose-ci.yml @@ -29,7 +29,6 @@ services: - Federation_Service_Enabled=true - 'Federation_Service_Domain=rc.host' - HEAP_USAGE_PERCENT=99 - - SOCKET_FORENSICS=true # keep server sockets alive longer than traefik's 90s idleConnTimeout so # the proxy always closes pooled conns first and never reuses a dead one - HTTP_SOCKET_TIMEOUT_MS=120000 @@ -227,25 +226,10 @@ services: timeout: 5s retries: 5 - tcpdump: - image: nicolaka/netshoot:v0.14 - network_mode: service:traefik - cap_add: - - NET_RAW - - NET_ADMIN - command: tcpdump -i any -s 96 -C 200 -W 3 -Z root -w /pcap/traefik.pcap tcp port 80 or tcp port 3000 - volumes: - - /tmp/pcap:/pcap - depends_on: - - traefik - traefik: image: traefik:v3.6.6 command: - --providers.docker=true - - --accesslog=true - - --accesslog.format=json - - --log.level=DEBUG ports: - 3000:80 volumes: