From 4cb9cd450e367bbd70df7be779c0303b0b645f09 Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 13:44:07 +0200 Subject: [PATCH 01/11] feat(stack): log gateway requests and ship them to Studio's API Gateway - The shared API proxy records one access line per request and websocket upgrade (nginx combined format plus duration, credentials in the query string redacted), persisted as a gateway log stream. - Gateway lines ship to the cloudflare.logs.prod source with the Kong request and response metadata Studio's API Gateway page reads. - supabase stack logs includes gateway lines and selects them with --service gateway. Co-Authored-By: Claude Opus 5.5 --- apps/cli/docs/stack-commands.md | 15 +- .../db-config.integration.test.ts | 1 + .../commands/db/dump/dump.integration.test.ts | 1 + .../db/reset/reset.integration.test.ts | 1 + .../generate/generate.integration.test.ts | 1 + .../declarative/sync/sync.integration.test.ts | 1 + .../db/start/start.integration.test.ts | 1 + .../experimental/stack/logs/SIDE_EFFECTS.md | 8 +- .../experimental/stack/logs/logs.command.ts | 2 +- .../experimental/stack/logs/logs.handler.ts | 34 ++- .../stack/logs/logs.integration.test.ts | 79 +++++ .../stack/prepare/prepare.integration.test.ts | 1 + .../experimental/stack/start/SIDE_EFFECTS.md | 16 +- .../start-export-pointer.integration.test.ts | 1 + .../stack/start/start.integration.test.ts | 1 + .../stack/status/status.integration.test.ts | 1 + .../serve/serve.stack.integration.test.ts | 1 + apps/cli/tests/helpers/storage.ts | 1 + packages/stack/ARCHITECTURE.md | 10 +- .../stack/src/HttpProxy.integration.test.ts | 258 +++++++++++++++- packages/stack/src/HttpProxy.ts | 282 ++++++++++++++---- packages/stack/src/Network.ts | 20 +- .../src/Owner.analytics.integration.test.ts | 10 + .../stack/src/Owner.logs.integration.test.ts | 56 ++++ packages/stack/src/Owner.ts | 46 ++- packages/stack/src/effect.ts | 30 +- packages/stack/src/host/GatewayLog.ts | 63 ++++ .../src/host/LogForwarder.integration.test.ts | 52 +++- packages/stack/src/host/LogForwarder.ts | 27 +- packages/stack/src/host/LogflareEvents.ts | 61 +++- .../src/host/LogflareEvents.unit.test.ts | 45 +++ 31 files changed, 998 insertions(+), 128 deletions(-) create mode 100644 packages/stack/src/host/GatewayLog.ts diff --git a/apps/cli/docs/stack-commands.md b/apps/cli/docs/stack-commands.md index f6d4e42511..05933fc4c0 100644 --- a/apps/cli/docs/stack-commands.md +++ b/apps/cli/docs/stack-commands.md @@ -237,13 +237,14 @@ lint transaction (always rolled back). It does not launch a client binary. ## Reading stack logs -`supabase stack logs` prints the retained stdout/stderr of composition members and -exits; `-f/--follow` then streams new lines until interrupted. Select `--stack ` -or `--stack-id `; the repeatable `--service ` can include -standalone services too. History is read from the persisted log files, so it works -while the stack is stopped; `--follow` requires a running owner and fails before -printing anything without one. Neither mode starts an owner or service, and Ctrl-C -leaves services running. +`supabase stack logs` prints the retained stdout/stderr of composition members, plus +the `gateway` request lines of the shared API port, and exits; `-f/--follow` then +streams new lines until interrupted. Select `--stack ` or `--stack-id `; the +repeatable `--service ` can include standalone services too, and +`--service gateway` reads only the request lines. History is read from the persisted +log files, so it works while the stack is stopped; `--follow` requires a running owner +and fails before printing anything without one. Neither mode starts an owner or +service, and Ctrl-C leaves services running. `--tail N` (default 200) keeps the newest lines across the selected services and `--since` takes a duration (`10m`, `1h30m`), an ISO-8601 time, or `start` for each diff --git a/apps/cli/src/command-internal/db-config.integration.test.ts b/apps/cli/src/command-internal/db-config.integration.test.ts index 1002a2b5d7..ad1e3d4390 100644 --- a/apps/cli/src/command-internal/db-config.integration.test.ts +++ b/apps/cli/src/command-internal/db-config.integration.test.ts @@ -489,6 +489,7 @@ describe("dbConfigResolver (db-url under the stack backend)", () => { }, stop: unused, destroy: unused, + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => unused }, }; return Layer.succeed(StackApi, { diff --git a/apps/cli/src/commands/db/dump/dump.integration.test.ts b/apps/cli/src/commands/db/dump/dump.integration.test.ts index e020809e10..642203185b 100644 --- a/apps/cli/src/commands/db/dump/dump.integration.test.ts +++ b/apps/cli/src/commands/db/dump/dump.integration.test.ts @@ -153,6 +153,7 @@ const managedDumpStackApi = (runtime: "native" | "docker") => { }, stop: Effect.void, destroy: Effect.succeed({ runtimeCleanup: "complete" as const }), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: runCommand }, } satisfies Stack; return Layer.succeed(StackApi, { diff --git a/apps/cli/src/commands/db/reset/reset.integration.test.ts b/apps/cli/src/commands/db/reset/reset.integration.test.ts index 1f73deb1b8..15f5c5b81f 100644 --- a/apps/cli/src/commands/db/reset/reset.integration.test.ts +++ b/apps/cli/src/commands/db/reset/reset.integration.test.ts @@ -808,6 +808,7 @@ function mockResetStackApi(opts: { }, stop: Effect.die("unused"), destroy: Effect.die("unused"), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => Effect.die("unused") }, }; return { diff --git a/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts b/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts index f6838085f6..cfeca95094 100644 --- a/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts +++ b/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts @@ -164,6 +164,7 @@ function generateStackApi(workdir: string) { }, stop: unusedStack, destroy: unusedStack, + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: unusedStackFn }, }; const identity = { projectRoot: workdir, branchContext: "main", stackName: "default" }; diff --git a/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts b/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts index c7035c2c4f..bb222990b2 100644 --- a/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts +++ b/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts @@ -166,6 +166,7 @@ function syncStackApi(workdir: string, port: number) { }, stop: unusedSync, destroy: unusedSync, + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: unusedSyncFn }, }; const identity = { projectRoot: workdir, branchContext: "main", stackName: "default" }; diff --git a/apps/cli/src/commands/db/start/start.integration.test.ts b/apps/cli/src/commands/db/start/start.integration.test.ts index 48f591f4dc..fdeca26575 100644 --- a/apps/cli/src/commands/db/start/start.integration.test.ts +++ b/apps/cli/src/commands/db/start/start.integration.test.ts @@ -1733,6 +1733,7 @@ describe("db start stack backend", () => { }, stop: Effect.void, destroy: Effect.succeed({ runtimeCleanup: "complete" as const }), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => Effect.die("unused") }, }; return { stack, state }; diff --git a/apps/cli/src/commands/experimental/stack/logs/SIDE_EFFECTS.md b/apps/cli/src/commands/experimental/stack/logs/SIDE_EFFECTS.md index 8cd7e8e4cf..0e67af126f 100644 --- a/apps/cli/src/commands/experimental/stack/logs/SIDE_EFFECTS.md +++ b/apps/cli/src/commands/experimental/stack/logs/SIDE_EFFECTS.md @@ -8,9 +8,11 @@ starts/stops a service. ## Selection and files Select the current project/branch/name, `--stack `, or `--stack-id `. -The selectors are mutually exclusive. By default, only composition members are -included. `--service ` is repeatable and can also select -standalone instances; a value that matches no saved instance fails with status 1. +The selectors are mutually exclusive. By default, composition members are +included, plus `gateway` (the shared API port's request lines) once the stack has +claimed that port. `--service ` is repeatable and can also select +standalone instances or `gateway`; a value that matches no saved instance, or +`gateway` without the shared API port, fails with status 1. A missing stack fails with status 1. Reads saved definitions under `/stacks//` and diff --git a/apps/cli/src/commands/experimental/stack/logs/logs.command.ts b/apps/cli/src/commands/experimental/stack/logs/logs.command.ts index 0e3d972b62..96ae1d2583 100644 --- a/apps/cli/src/commands/experimental/stack/logs/logs.command.ts +++ b/apps/cli/src/commands/experimental/stack/logs/logs.command.ts @@ -17,7 +17,7 @@ const config = { ), service: Flag.string("service").pipe( Flag.withDescription( - "Read one service kind or instance ID; repeat to select several. Defaults to composition members.", + "Read one service kind, instance ID, or gateway (shared API requests); repeat to select several. Defaults to composition members and gateway.", ), Flag.atLeast(0), ), diff --git a/apps/cli/src/commands/experimental/stack/logs/logs.handler.ts b/apps/cli/src/commands/experimental/stack/logs/logs.handler.ts index cc91d681a4..975a0d9f2b 100644 --- a/apps/cli/src/commands/experimental/stack/logs/logs.handler.ts +++ b/apps/cli/src/commands/experimental/stack/logs/logs.handler.ts @@ -1,5 +1,10 @@ import { Clock, Effect, Option, Path, Stream } from "effect"; -import { streamStackLogs, type SavedStack, type StackLogRecord } from "@supabase/stack/effect"; +import { + gatewayLog, + streamStackLogs, + type SavedStack, + type StackLogRecord, +} from "@supabase/stack/effect"; import { Output } from "../../../../shared/output/output.service.ts"; import { OutputFlag } from "../../../../command-internal/global-flags.ts"; import { dim } from "../../../../command-internal/colors.ts"; @@ -48,9 +53,16 @@ const select = ( id, service: creation.service, }); + // The owner records the shared API listener's requests once the stack has claimed its port. + const gateway: ReadonlyArray = definition.ports.some(({ key }) => key === "api") + ? [{ id: gatewayLog.instanceId, service: gatewayLog.service }] + : []; if (requested.length === 0) { const members = new Set(definition.composition.members.map(({ id }) => id)); - const selected = definition.instances.filter(({ id }) => members.has(id)).map(subject); + const selected = [ + ...definition.instances.filter(({ id }) => members.has(id)).map(subject), + ...gateway, + ]; return selected.length === 0 ? Effect.fail( new StackCommandLogsError({ @@ -63,17 +75,20 @@ const select = ( } const unmatched = requested.find( (value) => - !definition.instances.some(({ id, creation }) => id === value || creation.service === value), + !definition.instances.some( + ({ id, creation }) => id === value || creation.service === value, + ) && !gateway.some(({ service }) => service === value), ); if (unmatched !== undefined) return Effect.fail( new StackCommandLogsError({ reason: "flags", message: `No service matches ${unmatched}.` }), ); - return Effect.succeed( - definition.instances + return Effect.succeed([ + ...definition.instances .filter(({ id, creation }) => requested.includes(id) || requested.includes(creation.service)) .map(subject), - ); + ...gateway.filter(({ service }) => requested.includes(service)), + ]); }; export const stackLogs = Effect.fn("experimental.stack.logs")(function* (flags: StackLogsFlags) { @@ -177,13 +192,14 @@ export const stackLogs = Effect.fn("experimental.stack.logs")(function* (flags: ]), ); const streams = selected.flatMap(({ id, service }) => { - const handle = handles.get(id); - if (handle === undefined) return []; + const readLogs = + id === gatewayLog.instanceId ? stack.gateway.readLogs : handles.get(id)?.readLogs; + if (readLogs === undefined) return []; const from = printed.get(id); // Without history, the owner pins the start at its end under the writer's lock. const start = flags.tail === 0 ? { tail: 0 } : from === undefined ? {} : { from }; return [ - handle.readLogs({ follow: true, ...start, ...sinceTime }).pipe( + readLogs({ follow: true, ...start, ...sinceTime }).pipe( Stream.filter((record) => isAfter(record, from)), Stream.map((record): StackLogRecord => ({ ...record, service, instanceId: id })), ), diff --git a/apps/cli/src/commands/experimental/stack/logs/logs.integration.test.ts b/apps/cli/src/commands/experimental/stack/logs/logs.integration.test.ts index baedd7cdbf..b3221de3ba 100644 --- a/apps/cli/src/commands/experimental/stack/logs/logs.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/logs/logs.integration.test.ts @@ -96,6 +96,8 @@ const fixture = Effect.fn("StackLogsTest.fixture")(function* (options: { readonly stateRoot: string; readonly stackId: string; }) => ReadonlyArray>; + readonly ports?: SavedStack["ports"]; + readonly gatewayLogs?: (options?: ReadLogsOptions) => Stream.Stream; }) { const fs = yield* FileSystem.FileSystem; const path = yield* Path.Path; @@ -113,6 +115,7 @@ const fixture = Effect.fn("StackLogsTest.fixture")(function* (options: { const definition: SavedStack = { ...found.value.definition, instances: options.instances, + ports: options.ports ?? [], composition: { members: options.members.map((id) => ({ id, activation: "eager" as const })), dependencies: [], @@ -147,6 +150,7 @@ const fixture = Effect.fn("StackLogsTest.fixture")(function* (options: { ...stack.services, list: Effect.succeed(options.handles?.({ stateRoot, stackId: stack.id }) ?? []), }, + gateway: { readLogs: options.gatewayLogs ?? stack.gateway.readLogs }, }), ), }), @@ -435,6 +439,81 @@ describe("stack logs", () => { }).pipe(Effect.scoped, Effect.provide(live)), ); + const apiPort = [{ key: "api", host: "127.0.0.1", port: 54321 }]; + const request = + '127.0.0.1 - - [29/Sep/2026:10:00:00 +0000] "GET /rest/v1/ HTTP/1.1" 200 2 "-" "curl/8.7.1" 3ms'; + + it.live("includes the gateway's requests by default and selects them with --service", () => + Effect.gen(function* () { + const f = yield* fixture({ + instances: [mail("mail-a")], + members: ["mail-a"], + ports: apiPort, + }); + yield* f.writeSegment("mail", "mail-a", [launch(t0), line(t0 + 1, "stdout", "mail up")]); + yield* f.writeSegment("gateway", "gateway", [launch(t0), line(t0 + 2, "stdout", request)]); + + const all = yield* f.run({}); + const gateway = yield* f.run({ service: ["gateway"] }, "stream-json"); + + expect(lines(all.output.stdoutText).map((value) => value.replace(/\d{2}:\S+ /u, ""))).toEqual( + [ + "gateway | --- launch 1 ---", + "mail | --- launch 1 ---", + "mail | mail up", + `gateway | ${request}`, + ], + ); + expect(eventLines(gateway.output.events)).toEqual([request]); + expect(gateway.output.events.at(-1)).toMatchObject({ + service: "gateway", + instance_id: "gateway", + }); + }).pipe(Effect.scoped, Effect.provide(live)), + ); + + it.live("rejects --service gateway when the stack has no shared API listener", () => + Effect.gen(function* () { + const f = yield* fixture({ instances: [mail("mail-a")], members: ["mail-a"] }); + yield* f.writeSegment("mail", "mail-a", [launch(t0), line(t0 + 1, "stdout", "mail up")]); + + const selected = yield* f.run({ service: ["gateway"] }); + const all = yield* f.run({}, "stream-json"); + + expect(failure(selected.exit)).toMatchObject({ + reason: "flags", + message: "No service matches gateway.", + }); + expect(eventLines(all.output.events)).toEqual(["mail up"]); + }).pipe(Effect.scoped, Effect.provide(live)), + ); + + it.live("follows the gateway's new requests through the owner", () => + Effect.gen(function* () { + const f = yield* fixture({ + instances: [], + members: [], + ports: apiPort, + running: true, + gatewayLogs: () => + Stream.make({ + kind: "stdout" as const, + timestamp: iso(t0 + 100), + launchId: 1, + text: request, + position: { generation: 1, byteOffset: 1_000 }, + }), + }); + + const { exit, output } = yield* f.run({ follow: true, tail: 0 }, "stream-json"); + + expect(Exit.isSuccess(exit)).toBe(true); + expect(output.events).toEqual([ + expect.objectContaining({ service: "gateway", line: request, source: "live" }), + ]); + }).pipe(Effect.scoped, Effect.provide(live)), + ); + it.live("interrupts a follow and releases its subscriptions", () => Effect.gen(function* () { const subscribed = yield* Deferred.make(); diff --git a/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts b/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts index 352518aadb..c377fd3316 100644 --- a/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts @@ -157,6 +157,7 @@ const makeFixture = (root: string, options: FixtureOptions = {}) => { }, stop: Effect.void, destroy: Effect.succeed({ runtimeCleanup: "complete" as const }), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => Effect.die("unused") }, }; const output = mockOutput(); diff --git a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md index 0636d9e740..d55872ede0 100644 --- a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md +++ b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md @@ -41,7 +41,10 @@ The owner persists each service's output under `$SUPABASE_HOME/stacks/ most about 10 MiB (plus the segment being written) per service instance. Destroying an instance or the stack deletes those logs; stopping the stack and resetting database data keep them. PostgREST runs with `PGRST_LOG_LEVEL=info`, so every request line, query string included, is -persisted and shipped to Analytics. +persisted and shipped to Analytics. The shared API port also records one nginx combined line plus +duration (`... "GET /rest/v1/todos?select=* HTTP/1.1" 200 126 "-" "curl/8.7.1" 12ms`) per request +and WebSocket upgrade under `logs/gateway/gateway/`, with the same retention; `apikey`, +`access_token`, and `token` query values are written as `redacted`. When an owner starts a stack saved with a Vector instance, it removes that instance, its composition members, dependencies and port claims from `state.json`, and its stack-owned Vector config files under `data//runtime/vector/`; its containers go with the stack's container sweep. @@ -89,11 +92,12 @@ Studio requires REST; excluding REST while keeping Studio fails before stopping ## Service logs in Analytics -The owner ships the persisted Auth, REST, Realtime, Storage, Functions, and database output lines -(not launch or lost markers) to Analytics' `POST /api/logs` ingest endpoint on its direct backend, -using the Analytics API key and the legacy Logflare source names (`gotrue.logs.prod`, -`postgREST.logs.prod`, `realtime.logs.prod`, `storage.logs.prod.2`, `deno-relay-logs`, -`postgres.logs`) with the legacy per-service field remaps. This applies to the Docker, Podman, and +The owner ships the persisted Auth, REST, Realtime, Storage, Functions, database, and gateway +output lines (not launch or lost markers) to Analytics' `POST /api/logs` ingest endpoint on its +direct backend, using the Analytics API key and the legacy Logflare source names +(`gotrue.logs.prod`, `postgREST.logs.prod`, `realtime.logs.prod`, `storage.logs.prod.2`, +`deno-relay-logs`, `postgres.logs`, and `cloudflare.logs.prod` for Studio's API Gateway page) with +the legacy per-service field remaps. This applies to the Docker, Podman, and native runtimes. Shipping runs only while the composed Analytics service is running and healthy; each instance keeps its position in `logs///cursor.json`, so lines written while Analytics is stopped, starting, or unhealthy are shipped with their original timestamps once diff --git a/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts b/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts index b0b01e52d0..479a6963e5 100644 --- a/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts @@ -112,6 +112,7 @@ function makeDatabaseStack(sqlPort: number, credentials: StackCredentials): Stac }, stop: Effect.die("unused"), destroy: Effect.die("unused"), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => Effect.die("unused") }, } satisfies Stack; } diff --git a/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts b/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts index 91a1f0a761..5b0d9379a7 100644 --- a/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts @@ -352,6 +352,7 @@ const fakeStack = (compositionStart?: Stack["composition"]["start"]) => { hostDestroyed += 1; return { runtimeCleanup: "complete" as const }; }), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => Effect.die("command not used") }, }; return { diff --git a/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts b/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts index 3d2584df86..2abbb751c0 100644 --- a/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts @@ -176,6 +176,7 @@ const makeStack = ( }, stop: Effect.die("unused"), destroy: Effect.die("unused"), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: (_tool, _options) => Effect.die("unused"), }, diff --git a/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts b/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts index 16c710780e..e948fa0ac2 100644 --- a/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts +++ b/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts @@ -287,6 +287,7 @@ const fixture = ( }, stop: Effect.die("unused"), destroy: Effect.die("unused"), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => Effect.die("unused") }, } satisfies Stack; const identity = { projectRoot: "/project", branchContext: "main", stackName: "default" }; diff --git a/apps/cli/tests/helpers/storage.ts b/apps/cli/tests/helpers/storage.ts index 95cb7d9854..3e5b651316 100644 --- a/apps/cli/tests/helpers/storage.ts +++ b/apps/cli/tests/helpers/storage.ts @@ -263,6 +263,7 @@ export function buildStorageStackApi( }, stop: Effect.die("unused"), destroy: Effect.die("unused"), + gateway: { readLogs: () => Stream.die("unused") }, commands: { run: () => Effect.die("unused") }, }; const definition = { diff --git a/packages/stack/ARCHITECTURE.md b/packages/stack/ARCHITECTURE.md index 0d558590ce..34fe79f1f0 100644 --- a/packages/stack/ARCHITECTURE.md +++ b/packages/stack/ARCHITECTURE.md @@ -662,8 +662,16 @@ follow can resume at a record position, and a reader that finds its segment dele instances no longer saved, so a failed deletion is retried; destroying the stack removes `logs/`; resetting database data keeps them. +The shared API listener is the stack's gateway. Each completed request, and each WebSocket upgrade +once its handshake status is known, becomes one nginx combined line plus duration, with `apikey`, +`access_token` and `token` query values redacted. The proxy hands it to a bounded sliding buffer +after the response settles, so logging never delays a response or holds a target's activity. +The owner persists these lines as the `gateway` stream, `logs/gateway/gateway/`, with one launch +per owner run; it is not a service instance, so orphan cleanup keeps it. + While the composed Analytics instance is running and healthy, the owner ships the persisted -stdout/stderr records of Auth, REST, Realtime, Storage, Functions and database instances to its +stdout/stderr records of Auth, REST, Realtime, Storage, Functions and database instances, and of +the gateway stream as Studio's API Gateway source, to its direct backend (never the proxy, so shipping neither wakes it nor counts as activity), in bodies of at most 256 events and 1 MiB. Each instance reads from `cursor.json` in its logs directory, the position of its last shipped record, written atomically after each body settles: a missing cursor diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index 8e6398d412..42a2bea3bd 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1,6 +1,6 @@ import { NodeHttpClient, NodeServices } from "@effect/platform-node"; import { expect, it } from "@effect/vitest"; -import { Data, Deferred, Effect, Fiber, Layer } from "effect"; +import { Data, Deferred, Effect, Fiber, Layer, Queue } from "effect"; import { HttpClient, HttpClientRequest } from "effect/unstable/http"; import { createServer, type Server, type ServerResponse } from "node:http"; // oxlint-disable-line effecttsgo/node-builtin-import -- raw server fixture. import { createServer as createTcpServer, Socket, type Server as NetServer } from "node:net"; // oxlint-disable-line effecttsgo/node-builtin-import -- raw disconnect fixture. @@ -8,7 +8,7 @@ import { createServer as createTcpServer, Socket, type Server as NetServer } fro import { WebSocket, WebSocketServer } from "ws"; import { captureLogs } from "../tests/logs.ts"; import { ProxyError } from "./Proxy.ts"; -import { makeHttpProxy, type HttpRoute } from "./HttpProxy.ts"; +import { makeHttpProxy, type HttpAccess, type HttpRoute } from "./HttpProxy.ts"; const listen = (server: Server | NetServer, options?: { readonly beforeClose?: () => void }) => Effect.acquireRelease( @@ -1027,3 +1027,257 @@ it.live("releases a waiting WebSocket target quietly when its client resets", () }), ).pipe(Effect.provide(Layer.merge(NodeServices.layer, captureErrors(logs)))); }); + +/** Opens a raw client connection that has written `text`. */ +const rawClient = (port: number, text: string) => + Effect.acquireRelease( + Effect.callback((resume) => { + const socket = new Socket(); + socket.on("error", () => undefined); + socket.connect(port, "127.0.0.1", () => { + socket.write(text); + resume(Effect.succeed(socket)); + }); + }), + (socket) => Effect.sync(() => socket.destroy()), + ); + +const upgradeRequest = (path: string) => + `GET ${path} HTTP/1.1\r\nHost: localhost\r\nConnection: Upgrade\r\nUpgrade: websocket\r\n\r\n`; + +/** Sends a raw upgrade request and waits until the proxy closes the connection. */ +const rawUpgrade = (port: number, path: string) => + rawClient(port, upgradeRequest(path)).pipe( + Effect.flatMap((socket) => + Effect.callback((resume) => { + socket.once("close", () => resume(Effect.void)); + if (socket.destroyed) resume(Effect.void); + }), + ), + Effect.timeout("5 seconds"), + ); + +it.live("records each request once with the status the client was sent", () => { + const logs: Array = []; + return Effect.scoped( + Effect.gen(function* () { + const backend = createServer((request, response) => { + request.resume(); + if (request.url?.startsWith("/ok")) response.end("hello"); + else { + response.statusCode = 404; + response.end("nope"); + } + }); + const backendAddress = yield* listen(backend); + const accesses = yield* Queue.unbounded(); + const proxy = yield* makeHttpProxy({ + host: "127.0.0.1", + port: 0, + onAccess: (access) => Queue.offer(accesses, access), + }); + yield* proxy.setRoutes([ + { id: "api", prefix: "/api", upstreamPrefix: "/", target: Effect.succeed(backendAddress) }, + { + id: "down", + prefix: "/down", + target: Effect.fail(new ProxyError({ message: "wake failed" })), + }, + ]); + const get = (path: string, headers: Readonly> = {}) => + request(proxy.port, path, new Uint8Array(), headers, "GET").pipe( + Effect.map(({ status }) => status), + ); + + const statuses = [ + yield* get("/api/ok?select=*&apikey=sb_secret_x&Access_Token=jwt", { + "user-agent": "proxy-test/1", + referer: "http://studio.test/logs", + }), + yield* get("/api/missing"), + yield* get("/elsewhere"), + yield* get("/down/thing?token=t"), + ]; + const recorded = yield* Queue.takeN(accesses, 4); + + expect(statuses).toEqual([200, 404, 404, 502]); + expect(recorded.toSorted((left, right) => left.time - right.time)).toEqual([ + { + time: expect.any(Number), + client: "127.0.0.1", + method: "GET", + target: "/api/ok?select=*&apikey=redacted&Access_Token=redacted", + protocol: "HTTP/1.1", + status: 200, + bytes: 5, + referer: "http://studio.test/logs", + userAgent: "proxy-test/1", + durationMillis: expect.any(Number), + }, + expect.objectContaining({ target: "/api/missing", status: 404, bytes: 4 }), + expect.objectContaining({ target: "/elsewhere", status: 404, bytes: 9 }), + expect.objectContaining({ target: "/down/thing?token=redacted", status: 502, bytes: 11 }), + ]); + expect(yield* Queue.size(accesses)).toBe(0); + }), + ).pipe( + Effect.provide( + Layer.mergeAll(NodeHttpClient.layerNodeHttp, NodeServices.layer, captureErrors(logs)), + ), + ); +}); + +it.live("records WebSocket upgrades at the handshake with the status sent to the client", () => { + const logs: Array = []; + return Effect.scoped( + Effect.gen(function* () { + const backend = createServer(); + const sockets = new WebSocketServer({ server: backend }); + const backendAddress = yield* listen(backend, { beforeClose: () => sockets.close() }); + const upgradeReceived = yield* Deferred.make(); + const silent = createTcpServer((connection) => { + connection.on("error", () => undefined); + connection.once("data", () => Deferred.doneUnsafe(upgradeReceived, Effect.void)); + }); + const silentAddress = yield* listen(silent); + const accesses = yield* Queue.unbounded(); + const proxy = yield* makeHttpProxy({ + host: "127.0.0.1", + port: 0, + onAccess: (access) => Queue.offer(accesses, access), + }); + yield* proxy.setRoutes([ + { id: "ws", prefix: "/socket", target: Effect.succeed(backendAddress) }, + { id: "silent", prefix: "/silent", target: Effect.succeed(silentAddress) }, + { + id: "down", + prefix: "/down", + target: Effect.fail(new ProxyError({ message: "wake failed" })), + }, + ]); + const client = yield* Effect.acquireRelease( + Effect.callback((resume) => { + const socket = new WebSocket( + `ws://127.0.0.1:${proxy.port}/socket?apikey=sb_publishable_x&vsn=2.0.0`, + ); + socket.once("open", () => resume(Effect.succeed(socket))); + socket.once("error", (cause) => + resume(Effect.fail(new HttpProxyTestError({ message: cause.message, cause }))), + ); + }), + (socket) => Effect.sync(() => socket.terminate()), + ).pipe(Effect.timeout("5 seconds")); + + const opened = yield* Queue.take(accesses); + + expect(client.readyState).toBe(WebSocket.OPEN); + expect(opened).toMatchObject({ + method: "GET", + target: "/socket?apikey=redacted&vsn=2.0.0", + status: 101, + }); + expect(opened.bytes).toBeUndefined(); + + yield* rawUpgrade(proxy.port, "/elsewhere"); + expect(yield* Queue.take(accesses)).toMatchObject({ target: "/elsewhere", status: 404 }); + yield* rawUpgrade(proxy.port, "/down"); + expect(yield* Queue.take(accesses)).toMatchObject({ target: "/down", status: 502 }); + + const leaving = yield* rawClient(proxy.port, upgradeRequest("/silent")); + yield* Deferred.await(upgradeReceived); + leaving.destroy(); + expect(yield* Queue.take(accesses)).toMatchObject({ target: "/silent", status: 499 }); + }), + ).pipe(Effect.provide(Layer.merge(NodeServices.layer, captureErrors(logs)))); +}); + +it.live("records no body bytes for a client that left before its response completed", () => + Effect.scoped( + Effect.gen(function* () { + const backend = createServer((request, response) => { + request.resume(); + response.writeHead(200); + response.write("first chunk"); + }); + const backendAddress = yield* listen(backend, { + beforeClose: () => backend.closeAllConnections(), + }); + const acquiring = yield* Deferred.make(); + const accesses = yield* Queue.unbounded(); + const proxy = yield* makeHttpProxy({ + host: "127.0.0.1", + port: 0, + onAccess: (access) => Queue.offer(accesses, access), + }); + yield* proxy.setRoutes([ + { + id: "waking", + prefix: "/waking", + target: Deferred.succeed(acquiring, undefined).pipe(Effect.andThen(Effect.never)), + }, + { id: "streaming", prefix: "/streaming", target: Effect.succeed(backendAddress) }, + ]); + + const waiting = yield* rawClient( + proxy.port, + "GET /waking HTTP/1.1\r\nHost: localhost\r\n\r\n", + ); + yield* Deferred.await(acquiring); + waiting.destroy(); + const beforeHeaders = yield* Queue.take(accesses).pipe(Effect.timeout("5 seconds")); + const reading = yield* rawClient( + proxy.port, + "GET /streaming HTTP/1.1\r\nHost: localhost\r\n\r\n", + ); + yield* Effect.callback((resume) => { + reading.once("data", () => resume(Effect.void)); + }); + reading.destroy(); + const midBody = yield* Queue.take(accesses).pipe(Effect.timeout("5 seconds")); + + expect(beforeHeaders).toMatchObject({ target: "/waking", status: 499 }); + expect(beforeHeaders.bytes).toBeUndefined(); + expect(midBody).toMatchObject({ target: "/streaming", status: 200 }); + expect(midBody.bytes).toBeUndefined(); + }), + ).pipe(Effect.provide(NodeServices.layer)), +); + +it.live("answers and releases targets while the access sink is stalled", () => + Effect.scoped( + Effect.gen(function* () { + const backend = createServer((request, response) => { + request.resume(); + response.end("ok"); + }); + const backendAddress = yield* listen(backend); + const released = yield* Queue.unbounded(); + const proxy = yield* makeHttpProxy({ + host: "127.0.0.1", + port: 0, + onAccess: () => Effect.never, + }); + yield* proxy.setRoutes([ + { + id: "api", + prefix: "/api", + target: Effect.acquireRelease(Effect.succeed(backendAddress), () => + Queue.offer(released, undefined), + ), + }, + ]); + + const statuses = yield* Effect.forEach( + Array.from({ length: 20 }, (_, index) => `/api/${index}`), + (path) => + request(proxy.port, path, new Uint8Array(), {}, "GET").pipe( + Effect.map(({ status }) => status), + ), + { concurrency: 5 }, + ).pipe(Effect.timeout("10 seconds")); + + expect(statuses).toEqual(Array.from({ length: 20 }, () => 200)); + expect(yield* Queue.takeN(released, 20).pipe(Effect.timeout("5 seconds"))).toHaveLength(20); + }), + ).pipe(Effect.provide(Layer.merge(NodeHttpClient.layerNodeHttp, NodeServices.layer))), +); diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index d2ae57d119..2af6364346 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -1,4 +1,4 @@ -import { Data, Effect, FiberSet, Ref, Scope } from "effect"; +import { Clock, Data, Deferred, Effect, Fiber, FiberSet, Ref, Scope } from "effect"; import { PortError } from "./Ports.ts"; import type { BackendAddress, ProxyError } from "./Proxy.ts"; import { @@ -41,6 +41,32 @@ interface HttpRouteKeyRewrite { }; } +/** One request or WebSocket upgrade the proxy completed. */ +export interface HttpAccess { + /** Epoch milliseconds when the request arrived. */ + readonly time: number; + readonly client: string; + readonly method: string; + /** The request path and query, with credential query values redacted. */ + readonly target: string; + readonly protocol: string; + /** + * The recorded outcome: the status sent, or 499 when the client left before a response. An + * upgrade records the upstream handshake status; without one, 404 for no route and 502 for a + * failure, while the client sees its socket reset. + */ + readonly status: number; + /** Body bytes of a response that finished; absent when it was cut short, and for upgrades. */ + readonly bytes?: number; + readonly referer?: string; + readonly userAgent?: string; + /** Until the response finished; for an upgrade, until the upstream handshake answered. */ + readonly durationMillis: number; +} + +/** Receives each completed request after its response; it must not block. */ +export type HttpAccessSink = (access: HttpAccess) => Effect.Effect; + export interface HttpProxy { readonly host: string; readonly port: number; @@ -125,6 +151,73 @@ const decodeQuery = (value: string) => { } }; +const credentialParameters = new Set(["apikey", "access_token", "token"]); + +const redactCredentials = (url: string) => { + const queryAt = url.indexOf("?"); + if (queryAt < 0) return url; + const query = url + .slice(queryAt + 1) + .split("&") + .map((parameter) => { + const separator = parameter.indexOf("="); + if (separator < 0) return parameter; + const name = parameter.slice(0, separator); + return credentialParameters.has(decodeQuery(name).toLowerCase()) + ? `${name}=redacted` + : parameter; + }) + .join("&"); + return `${url.slice(0, queryAt)}?${query}`; +}; + +/** Captures a request's access fields while its socket is open; completes them once it settles. */ +const accessFor = (request: IncomingMessage, time: number) => { + const referer = headerValue(request.headers.referer); + const userAgent = headerValue(request.headers["user-agent"]); + const fields = { + time, + client: request.socket.remoteAddress ?? "-", + method: request.method ?? "GET", + target: redactCredentials(request.url ?? "/"), + protocol: `HTTP/${request.httpVersion}`, + ...(referer === undefined ? {} : { referer }), + ...(userAgent === undefined ? {} : { userAgent }), + }; + return (ended: number, status: number, bytes?: number): HttpAccess => ({ + ...fields, + status, + ...(bytes === undefined ? {} : { bytes }), + durationMillis: Math.max(0, ended - time), + }); +}; + +/** What one request's client was sent. */ +interface Sent { + /** Body bytes handed to the response. */ + bytes: number; + /** The client went away before the response completed. */ + clientLeft: boolean; +} + +const respond = (response: ServerResponse, sent: Sent, status: number, body?: string) => { + response.statusCode = status; + sent.bytes = body === undefined ? 0 : Buffer.byteLength(body); + response.end(body); +}; + +const responseSettled = (response: ServerResponse) => + Effect.callback((resume) => { + const onDone = () => resume(Effect.void); + response.once("finish", onDone); + response.once("close", onDone); + if (response.writableFinished || response.destroyed) onDone(); + return Effect.sync(() => { + response.off("finish", onDone); + response.off("close", onDone); + }); + }); + const queryValueFor = (value: string, keys: HttpRouteKeyRewrite["keys"]) => value === keys.secretKey ? keys.serviceRoleKey @@ -247,6 +340,7 @@ const forward = Effect.fn("HttpProxy.forward")( route: HttpRoute, backend: BackendAddress, agent: Agent | false, + sent: Sent, ) => Effect.callback((resume) => { let outgoing: ReturnType | undefined; @@ -296,6 +390,9 @@ const forward = Effect.fn("HttpProxy.forward")( incoming = value; value.once("aborted", onError); value.on("error", onError); + value.on("data", (chunk: Buffer) => { + sent.bytes += chunk.length; + }); response.once("finish", onFinish); setCors(response, request); response.statusCode = value.statusCode ?? 502; @@ -323,22 +420,43 @@ const forward = Effect.fn("HttpProxy.forward")( ); const proxyRequest = Effect.fn("HttpProxy.proxyRequest")( - (request: IncomingMessage, response: ServerResponse, route: HttpRoute, agent: Agent) => + ( + request: IncomingMessage, + response: ServerResponse, + route: HttpRoute, + agent: Agent, + sent: Sent, + ) => Effect.gen(function* () { const backend = yield* Effect.raceFirst(route.target, disconnected(request, response)); - yield* forward(request, response, route, backend, isReplayable(request) ? agent : false).pipe( + yield* forward( + request, + response, + route, + backend, + isReplayable(request) ? agent : false, + sent, + ).pipe( Effect.catchIf(isRetryable(request, response), (error) => Effect.logWarning( `Route ${route.id} ${request.method ?? "GET"} upstream failed before responding, retrying`, error, - ).pipe(Effect.andThen(forward(request, response, route, backend, false))), + ).pipe(Effect.andThen(forward(request, response, route, backend, false, sent))), ), ); }), ); +const statusLine = /^HTTP\/\d(?:\.\d)? (\d{3})\b/u; + const upgrade = Effect.fn("HttpProxy.upgrade")( - (request: IncomingMessage, client: Duplex, head: Buffer, route: HttpRoute) => + ( + request: IncomingMessage, + client: Duplex, + head: Buffer, + route: HttpRoute, + handshake: Deferred.Deferred, + ) => Effect.gen(function* () { const backend = yield* Effect.raceFirst( route.target, @@ -352,12 +470,14 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( const upstream = yield* connectInterruptibly(backend); yield* Effect.callback((resume) => { let settled = false; + let answer = ""; const cleanup = () => { - client.off("close", onClose); + client.off("close", onClientClose); upstream.off("close", onClose); client.off("end", onClientEnd); upstream.off("end", onUpstreamEnd); + upstream.off("data", onAnswer); }; const finish = (result: Effect.Effect) => { if (settled) return; @@ -373,10 +493,21 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( const onError = (cause: Error) => abandon(Effect.fail(errorFor(cause))); const onClientGone = () => abandon(Effect.fail(new HttpProxyDisconnected())); const onClose = () => abandon(Effect.void); + // A client leaving before the upstream answered never received a response. + const onClientClose = () => (Deferred.isDoneUnsafe(handshake) ? onClose() : onClientGone()); const onClientEnd = () => upstream.end(); const onUpstreamEnd = () => client.end(); + // Reads the handshake status off the bytes relayed to the client. + const onAnswer = (chunk: Buffer) => { + answer += chunk.toString("latin1"); + if (!answer.includes("\r\n") && answer.length < 64) return; + upstream.off("data", onAnswer); + const status = statusLine.exec(answer)?.[1]; + if (status !== undefined) Deferred.doneUnsafe(handshake, Effect.succeed(Number(status))); + }; + upstream.on("data", onAnswer); client.on("error", onClientGone); - client.once("close", onClose); + client.once("close", onClientClose); upstream.on("error", onError); upstream.once("close", onClose); client.once("end", onClientEnd); @@ -404,6 +535,7 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( export const makeHttpProxy = (options: { readonly host: string; readonly port: number; + readonly onAccess?: HttpAccessSink; }): Effect.Effect => Effect.gen(function* () { const routes = yield* Ref.make>([]); @@ -415,42 +547,54 @@ export const makeHttpProxy = (options: { ); const runRequest = yield* FiberSet.makeRuntime(); const sockets = new Set(); + const onAccess = options.onAccess; const server = createServer((request, response) => { runRequest( - Effect.scoped( - Effect.gen(function* () { - const route = yield* Ref.get(routes).pipe( - Effect.map((current) => routeFor(request.url ?? "/", current)), - ); - setCors(response, request); - if (request.method === "OPTIONS") { - response.statusCode = 204; - response.end(); - } else if (route === undefined) { - response.statusCode = 404; - response.end("Not Found"); - } else { - yield* proxyRequest(request, response, route, agent).pipe( - Effect.tapError((cause) => - cause._tag === "HttpProxyDisconnected" - ? Effect.void - : Effect.logError(`Route ${route.id} request failed`, cause), - ), - Effect.catch(() => - Effect.sync(() => { - if (response.destroyed) return; - if (response.headersSent) response.destroy(); - else { - setCors(response, request); - response.statusCode = 502; - response.end("Bad Gateway"); - } - }), - ), + Effect.gen(function* () { + const complete = accessFor(request, yield* Clock.currentTimeMillis); + const sent: Sent = { bytes: 0, clientLeft: false }; + // The access record waits outside this scope, so it never holds the target's activity. + yield* Effect.scoped( + Effect.gen(function* () { + const route = yield* Ref.get(routes).pipe( + Effect.map((current) => routeFor(request.url ?? "/", current)), ); - } - }), - ), + setCors(response, request); + if (request.method === "OPTIONS") respond(response, sent, 204); + else if (route === undefined) respond(response, sent, 404, "Not Found"); + else { + yield* proxyRequest(request, response, route, agent, sent).pipe( + Effect.tapError((cause) => + cause._tag === "HttpProxyDisconnected" + ? Effect.void + : Effect.logError(`Route ${route.id} request failed`, cause), + ), + Effect.catch((cause) => + Effect.sync(() => { + if (cause._tag === "HttpProxyDisconnected") sent.clientLeft = true; + if (response.destroyed) return; + if (response.headersSent || sent.clientLeft) response.destroy(); + else { + setCors(response, request); + respond(response, sent, 502, "Bad Gateway"); + } + }), + ), + ); + } + }), + ); + if (onAccess === undefined) return; + yield* responseSettled(response); + const delivered = response.writableFinished && !sent.clientLeft; + yield* onAccess( + complete( + yield* Clock.currentTimeMillis, + response.headersSent ? response.statusCode : 499, + delivered ? sent.bytes : undefined, + ), + ); + }), ); }); server.on("connection", (socket) => { @@ -460,23 +604,47 @@ export const makeHttpProxy = (options: { server.on("upgrade", (request, socket, head) => { socket.on("error", () => socket.destroy()); runRequest( - Effect.scoped( - Effect.gen(function* () { - const route = yield* Ref.get(routes).pipe( - Effect.map((current) => routeFor(request.url ?? "/", current)), - ); - if (route === undefined) socket.destroy(); - else - yield* upgrade(request, socket, head, route).pipe( - Effect.tapError((cause) => - cause._tag === "HttpProxyDisconnected" - ? Effect.void - : Effect.logError(`Route ${route.id} upgrade failed`, cause), - ), - Effect.catch(() => Effect.sync(() => socket.destroy())), - ); - }), - ), + Effect.gen(function* () { + const complete = accessFor(request, yield* Clock.currentTimeMillis); + // Completed by the upstream's handshake status, otherwise by the upgrade's outcome. + const handshake = yield* Deferred.make(); + const recorded = + onAccess === undefined + ? undefined + : yield* Deferred.await(handshake).pipe( + Effect.flatMap((status) => + Clock.currentTimeMillis.pipe( + Effect.flatMap((ended) => onAccess(complete(ended, status))), + ), + ), + Effect.forkChild({ startImmediately: true }), + ); + const route = yield* Ref.get(routes).pipe( + Effect.map((current) => routeFor(request.url ?? "/", current)), + ); + const outcome = + route === undefined + ? yield* Effect.sync(() => { + socket.destroy(); + return 404; + }) + : yield* Effect.scoped(upgrade(request, socket, head, route, handshake)).pipe( + Effect.as(502), + Effect.tapError((cause) => + cause._tag === "HttpProxyDisconnected" + ? Effect.void + : Effect.logError(`Route ${route.id} upgrade failed`, cause), + ), + Effect.catch((cause) => + Effect.sync(() => { + socket.destroy(); + return cause._tag === "HttpProxyDisconnected" ? 499 : 502; + }), + ), + ); + yield* Deferred.succeed(handshake, outcome); + if (recorded !== undefined) yield* Fiber.join(recorded); + }), ); }); yield* Effect.acquireRelease( diff --git a/packages/stack/src/Network.ts b/packages/stack/src/Network.ts index bb80763509..7f13dbaafc 100644 --- a/packages/stack/src/Network.ts +++ b/packages/stack/src/Network.ts @@ -3,7 +3,7 @@ import { DOCKER_HOST_ALIAS } from "./runtime/Container.ts"; import * as State from "./State.ts"; import { makePorts, PortError } from "./Ports.ts"; import { bindTcp, serveTcp, type BackendAddress, type ProxyError } from "./Proxy.ts"; -import { makeHttpProxy, type HttpProxy, type HttpRoute } from "./HttpProxy.ts"; +import { makeHttpProxy, type HttpAccessSink, type HttpProxy, type HttpRoute } from "./HttpProxy.ts"; export type NetworkRuntime = "native" | "docker" | "podman"; @@ -70,6 +70,7 @@ const makeNetwork = (options: { readonly stackId: string; readonly runtime: NetworkRuntime; readonly state: State.Interface; + readonly onAccess?: HttpAccessSink; }) => Effect.gen(function* () { const ports = yield* makePorts(options.state).pipe( @@ -174,7 +175,15 @@ const makeNetwork = (options: { }); return { proxy: current.proxy }; } - return { proxy: yield* makeHttpProxy({ host, port }) }; + return { + proxy: yield* makeHttpProxy({ + host, + port, + ...(options.onAccess === undefined + ? {} + : { onAccess: options.onAccess }), + }), + }; } if (endpoint.protocol === "http") { const proxy = yield* makeHttpProxy({ host, port }); @@ -341,7 +350,12 @@ const makeNetwork = (options: { return { register, release: release() } satisfies Interface; }); -export const layer = (options: { readonly stackId: string; readonly runtime: NetworkRuntime }) => +export const layer = (options: { + readonly stackId: string; + readonly runtime: NetworkRuntime; + /** Receives the shared API listener's completed requests. */ + readonly onAccess?: HttpAccessSink; +}) => Layer.effect( Service, Effect.gen(function* () { diff --git a/packages/stack/src/Owner.analytics.integration.test.ts b/packages/stack/src/Owner.analytics.integration.test.ts index 61dfe7c031..9b71be5a8d 100644 --- a/packages/stack/src/Owner.analytics.integration.test.ts +++ b/packages/stack/src/Owner.analytics.integration.test.ts @@ -201,6 +201,16 @@ it.live( timestamp: expect.any(String), }, ]); + expect( + yield* awaitStored( + "cloudflare.logs.prod", + `body->'metadata'->'request'->>'path' LIKE '%${restPath}' AND body->'metadata'->'response'->>'status_code' = '404'`, + ), + ).toEqual([ + expect.objectContaining({ + message: expect.stringContaining(`${restPath} HTTP/1.1" 404 `), + }), + ]); yield* Fiber.interrupt(keeper); const noise = yield* Effect.forkScoped( diff --git a/packages/stack/src/Owner.logs.integration.test.ts b/packages/stack/src/Owner.logs.integration.test.ts index 684eebfbc6..cd7ccafc0e 100644 --- a/packages/stack/src/Owner.logs.integration.test.ts +++ b/packages/stack/src/Owner.logs.integration.test.ts @@ -13,6 +13,7 @@ import { Scope, Stream, } from "effect"; +import { HttpClient } from "effect/unstable/http"; import { tmpdir } from "node:os"; import { ownerFor } from "../tests/owner-rpc.ts"; import type { LogRecord } from "./host/LogRecord.ts"; @@ -147,6 +148,61 @@ describe("owner persisted logs", () => { ).pipe(Effect.provide(services)), ); + it.live("keeps shared API requests as gateway logs across owner restarts until destroy", () => + Effect.scoped( + Effect.gen(function* () { + const fs = yield* FileSystem.FileSystem; + const path = yield* Path.Path; + const client = yield* HttpClient.HttpClient; + const root = yield* fs.makeTempDirectoryScoped({ prefix: "owner-logs-gateway-" }); + const firstScope = yield* Scope.make(); + const first = yield* openOwner("owner-logs-gateway-", "native", { root }).pipe( + Scope.provide(firstScope), + ); + const rest = yield* first.rpc.createService({ + service: "rest", + config: {}, + endpoints: { http: { port: "auto" } }, + }); + yield* first.rpc.configureComposition({ + members: [{ id: rest.id, activation: "lazy" }], + dependencies: [], + }); + yield* first.rpc.startComposition(); + const api = (yield* first.state.read(first.stack.id))?.ports.find( + ({ key }) => key === "api", + ); + if (api === undefined) return yield* Effect.die("the shared API port was not claimed"); + + const response = yield* client.get(`http://127.0.0.1:${api.port}/unrouted?apikey=k`); + const [recorded] = yield* firstOutput(first.rpc.readLogs({ id: "gateway", follow: true })); + + expect(response.status).toBe(404); + expect(recorded?.text).toMatch( + /^127\.0\.0\.1 - - \[[^\]]+\] "GET \/unrouted\?apikey=redacted HTTP\/1\.1" 404 9 "-" "[^"]*" \d+ms$/u, + ); + const directory = path.join(first.logsRoot, "gateway", "gateway"); + expect(yield* fs.readDirectory(directory)).toEqual(["0000000001.log"]); + yield* Scope.close(firstScope, Exit.void); + + const state = Context.get( + yield* Layer.build(State.layer({ root: first.stateRoot })), + State.Service, + ); + const saved = yield* state.read(first.stack.id); + if (saved === undefined) return yield* Effect.die("the stopped stack was not saved"); + const second = yield* ownerFor({ saved, state, root: `${root}/data`, cacheRoot }); + const history = Array.from( + yield* second.rpc.readLogs({ id: "gateway", follow: false }).pipe(Stream.runCollect), + ); + + expect(history).toContainEqual(recorded); + yield* second.namespace.destroy; + expect(yield* fs.exists(first.logsRoot)).toBe(false); + }), + ).pipe(Effect.provide(services)), + ); + it.live("resumes a follow at a record position without replaying earlier records", () => Effect.scoped( Effect.gen(function* () { diff --git a/packages/stack/src/Owner.ts b/packages/stack/src/Owner.ts index 4ffb5dbe11..877e1308c5 100644 --- a/packages/stack/src/Owner.ts +++ b/packages/stack/src/Owner.ts @@ -67,6 +67,7 @@ import { stackError, type OwnerRpc } from "./Rpc.ts"; import * as State from "./State.ts"; import type { SavedStack, StackCredentials, StackKeysInput } from "./State.ts"; import { makeDockerHelperRegistry } from "./storage/DockerHelperRegistry.ts"; +import * as GatewayLog from "./host/GatewayLog.ts"; import * as LogForwarder from "./host/LogForwarder.ts"; import * as LogStore from "./host/LogStore.ts"; @@ -171,7 +172,10 @@ const withoutInstance = (current: SavedStack, id: string): SavedStack => const drainingBlocks: ReadonlyArray = ["start", "arm", "restart", "storage"]; -const makeOwner = Effect.fn("Owner.make")(function* (options: OwnerOptions) { +const makeOwner = Effect.fn("Owner.make")(function* ( + options: OwnerOptions, + gateway: GatewayLog.GatewayLog, +) { const services = yield* Effect.context< | FileSystem.FileSystem | Path.Path @@ -193,6 +197,15 @@ const makeOwner = Effect.fn("Owner.make")(function* (options: OwnerOptions) { composition: orchestrator.composition, logs: logStore, }).pipe(Effect.provideContext(services)); + yield* logStore.attach({ + ...GatewayLog.gatewayLog, + logs: gateway.logs, + observation: gateway.observation, + }); + yield* forwarder.attach({ + id: GatewayLog.gatewayLog.instanceId, + service: GatewayLog.gatewayLog.service, + }); const definitionGate = yield* Semaphore.make(1); const draining = yield* Ref.make(false); const { id: stackId, runtime } = options.saved; @@ -753,17 +766,24 @@ const makeOwner = Effect.fn("Owner.make")(function* (options: OwnerOptions) { }); export const layer = (options: Omit) => - Layer.effect( - Service, - Effect.gen(function* () { - const state = yield* State.Service; - return Service.of(yield* makeOwner({ ...options, state })); - }), - ).pipe( - Layer.provide( - Network.layer({ - stackId: options.saved.id, - runtime: options.saved.runtime, - }), + Layer.unwrap( + GatewayLog.make.pipe( + Effect.map((gateway) => + Layer.effect( + Service, + Effect.gen(function* () { + const state = yield* State.Service; + return Service.of(yield* makeOwner({ ...options, state }, gateway)); + }), + ).pipe( + Layer.provide( + Network.layer({ + stackId: options.saved.id, + runtime: options.saved.runtime, + onAccess: gateway.record, + }), + ), + ), + ), ), ); diff --git a/packages/stack/src/effect.ts b/packages/stack/src/effect.ts index b8ab3d857d..94ff330d83 100644 --- a/packages/stack/src/effect.ts +++ b/packages/stack/src/effect.ts @@ -50,6 +50,7 @@ import { sinceMillis, streamStackLogs as streamPersistedLogs, } from "./host/LogStore.ts"; +import { gatewayLog } from "./host/GatewayLog.ts"; import type { LogPosition, LogRecord, StackLogRecord } from "./host/LogRecord.ts"; import { reclaimStack } from "./Sweep.ts"; import { @@ -69,6 +70,7 @@ import type { export { initialization, postgres } from "./Commands.ts"; export { resolveNativePostgresUser } from "./runtime/postgres-user.ts"; export { apiRoute } from "./host/Endpoints.ts"; +export { gatewayLog }; export { StackError } from "./Rpc.ts"; export type { ServiceCreation } from "./services/Catalog.ts"; /** A service creation as `services.create` accepts it, before stack credentials fill its inputs. */ @@ -279,6 +281,10 @@ export interface Stack { readonly stop: Effect.Effect, StackError>; readonly restart: Effect.Effect, StackError>; }; + /** The shared API listener's access log, read through the live owner like an instance's. */ + readonly gateway: { + readonly readLogs: (options?: ReadLogsOptions) => Stream.Stream; + }; readonly stop: Effect.Effect; readonly destroy: Effect.Effect; readonly commands: { @@ -640,6 +646,18 @@ const makeHandle = Effect.fn("Stack.makeHandle")(function* ( const snapshotScope = (options: DatabaseSnapshotOptions | undefined) => options?.scope === undefined ? {} : { scope: options.scope }; + const readLogs = + (id: string) => + (options?: ReadLogsOptions): Stream.Stream => + stream("readLogs", (rpc) => + rpc.readLogs({ + id, + follow: options?.follow ?? false, + ...(options?.from === undefined ? {} : { from: options.from }), + ...(options?.since === undefined ? {} : { since: options.since }), + ...(options?.tail === undefined ? {} : { tail: options.tail }), + }), + ); const common = (id: string, service: K): ServiceInstance => ({ id, service, @@ -661,16 +679,7 @@ const makeHandle = Effect.fn("Stack.makeHandle")(function* ( prepare: call("prepare", (rpc) => rpc.prepareService({ id })), status: call("status", (rpc) => rpc.status({ id }), "attach"), followStatus: stream("followStatus", (rpc) => rpc.followStatus({ id })), - readLogs: (options) => - stream("readLogs", (rpc) => - rpc.readLogs({ - id, - follow: options?.follow ?? false, - ...(options?.from === undefined ? {} : { from: options.from }), - ...(options?.since === undefined ? {} : { since: options.since }), - ...(options?.tail === undefined ? {} : { tail: options.tail }), - }), - ), + readLogs: readLogs(id), credentials: (options) => call("credentials", (rpc) => rpc.credentials({ id, from: options?.from ?? "host" })), }); @@ -915,6 +924,7 @@ const makeHandle = Effect.fn("Stack.makeHandle")(function* ( stop: whileRunning("stopComposition", (rpc) => rpc.stopComposition(), []), restart: call("restartComposition", (rpc) => rpc.restartComposition()), }, + gateway: { readLogs: readLogs(gatewayLog.instanceId) }, stop: shutdown(false).pipe(Effect.asVoid), destroy: shutdown(true), commands: { run }, diff --git a/packages/stack/src/host/GatewayLog.ts b/packages/stack/src/host/GatewayLog.ts new file mode 100644 index 0000000000..91e98d5713 --- /dev/null +++ b/packages/stack/src/host/GatewayLog.ts @@ -0,0 +1,63 @@ +import { DateTime, Effect, PubSub, Stream } from "effect"; +import type { HttpAccess, HttpAccessSink } from "../HttpProxy.ts"; +import { launchOutputPublisher, type LaunchOutput } from "../runtime/Session.ts"; +import type { CatalogLogs } from "../services/Recipe.ts"; + +/** The log stream of the shared API listener's access records, one per owner and stack. */ +export const gatewayLog = { service: "gateway", instanceId: "gateway" } as const; + +/** Bounds records not yet persisted; the oldest are dropped and reported as lost. */ +const bufferedRecords = 4096; + +const monthNames = [ + "Jan", + "Feb", + "Mar", + "Apr", + "May", + "Jun", + "Jul", + "Aug", + "Sep", + "Oct", + "Nov", + "Dec", +]; +const two = (value: number) => String(value).padStart(2, "0"); + +/** Formats epoch milliseconds as nginx's `$time_local` in UTC. */ +const nginxTime = (millis: number) => { + const parts = DateTime.toPartsUtc(DateTime.makeUnsafe(millis)); + return `${two(parts.day)}/${monthNames[parts.month - 1]}/${parts.year}:${two(parts.hour)}:${two(parts.minute)}:${two(parts.second)} +0000`; +}; + +/** Escapes quotes, backslashes and control characters like nginx's default log escaping. */ +const escape = (value: string) => + value.replace( + // oxlint-disable-next-line no-control-regex -- control characters are what this escapes. + /["\\\u0000-\u001f\u007f]/gu, + (character) => `\\x${character.charCodeAt(0).toString(16).padStart(2, "0")}`, + ); + +/** Formats an access record as an nginx combined log line followed by its duration. */ +export const formatAccess = (access: HttpAccess) => + `${access.client} - - [${nginxTime(access.time)}] "${escape(`${access.method} ${access.target} ${access.protocol}`)}" ${access.status} ${access.bytes ?? "-"} "${escape(access.referer ?? "-")}" "${escape(access.userAgent ?? "-")}" ${access.durationMillis}ms`; + +const encoder = new TextEncoder(); + +/** The gateway stream's output, its access sink, and an observation of one launch per owner run. */ +export interface GatewayLog { + readonly logs: CatalogLogs; + readonly record: HttpAccessSink; + readonly observation: Stream.Stream<{ readonly launchId: number }>; +} + +export const make = Effect.gen(function* () { + const output = yield* PubSub.sliding(bufferedRecords); + const publish = yield* (yield* launchOutputPublisher(output, 1)).part; + return { + logs: PubSub.subscribe(output), + record: (access) => publish("stdout", encoder.encode(`${formatAccess(access)}\n`)), + observation: Stream.make({ launchId: 1 }).pipe(Stream.concat(Stream.never)), + } satisfies GatewayLog; +}); diff --git a/packages/stack/src/host/LogForwarder.integration.test.ts b/packages/stack/src/host/LogForwarder.integration.test.ts index 6b6ae7e775..0c382e20fc 100644 --- a/packages/stack/src/host/LogForwarder.integration.test.ts +++ b/packages/stack/src/host/LogForwarder.integration.test.ts @@ -18,6 +18,7 @@ import { import type { ServiceObservation } from "../Service.ts"; import type { LaunchOutput } from "../runtime/Session.ts"; import { CatalogError } from "../services/Recipe.ts"; +import * as GatewayLog from "./GatewayLog.ts"; import type { LogRecord } from "./LogRecord.ts"; import * as LogForwarder from "./LogForwarder.ts"; import * as LogStore from "./LogStore.ts"; @@ -190,10 +191,12 @@ const composition = Effect.succeed({ /** Starts a forwarder in its own scope so a test can stop it like an owner. */ const startForwarder = ( store: LogStore.Interface, - instances: ReadonlyArray, + instances: ReadonlyArray, ) => Effect.gen(function* () { const scope = yield* Scope.make(); + // Stops before the test's store and temp directory close, so no cursor write races removal. + yield* Effect.addFinalizer(() => Scope.close(scope, Exit.void)); const forwarder = yield* LogForwarder.make({ composition, logs: store }).pipe( Scope.provide(scope), ); @@ -389,4 +392,51 @@ describe("LogForwarder", () => { ); }).pipe(Effect.scoped, Effect.provide(layer)), ); + + it.live("ships gateway access lines to the API Gateway source", () => + Effect.gen(function* () { + const { store, sink, analytics } = yield* fixture(); + const gateway = yield* GatewayLog.make; + yield* store.attach({ + ...GatewayLog.gatewayLog, + logs: gateway.logs, + observation: gateway.observation, + }); + yield* analytics.set(true); + yield* startForwarder(store, [ + analytics.instance, + { id: GatewayLog.gatewayLog.instanceId, service: GatewayLog.gatewayLog.service }, + ]); + + yield* gateway.record({ + time: Date.parse("2026-10-01T09:25:23.000Z"), + client: "127.0.0.1", + method: "POST", + target: "/auth/v1/token?grant_type=password", + protocol: "HTTP/1.1", + status: 400, + bytes: 60, + durationMillis: 3, + }); + const shipped = yield* sink.next; + + expect(shipped.url).toBe("/api/logs?source_name=cloudflare.logs.prod"); + expect(shipped.events).toEqual([ + expect.objectContaining({ + appname: "gateway", + timestamp: "2026-10-01T09:25:23.000Z", + metadata: { + request: { + method: "POST", + path: "/auth/v1/token", + search: "?grant_type=password", + protocol: "HTTP/1.1", + headers: { cf_connecting_ip: "127.0.0.1" }, + }, + response: { status_code: 400 }, + }, + }), + ]); + }).pipe(Effect.scoped, Effect.provide(layer)), + ); }); diff --git a/packages/stack/src/host/LogForwarder.ts b/packages/stack/src/host/LogForwarder.ts index 9f81111cca..8bc2fbbfb3 100644 --- a/packages/stack/src/host/LogForwarder.ts +++ b/packages/stack/src/host/LogForwarder.ts @@ -27,6 +27,7 @@ import { type LogflareEvent, type ShippedService, } from "./LogflareEvents.ts"; +import type { gatewayLog } from "./GatewayLog.ts"; import { LogPosition, type LogRecord } from "./LogRecord.ts"; import type * as LogStore from "./LogStore.ts"; @@ -39,9 +40,15 @@ export interface ForwardedInstance { readonly observation: Stream.Stream>; } +/** An owner log stream without a service instance; it ships while the owner runs. */ +export interface ForwardedStream { + readonly id: string; + readonly service: typeof gatewayLog.service; +} + interface Interface { /** Ships a shipped service's persisted logs, or tracks an Analytics instance as the target. */ - readonly attach: (instance: ForwardedInstance) => Effect.Effect; + readonly attach: (instance: ForwardedInstance | ForwardedStream) => Effect.Effect; /** Re-selects the shipping target after the composition changes. */ readonly rebind: Effect.Effect; /** Emits whether records are currently shipped; the current value first. */ @@ -372,25 +379,29 @@ export const make = Effect.fn("LogForwarder.make")(function* (options: LogForwar Stream.runDrain, ); - const forward = (instance: ForwardedInstance, service: ShippedService) => + const forward = (id: string, service: ShippedService, until: Effect.Effect) => Effect.gen(function* () { const current = yield* serving; // A stopped target pauses shipping; the cursor keeps the position to resume from. - yield* session(instance.id, service, current).pipe( + yield* session(id, service, current).pipe( Effect.catch((error) => (error._tag === "StaleTarget" ? Effect.void - : Effect.logWarning(`Log shipping of ${instance.id} paused`, error) + : Effect.logWarning(`Log shipping of ${id} paused`, error) ).pipe(Effect.andThen(retargeted(current))), ), Effect.raceFirst(retargeted(current)), ); - }).pipe(Effect.forever, Effect.raceFirst(unregistered(instance))); + }).pipe(Effect.forever, Effect.raceFirst(until)); - const attach = Effect.fn("LogForwarder.attach")(function* (instance: ForwardedInstance) { - if (instance.service === "analytics") yield* Effect.forkIn(trackTarget(instance), scope); + const attach = Effect.fn("LogForwarder.attach")(function* ( + instance: ForwardedInstance | ForwardedStream, + ) { + if (instance.service === "gateway") + yield* Effect.forkIn(forward(instance.id, instance.service, Effect.never), scope); + else if (instance.service === "analytics") yield* Effect.forkIn(trackTarget(instance), scope); else if (isShippedService(instance.service)) - yield* Effect.forkIn(forward(instance, instance.service), scope); + yield* Effect.forkIn(forward(instance.id, instance.service, unregistered(instance)), scope); }); return { diff --git a/packages/stack/src/host/LogflareEvents.ts b/packages/stack/src/host/LogflareEvents.ts index 432200106e..fe4846ae7e 100644 --- a/packages/stack/src/host/LogflareEvents.ts +++ b/packages/stack/src/host/LogflareEvents.ts @@ -1,7 +1,11 @@ import { DateTime, Option } from "effect"; import type { ServiceCreation } from "../services/Catalog.ts"; +import type { gatewayLog } from "./GatewayLog.ts"; -/** Logflare source per shipped service kind; Studio's Logs pages query these names. */ +/** A service kind, or the owner's `gateway` stream of shared API listener requests. */ +export type LogService = ServiceCreation["service"] | typeof gatewayLog.service; + +/** Logflare source per shipped log service; Studio's Logs pages query these names. */ export const logflareSources = { auth: "gotrue.logs.prod", rest: "postgREST.logs.prod", @@ -9,11 +13,12 @@ export const logflareSources = { storage: "storage.logs.prod.2", functions: "deno-relay-logs", database: "postgres.logs", -} as const satisfies Partial>; + gateway: "cloudflare.logs.prod", +} as const satisfies Partial>; export type ShippedService = keyof typeof logflareSources; -export const isShippedService = (service: ServiceCreation["service"]): service is ShippedService => +export const isShippedService = (service: LogService): service is ShippedService => Object.hasOwn(logflareSources, service); /** One ingest event in the shape Studio's local log queries expect. */ @@ -53,8 +58,8 @@ const months: Record = { dec: 11, }; -/** Parses PostgREST's `%d/%b/%Y:%H:%M:%S %z` prefix into an ISO-8601 timestamp. */ -const parsePostgrestTime = (text: string): string | undefined => { +/** Parses the `%d/%b/%Y:%H:%M:%S %z` time of PostgREST and nginx logs into ISO-8601. */ +const parseLogTime = (text: string): string | undefined => { const match = /^(\d{2})\/([A-Za-z]{3})\/(\d{4}):(\d{2}):(\d{2}):(\d{2}) ([+-])(\d{2})(\d{2})$/u.exec(text); if (match === null) return undefined; @@ -78,6 +83,19 @@ const parsePostgrestTime = (text: string): string | undefined => { /** The time and request of PostgREST's Apache combined request line. */ const postgrestRequest = /^\S+ \S+ \S+ \[([^\]]+)\] "([A-Z]+) (\S+) ([^"\s]+)" (\d{3}) /u; +/** The gateway's nginx combined line with its trailing duration. */ +const gatewayRequest = + /^(\S+) \S+ \S+ \[([^\]]+)\] "(\S+) (\S+) (\S+)" (\d{3}) (?:\d+|-) "([^"]*)" "([^"]*)" \d+ms$/u; + +const unescapeLogValue = (value: string) => + value.replace(/\\x([0-9a-f]{2})/giu, (_, hex: string) => + String.fromCharCode(Number.parseInt(hex, 16)), + ); + +/** A quoted combined-log field, absent when nginx wrote `-`. */ +const logValue = (value: string | undefined) => + value === undefined || value === "-" ? undefined : unescapeLogValue(value); + const withoutProject = ({ project: _project, ...event }: LogflareEvent): LogflareEvent => event; const remaps: Record LogflareEvent> = { @@ -89,7 +107,7 @@ const remaps: Record LogflareEvent> = }, rest: (event) => { const request = postgrestRequest.exec(event.event_message); - const requestTime = request === null ? undefined : parsePostgrestTime(request[1] ?? ""); + const requestTime = request === null ? undefined : parseLogTime(request[1] ?? ""); if (request !== null && requestTime !== undefined) return { ...event, @@ -104,7 +122,7 @@ const remaps: Record LogflareEvent> = }, }; const match = /^(.*): (.*)$/u.exec(event.event_message); - const timestamp = match === null ? undefined : parsePostgrestTime(match[1] ?? ""); + const timestamp = match === null ? undefined : parseLogTime(match[1] ?? ""); return match === null || timestamp === undefined ? event : { @@ -154,6 +172,35 @@ const remaps: Record LogflareEvent> = }, }; }, + gateway: (event) => { + const match = gatewayRequest.exec(event.event_message); + const timestamp = match === null ? undefined : parseLogTime(match[2] ?? ""); + if (match === null || timestamp === undefined) return event; + const [, client, , method, target = "", protocol, status, referer, userAgent] = match; + const decoded = unescapeLogValue(target); + const queryAt = decoded.indexOf("?"); + const refererHeader = logValue(referer); + const userAgentHeader = logValue(userAgent); + return { + ...event, + timestamp, + metadata: { + ...event.metadata, + request: { + method, + path: queryAt < 0 ? decoded : decoded.slice(0, queryAt), + ...(queryAt < 0 ? {} : { search: decoded.slice(queryAt) }), + protocol, + headers: { + cf_connecting_ip: client, + ...(refererHeader === undefined ? {} : { referer: refererHeader }), + ...(userAgentHeader === undefined ? {} : { user_agent: userAgentHeader }), + }, + }, + response: { status_code: Number(status) }, + }, + }; + }, }; /** Builds the Logflare event for one service log line received at `timestamp`. */ diff --git a/packages/stack/src/host/LogflareEvents.unit.test.ts b/packages/stack/src/host/LogflareEvents.unit.test.ts index ebbf816ad6..ae7b955152 100644 --- a/packages/stack/src/host/LogflareEvents.unit.test.ts +++ b/packages/stack/src/host/LogflareEvents.unit.test.ts @@ -1,4 +1,5 @@ import { expect, it } from "@effect/vitest"; +import { formatAccess } from "./GatewayLog.ts"; import { logflareEvent } from "./LogflareEvents.ts"; const received = "2026-09-28T10:00:00.000Z"; @@ -112,3 +113,47 @@ it("derives the Postgres severity from the last level marker and defaults to LOG error_severity: "LOG", }); }); + +it("ships a gateway access line as an API Gateway request stamped with its request time", () => { + const line = formatAccess({ + time: Date.parse("2026-10-01T09:25:23.456Z"), + client: "127.0.0.1", + method: "GET", + target: '/rest/v1/todos?select=*&q="x"', + protocol: "HTTP/1.1", + status: 200, + bytes: 126, + userAgent: "curl/8.7.1", + durationMillis: 12, + }); + + expect(line).toBe( + '127.0.0.1 - - [01/Oct/2026:09:25:23 +0000] "GET /rest/v1/todos?select=*&q=\\x22x\\x22 HTTP/1.1" 200 126 "-" "curl/8.7.1" 12ms', + ); + expect(logflareEvent("gateway", received, line)).toEqual({ + project: "default", + appname: "gateway", + event_message: line, + timestamp: "2026-10-01T09:25:23.000Z", + metadata: { + request: { + method: "GET", + path: "/rest/v1/todos", + search: '?select=*&q="x"', + protocol: "HTTP/1.1", + headers: { cf_connecting_ip: "127.0.0.1", user_agent: "curl/8.7.1" }, + }, + response: { status_code: 200 }, + }, + }); +}); + +it("passes a malformed gateway line through without request metadata", () => { + expect(logflareEvent("gateway", received, "not an access line")).toEqual({ + project: "default", + appname: "gateway", + event_message: "not an access line", + timestamp: received, + metadata: {}, + }); +}); From 0b33f5c2663fee51238d89f09f12e683ea0d2dff Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 14:27:59 +0200 Subject: [PATCH 02/11] fix(stack): redact referer credentials and settle reset gateway requests - Redact apikey, access_token and token in the Referer's query and in fragments, as for the request target. - Settle a forwarded request when the client closes after the response ended but before it finished, so it records once and releases its target. Co-Authored-By: Claude Opus 5.5 --- .../stack/src/HttpProxy.integration.test.ts | 71 +++++++++++++++++-- packages/stack/src/HttpProxy.ts | 29 +++++--- 2 files changed, 85 insertions(+), 15 deletions(-) diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index 42a2bea3bd..325c874c30 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1092,10 +1092,10 @@ it.live("records each request once with the status the client was sent", () => { const statuses = [ yield* get("/api/ok?select=*&apikey=sb_secret_x&Access_Token=jwt", { "user-agent": "proxy-test/1", - referer: "http://studio.test/logs", + referer: "http://127.0.0.1:54321/x?token=t1&select=*#access_token=frag&type=bearer", }), - yield* get("/api/missing"), - yield* get("/elsewhere"), + yield* get("/api/missing", { referer: "http://127.0.0.1:54321/y?apikey=sb_publishable_x" }), + yield* get("/elsewhere", { referer: "/relative?Access_Token=jwt" }), yield* get("/down/thing?token=t"), ]; const recorded = yield* Queue.takeN(accesses, 4); @@ -1110,12 +1110,23 @@ it.live("records each request once with the status the client was sent", () => { protocol: "HTTP/1.1", status: 200, bytes: 5, - referer: "http://studio.test/logs", + referer: + "http://127.0.0.1:54321/x?token=redacted&select=*#access_token=redacted&type=bearer", userAgent: "proxy-test/1", durationMillis: expect.any(Number), }, - expect.objectContaining({ target: "/api/missing", status: 404, bytes: 4 }), - expect.objectContaining({ target: "/elsewhere", status: 404, bytes: 9 }), + expect.objectContaining({ + target: "/api/missing", + status: 404, + bytes: 4, + referer: "http://127.0.0.1:54321/y?apikey=redacted", + }), + expect.objectContaining({ + target: "/elsewhere", + status: 404, + bytes: 9, + referer: "/relative?Access_Token=redacted", + }), expect.objectContaining({ target: "/down/thing?token=redacted", status: 502, bytes: 11 }), ]); expect(yield* Queue.size(accesses)).toBe(0); @@ -1281,3 +1292,51 @@ it.live("answers and releases targets while the access sink is stalled", () => }), ).pipe(Effect.provide(Layer.merge(NodeHttpClient.layerNodeHttp, NodeServices.layer))), ); + +it.live("records and releases a request whose client resets after the full body was sent", () => + Effect.scoped( + Effect.gen(function* () { + const bodySent = yield* Deferred.make(); + const body = new Uint8Array(256 * 1024).fill(65); + const backend = createServer((request, response) => { + request.resume(); + response.once("finish", () => Deferred.doneUnsafe(bodySent, Effect.void)); + response.end(body); + }); + const backendAddress = yield* listen(backend, { + beforeClose: () => backend.closeAllConnections(), + }); + const released = yield* Deferred.make(); + const accesses = yield* Queue.unbounded(); + const proxy = yield* makeHttpProxy({ + host: "127.0.0.1", + port: 0, + onAccess: (access) => Queue.offer(accesses, access), + }); + yield* proxy.setRoutes([ + { + id: "api", + prefix: "/api", + target: Effect.acquireRelease(Effect.succeed(backendAddress), () => + Deferred.succeed(released, undefined), + ), + }, + ]); + + // The client never reads; socket buffers decide how much of the body the proxy flushed + // before the reset, so the record holds either the whole body or no byte count. + const client = yield* rawClient( + proxy.port, + "GET /api/full HTTP/1.1\r\nHost: localhost\r\n\r\n", + ); + yield* Deferred.await(bodySent).pipe(Effect.timeout("5 seconds")); + client.resetAndDestroy(); + const recorded = yield* Queue.take(accesses).pipe(Effect.timeout("5 seconds")); + yield* Deferred.await(released).pipe(Effect.timeout("5 seconds")); + + expect(recorded).toMatchObject({ target: "/api/full", status: 200 }); + expect([undefined, body.length]).toContain(recorded.bytes); + expect(yield* Queue.size(accesses)).toBe(0); + }), + ).pipe(Effect.provide(NodeServices.layer)), +); diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index 2af6364346..ee41177dc3 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -47,7 +47,7 @@ export interface HttpAccess { readonly time: number; readonly client: string; readonly method: string; - /** The request path and query, with credential query values redacted. */ + /** The request path and query, with credential query and fragment values redacted. */ readonly target: string; readonly protocol: string; /** @@ -58,6 +58,7 @@ export interface HttpAccess { readonly status: number; /** Body bytes of a response that finished; absent when it was cut short, and for upgrades. */ readonly bytes?: number; + /** The Referer header, with credential query and fragment values redacted. */ readonly referer?: string; readonly userAgent?: string; /** Until the response finished; for an upgrade, until the upstream handshake answered. */ @@ -153,11 +154,8 @@ const decodeQuery = (value: string) => { const credentialParameters = new Set(["apikey", "access_token", "token"]); -const redactCredentials = (url: string) => { - const queryAt = url.indexOf("?"); - if (queryAt < 0) return url; - const query = url - .slice(queryAt + 1) +const redactPairs = (pairs: string) => + pairs .split("&") .map((parameter) => { const separator = parameter.indexOf("="); @@ -168,7 +166,19 @@ const redactCredentials = (url: string) => { : parameter; }) .join("&"); - return `${url.slice(0, queryAt)}?${query}`; + +/** + * Redacts credential values in a URL's query and fragment, where OAuth implicit grants put + * `access_token`. Edits the text in place, so relative and unparsable URLs work and the rest of + * the URL keeps its original encoding. + */ +const redactCredentials = (url: string) => { + const hashAt = url.indexOf("#"); + const beforeHash = hashAt < 0 ? url : url.slice(0, hashAt); + const queryAt = beforeHash.indexOf("?"); + const query = queryAt < 0 ? "" : `?${redactPairs(beforeHash.slice(queryAt + 1))}`; + const fragment = hashAt < 0 ? "" : `#${redactPairs(url.slice(hashAt + 1))}`; + return `${queryAt < 0 ? beforeHash : beforeHash.slice(0, queryAt)}${query}${fragment}`; }; /** Captures a request's access fields while its socket is open; completes them once it settles. */ @@ -181,7 +191,7 @@ const accessFor = (request: IncomingMessage, time: number) => { method: request.method ?? "GET", target: redactCredentials(request.url ?? "/"), protocol: `HTTP/${request.httpVersion}`, - ...(referer === undefined ? {} : { referer }), + ...(referer === undefined ? {} : { referer: redactCredentials(referer) }), ...(userAgent === undefined ? {} : { userAgent }), }; return (ended: number, status: number, bytes?: number): HttpAccess => ({ @@ -372,8 +382,9 @@ const forward = Effect.fn("HttpProxy.forward")( abandon(Effect.fail(errorFor(cause, incoming !== undefined))); const onClientGone = () => abandon(Effect.fail(new HttpProxyDisconnected())); const onFinish = () => finish(Effect.void); + // A close after `end()` but before `finish` means the client reset with writes still queued. const onResponseClose = () => { - if (!response.writableEnded) onClientGone(); + if (!response.writableFinished) onClientGone(); }; outgoing = upstreamRequest( { From f8afda812dd77603ced8eb56881a586d452aa642 Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 16:33:24 +0200 Subject: [PATCH 03/11] fix(stack): redact OAuth codes and tokens in gateway access lines Auth redirect and verify URLs carry PKCE codes, OTP token hashes and refresh, ID and provider tokens; redact them like API keys. Co-Authored-By: Claude Opus 5.5 --- .../experimental/stack/start/SIDE_EFFECTS.md | 5 +++-- packages/stack/ARCHITECTURE.md | 5 +++-- packages/stack/src/HttpProxy.integration.test.ts | 10 +++++++--- packages/stack/src/HttpProxy.ts | 13 ++++++++++++- 4 files changed, 25 insertions(+), 8 deletions(-) diff --git a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md index d55872ede0..0f480d6be8 100644 --- a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md +++ b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md @@ -43,8 +43,9 @@ the stack deletes those logs; stopping the stack and resetting database data kee PostgREST runs with `PGRST_LOG_LEVEL=info`, so every request line, query string included, is persisted and shipped to Analytics. The shared API port also records one nginx combined line plus duration (`... "GET /rest/v1/todos?select=* HTTP/1.1" 200 126 "-" "curl/8.7.1" 12ms`) per request -and WebSocket upgrade under `logs/gateway/gateway/`, with the same retention; `apikey`, -`access_token`, and `token` query values are written as `redacted`. +and WebSocket upgrade under `logs/gateway/gateway/`, with the same retention; credential query and +fragment values (`apikey`, `token`, `token_hash`, `code`, and access, refresh, ID, and provider +tokens), in the request target and the Referer, are written as `redacted`. When an owner starts a stack saved with a Vector instance, it removes that instance, its composition members, dependencies and port claims from `state.json`, and its stack-owned Vector config files under `data//runtime/vector/`; its containers go with the stack's container sweep. diff --git a/packages/stack/ARCHITECTURE.md b/packages/stack/ARCHITECTURE.md index 34fe79f1f0..415ca25de2 100644 --- a/packages/stack/ARCHITECTURE.md +++ b/packages/stack/ARCHITECTURE.md @@ -663,8 +663,9 @@ instances no longer saved, so a failed deletion is retried; destroying the stack resetting database data keeps them. The shared API listener is the stack's gateway. Each completed request, and each WebSocket upgrade -once its handshake status is known, becomes one nginx combined line plus duration, with `apikey`, -`access_token` and `token` query values redacted. The proxy hands it to a bounded sliding buffer +once its handshake status is known, becomes one nginx combined line plus duration, with credential +query and fragment values (API keys, tokens, token hashes, PKCE codes) redacted in the target and +the Referer. The proxy hands it to a bounded sliding buffer after the response settles, so logging never delays a response or holds a target's activity. The owner persists these lines as the `gateway` stream, `logs/gateway/gateway/`, with one launch per owner run; it is not a service instance, so orphan cleanup keeps it. diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index 325c874c30..941300fa15 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1094,7 +1094,10 @@ it.live("records each request once with the status the client was sent", () => { "user-agent": "proxy-test/1", referer: "http://127.0.0.1:54321/x?token=t1&select=*#access_token=frag&type=bearer", }), - yield* get("/api/missing", { referer: "http://127.0.0.1:54321/y?apikey=sb_publishable_x" }), + yield* get("/api/missing?code=pkce&state=s", { + referer: + "http://127.0.0.1:54321/y?apikey=sb_publishable_x#refresh_token=r&provider_token=p", + }), yield* get("/elsewhere", { referer: "/relative?Access_Token=jwt" }), yield* get("/down/thing?token=t"), ]; @@ -1116,10 +1119,11 @@ it.live("records each request once with the status the client was sent", () => { durationMillis: expect.any(Number), }, expect.objectContaining({ - target: "/api/missing", + target: "/api/missing?code=redacted&state=s", status: 404, bytes: 4, - referer: "http://127.0.0.1:54321/y?apikey=redacted", + referer: + "http://127.0.0.1:54321/y?apikey=redacted#refresh_token=redacted&provider_token=redacted", }), expect.objectContaining({ target: "/elsewhere", diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index ee41177dc3..f8fc1c33b8 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -152,7 +152,18 @@ const decodeQuery = (value: string) => { } }; -const credentialParameters = new Set(["apikey", "access_token", "token"]); +// Auth puts PKCE codes, OTP token hashes and OAuth tokens in redirect and verify URLs. +const credentialParameters = new Set([ + "apikey", + "access_token", + "token", + "token_hash", + "code", + "refresh_token", + "id_token", + "provider_token", + "provider_refresh_token", +]); const redactPairs = (pairs: string) => pairs From d5254148f2ccae54c7e16789bb0df83e183dfbd7 Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 16:47:28 +0200 Subject: [PATCH 04/11] fix(stack): tighten gateway access timing, upgrade status and redaction - Measure request duration when the response settles, before target cleanup, and skip interim 1xx answers when recording upgrade status. - Redact parameters whose value carries nested credentials, and URL userinfo in logged URLs. - Make the reset, restart and raw-client test fixtures deterministic and leak-free. Co-Authored-By: Claude Opus 5.5 --- .../experimental/stack/start/SIDE_EFFECTS.md | 3 +- .../stack/src/HttpProxy.integration.test.ts | 74 ++++++++++++++++--- packages/stack/src/HttpProxy.ts | 63 ++++++++++++---- .../stack/src/Owner.logs.integration.test.ts | 2 + 4 files changed, 118 insertions(+), 24 deletions(-) diff --git a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md index 0f480d6be8..5c3c5c40de 100644 --- a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md +++ b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md @@ -45,7 +45,8 @@ persisted and shipped to Analytics. The shared API port also records one nginx c duration (`... "GET /rest/v1/todos?select=* HTTP/1.1" 200 126 "-" "curl/8.7.1" 12ms`) per request and WebSocket upgrade under `logs/gateway/gateway/`, with the same retention; credential query and fragment values (`apikey`, `token`, `token_hash`, `code`, and access, refresh, ID, and provider -tokens), in the request target and the Referer, are written as `redacted`. +tokens), in the request target and the Referer, are written as `redacted`, as are values that +themselves carry such a pair (a `redirect_to` URL with a token) and URL userinfo. When an owner starts a stack saved with a Vector instance, it removes that instance, its composition members, dependencies and port claims from `state.json`, and its stack-owned Vector config files under `data//runtime/vector/`; its containers go with the stack's container sweep. diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index 941300fa15..ad7a960709 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1031,13 +1031,21 @@ it.live("releases a waiting WebSocket target quietly when its client resets", () /** Opens a raw client connection that has written `text`. */ const rawClient = (port: number, text: string) => Effect.acquireRelease( - Effect.callback((resume) => { + Effect.callback((resume) => { const socket = new Socket(); - socket.on("error", () => undefined); + const onConnectError = (cause: Error) => { + socket.destroy(); + resume(Effect.fail(new HttpProxyTestError({ message: cause.message, cause }))); + }; + socket.once("error", onConnectError); socket.connect(port, "127.0.0.1", () => { + socket.off("error", onConnectError); + // Tests reset these connections on purpose. + socket.on("error", () => undefined); socket.write(text); resume(Effect.succeed(socket)); }); + return Effect.sync(() => socket.destroy()); }), (socket) => Effect.sync(() => socket.destroy()), ); @@ -1051,6 +1059,8 @@ const rawUpgrade = (port: number, path: string) => Effect.flatMap((socket) => Effect.callback((resume) => { socket.once("close", () => resume(Effect.void)); + // Drains any answer so an upstream's graceful end reaches the client as a close. + socket.resume(); if (socket.destroyed) resume(Effect.void); }), ), @@ -1098,8 +1108,11 @@ it.live("records each request once with the status the client was sent", () => { referer: "http://127.0.0.1:54321/y?apikey=sb_publishable_x#refresh_token=r&provider_token=p", }), - yield* get("/elsewhere", { referer: "/relative?Access_Token=jwt" }), - yield* get("/down/thing?token=t"), + yield* get( + "/elsewhere?redirect_to=https%3A%2F%2Fclient%2Fcb%3Faccess_token%3DJWT&next=http%3A%2F%2Flocalhost%3A3000%2F", + { referer: "https://user:password@studio.test/relative?Access_Token=jwt" }, + ), + yield* get("/down/thing?token=t&redirect_to=https://client/cb?access_token=JWT"), ]; const recorded = yield* Queue.takeN(accesses, 4); @@ -1126,12 +1139,16 @@ it.live("records each request once with the status the client was sent", () => { "http://127.0.0.1:54321/y?apikey=redacted#refresh_token=redacted&provider_token=redacted", }), expect.objectContaining({ - target: "/elsewhere", + target: "/elsewhere?redirect_to=redacted&next=http%3A%2F%2Flocalhost%3A3000%2F", status: 404, bytes: 9, - referer: "/relative?Access_Token=redacted", + referer: "https://redacted@studio.test/relative?Access_Token=redacted", + }), + expect.objectContaining({ + target: "/down/thing?token=redacted&redirect_to=redacted", + status: 502, + bytes: 11, }), - expect.objectContaining({ target: "/down/thing?token=redacted", status: 502, bytes: 11 }), ]); expect(yield* Queue.size(accesses)).toBe(0); }), @@ -1155,6 +1172,24 @@ it.live("records WebSocket upgrades at the handshake with the status sent to the connection.once("data", () => Deferred.doneUnsafe(upgradeReceived, Effect.void)); }); const silentAddress = yield* listen(silent); + // Answers with an interim 1xx before the final handshake status, in separate writes. + const interim = createTcpServer((connection) => { + connection.on("error", () => undefined); + connection.once("data", (chunk: Buffer) => { + const upgrading = chunk.toString("latin1").startsWith("GET /interim/upgrade "); + connection.write( + upgrading + ? "HTTP/1.1 103 Early Hints\r\nLink: ; rel=preload\r\n\r\n" + : "HTTP/1.1 100 Continue\r\n\r\n", + ); + connection.end( + upgrading + ? "HTTP/1.1 101 Switching Protocols\r\nUpgrade: websocket\r\nConnection: Upgrade\r\n\r\n" + : "HTTP/1.1 403 Forbidden\r\nContent-Length: 0\r\nConnection: close\r\n\r\n", + ); + }); + }); + const interimAddress = yield* listen(interim); const accesses = yield* Queue.unbounded(); const proxy = yield* makeHttpProxy({ host: "127.0.0.1", @@ -1164,6 +1199,7 @@ it.live("records WebSocket upgrades at the handshake with the status sent to the yield* proxy.setRoutes([ { id: "ws", prefix: "/socket", target: Effect.succeed(backendAddress) }, { id: "silent", prefix: "/silent", target: Effect.succeed(silentAddress) }, + { id: "interim", prefix: "/interim", target: Effect.succeed(interimAddress) }, { id: "down", prefix: "/down", @@ -1197,6 +1233,16 @@ it.live("records WebSocket upgrades at the handshake with the status sent to the expect(yield* Queue.take(accesses)).toMatchObject({ target: "/elsewhere", status: 404 }); yield* rawUpgrade(proxy.port, "/down"); expect(yield* Queue.take(accesses)).toMatchObject({ target: "/down", status: 502 }); + yield* rawUpgrade(proxy.port, "/interim/forbidden"); + expect(yield* Queue.take(accesses)).toMatchObject({ + target: "/interim/forbidden", + status: 403, + }); + yield* rawUpgrade(proxy.port, "/interim/upgrade"); + expect(yield* Queue.take(accesses)).toMatchObject({ + target: "/interim/upgrade", + status: 101, + }); const leaving = yield* rawClient(proxy.port, upgradeRequest("/silent")); yield* Deferred.await(upgradeReceived); @@ -1327,13 +1373,21 @@ it.live("records and releases a request whose client resets after the full body }, ]); - // The client never reads; socket buffers decide how much of the body the proxy flushed - // before the reset, so the record holds either the whole body or no byte count. + // The client stops reading after its first bytes; socket buffers decide how much of the + // body the proxy flushed before the reset, so the record holds the whole body or no count. const client = yield* rawClient( proxy.port, "GET /api/full HTTP/1.1\r\nHost: localhost\r\n\r\n", ); - yield* Deferred.await(bodySent).pipe(Effect.timeout("5 seconds")); + const firstBytes = Effect.callback((resume) => { + client.once("data", () => { + client.pause(); + resume(Effect.void); + }); + }); + yield* Effect.all([firstBytes, Deferred.await(bodySent)], { concurrency: "unbounded" }).pipe( + Effect.timeout("5 seconds"), + ); client.resetAndDestroy(); const recorded = yield* Queue.take(accesses).pipe(Effect.timeout("5 seconds")); yield* Deferred.await(released).pipe(Effect.timeout("5 seconds")); diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index f8fc1c33b8..e0a0a2b634 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -165,6 +165,9 @@ const credentialParameters = new Set([ "provider_refresh_token", ]); +/** A credential pair inside a decoded value, such as a `redirect_to` URL carrying a token. */ +const nestedCredential = new RegExp(`(?:^|[?&#])(?:${[...credentialParameters].join("|")})=`, "iu"); + const redactPairs = (pairs: string) => pairs .split("&") @@ -172,24 +175,31 @@ const redactPairs = (pairs: string) => const separator = parameter.indexOf("="); if (separator < 0) return parameter; const name = parameter.slice(0, separator); - return credentialParameters.has(decodeQuery(name).toLowerCase()) + return credentialParameters.has(decodeQuery(name).toLowerCase()) || + nestedCredential.test(decodeQuery(parameter.slice(separator + 1))) ? `${name}=redacted` : parameter; }) .join("&"); +const userinfo = /^([a-z][a-z\d+.-]*:\/\/)[^/?#@]*@/iu; + /** - * Redacts credential values in a URL's query and fragment, where OAuth implicit grants put - * `access_token`. Edits the text in place, so relative and unparsable URLs work and the rest of - * the URL keeps its original encoding. + * Redacts an absolute URL's userinfo and credential values in its query and fragment, where + * OAuth implicit grants put `access_token`. Edits the text in place, so relative and unparsable + * URLs work and the rest of the URL keeps its original encoding. */ const redactCredentials = (url: string) => { const hashAt = url.indexOf("#"); const beforeHash = hashAt < 0 ? url : url.slice(0, hashAt); const queryAt = beforeHash.indexOf("?"); + const base = (queryAt < 0 ? beforeHash : beforeHash.slice(0, queryAt)).replace( + userinfo, + "$1redacted@", + ); const query = queryAt < 0 ? "" : `?${redactPairs(beforeHash.slice(queryAt + 1))}`; const fragment = hashAt < 0 ? "" : `#${redactPairs(url.slice(hashAt + 1))}`; - return `${queryAt < 0 ? beforeHash : beforeHash.slice(0, queryAt)}${query}${fragment}`; + return `${base}${query}${fragment}`; }; /** Captures a request's access fields while its socket is open; completes them once it settles. */ @@ -470,6 +480,8 @@ const proxyRequest = Effect.fn("HttpProxy.proxyRequest")( ); const statusLine = /^HTTP\/\d(?:\.\d)? (\d{3})\b/u; +/** Upstream bytes read for the handshake status before giving up on finding one. */ +const answerLimit = 8 * 1024; const upgrade = Effect.fn("HttpProxy.upgrade")( ( @@ -519,13 +531,30 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( const onClientClose = () => (Deferred.isDoneUnsafe(handshake) ? onClose() : onClientGone()); const onClientEnd = () => upstream.end(); const onUpstreamEnd = () => client.end(); - // Reads the handshake status off the bytes relayed to the client. + // Reads the final handshake status off the bytes relayed to the client, skipping interim + // 1xx responses such as 100 Continue (RFC 9110 section 15.2). const onAnswer = (chunk: Buffer) => { answer += chunk.toString("latin1"); - if (!answer.includes("\r\n") && answer.length < 64) return; - upstream.off("data", onAnswer); - const status = statusLine.exec(answer)?.[1]; - if (status !== undefined) Deferred.doneUnsafe(handshake, Effect.succeed(Number(status))); + while (true) { + const lineEnd = answer.indexOf("\r\n"); + if (lineEnd < 0) { + if (answer.length >= answerLimit) upstream.off("data", onAnswer); + return; + } + const status = Number(statusLine.exec(answer.slice(0, lineEnd))?.[1] ?? Number.NaN); + if (status >= 100 && status < 200 && status !== 101) { + const headEnd = answer.indexOf("\r\n\r\n"); + if (headEnd < 0) { + if (answer.length >= answerLimit) upstream.off("data", onAnswer); + return; + } + answer = answer.slice(headEnd + 4); + continue; + } + upstream.off("data", onAnswer); + if (!Number.isNaN(status)) Deferred.doneUnsafe(handshake, Effect.succeed(status)); + return; + } }; upstream.on("data", onAnswer); client.on("error", onClientGone); @@ -575,6 +604,14 @@ export const makeHttpProxy = (options: { Effect.gen(function* () { const complete = accessFor(request, yield* Clock.currentTimeMillis); const sent: Sent = { bytes: 0, clientLeft: false }; + // Timed when the response settles, before the target's release runs. + const settled = + onAccess === undefined + ? undefined + : yield* responseSettled(response).pipe( + Effect.andThen(Clock.currentTimeMillis), + Effect.forkChild({ startImmediately: true }), + ); // The access record waits outside this scope, so it never holds the target's activity. yield* Effect.scoped( Effect.gen(function* () { @@ -606,12 +643,12 @@ export const makeHttpProxy = (options: { } }), ); - if (onAccess === undefined) return; - yield* responseSettled(response); + if (onAccess === undefined || settled === undefined) return; + const ended = yield* Fiber.join(settled); const delivered = response.writableFinished && !sent.clientLeft; yield* onAccess( complete( - yield* Clock.currentTimeMillis, + ended, response.headersSent ? response.statusCode : 499, delivered ? sent.bytes : undefined, ), diff --git a/packages/stack/src/Owner.logs.integration.test.ts b/packages/stack/src/Owner.logs.integration.test.ts index cd7ccafc0e..3209ef069b 100644 --- a/packages/stack/src/Owner.logs.integration.test.ts +++ b/packages/stack/src/Owner.logs.integration.test.ts @@ -156,6 +156,8 @@ describe("owner persisted logs", () => { const client = yield* HttpClient.HttpClient; const root = yield* fs.makeTempDirectoryScoped({ prefix: "owner-logs-gateway-" }); const firstScope = yield* Scope.make(); + // Closes the first owner if the test fails before the restart closes it. + yield* Effect.addFinalizer(() => Scope.close(firstScope, Exit.void)); const first = yield* openOwner("owner-logs-gateway-", "native", { root }).pipe( Scope.provide(firstScope), ); From 12bfb02623512ce669e70b2c16cf8788b320f344 Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 16:58:17 +0200 Subject: [PATCH 05/11] fix(stack): redact userinfo in URLs nested in gateway query values Co-Authored-By: Claude Opus 5.5 --- packages/stack/src/HttpProxy.integration.test.ts | 5 +++-- packages/stack/src/HttpProxy.ts | 9 ++++++--- 2 files changed, 9 insertions(+), 5 deletions(-) diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index ad7a960709..eda9029e4c 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1109,7 +1109,7 @@ it.live("records each request once with the status the client was sent", () => { "http://127.0.0.1:54321/y?apikey=sb_publishable_x#refresh_token=r&provider_token=p", }), yield* get( - "/elsewhere?redirect_to=https%3A%2F%2Fclient%2Fcb%3Faccess_token%3DJWT&next=http%3A%2F%2Flocalhost%3A3000%2F", + "/elsewhere?redirect_to=https%3A%2F%2Fclient%2Fcb%3Faccess_token%3DJWT&return_to=https%3A%2F%2Fuser%3Asecret%40client%2Fcb&next=http%3A%2F%2Flocalhost%3A3000%2F", { referer: "https://user:password@studio.test/relative?Access_Token=jwt" }, ), yield* get("/down/thing?token=t&redirect_to=https://client/cb?access_token=JWT"), @@ -1139,7 +1139,8 @@ it.live("records each request once with the status the client was sent", () => { "http://127.0.0.1:54321/y?apikey=redacted#refresh_token=redacted&provider_token=redacted", }), expect.objectContaining({ - target: "/elsewhere?redirect_to=redacted&next=http%3A%2F%2Flocalhost%3A3000%2F", + target: + "/elsewhere?redirect_to=redacted&return_to=redacted&next=http%3A%2F%2Flocalhost%3A3000%2F", status: 404, bytes: 9, referer: "https://redacted@studio.test/relative?Access_Token=redacted", diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index e0a0a2b634..afc8a4b300 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -168,6 +168,9 @@ const credentialParameters = new Set([ /** A credential pair inside a decoded value, such as a `redirect_to` URL carrying a token. */ const nestedCredential = new RegExp(`(?:^|[?&#])(?:${[...credentialParameters].join("|")})=`, "iu"); +const userinfo = /^([a-z][a-z\d+.-]*:\/\/)[^/?#@]*@/iu; +const nestedUserinfo = /[a-z][a-z\d+.-]*:\/\/[^/?#@]*@/iu; + const redactPairs = (pairs: string) => pairs .split("&") @@ -175,15 +178,15 @@ const redactPairs = (pairs: string) => const separator = parameter.indexOf("="); if (separator < 0) return parameter; const name = parameter.slice(0, separator); + const value = decodeQuery(parameter.slice(separator + 1)); return credentialParameters.has(decodeQuery(name).toLowerCase()) || - nestedCredential.test(decodeQuery(parameter.slice(separator + 1))) + nestedCredential.test(value) || + nestedUserinfo.test(value) ? `${name}=redacted` : parameter; }) .join("&"); -const userinfo = /^([a-z][a-z\d+.-]*:\/\/)[^/?#@]*@/iu; - /** * Redacts an absolute URL's userinfo and credential values in its query and fragment, where * OAuth implicit grants put `access_token`. Edits the text in place, so relative and unparsable From 04ed9439e2e2c3f3c230dd780691a12d780af755 Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 17:08:13 +0200 Subject: [PATCH 06/11] fix(stack): detect credentials in multiply-encoded gateway query values Co-Authored-By: Claude Opus 5.5 --- packages/stack/src/HttpProxy.integration.test.ts | 6 ++++-- packages/stack/src/HttpProxy.ts | 13 ++++++++++++- 2 files changed, 16 insertions(+), 3 deletions(-) diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index eda9029e4c..d8f4adb4ff 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1112,7 +1112,9 @@ it.live("records each request once with the status the client was sent", () => { "/elsewhere?redirect_to=https%3A%2F%2Fclient%2Fcb%3Faccess_token%3DJWT&return_to=https%3A%2F%2Fuser%3Asecret%40client%2Fcb&next=http%3A%2F%2Flocalhost%3A3000%2F", { referer: "https://user:password@studio.test/relative?Access_Token=jwt" }, ), - yield* get("/down/thing?token=t&redirect_to=https://client/cb?access_token=JWT"), + yield* get( + "/down/thing?token=t&redirect_to=https://client/cb?access_token=JWT&back=https%253A%252F%252Fclient%252Fcb%253Faccess_token%253DJWT", + ), ]; const recorded = yield* Queue.takeN(accesses, 4); @@ -1146,7 +1148,7 @@ it.live("records each request once with the status the client was sent", () => { referer: "https://redacted@studio.test/relative?Access_Token=redacted", }), expect.objectContaining({ - target: "/down/thing?token=redacted&redirect_to=redacted", + target: "/down/thing?token=redacted&redirect_to=redacted&back=redacted", status: 502, bytes: 11, }), diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index afc8a4b300..657c24961e 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -152,6 +152,17 @@ const decodeQuery = (value: string) => { } }; +/** Decodes repeatedly so a nested URL encoded more than once still exposes its delimiters. */ +const decodeNested = (value: string) => { + let current = value; + for (let pass = 0; pass < 4; pass++) { + const next = decodeQuery(current); + if (next === current) break; + current = next; + } + return current; +}; + // Auth puts PKCE codes, OTP token hashes and OAuth tokens in redirect and verify URLs. const credentialParameters = new Set([ "apikey", @@ -178,7 +189,7 @@ const redactPairs = (pairs: string) => const separator = parameter.indexOf("="); if (separator < 0) return parameter; const name = parameter.slice(0, separator); - const value = decodeQuery(parameter.slice(separator + 1)); + const value = decodeNested(parameter.slice(separator + 1)); return credentialParameters.has(decodeQuery(name).toLowerCase()) || nestedCredential.test(value) || nestedUserinfo.test(value) From 0cb3e904474850db8ac83ac24600254f8eedbbe1 Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 18:32:44 +0200 Subject: [PATCH 07/11] refactor(stack): simplify gateway access recording and redaction - Build gateway access records only on the proxy that logs them. - Collapse credential redaction into one pattern and move its cases to a unit table. - Share the month table, rename the log escaper, read upgrade answers in one loop, and trim a forwarder assertion the remap test already pins. Co-Authored-By: Claude Opus 5.5 --- packages/stack/ARCHITECTURE.md | 7 +- .../stack/src/HttpProxy.integration.test.ts | 167 ++++++++---------- packages/stack/src/HttpProxy.ts | 98 +++++----- packages/stack/src/HttpProxy.unit.test.ts | 71 ++++++++ packages/stack/src/Network.ts | 4 +- packages/stack/src/host/GatewayLog.ts | 19 +- .../src/host/LogForwarder.integration.test.ts | 17 +- packages/stack/src/host/LogForwarder.ts | 18 +- packages/stack/src/host/LogflareEvents.ts | 35 ++-- 9 files changed, 235 insertions(+), 201 deletions(-) create mode 100644 packages/stack/src/HttpProxy.unit.test.ts diff --git a/packages/stack/ARCHITECTURE.md b/packages/stack/ARCHITECTURE.md index 415ca25de2..98b1677332 100644 --- a/packages/stack/ARCHITECTURE.md +++ b/packages/stack/ARCHITECTURE.md @@ -664,9 +664,10 @@ resetting database data keeps them. The shared API listener is the stack's gateway. Each completed request, and each WebSocket upgrade once its handshake status is known, becomes one nginx combined line plus duration, with credential -query and fragment values (API keys, tokens, token hashes, PKCE codes) redacted in the target and -the Referer. The proxy hands it to a bounded sliding buffer -after the response settles, so logging never delays a response or holds a target's activity. +query and fragment values (API keys, tokens, token hashes, PKCE codes), values that nest one or a +URL with userinfo, and URL userinfo redacted in the target and the Referer. The proxy hands it to +a bounded sliding buffer after the response settles, so logging never delays a response or holds +a target's activity. The owner persists these lines as the `gateway` stream, `logs/gateway/gateway/`, with one launch per owner run; it is not a service instance, so orphan cleanup keeps it. diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index d8f4adb4ff..c9d6e8b9e9 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1067,100 +1067,83 @@ const rawUpgrade = (port: number, path: string) => Effect.timeout("5 seconds"), ); -it.live("records each request once with the status the client was sent", () => { - const logs: Array = []; - return Effect.scoped( - Effect.gen(function* () { - const backend = createServer((request, response) => { - request.resume(); - if (request.url?.startsWith("/ok")) response.end("hello"); - else { - response.statusCode = 404; - response.end("nope"); - } - }); - const backendAddress = yield* listen(backend); - const accesses = yield* Queue.unbounded(); - const proxy = yield* makeHttpProxy({ - host: "127.0.0.1", - port: 0, - onAccess: (access) => Queue.offer(accesses, access), - }); - yield* proxy.setRoutes([ - { id: "api", prefix: "/api", upstreamPrefix: "/", target: Effect.succeed(backendAddress) }, - { - id: "down", - prefix: "/down", - target: Effect.fail(new ProxyError({ message: "wake failed" })), - }, - ]); - const get = (path: string, headers: Readonly> = {}) => - request(proxy.port, path, new Uint8Array(), headers, "GET").pipe( - Effect.map(({ status }) => status), - ); +it.live( + "records each request once with its sent status, body bytes and redacted credentials", + () => { + const logs: Array = []; + return Effect.scoped( + Effect.gen(function* () { + const backend = createServer((request, response) => { + request.resume(); + if (request.url?.startsWith("/ok")) response.end("hello"); + else { + response.statusCode = 404; + response.end("nope"); + } + }); + const backendAddress = yield* listen(backend); + const accesses = yield* Queue.unbounded(); + const proxy = yield* makeHttpProxy({ + host: "127.0.0.1", + port: 0, + onAccess: (access) => Queue.offer(accesses, access), + }); + yield* proxy.setRoutes([ + { + id: "api", + prefix: "/api", + upstreamPrefix: "/", + target: Effect.succeed(backendAddress), + }, + { + id: "down", + prefix: "/down", + target: Effect.fail(new ProxyError({ message: "wake failed" })), + }, + ]); + const get = (path: string, headers: Readonly> = {}) => + request(proxy.port, path, new Uint8Array(), headers, "GET").pipe( + Effect.map(({ status }) => status), + ); - const statuses = [ - yield* get("/api/ok?select=*&apikey=sb_secret_x&Access_Token=jwt", { - "user-agent": "proxy-test/1", - referer: "http://127.0.0.1:54321/x?token=t1&select=*#access_token=frag&type=bearer", - }), - yield* get("/api/missing?code=pkce&state=s", { - referer: - "http://127.0.0.1:54321/y?apikey=sb_publishable_x#refresh_token=r&provider_token=p", - }), - yield* get( - "/elsewhere?redirect_to=https%3A%2F%2Fclient%2Fcb%3Faccess_token%3DJWT&return_to=https%3A%2F%2Fuser%3Asecret%40client%2Fcb&next=http%3A%2F%2Flocalhost%3A3000%2F", - { referer: "https://user:password@studio.test/relative?Access_Token=jwt" }, - ), - yield* get( - "/down/thing?token=t&redirect_to=https://client/cb?access_token=JWT&back=https%253A%252F%252Fclient%252Fcb%253Faccess_token%253DJWT", - ), - ]; - const recorded = yield* Queue.takeN(accesses, 4); + const statuses = [ + yield* get("/api/ok?select=*&apikey=sb_secret_x", { + "user-agent": "proxy-test/1", + referer: "http://127.0.0.1:54321/x?token=t1&select=*", + }), + yield* get("/api/missing"), + yield* get("/elsewhere"), + yield* get("/down/thing"), + ]; + const recorded = yield* Queue.takeN(accesses, 4); - expect(statuses).toEqual([200, 404, 404, 502]); - expect(recorded.toSorted((left, right) => left.time - right.time)).toEqual([ - { - time: expect.any(Number), - client: "127.0.0.1", - method: "GET", - target: "/api/ok?select=*&apikey=redacted&Access_Token=redacted", - protocol: "HTTP/1.1", - status: 200, - bytes: 5, - referer: - "http://127.0.0.1:54321/x?token=redacted&select=*#access_token=redacted&type=bearer", - userAgent: "proxy-test/1", - durationMillis: expect.any(Number), - }, - expect.objectContaining({ - target: "/api/missing?code=redacted&state=s", - status: 404, - bytes: 4, - referer: - "http://127.0.0.1:54321/y?apikey=redacted#refresh_token=redacted&provider_token=redacted", - }), - expect.objectContaining({ - target: - "/elsewhere?redirect_to=redacted&return_to=redacted&next=http%3A%2F%2Flocalhost%3A3000%2F", - status: 404, - bytes: 9, - referer: "https://redacted@studio.test/relative?Access_Token=redacted", - }), - expect.objectContaining({ - target: "/down/thing?token=redacted&redirect_to=redacted&back=redacted", - status: 502, - bytes: 11, - }), - ]); - expect(yield* Queue.size(accesses)).toBe(0); - }), - ).pipe( - Effect.provide( - Layer.mergeAll(NodeHttpClient.layerNodeHttp, NodeServices.layer, captureErrors(logs)), - ), - ); -}); + expect(statuses).toEqual([200, 404, 404, 502]); + expect(recorded.toSorted((left, right) => left.time - right.time)).toEqual([ + { + time: expect.any(Number), + client: "127.0.0.1", + method: "GET", + target: "/api/ok?select=*&apikey=redacted", + protocol: "HTTP/1.1", + status: 200, + bytes: 5, + referer: "http://127.0.0.1:54321/x?token=redacted&select=*", + userAgent: "proxy-test/1", + durationMillis: expect.any(Number), + }, + expect.objectContaining({ target: "/api/missing", status: 404, bytes: 4 }), + expect.objectContaining({ target: "/elsewhere", status: 404, bytes: 9 }), + expect.objectContaining({ target: "/down/thing", status: 502, bytes: 11 }), + ]); + expect(yield* Queue.size(accesses)).toBe(0); + }), + ).pipe( + Effect.provide( + Layer.mergeAll(NodeHttpClient.layerNodeHttp, NodeServices.layer, captureErrors(logs)), + ), + ); + }, +); it.live("records WebSocket upgrades at the handshake with the status sent to the client", () => { const logs: Array = []; diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index 657c24961e..3c6ec89959 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -164,7 +164,7 @@ const decodeNested = (value: string) => { }; // Auth puts PKCE codes, OTP token hashes and OAuth tokens in redirect and verify URLs. -const credentialParameters = new Set([ +const credentialParameters = [ "apikey", "access_token", "token", @@ -174,36 +174,36 @@ const credentialParameters = new Set([ "id_token", "provider_token", "provider_refresh_token", -]); - -/** A credential pair inside a decoded value, such as a `redirect_to` URL carrying a token. */ -const nestedCredential = new RegExp(`(?:^|[?&#])(?:${[...credentialParameters].join("|")})=`, "iu"); +]; +const scheme = String.raw`[a-z][a-z\d+.-]*`; -const userinfo = /^([a-z][a-z\d+.-]*:\/\/)[^/?#@]*@/iu; -const nestedUserinfo = /[a-z][a-z\d+.-]*:\/\/[^/?#@]*@/iu; +/** + * A decoded parameter that is a credential pair, nests one (a `redirect_to` URL carrying a + * token), or nests a URL with userinfo. + */ +const sensitive = new RegExp( + String.raw`(?:^|[?&#=])(?:${credentialParameters.join("|")})=|${scheme}:\/\/[^/?#@]*@`, + "iu", +); +const userinfo = new RegExp(String.raw`^(${scheme}:\/\/)[^/?#@]*@`, "iu"); const redactPairs = (pairs: string) => pairs .split("&") .map((parameter) => { const separator = parameter.indexOf("="); - if (separator < 0) return parameter; - const name = parameter.slice(0, separator); - const value = decodeNested(parameter.slice(separator + 1)); - return credentialParameters.has(decodeQuery(name).toLowerCase()) || - nestedCredential.test(value) || - nestedUserinfo.test(value) - ? `${name}=redacted` + return separator >= 0 && sensitive.test(decodeNested(parameter)) + ? `${parameter.slice(0, separator)}=redacted` : parameter; }) .join("&"); /** * Redacts an absolute URL's userinfo and credential values in its query and fragment, where - * OAuth implicit grants put `access_token`. Edits the text in place, so relative and unparsable - * URLs work and the rest of the URL keeps its original encoding. + * OAuth implicit grants put `access_token` for non-browser clients. Edits the text in place, so + * relative and unparsable URLs work and the rest of the URL keeps its original encoding. */ -const redactCredentials = (url: string) => { +export const redactCredentials = (url: string) => { const hashAt = url.indexOf("#"); const beforeHash = hashAt < 0 ? url : url.slice(0, hashAt); const queryAt = beforeHash.indexOf("?"); @@ -549,19 +549,13 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( // 1xx responses such as 100 Continue (RFC 9110 section 15.2). const onAnswer = (chunk: Buffer) => { answer += chunk.toString("latin1"); - while (true) { - const lineEnd = answer.indexOf("\r\n"); - if (lineEnd < 0) { - if (answer.length >= answerLimit) upstream.off("data", onAnswer); - return; - } - const status = Number(statusLine.exec(answer.slice(0, lineEnd))?.[1] ?? Number.NaN); + for ( + let headEnd = answer.indexOf("\r\n\r\n"); + headEnd >= 0; + headEnd = answer.indexOf("\r\n\r\n") + ) { + const status = Number(statusLine.exec(answer)?.[1] ?? Number.NaN); if (status >= 100 && status < 200 && status !== 101) { - const headEnd = answer.indexOf("\r\n\r\n"); - if (headEnd < 0) { - if (answer.length >= answerLimit) upstream.off("data", onAnswer); - return; - } answer = answer.slice(headEnd + 4); continue; } @@ -569,6 +563,7 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( if (!Number.isNaN(status)) Deferred.doneUnsafe(handshake, Effect.succeed(status)); return; } + if (answer.length >= answerLimit) upstream.off("data", onAnswer); }; upstream.on("data", onAnswer); client.on("error", onClientGone); @@ -600,7 +595,7 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( export const makeHttpProxy = (options: { readonly host: string; readonly port: number; - readonly onAccess?: HttpAccessSink; + readonly onAccess?: HttpAccessSink | undefined; }): Effect.Effect => Effect.gen(function* () { const routes = yield* Ref.make>([]); @@ -616,16 +611,19 @@ export const makeHttpProxy = (options: { const server = createServer((request, response) => { runRequest( Effect.gen(function* () { - const complete = accessFor(request, yield* Clock.currentTimeMillis); const sent: Sent = { bytes: 0, clientLeft: false }; - // Timed when the response settles, before the target's release runs. - const settled = + const access = onAccess === undefined ? undefined - : yield* responseSettled(response).pipe( - Effect.andThen(Clock.currentTimeMillis), - Effect.forkChild({ startImmediately: true }), - ); + : { + complete: accessFor(request, yield* Clock.currentTimeMillis), + // Timed when the response settles, before the target's release runs. + settled: yield* responseSettled(response).pipe( + Effect.andThen(Clock.currentTimeMillis), + Effect.forkChild({ startImmediately: true }), + ), + record: onAccess, + }; // The access record waits outside this scope, so it never holds the target's activity. yield* Effect.scoped( Effect.gen(function* () { @@ -657,11 +655,11 @@ export const makeHttpProxy = (options: { } }), ); - if (onAccess === undefined || settled === undefined) return; - const ended = yield* Fiber.join(settled); + if (access === undefined) return; + const ended = yield* Fiber.join(access.settled); const delivered = response.writableFinished && !sent.clientLeft; - yield* onAccess( - complete( + yield* access.record( + access.complete( ended, response.headersSent ? response.statusCode : 499, delivered ? sent.bytes : undefined, @@ -678,20 +676,22 @@ export const makeHttpProxy = (options: { socket.on("error", () => socket.destroy()); runRequest( Effect.gen(function* () { - const complete = accessFor(request, yield* Clock.currentTimeMillis); // Completed by the upstream's handshake status, otherwise by the upgrade's outcome. const handshake = yield* Deferred.make(); const recorded = onAccess === undefined ? undefined - : yield* Deferred.await(handshake).pipe( - Effect.flatMap((status) => - Clock.currentTimeMillis.pipe( - Effect.flatMap((ended) => onAccess(complete(ended, status))), + : yield* Effect.gen(function* () { + const complete = accessFor(request, yield* Clock.currentTimeMillis); + return yield* Deferred.await(handshake).pipe( + Effect.flatMap((status) => + Clock.currentTimeMillis.pipe( + Effect.flatMap((ended) => onAccess(complete(ended, status))), + ), ), - ), - Effect.forkChild({ startImmediately: true }), - ); + Effect.forkChild({ startImmediately: true }), + ); + }); const route = yield* Ref.get(routes).pipe( Effect.map((current) => routeFor(request.url ?? "/", current)), ); diff --git a/packages/stack/src/HttpProxy.unit.test.ts b/packages/stack/src/HttpProxy.unit.test.ts new file mode 100644 index 0000000000..414cfc6025 --- /dev/null +++ b/packages/stack/src/HttpProxy.unit.test.ts @@ -0,0 +1,71 @@ +import { describe, expect, it } from "@effect/vitest"; +import { redactCredentials } from "./HttpProxy.ts"; + +describe("redactCredentials", () => { + it.each([ + { + case: "redacts credential query values, any case", + url: "/api/ok?select=*&apikey=sb_secret_x&Access_Token=jwt", + redacted: "/api/ok?select=*&apikey=redacted&Access_Token=redacted", + }, + { + case: "redacts Auth codes and OTP token hashes", + url: "/auth/v1/verify?code=pkce&token_hash=h&type=signup", + redacted: "/auth/v1/verify?code=redacted&token_hash=redacted&type=signup", + }, + { + case: "redacts fragment credentials of an absolute URL", + url: "http://127.0.0.1:54321/x?token=t1&select=*#access_token=frag&type=bearer", + redacted: + "http://127.0.0.1:54321/x?token=redacted&select=*#access_token=redacted&type=bearer", + }, + { + case: "redacts refresh and provider tokens in a fragment", + url: "http://127.0.0.1:54321/y?apikey=k#refresh_token=r&provider_token=p&provider_refresh_token=q", + redacted: + "http://127.0.0.1:54321/y?apikey=redacted#refresh_token=redacted&provider_token=redacted&provider_refresh_token=redacted", + }, + { + case: "redacts an encoded nested URL carrying a token", + url: "/elsewhere?redirect_to=https%3A%2F%2Fclient%2Fcb%3Faccess_token%3DJWT", + redacted: "/elsewhere?redirect_to=redacted", + }, + { + case: "redacts a raw nested URL carrying a token", + url: "/down?redirect_to=https://client/cb?access_token=JWT", + redacted: "/down?redirect_to=redacted", + }, + { + case: "redacts a doubly encoded nested URL carrying a token", + url: "/down?back=https%253A%252F%252Fclient%252Fcb%253Faccess_token%253DJWT", + redacted: "/down?back=redacted", + }, + { + case: "redacts a nested URL with userinfo", + url: "/elsewhere?return_to=https%3A%2F%2Fuser%3Asecret%40client%2Fcb", + redacted: "/elsewhere?return_to=redacted", + }, + { + case: "redacts userinfo of an absolute URL", + url: "https://user:password@studio.test/relative?Access_Token=jwt", + redacted: "https://redacted@studio.test/relative?Access_Token=redacted", + }, + { + case: "redacts a value that embeds a credential pair", + url: "/api?data=a=token=b", + redacted: "/api?data=redacted", + }, + { + case: "keeps a nested URL without credentials, with its encoding", + url: "/elsewhere?next=http%3A%2F%2Flocalhost%3A3000%2F&country_code=FR", + redacted: "/elsewhere?next=http%3A%2F%2Flocalhost%3A3000%2F&country_code=FR", + }, + { + case: "keeps a path without a query", + url: "/rest/v1/todos", + redacted: "/rest/v1/todos", + }, + ])("$case", ({ url, redacted }) => { + expect(redactCredentials(url)).toBe(redacted); + }); +}); diff --git a/packages/stack/src/Network.ts b/packages/stack/src/Network.ts index 7f13dbaafc..d5b2ca44ad 100644 --- a/packages/stack/src/Network.ts +++ b/packages/stack/src/Network.ts @@ -179,9 +179,7 @@ const makeNetwork = (options: { proxy: yield* makeHttpProxy({ host, port, - ...(options.onAccess === undefined - ? {} - : { onAccess: options.onAccess }), + onAccess: options.onAccess, }), }; } diff --git a/packages/stack/src/host/GatewayLog.ts b/packages/stack/src/host/GatewayLog.ts index 91e98d5713..b833be862a 100644 --- a/packages/stack/src/host/GatewayLog.ts +++ b/packages/stack/src/host/GatewayLog.ts @@ -2,6 +2,7 @@ import { DateTime, Effect, PubSub, Stream } from "effect"; import type { HttpAccess, HttpAccessSink } from "../HttpProxy.ts"; import { launchOutputPublisher, type LaunchOutput } from "../runtime/Session.ts"; import type { CatalogLogs } from "../services/Recipe.ts"; +import { monthNames } from "./LogflareEvents.ts"; /** The log stream of the shared API listener's access records, one per owner and stack. */ export const gatewayLog = { service: "gateway", instanceId: "gateway" } as const; @@ -9,20 +10,6 @@ export const gatewayLog = { service: "gateway", instanceId: "gateway" } as const /** Bounds records not yet persisted; the oldest are dropped and reported as lost. */ const bufferedRecords = 4096; -const monthNames = [ - "Jan", - "Feb", - "Mar", - "Apr", - "May", - "Jun", - "Jul", - "Aug", - "Sep", - "Oct", - "Nov", - "Dec", -]; const two = (value: number) => String(value).padStart(2, "0"); /** Formats epoch milliseconds as nginx's `$time_local` in UTC. */ @@ -32,7 +19,7 @@ const nginxTime = (millis: number) => { }; /** Escapes quotes, backslashes and control characters like nginx's default log escaping. */ -const escape = (value: string) => +const escapeLogValue = (value: string) => value.replace( // oxlint-disable-next-line no-control-regex -- control characters are what this escapes. /["\\\u0000-\u001f\u007f]/gu, @@ -41,7 +28,7 @@ const escape = (value: string) => /** Formats an access record as an nginx combined log line followed by its duration. */ export const formatAccess = (access: HttpAccess) => - `${access.client} - - [${nginxTime(access.time)}] "${escape(`${access.method} ${access.target} ${access.protocol}`)}" ${access.status} ${access.bytes ?? "-"} "${escape(access.referer ?? "-")}" "${escape(access.userAgent ?? "-")}" ${access.durationMillis}ms`; + `${access.client} - - [${nginxTime(access.time)}] "${escapeLogValue(`${access.method} ${access.target} ${access.protocol}`)}" ${access.status} ${access.bytes ?? "-"} "${escapeLogValue(access.referer ?? "-")}" "${escapeLogValue(access.userAgent ?? "-")}" ${access.durationMillis}ms`; const encoder = new TextEncoder(); diff --git a/packages/stack/src/host/LogForwarder.integration.test.ts b/packages/stack/src/host/LogForwarder.integration.test.ts index 0c382e20fc..2845fbd435 100644 --- a/packages/stack/src/host/LogForwarder.integration.test.ts +++ b/packages/stack/src/host/LogForwarder.integration.test.ts @@ -421,22 +421,7 @@ describe("LogForwarder", () => { const shipped = yield* sink.next; expect(shipped.url).toBe("/api/logs?source_name=cloudflare.logs.prod"); - expect(shipped.events).toEqual([ - expect.objectContaining({ - appname: "gateway", - timestamp: "2026-10-01T09:25:23.000Z", - metadata: { - request: { - method: "POST", - path: "/auth/v1/token", - search: "?grant_type=password", - protocol: "HTTP/1.1", - headers: { cf_connecting_ip: "127.0.0.1" }, - }, - response: { status_code: 400 }, - }, - }), - ]); + expect(shipped.events).toEqual([expect.objectContaining({ appname: "gateway" })]); }).pipe(Effect.scoped, Effect.provide(layer)), ); }); diff --git a/packages/stack/src/host/LogForwarder.ts b/packages/stack/src/host/LogForwarder.ts index 8bc2fbbfb3..991b799387 100644 --- a/packages/stack/src/host/LogForwarder.ts +++ b/packages/stack/src/host/LogForwarder.ts @@ -47,7 +47,10 @@ export interface ForwardedStream { } interface Interface { - /** Ships a shipped service's persisted logs, or tracks an Analytics instance as the target. */ + /** + * Ships the persisted logs of a shipped service or an owner stream, or tracks an Analytics + * instance as the target. + */ readonly attach: (instance: ForwardedInstance | ForwardedStream) => Effect.Effect; /** Re-selects the shipping target after the composition changes. */ readonly rebind: Effect.Effect; @@ -397,11 +400,16 @@ export const make = Effect.fn("LogForwarder.make")(function* (options: LogForwar const attach = Effect.fn("LogForwarder.attach")(function* ( instance: ForwardedInstance | ForwardedStream, ) { - if (instance.service === "gateway") - yield* Effect.forkIn(forward(instance.id, instance.service, Effect.never), scope); - else if (instance.service === "analytics") yield* Effect.forkIn(trackTarget(instance), scope); + if (instance.service === "analytics") yield* Effect.forkIn(trackTarget(instance), scope); else if (isShippedService(instance.service)) - yield* Effect.forkIn(forward(instance.id, instance.service, unregistered(instance)), scope); + yield* Effect.forkIn( + forward( + instance.id, + instance.service, + "observation" in instance ? unregistered(instance) : Effect.never, + ), + scope, + ); }); return { diff --git a/packages/stack/src/host/LogflareEvents.ts b/packages/stack/src/host/LogflareEvents.ts index fe4846ae7e..21f6d1a109 100644 --- a/packages/stack/src/host/LogflareEvents.ts +++ b/packages/stack/src/host/LogflareEvents.ts @@ -3,7 +3,7 @@ import type { ServiceCreation } from "../services/Catalog.ts"; import type { gatewayLog } from "./GatewayLog.ts"; /** A service kind, or the owner's `gateway` stream of shared API listener requests. */ -export type LogService = ServiceCreation["service"] | typeof gatewayLog.service; +type LogService = ServiceCreation["service"] | typeof gatewayLog.service; /** Logflare source per shipped log service; Studio's Logs pages query these names. */ export const logflareSources = { @@ -43,20 +43,21 @@ const parseJsonObject = (text: string): Record | undefined => { } }; -const months: Record = { - jan: 0, - feb: 1, - mar: 2, - apr: 3, - may: 4, - jun: 5, - jul: 6, - aug: 7, - sep: 8, - oct: 9, - nov: 10, - dec: 11, -}; +/** The `%b` month abbreviations of PostgREST and nginx log times, January first. */ +export const monthNames = [ + "Jan", + "Feb", + "Mar", + "Apr", + "May", + "Jun", + "Jul", + "Aug", + "Sep", + "Oct", + "Nov", + "Dec", +] as const; /** Parses the `%d/%b/%Y:%H:%M:%S %z` time of PostgREST and nginx logs into ISO-8601. */ const parseLogTime = (text: string): string | undefined => { @@ -64,8 +65,8 @@ const parseLogTime = (text: string): string | undefined => { /^(\d{2})\/([A-Za-z]{3})\/(\d{4}):(\d{2}):(\d{2}):(\d{2}) ([+-])(\d{2})(\d{2})$/u.exec(text); if (match === null) return undefined; const [, day, month, year, hour, minute, second, sign, zoneHours, zoneMinutes] = match; - const monthIndex = months[month?.toLowerCase() ?? ""]; - if (monthIndex === undefined) return undefined; + const monthIndex = monthNames.findIndex((name) => name.toLowerCase() === month?.toLowerCase()); + if (monthIndex < 0) return undefined; const utc = Date.UTC( Number(year), monthIndex, From a267a43fa134d2a5837456471059fb558524b59a Mon Sep 17 00:00:00 2001 From: avallete Date: Thu, 1 Oct 2026 19:45:58 +0200 Subject: [PATCH 08/11] fix(stack): redact S3 presigned URL signatures in gateway access lines Co-Authored-By: Claude Opus 5.5 --- .../src/commands/experimental/stack/start/SIDE_EFFECTS.md | 7 ++++--- packages/stack/src/HttpProxy.ts | 6 +++++- packages/stack/src/HttpProxy.unit.test.ts | 6 ++++++ 3 files changed, 15 insertions(+), 4 deletions(-) diff --git a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md index 5c3c5c40de..4f40624488 100644 --- a/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md +++ b/apps/cli/src/commands/experimental/stack/start/SIDE_EFFECTS.md @@ -44,9 +44,10 @@ PostgREST runs with `PGRST_LOG_LEVEL=info`, so every request line, query string persisted and shipped to Analytics. The shared API port also records one nginx combined line plus duration (`... "GET /rest/v1/todos?select=* HTTP/1.1" 200 126 "-" "curl/8.7.1" 12ms`) per request and WebSocket upgrade under `logs/gateway/gateway/`, with the same retention; credential query and -fragment values (`apikey`, `token`, `token_hash`, `code`, and access, refresh, ID, and provider -tokens), in the request target and the Referer, are written as `redacted`, as are values that -themselves carry such a pair (a `redirect_to` URL with a token) and URL userinfo. +fragment values (`apikey`, `token`, `token_hash`, `code`, access, refresh, ID, and provider +tokens, and the `X-Amz-Signature`, `X-Amz-Credential`, and `X-Amz-Security-Token` of S3 +presigned URLs), in the request target and the Referer, are written as `redacted`, as are values +that themselves carry such a pair (a `redirect_to` URL with a token) and URL userinfo. When an owner starts a stack saved with a Vector instance, it removes that instance, its composition members, dependencies and port claims from `state.json`, and its stack-owned Vector config files under `data//runtime/vector/`; its containers go with the stack's container sweep. diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index 3c6ec89959..a1132aca94 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -163,7 +163,8 @@ const decodeNested = (value: string) => { return current; }; -// Auth puts PKCE codes, OTP token hashes and OAuth tokens in redirect and verify URLs. +// Auth puts PKCE codes, OTP token hashes and OAuth tokens in redirect and verify URLs; S3 +// presigned URLs carry their SigV4 signature, credential scope and session token. const credentialParameters = [ "apikey", "access_token", @@ -174,6 +175,9 @@ const credentialParameters = [ "id_token", "provider_token", "provider_refresh_token", + "x-amz-signature", + "x-amz-credential", + "x-amz-security-token", ]; const scheme = String.raw`[a-z][a-z\d+.-]*`; diff --git a/packages/stack/src/HttpProxy.unit.test.ts b/packages/stack/src/HttpProxy.unit.test.ts index 414cfc6025..f05992d06f 100644 --- a/packages/stack/src/HttpProxy.unit.test.ts +++ b/packages/stack/src/HttpProxy.unit.test.ts @@ -13,6 +13,12 @@ describe("redactCredentials", () => { url: "/auth/v1/verify?code=pkce&token_hash=h&type=signup", redacted: "/auth/v1/verify?code=redacted&token_hash=redacted&type=signup", }, + { + case: "redacts S3 presigned URL signatures and session tokens", + url: "/storage/v1/s3/b/o.txt?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AK%2F20261001%2Flocal%2Fs3%2Faws4_request&X-Amz-Expires=60&X-Amz-Security-Token=st&X-Amz-Signature=abc", + redacted: + "/storage/v1/s3/b/o.txt?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=redacted&X-Amz-Expires=60&X-Amz-Security-Token=redacted&X-Amz-Signature=redacted", + }, { case: "redacts fragment credentials of an absolute URL", url: "http://127.0.0.1:54321/x?token=t1&select=*#access_token=frag&type=bearer", From 91458781880e6525660b665874b9fbc07366cb2c Mon Sep 17 00:00:00 2001 From: avallete Date: Fri, 2 Oct 2026 19:40:59 +0200 Subject: [PATCH 09/11] fix(stack): redact Edge Function websocket JWTs in gateway logs Co-Authored-By: Claude Opus 5.5 --- packages/stack/src/HttpProxy.ts | 1 + packages/stack/src/HttpProxy.unit.test.ts | 5 +++++ 2 files changed, 6 insertions(+) diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index a1132aca94..d1f3f6cdbd 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -167,6 +167,7 @@ const decodeNested = (value: string) => { // presigned URLs carry their SigV4 signature, credential scope and session token. const credentialParameters = [ "apikey", + "jwt", "access_token", "token", "token_hash", diff --git a/packages/stack/src/HttpProxy.unit.test.ts b/packages/stack/src/HttpProxy.unit.test.ts index f05992d06f..8b3c2c84b3 100644 --- a/packages/stack/src/HttpProxy.unit.test.ts +++ b/packages/stack/src/HttpProxy.unit.test.ts @@ -8,6 +8,11 @@ describe("redactCredentials", () => { url: "/api/ok?select=*&apikey=sb_secret_x&Access_Token=jwt", redacted: "/api/ok?select=*&apikey=redacted&Access_Token=redacted", }, + { + case: "redacts an Edge Function websocket JWT", + url: "/functions/v1/realtime-chat?jwt=eyJ.p.s", + redacted: "/functions/v1/realtime-chat?jwt=redacted", + }, { case: "redacts Auth codes and OTP token hashes", url: "/auth/v1/verify?code=pkce&token_hash=h&type=signup", From 84125ac6e57861cb4840a69ceb9284b64adf207d Mon Sep 17 00:00:00 2001 From: avallete Date: Fri, 2 Oct 2026 20:33:10 +0200 Subject: [PATCH 10/11] refactor(stack): move gateway credential redaction into its own module Proxy request and upgrade spans record their route and response status. CLI tests share one unused gateway fake, and the gateway tests leave the line format to the proxy tests and prove a request is recorded once. Co-Authored-By: Claude Opus 5.5 --- .../db-config.integration.test.ts | 3 +- .../commands/db/dump/dump.integration.test.ts | 3 +- .../db/reset/reset.integration.test.ts | 3 +- .../generate/generate.integration.test.ts | 3 +- .../declarative/sync/sync.integration.test.ts | 3 +- .../db/start/start.integration.test.ts | 3 +- .../stack/prepare/prepare.integration.test.ts | 3 +- .../start-export-pointer.integration.test.ts | 3 +- .../stack/start/start.integration.test.ts | 3 +- .../stack/status/status.integration.test.ts | 3 +- .../serve/serve.stack.integration.test.ts | 3 +- apps/cli/tests/helpers/storage.ts | 3 +- apps/cli/tests/helpers/unused-stack.ts | 6 +- .../stack/src/HttpProxy.integration.test.ts | 6 ++ packages/stack/src/HttpProxy.ts | 90 +++---------------- .../stack/src/Owner.logs.integration.test.ts | 6 +- .../stack/src/internal/redact-credentials.ts | 77 ++++++++++++++++ .../redact-credentials.unit.test.ts} | 2 +- 18 files changed, 127 insertions(+), 96 deletions(-) create mode 100644 packages/stack/src/internal/redact-credentials.ts rename packages/stack/src/{HttpProxy.unit.test.ts => internal/redact-credentials.unit.test.ts} (98%) diff --git a/apps/cli/src/command-internal/db-config.integration.test.ts b/apps/cli/src/command-internal/db-config.integration.test.ts index ad1e3d4390..8ce8f853f6 100644 --- a/apps/cli/src/command-internal/db-config.integration.test.ts +++ b/apps/cli/src/command-internal/db-config.integration.test.ts @@ -33,6 +33,7 @@ import { mockTty, } from "../../tests/helpers/mocks.ts"; import { VALID_TOKEN, mockCommandSettings } from "../../tests/helpers/command-mocks.ts"; +import { unusedGateway } from "../../tests/helpers/unused-stack.ts"; import { DebugFlag, DnsResolverFlag, @@ -489,7 +490,7 @@ describe("dbConfigResolver (db-url under the stack backend)", () => { }, stop: unused, destroy: unused, - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => unused }, }; return Layer.succeed(StackApi, { diff --git a/apps/cli/src/commands/db/dump/dump.integration.test.ts b/apps/cli/src/commands/db/dump/dump.integration.test.ts index 642203185b..76a7e9518e 100644 --- a/apps/cli/src/commands/db/dump/dump.integration.test.ts +++ b/apps/cli/src/commands/db/dump/dump.integration.test.ts @@ -16,6 +16,7 @@ import { import { ChildProcess, ChildProcessSpawner } from "effect/unstable/process"; import { mockOutput, mockTty, processEnvLayer } from "../../../../tests/helpers/mocks.ts"; +import { unusedGateway } from "../../../../tests/helpers/unused-stack.ts"; import { VALID_REF, mockCommandSettings, @@ -153,7 +154,7 @@ const managedDumpStackApi = (runtime: "native" | "docker") => { }, stop: Effect.void, destroy: Effect.succeed({ runtimeCleanup: "complete" as const }), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: runCommand }, } satisfies Stack; return Layer.succeed(StackApi, { diff --git a/apps/cli/src/commands/db/reset/reset.integration.test.ts b/apps/cli/src/commands/db/reset/reset.integration.test.ts index 15f5c5b81f..d3fed41fb4 100644 --- a/apps/cli/src/commands/db/reset/reset.integration.test.ts +++ b/apps/cli/src/commands/db/reset/reset.integration.test.ts @@ -39,6 +39,7 @@ import { sequentialExecBatch, transportFailure, } from "../../../../tests/helpers/command-mocks.ts"; +import { unusedGateway } from "../../../../tests/helpers/unused-stack.ts"; import { CommandPlatformApi } from "../../../auth/command-platform-api.service.ts"; import { CommandPlatformApiFactory } from "../../../auth/command-platform-api-factory.service.ts"; import { ProjectRefNotLinkedError } from "../../../config/project-ref.errors.ts"; @@ -808,7 +809,7 @@ function mockResetStackApi(opts: { }, stop: Effect.die("unused"), destroy: Effect.die("unused"), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => Effect.die("unused") }, }; return { diff --git a/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts b/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts index cfeca95094..74e8cee717 100644 --- a/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts +++ b/apps/cli/src/commands/db/schema/declarative/generate/generate.integration.test.ts @@ -14,6 +14,7 @@ import { } from "effect"; import { StackError, type DatabaseInstance, type Stack } from "@supabase/stack/effect"; import { stripAnsi } from "../../../../../../tests/helpers/ansi.ts"; +import { unusedGateway } from "../../../../../../tests/helpers/unused-stack.ts"; import { alwaysReadyHttpClientLayer, @@ -164,7 +165,7 @@ function generateStackApi(workdir: string) { }, stop: unusedStack, destroy: unusedStack, - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: unusedStackFn }, }; const identity = { projectRoot: workdir, branchContext: "main", stackName: "default" }; diff --git a/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts b/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts index bb222990b2..4d0321f07d 100644 --- a/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts +++ b/apps/cli/src/commands/db/schema/declarative/sync/sync.integration.test.ts @@ -14,6 +14,7 @@ import { } from "effect"; import { stripAnsi } from "../../../../../../tests/helpers/ansi.ts"; +import { unusedGateway } from "../../../../../../tests/helpers/unused-stack.ts"; import { alwaysReadyHttpClientLayer, defaultLocalResetRoute, @@ -166,7 +167,7 @@ function syncStackApi(workdir: string, port: number) { }, stop: unusedSync, destroy: unusedSync, - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: unusedSyncFn }, }; const identity = { projectRoot: workdir, branchContext: "main", stackName: "default" }; diff --git a/apps/cli/src/commands/db/start/start.integration.test.ts b/apps/cli/src/commands/db/start/start.integration.test.ts index fdeca26575..eeaaefa772 100644 --- a/apps/cli/src/commands/db/start/start.integration.test.ts +++ b/apps/cli/src/commands/db/start/start.integration.test.ts @@ -23,6 +23,7 @@ import { mockProcessControl, mockRuntimeInfo, } from "../../../../tests/helpers/mocks.ts"; +import { unusedGateway } from "../../../../tests/helpers/unused-stack.ts"; import { mockCommandSettings, mockLocalDockerEngineUnavailableLayer, @@ -1733,7 +1734,7 @@ describe("db start stack backend", () => { }, stop: Effect.void, destroy: Effect.succeed({ runtimeCleanup: "complete" as const }), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => Effect.die("unused") }, }; return { stack, state }; diff --git a/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts b/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts index c377fd3316..bce7ca9e63 100644 --- a/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/prepare/prepare.integration.test.ts @@ -17,6 +17,7 @@ import { containerEngineSpawner, type ContainerEngineState, } from "../../../../../tests/helpers/child-process-spawner.ts"; +import { unusedGateway } from "../../../../../tests/helpers/unused-stack.ts"; import { mockCommandSettings, mockTelemetryStateTracked, @@ -157,7 +158,7 @@ const makeFixture = (root: string, options: FixtureOptions = {}) => { }, stop: Effect.void, destroy: Effect.succeed({ runtimeCleanup: "complete" as const }), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => Effect.die("unused") }, }; const output = mockOutput(); diff --git a/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts b/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts index f8ac2d7753..dc425005fb 100644 --- a/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/start/start-export-pointer.integration.test.ts @@ -19,6 +19,7 @@ import { mockTty, } from "../../../../../tests/helpers/mocks.ts"; import { mockTelemetryStateTracked } from "../../../../../tests/helpers/command-mocks.ts"; +import { unusedGateway } from "../../../../../tests/helpers/unused-stack.ts"; import { commandRuntimeLayer } from "../../../../shared/runtime/command-runtime.layer.ts"; import { CliArgs } from "../../../../shared/cli/cli-args.service.ts"; import { textCliOutputFormatter } from "../../../../shared/output/text-formatter.ts"; @@ -112,7 +113,7 @@ function makeDatabaseStack(sqlPort: number, credentials: StackCredentials): Stac }, stop: Effect.die("unused"), destroy: Effect.die("unused"), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => Effect.die("unused") }, } satisfies Stack; } diff --git a/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts b/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts index 5b0d9379a7..0df657500d 100644 --- a/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/start/start.integration.test.ts @@ -34,6 +34,7 @@ import { withEnvVar, } from "../../../../../tests/helpers/command-mocks.ts"; import { mockOutput, mockRuntimeInfo, mockTty } from "../../../../../tests/helpers/mocks.ts"; +import { unusedGateway } from "../../../../../tests/helpers/unused-stack.ts"; import { containerEngineSpawner } from "../../../../../tests/helpers/child-process-spawner.ts"; import { DbConnection, @@ -352,7 +353,7 @@ const fakeStack = (compositionStart?: Stack["composition"]["start"]) => { hostDestroyed += 1; return { runtimeCleanup: "complete" as const }; }), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => Effect.die("command not used") }, }; return { diff --git a/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts b/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts index 2abbb751c0..c41c585456 100644 --- a/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts +++ b/apps/cli/src/commands/experimental/stack/status/status.integration.test.ts @@ -9,6 +9,7 @@ import { StackError, } from "@supabase/stack/effect"; import { mockOutput } from "../../../../../tests/helpers/mocks.ts"; +import { unusedGateway } from "../../../../../tests/helpers/unused-stack.ts"; import { mockCommandSettings, mockTelemetryStateTracked, @@ -176,7 +177,7 @@ const makeStack = ( }, stop: Effect.die("unused"), destroy: Effect.die("unused"), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: (_tool, _options) => Effect.die("unused"), }, diff --git a/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts b/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts index 0f9ba4f130..0dc3a08250 100644 --- a/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts +++ b/apps/cli/src/commands/functions/serve/serve.stack.integration.test.ts @@ -26,6 +26,7 @@ import { import { StackApi } from "../../../command-internal/stack-api.ts"; import { OutputFlag } from "../../../command-internal/global-flags.ts"; import { mockCommandSettings } from "../../../../tests/helpers/command-mocks.ts"; +import { unusedGateway } from "../../../../tests/helpers/unused-stack.ts"; import { mockOutput, mockProcessControl, @@ -287,7 +288,7 @@ const fixture = ( }, stop: Effect.die("unused"), destroy: Effect.die("unused"), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => Effect.die("unused") }, } satisfies Stack; const identity = { projectRoot: "/project", branchContext: "main", stackName: "default" }; diff --git a/apps/cli/tests/helpers/storage.ts b/apps/cli/tests/helpers/storage.ts index 3e5b651316..33430edc67 100644 --- a/apps/cli/tests/helpers/storage.ts +++ b/apps/cli/tests/helpers/storage.ts @@ -18,6 +18,7 @@ import { CliArgs } from "../../src/shared/cli/cli-args.service.ts"; import { CommandPlatformApi } from "../../src/auth/command-platform-api.service.ts"; import { CommandPlatformApiFactory } from "../../src/auth/command-platform-api-factory.service.ts"; import { ProjectRefNotLinkedError } from "../../src/config/project-ref.errors.ts"; +import { unusedGateway } from "./unused-stack.ts"; import { ProjectRefResolver } from "../../src/config/project-ref.service.ts"; import { generateGoJwt } from "../../src/command-internal/go-jwt.ts"; import { YesFlag } from "../../src/command-internal/global-flags.ts"; @@ -263,7 +264,7 @@ export function buildStorageStackApi( }, stop: Effect.die("unused"), destroy: Effect.die("unused"), - gateway: { readLogs: () => Stream.die("unused") }, + gateway: unusedGateway, commands: { run: () => Effect.die("unused") }, }; const definition = { diff --git a/apps/cli/tests/helpers/unused-stack.ts b/apps/cli/tests/helpers/unused-stack.ts index ea1039f398..381dc84a8a 100644 --- a/apps/cli/tests/helpers/unused-stack.ts +++ b/apps/cli/tests/helpers/unused-stack.ts @@ -1,4 +1,5 @@ -import { Effect, Layer } from "effect"; +import { Effect, Layer, Stream } from "effect"; +import type { Stack } from "@supabase/stack/effect"; import { StackApi } from "../../src/command-internal/stack-api.ts"; import { StackCatalogSetup } from "../../src/command-internal/stack-catalog-setup.ts"; @@ -13,3 +14,6 @@ export const unusedStackServices = Layer.mergeAll( }), Layer.succeed(StackCatalogSetup, { apply: unused }), ); + +/** Fills a fake `Stack`'s gateway log stream for tests that never read it. */ +export const unusedGateway: Stack["gateway"] = { readLogs: () => Stream.die("unused") }; diff --git a/packages/stack/src/HttpProxy.integration.test.ts b/packages/stack/src/HttpProxy.integration.test.ts index c9d6e8b9e9..2d95d4cb1a 100644 --- a/packages/stack/src/HttpProxy.integration.test.ts +++ b/packages/stack/src/HttpProxy.integration.test.ts @@ -1135,6 +1135,12 @@ it.live( expect.objectContaining({ target: "/elsewhere", status: 404, bytes: 9 }), expect.objectContaining({ target: "/down/thing", status: 502, bytes: 11 }), ]); + + // A later sentinel request proves none of the four requests above recorded twice. + const sentinelStatus = yield* get("/api/ok?select=sentinel"); + const sentinel = yield* Queue.take(accesses); + expect(sentinelStatus).toBe(200); + expect(sentinel).toMatchObject({ target: "/api/ok?select=sentinel" }); expect(yield* Queue.size(accesses)).toBe(0); }), ).pipe( diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index d1f3f6cdbd..1c7ffaacc3 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -1,4 +1,5 @@ import { Clock, Data, Deferred, Effect, Fiber, FiberSet, Ref, Scope } from "effect"; +import { decodeQuery, redactCredentials } from "./internal/redact-credentials.ts"; import { PortError } from "./Ports.ts"; import type { BackendAddress, ProxyError } from "./Proxy.ts"; import { @@ -144,83 +145,6 @@ const upstreamHeadersFor = (headers: IncomingMessage["headers"], route: HttpRout return result; }; -const decodeQuery = (value: string) => { - try { - return decodeURIComponent(value.replace(/\+/gu, " ")); - } catch { - return value; - } -}; - -/** Decodes repeatedly so a nested URL encoded more than once still exposes its delimiters. */ -const decodeNested = (value: string) => { - let current = value; - for (let pass = 0; pass < 4; pass++) { - const next = decodeQuery(current); - if (next === current) break; - current = next; - } - return current; -}; - -// Auth puts PKCE codes, OTP token hashes and OAuth tokens in redirect and verify URLs; S3 -// presigned URLs carry their SigV4 signature, credential scope and session token. -const credentialParameters = [ - "apikey", - "jwt", - "access_token", - "token", - "token_hash", - "code", - "refresh_token", - "id_token", - "provider_token", - "provider_refresh_token", - "x-amz-signature", - "x-amz-credential", - "x-amz-security-token", -]; -const scheme = String.raw`[a-z][a-z\d+.-]*`; - -/** - * A decoded parameter that is a credential pair, nests one (a `redirect_to` URL carrying a - * token), or nests a URL with userinfo. - */ -const sensitive = new RegExp( - String.raw`(?:^|[?&#=])(?:${credentialParameters.join("|")})=|${scheme}:\/\/[^/?#@]*@`, - "iu", -); -const userinfo = new RegExp(String.raw`^(${scheme}:\/\/)[^/?#@]*@`, "iu"); - -const redactPairs = (pairs: string) => - pairs - .split("&") - .map((parameter) => { - const separator = parameter.indexOf("="); - return separator >= 0 && sensitive.test(decodeNested(parameter)) - ? `${parameter.slice(0, separator)}=redacted` - : parameter; - }) - .join("&"); - -/** - * Redacts an absolute URL's userinfo and credential values in its query and fragment, where - * OAuth implicit grants put `access_token` for non-browser clients. Edits the text in place, so - * relative and unparsable URLs work and the rest of the URL keeps its original encoding. - */ -export const redactCredentials = (url: string) => { - const hashAt = url.indexOf("#"); - const beforeHash = hashAt < 0 ? url : url.slice(0, hashAt); - const queryAt = beforeHash.indexOf("?"); - const base = (queryAt < 0 ? beforeHash : beforeHash.slice(0, queryAt)).replace( - userinfo, - "$1redacted@", - ); - const query = queryAt < 0 ? "" : `?${redactPairs(beforeHash.slice(queryAt + 1))}`; - const fragment = hashAt < 0 ? "" : `#${redactPairs(url.slice(hashAt + 1))}`; - return `${base}${query}${fragment}`; -}; - /** Captures a request's access fields while its socket is open; completes them once it settles. */ const accessFor = (request: IncomingMessage, time: number) => { const referer = headerValue(request.headers.referer); @@ -479,6 +403,7 @@ const proxyRequest = Effect.fn("HttpProxy.proxyRequest")( sent: Sent, ) => Effect.gen(function* () { + yield* Effect.annotateCurrentSpan({ route_id: route.id }); const backend = yield* Effect.raceFirst(route.target, disconnected(request, response)); yield* forward( request, @@ -495,7 +420,15 @@ const proxyRequest = Effect.fn("HttpProxy.proxyRequest")( ).pipe(Effect.andThen(forward(request, response, route, backend, false, sent))), ), ); - }), + }).pipe( + Effect.ensuring( + Effect.suspend(() => + response.headersSent + ? Effect.annotateCurrentSpan({ "http.response.status_code": response.statusCode }) + : Effect.void, + ), + ), + ), ); const statusLine = /^HTTP\/\d(?:\.\d)? (\d{3})\b/u; @@ -511,6 +444,7 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( handshake: Deferred.Deferred, ) => Effect.gen(function* () { + yield* Effect.annotateCurrentSpan({ route_id: route.id }); const backend = yield* Effect.raceFirst( route.target, Effect.callback((resume) => { diff --git a/packages/stack/src/Owner.logs.integration.test.ts b/packages/stack/src/Owner.logs.integration.test.ts index 2555e3ba46..53c219aa2b 100644 --- a/packages/stack/src/Owner.logs.integration.test.ts +++ b/packages/stack/src/Owner.logs.integration.test.ts @@ -210,13 +210,11 @@ describe("owner persisted logs", () => { ); if (api === undefined) return yield* Effect.die("the shared API port was not claimed"); - const response = yield* client.get(`http://127.0.0.1:${api.port}/unrouted?apikey=k`); + const response = yield* client.get(`http://127.0.0.1:${api.port}/unrouted`); const [recorded] = yield* firstOutput(first.rpc.readLogs({ id: "gateway", follow: true })); expect(response.status).toBe(404); - expect(recorded?.text).toMatch( - /^127\.0\.0\.1 - - \[[^\]]+\] "GET \/unrouted\?apikey=redacted HTTP\/1\.1" 404 9 "-" "[^"]*" \d+ms$/u, - ); + expect(recorded?.text).toContain("/unrouted"); const directory = path.join(first.logsRoot, "gateway", "gateway"); expect(yield* fs.readDirectory(directory)).toEqual(["0000000001.log"]); yield* Scope.close(firstScope, Exit.void); diff --git a/packages/stack/src/internal/redact-credentials.ts b/packages/stack/src/internal/redact-credentials.ts new file mode 100644 index 0000000000..4d9f257925 --- /dev/null +++ b/packages/stack/src/internal/redact-credentials.ts @@ -0,0 +1,77 @@ +/** Decodes a query component, keeping it as is when it is not valid percent-encoding. */ +export const decodeQuery = (value: string) => { + try { + return decodeURIComponent(value.replace(/\+/gu, " ")); + } catch { + return value; + } +}; + +/** Decodes repeatedly so a nested URL encoded more than once still exposes its delimiters. */ +const decodeNested = (value: string) => { + let current = value; + for (let pass = 0; pass < 4; pass++) { + const next = decodeQuery(current); + if (next === current) break; + current = next; + } + return current; +}; + +// Auth puts PKCE codes, OTP token hashes and OAuth tokens in redirect and verify URLs; S3 +// presigned URLs carry their SigV4 signature, credential scope and session token. +const credentialParameters = [ + "apikey", + "jwt", + "access_token", + "token", + "token_hash", + "code", + "refresh_token", + "id_token", + "provider_token", + "provider_refresh_token", + "x-amz-signature", + "x-amz-credential", + "x-amz-security-token", +]; +const scheme = String.raw`[a-z][a-z\d+.-]*`; + +/** + * A decoded parameter that is a credential pair, nests one (a `redirect_to` URL carrying a + * token), or nests a URL with userinfo. + */ +const sensitive = new RegExp( + String.raw`(?:^|[?&#=])(?:${credentialParameters.join("|")})=|${scheme}:\/\/[^/?#@]*@`, + "iu", +); +const userinfo = new RegExp(String.raw`^(${scheme}:\/\/)[^/?#@]*@`, "iu"); + +const redactPairs = (pairs: string) => + pairs + .split("&") + .map((parameter) => { + const separator = parameter.indexOf("="); + return separator >= 0 && sensitive.test(decodeNested(parameter)) + ? `${parameter.slice(0, separator)}=redacted` + : parameter; + }) + .join("&"); + +/** + * Redacts an absolute URL's userinfo and credential values in its query and fragment, where + * OAuth implicit grants put `access_token` for non-browser clients. Edits the text in place, so + * relative and unparsable URLs work and the rest of the URL keeps its original encoding. + */ +export const redactCredentials = (url: string) => { + const hashAt = url.indexOf("#"); + const beforeHash = hashAt < 0 ? url : url.slice(0, hashAt); + const queryAt = beforeHash.indexOf("?"); + const base = (queryAt < 0 ? beforeHash : beforeHash.slice(0, queryAt)).replace( + userinfo, + "$1redacted@", + ); + const query = queryAt < 0 ? "" : `?${redactPairs(beforeHash.slice(queryAt + 1))}`; + const fragment = hashAt < 0 ? "" : `#${redactPairs(url.slice(hashAt + 1))}`; + return `${base}${query}${fragment}`; +}; diff --git a/packages/stack/src/HttpProxy.unit.test.ts b/packages/stack/src/internal/redact-credentials.unit.test.ts similarity index 98% rename from packages/stack/src/HttpProxy.unit.test.ts rename to packages/stack/src/internal/redact-credentials.unit.test.ts index 8b3c2c84b3..93d44c6a49 100644 --- a/packages/stack/src/HttpProxy.unit.test.ts +++ b/packages/stack/src/internal/redact-credentials.unit.test.ts @@ -1,5 +1,5 @@ import { describe, expect, it } from "@effect/vitest"; -import { redactCredentials } from "./HttpProxy.ts"; +import { redactCredentials } from "./redact-credentials.ts"; describe("redactCredentials", () => { it.each([ From e756e1e45f5027fedd486976cd08837a9f2e2e22 Mon Sep 17 00:00:00 2001 From: avallete Date: Fri, 2 Oct 2026 21:01:09 +0200 Subject: [PATCH 11/11] fix(stack): record the handshake status on proxy upgrade spans Co-Authored-By: Claude Opus 5.5 --- packages/stack/src/HttpProxy.ts | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/packages/stack/src/HttpProxy.ts b/packages/stack/src/HttpProxy.ts index 1c7ffaacc3..c899dedd43 100644 --- a/packages/stack/src/HttpProxy.ts +++ b/packages/stack/src/HttpProxy.ts @@ -528,7 +528,19 @@ const upgrade = Effect.fn("HttpProxy.upgrade")( upstream.destroy(); }); }); - }), + }).pipe( + Effect.ensuring( + Effect.suspend(() => + Deferred.isDoneUnsafe(handshake) + ? Deferred.await(handshake).pipe( + Effect.flatMap((status) => + Effect.annotateCurrentSpan({ "http.response.status_code": status }), + ), + ) + : Effect.void, + ), + ), + ), ); export const makeHttpProxy = (options: {