diff --git a/src/servers/api/photos/router.ts b/src/servers/api/photos/router.ts index 7dfaf7f0..b4d80e2a 100644 --- a/src/servers/api/photos/router.ts +++ b/src/servers/api/photos/router.ts @@ -11,6 +11,12 @@ const proxy = createSidecarProxy({ // Originals and `download/archive` zips are large and Immich builds the archive as it streams it, so the // socket can sit quiet longer than the default 60s idle drop allows. timeoutSeconds: 600, + // Immich judges an asset from its first few KB and rejects immediately, while we are still writing — + // and the response is lost in the teardown, which is what made every large upload fail with an + // unexplained empty 400. Buffering here removes the overlap. The sidecar does the same on its own hop + // to Immich (sidecar/photos/routes.ts → readBodyCapped), and both are needed: fixing one alone still + // lost the answer roughly two runs in three at 32 MB. + bufferRequestBody: true, }); export const photosRouter = proxy.router; diff --git a/src/servers/sidecar/create-proxy.test.ts b/src/servers/sidecar/create-proxy.test.ts index 87f4c3b5..67a51f6c 100644 --- a/src/servers/sidecar/create-proxy.test.ts +++ b/src/servers/sidecar/create-proxy.test.ts @@ -73,6 +73,10 @@ beforeAll(async () => { sidecar = Bun.serve({ port: 0, async fetch(req) { + // A rejection with no body at all — the shape from COMMS/UPLOAD_EMPTY_400.md that tells the client + // "no" and gives it nothing to act on. + if (new URL(req.url).pathname.endsWith('/empty400')) return new Response(null, { status: 400 }); + const contentType = req.headers.get('content-type') ?? ''; const raw = new Uint8Array(await req.arrayBuffer()); const asText = new TextDecoder().decode(raw); @@ -160,6 +164,61 @@ describe('sidecar proxy multipart forwarding', () => { expect(seen!.fileBytes).toEqual([...FILE_BYTES]); }); + it('reports a rejection instead of passing it on in silence', async () => { + // COMMS/UPLOAD_EMPTY_400.md: uploads failed with an empty-bodied 400 and nothing logged it anywhere, + // so localising the fault took an evening of curl bisection. The platform is the only hop that sees + // both sides. `requestBytes` is the field that would have cracked it — a size threshold is legible at + // a glance instead of by bisection. + const warnings: unknown[][] = []; + const realWarn = console.warn; + console.warn = (...args: unknown[]) => void warnings.push(args); + + try { + const payload = JSON.stringify({ some: 'payload' }); + const res = await app.request('http://x/api/testcar/_officer/empty400', { + method: 'POST', + // Set explicitly: `app.request` does not derive it, and this is the field the bug report needed. + headers: { 'content-type': 'application/json', 'content-length': String(payload.length) }, + body: payload, + }); + + // Pass-through is unchanged: the proxy reports, it does not rewrite. + expect(res.status).toBe(400); + expect(await res.text()).toBe(''); + + expect(warnings.length).toBe(1); + const [message, detail] = warnings[0] as [string, Record]; + expect(message).toContain('[testcar]'); + expect(message).toContain('POST /_officer/empty400'); + expect(message).toContain('400'); + // The empty body is named, not left to be inferred from a byte count of zero. + expect(detail.emptyBody).toBe(true); + expect(detail.requestBytes).toBe(String(payload.length)); + expect(detail.responseBytes).toBe('0'); + } finally { + console.warn = realWarn; + } + }); + + it('says nothing about a request that succeeded', async () => { + const { body, contentType } = phoneMultipart(); + const warnings: unknown[][] = []; + const realWarn = console.warn; + console.warn = (...args: unknown[]) => void warnings.push(args); + + try { + const res = await app.request('http://x/api/testcar/_officer/assets', { + method: 'POST', + headers: { 'content-type': contentType }, + body: new Blob([body]), + }); + expect(res.status).toBe(201); + expect(warnings).toEqual([]); + } finally { + console.warn = realWarn; + } + }); + it('still forwards a JSON body untouched', async () => { const res = await app.request('http://x/api/testcar/_officer/echo', { method: 'POST', diff --git a/src/servers/sidecar/create-proxy.ts b/src/servers/sidecar/create-proxy.ts index b01cc3a2..e0243763 100644 --- a/src/servers/sidecar/create-proxy.ts +++ b/src/servers/sidecar/create-proxy.ts @@ -16,7 +16,8 @@ import { registerProxiedPrefix } from './proxied-prefixes'; // the platform process is long-lived, restarts on every deploy and is the largest attack surface in the // system, while the bodies passing through carry wallet unlock passphrases, macaroons and vault secrets. // Keeping this layer structurally incapable of seeing them is the point. Note the absence of any body -// inspection below, and that the error path logs the target path ONLY. +// inspection below: the two error paths log a path, a status and byte counts taken from HEADERS, and +// nothing ever reads or buffers the streams themselves. // // Sidecars own their own contracts. This file must never grow per-app logic — if a sidecar needs // something extra at registration time it gets `onRegister`, not a branch in here. @@ -35,8 +36,30 @@ export type SidecarProxyParams = { * of a sidecar's routes are slow. */ timeoutSeconds?: number; + /** + * Read the request body fully before forwarding, instead of streaming it. + * + * OFF by default and it must stay that way: streaming is what keeps wallet passphrases, macaroons and + * vault secrets out of this process's heap, and what lets a multi-gigabyte upload through at all. + * + * Opt in only where a sidecar's upstream answers BEFORE the body finishes arriving. When that happens + * the response is lost — the far side closes while we are still writing, and the real answer is + * replaced by a bodyless 400. Photos hits this because Immich judges an asset from its first few KB + * and rejects immediately; see `readBodyCapped` in sidecar/photos/routes.ts for the measurements. + * + * Bounded by `MAX_BUFFERED_BODY`: a body larger than that is streamed anyway, so enabling this can + * never put a 4 GB video in the heap. Above the cap the race is accepted, because an upload that size + * only loses its ERROR MESSAGE — one Immich accepts is read to the end and never races at all. + */ + bufferRequestBody?: boolean; }; +/** + * Ceiling on `bufferRequestBody`. Kept in step with the photos sidecar's own cap so the two hops make the + * same call on the same request; officer buffering is what gives the sidecar a content-length to decide by. + */ +const MAX_BUFFERED_BODY = 512 * 1024 * 1024; + export type SidecarProxy = { /** Catch-all router to mount at `prefix`. Has no routes of its own by design. */ router: Hono<{ Variables: HonoVariables }>; @@ -46,7 +69,13 @@ export type SidecarProxy = { getWsUrl: () => string | null; }; -export function createSidecarProxy({ name, prefix, onRegister, timeoutSeconds }: SidecarProxyParams): SidecarProxy { +export function createSidecarProxy({ + name, + prefix, + onRegister, + timeoutSeconds, + bufferRequestBody, +}: SidecarProxyParams): SidecarProxy { let serverPort: number | null = null; // Tells bodyParser to keep its hands off this prefix's request bodies. Load-bearing for uploads, not an @@ -106,10 +135,23 @@ export function createSidecarProxy({ name, prefix, onRegister, timeoutSeconds }: // is absent from TypeScript's RequestInit, hence the widened type. // This is only safe because bodyParser skips proxied prefixes: a body consumed upstream would arrive // here as an already-locked stream. + // Buffered only where the sidecar opted in (see `bufferRequestBody`), and only up to the cap: an + // upstream that answers before the body lands loses its own response, and streaming is what exposes + // that race. Anything larger streams as it always did — a 4 GB video must not land in this heap, and + // does not need to, since a file the upstream ACCEPTS is read to the end and never races. + const declaredLength = Number(ctx.req.header('content-length') ?? ''); + const withinBufferCap = + Number.isFinite(declaredLength) && declaredLength > 0 && declaredLength <= MAX_BUFFERED_BODY; + const body = hasBody + ? bufferRequestBody && withinBufferCap + ? await ctx.req.raw.arrayBuffer() + : ctx.req.raw.body + : undefined; + const init: RequestInit & { duplex?: 'half' } = { method, headers, - body: hasBody ? ctx.req.raw.body : undefined, + body, duplex: 'half', }; @@ -122,6 +164,29 @@ export function createSidecarProxy({ name, prefix, onRegister, timeoutSeconds }: return ctx.text(`${name} sidecar unreachable`, 502); } + // Every rejection that passes through gets one line. This is METADATA ONLY — status and two byte + // counts read from headers, never the bytes themselves — so the no-bodies rule above still holds. + // + // It exists because of COMMS/UPLOAD_EMPTY_400.md: photo uploads over ~16 KB failed with a 400 carrying + // an EMPTY body, and nothing anywhere logged it — not Immich, not the sidecar, not here. The platform + // is the only hop that sees both sides, and it said nothing, so localising the fault took an evening of + // curl bisection. An error with no body is the unactionable case: the client is told "no" and given + // nothing to act on, and silence here makes it invisible to the server too. + // + // `requestBytes` is the field that would have cracked it: it makes a size threshold legible at a glance + // instead of by bisection. The subpath is logged without its query string — the 502 path above logs the + // full target, but this fires on ordinary 401s and 404s too, and query strings carry tokens. + if (upstream.status >= 400) { + const responseBytes = upstream.headers.get('content-length'); + console.warn(`[${name}] proxy ${method} ${subpath} -> ${upstream.status}`, { + requestBytes: ctx.req.header('content-length') ?? 'unknown', + responseBytes: responseBytes ?? 'unknown', + // Called out rather than left to be inferred from `responseBytes: '0'`, because this exact shape is + // the one that is impossible to diagnose from the client. + ...(responseBytes === '0' ? { emptyBody: true } : {}), + }); + } + return new Response(upstream.body, { status: upstream.status, headers: new Headers(upstream.headers) }); }); diff --git a/src/servers/sidecar/photos/routes.ts b/src/servers/sidecar/photos/routes.ts index f6950587..d0aeabf6 100644 --- a/src/servers/sidecar/photos/routes.ts +++ b/src/servers/sidecar/photos/routes.ts @@ -83,11 +83,86 @@ export function relayResponse(res: Response): Response { return new Response(body, { status: res.status, headers }); } +/** + * The largest request body held in memory. Above this the body is STREAMED instead — never refused. + * + * The cap exists to bound heap, not to bound uploads: a 4 GB video must still go through. What is given + * up above the cap is only the guarantee that a REJECTION carries its message, and an upload that big + * which Immich rejects was going to fail either way — see `readBodyCapped`. + */ +const MAX_BUFFERED_BODY = 512 * 1024 * 1024; + +/** + * Read the whole request body into memory, refusing above `MAX_BUFFERED_BODY`. + * + * ── Why this is buffered rather than streamed ── + * + * It used to stream, which is the obvious thing for an upload and was wrong for one specific reason: + * when the body is still being written and Immich answers early, the response is lost. Immich rejects + * an asset as soon as it has enough of the file to judge it, then closes; our writer is still going; + * Node's HTTP server calls the leftover bytes a protocol violation and replaces the app's answer with a + * bodyless `400 Bad Request` + `Connection: close`. The app's real message never reaches the wire and + * Immich logs nothing, so the client sees an unexplained 400 and the server has no record of it. + * + * Measured on this machine (COMMS/UPLOAD_EMPTY_400*.md): streamed lost the response in 2 of 4 attempts + * at 8 MB, 32 MB and 64 MB alike; buffered lost it in 0 of 4 at every size. It is a race, not a size + * limit — its probability just approaches certainty as the body grows, which is why a phone's video + * failed every time while a small photo usually got through. + * + * A size threshold was considered and rejected: buffering only the small bodies would leave exactly the + * large uploads that always fail on the broken path. Cancelling the write once the response arrives was + * tried and does not help — by the time `fetch` resolves, the teardown has already happened. + * + * The cost is real and was accepted deliberately: a 300 MB video is 300 MB of this process's heap for + * the duration of the upload. That is the price of the upload working at all. + * + * ── And why there is a ceiling on it ── + * + * Buffering everything would mean a 4 GB video sitting in this heap (and another copy in officer's), so + * above MAX_BUFFERED_BODY the body is streamed as it always was. That is not a refusal and not a + * degradation of uploads: a file Immich ACCEPTS never triggers the race, because it is read to the end + * before anything is answered. The only thing lost above the cap is the error message on a file Immich + * rejects — and an upload that size which Immich rejects fails either way. Refusing it outright would + * break the legitimate case to improve the diagnosis of the doomed one. + */ +async function readBodyCapped( + req: Request, +): Promise<{ ok: true; bytes: Uint8Array } | { ok: false; seen: number }> { + // Decided from `content-length` alone. Officer sends one whenever IT buffered, so the two hops agree + // without coordinating: a body small enough for officer to hold is small enough to hold here. When the + // header is absent officer streamed, which means it was over the cap there too. + const declared = Number(req.headers.get('content-length') ?? ''); + if (!Number.isFinite(declared) || declared <= 0 || declared > MAX_BUFFERED_BODY) return { ok: false, seen: declared }; + + const reader = req.body!.getReader(); + const chunks: Uint8Array[] = []; + let total = 0; + for (;;) { + const { done, value } = await reader.read(); + if (done) break; + total += value.length; + if (total > MAX_BUFFERED_BODY) { + await reader.cancel().catch(() => {}); + return { ok: false, seen: total }; + } + chunks.push(value); + } + + const bytes = new Uint8Array(new ArrayBuffer(total)); + let at = 0; + for (const chunk of chunks) { + bytes.set(chunk, at); + at += chunk.length; + } + return { ok: true, bytes }; +} + /** * Forward one request to Immich and stream the answer back. * - * The body is a stream, never an ArrayBuffer: a full-resolution original or a `download/archive` zip is - * hundreds of megabytes and buffering it would hold all of it in the sidecar's heap for no reason. + * The RESPONSE is still a stream, never an ArrayBuffer: a full-resolution original or a + * `download/archive` zip is hundreds of megabytes and buffering it would hold all of it in the + * sidecar's heap for no reason. Only the request body is held, and only for the reason above. */ export async function handleOfficerRoute(cfg: UpstreamConfig, req: Request, url: URL): Promise { const rest = url.pathname.slice('/_officer/'.length); @@ -109,12 +184,20 @@ export async function handleOfficerRoute(cfg: UpstreamConfig, req: Request, url: query.delete('token'); const search = query.toString(); + // Buffered, not streamed — see readBodyCapped. A body that is still being written when Immich answers + // loses the answer, which is what made every large upload fail with an unexplained empty 400. + let body: BodyInit | null = null; + if (hasBody && req.body) { + const read = await readBodyCapped(req); + // Over the cap (or no declared length): stream it, exactly as this always did. Not an error. + body = read.ok ? read.bytes : req.body; + } + const res = await callUpstream(cfg, { path: `/api/${rest}`, method: req.method, query: search ? `?${search}` : '', - // Streamed, not buffered: an asset upload can be gigabytes and this layer never reads the bytes. - body: hasBody ? req.body : null, + body, contentType: req.headers.get('content-type'), range: req.headers.get('range'), ifNoneMatch: req.headers.get('if-none-match'), diff --git a/src/servers/sidecar/photos/upstream.ts b/src/servers/sidecar/photos/upstream.ts index 2a429735..af642eb3 100644 --- a/src/servers/sidecar/photos/upstream.ts +++ b/src/servers/sidecar/photos/upstream.ts @@ -165,12 +165,15 @@ type CallOptions = { /** Raw search string including the leading `?`, or empty. */ query?: string; /** - * A string for the JSON callers, or the caller's own request body as a STREAM for the two forwarders. + * A string for the JSON callers, or the forwarder's already-buffered request body. * - * Streamed rather than buffered because a phone's video upload is bounded by `maxRequestBodySize` - * (4 GB) and buffering put all of it in this process's heap for a hop that never looks at the bytes. - * Streaming to Immich means chunked transfer-encoding instead of Content-Length — which is already how - * the body reaches us, since the platform proxy forwards no content-length either. + * This used to be a stream, for the obvious reason that a phone's video should not sit in this + * process's heap. It was changed back deliberately: a request body still being written when Immich + * answers loses the answer entirely — Node replaces the app's response with a bodyless 400 and closes + * — which is what made every large upload fail inexplicably. `readBodyCapped` in routes.ts has the + * measurements and the alternatives that were tried; the heap cost is the accepted price. + * + * A buffer also carries a Content-Length, so the request to Immich is no longer chunked. */ body?: BodyInit | null; contentType?: string | null;