diff --git a/apps/cli/src/legacy/commands/experimental/workers/logs/SIDE_EFFECTS.md b/apps/cli/src/legacy/commands/experimental/workers/logs/SIDE_EFFECTS.md new file mode 100644 index 0000000000..8c12df3ba4 --- /dev/null +++ b/apps/cli/src/legacy/commands/experimental/workers/logs/SIDE_EFFECTS.md @@ -0,0 +1,132 @@ +# `supabase experimental workers logs ` + +> **No live test yet.** The other `workers` commands skip live coverage because they +> run against the v2 Management API, which the supabase/cli-e2e-ci supabox stack is +> not expected to serve. This one reads the v1 analytics endpoint, which that stack +> may well serve — but a meaningful assertion needs a deployed worker that has +> actually emitted log lines, which the stack cannot provide. Revisit alongside the +> rest of the family. + +## Files Read + +| Path | Format | When | +| --------------------------------------------- | ---------- | ----------------------------------------------------------------------------------------------------------- | +| `/access-token` | plain text | when `SUPABASE_ACCESS_TOKEN` is unset and the keyring holds no credential | +| `/supabase/.temp/project-ref` | plain text | when neither `--project-ref` nor `SUPABASE_PROJECT_ID` is set — names the linked project | +| `/profile` | plain text | when neither `--profile` nor `SUPABASE_PROFILE` is set — names the profile, defaulting to `supabase` | +| `` (YAML) | YAML | when `SUPABASE_PROFILE` is a filesystem path rather than a built-in name; a read failure aborts the command | + +The project config is **not** read. Unlike `status` and `delete`, nothing in this +command's output depends on local state — there is no source path to report — so +`config.toml` is never opened and an unparseable one cannot block a log read. + +## Files Written + +| Path | Format | When | +| ----------------------------------------------- | ------ | --------------------------------------------------------------- | +| `/telemetry.json` | JSON | always — flushed on success and on failure | +| `/supabase/.temp/linked-project.json` | JSON | after the project ref resolves, when the cache does not hold it | + +## API Routes + +| Method | Path | Auth | Request | Response (used fields) | +| ------ | --------------------------------------------- | ------------ | ----------------------------------------------------------------------------------------------------- | ---------------------- | +| `GET` | `/v1/projects/{ref}/analytics/endpoints/logs` | Bearer token | `sql`, `iso_timestamp_start`, `iso_timestamp_end` as query parameters | `result[]`, `error` | +| `GET` | `/v2/projects/{ref}/workers/{name}` | Bearer token | none — **only when the log query returned no rows**, to tell "not deployed" from "deployed and quiet" | presence only | +| `GET` | `/v1/projects` | Bearer token | none — only when no ref resolved and the session is interactive | project picker | + +Requires the `analytics_logs_read` permission, and the project must be on the +Workers private-alpha allow-list — an unenrolled project answers 404. + +### The query + +SQL in **ClickHouse dialect** against the project's unified `logs` table, filtered +on `log_attributes['worker']` and `log_attributes['source']`. It does **not** filter +the top-level `source` column: worker rows carry an empty string there, because the +Workers Logflare source is not enrolled as a category in the generic logs path. + +### The window + +Both `iso_timestamp_start` and `iso_timestamp_end` are always sent, spanning just +under 24 hours. This is not optional: + +- one bound alone yields a **one-minute** window, server-side and silently; +- neither bound is an outright error; +- a span over 24 hours is **silently clamped** to `start + 24h`, which returns an + older slice than the one requested rather than a truncated one. + +### Rate limits + +The v1 analytics endpoints allow **10 requests per 60 seconds**, and the server +applies a 30-second query timeout. One bounded invocation spends one request, or +two when the result is empty. + +`--follow` polls every **10 seconds** — 6 requests a minute, leaving room for the +history query, the deployed-worker check, and a retry inside the same window. The +interval is set by that limit, not by responsiveness: a 2-second poll would spend +the allowance in ten seconds. A 429 mid-tail is retried on a spaced schedule +rather than ending the tail. + +Each poll re-asks for a window starting 60 seconds behind the newest line already +printed, because guest lines arrive late and out of order. Overlap is therefore +guaranteed and is deduplicated on the Logflare-minted `id`. + +## Exit Codes + +| Code | Condition | +| ---- | ------------------------------------------------------------ | +| `0` | success, including "no logs in the last 24 hours" | +| `1` | invalid worker name | +| `1` | nothing deployed under that name | +| `1` | the log query failed (rejected, or the server's 30s timeout) | +| `1` | log usage exceeded (402), or rate limited (429) | +| `1` | API error, or project not enrolled in the alpha | + +## Environment Variables + +| Variable | Purpose | Required? | +| ----------------------- | ---------------------------------------------------- | ---------------------------------------------------------------- | +| `SUPABASE_ACCESS_TOKEN` | auth token (bypasses credential file/keyring lookup) | no (falls back to keyring → `~/.supabase/access-token`) | +| `SUPABASE_PROFILE` | built-in profile name or YAML file path | no (falls back to `~/.supabase/profile` -> `supabase`) | +| `SUPABASE_PROJECT_ID` | project ref, consulted after `--project-ref` | no (falls back to `supabase/.temp/project-ref`, then the picker) | +| `SUPABASE_WORKDIR` | project directory the command acts on | no (falls back to `--workdir`, then the ancestor walk) | +| `SUPABASE_HOME` | directory holding `telemetry.json` | no (falls back to `~/.supabase`) | + +## Telemetry Events Fired + +| Event | When | Notable properties / groups | +| ---------------------- | ------------------------------------------ | ----------------------------------- | +| `cli_command_executed` | post-run, success or failure (via wrapper) | `exit_code`, `duration_ms`, `flags` | + +`--source` is a choice flag, so its value is logged verbatim (a closed enum carries +no user data). `--project-ref` is not on this command's safe list, so its value is +redacted. No custom events. + +## Output Formats + +| Mode | stdout | stderr | +| ----------------------------- | --------------------------------------------------------------------------------------------------- | --------------------------------------------------------- | +| text (default) | one line per entry, oldest first, per-stream layout; `HH:MM:SS` local time; severity as colour | the spinner, and the `status` hint when there are no logs | +| `--output-format json` | one structured result carrying every entry | as above | +| `--output-format stream-json` | the same result as a single terminal event | as above | +| `-o json` / `yaml` / `toml` | the same payload in that encoding, and nothing else | as above | +| `-o pretty` / `table` / `csv` | the text rendering — these fall through rather than encoding | as above | +| `-o env` | refused before any request; the payload nests a `logs` array a flat `KEY=value` list cannot express | the error | + +With `--follow`, `stream-json` emits a `log-entry` event per line rather than one +terminal `result` — a tail has no last element. Its `stream` field is `stderr` when +the derived level is error or warn and `stdout` otherwise, and `source` separates +the initial backlog (`history`) from lines that arrived afterwards (`live`). +`--tail 0 --follow` skips the backlog entirely and makes no history request, since +the endpoint rejects `limit 0`. + +Text output prints the time in the reader's own timezone, matching the `--debug` +HTTP logger. Machine payloads carry the unambiguous forms instead — each entry's +`id`, both `timestamp` (ISO-8601 UTC) and `timestamp_ms` (raw epoch), `stream`, +`message`, the derived `level` when one exists, and the raw `attributes` map — whose values are all strings, since the column is a +`Map(String, String)`. + +A `worker_guest_logs` message is bytes the tenant's own code printed. Control and +escape sequences are stripped before it reaches a terminal, so a worker cannot +reposition the cursor or forge CLI output; interior newlines and indentation are +preserved so a stack trace survives intact. diff --git a/apps/cli/src/legacy/commands/experimental/workers/logs/logs.command.ts b/apps/cli/src/legacy/commands/experimental/workers/logs/logs.command.ts new file mode 100644 index 0000000000..ebeedc332f --- /dev/null +++ b/apps/cli/src/legacy/commands/experimental/workers/logs/logs.command.ts @@ -0,0 +1,97 @@ +import { Argument, Command, Flag } from "effect/unstable/cli"; +import type * as CliCommand from "effect/unstable/cli/Command"; +import { withJsonErrorHandling } from "../../../../../shared/output/json-error-handling.ts"; +import { legacyManagementApiRuntimeLayer } from "../../../../shared/legacy-management-api-runtime.layer.ts"; +import { WORKER_LOG_POLL_SECONDS } from "../../../../../shared/workers/worker-logs.sql.ts"; +import { withLegacyCommandInstrumentation } from "../../../../telemetry/legacy-command-instrumentation.ts"; +import { legacyWorkersLogs } from "./logs.handler.ts"; + +/** The `--source` words, mapped to stream names in `worker-logs.sql.ts`. */ +const SOURCE_VALUES = ["app", "requests", "builds"] as const; + +/** + * The endpoint's own ceiling is the SQL `LIMIT`, so this bound is the CLI's + * choice. 1000 is high enough to be a non-issue in practice and low enough that a + * typo cannot ask for a payload nobody wants. + * + * 0 is allowed and means "no history", which only becomes useful alongside + * `--follow`; on its own it prints nothing and makes no request. + */ +const MAX_TAIL = 1000; + +const config = { + name: Argument.string("name").pipe(Argument.withDescription("Worker to read logs for.")), + projectRef: Flag.string("project-ref").pipe( + Flag.withDescription("Project ref of the Supabase project."), + Flag.optional, + ), + source: Flag.choice("source", SOURCE_VALUES).pipe( + Flag.withDescription( + "Limit to one log stream: app (the worker's own output), requests (HTTP access), " + + "builds (deploy lifecycle). Defaults to all three.", + ), + Flag.optional, + ), + follow: Flag.boolean("follow").pipe( + Flag.withAlias("f"), + Flag.withDescription( + `Keep printing new lines until interrupted, polling every ${WORKER_LOG_POLL_SECONDS} seconds.`, + ), + // Required: `Flag.boolean` alone builds a *required* param, which breaks + // invocations that omit the flag. `legacy-boolean-flag-defaults.unit.test.ts` + // walks the command tree and fails any bare boolean. + Flag.withDefault(false), + ), + tail: Flag.integer("tail").pipe( + Flag.filter( + (tail) => tail >= 0 && tail <= MAX_TAIL, + (tail) => `Expected --tail between 0 and ${MAX_TAIL}, got ${tail}`, + ), + Flag.withDescription( + "Number of log lines to print. Use 0 with --follow to skip history and print only new lines.", + ), + Flag.withDefault(100), + ), +} as const; + +export type LegacyWorkersLogsFlags = CliCommand.Command.Config.Infer; + +export const legacyWorkersLogsCommand = Command.make("logs", config).pipe( + Command.withDescription( + "Print a worker's recent logs: its own output, the HTTP requests it served, and its " + + "deploy lifecycle events.\n\n" + + "Covers the last 24 hours, which is the longest window the logs API will answer in one " + + "query. Lines are printed oldest first.\n\n" + + `Use --follow to keep printing new lines as they arrive. The logs API is rate limited, so ` + + `following polls every ${WORKER_LOG_POLL_SECONDS} seconds rather than continuously; new ` + + "lines can take that long to appear.", + ), + Command.withShortDescription("Show a worker's logs"), + Command.withExamples([ + { + command: "supabase experimental workers logs api", + description: "Print the last 100 log lines across all streams", + }, + { + command: "supabase experimental workers logs api --source requests --tail 20", + description: "Print the 20 most recent HTTP requests the worker served", + }, + { + command: "supabase experimental workers logs api --follow", + description: "Print recent logs, then keep printing new lines until interrupted", + }, + { + command: "supabase experimental workers logs api --tail 0 --follow", + description: "Skip the backlog and print only lines that arrive from now on", + }, + ]), + Command.withHandler((flags) => + legacyWorkersLogs(flags).pipe( + // `config` as well as `flags`: `--source` is a choice flag, and the wrapper + // treats a command's own declared choices as safe to log verbatim. + withLegacyCommandInstrumentation({ flags, config }), + withJsonErrorHandling, + ), + ), + Command.provide(legacyManagementApiRuntimeLayer(["experimental", "workers", "logs"])), +); diff --git a/apps/cli/src/legacy/commands/experimental/workers/logs/logs.handler.ts b/apps/cli/src/legacy/commands/experimental/workers/logs/logs.handler.ts new file mode 100644 index 0000000000..df6869fce0 --- /dev/null +++ b/apps/cli/src/legacy/commands/experimental/workers/logs/logs.handler.ts @@ -0,0 +1,335 @@ +import { Effect, Option, Ref, Schedule } from "effect"; +import { Output } from "../../../../../shared/output/output.service.ts"; +import { emitSuccessTrailer } from "../../../../../shared/cli/success-trailer.ts"; +import { legacyAqua } from "../../../../shared/legacy-colors.ts"; +import { + legacyEmitWorkersMachineOutput, + legacyRejectWorkersEnvOutput, + legacyWorkersProjectRefSuffix, +} from "../workers.output.ts"; +import { legacyRenderWorkerLogLine, legacyWorkerLogLevel } from "../workers-logs.format.ts"; +import { ProcessControl } from "../../../../../shared/runtime/process-control.service.ts"; +import { LegacyWorkersFollowNotSupportedError } from "../workers.errors.ts"; +import { LegacyPlatformApi } from "../../../../auth/legacy-platform-api.service.ts"; +import { + fetchWorkerLogs, + type WorkerLogEntry, +} from "../../../../../shared/workers/worker-logs-api.ts"; +import { + ALL_WORKER_LOG_STREAMS, + followWindow, + logWindow, + WORKER_LOG_POLL_SECONDS, + WORKER_LOG_STREAMS, + type WorkerLogSourceChoice, +} from "../../../../../shared/workers/worker-logs.sql.ts"; +import { getWorker } from "../../../../../shared/workers/workers-api.ts"; +import { WorkerNotDeployedError } from "../../../../../shared/workers/workers.errors.ts"; +import { LegacyProjectRefResolver } from "../../../../config/legacy-project-ref.service.ts"; +import { LegacyLinkedProjectCache } from "../../../../telemetry/legacy-linked-project-cache.service.ts"; +import { LegacyTelemetryState } from "../../../../telemetry/legacy-telemetry-state.service.ts"; +import { legacyValidateWorkerName } from "../workers.shared.ts"; +import { legacyWorkersMachineOutputRequested } from "../workers.output.ts"; +import type { LegacyWorkersLogsFlags } from "./logs.command.ts"; + +/** + * `supabase experimental workers logs ` — what the worker has actually been doing. + * + * `status` reports the deployment; this reports the runtime. Between them they + * cover the two questions a deployed worker raises, and neither answers the + * other's. + * + * Unlike the rest of the family this does not talk to `/v2/.../workers` — there is + * no worker-scoped log route — but to the project's unified logs stream. See + * `worker-logs.sql.ts` for the query and why it filters on `log_attributes` + * rather than the `source` column. + */ + +/** + * How many printed ids the follow loop remembers. + * + * Only lines inside the cursor's grace window can still be re-offered by a later + * poll, so a bound well above one window's worth cannot cause a repeat while + * keeping the set from growing for the lifetime of a long tail. + */ +const SEEN_ID_LIMIT = 5000; + +/** + * How long one poll may keep failing before the tail gives up. + * + * Bounded by elapsed time rather than attempts, and spaced, so a 429 or a + * momentary blip is ridden out without spending the rate limit on retries. Same + * reasoning as `awaitWorkerBuild`'s read retry. + */ +const FOLLOW_READ_RETRY = Schedule.spaced("5 seconds").pipe( + Schedule.upTo({ duration: "1 minute" }), +); + +/** + * Test seams for the follow loop. + * + * Both schedules are parameters for the same reason `awaitWorkerBuild`'s are: the + * real ones are spaced in seconds, and a test exercising the cursor, the dedupe, + * or the retry path should not wait on a wall clock to do it. + */ +export interface LegacyWorkersLogsOptions { + readonly pollSchedule?: Schedule.Schedule; + readonly retrySchedule?: Schedule.Schedule; +} + +/** The machine-format row for one line. */ +function toPayloadEntry(entry: WorkerLogEntry) { + const level = legacyWorkerLogLevel(entry); + return { + id: entry.id, + // Both forms: the ISO string is what a human or `jq` wants to read, the raw + // epoch value is what a script sorts or diffs on without reparsing. + timestamp: new Date(entry.timestampMs).toISOString(), + timestamp_ms: entry.timestampMs, + stream: entry.stream, + message: entry.message, + ...(level === undefined ? {} : { level }), + attributes: entry.attributes, + }; +} + +export const legacyWorkersLogs = Effect.fn("legacy.experimental.workers.logs")(function* ( + flags: LegacyWorkersLogsFlags, + options: LegacyWorkersLogsOptions = {}, +) { + const output = yield* Output; + const api = yield* LegacyPlatformApi; + const resolver = yield* LegacyProjectRefResolver; + const linkedProjectCache = yield* LegacyLinkedProjectCache; + const telemetryState = yield* LegacyTelemetryState; + const processControl = yield* ProcessControl; + + // The ref is resolved outside the finalizers because caching it is one of them; + // everything that can fail on its own belongs inside, so those failures still + // flush telemetry. Same shape as the rest of the family. + const projectRef = yield* resolver.resolve(flags.projectRef); + const refSuffix = legacyWorkersProjectRefSuffix(flags.projectRef); + + yield* Effect.gen(function* () { + const name = yield* legacyValidateWorkerName(flags.name); + + // Up front, like the rest of the family: this payload always carries a `logs` + // array, so `-o env` can never encode it, and finding that out at emit time + // means failing after the query has already been paid for. + yield* legacyRejectWorkersEnvOutput(); + + // Also up front: a tail has no single terminal payload, so the bounded + // machine formats cannot express it. `stream-json` can, and is allowed. + if (flags.follow) { + const machineOutput = yield* legacyWorkersMachineOutputRequested(); + if (machineOutput || output.format === "json") { + return yield* new LegacyWorkersFollowNotSupportedError({ + message: + "--follow cannot be combined with a single-payload output format. " + + "Use --output-format stream-json to stream, or drop --follow.", + }); + } + } + + const pollSchedule = + options.pollSchedule ?? Schedule.spaced(`${WORKER_LOG_POLL_SECONDS} seconds`); + const readRetrySchedule = options.retrySchedule ?? FOLLOW_READ_RETRY; + // A poll asks for whatever arrived since the cursor, not for `--tail` lines; + // `--tail 0` means "no history", not "no new lines". + const pollTail = Math.max(flags.tail, 1); + + // The stream tag only earns its width when streams are actually mixed; with + // `--source` every line would carry the same one. + const showStream = Option.isNone(flags.source); + + /** + * Write a batch of lines out, in whichever form the format calls for. + * + * `stream-json` emits the existing `log-entry` event per line rather than one + * terminal `result`: a tail has no terminal element, and that variant already + * carries the field set this needs. `stream` is derived from the level so a + * consumer can split diagnostics from ordinary output the way it would for a + * real process; `source` distinguishes the backlog from what arrived after. + */ + const emitLines = ( + batch: ReadonlyArray, + origin: "history" | "live" = "history", + ) => + Effect.gen(function* () { + if (batch.length === 0) { + return; + } + if (output.format === "stream-json") { + for (const entry of batch) { + const level = legacyWorkerLogLevel(entry); + yield* output.event({ + type: "log-entry", + timestamp: new Date(entry.timestampMs).toISOString(), + service: name, + stream: level === "error" || level === "warn" ? "stderr" : "stdout", + line: entry.message, + source: origin, + }); + } + return; + } + yield* output.raw( + `${batch.map((entry) => legacyRenderWorkerLogLine(entry, { showStream })).join("\n")}\n`, + ); + }); + + const streams = Option.isSome(flags.source) + ? [WORKER_LOG_STREAMS[flags.source.value as WorkerLogSourceChoice]] + : ALL_WORKER_LOG_STREAMS; + + // `--tail 0` is "no history". On its own that is a no-op, but it is the shape + // `--follow` will want, and issuing a `limit 0` query would be a 400. + const entries = + flags.tail === 0 + ? [] + : yield* Effect.gen(function* () { + const fetching = yield* output.task("Fetching logs..."); + const rows = yield* fetchWorkerLogs(api, projectRef, { + name, + streams, + tail: flags.tail, + window: logWindow(new Date()), + }).pipe(Effect.tapError(() => fetching.fail())); + yield* fetching.clear(); + return rows; + }); + + // Nothing came back, which is two different situations wearing the same face: + // a worker that is not deployed at all, and one that is deployed and quiet. + // Only worth one extra request, and only in this branch. + // + // Skipped when `--tail 0` asked for no history: no query was made, so zero + // rows says nothing about whether the worker exists. + if (entries.length === 0 && flags.tail > 0) { + const deployed = yield* getWorker(api, projectRef, name); + if (Option.isNone(deployed)) { + return yield* Effect.fail( + new WorkerNotDeployedError({ + detail: `Nothing is deployed for "${name}" in project ${projectRef}.`, + suggestion: `Deploy it with \`supabase experimental workers push ${name}${refSuffix}\`.`, + }), + ); + } + } + + const payload = { + worker_name: name, + project_ref: projectRef, + ...(Option.isSome(flags.source) ? { source: flags.source.value } : {}), + logs: entries.map(toPayloadEntry), + }; + + // `-o` asks for a machine-readable stdout, so nothing human may be written to + // it — `output.success` logs to stdout in text mode. Unreachable while + // following, which refuses these formats up front. + if (!flags.follow && (yield* legacyEmitWorkersMachineOutput(payload))) { + return; + } + + // One structured emission, in the structured branch only, and only for a + // bounded read. A tail has no terminal payload to put here — it emits a + // `log-entry` event per line through `emitLines` instead. + if (!flags.follow && output.format !== "text") { + yield* output.success("", payload); + return; + } + + if (entries.length === 0 && !flags.follow) { + // Deployed (the check above would have failed otherwise) and silent. + yield* output.raw(`No logs for "${name}" in the last 24 hours.\n`); + yield* emitSuccessTrailer( + `Check it is running with ${legacyAqua(`supabase experimental workers status ${name}${refSuffix}`)}.\n`, + ); + return; + } + + // Oldest first: the query orders newest-first so `limit` means "most recent", + // but a reader scrolls forwards through time, and a stack trace only makes + // sense in the order it was printed. + yield* emitLines(entries); + + // A tail with nothing to show yet would otherwise look like a hang. On stderr, + // so it never lands in piped output. + if (flags.follow && entries.length === 0 && output.format === "text") { + yield* output.raw(`Waiting for new logs from "${name}". Press Ctrl+C to stop.\n`, "stderr"); + } + + if (!flags.follow) { + return; + } + + // --- follow --------------------------------------------------------------- + // + // The cursor is the newest timestamp printed, and the set of ids already + // printed. Both live inside this generator rather than being captured while + // the Effect was built: an Effect is a reusable description and may run more + // than once, and shared cursor state across runs would drop lines. + const seenIds = yield* Ref.make(new Set(entries.map((entry) => entry.id))); + const newestSeenMs = yield* Ref.make( + entries.length === 0 ? Date.now() : entries[entries.length - 1]!.timestampMs, + ); + + const pollOnce = Effect.gen(function* () { + const cursor = yield* Ref.get(newestSeenMs); + const rows = yield* fetchWorkerLogs(api, projectRef, { + name, + streams, + tail: pollTail, + window: followWindow(new Date(), cursor), + }); + + // Windows always overlap - the server rounds them to the minute and the + // cursor deliberately lags - so dedupe is what makes the overlap invisible + // rather than a source of repeats. + const printed = yield* Ref.get(seenIds); + const fresh = rows.filter((row) => !printed.has(row.id)); + if (fresh.length === 0) { + return; + } + + yield* emitLines(fresh, "live"); + yield* Ref.update(seenIds, (previous) => { + const next = new Set(previous); + for (const row of fresh) { + next.add(row.id); + } + // Bounded so a tail left running for hours does not grow it without + // limit. Only ids inside the grace window can still be re-offered, so + // forgetting the oldest cannot resurrect them. + if (next.size <= SEEN_ID_LIMIT) { + return next; + } + return new Set([...next].slice(next.size - SEEN_ID_LIMIT)); + }); + yield* Ref.set( + newestSeenMs, + fresh.reduce((newest, row) => Math.max(newest, row.timestampMs), cursor), + ); + }); + + // A 429 or a blip should not end a tail the user is watching; the schedule is + // spaced in seconds, so retrying rides out a transient failure without + // spending the rate limit. + const poll = pollOnce.pipe(Effect.retry({ schedule: readRetrySchedule })); + + // `repeat` runs the body before applying the schedule, so the first poll is + // immediate. That is wanted: it catches anything that landed while the history + // query was in flight, and the rows it repeats are discarded by the id dedupe. + // Measured cost is ~7 requests in the worst 60-second window, against a limit + // of 10. + yield* Effect.raceFirst( + poll.pipe(Effect.repeat({ schedule: pollSchedule })), + processControl + .awaitSignal() + .pipe(Effect.flatMap((signal) => processControl.exit(signal === "SIGINT" ? 130 : 0))), + ); + }).pipe( + Effect.ensuring(linkedProjectCache.cache(projectRef)), + Effect.ensuring(telemetryState.flush), + ); +}); diff --git a/apps/cli/src/legacy/commands/experimental/workers/logs/logs.integration.test.ts b/apps/cli/src/legacy/commands/experimental/workers/logs/logs.integration.test.ts new file mode 100644 index 0000000000..e0900bf8d8 --- /dev/null +++ b/apps/cli/src/legacy/commands/experimental/workers/logs/logs.integration.test.ts @@ -0,0 +1,745 @@ +import { rmSync } from "node:fs"; +import { describe, expect, it } from "@effect/vitest"; +import { Effect, Option, Schedule } from "effect"; +import { + makeWorkersProject, + setupLegacyWorkers, + workerApiLogRow, + workerIngressLogRow, + workerLogRow, + workerLogsRoute, + workerResource, + workersRoute, + WORKERS_PROJECT_REF, +} from "../../../../../../tests/helpers/legacy-workers.ts"; +import { LegacyWorkersFollowNotSupportedError } from "../workers.errors.ts"; +import { + InvalidWorkerNameError, + WorkerLogsQueryFailedError, + WorkerLogsRateLimitedError, + WorkerLogsUsageExceededError, + WorkerNotDeployedError, + WorkersApiNetworkError, + WorkersApiUnexpectedStatusError, + WorkersUnavailableError, +} from "../../../../../shared/workers/workers.errors.ts"; +import { LegacyWorkersEnvNotSupportedError } from "../workers.errors.ts"; +import { legacyWorkersLogs } from "./logs.handler.ts"; + +const ESCAPE = "\u001b"; +const CONFIG = 'project_id = "demo"\n\n[workers.api]\nruntime = "node"\n'; +const LOGS_ROUTE = `GET ${workerLogsRoute()}`; +const GET_WORKER_ROUTE = `GET ${workersRoute("/api")}`; + +const T1 = 1_788_187_525_212; +const T2 = 1_788_187_531_671; +const T3 = 1_788_187_532_576; + +function project() { + const created = makeWorkersProject({ + "supabase/config.toml": CONFIG, + "supabase/workers/api/index.js": "export default {};\n", + }); + return { dir: created.dir, cleanup: () => rmSync(created.dir, { recursive: true, force: true }) }; +} + +/** The default flag set; every test overrides only what it is about. */ +function flags(overrides: Record = {}) { + return { + name: "api", + projectRef: Option.none(), + source: Option.none(), + tail: 100, + ...overrides, + } as Parameters[0]; +} + +/** + * Follow options that drive the loop instantly and stop after N polls. + * + * The real schedule is spaced in seconds; `recurs` also gives the tail an end, so + * a test does not have to deliver a signal just to finish. + */ +function followFor(polls: number) { + return { + pollSchedule: Schedule.recurs(polls), + retrySchedule: Schedule.recurs(0), + }; +} + +function logsResponse(rows: ReadonlyArray) { + return { status: 200, body: { result: rows, error: null } }; +} + +/** + * The query parameters the handler actually sent. + * + * Read off the recorded request rather than the URL: `HttpClientRequest` keeps + * `urlParams` beside the URL rather than appended to it. + */ +function sentQuery(request: { readonly urlParams: Readonly> }) { + return request.urlParams; +} + +describe("legacy workers logs", () => { + it.live("prints a worker's own output oldest first", () => { + const repo = project(); + const { layer, out } = setupLegacyWorkers({ + workdir: repo.dir, + routes: { + [LOGS_ROUTE]: logsResponse([ + workerLogRow({ id: "c", tsMs: T3, message: "app drained" }), + workerLogRow({ id: "a", tsMs: T1, message: "listening on :8080" }), + workerLogRow({ id: "b", tsMs: T2, message: "terminate hook" }), + ]), + }, + }); + + return Effect.gen(function* () { + yield* legacyWorkersLogs(flags()); + + // `