diff --git a/.changeset/balanced-aca-admission.md b/.changeset/balanced-aca-admission.md new file mode 100644 index 00000000..7f29fdb7 --- /dev/null +++ b/.changeset/balanced-aca-admission.md @@ -0,0 +1,5 @@ +--- +"sql-fs-api": patch +--- + +Update the ACA deployment example with early HTTP concurrency scaling, bounded five-second queues, faster readiness probes, a drain grace period and an immutable image reference. Keep blob caching off in the example so control Redis does not also carry blob traffic. diff --git a/.changeset/queued-input-cancellation.md b/.changeset/queued-input-cancellation.md new file mode 100644 index 00000000..a6163542 --- /dev/null +++ b/.changeset/queued-input-cancellation.md @@ -0,0 +1,7 @@ +--- +"sql-fs-api": patch +--- + +Read accepted queued HTTP and MCP request bodies within the existing byte budgets so client disconnects can remove waiting requests before route execution. Preserve streaming, response and retained-work ownership, and unread immediate queue-full refusal. Add independent global and tenant ingress queue limits, including zero waiting, while keeping the current queue sizes and 250 ms wait by default. + +Expose ingress capacity, outcome counters and admitted queue wait histograms through metrics. diff --git a/.changeset/skip-applied-startup-migrations.md b/.changeset/skip-applied-startup-migrations.md new file mode 100644 index 00000000..89d0a6eb --- /dev/null +++ b/.changeset/skip-applied-startup-migrations.md @@ -0,0 +1,5 @@ +--- +"sql-fs-api": patch +--- + +Record applied Postgres migrations and their SHA-256 checksums in a transactionally committed ledger per tenant database. Replica startup skips unchanged migrations instead of repeating table DDL while other replicas serve requests. Reject changes to recorded migration files and roll back pending DDL and history together on failure. diff --git a/.changeset/tidy-ingress-outcomes.md b/.changeset/tidy-ingress-outcomes.md new file mode 100644 index 00000000..ffe0bf2a --- /dev/null +++ b/.changeset/tidy-ingress-outcomes.md @@ -0,0 +1,5 @@ +--- +"sql-fs-api": patch +--- + +Preserve completed route responses when request input fails after dispatch, and count queued-hook failures as cancelled admissions. Keep overload retry and Redis scaling guidance aligned with operation outcomes and configured cache roles. diff --git a/.changeset/tidy-runtime-dependencies.md b/.changeset/tidy-runtime-dependencies.md new file mode 100644 index 00000000..4858ef10 --- /dev/null +++ b/.changeset/tidy-runtime-dependencies.md @@ -0,0 +1,5 @@ +--- +"sql-fs-api": patch +--- + +Remove development dependencies from the runtime Docker image after building the API. diff --git a/.claude/skills/verify/SKILL.md b/.claude/skills/verify/SKILL.md index 14b0f814..00b58648 100644 --- a/.claude/skills/verify/SKILL.md +++ b/.claude/skills/verify/SKILL.md @@ -22,7 +22,7 @@ Run every row your diff touches. `pnpm check` is always required; the full verif | `src/sql-fs/` (fs, transactions, cache, RLS, symlinks) | targeted `pnpm exec vitest run `, `$S suite integration `, [files](features/files.md) / [exec](features/exec.md) drive | `pnpm check` + `pnpm verify:local` | | `src/api/routes/`, `auth.ts`, `validation.ts`, `openapi-spec.ts` | the matching feature drive + `$S suite contracts` | `pnpm check` + `pnpm verify:local` | | `src/api/mcp/` | [mcp](features/mcp.md) drive + `$S suite contracts` | `pnpm check` + `pnpm verify:local` | -| `src/api/worker-owner/`, `ingress-admission.ts`, `session-manager.ts`, `src/execution/`, `script-scope.ts`, budgets, cancellation, deadlines, body limits | `$S suite worker-failures`, `sse-finalization`, `input-budgets`, `output-cap` | `pnpm check` + `pnpm verify:architecture` | +| `src/api/worker-owner/`, `ingress-admission.ts`, `session-manager.ts`, `src/execution/`, `script-scope.ts`, budgets, cancellation, deadlines, body limits | `$S suite worker-failures`, `sse-finalization`, `input-budgets`, `ingress-queue`, `output-cap` | `pnpm check` + `pnpm verify:architecture` | | `src/api/server.ts` startup/shutdown, `src/api/mcp/server.ts` listener lifecycle, ingress waits | `$S suite shutdown`, `$S suite contracts` | `pnpm check` + `pnpm verify:local` | | Tenancy, `TENANT_DATABASES`, owner isolation | `$S suite tenants`, [sandboxes](features/sandboxes.md) isolation steps | `pnpm check` + `pnpm verify:architecture` | | `src/redis/`, `redis-blob-cache.ts` | `$S suite integration src/redis` | `pnpm check` + `pnpm verify:local` | diff --git a/.claude/skills/verify/features/README.md b/.claude/skills/verify/features/README.md index ff77b8b4..7a9836b0 100644 --- a/.claude/skills/verify/features/README.md +++ b/.claude/skills/verify/features/README.md @@ -46,6 +46,7 @@ These have no hand-driven journey yet. Run the suite through `$S suite `, - Worker crash, lease loss, and unknown-outcome errors: `worker-failures` - SSE stream finalization: `sse-finalization` - Request and input budgets: `input-budgets` +- Queued upload cancellation and durable absence: `ingress-queue` - Output caps: `output-cap` - Graceful shutdown with open MCP streams: `shutdown` - Full HTTP/MCP contract against `/openapi.json`: `contracts` diff --git a/.claude/skills/verify/features/files.md b/.claude/skills/verify/features/files.md index aed9cd8a..99e7365d 100644 --- a/.claude/skills/verify/features/files.md +++ b/.claude/skills/verify/features/files.md @@ -10,6 +10,7 @@ Clients read and write sandbox files directly, without bash. They can write raw - `files-mkdir` creates directories recursively (`204`). - `files-tree` lists entries under a prefix to a given depth. - `files-delete` removes a file (`204`), after which reads return `404 ENOENT`. +- `files-queued-cancel` abandons a queued 1 MiB upload and verifies that it never becomes a durable file. ## How to get to it (user POV) @@ -28,6 +29,7 @@ Preconditions: - **Bulk write, seen by bash.** Run `EXPECT=204 $S api POST /v1/sandboxes/$ID/writeFiles --json '{"files":{"/home/user/v/one.txt":"one\n","/home/user/v/two.txt":"two\n"}}'`, then `$S api POST /v1/sandboxes/$ID/exec-sync --json '{"script":"cat /home/user/v/one.txt /home/user/v/two.txt","readOnly":true}' | jq -r .stdout`. It prints `one` and `two`. - **Tree.** Run `$S api GET "/v1/sandboxes/$ID/tree?prefix=/home/user/v&depth=3" | jq -c '[.[].path]'`. The output lists `note.txt`, `one.txt`, and `two.txt` under `/home/user/v/`. - **Delete.** Run `EXPECT=204 $S api DELETE /v1/sandboxes/$ID/files/home/user/v/note.txt`, then `EXPECT=404 $S api GET /v1/sandboxes/$ID/files/home/user/v/note.txt`. The body is `{"error":"not_found","code":"ENOENT"}`. +- **Queued cancellation.** Run `$S suite ingress-queue`. It holds ingress with an incomplete body, sends and abandons a queued upload, then checks queue removal before admission and reads the file after capacity returns. All five repetitions must leave no file and no retained bytes. A live 1 MiB upload control must preserve its exact hash. ## Gotchas diff --git a/.claude/skills/verify/scripts/journeys.sh b/.claude/skills/verify/scripts/journeys.sh index d6d8d32c..6cf758a1 100755 --- a/.claude/skills/verify/scripts/journeys.sh +++ b/.claude/skills/verify/scripts/journeys.sh @@ -82,6 +82,7 @@ journey_files() { EXPECT=204 api DELETE "/v1/sandboxes/$id/files/home/user/v/note.txt" >/dev/null eq "$(EXPECT=404 api GET "/v1/sandboxes/$id/files/home/user/v/note.txt" | jq -r .code)" ENOENT "deleted file -> ENOENT" drop "$id" + $S suite ingress-queue } journey_ingest() { diff --git a/AGENTS.md b/AGENTS.md index e9e06b12..a949fdf4 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -10,12 +10,12 @@ Use Node 22 from `.node-version`, pnpm 10.30.3 from `package.json`, Python 3.12, pnpm setup:dev # install all three packages from their lockfiles; install git hooks pnpm check # types, formatting, unit tests, builds, and both SDKs; no services or .env needed pnpm verify:local # isolated Postgres/Redis, HTTP/MCP contracts, integration tests, and both live SDKs -pnpm verify:architecture # also worker failure, stream finalization, input budgets, and multi-tenant proofs +pnpm verify:architecture # also worker failure, stream finalization, input budgets, ingress queue, and multi-tenant proofs ``` `pnpm verify:local` uses random loopback ports and a unique Compose project, applies migrations through server startup, and removes only its own containers and volumes. It ignores `.env` and inherited deployment settings. It writes logs and JSON proof to `scripts/verify/.run/`. A missing Docker daemon or skipped integration test fails the command. -`pnpm verify:architecture` runs the standard verification plus `worker-failures.mjs`, `sse-finalization.mjs`, `input-budgets.mjs`, and `tenants.mjs` in the same disposable stack. Run it for worker ownership, script completion, command protocol, or isolation changes. CI runs this expanded profile on pushes to `main`; PR checks keep the faster static, unit, build, and SDK gates. Resource and large-file profiling remain separate and require a suitable cgroup v2 host. +`pnpm verify:architecture` runs the standard verification plus `worker-failures.mjs`, `sse-finalization.mjs`, `input-budgets.mjs`, `ingress-queue.mjs`, and `tenants.mjs` in the same disposable stack. Run it for worker ownership, script completion, command protocol, ingress admission, or isolation changes. CI runs this expanded profile on pushes to `main`; PR checks keep the faster static, unit, build, and SDK gates. Resource and large-file profiling remain separate and require a suitable cgroup v2 host. Use `pnpm check:typescript` or `pnpm check:python` for SDK-only changes. Run a targeted core test with `pnpm exec vitest run src/sql-fs/tests/unit/sql-fs.cache.test.ts`. A nonexistent test selection must fail. `pnpm test:integration` is the lower-level command for an already migrated disposable database with `DATABASE_URL` and `REDIS_URL`; it can skip without those variables. Prefer `pnpm verify:local` for completion evidence. @@ -47,7 +47,7 @@ Evidence lands in `scripts/verify/.run/stack-/` (`transcript.jsonl`, `server | `output-cap` | worker output limits in both worker modes | `verify:local` | | `shutdown` | graceful shutdown ends MCP listener streams and refuses new connections | `verify:local` | | `sdk-clients` (+ `sdk-python.py`) | live TypeScript and Python SDKs | `verify:local` | -| `worker-failures`, `sse-finalization`, `input-budgets`, `tenants` | worker loss, stream finalization, input budgets, tenant isolation | `verify:architecture` | +| `worker-failures`, `sse-finalization`, `input-budgets`, `ingress-queue`, `tenants` | worker loss, stream finalization, input budgets, ingress queue admission, tenant isolation | `verify:architecture` | | `ingest-admission`, `large-files` | ingest budgets, large-file profiling | manual; large files need cgroup v2 | `local-api.mjs` is the shared harness: owned servers, tokens, schema validation, `proof.json`. `assert-integration-report.mjs` is the shared check that an integration run executed tests with none failed or skipped. `*-faults.mjs` files are fault injectors loaded by the suites, not entry points. When you add an endpoint or client-visible behavior, add or extend a suite here, add its journey to `features/` and `journeys.sh`, and update `openapi-spec.ts`. diff --git a/Dockerfile b/Dockerfile index 3448dca9..a1f2559f 100644 --- a/Dockerfile +++ b/Dockerfile @@ -1,6 +1,5 @@ # syntax=docker/dockerfile:1.7 -# ------- Builder ------- FROM node:22-bookworm-slim AS builder WORKDIR /app RUN corepack enable @@ -16,14 +15,16 @@ RUN --mount=type=secret,id=proxy_ca \ COPY . . RUN pnpm build -# ------- Runtime ------- +FROM builder AS production-dependencies +RUN pnpm --config.ignore-scripts=true prune --prod + FROM node:22-slim AS runtime ENV NODE_ENV=production ENV PORT=8080 WORKDIR /app RUN groupadd -r app && useradd -r -g app app COPY --from=builder --chown=app:app /app/dist ./dist -COPY --from=builder --chown=app:app /app/node_modules ./node_modules +COPY --from=production-dependencies --chown=app:app /app/node_modules ./node_modules COPY --from=builder --chown=app:app /app/package.json ./package.json USER app EXPOSE 8080 diff --git a/clients/python/uv.lock b/clients/python/uv.lock index 562afadb..6ec15e4d 100644 --- a/clients/python/uv.lock +++ b/clients/python/uv.lock @@ -44,11 +44,11 @@ wheels = [ [[package]] name = "certifi" -version = "2026.4.22" +version = "2026.10.23" source = { registry = "https://pypi.org/simple" } -sdist = { url = "https://files.pythonhosted.org/packages/25/ee/6caf7a40c36a1220410afe15a1cc64993a1f864871f698c0f93acb72842a/certifi-2026.4.22.tar.gz", hash = "sha256:8d455352a37b71bf76a79caa83a3d6c25afee4a385d632127b6afb3963f1c580", size = 137077, upload-time = "2026-04-22T11:26:11.191Z" } +sdist = { url = "https://files.pythonhosted.org/packages/fd/11/b524cbd9bbdaca58608e4cf4053fd463417549e1959fa8d3aa18319f9555/certifi-2026.10.23.tar.gz", hash = "sha256:a9895e6e2758b371e0545e321a3a8fd1fcfd9829ada8824a936dfb16aaaf36cd", size = 136225, upload-time = "2026-10-23T11:36:16.478Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/22/30/7cd8fdcdfbc5b869528b079bfb76dcdf6056b1a2097a662e5e8c04f42965/certifi-2026.4.22-py3-none-any.whl", hash = "sha256:3cb2210c8f88ba2318d29b0388d1023c8492ff72ecdde4ebdaddbb13a31b1c4a", size = 135707, upload-time = "2026-04-22T11:26:09.372Z" }, + { url = "https://files.pythonhosted.org/packages/32/d1/a3652fe2c19134d0d15922177821d863cbd7e842d53a21bbe7e8e3a1b5ac/certifi-2026.10.23-py3-none-any.whl", hash = "sha256:e9b54de76e530bb6cf0ccd036787103acb58fd42ba930ea8bf948ddbaa2f61d1", size = 135082, upload-time = "2026-10-23T11:36:14.763Z" }, ] [[package]] diff --git a/deploy/azure/aca.yaml b/deploy/azure/aca.yaml index 160986c3..bb4ac30f 100644 --- a/deploy/azure/aca.yaml +++ b/deploy/azure/aca.yaml @@ -22,9 +22,10 @@ properties: - name: ghcr-token value: "" template: + terminationGracePeriodSeconds: 90 containers: - name: api - image: ghcr.io//sql-fs-api:latest + image: ghcr.io//sql-fs@sha256: resources: cpu: 1.0 memory: 2Gi @@ -39,17 +40,31 @@ properties: secretRef: redis-url - name: PORT value: "8080" + - name: REDIS_BLOB_CACHE_ENABLED + value: "false" + - name: SQL_FS_MAX_INGRESS_QUEUED_REQUESTS + value: "64" + - name: SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS + value: "16" + - name: SQL_FS_MAX_INGRESS_WAIT_MS + value: "5000" + - name: SQL_FS_WORKER_QUEUE_WAIT_MS + value: "5000" + - name: SQL_FS_WORKER_EXECUTION_MS + value: "45000" probes: - type: Liveness httpGet: path: /healthz port: 8080 periodSeconds: 15 + timeoutSeconds: 3 - type: Readiness httpGet: path: /readyz port: 8080 - periodSeconds: 10 + periodSeconds: 2 + timeoutSeconds: 3 - type: Startup httpGet: path: /readyz @@ -57,10 +72,11 @@ properties: failureThreshold: 30 periodSeconds: 2 scale: - minReplicas: 1 + minReplicas: 2 maxReplicas: 10 + # HTTP scaling uses ACA's fleet request signal, evaluated every 15 seconds. rules: - name: http-rule http: metadata: - concurrentRequests: "50" + concurrentRequests: "1" diff --git a/docs/AUTOSCALING.md b/docs/AUTOSCALING.md index 061bc061..9d9688e1 100644 --- a/docs/AUTOSCALING.md +++ b/docs/AUTOSCALING.md @@ -84,7 +84,7 @@ The names below come from `src/api/worker-owner/metrics.ts` and from a scrape of | `sql_fs_worker_queue_timeouts_total` | counter | The part of `sql_fs_worker_refused_total` whose wait passed `SQL_FS_WORKER_QUEUE_WAIT_MS`. | | `sql_fs_worker_cancelled_total` | counter | Operations that left the queue because the client disconnected or the server shut down. | | `sql_fs_worker_completed_total` | counter | Operations that released their worker. | -| `sql_fs_worker_queue_wait_milliseconds` | histogram | Time from the request for a worker to admission. Buckets: 1, 5, 25, 100, 250 and 1000 ms. | +| `sql_fs_worker_queue_wait_milliseconds` | histogram | Time from the request for a worker to admission. Buckets: 1, 5, 25, 100, 250, 1000, 2500, 5000, 10000 and 30000 ms. | | `sql_fs_worker_queue_wait_milliseconds_total` | counter | Same value as the histogram's `_sum`. | The wait histogram counts admitted operations only. An operation admitted at once records 0. A refused operation records nothing, so the histogram never goes above `SQL_FS_WORKER_QUEUE_WAIT_MS` and hides the requests that hurt most. Read it together with the refusal counters. @@ -95,11 +95,20 @@ Ingress admission runs before the worker queue. It bounds the requests that one | Metric | Type | Meaning | |---|---|---| +| `sql_fs_ingress_request_capacity` | gauge | Configured ordinary active request limit. | +| `sql_fs_ingress_queue_capacity` | gauge | Configured ordinary queued request limit. | +| `sql_fs_ingress_raw_byte_capacity` | gauge | Configured global retained raw-body byte limit. | +| `sql_fs_ingress_queue_wait_limit_milliseconds` | gauge | Configured ingress queue deadline. | | `sql_fs_ingress_active_requests` | gauge | Requests that hold one of the `SQL_FS_MAX_INGRESS_REQUESTS` permits. A permit stays held until the response finishes. | | `sql_fs_ingress_queued_requests` | gauge | Requests that wait for a permit. | +| `sql_fs_ingress_offered_total` | counter | Requests that seek an ordinary ingress permit after the declared body-size check. | +| `sql_fs_ingress_admitted_total` | counter | Requests that acquire an ordinary ingress permit. | +| `sql_fs_ingress_completed_total` | counter | Ordinary ingress permits released after response and retained work completion. | +| `sql_fs_ingress_cancelled_total` | counter | Requests removed before admission by client cancellation, shutdown or an input failure. | +| `sql_fs_ingress_queue_wait_milliseconds` | histogram | Ordinary ingress delay for admitted requests, with the same buckets as worker admission. | | `sql_fs_ingress_refused_total` | counter | Requests that failed with `EWORKER_BUSY` (503) at ingress. It counts a full queue, a wait that ran out and a body that did not fit the byte budget. It does not count MCP listeners. | | `sql_fs_ingress_queue_timeouts_total` | counter | The part of `sql_fs_ingress_refused_total` whose wait passed `SQL_FS_MAX_INGRESS_WAIT_MS`. | -| `sql_fs_ingress_retained_raw_bytes` | gauge | Request-body bytes that admitted requests hold, counted against `SQL_FS_MAX_INGRESS_BYTES`. | +| `sql_fs_ingress_retained_raw_bytes` | gauge | Request-body bytes held by queued and admitted requests, counted against `SQL_FS_MAX_INGRESS_BYTES`. Transport buffers are additional memory. | | `sql_fs_ingress_payload_too_large_total` | counter | Requests that failed with 413 because the body passed its limit. More replicas do not help. | | `sql_fs_ingress_aborted_total` | counter | Requests whose client disconnected before the server finished. | | `sql_fs_ingress_mcp_listeners_active` | gauge | Open `GET /mcp` streams. | @@ -107,7 +116,7 @@ Ingress admission runs before the worker queue. It bounds the requests that one | `sql_fs_ingress_mcp_listeners_refused_total` | counter | `GET /mcp` streams that failed with 503. | | `sql_fs_ingress_mcp_listeners_queue_timeouts_total` | counter | The part of `sql_fs_ingress_mcp_listeners_refused_total` whose wait ran out. | -Ingress has no wait histogram. Use `sql_fs_ingress_queued_requests` and the refusal counters. +The ingress wait histogram records admitted requests only. Read it with queue depth, refusals and queue timeouts. Requests refused before admission do not appear in its latency distribution. MCP listeners use their separate gauges and counters. ### Memory @@ -157,7 +166,7 @@ max(sql_fs_worker_runnable_queued) max(sql_fs_ingress_queued_requests) ``` -The p95 normally stays below `SQL_FS_WORKER_QUEUE_WAIT_MS`, because a request that waits longer is refused and not recorded. An event-loop stall can delay the refusal and let a slightly later admission through. A p95 at the limit means the histogram is saturated, not that the wait is bounded. The top finite bucket is 1000 ms. If you raise `SQL_FS_WORKER_QUEUE_WAIT_MS` above 1000 ms, quantiles above 1000 ms report 1000. +The p95 normally stays below `SQL_FS_WORKER_QUEUE_WAIT_MS`, because a request that waits longer is refused and not recorded. An event-loop stall can delay the refusal and let a slightly later admission through. Read the deadline and refusal counters alongside the histogram. The top finite bucket is 30000 ms. Quantiles above that bucket report 30000 ms, so use client latency measurements for longer waits. Scale on `sql_fs_worker_runnable_queued`, not `sql_fs_worker_queued`. The difference is `sql_fs_worker_sandbox_waiting`, which more replicas do not reduce. @@ -213,7 +222,7 @@ For example, a peak of 300 execs per second from many tenants needs 300 / 100 = - Configure Redis before you run more than one replica. `REDIS_URL` carries the sandbox locks. The [README](../README.md#deploy-with-docker) describes the multi-replica setup. - Scale out fast and scale in slowly. A short burst of refusals should add replicas within a minute. Removing replicas should wait for several minutes of low load, so that the count does not swing. - Let a replica drain before it stops. A script that is cut off mid-run has an unknown outcome, and the client gets no result. -- Make clients retry. Retry a 503 with `retryable: true` after `Retry-After`, with jitter. Also retry connection errors on large uploads, because a client can see a refused upload as a socket error (`UND_ERR_SOCKET`) instead of the 503. Never retry `EEXEC_OUTCOME_UNKNOWN` automatically. +- Automatically retry only overload refusals known to occur before dispatch, after `Retry-After`, with jitter and a deadline. `retryable: true` applies to the failing operation; earlier steps in a multi-step request may already be durable, so reconcile request state before replaying it. Treat `ECOHERENCE`, `EDRIVERFAULT`, transport failures after dispatch, and `EEXEC_OUTCOME_UNKNOWN` as requiring state inspection before replay. - Size the caps for each box size and keep them fixed. Do not change worker counts, output caps or ingress limits at runtime to absorb load. Add replicas instead. The memory measurements in [CONFIGURATION.md](CONFIGURATION.md#sizing) hold only for the caps they were taken with. ### Shutdown and draining @@ -232,7 +241,11 @@ The 30 s drain starts only after open requests finish, so an in-flight request e A request can wait twice before it gets a 503. It first waits for an ingress permit, up to `SQL_FS_MAX_INGRESS_WAIT_MS`. An exec then waits for a worker, up to `SQL_FS_WORKER_QUEUE_WAIT_MS`. Both default to 250 ms, so an exec can queue for up to 0.5 s before it fails. -A longer ingress wait does not absorb bursts. The ingress queue holds at most as many requests as ingress admits at once: `SQL_FS_MAX_INGRESS_REQUESTS` for the replica and `SQL_FS_MAX_INGRESS_TENANT_REQUESTS` for each tenant, 8 and 4 by default. In a burst of 100 requests spread across tenants, 8 run, 8 wait and the rest are refused at once, whatever the wait. One tenant on its own gets 4 running and 4 waiting. The wait only decides how long those few queued requests hold their places. [#269](https://github.com/Hazzng/sql-fs/issues/269) tracks a deeper ingress queue. +Queue depth and wait are separate controls. `SQL_FS_MAX_INGRESS_QUEUED_REQUESTS` sets the ordinary request queue for each replica. `SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS` sets one tenant's share. Defaults remain 8 and 4, derived from the corresponding active limits. A zero queue count refuses a request immediately when it cannot acquire an active permit. MCP GET listeners retain their separate quotas. + +Queued uploads make input progress within the same global and tenant byte budgets as admitted requests. This lets the server observe a disconnect behind unread network data. Active input follows consumer demand. A full byte budget returns 503, and a body above its limit returns 413. Increasing the count does not increase the byte budget or worker capacity. + +Size a queue against the delay you accept and the capacity gap you measure. A first estimate is excess incoming requests per second multiplied by the gap until useful capacity arrives. Apply this to the load arriving at each existing replica, including uneven routing. For example, 50 excess requests per second over 20 seconds needs 1000 queue places. A wait shorter than the gap expires first, and a finite queue cannot cover an arbitrary surge. Scale early, retain headroom, and use bounded client retries for explicit overload refusals. These runs used the same 2 GiB replica as [Measured capacity](#measured-capacity), with clients that waited 1 s after each 503, as `Retry-After: 1` asks. They ran on 2026-10-17. @@ -243,39 +256,78 @@ These runs used the same 2 GiB replica as [Measured capacity](#measured-capacity | The same runs: successful execs/s | 74.5, 69.8, 68.5 | 67.8, 63.4, 67.2 | | The same runs: p99 latency | 123, 151, 174 ms | 246, 283, 173 ms | -The longer wait refused as many requests in the burst, and slightly more under sustained overload, with higher tail latency. Keep the default. Raise the wait only if your clients cannot retry, and add replicas for any load that refuses requests for more than a burst. +These historical runs kept queue counts equal to active counts. A longer wait alone therefore left most arrivals outside the queue. Measure depth and wait together before changing defaults, and add replicas for sustained demand. ## Example: Azure Container Apps -`deploy/azure/aca.yaml` deploys sql-fs to Azure Container Apps. Its scale rule targets 50 concurrent requests for each replica. One replica admits only 8 requests by default and runs 2 operations at a time, so that rule starts adding replicas long after requests begin to fail. The example below shows only the fields to change. Merge them into the `template` block of `aca.yaml`, which keeps the image, environment and probes. It is a starting point, not a tested configuration. +### Measuring an existing app -```yaml -template: - terminationGracePeriodSeconds: 90 - containers: - - name: api - resources: - cpu: 2.0 - memory: 4Gi - scale: - minReplicas: 2 - maxReplicas: 10 - rules: - - name: concurrent-requests - http: - metadata: - concurrentRequests: "4" - - name: worker-refusals - custom: - type: prometheus - metadata: - serverAddress: http://prometheus.example.internal:9090 - query: sum(rate(sql_fs_ingress_refused_total[2m])) + sum(rate(sql_fs_worker_refused_total[2m])) - threshold: "1" +`scripts/verify/aca-load.mjs` runs a bounded open-loop workload against an existing ACA app. It resolves the app's signing secret through your current Azure CLI identity without writing credentials to evidence. Each run owns its sandboxes, verifies durable markers, and removes its resources. Run this only against an app authorized for load testing. + +```bash +node scripts/verify/aca-load.mjs load --app virtualfs-api --group rg-harry-dev \ + --duration 30 --rate 5 --pool 30 --max-inflight 30 --hold-ms 250 --retries 0 ``` -The HTTP rule needs no Prometheus. It scales on concurrent requests, which track the ingress and worker gates. Set `concurrentRequests` to about the worker count plus the queue you accept. Use 4 for short execs with 2 workers. Use a value closer to the worker count when scripts run for seconds. +The default evidence directory is `scripts/verify/.run/aca-*`. `summary.json` separates offered arrivals, generator drops, sent attempts, successful operations, explicit overload refusals, and unknown outcomes. `reconciliation.json` checks durable markers before cleanup. To resume interrupted cleanup, run `node scripts/verify/aca-load.mjs cleanup --manifest /manifest.json`. + +Keep script work fixed when comparing replica counts. This example includes sleep, so its throughput does not establish CPU-intensive bash capacity. Inspect generator delay and drops before attributing a limit to the service. Application metrics are load-balanced samples from individual replicas. Use per-pod Azure Monitor series to establish CPU and memory pressure across the fleet. + +For a cold scale-out test, prepare fixtures while ACA is fixed at one replica. Pass `--start-barrier ` to pause the load tool after setup. It writes `.prepared.json` with a `runId` and waits without application or ARM sampling. Enable the intended scale range, verify that exactly one replica is ready, then atomically write `{"runId":"","release":true}` to ``. The tool takes its own pre-offer snapshot before starting arrivals. A stale release, stop signal or timeout fails into fixture cleanup. The default wait is five minutes; `--start-barrier-timeout-ms` accepts one second to fifteen minutes. Keep any run whose pre-offer snapshot already shows multiple replicas out of cold-start comparisons. + +### Scale rules + +`deploy/azure/aca.yaml` starts with 1 CPU, 2 GiB, two workers, bounded five-second waits and an HTTP target of one concurrent request. It uses an immutable image reference. Set its digest to the image you verified. The example keeps at least two replicas for availability; use a minimum of zero for an idle development app when the wake-up delay is acceptable. + +The HTTP rule uses ACA's fleet request signal and is evaluated every fifteen seconds. It needs no application polling or Prometheus service. One scrape of the load-balanced `/metrics` endpoint describes one replica and cannot establish fleet pressure. Use the new metrics to observe queue capacity, wait, refusals and recovery. If you later add per-replica collection, a separate Prometheus rule can use its aggregate. + +The platform's five-minute scale-down stabilization window applies when checking that a fleet has shrunk. See [ACA scale behavior](https://learn.microsoft.com/en-us/azure/container-apps/scale-app#scale-behavior). + +The queue waits apply at both gates, so an execution can wait up to ten seconds before it begins. They absorb a bounded burst; they do not hold an arbitrary surge for the whole time that replicas need to start. Clients should automatically retry only explicit overload refusals known to occur before dispatch, respect `Retry-After`, add bounded exponential backoff with jitter, and use a deadline that covers the observed scaling gap. Connection failures and unknown execution outcomes still require reconciliation before replaying a mutation. + +Budget shared connections for old and new replicas during a rollout. With blob caching off, each replica holds a control Redis connection. Twenty old plus twenty new replicas already need forty connections before observation and restart headroom. A thirty-connection test instance cannot support that rollout safely. Set `REDIS_URL` to the control Redis instance and keep it on `noeviction`. When blob caching is enabled, set `REDIS_DATA_URL` to a separate data Redis instance configured with `allkeys-lru` or `allkeys-lfu`; otherwise it defaults to `REDIS_URL`. Postgres capacity must cover worker pools and metadata pools for configured tenants, including rollout overlap. + +### Startup work + +Unchanged replicas check `public.sql_fs_migrations` and skip already applied filesystem DDL. This avoids taking filesystem table locks just because capacity is scaling out. Each tenant database records filenames, SHA-256 checksums and application timestamps under the existing transaction advisory lock. Pending DDL and its history commit together; an applied checksum mismatch stops startup. + +The first boot of this version against a legacy database establishes that history by applying the existing idempotent files once. Keep traffic idle for that adoption. Deployments with genuinely new migrations still need to account for their DDL locks. See [startup migration configuration](CONFIGURATION.md). + +### Hosted measurements, 2026-10-18 + +These bounded tests ran on the candidate in `virtualfs-api`, ACA Consumption in Australia East. Each replica had 1 CPU and 2 GiB. Two workers retained the default limit of one active execution per tenant. One tenant used distinct sandboxes with durable marker appends. Sandbox setup warmed the app before each thirty-second offer window. No retries were enabled for these fixed-replica points. + +The measured app retained its existing `REDIS_RWLOCK_ENABLED=false` and `REDIS_BLOB_CACHE_ENABLED=false` settings. These measurements do not establish the performance of either feature when enabled. The deployment example leaves the read/write-lock default unchanged; it is a starting configuration, not an exact reproduction of the measured app. Hosted startup and liveness used TCP probes; readiness used `/readyz` every two seconds. + +| Replicas | Offered writes/s | Successful completions/s during offer window | Eventual successful writes | Client p99 | +| --- | ---: | ---: | ---: | ---: | +| 2 | 6 | 5.97 | 180/180 | 550 ms | +| 5 | 15 | 14.83 | 450/450 | 733 ms | +| 10 | 30 | 29.67 | 900/900 | 855 ms | +| 20 | 60 | 59.20 | 1800/1800 | 879 ms | + +Every point had zero generator drops, refusals, unknown outcomes, duplicate markers or missing successful writes. These are tested rates, not estimates of maximum capacity or production latency guarantees. CPU-heavy scripts and same-sandbox contention need separate capacity measurements. + +A separate fifteen-second overload run offered 200 writes/s to twenty replicas. It completed 81.2 successful writes/s during the offer window. Including drain, 1613 writes succeeded and 1387 received explicit busy refusals. All 3000 operations reconciled correctly: each successful marker appeared once, each refused marker was absent, and no unknown outcome occurred. The load generator sent every arrival; maximum send delay was 21.3 ms and peak in-flight requests were 405 of the allowed 500. Queueing raised successful-request p99 to 6.05 seconds. + +The dependency-pruning experiment used source `4b0a721` with the same AMD64 base images. It produced 179905757 compressed layer bytes with development dependencies and 106470873 after pruning, a 40.82% reduction. Runtime parity covered Git, JavaScript, TypeScript, Python, SQLite, tar, MCP and cross-replica persistence. The later migration-history candidate retains that pruning. Smaller transfer size is not proof of a faster ACA startup. + +The throwaway Redis accepted only thirty concurrent connections and refused `noeviction`. Twenty replicas therefore remain a test configuration. Production use requires suitable control Redis, rollout headroom and workload-specific confirmation. The load driver preserves raw summaries and durable reconciliation in its evidence directory. + +### Final cold and sustained confirmation + +The final candidate, source `e0bf5f3`, adds migration history to the same admission and worker code used for the fixed-replica points above. It ran as immutable image `ghcr.io/hazzng/sql-fs@sha256:fa390528895c1996b6ad0f3ccbc044b6d005c2d8125e9db51faeec506834f330`. + +A cold burst began with exactly one ready replica and allowed ACA to grow to ten. It offered twelve operations/s for three minutes, each including 250 ms of waiting work. All 2160 operations succeeded and reconciled once, with no generator drops or unknown outcomes. The reference client sent 3533 attempts, including 1373 explicit safe busy refusals. It retried those refusals within a 120-second operation deadline. Client p99 including queueing and backoff was 47.49 seconds; the maximum was 59.72 seconds. + +The scaler's rescale event appeared 9.79 seconds after demand. The earliest retained durable write on a new replica appeared at 28.36 seconds. Ten replicas were first observed ready at 46.40 seconds; that ARM read spanned 10.40 seconds. These are observations from one episode, not startup percentiles or a demonstrated speedup. Queues alone did not hold every request throughout that gap. The existing SDK write-execution defaults retain their conservative retry policy; callers need an explicit safe-overload retry policy to reproduce this result. Unknown outcomes and transport failures require reconciliation. + +The earlier cold candidate produced one nonretryable internal error and a container restart while the database deadlock counter rose by two. Repeated startup DDL was independently reproduced blocking behind live filesystem table locks. The final runner skips that DDL on unchanged boots. During the corrected episode the sampled deadlock counter stayed unchanged, with no observed lock waiters or container restarts. The retained earlier logs do not establish the exact cause of that particular internal error or restart. + +A separate five-minute confirmation fixed ten final-image replicas and offered thirty short writes/s with no retries. All 9000 operations succeeded and reconciled once, with zero refusals, unknown outcomes, generator drops or marker errors. Successful completions during the offer window were 29.96/s; client p50 was 318 ms, p95 932 ms and p99 1615 ms. Peak in-flight work was 25 of the allowed 200 and maximum initial send delay was 3.31 ms. All 200 fixtures were deleted. This confirms that workload for five minutes; CPU-heavy commands, large files, shared-sandbox contention and longer soaks need their own capacity evidence. + +### Cold-start follow-up, 2026-10-24 -The `prometheus` rule is a KEDA scaler. It needs a Prometheus server that scrapes every replica with the token from [Endpoints](#endpoints). It asks for one replica for each refusal per second. Container Apps uses the highest replica count that any rule asks for. Once refusals stop, this rule asks for none, so the HTTP rule holds the steady count. +The original trial files are unavailable. The timings below are transcript-recovered and exploratory, not a release baseline. Five alternating requests per profile reported a median of 22.18 s on Consumption and 9.32 s on an already allocated D4 node. This measures a replica starting inside a running D4 node. It does not measure provisioning a D4 node during a burst. The Dedicated profile was removed after testing because its idle cost was not justified. -On the Consumption plan, CPU and memory come in fixed pairs, and 2 CPUs come with 4 GiB. The measured capacity above used 2 CPUs and 2 GiB. +Regional ACR and overlapping boot work showed no reliable end-to-end latency improvement. A smaller image used 22.4% fewer compressed layer bytes, but its startup results did not establish a latency gain. These trials do not justify a runtime or boot-order change. Keep Consumption, bounded queues and replica headroom. This follow-up did not test a custom `/metrics` scaling rule or a burst that requires new Dedicated nodes. diff --git a/docs/CONFIGURATION.md b/docs/CONFIGURATION.md index e66c2b83..ab25fd5d 100644 --- a/docs/CONFIGURATION.md +++ b/docs/CONFIGURATION.md @@ -14,6 +14,10 @@ The server reads every setting from an environment variable. The API requires `A | `SESSION_IDLE_MS` | `600000` | Idle time before the server evicts a warm sandbox session. | | `SKIP_STARTUP_MIGRATIONS` | `false` | If `true`, the server does not apply migrations at boot. | +Startup records each applied migration's filename, SHA-256 checksum, and timestamp in `public.sql_fs_migrations` in each tenant database. Later boots check the recorded checksums and execute only pending files. Changed applied files fail startup; add a new numbered migration instead. The advisory lock, pending DDL, and ledger writes share one transaction, including through a transaction pooler. + +The first boot against an existing database without this ledger applies the idempotent SQL files once to establish history. Roll out that first boot while traffic is idle because those files take locks on filesystem tables. Subsequent unchanged replica boots skip that table DDL. `migrations_committed` logs the total `files` and separate `applied` and `skipped` counts. + ## Postgres | Variable | Default | Description | @@ -173,13 +177,13 @@ To upgrade replicas that run with workers off, roll out in two stages. A rolling **Admission.** Each tenant has a queue, and the server takes requests from the queues in turn. On one sandbox, a waiting writer goes before new readers. With the defaults, one tenant can hold one of the two workers and four of the eight ingress permits. Long-lived `GET /mcp` streams count against a separate listener quota. A request that waits longer than `SQL_FS_MAX_INGRESS_WAIT_MS` for an ingress permit, or an exec that waits longer than `SQL_FS_WORKER_QUEUE_WAIT_MS` for a worker, fails with `EWORKER_BUSY` (503) and `Retry-After: 1`. With the defaults, an exec can queue for up to 0.5 s before it fails. -A longer ingress wait does not absorb bursts, because the ingress queue holds no more requests than ingress admits at once. [Wait limits](AUTOSCALING.md#wait-limits) has the measurements. +In the default configuration, `SQL_FS_MAX_INGRESS_QUEUED_REQUESTS` and `SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS` default to the active limits (8 global and 4 per tenant). The tenant queue default is capped by the global queue's available tenant share, reserving one slot for another tenant when the global queue is greater than one. Increase queue depth and wait together to hold a bounded burst. Queued request bodies share the existing global and tenant raw-byte budgets. A full queue or byte budget still refuses work. [Wait limits](AUTOSCALING.md#wait-limits) explains sizing. **Unknown outcomes.** If a script loses its worker, lease or response after it starts, the request fails with `EEXEC_OUTCOME_UNKNOWN` (503, `retryable: false`). The server and the SDKs do not replay it. That includes read-only scripts, because they can still have network side effects. Read the sandbox state before the next action. Earlier items in a batch can already be committed. **Input budget.** Every byte that a script reads counts against `SQL_FS_WORKER_INPUT_BYTES`. That includes repeated reads, cached reads and the Python and JavaScript bridges. If a script exceeds it, the exec fails with `EEXEC_INPUT_LIMIT` (413, not retryable) and its writes roll back. -Every worker setting must be a positive integer. If a global limit is above 1, its per-tenant limit must be lower, so that other tenants keep some capacity. +Every worker setting must be a positive integer. The two ingress queue count settings also accept zero, which disables waiting while preserving immediate admission. If a global limit is above 1, its per-tenant limit must be lower, so that other tenants keep some capacity. | Variable | Default | |---|---| @@ -197,6 +201,8 @@ Every worker setting must be a positive integer. If a global limit is above 1, i | `SQL_FS_WORKER_CANCEL_GRACE_MS` | 500 ms | | `SQL_FS_MAX_INGRESS_REQUESTS` | 8 requests | | `SQL_FS_MAX_INGRESS_TENANT_REQUESTS` | Half of `SQL_FS_MAX_INGRESS_REQUESTS`, at least 1 | +| `SQL_FS_MAX_INGRESS_QUEUED_REQUESTS` | `SQL_FS_MAX_INGRESS_REQUESTS` | +| `SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS` | The active tenant limit, capped to the global queue's available tenant share | | `SQL_FS_MAX_INGRESS_BYTES` | 128 MiB | | `SQL_FS_MAX_INGRESS_TENANT_BYTES` | Three quarters of `SQL_FS_MAX_INGRESS_BYTES`, at least 1 | | `SQL_FS_MAX_INGRESS_MCP_LISTENERS` | 8 listeners | diff --git a/docs/READINESS.md b/docs/READINESS.md index 28a4d6e0..d6689bbf 100644 --- a/docs/READINESS.md +++ b/docs/READINESS.md @@ -4,7 +4,7 @@ This audit uses the eight areas in [Factory's Agent Readiness article](https://f ## Implementation workflow -The entry point is [AGENTS.md](../AGENTS.md). Run `pnpm setup:dev`, `pnpm check`, and `pnpm verify:local`. The first command installs locked dependencies. The second covers the server and both SDKs without services. The third exercises real Postgres, Redis, HTTP, MCP, and SDK behavior in a disposable stack. Use `pnpm verify:architecture` for ownership or protocol changes; CI runs that expanded profile, including worker failures, SSE finalization, input budgets, and tenant isolation. +The entry point is [AGENTS.md](../AGENTS.md). Run `pnpm setup:dev`, `pnpm check`, and `pnpm verify:local`. The first command installs locked dependencies. The second covers the server and both SDKs without services. The third exercises real Postgres, Redis, HTTP, MCP, and SDK behavior in a disposable stack. Use `pnpm verify:architecture` for ownership, protocol, or ingress admission changes; CI runs that expanded profile, including worker failures, SSE finalization, input budgets, ingress queue admission, and tenant isolation. | Area | Repository evidence | Remaining limit | | --- | --- | --- | diff --git a/package.json b/package.json index 118cd670..399f2acd 100644 --- a/package.json +++ b/package.json @@ -54,7 +54,7 @@ "just-git": "^1.10.0", "lru-cache": "^11.0.0", "postgres": "^3.4.0", - "zod": "^3.24.0" + "zod": "^4.6.7" }, "devDependencies": { "@biomejs/biome": "^2.5.15", diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index 9263ea63..5b7c655e 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -5,7 +5,8 @@ settings: excludeLinksFromLockfile: false overrides: - guarded-fetch>undici: 7.29.1 + guarded-fetch>undici: 7.30.1 + express>body-parser: 2.4.0 express-rate-limit>ip-address: 10.7.1 patchedDependencies: @@ -25,7 +26,7 @@ importers: version: 0.6.1(hono@4.13.13) '@modelcontextprotocol/sdk': specifier: ^1.32.1 - version: 1.32.1(zod@3.25.76) + version: 1.32.1(zod@4.6.7) async-mutex: specifier: ^0.5.0 version: 0.5.0 @@ -51,8 +52,8 @@ importers: specifier: ^3.4.0 version: 3.4.9 zod: - specifier: ^3.24.0 - version: 3.25.76 + specifier: ^4.6.7 + version: 4.6.7 devDependencies: '@biomejs/biome': specifier: ^2.5.15 @@ -1365,8 +1366,8 @@ packages: bl@4.1.0: resolution: {integrity: sha512-1W07cM9gS6DcLperZfFSj+bWLtaPGSOHWhPiGzXmvVJbRLdG82sH/Kn8EtW1VqWVA54AKf2h5k5BbnIbwF3h6w==} - body-parser@2.3.0: - resolution: {integrity: sha512-2cGmJupaNgg+QUwVLAucDuWuoMZ6EX9iHDRswZ5lsNYEmwPaRknMPCLZz07yTzVq/83p4o/wzbDZbBrTvGGTIw==} + body-parser@2.4.0: + resolution: {integrity: sha512-Ifk1KcLrxaGt1occQagQNFNNOqRt1LFuehEnHHzB8Z6cRgIxRU1TBaiIsUiCdA+gy5PL7Y1IX31DNKkRmxtXjQ==} engines: {node: '>=18'} braces@3.0.3: @@ -1685,6 +1686,10 @@ packages: resolution: {integrity: sha512-im9DjEDQ55s9fL4EYzOAv0yMqmMBSZp6G0VvFyTMPKWxiSBHUj9NW/qqLmXUwXrrM7AvqSlTCfvqRb0cM8yYqw==} engines: {node: '>=0.10.0'} + iconv-lite@0.7.3: + resolution: {integrity: sha512-IKXpvIzjnC9XTAUbVBcMfGS0EPaIXtW6v+zr+RRp+hqULEpo0owZax6wyRwPOJbWbzjYspQwusTsfVr0ifh4uQ==} + engines: {node: '>=0.10.0'} + ieee754@1.2.1: resolution: {integrity: sha512-dcyqhDvX1C46lXZcVqCpK+FtMRQVdIMN6/Df5js2zouUsqG7I6sFxitIC+7KYK29KdXOLHdu9zL4sFnoVQnqaA==} @@ -2041,6 +2046,10 @@ packages: resolution: {integrity: sha512-h6fhOIaRrID2CbEY2fqs+7t+UXZo+MLAnU5gRIq85uFtdiUPCdsApMlHhXogKVM4HM2DVbIjGNTTYH2OcmP1vA==} engines: {node: '>=0.6'} + qs@6.16.1: + resolution: {integrity: sha512-5Px6J7rfHBAGUhNQ3es4YzcOdBBw0SDcVtThJml4RdnKw4tKs2epA0kPZ+K8X+WiHktT93RHVcQ/3ym5aTCgtg==} + engines: {node: '>=0.6'} + queue-microtask@1.2.3: resolution: {integrity: sha512-NuaNSa6flKT5JaSYQzJok04JzTL1CA6aGhv5rfLW3PgqA+M2ChpZQnAC8h8i4ZFkBS8X5RqkDBHA7r4hej3K9A==} @@ -2315,8 +2324,8 @@ packages: undici-types@6.21.0: resolution: {integrity: sha512-iwDZqg0QAGrg9Rav5H4n0M64c3mkR59cJ6wQp+7C4nI0gsmExaedaYLNO44eT4AtBBwjbTiGPMlt2Md0T9H9JQ==} - undici@7.29.1: - resolution: {integrity: sha512-RYONW2MeafgYlkVOKYKkA/Ag7BmXqgIWCa8t1m0JcxrQg9pI9lEqRhAOruOBCbAohOa/gkCF+iPi9hrgvTzu6Q==} + undici@7.30.1: + resolution: {integrity: sha512-03KrMbjIFDWQR5RNPrSw3bd1r12JpyFQl9/yxjUbJtqkjmllqC5lFjZh6ujeuJCKr8EOQvRW872Oy/az+nLYxg==} engines: {node: '>=20.18.1'} unpipe@1.0.0: @@ -2439,11 +2448,8 @@ packages: peerDependencies: zod: ^3.25.28 || ^4 - zod@3.25.76: - resolution: {integrity: sha512-gzUt/qt81nXsFGKIFcC3YnfEAx5NkunCfnDlvuBSSFS02bcXu4Lmea0AFIUwbLWxWPx3d9p8S5QoaujKcNQxcQ==} - - zod@4.3.6: - resolution: {integrity: sha512-rftlrkhHZOcjDwkGlnUtZZkvaPHCsDATp4pGpuOOMDaTdDDXF91wuVDJoWoPsKX/3YPQ5fHuF3STjcYyKr+Qhg==} + zod@4.6.7: + resolution: {integrity: sha512-g8W2D2kU6a8untc053fX1uVBKzM7yqAxW/3zwk83+6RyF2+SKOuV+c0wBDhUwzV1PaGapmZH+rmcUzPf+3CGwg==} snapshots: @@ -2810,7 +2816,7 @@ snapshots: '@mixmark-io/domino@2.2.0': {} - '@modelcontextprotocol/sdk@1.32.1(zod@3.25.76)': + '@modelcontextprotocol/sdk@1.32.1(zod@4.6.7)': dependencies: '@hono/node-server': 1.19.17(hono@4.13.13) ajv: 8.18.0 @@ -2827,8 +2833,8 @@ snapshots: json-schema-typed: 8.0.2 pkce-challenge: 5.0.1 raw-body: 3.0.2 - zod: 3.25.76 - zod-to-json-schema: 3.25.2(zod@3.25.76) + zod: 4.6.7 + zod-to-json-schema: 3.25.2(zod@4.6.7) transitivePeerDependencies: - supports-color @@ -3308,15 +3314,15 @@ snapshots: readable-stream: 3.6.2 optional: true - body-parser@2.3.0: + body-parser@2.4.0: dependencies: bytes: 3.1.2 content-type: 2.1.0 debug: 4.4.3 http-errors: 2.0.1 - iconv-lite: 0.7.2 + iconv-lite: 0.7.3 on-finished: 2.4.1 - qs: 6.16.0 + qs: 6.16.1 raw-body: 3.0.2 type-is: 2.1.0 transitivePeerDependencies: @@ -3521,7 +3527,7 @@ snapshots: express@5.2.1: dependencies: accepts: 2.0.0 - body-parser: 2.3.0 + body-parser: 2.4.0 content-disposition: 1.1.0 content-type: 1.0.5 cookie: 0.7.2 @@ -3673,7 +3679,7 @@ snapshots: guarded-fetch@0.1.3: dependencies: ipaddr.js: 2.2.0 - undici: 7.29.1 + undici: 7.30.1 has-symbols@1.1.0: {} @@ -3697,6 +3703,10 @@ snapshots: dependencies: safer-buffer: 2.1.2 + iconv-lite@0.7.3: + dependencies: + safer-buffer: 2.1.2 + ieee754@1.2.1: {} import-meta-resolve@4.2.0: {} @@ -3798,7 +3808,7 @@ snapshots: strip-json-comments: 5.0.3 unbash: 2.2.0 yaml: 2.8.3 - zod: 4.3.6 + zod: 4.6.7 transitivePeerDependencies: - '@emnapi/core' - '@emnapi/runtime' @@ -4086,6 +4096,11 @@ snapshots: es-define-property: 1.0.1 side-channel: 1.1.1 + qs@6.16.1: + dependencies: + es-define-property: 1.0.1 + side-channel: 1.1.1 + queue-microtask@1.2.3: {} range-parser@1.2.1: {} @@ -4412,7 +4427,7 @@ snapshots: undici-types@6.21.0: {} - undici@7.29.1: {} + undici@7.30.1: {} unpipe@1.0.0: {} @@ -4517,10 +4532,8 @@ snapshots: yaml@2.9.1: {} - zod-to-json-schema@3.25.2(zod@3.25.76): + zod-to-json-schema@3.25.2(zod@4.6.7): dependencies: - zod: 3.25.76 - - zod@3.25.76: {} + zod: 4.6.7 - zod@4.3.6: {} + zod@4.6.7: {} diff --git a/pnpm-workspace.yaml b/pnpm-workspace.yaml index cd38c1ea..79ec6825 100644 --- a/pnpm-workspace.yaml +++ b/pnpm-workspace.yaml @@ -1,5 +1,6 @@ patchedDependencies: just-bash@3.6.0: patches/just-bash@3.6.0.patch overrides: - guarded-fetch>undici: 7.29.1 + guarded-fetch>undici: 7.30.1 + express>body-parser: 2.4.0 express-rate-limit>ip-address: 10.7.1 diff --git a/scripts/verify-local.sh b/scripts/verify-local.sh index 3db8e900..f53ab9e7 100644 --- a/scripts/verify-local.sh +++ b/scripts/verify-local.sh @@ -56,7 +56,7 @@ node scripts/verify/assert-integration-report.mjs "$evidence/integration.json" "${verify_env[@]}" node scripts/verify/sdk-clients.mjs if [[ "$profile" == architecture ]]; then - for suite in worker-failures sse-finalization input-budgets tenants; do + for suite in worker-failures sse-finalization input-budgets ingress-queue tenants; do "${verify_env[@]}" node "scripts/verify/$suite.mjs" done fi diff --git a/scripts/verify/aca-load-barrier.mjs b/scripts/verify/aca-load-barrier.mjs new file mode 100644 index 00000000..712daf91 --- /dev/null +++ b/scripts/verify/aca-load-barrier.mjs @@ -0,0 +1,26 @@ +import { readFile, writeFile } from "node:fs/promises"; + +const failure = (code) => Object.assign(new Error(code), { code }); + +export async function waitForStartBarrier(path, runId, { timeoutMs, isStopped = () => false }) { + const expires = Date.now() + timeoutMs; + if (isStopped()) throw failure("ESTART_BARRIER_STOPPED"); + await writeFile(`${path}.prepared.json`, JSON.stringify({ + runId, preparedAt: new Date().toISOString(), expiresAt: new Date(expires).toISOString(), releasePath: path, + }), { flag: "wx" }); + while (!isStopped()) { + if (Date.now() >= expires) throw failure("ESTART_BARRIER_TIMEOUT"); + let release; + try { release = JSON.parse(await readFile(path, "utf8")); } + catch (error) { if (error.code !== "ENOENT") throw error; } + if (isStopped()) break; + if (Date.now() >= expires) throw failure("ESTART_BARRIER_TIMEOUT"); + if (release !== undefined) { + if (release?.runId !== runId) throw failure("ESTART_BARRIER_MISMATCH"); + if (release.release !== true) throw failure("ESTART_BARRIER_RELEASE"); + return; + } + await new Promise((resolve) => setTimeout(resolve, Math.min(250, Math.max(1, expires - Date.now())))); + } + throw failure("ESTART_BARRIER_STOPPED"); +} diff --git a/scripts/verify/aca-load-barrier.test.mjs b/scripts/verify/aca-load-barrier.test.mjs new file mode 100644 index 00000000..30e13d84 --- /dev/null +++ b/scripts/verify/aca-load-barrier.test.mjs @@ -0,0 +1,56 @@ +import assert from "node:assert/strict"; +import { mkdtemp, readFile, rm, writeFile } from "node:fs/promises"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { test } from "node:test"; +import { waitForStartBarrier } from "./aca-load-barrier.mjs"; + +const pause = (ms) => new Promise((resolve) => setTimeout(resolve, ms)); +async function fixture(visit) { + const directory = await mkdtemp(join(tmpdir(), "sqlfs-start-barrier-")); + try { await visit(join(directory, "release.json")); } + finally { await rm(directory, { recursive: true, force: true }); } +} +async function prepared(path) { + for (let i = 0; i < 100; i++) { + try { return JSON.parse(await readFile(`${path}.prepared.json`, "utf8")); } + catch (error) { if (error.code !== "ENOENT" && !(error instanceof SyntaxError)) throw error; } + await pause(5); + } + throw new Error("prepared signal not observed"); +} + +test("the local barrier waits for an explicit release matching its run", async () => { + await fixture(async (path) => { + let settled = false; + const waiting = waitForStartBarrier(path, "fresh-run", { timeoutMs: 1000 }); + waiting.then(() => { settled = true; }, () => { settled = true; }); + const signal = await prepared(path); + assert.equal(signal.runId, "fresh-run"); assert.equal(signal.releasePath, path); + await pause(20); assert.equal(settled, false); + await writeFile(path, JSON.stringify({ runId: signal.runId, release: true })); + await waiting; assert.equal(settled, true); + }); +}); + +test("a stale release or a missing explicit release flag cannot start work", async () => { + for (const [release, code] of [ + [{ runId: "old-run", release: true }, "ESTART_BARRIER_MISMATCH"], + [{ runId: "fresh-run" }, "ESTART_BARRIER_RELEASE"], + ]) await fixture(async (path) => { + await writeFile(path, JSON.stringify(release)); + await assert.rejects(waitForStartBarrier(path, "fresh-run", { timeoutMs: 1000 }), { code }); + }); +}); + +test("an unreleased barrier times out and a stopped run never auto-releases", async () => { + await fixture(async (path) => { + await assert.rejects(waitForStartBarrier(path, "fresh-run", { timeoutMs: 25 }), { code: "ESTART_BARRIER_TIMEOUT" }); + }); + await fixture(async (path) => { + let stopped = false; + const waiting = waitForStartBarrier(path, "fresh-run", { timeoutMs: 1000, isStopped: () => stopped }); + const rejection = assert.rejects(waiting, { code: "ESTART_BARRIER_STOPPED" }); + await prepared(path); stopped = true; await rejection; + }); +}); diff --git a/scripts/verify/aca-load-logger.mjs b/scripts/verify/aca-load-logger.mjs new file mode 100644 index 00000000..b500622d --- /dev/null +++ b/scripts/verify/aca-load-logger.mjs @@ -0,0 +1,21 @@ +export function createEventLogger(append, onFailure) { + let pending = Promise.resolve(); + let firstError; + return { + record(entry) { + pending = pending.then(() => append(entry)).catch((error) => { + if (firstError === undefined) { + firstError = error; + onFailure(error); + } + }); + return pending; + }, + flush() { + return pending; + }, + get error() { + return firstError; + }, + }; +} diff --git a/scripts/verify/aca-load-workload.mjs b/scripts/verify/aca-load-workload.mjs new file mode 100644 index 00000000..eba76930 --- /dev/null +++ b/scripts/verify/aca-load-workload.mjs @@ -0,0 +1,61 @@ +export async function visitConcurrent(items, concurrency, visit) { + let next = 0, failed = false, failure; + await Promise.all(Array.from({ length: Math.min(concurrency, items.length) }, async () => { + while (!failed && next < items.length) { + const index = next++; + try { await visit(items[index], index); } + catch (error) { if (!failed) { failed = true; failure = error; } } + } + })); + if (failed) throw failure; +} + +const quote = value => `'${value.replaceAll("'", "'\\''")}'`; + +export function overloadDelayMs(retryAfter, attempt, nowMs = Date.now()) { + const seconds = retryAfter?.trim() ? Number(retryAfter) : NaN; + const date = Date.parse(retryAfter || ''); + const minimum = Number.isFinite(seconds) && seconds >= 0 ? seconds * 1000 : + Number.isFinite(date) ? Math.max(0, date - nowMs) : 1000; + return Math.max(minimum, Math.min(10000, 1000 * 2 ** Math.min(attempt, 4))); +} + +export function safeRetryAfter(value) { + if (typeof value !== 'string' || value.length > 128) return null; + const trimmed = value.trim(); + if (/^\d{1,10}$/.test(trimmed)) return trimmed; + if (!/^(Mon|Tue|Wed|Thu|Fri|Sat|Sun), \d{2} (Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec) \d{4} \d{2}:\d{2}:\d{2} GMT$/.test(trimmed)) return null; + const timestamp = Date.parse(trimmed); + return Number.isFinite(timestamp) && new Date(timestamp).toUTCString() === trimmed ? trimmed : null; +} + +export function buildScript(marker, cfg, path = '/home/user/aca-markers.txt') { + return `${cfg.hold ? `sleep ${cfg.hold / 1000} && ` : ''}${cfg.cpu ? `i=0; while [ "$i" -lt ${cfg.cpu} ]; do i=$((i+1)); done; ` : ''}` + + `printf '%s\\n' ${quote(marker)} >> ${quote(path)} && printf '%s' ${quote(marker)}`; +} + +export function validateOperation(op, counts, readable) { + const attempts = op.attempts.map(a => { + const count = readable ? counts.get(a.marker) || 0 : null; + return { marker: a.marker, count, valid: a.success ? count === 1 : a.safeRefusal || a.rejected ? count === 0 : null }; + }); + const count = readable ? attempts.reduce((n, a) => n + a.count, 0) : null; + const valid = attempts.some(a => a.valid === false) ? false : op.outcome === 'unknown' ? null : + attempts.every(a => a.valid === true) && count === (op.outcome === 'success' ? 1 : 0); + return { op: op.id, marker: op.marker, sandbox: op.sandbox, outcome: op.outcome, count, attempts, valid }; +} + +export function markerIntegrity(operations, counts) { + const known = new Set(operations.flatMap(op => op.attempts.map(a => a.marker))); + const unexpected = [...counts.keys()].filter(marker => !known.has(marker)); + const duplicates = [...counts].filter(([, count]) => count > 1).map(([marker]) => marker); + return { valid: unexpected.length === 0 && duplicates.length === 0, + unexpectedCount: unexpected.length, duplicateCount: duplicates.length, + unexpectedMarkers: unexpected.slice(0, 20), duplicateMarkers: duplicates.slice(0, 20) }; +} + +export function outcomeTotals(ledger) { + const totals = { success: 0, safeRefusal: 0, unknown: 0, failed: 0 }; + for (const op of ledger) totals[Object.hasOwn(totals, op.outcome) ? op.outcome : 'unknown']++; + return totals; +} diff --git a/scripts/verify/aca-load.mjs b/scripts/verify/aca-load.mjs new file mode 100644 index 00000000..e22a663f --- /dev/null +++ b/scripts/verify/aca-load.mjs @@ -0,0 +1,351 @@ +import { execFile } from 'node:child_process'; +import { promisify, parseArgs } from 'node:util'; +import { createHash, createHmac, randomUUID } from 'node:crypto'; +import { appendFile, mkdir, readFile, rename, writeFile } from 'node:fs/promises'; +import { dirname, join, resolve } from 'node:path'; +import { fileURLToPath } from 'node:url'; +import { monitorEventLoopDelay } from 'node:perf_hooks'; +import { buildScript, markerIntegrity, outcomeTotals, overloadDelayMs, safeRetryAfter, validateOperation, visitConcurrent } from './aca-load-workload.mjs'; +import { createEventLogger } from './aca-load-logger.mjs'; +import { waitForStartBarrier } from './aca-load-barrier.mjs'; + +const defaults = { app: 'virtualfs-api', group: 'rg-harry-dev', duration: '30', rate: '2', pool: '20', + 'max-inflight': '20', 'setup-concurrency': '1', 'timeout-ms': '120000', 'command-timeout-ms': '30000', 'hold-ms': '250', + 'cpu-iterations': '0', 'start-barrier-timeout-ms': '300000', interval: '5', 'max-start-delay-ms': '250', retries: '0' }; +const { positionals: [command], values: flags } = parseArgs({ allowPositionals: true, options: { + ...Object.fromEntries(Object.entries(defaults).map(([k, v]) => [k, { type: 'string', default: v }])), + 'start-barrier': { type: 'string' }, out: { type: 'string' }, manifest: { type: 'string' }, tenant: { type: 'string' }, + resource: { type: 'string', multiple: true, default: [] }, 'app-metrics': { type: 'boolean', default: false }, + help: { type: 'boolean', default: false }, +} }); +if (flags.help || !['inspect', 'observe', 'load', 'cleanup'].includes(command)) { + console.log('node aca-load.mjs inspect|observe|load|cleanup [--help]\n' + + 'Common: --app NAME --group RG --out NEW_DIRECTORY --resource ARM_ID (repeatable)\n' + + 'Observe: --duration SECONDS --interval SECONDS [--app-metrics]\n' + + 'Load: --duration SECONDS --rate OPS_PER_SECOND --pool N --max-inflight N --hold-ms N\n' + + ' --cpu-iterations N --retries N --timeout-ms N --command-timeout-ms N --tenant ID\n' + + ' --max-start-delay-ms N --interval SECONDS --setup-concurrency N (1..8, default 1)\n' + + ' --start-barrier PATH [--start-barrier-timeout-ms N (1000..900000, default 300000)]\n' + + ' Creates PATH.prepared.json after setup; atomically write {runId,release:true} to PATH to start.\nCleanup: --manifest PATH'); + process.exit(flags.help ? 0 : 2); +} +function number(key, min, max, integer = false) { + const n = Number(flags[key]); + if (!Number.isFinite(n) || n < min || n > max || (integer && !Number.isInteger(n))) throw new Error(`Invalid --${key}`); + return n; +} +const cfg = { duration: number('duration', 1, 7200), rate: number('rate', 0.01, 1000), + pool: number('pool', 1, 500, true), setupConcurrency: number('setup-concurrency', 1, 8, true), maxInflight: number('max-inflight', 1, 500, true), + timeout: number('timeout-ms', 5000, 120000, true), commandTimeout: number('command-timeout-ms', 1000, 90000, true), + hold: number('hold-ms', 0, 60000), cpu: number('cpu-iterations', 0, 100000, true), + startBarrierTimeoutMs: number('start-barrier-timeout-ms', 1000, 900000, true), + interval: number('interval', 1, 300), maxDelay: number('max-start-delay-ms', 1, 10000), retries: number('retries', 0, 20, true) }; +if (flags['start-barrier'] !== undefined && !flags['start-barrier'].trim()) throw new Error('--start-barrier must name a local release file'); +if (flags['start-barrier'] && command !== 'load') throw new Error('--start-barrier is only valid for load'); +if (cfg.timeout <= cfg.commandTimeout + 5000 || cfg.hold >= cfg.commandTimeout || Math.ceil(cfg.duration * cfg.rate) * (cfg.retries + 1) > 500000) + throw new Error('Require timeout > command timeout + 5000ms, hold < command timeout, and <= 500000 possible attempts'); +if (flags.resource.length > 8 || flags.resource.some(x => !/^\/subscriptions\/[\w-]+\/resourceGroups\/[\w.-]+\/providers\/Microsoft\.(App\/containerApps|DBforPostgreSQL\/flexibleServers|Cache\/Redis)\/[\w.-]+$/i.test(x))) + throw new Error('Resources must be up to 8 ACA, PostgreSQL Flexible Server or Azure Redis ARM IDs'); +const exec = promisify(execFile), now = () => new Date().toISOString(), sleep = ms => new Promise(r => setTimeout(r, ms)); +const runId = `aca-${Date.now().toString(36)}-${randomUUID().slice(0, 8)}`; +const root = flags.manifest ? dirname(resolve(flags.manifest)) : resolve(flags.out || join(dirname(fileURLToPath(import.meta.url)), '.run', runId)); +let manifest, base, token, loadStart, loadDeadline, stopped = false; +const eventLogger = createEventLogger((entry) => appendFile(join(root, 'events.jsonl'), entry), () => { process.exitCode = 1; }); +const ledger = [], delays = [], running = new Set(), errors = Object.create(null); +const counters = { planned: Math.ceil(cfg.rate * cfg.duration), offered: 0, dropped: 0, sentOperations: 0, + sentAttempts: 0, completedAttempts: 0, completedOperations: 0, completedInOfferWindow: 0, successesInOfferWindow: 0, httpResponses: 0, + successes: 0, safeRefusals: 0, unknown: 0, failed: 0, peakInflight: 0 }; +for (const signal of ['SIGINT', 'SIGTERM']) process.on(signal, () => { stopped = true; }); +const safeCode = x => typeof x === 'string' && /^[A-Za-z0-9_.:-]{1,160}$/.test(x) ? x : null; +const safeError = error => ({ error: safeCode(error?.name) || 'Error', code: safeCode(error?.code ?? error?.cause?.code), killed: error?.killed === true }); +const record = row => eventLogger.record(JSON.stringify({ at: now(), ...row }) + '\n'); +async function jsonFile(name, value) { const path = join(root, name); await writeFile(path + '.tmp', JSON.stringify(value, null, 2)); await rename(path + '.tmp', path); } +let manifestWrites = Promise.resolve(); +const saveManifest = () => { + const snapshot = structuredClone(manifest); + manifestWrites = manifestWrites.then(() => jsonFile('manifest.json', snapshot)); + return manifestWrites; +}; +async function az(args) { + try { const r = await exec('az', [...args, '--output', 'json', '--only-show-errors'], { timeout: 60000, maxBuffer: 16 * 1024 ** 2 }); return JSON.parse(r.stdout); } + catch (error) { throw Object.assign(new Error('Azure CLI read failed; stdout and stderr suppressed'), { code: safeCode(String(error?.code)), name: 'AzureReadError' }); } +} +const appArgs = () => ['--name', flags.app, '--resource-group', flags.group]; +async function appState() { + return az(['containerapp', 'show', ...appArgs(), '--query', '{id:id,name:name,location:location,fqdn:properties.configuration.ingress.fqdn,revision:properties.latestRevisionName,ready:properties.latestReadyRevisionName,provisioning:properties.provisioningState,scale:{min:properties.template.scale.minReplicas,max:properties.template.scale.maxReplicas,polling:properties.template.scale.pollingInterval,cooldown:properties.template.scale.cooldownPeriod,rules:properties.template.scale.rules[].{name:name,httpConcurrency:http.metadata.concurrentRequests,customType:custom.type}},containers:properties.template.containers[].{name:name,image:image,resources:resources}}']); +} +async function armSnapshot() { + const requestedAt = now(), state = await appState(); + const revisions = await az(['containerapp', 'revision', 'list', ...appArgs(), '--all', '--query', '[].{name:name,active:properties.active,replicas:properties.replicas,running:properties.runningState,health:properties.healthState}']); + const eligible = revisions.filter(x => x.active || x.replicas > 0), selected = eligible.slice(0, 30); + const replicas = await Promise.all(selected.map(async revision => { + try { return { revision: revision.name, replicas: await az(['containerapp', 'replica', 'list', ...appArgs(), '--revision', revision.name, '--query', '[].{name:name,created:properties.createdTime,state:properties.runningState,containers:properties.containers[].{name:name,ready:ready,started:started,restarts:restartCount,state:runningState}}']) }; } + catch (error) { return { revision: revision.name, ...safeError(error) }; } + })); + return { requestedAt, observedAt: now(), state, revisions, replicas, replicaInventoryTruncated: eligible.length > selected.length }; +} +async function authenticate(owner, tenant) { + const app = await az(['containerapp', 'show', ...appArgs()]); + const env = app.properties.template.containers.find(c => c.name === 'api')?.env || []; + const entry = env.find(x => x.name === 'AUTH_SECRET'); + let secret = entry?.value; + if (!secret && entry?.secretRef) { + const secrets = await az(['rest', '--method', 'post', '--url', `https://management.azure.com${app.id}/listSecrets?api-version=2025-07-01`]); + secret = secrets.value.find(x => x.name === entry.secretRef)?.value; + } + if (!secret) throw new Error('Cannot resolve application signing key'); + const enc = x => Buffer.from(JSON.stringify(x)).toString('base64url'); + const payload = `${enc({ alg: 'HS256' })}.${enc({ sub: owner, ...(tenant ? { tenant } : {}), iat: Math.floor(Date.now() / 1000), exp: Math.floor(Date.now() / 1000) + 14400 })}`; + token = `${payload}.${createHmac('sha256', secret).update(payload).digest('base64url')}`; + base = `https://${app.properties.configuration.ingress.fqdn}`; + if (manifest?.base && manifest.base !== base) throw new Error('Application hostname differs from cleanup manifest'); +} +async function request(path, body, method = body === undefined ? 'GET' : 'POST', limit = 1024 * 1024, deadline = cfg.timeout) { + const began = performance.now(), requestedAt = now(); let status = null; + try { + const response = await fetch(base + path, { method, redirect: 'error', headers: { Authorization: `Bearer ${token}`, + ...(body === undefined ? {} : { 'Content-Type': 'application/json' }) }, ...(body === undefined ? {} : { body: JSON.stringify(body) }), signal: AbortSignal.timeout(Math.max(1, Math.ceil(deadline))) }); + status = response.status; const chunks = []; let bytes = 0; + if (response.body) for await (const chunk of response.body) { bytes += chunk.length; if (bytes > limit) throw Object.assign(new Error('Response exceeds limit'), { name: 'ResponseTooLarge' }); chunks.push(chunk); } + const text = Buffer.concat(chunks).toString('utf8'); let json; + try { json = JSON.parse(text); } catch { /* Binary and Prometheus responses have no JSON body. */ } + const retryAfter = response.headers.get('retry-after'); + const replica = ['x-sqlfs-replica', 'x-replica-id', 'x-azure-containerapp-replica-name'].map(k => safeCode(response.headers.get(k))).find(Boolean) || null; + return { status, requestedAt, ms: performance.now() - began, bytes, hash: createHash('sha256').update(text).digest('hex'), + code: safeCode(json?.code), retryable: json?.retryable === true, retryAfter, replica, text, json }; + } catch (error) { return { status, requestedAt, ms: performance.now() - began, ...safeError(error), transportFailure: true }; } +} +function publicResult(r) { return { status: r.status, requestedAt: r.requestedAt, ms: r.ms, bytes: r.bytes, hash: r.hash, + code: r.code, retryable: r.retryable, retryAfter: safeRetryAfter(r.retryAfter), replica: r.replica, error: r.error, + transportFailure: r.transportFailure, exitCode: r.json?.exitCode, stdoutBytes: typeof r.json?.stdout === 'string' ? Buffer.byteLength(r.json.stdout) : undefined, + stderrBytes: typeof r.json?.stderr === 'string' ? Buffer.byteLength(r.json.stderr) : undefined }; } +const safeRefusal = r => !r.transportFailure && r.status === 503 && r.retryable === true && ['EWORKER_BUSY', 'ERUNTIME_BUSY', 'ESHUTTINGDOWN'].includes(r.code); +async function appMetrics() { + const r = await request('/metrics'); const metrics = Object.create(null); + if (r.status === 200 && !r.transportFailure) for (const line of r.text.split('\n')) { + const m = /^((?:sql_fs_|process_|nodejs_)[a-zA-Z0-9_]+(?:\{le="(?:\+Inf|\d+)"\})?) ([+\-\d.eE]+)$/.exec(line); + if (m && Number.isFinite(Number(m[2])) && Object.keys(metrics).length < 200) metrics[m[1]] = Number(m[2]); + } + return { scope: 'load-balanced per-replica sample, never a fleet total', replica: r.replica, + identityAvailable: r.replica !== null, request: publicResult(r), metrics }; +} +const resourceMetrics = new Map(); +async function prepareResources() { + for (const resource of flags.resource) { + try { + const definitions = await az(['monitor', 'metrics', 'list-definitions', '--resource', resource]); + const available = definitions.map(d => ({ name: safeCode(d.name?.value), unit: safeCode(d.unit), aggregation: safeCode(d.primaryAggregationType) })); + const acaNames = new Set(['UsageNanoCores', 'WorkingSetBytes', 'RestartCount', 'Replicas', 'Requests', 'RxBytes', 'TxBytes']); + const chosen = available.filter(d => /Microsoft\.App\/containerApps/i.test(resource) ? acaNames.has(d.name) : + /cpu|nano.?cores|memory|working.?set|restart|connection|request|latency|error|load|cache|bandwidth|network|iops|replica|bytes/i.test(d.name || '')).slice(0, 16); + resourceMetrics.set(resource, chosen.map(d => d.name)); + await record({ kind: 'metricDefinitions', resource, available, chosen }); + } catch (error) { await record({ kind: 'metricDefinitions', resource, ...safeError(error) }); } + } +} +async function azureMetrics() { + for (const [resource, names] of resourceMetrics) { + if (!names.length) continue; + try { + const result = await az(['monitor', 'metrics', 'list', '--resource', resource, '--metric', ...names, + '--start-time', new Date(Date.now() - 300000).toISOString(), '--end-time', now(), '--interval', 'PT1M']); + await record({ kind: 'azureMetrics', resource, interval: 'PT1M', values: result.value?.map(m => ({ name: safeCode(m.name?.value), unit: safeCode(m.unit), + series: m.timeseries?.slice(0, 100).map(s => ({ dimensions: s.metadatavalues?.map(d => ({ name: safeCode(d.name?.value), value: safeCode(d.value) })), + data: s.data?.slice(-6).map(d => ({ timeStamp: d.timeStamp, average: d.average, maximum: d.maximum, minimum: d.minimum, total: d.total, count: d.count })) })) })) }); + } catch (error) { await record({ kind: 'azureMetrics', resource, ...safeError(error) }); } + } +} +async function sample(withApp) { + await record({ kind: 'generatorSample', rssBytes: process.memoryUsage().rss, cpu: process.cpuUsage(), inflight: running.size }); + const tasks = [armSnapshot().then(value => record({ kind: 'arm', value })), azureMetrics()]; + if (withApp) tasks.push(appMetrics().then(value => record({ kind: 'appMetrics', value }))); + for (const result of await Promise.allSettled(tasks)) if (result.status === 'rejected') await record({ kind: 'observationError', ...safeError(result.reason) }); +} +async function cleanup(recover = false) { + const found = await request('/v1/sandboxes'); + await record({ kind: 'cleanupDiscovery', request: publicResult(found) }); + const discovered = found.status === 200 && !found.transportFailure && Array.isArray(found.json?.sandboxes); + if (discovered) { + for (const s of found.json.sandboxes) if (s.owner === manifest.owner && /^[0-9a-f-]{36}$/i.test(s.id)) { + if (!manifest.sandboxes.some(x => x.id === s.id)) manifest.sandboxes.push({ id: s.id, name: s.name }); + } + } + manifest.cleanupPending = true; await saveManifest(); + await visitConcurrent(manifest.sandboxes, 4, async sandbox => { + if (recover) { + const r = await request(`/v1/sandboxes/${sandbox.id}/files/home/user/aca-markers.txt`, undefined, 'GET', 32 * 1024 ** 2); + const markerCounts = new Map(); + if (r.status === 200 && !r.transportFailure) for (const line of r.text.split('\n')) if (line.startsWith(`${manifest.runId}-`) && safeCode(line)) markerCounts.set(line, (markerCounts.get(line) || 0) + 1); + const file = `recovery-${Date.now()}-${sandbox.id}.json`; + await jsonFile(file, { sandbox: sandbox.id, request: publicResult(r), markerCounts: [...markerCounts] }); + await record({ kind: 'recoveryReadback', sandbox: sandbox.id, file, request: publicResult(r) }); + } + let r; + for (let attempt = 0; attempt < 3; attempt++) { + r = await request(`/v1/sandboxes/${sandbox.id}`, undefined, 'DELETE'); + await record({ kind: 'cleanup', sandbox: sandbox.id, attempt, request: publicResult(r) }); + if ([200, 204, 404].includes(r.status) && !r.transportFailure) break; + await sleep(1000 + Math.random() * 500); + } + sandbox.deleted = [200, 204, 404].includes(r.status) && !r.transportFailure; + await saveManifest(); + }); + manifest.cleanupPending = !discovered || manifest.sandboxes.some(sandbox => !sandbox.deleted); + manifest.cleanedAt = now(); await saveManifest(); + if (manifest.cleanupPending) process.exitCode = 1; +} +function stats(values) { + if (!values.length) return { count: 0 }; + const sorted = [...values].sort((a, b) => a - b), q = p => sorted[Math.min(sorted.length - 1, Math.ceil(p * sorted.length) - 1)]; + return { count: sorted.length, min: sorted[0], mean: sorted.reduce((a, b) => a + b, 0) / sorted.length, p50: q(.5), p95: q(.95), p99: q(.99), max: sorted.at(-1) }; +} +async function validate() { + const validation = [], unknown = [], integrity = []; + await visitConcurrent(manifest.sandboxes, 4, async sandbox => { + const r = await request(`/v1/sandboxes/${sandbox.id}/files/home/user/aca-markers.txt`, undefined, 'GET', 32 * 1024 ** 2); + const counts = new Map(); + if (r.status === 200 && !r.transportFailure) for (const line of r.text.split('\n').filter(Boolean)) counts.set(line, (counts.get(line) || 0) + 1); + const readable = !r.transportFailure && (r.status === 200 || (r.status === 404 && r.code === 'ENOENT')); + const operations = ledger.filter(op => op.sandbox === sandbox.id); + for (const op of operations) { + const row = validateOperation(op, counts, readable); + validation.push(row); if (op.outcome === 'unknown') unknown.push({ ...row, attempts: op.attempts }); + await record({ kind: 'validation', ...row }); + } + const checked = { sandbox: sandbox.id, ...markerIntegrity(operations, counts) }; integrity.push(checked); + await record({ kind: 'readback', sandbox: sandbox.id, request: publicResult(r), readable, markers: counts.size, integrity: checked }); + }); + await jsonFile('reconciliation.json', { checkedAt: now(), validation, integrity, unknown, + note: 'Unknown outcomes remain unknown even when a marker is found. Cleanup follows this saved readback.' }); + return { validation, integrity }; +} +async function execute(op) { + const began = performance.now(); + for (let attempt = 0; ; attempt++) { + const marker = `${op.marker}-${attempt}`; + const script = buildScript(marker, cfg); + record({ kind: 'attemptStart', op: op.id, sandbox: op.sandbox, attempt, marker, scheduledMs: op.scheduledMs }); + const sendDelayMs = performance.now() - loadStart - op.scheduledMs; + if (attempt === 0) op.sendStartDelayMs = sendDelayMs; + counters.sentAttempts++; + const r = await request(`/v1/sandboxes/${op.sandbox}/exec-sync`, { script, timeoutMs: cfg.commandTimeout }, 'POST', 1024 * 1024, cfg.timeout - (performance.now() - began)); + counters.completedAttempts++; + if (r.status !== null) counters.httpResponses++; + const success = !r.transportFailure && r.status === 200 && r.json?.exitCode === 0 && r.json?.stdout === marker && r.json?.stderr === ''; + const refused = safeRefusal(r), key = `${r.status ?? 'transport'}:${r.code || r.error || (success ? 'success' : 'unexpected')}`; + const rejected = !r.transportFailure && [400, 401, 403, 404, 413, 415, 422, 429].includes(r.status); + if (!success) errors[key] = (errors[key] || 0) + 1; + op.attempts.push({ ...publicResult(r), marker, success, safeRefusal: refused, rejected, sendDelayMs }); + record({ kind: 'attempt', op: op.id, sandbox: op.sandbox, attempt, marker, success, safeRefusal: refused, rejected, result: publicResult(r) }); + if (refused && attempt < cfg.retries && !stopped) { + const after = overloadDelayMs(r.retryAfter, attempt); + if (performance.now() - began + after + cfg.commandTimeout + 5000 > cfg.timeout) { op.outcome = 'safeRefusal'; break; } + await sleep(after + Math.random() * Math.min(1000, after * .25 + 100)); + if (stopped) { op.outcome = 'safeRefusal'; break; } + continue; + } + op.outcome = success ? 'success' : refused ? 'safeRefusal' : rejected ? 'failed' : 'unknown'; break; + } + op.ms = performance.now() - began; op.completedAfterStartMs = performance.now() - loadStart; op.endedAt = now(); counters.completedOperations++; + if (performance.now() <= loadDeadline) { counters.completedInOfferWindow++; if (op.outcome === 'success') counters.successesInOfferWindow++; } + if (op.outcome === 'success') counters.successes++; else if (op.outcome === 'safeRefusal') counters.safeRefusals++; else if (op.outcome === 'failed') counters.failed++; else counters.unknown++; + record({ kind: 'operation', ...op }); +} +async function load() { + manifest = { version: 1, runId, owner: `aca-load-${randomUUID()}`, tenant: flags.tenant || null, app: flags.app, group: flags.group, + namePrefix: `${runId}-`, createdAt: now(), cleanupPending: true, sandboxes: [] }; + await saveManifest(); await authenticate(manifest.owner, manifest.tenant); manifest.base = base; await saveManifest(); + let sampler, sampling = true, validation = [], integrity = [], measurement, began, offeredEnd; + const loop = monitorEventLoopDelay({ resolution: 10 }); + try { + await visitConcurrent(Array.from({ length: cfg.pool }), cfg.setupConcurrency, async (_, i) => { + if (stopped) return; + const name = `${manifest.namePrefix}${i}`; + const r = await request('/v1/sandboxes', { name }); + await record({ kind: 'create', name, request: publicResult(r) }); + if (r.status !== 201 || r.json?.owner !== manifest.owner || !/^[0-9a-f-]{36}$/i.test(r.json?.id || '') || r.transportFailure) throw new Error('Sandbox creation failed; cleanup discovers any owned orphan'); + manifest.sandboxes.push({ id: r.json.id, name }); await saveManifest(); + }); + if (flags['start-barrier']) { + await waitForStartBarrier(resolve(flags['start-barrier']), runId, { timeoutMs: cfg.startBarrierTimeoutMs, isStopped: () => stopped }); + await record({ kind: 'startBarrierReleased', runId }); + } + await sample(true); + const available = [...manifest.sandboxes]; + loop.enable(); began = performance.now(); loadStart = began; loadDeadline = began + cfg.duration * 1000; measurement = now(); + record({ kind: 'offerWindowStart', measurement, durationSeconds: cfg.duration, planned: counters.planned }); + sampler = (async () => { while (sampling && !stopped) { await sleep(cfg.interval * 1000); if (sampling && !stopped) await sample(true); } })().catch(() => { stopped = true; sampling = false; }); + for (let id = 0; id < counters.planned && !stopped; id++) { + const due = began + id * 1000 / cfg.rate; + if (due > performance.now()) await sleep(due - performance.now()); + if (stopped) break; + const delay = performance.now() - due; counters.offered++; delays.push(delay); + if (delay > cfg.maxDelay || running.size >= cfg.maxInflight || !available.length) { + counters.dropped++; record({ kind: 'drop', id, scheduledMs: id * 1000 / cfg.rate, startDelayMs: delay, + reason: delay > cfg.maxDelay ? 'generator-late' : running.size >= cfg.maxInflight ? 'max-inflight' : 'pool-exhausted' }); continue; + } + const sandbox = available.shift(), op = { id, sandbox: sandbox.id, marker: `${runId}-${id}`, scheduledMs: id * 1000 / cfg.rate, + startDelayMs: delay, startedAt: now(), attempts: [] }; + ledger.push(op); counters.sentOperations++; + const task = execute(op).catch(error => { stopped = true; op.outcome ||= 'unknown'; op.driverError = safeError(error); }).finally(() => { running.delete(task); available.push(sandbox); }); + running.add(task); counters.peakInflight = Math.max(counters.peakInflight, running.size); + } + if (!stopped && performance.now() < loadDeadline) await sleep(loadDeadline - performance.now()); + offeredEnd = performance.now(); record({ kind: 'offerWindowEnd', elapsedMs: offeredEnd - began }); + await Promise.allSettled(running); loop.disable(); record({ kind: 'drainEnd', elapsedMs: performance.now() - began }); + if (ledger.some(op => op.outcome === 'unknown')) { + await record({ kind: 'reconciliationWait', ms: cfg.commandTimeout + 5000 }); await sleep(cfg.commandTimeout + 5000); + } + ({ validation, integrity } = await validate()); + } finally { + sampling = false; await sampler?.catch(() => { stopped = true; }); loop.disable(); await Promise.allSettled(running); + await cleanup(); + const valid = validation.filter(x => x.valid === true).length, invalid = validation.filter(x => x.valid === false).length; + const integrityFailures = integrity.filter(x => !x.valid).length; + const totals = outcomeTotals(ledger); + const attemptLatencies = Object.create(null); + for (const op of ledger) for (const a of op.attempts) { + const key = `${a.status ?? 'transport'}:${a.code || a.error || (a.success ? 'success' : 'unexpected')}`; + (attemptLatencies[key] ||= []).push(a.ms); + } + await eventLogger.flush(); + const summary = { runId, measurement, config: cfg, stopped, ...counters, loggingError: eventLogger.error ? safeError(eventLogger.error) : undefined, ledgerOperations: ledger.length, + successes: totals.success, safeRefusals: totals.safeRefusal, unknown: totals.unknown, failed: totals.failed, + errors, offersSeconds: began === undefined ? null : (offeredEnd - began) / 1000, + wallSeconds: began === undefined ? null : (performance.now() - began) / 1000, targetOfferedRate: cfg.rate, + actualOfferedRate: counters.offered / cfg.duration, sentOperationsRate: counters.sentOperations / cfg.duration, + completedRateDuringOfferWindow: counters.completedInOfferWindow / cfg.duration, successRateDuringOfferWindow: counters.successesInOfferWindow / cfg.duration, + latencyMs: stats(ledger.map(x => x.ms).filter(Number.isFinite)), successLatencyMs: stats(ledger.filter(x => x.outcome === 'success').map(x => x.ms)), + attemptLatencyMsByResult: Object.fromEntries(Object.entries(attemptLatencies).map(([key, values]) => [key, stats(values)])), + startDelayMs: stats(delays), sentStartDelayMs: stats(ledger.map(x => x.sendStartDelayMs).filter(Number.isFinite)), generator: { rssBytes: process.memoryUsage().rss, maxRssBytes: process.resourceUsage().maxRSS * 1024, + eventLoopLagMs: { mean: Number.isFinite(loop.mean) ? loop.mean / 1e6 : null, p99: loop.percentile(99) / 1e6, max: loop.max / 1e6 } }, + validation: { checked: validation.length, valid, invalid, integrityFailures }, cleanupPending: manifest.cleanupPending }; + await jsonFile('summary.json', summary); + if (invalid || integrityFailures || validation.length !== ledger.length || totals.unknown || totals.failed || manifest.cleanupPending || stopped) process.exitCode = 1; + } +} +try { + if (command === 'cleanup') { + if (!flags.manifest) throw new Error('cleanup requires --manifest'); + manifest = JSON.parse(await readFile(resolve(flags.manifest), 'utf8')); + if (manifest.version !== 1 || !/^aca-load-[0-9a-f-]{36}$/i.test(manifest.owner) || !/^aca-[a-z0-9-]+-$/.test(manifest.namePrefix) || !Array.isArray(manifest.sandboxes) || manifest.sandboxes.some(s => !/^[0-9a-f-]{36}$/i.test(s.id))) throw new Error('Invalid cleanup manifest'); + flags.app = manifest.app; flags.group = manifest.group; await authenticate(manifest.owner, manifest.tenant); await cleanup(true); + } else { + await mkdir(dirname(root), { recursive: true }); await mkdir(root); + await record({ kind: 'configuration', runId, command, app: flags.app, group: flags.group, config: cfg, + workload: 'one tenant, distinct owned sandboxes, durable append, no concurrent reuse of a sandbox', node: process.version }); + await prepareResources(); + if (command === 'load') await load(); + else if (command === 'inspect') await jsonFile('inspect.json', await armSnapshot()); + else { + if (flags['app-metrics']) await authenticate(`aca-observe-${randomUUID()}`, flags.tenant); + const until = Date.now() + cfg.duration * 1000; + do { await sample(flags['app-metrics']); if (Date.now() >= until || stopped) break; await sleep(Math.min(cfg.interval * 1000, until - Date.now())); } while (!stopped); + } + } + await eventLogger.flush(); + console.log(JSON.stringify({ evidence: root, loggingError: eventLogger.error ? safeError(eventLogger.error) : undefined, exitCode: process.exitCode || 0 })); +} catch (error) { + await record({ kind: 'fatal', ...safeError(error) }).catch(() => {}); + console.error(JSON.stringify({ error: 'Driver failed; inspect sanitized evidence', ...safeError(error), evidence: root })); process.exitCode = 1; +} diff --git a/scripts/verify/aca-load.test.mjs b/scripts/verify/aca-load.test.mjs new file mode 100644 index 00000000..427aaff9 --- /dev/null +++ b/scripts/verify/aca-load.test.mjs @@ -0,0 +1,141 @@ +import assert from "node:assert/strict"; +import { execFile } from "node:child_process"; +import { mkdtemp, readFile, rm } from "node:fs/promises"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { test } from "node:test"; +import { promisify } from "node:util"; +import { buildScript, markerIntegrity, outcomeTotals, overloadDelayMs, safeRetryAfter, validateOperation, visitConcurrent } from "./aca-load-workload.mjs"; +import { createEventLogger } from "./aca-load-logger.mjs"; + +const execute = promisify(execFile); +const operation = (outcome, attempts) => ({ id: 1, marker: "one", sandbox: "owned", outcome, attempts }); +const counts = (text) => { + const result = new Map(); + for (const line of text.split("\n").filter(Boolean)) result.set(line, (result.get(line) ?? 0) + 1); + return result; +}; + +test("load scripts preserve marker lines and catch broken newline escaping", async () => { + const directory = await mkdtemp(join(tmpdir(), "sqlfs-aca-script-")); + try { + const path = join(directory, "marker file's.txt"); + const config = { hold: 0, cpu: 3 }; + assert.equal((await execute("bash", ["-c", buildScript("first", config, path)])).stdout, "first"); + await execute("bash", ["-c", buildScript("second", config, path)]); + assert.equal(await readFile(path, "utf8"), "first\nsecond\n"); + const brokenPath = join(directory, "broken.txt"); + const script = buildScript("broken", config, brokenPath); + const broken = script.replace(String.raw`printf '%s\n'`, String.raw`printf '%s\\n'`); + assert.notEqual(broken, script); + await execute("bash", ["-c", broken]); + const content = await readFile(brokenPath, "utf8"); + assert.equal(content, String.raw`broken\n`); + const op = operation("success", [{ marker: "broken", success: true }]); + assert.equal(validateOperation(op, counts(content), true).valid, false); + assert.equal(markerIntegrity([op], counts(content)).valid, false); + } finally { + await rm(directory, { recursive: true, force: true }); + } +}); + +test("durable validation rejects missing, duplicate, unexpected and unreadable successes", () => { + const op = operation("success", [{ marker: "one", success: true }]); + assert.equal(validateOperation(op, counts("one\n"), true).valid, true); + assert.equal(validateOperation(op, new Map(), true).valid, false); + assert.equal(validateOperation(op, counts("one\none\n"), true).valid, false); + assert.equal(validateOperation(op, new Map(), false).valid, false); + assert.equal(markerIntegrity([op], counts("one\nunexpected\n")).valid, false); + assert.equal(markerIntegrity([op], counts("one\none\n")).valid, false); +}); + +test("a safe refusal never writes, including before a successful retry", () => { + const op = operation("success", [ + { marker: "busy", safeRefusal: true }, + { marker: "done", success: true }, + ]); + assert.equal(validateOperation(op, counts("done\n"), true).valid, true); + assert.equal(validateOperation(op, counts("busy\ndone\n"), true).valid, false); +}); + +test("observed markers do not turn unknown or incomplete outcomes into successes", () => { + const op = operation("unknown", [{ marker: "maybe" }]); + assert.equal(validateOperation(op, counts("maybe\n"), true).valid, null); + assert.deepEqual(outcomeTotals([op, { driverError: "interrupted" }]), { + success: 0, + safeRefusal: 0, + unknown: 2, + failed: 0, + }); +}); + +test("overload backoff grows within the client deadline and respects Retry-After", () => { + assert.deepEqual([0, 1, 2, 3, 4, 20].map((attempt) => overloadDelayMs("1", attempt)), [ + 1000, 2000, 4000, 8000, 10000, 10000, + ]); + assert.equal(overloadDelayMs(null, 0), 1000); + assert.equal(overloadDelayMs("", 0), 1000); + assert.equal(overloadDelayMs("not-a-date", 0), 1000); + assert.equal(overloadDelayMs("30", 0), 30000); + assert.equal(overloadDelayMs("Thu, 01 Jan 1970 00:00:30 GMT", 0, 0), 30000); + assert.equal(overloadDelayMs("Thu, 01 Jan 1970 00:00:01 GMT", 0, 30000), 1000); +}); + +test("Retry-After evidence preserves bounded HTTP dates", () => { + assert.equal(safeRetryAfter("Thu, 01 Jan 1970 00:00:30 GMT"), "Thu, 01 Jan 1970 00:00:30 GMT"); + assert.equal(safeRetryAfter("30"), "30"); + assert.equal(safeRetryAfter("not-a-date"), null); + assert.equal(safeRetryAfter("x".repeat(129)), null); +}); + +test("event logging recovers after an append failure and retains the first error", async () => { + const appendFailure = new Error("disk full"); + const writes = []; + const failures = []; + let appendCalls = 0; + const logger = createEventLogger(async (entry) => { + if (appendCalls++ === 0) throw appendFailure; + writes.push(entry); + }, (error) => failures.push(error)); + await logger.record("first"); + await logger.record("second"); + await logger.flush(); + assert.equal(logger.error, appendFailure); + assert.deepEqual(failures, [appendFailure]); + assert.deepEqual(writes, ["second"]); +}); + + +test("fixture workers bound concurrency and drain active calls before rejecting", async () => { + let active = 0, peak = 0, released = false; + const started = [], finished = []; + let release; + const barrier = new Promise(resolve => { release = resolve; }); + const failure = new Error("fixture creation failed"); + const work = visitConcurrent([0, 1, 2, 3, 4], 3, async item => { + started.push(item); peak = Math.max(peak, ++active); + try { + if (item === 1) throw failure; + await barrier; finished.push(item); + } finally { active--; } + }); + const rejected = assert.rejects(work, error => { + assert.equal(error, failure); assert.equal(released, true); assert.equal(active, 0); return true; + }); + await Promise.resolve(); + try { assert.deepEqual(started, [0, 1, 2]); assert.equal(peak, 2); } + finally { released = true; release(); } + await rejected; + assert.deepEqual(finished, [0, 2]); +}); + +test("fixture workers visit each item once at the requested bound", async () => { + let active = 0, peak = 0; + const visited = []; + await visitConcurrent(Array.from({ length: 11 }, (_, i) => i), 4, async item => { + peak = Math.max(peak, ++active); await new Promise(resolve => setTimeout(resolve, 1)); + visited.push(item); active--; + }); + assert.equal(peak, 4); assert.equal(active, 0); + assert.deepEqual(visited.sort((a, b) => a - b), Array.from({ length: 11 }, (_, i) => i)); +}); diff --git a/scripts/verify/container-api.mjs b/scripts/verify/container-api.mjs index 99963df9..301d50ca 100644 --- a/scripts/verify/container-api.mjs +++ b/scripts/verify/container-api.mjs @@ -6,7 +6,7 @@ import { promisify } from "node:util"; const execute = promisify(execFile); const applicationSetting = - /^(SQL_FS_|JUST_BASH_|MAX_|SCRIPT_TX_|REDIS_|AUTH_|ADMIN_|BOOTSTRAP_|TENANT_|DATABASE_|SESSION_|EXEC_|MCP_|PYTHON_|JS_|ENABLE_|EVENT_LOOP_|SKIP_STARTUP_|SDK_VERIFY_|INPUT_VERIFY_|SSE_FINALIZATION_|NODE_OPTIONS$|PORT$)/; + /^(SQL_FS_|JUST_BASH_|MAX_|SCRIPT_TX_|REDIS_|AUTH_|ADMIN_|BOOTSTRAP_|TENANT_|DATABASE_|SESSION_|EXEC_|MCP_|PYTHON_|JS_|ENABLE_|EVENT_LOOP_|SKIP_STARTUP_|SDK_VERIFY_|INPUT_VERIFY_|INGRESS_VERIFY_|SSE_FINALIZATION_|NODE_OPTIONS$|PORT$)/; export function startApiContainer(repo, name, env, evidence) { const image = process.env.VERIFY_CONTAINER_IMAGE; diff --git a/scripts/verify/ingress-faults.mjs b/scripts/verify/ingress-faults.mjs new file mode 100644 index 00000000..5672bd58 --- /dev/null +++ b/scripts/verify/ingress-faults.mjs @@ -0,0 +1,16 @@ +import { isMainThread } from "node:worker_threads"; + +if (isMainThread && process.env.INGRESS_VERIFY_DELETE_ID && process.env.INGRESS_VERIFY_BARRIER) { + const { SessionManager } = await import("../../dist/api/session-manager.js"); + const destroy = SessionManager.prototype.destroy; + SessionManager.prototype.destroy = async function (tenant, id) { + const found = await destroy.call(this, tenant, id); + if (id === process.env.INGRESS_VERIFY_DELETE_ID) { + const response = await fetch(`${process.env.INGRESS_VERIFY_BARRIER}/${id}`, { + signal: AbortSignal.timeout(10000), + }); + if (response.status !== 204) throw new Error("Ingress delete barrier failed"); + } + return found; + }; +} diff --git a/scripts/verify/ingress-queue.mjs b/scripts/verify/ingress-queue.mjs new file mode 100644 index 00000000..567b9795 --- /dev/null +++ b/scripts/verify/ingress-queue.mjs @@ -0,0 +1,236 @@ +#!/usr/bin/env node +import { once } from "node:events"; +import { createServer, request } from "node:http"; +import { performance } from "node:perf_hooks"; +import { delay, LocalApiRun, sha256 } from "./local-api.mjs"; + +const run = new LocalApiRun("ingress-queue"); +const trials = []; +const opened = new Set(); +let failure; + +function open(server, owner, method, path, bytes) { + let finish; + let status; + const done = new Promise((resolve) => { + finish = resolve; + }); + const wire = request( + new URL(path, server.base), + { + method, + agent: false, + headers: { + authorization: `Bearer ${owner.token}`, + "content-type": "application/octet-stream", + "content-length": String(bytes), + }, + }, + (response) => { + status = response.statusCode; + response.resume(); + response.once("end", () => finish()); + response.once("error", () => finish()); + }, + ); + wire.once("error", () => finish()); + wire.once("close", () => finish()); + wire.setTimeout(10000, () => wire.destroy()); + wire.flushHeaders(); + opened.add(wire); + return { + wire, + done, + get status() { + return status; + }, + async send(body, end = true) { + await new Promise((resolve, reject) => { + const callback = (error) => (error ? reject(error) : resolve()); + if (end) wire.end(body, callback); + else wire.write(body, callback); + }); + }, + async close() { + wire.destroy(); + await done; + opened.delete(wire); + }, + }; +} + +async function metrics(server, owner) { + const response = await run.request(server, owner, "GET", "/metrics"); + const values = Object.fromEntries( + response.body + .toString() + .split("\n") + .filter((line) => /^sql_fs_ingress_[a-z_]+ /.test(line)) + .map((line) => { + const [name, value] = line.split(" "); + return [name, Number(value)]; + }), + ); + return { + active: values.sql_fs_ingress_active_requests, + queued: values.sql_fs_ingress_queued_requests, + bytes: values.sql_fs_ingress_retained_raw_bytes, + aborted: values.sql_fs_ingress_aborted_total, + timeouts: values.sql_fs_ingress_queue_timeouts_total, + refused: values.sql_fs_ingress_refused_total, + }; +} + +async function until(server, owner, predicate, label) { + const deadline = performance.now() + 3000; + let sample; + do { + sample = await metrics(server, owner); + if (predicate(sample)) return sample; + await delay(20); + } while (performance.now() < deadline); + throw new Error(`${label}: ${JSON.stringify(sample)}`); +} + +async function lateDelete(peer, owner) { + const sandbox = await run.create(peer, owner); + const freshPeer = await run.start({ SQL_FS_WORKERS_ENABLED: "false" }); + let entered; + let barrierResponse; + let timer; + const arrived = new Promise((resolve) => { + entered = resolve; + }); + const barrier = createServer((incoming, outgoing) => { + if (incoming.url !== `/${sandbox.id}`) { + outgoing.writeHead(404).end(); + return; + } + barrierResponse = outgoing; + entered(); + }); + barrier.listen(0, "127.0.0.1"); + await once(barrier, "listening"); + let holder; + let target; + try { + const server = await run.start({ + SQL_FS_WORKERS_ENABLED: "true", + SQL_FS_MAX_INGRESS_REQUESTS: "3", + SQL_FS_MAX_INGRESS_TENANT_REQUESTS: "2", + SQL_FS_MAX_INGRESS_BYTES: "10", + SQL_FS_MAX_INGRESS_TENANT_BYTES: "9", + SQL_FS_MAX_INGRESS_WAIT_MS: "5000", + INGRESS_VERIFY_DELETE_ID: sandbox.id, + INGRESS_VERIFY_BARRIER: `http://127.0.0.1:${barrier.address().port}`, + NODE_OPTIONS: `${process.env.NODE_OPTIONS ?? ""} --import=./scripts/verify/ingress-faults.mjs`.trim(), + }); + holder = open(server, owner, "POST", "/v1/sandboxes", 9); + await holder.send(Buffer.from(" "), false); + await until(server, owner, (sample) => sample.active === 1 && sample.bytes === 8, "The holder retains eight bytes"); + target = open(server, owner, "DELETE", sandbox.path, 3); + await Promise.race([ + arrived, + new Promise((_, reject) => { + timer = setTimeout(() => reject(new Error("Durable DELETE did not reach the reply barrier")), 5000); + }), + ]); + clearTimeout(timer); + await run.request(freshPeer, owner, "GET", sandbox.path, { status: 404 }); + owner.sandboxes.delete(sandbox.id); + await target.send(Buffer.from("abc")); + await delay(100); + const during = await metrics(server, owner); + barrierResponse.writeHead(204).end(); + await target.done; + run.record({ case: "late-input-after-durable-delete", during, status: target.status }); + run.equal(target.status, 204, "Late ignored DELETE input does not replace a committed result with retryable busy"); + run.equal(during.refused, 0, "Ignored active input does not create a post-dispatch ingress refusal"); + await holder.close(); + await until( + server, + owner, + (sample) => sample.active === 0 && sample.queued === 0 && sample.bytes === 0, + "DELETE and holder release their ingress charges", + ); + } finally { + clearTimeout(timer); + barrierResponse?.end(); + await target?.close(); + await holder?.close(); + barrier.closeAllConnections(); + await new Promise((resolve, reject) => barrier.close((error) => (error ? reject(error) : resolve()))); + } +} + +try { + const server = await run.start({ + SQL_FS_WORKERS_ENABLED: "true", + SQL_FS_MAX_INGRESS_REQUESTS: "1", + SQL_FS_MAX_INGRESS_TENANT_REQUESTS: "1", + SQL_FS_MAX_INGRESS_QUEUED_REQUESTS: "4", + SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS: "3", + SQL_FS_MAX_INGRESS_BYTES: String(8 * 1024 * 1024), + SQL_FS_MAX_INGRESS_TENANT_BYTES: String(6 * 1024 * 1024), + SQL_FS_MAX_INGRESS_WAIT_MS: "5000", + }); + const owner = await run.owner(); + const sandbox = await run.create(server, owner); + const bytes = Buffer.alloc(1024 * 1024, 0x71); + const positive = `${sandbox.path}/files/home/user/positive`; + await run.request(server, owner, "PUT", positive, { raw: bytes, status: 204 }); + run.equal( + sha256((await run.request(server, owner, "GET", positive)).body), + sha256(bytes), + "The live upload control stores all 1 MiB exactly", + ); + for (let round = 0; round < 5; round++) { + const trial = { round }; + trials.push(trial); + const holder = open(server, owner, "POST", "/v1/sandboxes", 2 * 1024 * 1024); + let target; + try { + await holder.send(Buffer.from(" "), false); + await until(server, owner, (sample) => sample.active === 1 && sample.bytes === 1, "Incomplete body holds ingress"); + const path = `${sandbox.path}/files/home/user/abandoned-${round}`; + target = open(server, owner, "PUT", path, bytes.length); + [trial.before] = await Promise.all([ + until( + server, + owner, + (sample) => sample.active === 1 && sample.queued === 1, + "The fully offered upload waits for ingress", + ), + target.send(bytes), + ]); + run.equal(target.status, undefined, "The target has no response before abandonment"); + await target.close(); + await delay(500); + trial.afterAbort = await metrics(server, owner); + run.equal(holder.status, undefined, "The holder still prevents target admission after abandonment"); + await holder.close(); + trial.settled = await until( + server, + owner, + (sample) => sample.active === 0 && sample.queued === 0 && sample.bytes === 0, + "Cancelled upload and holder release every ingress charge", + ); + const durable = await run.request(server, owner, "GET", path, { status: null }); + trial.readStatus = durable.status; + run.record({ case: "abandoned-queued-upload", ...trial }); + run.equal(durable.status, 404, "An upload abandoned while queued never becomes a durable file"); + run.equal(trial.afterAbort.queued, 0, "Disconnect removes the upload before the active holder releases"); + run.equal(trial.afterAbort.aborted - trial.before.aborted, 1, "The queued disconnect is observed exactly once"); + run.equal(trial.afterAbort.timeouts, trial.before.timeouts, "Cancellation is observed without a queue timeout"); + } finally { + await target?.close(); + await holder.close(); + } + } + await lateDelete(server, owner); +} catch (error) { + failure = error; +} finally { + for (const wire of opened) wire.destroy(); + await run.finish(failure, { trials }); +} diff --git a/src/api/ingress-admission.ts b/src/api/ingress-admission.ts index 96cb9899..9e5629a3 100644 --- a/src/api/ingress-admission.ts +++ b/src/api/ingress-admission.ts @@ -10,6 +10,12 @@ interface IngressRetention { readonly hold: () => () => void; } +type IngressFailure = + | { readonly kind: "busy" | "too_large" | "aborted" | "shutdown" } + | { readonly kind: "input_error"; readonly error: unknown }; + +type InputDemand = { readonly kind: "queued" | "idle" } | { readonly kind: "pull"; readonly resolve: () => void }; + const ingressRetention = new AsyncLocalStorage(); export function retainIngressWork( @@ -28,6 +34,8 @@ export function retainIngressWork( export interface IngressOptions { readonly maxRequests: number; readonly maxTenantRequests: number; + readonly maxQueuedRequests?: number; + readonly maxTenantQueuedRequests?: number; readonly maxMcpListeners?: number; readonly maxTenantMcpListeners?: number; readonly maxBytes: number; @@ -37,10 +45,12 @@ export interface IngressOptions { } export function loadIngressOptions(env: NodeJS.ProcessEnv = process.env): IngressOptions { - const read = (name: string, fallback: number): number => { + const read = (name: string, fallback: number, minimum = 1): number => { const raw = env[name]; const value = raw === undefined || raw === "" ? fallback : Number(raw); - if (!Number.isSafeInteger(value) || value <= 0) throw new Error(`${name} must be a positive safe integer`); + if (!Number.isSafeInteger(value) || value < minimum) { + throw new Error(`${name} must be a ${minimum === 0 ? "nonnegative" : "positive"} safe integer`); + } return value; }; const maxRequests = read("SQL_FS_MAX_INGRESS_REQUESTS", 8); @@ -48,6 +58,16 @@ export function loadIngressOptions(env: NodeJS.ProcessEnv = process.env): Ingres if (maxTenantRequests > Math.max(1, maxRequests - 1)) { throw new Error("SQL_FS_MAX_INGRESS_TENANT_REQUESTS must leave capacity for another tenant"); } + const maxQueuedRequests = read("SQL_FS_MAX_INGRESS_QUEUED_REQUESTS", maxRequests, 0); + const tenantQueueShare = maxQueuedRequests > 1 ? maxQueuedRequests - 1 : maxQueuedRequests; + const maxTenantQueuedRequests = read( + "SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS", + Math.min(maxTenantRequests, tenantQueueShare), + 0, + ); + if (maxTenantQueuedRequests > tenantQueueShare) { + throw new Error("SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS must leave capacity for another tenant"); + } const maxMcpListeners = read("SQL_FS_MAX_INGRESS_MCP_LISTENERS", maxRequests); const maxTenantMcpListeners = read( "SQL_FS_MAX_INGRESS_TENANT_MCP_LISTENERS", @@ -64,6 +84,8 @@ export function loadIngressOptions(env: NodeJS.ProcessEnv = process.env): Ingres return { maxRequests, maxTenantRequests, + maxQueuedRequests, + maxTenantQueuedRequests, maxMcpListeners, maxTenantMcpListeners, maxBytes, @@ -85,11 +107,14 @@ export class IngressAdmission { private aborted = 0; constructor(private readonly options: IngressOptions) { + const maxQueued = options.maxQueuedRequests ?? options.maxRequests; this.admission = new FairAdmission({ capacity: options.maxRequests, maxActivePerTenant: options.maxTenantRequests, - maxQueued: options.maxRequests, - maxQueuedPerTenant: options.maxTenantRequests, + maxQueued, + maxQueuedPerTenant: + options.maxTenantQueuedRequests ?? + Math.min(options.maxTenantRequests, maxQueued > 1 ? maxQueued - 1 : maxQueued), maxQueuedBytes: 0, maxQueuedBytesPerTenant: 0, waitMs: options.waitMs, @@ -115,8 +140,18 @@ export class IngressAdmission { const admission = this.admission.metrics; const mcpListeners = this.mcpListenerAdmission.metrics; return { + requestCapacity: this.options.maxRequests, + queueCapacity: this.options.maxQueuedRequests ?? this.options.maxRequests, + rawByteCapacity: this.options.maxBytes, + queueWaitLimitMs: this.options.waitMs, activeRequests: admission.active, queuedRequests: admission.queued, + offered: admission.offered, + admitted: admission.admitted, + completed: admission.completed, + cancelled: admission.cancelled, + totalWaitMs: admission.totalWaitMs, + waitBuckets: admission.waitBuckets, queueTimeouts: admission.timedOut, activeMcpListeners: mcpListeners.active, queuedMcpListeners: mcpListeners.queued, @@ -179,39 +214,77 @@ export class IngressAdmission { } const signal = c.req.raw.signal; + const cancellation = new AbortController(); const key = typeof tenant === "string" ? `tenant:${tenant}` : "bootstrap"; - let releaseAdmission: () => void; - try { - releaseAdmission = await admission.acquire(key, key, 0, signal, true); - } catch (error) { - void body?.cancel().catch(() => {}); - if (signal.aborted) { - this.aborted++; - return new Response(null, { status: 499 }); - } - if (this.closed) return busy("ESHUTTINGDOWN"); - if (error instanceof WorkerBusyError) return busy(); - throw error; - } + let releaseAdmission: (() => void) | undefined; let reader: ReadableStreamDefaultReader | undefined; + let inputController: ReadableStreamDefaultController | undefined; let retained = 0; - let failure: "busy" | "too_large" | "aborted" | undefined; + let failure: IngressFailure | undefined; let ended = false; - let onAbort: (() => void) | undefined; + let demand: InputDemand = { kind: "idle" }; + let wakeInput: (() => void) | undefined; let abortOutput: (() => void) | undefined; + const hasDemand = () => demand.kind !== "idle"; + const waitForInput = () => + new Promise((resolve) => { + wakeInput = resolve; + }); + const finishPull = () => { + if (demand.kind !== "pull") return; + const { resolve } = demand; + demand = { kind: "idle" }; + resolve(); + }; const cancel = () => { + ended = true; + finishPull(); + wakeInput?.(); + wakeInput = undefined; void (reader === undefined ? body?.cancel() : reader.cancel())?.catch(() => {}); }; + const fail = (cause: IngressFailure) => { + if (failure !== undefined) return; + failure = cause; + if (cause.kind === "aborted") this.aborted++; + if (cause.kind === "too_large") this.payloadTooLarge++; + ended = true; + inputController?.error( + cause.kind === "input_error" ? cause.error : new DOMException("Request input stopped", "AbortError"), + ); + cancellation.abort(); + cancel(); + if (cause.kind === "aborted") abortOutput?.(); + }; + const failureResponse = (propagateInputError = true) => { + switch (failure?.kind) { + case "busy": + return busy(); + case "shutdown": + return busy("ESHUTTINGDOWN"); + case "too_large": + return tooLarge(); + case "aborted": + return new Response(null, { status: 499 }); + case "input_error": + if (propagateInputError) throw failure.error; + return undefined; + default: + return undefined; + } + }; + const onAbort = () => fail({ kind: "aborted" }); let references = 1; const release = () => { if (--references !== 0) return; - if (onAbort !== undefined) signal.removeEventListener("abort", onAbort); + signal.removeEventListener("abort", onAbort); + inputController?.error(new DOMException("Request already completed", "AbortError")); cancel(); this.retainedRawBytes -= retained; const remainingBytes = (this.tenantBytes.get(tenant) ?? 0) - retained; if (remainingBytes === 0) this.tenantBytes.delete(tenant); else this.tenantBytes.set(tenant, remainingBytes); - releaseAdmission(); + releaseAdmission?.(); }; const hold = () => { if (references === 0) throw new DOMException("Request already completed", "AbortError"); @@ -223,12 +296,94 @@ export class IngressAdmission { release(); }; }; + const startInput = () => { + if (body === null || reader !== undefined || ended) return; + const bodyReader = body.getReader(); + reader = bodyReader; + const counted = new ReadableStream( + { + start(controller) { + inputController = controller; + }, + pull() { + if (ended) return; + return new Promise((resolve) => { + demand = { kind: "pull", resolve }; + wakeInput?.(); + wakeInput = undefined; + }); + }, + cancel, + }, + { highWaterMark: 0 }, + ); + c.req.raw = new Request(c.req.raw, { + body: counted, + signal: cancellation.signal, + duplex: "half", + } as RequestInit); + const pump = async () => { + try { + while (!ended) { + while (!ended && !hasDemand()) await waitForInput(); + if (ended) return; + const { done, value } = await bodyReader.read(); + while (!ended && !hasDemand()) await waitForInput(); + if (ended) return; + if (done) { + ended = true; + inputController?.close(); + finishPull(); + return; + } + if (value.byteLength > bodyLimit - retained) { + fail({ kind: "too_large" }); + return; + } + if ( + value.byteLength > this.options.maxBytes - this.retainedRawBytes || + value.byteLength > this.options.maxTenantBytes - (this.tenantBytes.get(tenant) ?? 0) + ) { + this.refused++; + fail({ kind: "busy" }); + return; + } + retained += value.byteLength; + this.retainedRawBytes += value.byteLength; + this.tenantBytes.set(tenant, (this.tenantBytes.get(tenant) ?? 0) + value.byteLength); + inputController?.enqueue(value); + finishPull(); + } + } catch (error) { + while (!ended && !hasDemand()) await waitForInput(); + if (!ended) fail({ kind: "input_error", error }); + } + }; + void pump(); + }; try { - if (signal.aborted) { - this.aborted++; - return new Response(null, { status: 499 }); + signal.addEventListener("abort", onAbort, { once: true }); + if (signal.aborted) onAbort(); + try { + releaseAdmission = await admission.acquire(key, key, 0, cancellation.signal, true, () => { + demand = { kind: "queued" }; + startInput(); + }); + demand = { kind: "idle" }; + } catch (error) { + if (failure === undefined) { + if (this.closed) fail({ kind: "shutdown" }); + else if (error instanceof WorkerBusyError) fail({ kind: "busy" }); + else fail({ kind: "input_error", error }); + } + return failureResponse(); } - if (this.closed) return busy("ESHUTTINGDOWN"); + if (this.closed) fail({ kind: "shutdown" }); + const rejected = failureResponse(); + if (rejected !== undefined) return rejected; + startInput(); + const inputFailure = failureResponse(); + if (inputFailure !== undefined) return inputFailure; const outgoing: unknown = c.env?.outgoing; const nodeResponse = outgoing instanceof ServerResponse || outgoing instanceof Http2ServerResponse ? outgoing : undefined; @@ -245,77 +400,9 @@ export class IngressAdmission { nodeResponse.once("error", finish); if (nodeResponse.destroyed || nodeResponse.closed || nodeResponse.writableFinished) finish(); } - let inputController: ReadableStreamDefaultController | undefined; - onAbort = () => { - if (failure === "aborted") return; - failure = "aborted"; - this.aborted++; - if (!ended) { - ended = true; - inputController?.error(new DOMException("Request aborted", "AbortError")); - } - cancel(); - abortOutput?.(); - }; - signal.addEventListener("abort", onAbort, { once: true }); - if (body !== null) { - const bodyReader = body.getReader(); - reader = bodyReader; - const counted = new ReadableStream( - { - start(controller) { - inputController = controller; - }, - pull: async (controller) => { - try { - const { done, value } = await bodyReader.read(); - if (ended) return; - if (done) { - ended = true; - controller.close(); - return; - } - if (value.byteLength > bodyLimit - retained) { - failure = "too_large"; - this.payloadTooLarge++; - } else if ( - value.byteLength > this.options.maxBytes - this.retainedRawBytes || - value.byteLength > this.options.maxTenantBytes - (this.tenantBytes.get(tenant) ?? 0) - ) { - failure = "busy"; - this.refused++; - } else { - retained += value.byteLength; - this.retainedRawBytes += value.byteLength; - this.tenantBytes.set(tenant, (this.tenantBytes.get(tenant) ?? 0) + value.byteLength); - controller.enqueue(value); - return; - } - ended = true; - controller.error(new Error("Request body capacity exceeded")); - cancel(); - } catch (error) { - ended = true; - controller.error(error); - } - }, - cancel() { - ended = true; - cancel(); - }, - }, - { highWaterMark: 0 }, - ); - c.req.raw = new Request(c.req.raw, { body: counted, duplex: "half" } as RequestInit); - } - if (signal.aborted) { - onAbort(); - return new Response(null, { status: 499 }); - } await ingressRetention.run({ hold }, next); - if (failure === "busy") c.res = busy(); - if (failure === "too_large") c.res = tooLarge(); - if (failure === "aborted") c.res = new Response(null, { status: 499 }); + const failed = failureResponse(false); + if (failed !== undefined) c.res = failed; if (c.req.method === "HEAD") { void c.res.body?.cancel().catch(() => {}); } else if (nodeResponse === undefined && c.res.body !== null) { diff --git a/src/api/migrations.ts b/src/api/migrations.ts index 2ce2c78a..15aacc7f 100644 --- a/src/api/migrations.ts +++ b/src/api/migrations.ts @@ -1,14 +1,14 @@ /** * Startup migration runner. * - * Applies every .sql file under src/sql-fs/migrations/postgres/ (lexicographic - * order) to each configured tenant database in ONE transaction. Migrations are - * idempotent (CREATE TABLE IF NOT EXISTS / CREATE OR REPLACE FUNCTION), so - * rerunning on a migrated database is a no-op. + * Applies pending .sql files under src/sql-fs/migrations/postgres/ in filename + * order to each configured tenant database in one transaction. The migration + * ledger records checksums so unchanged replica boots do not repeat table DDL. * * Fails closed: the first tenant error aborts the boot with a clear log line. */ +import { createHash } from "node:crypto"; import { readdirSync, readFileSync } from "node:fs"; import { join } from "node:path"; import { fileURLToPath } from "node:url"; @@ -23,12 +23,21 @@ import type { TenantConfig } from "./tenants.js"; */ const MIGRATION_LOCK_KEY = 7_263_001_954_120_388n; -function migrationFiles(): readonly string[] { +interface Migration { + readonly file: string; + readonly body: string; + readonly sha256: string; +} + +function migrationFiles(): readonly Migration[] { const dir = fileURLToPath(new URL("../sql-fs/migrations/postgres/", import.meta.url)); return readdirSync(dir) .filter((name) => name.endsWith(".sql")) .sort() - .map((name) => join(dir, name)); + .map((file) => { + const body = readFileSync(join(dir, file)); + return { file, body: body.toString("utf8"), sha256: createHash("sha256").update(body).digest("hex") }; + }); } /** @@ -55,24 +64,48 @@ export async function runMigrations(tenantConfig: TenantConfig): Promise { const url = tenantConfig.getConnectionString(tenantId); const sql = postgres(url, { prepare: false, max: 1 }); try { - await sql.begin(async (tx) => { - // Audit M4: serialize concurrent multi-replica boots. Without this, two - // replicas can run the same DDL at once and crash-loop / race. The - // second booter waits here for the first to commit (the migrations are - // idempotent, so it then re-applies cleanly). + const appliedCount = await sql.begin(async (tx) => { // Inlined constant (not user input) — pg_advisory_xact_lock takes a // bigint literal; the tagged-template param path binds bigints as text. await tx.unsafe(`SELECT pg_advisory_xact_lock(${MIGRATION_LOCK_KEY})`); - for (const path of files) { - const body = readFileSync(path, "utf8"); - const file = path.split(/[/\\]/).pop() ?? path; + await tx` + CREATE TABLE IF NOT EXISTS public.sql_fs_migrations ( + filename TEXT PRIMARY KEY, + sha256 TEXT NOT NULL, + applied_at TIMESTAMPTZ NOT NULL DEFAULT now() + ) + `; + const rows = await tx<{ filename: string; sha256: string }[]>` + SELECT filename, sha256 FROM public.sql_fs_migrations + `; + const applied = new Map(rows.map((row) => [row.filename, row.sha256])); + for (const { file, sha256 } of files) { + const recorded = applied.get(file); + if (recorded !== undefined && recorded !== sha256) { + throw new Error(`Checksum mismatch for applied migration "${file}"; add a new migration instead`); + } + } + const pending = files.filter(({ file }) => !applied.has(file)); + for (const { file, body, sha256 } of pending) { console.log(JSON.stringify({ event: "migration_start", tenantId, file })); await tx.unsafe(body); + await tx` + INSERT INTO public.sql_fs_migrations (filename, sha256) VALUES (${file}, ${sha256}) + `; // Applied, not yet durable — a later file can still roll the whole run back. console.log(JSON.stringify({ event: "migration_ok", tenantId, file })); } + return pending.length; }); - console.log(JSON.stringify({ event: "migrations_committed", tenantId, files: files.length })); + console.log( + JSON.stringify({ + event: "migrations_committed", + tenantId, + files: files.length, + applied: appliedCount, + skipped: files.length - appliedCount, + }), + ); } catch (err) { const message = err instanceof Error ? err.message : String(err); console.error(JSON.stringify({ event: "migration_failed", tenantId, error: message })); diff --git a/src/api/routes/sandboxes.ts b/src/api/routes/sandboxes.ts index 4b069f39..3e606cd0 100644 --- a/src/api/routes/sandboxes.ts +++ b/src/api/routes/sandboxes.ts @@ -17,8 +17,8 @@ import { workerRequestContext } from "../worker-owner/request-context.js"; const createBodySchema = z.object({ name: z.string().max(255).optional(), - env: z.record(z.string()).optional(), - files: z.record(z.string()).optional(), + env: z.record(z.string(), z.string()).optional(), + files: z.record(z.string(), z.string()).optional(), python: z.boolean().optional(), javascript: z.boolean().optional(), /** When true, js-exec fetch() is granted unrestricted outbound HTTPS access. */ diff --git a/src/api/tests/integration/migrations.integration.test.ts b/src/api/tests/integration/migrations.integration.test.ts index b828089d..4b78731d 100644 --- a/src/api/tests/integration/migrations.integration.test.ts +++ b/src/api/tests/integration/migrations.integration.test.ts @@ -5,13 +5,26 @@ * does not drop tables on a shared dev database. Skips when DATABASE_URL is unset. */ -import { randomBytes } from "node:crypto"; +import { createHash, randomBytes } from "node:crypto"; +import { readdirSync, readFileSync } from "node:fs"; +import { join } from "node:path"; +import { fileURLToPath } from "node:url"; import postgres from "postgres"; import { afterAll, beforeAll, describe, expect, it } from "vitest"; import { runMigrations } from "../../migrations.js"; import { loadTenantConfig } from "../../tenants.js"; const SKIP = !process.env.DATABASE_URL; +const MIGRATION_DIR = fileURLToPath(new URL("../../../sql-fs/migrations/postgres/", import.meta.url)); +const MIGRATION_FILES = readdirSync(MIGRATION_DIR) + .filter((file) => file.endsWith(".sql")) + .sort(); + +async function migrationLedger(sql: postgres.Sql): Promise<{ filename: string; sha256: string; applied_at: string }[]> { + return sql<{ filename: string; sha256: string; applied_at: string }[]>` + SELECT filename, sha256, applied_at::text FROM public.sql_fs_migrations ORDER BY filename + `; +} function withDatabase(connectionString: string, database: string): string { const u = new URL(connectionString); @@ -165,6 +178,170 @@ describe.skipIf(SKIP)("runMigrations (integration)", () => { } }, 60_000); + it("records each file checksum and preserves history for each tenant on later boots", async () => { + const urls = [await createScratchDb(), await createScratchDb()]; + const cfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ first: urls[0], second: urls[1] }) }); + await runMigrations(cfg); + for (const url of urls) { + const sql = postgres(url, { prepare: false, max: 1 }); + try { + const before = await migrationLedger(sql); + expect(before.map(({ filename, sha256 }) => ({ filename, sha256 }))).toEqual( + MIGRATION_FILES.map((filename) => ({ + filename, + sha256: createHash("sha256") + .update(readFileSync(join(MIGRATION_DIR, filename))) + .digest("hex"), + })), + ); + expect(before.every(({ applied_at }) => Number.isFinite(Date.parse(applied_at)))).toBe(true); + await runMigrations(cfg); + expect(await migrationLedger(sql)).toEqual(before); + } finally { + await sql.end({ timeout: 5 }); + } + } + }); + + it("bootstraps migration history for a legacy database", async () => { + const url = await createScratchDb(); + const sql = postgres(url, { prepare: false, max: 1 }); + try { + await sql.begin(async (tx) => { + for (const file of MIGRATION_FILES) { + await tx.unsafe(readFileSync(join(MIGRATION_DIR, file), "utf8")); + } + }); + const before = await sql<{ ledger: string | null }[]>` + SELECT to_regclass('public.sql_fs_migrations')::text AS ledger + `; + expect(before).toEqual([{ ledger: null }]); + const cfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: url }) }); + await runMigrations(cfg); + expect((await migrationLedger(sql)).map(({ filename }) => filename)).toEqual(MIGRATION_FILES); + } finally { + await sql.end({ timeout: 5 }); + } + }); + + it("rejects changed applied checksums before executing pending migrations", async () => { + const url = await createScratchDb(); + const cfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: url }) }); + await runMigrations(cfg); + const sql = postgres(url, { prepare: false, max: 1 }); + try { + const removedMigration = "0008_resolve_relative_symlinks.sql"; + await sql`UPDATE public.sql_fs_migrations SET sha256 = ${"0".repeat(64)} WHERE filename = '0000_create_tables.sql'`; + await sql`DELETE FROM public.sql_fs_migrations WHERE filename = ${removedMigration}`; + await sql`DROP FUNCTION fs_resolve_internal(text, boolean, integer)`; + await expect(runMigrations(cfg)).rejects.toThrow(/Checksum mismatch.*0000_create_tables.sql/); + const after = await sql<{ resolver: string | null }[]>` + SELECT to_regprocedure('fs_resolve_internal(text,boolean,integer)')::text AS resolver + `; + expect(after).toEqual([{ resolver: null }]); + expect((await migrationLedger(sql)).map(({ filename }) => filename)).toEqual( + MIGRATION_FILES.filter((filename) => filename !== removedMigration), + ); + } finally { + await sql.end({ timeout: 5 }); + } + }); + + it("preserves unknown newer migration history", async () => { + const url = await createScratchDb(); + const cfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: url }) }); + await runMigrations(cfg); + const sql = postgres(url, { prepare: false, max: 1 }); + try { + await sql` + INSERT INTO public.sql_fs_migrations (filename, sha256) + VALUES ('9999_newer_image.sql', ${"1".repeat(64)}) + `; + const before = await migrationLedger(sql); + await runMigrations(cfg); + expect(await migrationLedger(sql)).toEqual(before); + } finally { + await sql.end({ timeout: 5 }); + } + }); + + it("rolls back pending DDL and ledger entries together after a later failure", async () => { + const url = await createScratchDb(); + const cfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: url }) }); + await runMigrations(cfg); + const sql = postgres(url, { prepare: false, max: 1 }); + try { + await sql`DELETE FROM public.sql_fs_migrations WHERE filename >= '0007_fence_sandbox_epochs.sql'`; + await sql`DROP TABLE sandbox_epochs`; + await sql`ALTER TABLE sandboxes DROP COLUMN version`; + await sql`DROP FUNCTION fs_resolve_internal(text, boolean, integer)`; + await sql`CREATE FUNCTION fs_resolve_internal(text, boolean, integer) RETURNS text LANGUAGE sql AS 'SELECT NULL::text'`; + const before = await migrationLedger(sql); + await expect(runMigrations(cfg)).rejects.toThrow(/cannot change return type of existing function/); + expect(await migrationLedger(sql)).toEqual(before); + const rolledBack = await sql<{ epochs: string | null; has_version: boolean }[]>` + SELECT to_regclass('public.sandbox_epochs')::text AS epochs, + EXISTS ( + SELECT 1 FROM information_schema.columns + WHERE table_schema = 'public' AND table_name = 'sandboxes' AND column_name = 'version' + ) AS has_version + `; + expect(rolledBack).toEqual([{ epochs: null, has_version: false }]); + await sql`DROP FUNCTION fs_resolve_internal(text, boolean, integer)`; + await runMigrations(cfg); + const after = await migrationLedger(sql); + expect(after.slice(0, before.length)).toEqual(before); + expect(after.map(({ filename }) => filename)).toEqual(MIGRATION_FILES); + const applied = await sql<{ epochs: string | null; has_version: boolean }[]>` + SELECT to_regclass('public.sandbox_epochs')::text AS epochs, + EXISTS ( + SELECT 1 FROM information_schema.columns + WHERE table_schema = 'public' AND table_name = 'sandboxes' AND column_name = 'version' + ) AS has_version + `; + expect(applied).toEqual([{ epochs: "sandbox_epochs", has_version: true }]); + } finally { + await sql.end({ timeout: 5 }); + } + }); + + it("boots a migrated database while live writers hold filesystem table locks", async () => { + const url = await createScratchDb(); + const cfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: url }) }); + await runMigrations(cfg); + const bootUrl = new URL(url); + bootUrl.searchParams.set("options", "-c lock_timeout=2s"); + const bootCfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: bootUrl.toString() }) }); + const writer = postgres(url, { prepare: false, max: 1 }); + try { + await writer.begin(async (tx) => { + await tx`LOCK TABLE sandboxes, inodes, dirents, blobs IN ROW EXCLUSIVE MODE`; + await expect(runMigrations(bootCfg)).resolves.toBeUndefined(); + }); + } finally { + await writer.end({ timeout: 5 }); + } + }); + + it("concurrent cold boots skip DDL while filesystem table locks are held", async () => { + const url = await createScratchDb(); + const cfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: url }) }); + await runMigrations(cfg); + const bootUrl = new URL(url); + bootUrl.searchParams.set("options", "-c lock_timeout=2s"); + const bootCfg = loadTenantConfig({ TENANT_DATABASES: JSON.stringify({ default: bootUrl.toString() }) }); + const writer = postgres(url, { prepare: false, max: 1 }); + try { + await writer.begin(async (tx) => { + await tx`LOCK TABLE sandboxes, inodes, dirents, blobs IN ROW EXCLUSIVE MODE`; + const boots = await Promise.allSettled(Array.from({ length: 4 }, () => runMigrations(bootCfg))); + expect(boots).toEqual(Array.from({ length: 4 }, () => ({ status: "fulfilled", value: undefined }))); + }); + } finally { + await writer.end({ timeout: 5 }); + } + }); + /** * #164: the whole run must be one transaction, because that is what lets the * advisory lock be transaction-scoped and therefore survive a transaction diff --git a/src/api/tests/unit/ingress-admission.test.ts b/src/api/tests/unit/ingress-admission.test.ts index 58c7ddab..40788eeb 100644 --- a/src/api/tests/unit/ingress-admission.test.ts +++ b/src/api/tests/unit/ingress-admission.test.ts @@ -76,6 +76,8 @@ describe("ingress configuration", () => { expect(loadIngressOptions({})).toEqual({ maxRequests: 8, maxTenantRequests: 4, + maxQueuedRequests: 8, + maxTenantQueuedRequests: 4, maxMcpListeners: 8, maxTenantMcpListeners: 4, maxBytes: 128 * 1024 * 1024, @@ -102,6 +104,42 @@ describe("ingress configuration", () => { }); describe("HTTP body admission", () => { + it("preserves a successful route response after it handles a body input error", async () => { + const { app, ingress } = setup(); + let mutationCompleted = false; + app.post("/handled-input-error", async (c) => { + const reader = c.req.raw.body?.getReader(); + if (reader === undefined) throw new Error("Expected a request body"); + await reader.read(); + try { + await reader.read(); + } catch { + mutationCompleted = true; + } + return c.text("committed", 201); + }); + let reads = 0; + const body = new ReadableStream( + { + pull(controller) { + if (reads++ === 0) controller.enqueue(new TextEncoder().encode("partial")); + else controller.error(new Error("input stream failed")); + }, + }, + { highWaterMark: 0 }, + ); + try { + const response = await app.fetch( + new Request("http://localhost/handled-input-error", { method: "POST", body, duplex: "half" } as RequestInit), + ); + expect(mutationCompleted).toBe(true); + expect(response.status).toBe(201); + expect(await response.text()).toBe("committed"); + } finally { + ingress.close(); + } + }); + it("rejects excess request count without reading the rejected body", async () => { const { app, ingress } = setup(1); const hold = deferred(); @@ -120,6 +158,8 @@ describe("HTTP body admission", () => { }); const first = app.request("/hold", { method: "POST", body: "retained" }); await entered.promise; + const queued = app.request("/write", { method: "PUT", body: "queued" }); + await expect.poll(() => ingress.metrics.queuedRequests).toBe(1); let reads = 0; let cancelled = false; const stream = new ReadableStream( @@ -148,10 +188,17 @@ describe("HTTP body admission", () => { expect(reads).toBe(0); expect(cancelled).toBe(true); expect(writes).toBe(0); - expect(ingress.metrics).toMatchObject({ activeRequests: 1, retainedRawBytes: 8, refused: 1 }); + expect(ingress.metrics).toMatchObject({ + activeRequests: 1, + queuedRequests: 1, + retainedRawBytes: 14, + refused: 1, + queueTimeouts: 0, + }); } finally { hold.resolve(); await (await first).arrayBuffer(); + await (await queued).arrayBuffer(); } expect(ingress.metrics).toMatchObject({ activeRequests: 0, retainedRawBytes: 0 }); }); diff --git a/src/api/tests/unit/ingress-metrics.test.ts b/src/api/tests/unit/ingress-metrics.test.ts new file mode 100644 index 00000000..907501cb --- /dev/null +++ b/src/api/tests/unit/ingress-metrics.test.ts @@ -0,0 +1,66 @@ +import { Hono } from "hono"; +import { describe, expect, it, vi } from "vitest"; +import type { AuthVariables } from "../../auth.js"; +import { IngressAdmission, loadIngressOptions } from "../../ingress-admission.js"; +import { renderWorkerMetrics } from "../../worker-owner/metrics.js"; + +describe("ingress metrics", () => { + it("exports configured capacity and cumulative queue waits beyond one second", async () => { + vi.useFakeTimers(); + const ingress = new IngressAdmission( + loadIngressOptions({ + SQL_FS_MAX_INGRESS_REQUESTS: "1", + SQL_FS_MAX_INGRESS_TENANT_REQUESTS: "1", + SQL_FS_MAX_INGRESS_QUEUED_REQUESTS: "4", + SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS: "3", + SQL_FS_MAX_INGRESS_WAIT_MS: "5000", + }), + ); + const app = new Hono<{ Variables: AuthVariables }>(); + let release = () => {}; + const held = new Promise((resolve) => { + release = resolve; + }); + app.use("*", (c, next) => { + c.set("tenant", "one"); + return ingress.middleware(c, next); + }); + app.get("/hold", async (c) => { + await held; + return c.text("done"); + }); + app.get("/queued", (c) => c.text("done")); + const active = app.request("/hold"); + const queued = app.request("/queued"); + try { + await vi.advanceTimersByTimeAsync(2000); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1 }); + release(); + await (await active).text(); + await (await queued).text(); + const metrics = renderWorkerMetrics(undefined, ingress.metrics); + for (const line of [ + "sql_fs_ingress_request_capacity 1", + "sql_fs_ingress_queue_capacity 4", + "sql_fs_ingress_raw_byte_capacity 134217728", + "sql_fs_ingress_queue_wait_limit_milliseconds 5000", + "sql_fs_ingress_offered_total 2", + "sql_fs_ingress_admitted_total 2", + "sql_fs_ingress_completed_total 2", + "sql_fs_ingress_cancelled_total 0", + 'sql_fs_ingress_queue_wait_milliseconds_bucket{le="1000"} 1', + 'sql_fs_ingress_queue_wait_milliseconds_bucket{le="2500"} 2', + 'sql_fs_ingress_queue_wait_milliseconds_bucket{le="+Inf"} 2', + "sql_fs_ingress_queue_wait_milliseconds_sum 2000", + "sql_fs_ingress_queue_wait_milliseconds_count 2", + ]) { + expect(metrics.split("\n")).toContain(line); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0 }); + } finally { + release(); + ingress.close(); + vi.useRealTimers(); + } + }); +}); diff --git a/src/api/tests/unit/ingress-outcome.test.ts b/src/api/tests/unit/ingress-outcome.test.ts new file mode 100644 index 00000000..a0863541 --- /dev/null +++ b/src/api/tests/unit/ingress-outcome.test.ts @@ -0,0 +1,185 @@ +import { Hono } from "hono"; +import { InMemoryFs } from "just-bash"; +import { describe, expect, it, vi } from "vitest"; +import type { AuthVariables } from "../../auth.js"; +import { IngressAdmission } from "../../ingress-admission.js"; +import { fileRoutes } from "../../routes/files.js"; +import { SessionManager } from "../../session-manager.js"; + +function deferred() { + let resolve: () => void = () => {}; + const promise = new Promise((done) => { + resolve = done; + }); + return { promise, resolve }; +} + +function setup() { + const ingress = new IngressAdmission({ + maxRequests: 2, + maxTenantRequests: 1, + maxBytes: 10, + maxTenantBytes: 9, + maxBodyBytes: 20, + waitMs: 250, + }); + const app = new Hono<{ Variables: AuthVariables }>(); + app.use("*", (c, next) => { + c.set("tenant", c.req.header("X-Tenant") ?? "a"); + c.set("owner", "owner"); + return ingress.middleware(c, next); + }); + app.post("/holder", async (c) => { + await c.req.text(); + return c.body(new ReadableStream()); + }); + app.get("/blocker", (c) => c.body(new ReadableStream())); + return { app, ingress }; +} + +describe("body-ignoring mutation outcomes", () => { + it.each(["immediate", "queued"] as const)( + "preserves an unknown outcome after %s admission when unused body bytes arrive", + async (admission) => { + const { app, ingress } = setup(); + const mutated = deferred(); + const finish = deferred(); + let mutations = 0; + app.delete("/outcome", async (c) => { + mutations++; + mutated.resolve(); + await finish.promise; + return c.json({ code: "EEXEC_OUTCOME_UNKNOWN", error: "Worker reply lost", retryable: false }, 503); + }); + const holder = await app.request("/holder", { + method: "POST", + headers: { "X-Tenant": "b" }, + body: "12345678", + }); + const blocker = admission === "queued" ? await app.request("/blocker") : undefined; + const reading = deferred(); + let source!: ReadableStreamDefaultController; + let cancelled = false; + let reads = 0; + const body = new ReadableStream( + { + start(controller) { + source = controller; + }, + pull() { + reads++; + reading.resolve(); + }, + cancel() { + cancelled = true; + }, + }, + { highWaterMark: 0 }, + ); + const response = app.request( + new Request("http://localhost/outcome", { method: "DELETE", body, duplex: "half" } as RequestInit), + ); + try { + if (blocker !== undefined) { + await reading.promise; + expect(ingress.metrics.queuedRequests).toBe(1); + await blocker.body?.cancel(); + } + await mutated.promise; + expect(reads).toBe(admission === "queued" ? 1 : 0); + source.enqueue(new Uint8Array(3)); + await new Promise((resolve) => setImmediate(resolve)); + expect(reads).toBe(admission === "queued" ? 1 : 0); + expect(ingress.metrics).toMatchObject({ retainedRawBytes: 8, refused: 0 }); + finish.resolve(); + const result = await response; + expect(result.status).toBe(503); + expect(await result.json()).toEqual({ + code: "EEXEC_OUTCOME_UNKNOWN", + error: "Worker reply lost", + retryable: false, + }); + expect(result.headers.get("Retry-After")).toBeNull(); + expect(mutations).toBe(1); + expect(cancelled).toBe(true); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, retainedRawBytes: 8, refused: 0, aborted: 0 }); + } finally { + finish.resolve(); + await holder.body?.cancel(); + await blocker?.body?.cancel(); + const result = await response; + if (!result.bodyUsed) await result.body?.cancel(); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); + }, + ); + + it.each(["immediate", "queued"] as const)( + "preserves the real file DELETE's 204 after %s admission when unused body bytes arrive", + async (admission) => { + const { app, ingress } = setup(); + const fs = new InMemoryFs(); + const manager = new SessionManager({ createFs: async () => fs }); + await manager.getOrCreate("a", "delete-outcome", undefined, "owner"); + await fs.writeFile("/target", "present"); + const mutated = deferred(); + const finish = deferred(); + const remove = fs.rm.bind(fs); + vi.spyOn(fs, "rm").mockImplementation(async (...args) => { + await remove(...args); + mutated.resolve(); + await finish.promise; + }); + app.route("/v1/sandboxes", fileRoutes(manager)); + const holder = await app.request("/holder", { + method: "POST", + headers: { "X-Tenant": "b" }, + body: "12345678", + }); + const blocker = admission === "queued" ? await app.request("/blocker") : undefined; + const reading = deferred(); + let source!: ReadableStreamDefaultController; + const body = new ReadableStream( + { + start(controller) { + source = controller; + }, + pull: reading.resolve, + }, + { highWaterMark: 0 }, + ); + const response = app.request( + new Request("http://localhost/v1/sandboxes/delete-outcome/files/target", { + method: "DELETE", + body, + duplex: "half", + } as RequestInit), + ); + try { + if (blocker !== undefined) { + await reading.promise; + expect(ingress.metrics.queuedRequests).toBe(1); + await blocker.body?.cancel(); + } + await mutated.promise; + expect(await fs.exists("/target")).toBe(false); + source.enqueue(new Uint8Array(3)); + await new Promise((resolve) => setImmediate(resolve)); + finish.resolve(); + const result = await response; + expect(result.status).toBe(204); + expect(result.headers.get("Retry-After")).toBeNull(); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, retainedRawBytes: 8, refused: 0, aborted: 0 }); + } finally { + finish.resolve(); + await holder.body?.cancel(); + await blocker?.body?.cancel(); + await (await response).body?.cancel(); + vi.restoreAllMocks(); + await manager.destroy("a", "delete-outcome"); + await manager.shutdown(); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); + }, + ); +}); diff --git a/src/api/tests/unit/ingress-queue.test.ts b/src/api/tests/unit/ingress-queue.test.ts new file mode 100644 index 00000000..0b7f4ee4 --- /dev/null +++ b/src/api/tests/unit/ingress-queue.test.ts @@ -0,0 +1,374 @@ +import { Hono } from "hono"; +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import type { AuthVariables } from "../../auth.js"; +import { IngressAdmission, type IngressOptions, loadIngressOptions } from "../../ingress-admission.js"; + +function deferred() { + let resolve!: (value: T) => void; + const promise = new Promise((done) => { + resolve = done; + }); + return { promise, resolve }; +} + +function setup(options: Partial = {}) { + const ingress = new IngressAdmission({ + maxRequests: 2, + maxTenantRequests: 1, + maxQueuedRequests: 3, + maxTenantQueuedRequests: 2, + maxBytes: 100, + maxTenantBytes: 75, + maxBodyBytes: 60, + waitMs: 250, + ...options, + }); + const app = new Hono<{ Variables: AuthVariables }>(); + const hold = deferred(); + let dispatched = 0; + app.onError((_error, c) => c.text("failed", 500)); + app.use("*", (c, next) => { + c.set("tenant", c.req.header("X-Tenant") ?? "a"); + return c.req.path === "/mcp" ? ingress.mcpMiddleware(c, next) : ingress.middleware(c, next); + }); + app.on(["GET", "POST"], "/hold", async (c) => { + await c.req.text(); + await hold.promise; + return c.text("held"); + }); + app.on(["GET", "POST"], ["/work", "/mcp"], async (c) => { + dispatched++; + return c.text(await c.req.text()); + }); + return { app, ingress, hold, dispatched: () => dispatched }; +} + +function input(chunks: number[], onCancel?: () => void) { + const observed = { reads: 0, cancelled: false }; + const body = new ReadableStream( + { + pull(controller) { + observed.reads++; + const size = chunks.shift(); + if (size !== undefined) controller.enqueue(new Uint8Array(size)); + }, + cancel() { + observed.cancelled = true; + onCancel?.(); + }, + }, + { highWaterMark: 0 }, + ); + return { body, observed }; +} + +function request(body: ReadableStream, signal?: AbortSignal, tenant = "a") { + return new Request("http://localhost/work", { + method: "POST", + headers: { "X-Tenant": tenant }, + body, + signal, + duplex: "half", + } as RequestInit); +} + +async function consume(response: Response | Promise) { + const result = await response; + if (!result.bodyUsed) await result.arrayBuffer(); + return result; +} + +const flush = () => vi.advanceTimersByTimeAsync(0); + +beforeEach(() => vi.useFakeTimers()); +afterEach(() => { + vi.restoreAllMocks(); + vi.useRealTimers(); +}); + +describe("ingress queue configuration", () => { + it.each([ + { global: 0, tenant: 0 }, + { global: 1, tenant: 1 }, + { global: 2, tenant: 1 }, + { global: 3, tenant: 2 }, + { global: 12, tenant: 4 }, + ])("bounds the default tenant share for a $global slot queue", ({ global, tenant }) => { + expect(loadIngressOptions({ SQL_FS_MAX_INGRESS_QUEUED_REQUESTS: String(global) })).toMatchObject({ + maxQueuedRequests: global, + maxTenantQueuedRequests: tenant, + maxRequests: 8, + maxTenantRequests: 4, + waitMs: 250, + }); + }); + + it("allows zero tenant waiting and rejects invalid queue counts or tenant shares", () => { + expect(loadIngressOptions({ SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS: "0" }).maxTenantQueuedRequests).toBe(0); + for (const name of ["SQL_FS_MAX_INGRESS_QUEUED_REQUESTS", "SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS"]) { + for (const value of ["-1", "1.5", "NaN", "Infinity", "9007199254740992"]) { + expect(() => loadIngressOptions({ [name]: value })).toThrow(name); + } + } + for (const [global, tenant] of [ + [0, 1], + [1, 2], + [2, 2], + [3, 3], + ]) { + expect(() => + loadIngressOptions({ + SQL_FS_MAX_INGRESS_QUEUED_REQUESTS: String(global), + SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS: String(tenant), + }), + ).toThrow("SQL_FS_MAX_INGRESS_TENANT_QUEUED_REQUESTS"); + } + }); +}); + +describe("queued input ownership", () => { + it("cancels an immediately admitted request when consuming its input observes cancellation", async () => { + const { app, ingress, dispatched } = setup(); + const abort = new AbortController(); + const body = new ReadableStream( + { + pull() { + abort.abort(); + }, + }, + { highWaterMark: 0 }, + ); + expect((await app.request(request(body, abort.signal))).status).toBe(499); + expect(dispatched()).toBe(1); + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0, aborted: 1 }); + }); + + it("allows immediate admission with zero waiting and refuses excess input unread", async () => { + const { app, ingress, hold } = setup({ maxQueuedRequests: 0, maxTenantQueuedRequests: 0 }); + const active = app.request("/hold", { method: "POST", body: "held" }); + const rejected = input([1]); + try { + await flush(); + const response = await app.request(request(rejected.body)); + expect(response.status).toBe(503); + expect(rejected.observed).toEqual({ reads: 0, cancelled: true }); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 0, queueTimeouts: 0, refused: 1 }); + expect((await consume(app.request("/work", { method: "POST", headers: { "X-Tenant": "b" } }))).status).toBe(200); + } finally { + hold.resolve(); + await consume(active); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); + }); + + it("enforces queue counts independently of active counts across HTTP and MCP POST", async () => { + const { app, ingress, hold } = setup(); + const post = (tenant: string, path: string) => + app.request(path, { + method: "POST", + headers: { "X-Tenant": tenant }, + body: "data", + }); + const active = [post("a", "/hold"), post("b", "/hold")]; + const pending: (Response | Promise)[] = []; + try { + await flush(); + pending.push(post("a", "/work"), post("a", "/mcp")); + await flush(); + expect(ingress.metrics).toMatchObject({ activeRequests: 2, queuedRequests: 2, retainedRawBytes: 16 }); + const tenantExcess = input([1]); + expect((await app.request(request(tenantExcess.body))).status).toBe(503); + expect(tenantExcess.observed).toEqual({ reads: 0, cancelled: true }); + pending.push(post("b", "/work")); + await flush(); + expect(ingress.metrics).toMatchObject({ activeRequests: 2, queuedRequests: 3, retainedRawBytes: 20 }); + const globalExcess = input([1]); + expect((await app.request(request(globalExcess.body, undefined, "c"))).status).toBe(503); + expect(globalExcess.observed).toEqual({ reads: 0, cancelled: true }); + expect((await consume(app.request("/mcp"))).status).toBe(200); + expect(ingress.metrics).toMatchObject({ queuedRequests: 3, refused: 2, queueTimeouts: 0 }); + } finally { + hold.resolve(); + await Promise.allSettled([...active, ...pending].map(consume)); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); + }); + + it.each([ + { limit: "tenant", maxBytes: 100, maxTenantBytes: 20, maxBodyBytes: 60, chunks: [8, 9], status: 503 }, + { limit: "global", maxBytes: 20, maxTenantBytes: 75, maxBodyBytes: 60, chunks: [8, 9], status: 503 }, + { limit: "body", maxBytes: 100, maxTenantBytes: 75, maxBodyBytes: 12, chunks: [8, 5], status: 413 }, + ])( + "removes queued input at the $limit byte limit and preserves the cause during cancellation", + async ({ chunks, status, ...options }) => { + const { app, ingress, hold, dispatched } = setup(options); + const active = app.request("/hold", { method: "POST", body: "held" }); + const abort = new AbortController(); + const incoming = input(chunks, () => abort.abort()); + try { + await flush(); + const result = await app.request(request(incoming.body, abort.signal)); + expect(result.status).toBe(status); + expect(await result.json()).toMatchObject({ code: status === 413 ? "PAYLOAD_TOO_LARGE" : "EWORKER_BUSY" }); + expect(incoming.observed.cancelled).toBe(true); + expect(dispatched()).toBe(0); + expect(ingress.metrics).toMatchObject({ + activeRequests: 1, + queuedRequests: 0, + retainedRawBytes: 4, + aborted: 0, + queueTimeouts: 0, + }); + } finally { + hold.resolve(); + await consume(active); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, retainedRawBytes: 0 }); + }, + ); + + it("dispatches an admitted request while its queued body is still arriving", async () => { + const { app, ingress, hold, dispatched } = setup(); + const active = app.request("/hold", { method: "POST", body: "held" }); + const outgoing = deferred>(); + const body = new ReadableStream({ start: outgoing.resolve }); + const controller = await outgoing.promise; + controller.enqueue(new TextEncoder().encode("first")); + const waiting = app.request(request(body)); + try { + await flush(); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 9 }); + expect(dispatched()).toBe(0); + hold.resolve(); + await consume(active); + await flush(); + expect(dispatched()).toBe(1); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 0, retainedRawBytes: 5 }); + controller.enqueue(new TextEncoder().encode("second")); + controller.close(); + expect(await (await waiting).text()).toBe("firstsecond"); + } finally { + hold.resolve(); + ingress.close(); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); + }); + + it("cancels active work at a body limit while retaining its permit until settlement", async () => { + const { app, ingress, hold } = setup({ maxBodyBytes: 12 }); + let workSignal: AbortSignal | undefined; + app.post("/stream", async (c) => { + workSignal = c.req.raw.signal; + const reader = c.req.raw.body!.getReader(); + await reader.read(); + await expect(reader.read()).rejects.toMatchObject({ name: "AbortError" }); + await hold.promise; + return c.text("settled"); + }); + const body = input([8, 5]).body; + const response = app.request( + new Request("http://localhost/stream", { + method: "POST", + body, + duplex: "half", + } as RequestInit), + ); + try { + await flush(); + expect(workSignal?.aborted).toBe(true); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, retainedRawBytes: 8, payloadTooLarge: 1, aborted: 0 }); + } finally { + hold.resolve(); + } + expect((await consume(response)).status).toBe(413); + expect(ingress.metrics).toMatchObject({ activeRequests: 0, retainedRawBytes: 0 }); + }); + + it("drops an input read that settles after queued cancellation", async () => { + const { app, ingress, hold, dispatched } = setup(); + const active = app.request("/hold", { method: "POST", body: "held" }); + const body = new ReadableStream(); + const abort = new AbortController(); + const incoming = request(body, abort.signal); + const reader = body.getReader(); + const late = deferred>>(); + vi.spyOn(reader, "read").mockReturnValue(late.promise); + vi.spyOn(reader, "cancel").mockResolvedValue(); + vi.spyOn(body, "getReader").mockReturnValue(reader); + const waiting = app.request(incoming); + try { + await flush(); + expect(ingress.metrics.queuedRequests).toBe(1); + abort.abort(); + expect((await waiting).status).toBe(499); + late.resolve({ done: false, value: new Uint8Array(50) }); + await flush(); + expect(dispatched()).toBe(0); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 0, retainedRawBytes: 4, aborted: 1 }); + } finally { + hold.resolve(); + await consume(active); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); + }); + + it("removes a client that disconnects after body EOF while still queued", async () => { + const { app, ingress, hold, dispatched } = setup(); + const active = app.request("/hold", { method: "POST", body: "held" }); + const abort = new AbortController(); + const waiting = app.request("/work", { method: "POST", body: "complete", signal: abort.signal }); + try { + await flush(); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 12 }); + abort.abort(); + expect((await waiting).status).toBe(499); + expect(dispatched()).toBe(0); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 0, retainedRawBytes: 4, aborted: 1 }); + } finally { + hold.resolve(); + await consume(active); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); + }); + + it("discards unread counted chunks when the response completes", async () => { + const { app, ingress, hold } = setup(); + let retainedRequest: Request | undefined; + app.post("/ignore", async (c) => { + retainedRequest = c.req.raw; + await flush(); + return c.text("ignored"); + }); + const active = app.request("/hold", { method: "POST", body: "held" }); + await flush(); + const ignored = app.request("/ignore", { method: "POST", body: "unconsumed" }); + try { + await flush(); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 14 }); + } finally { + hold.resolve(); + await consume(active); + await consume(ignored); + } + expect(ingress.metrics).toMatchObject({ activeRequests: 0, retainedRawBytes: 0 }); + expect(retainedRequest).toBeDefined(); + await expect(retainedRequest?.text()).rejects.toMatchObject({ name: "AbortError" }); + }); + + it("releases a queued permit granted in the same turn as cancellation", async () => { + const { app, ingress, dispatched } = setup(); + app.get("/events", () => new Response(new ReadableStream())); + const active = await app.request("/events"); + const abort = new AbortController(); + const waiting = app.request(request(input([5]).body, abort.signal)); + await flush(); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 5 }); + const cancelled = active.body!.cancel(); + abort.abort(); + await cancelled; + expect((await waiting).status).toBe(499); + expect(dispatched()).toBe(0); + expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0, aborted: 1 }); + expect((await consume(app.request("/work", { method: "POST", body: "next" }))).status).toBe(200); + }); +}); diff --git a/src/api/tests/unit/ingress-wait.test.ts b/src/api/tests/unit/ingress-wait.test.ts index 044a9aae..dfd26430 100644 --- a/src/api/tests/unit/ingress-wait.test.ts +++ b/src/api/tests/unit/ingress-wait.test.ts @@ -30,14 +30,15 @@ function setup(maxRequests = 8, maxTenantRequests = 4, env: NodeJS.ProcessEnv = return { ingress, app }; } -function unreadBody() { +function unreadBody(complete = true) { const observed = { reads: 0, cancelled: false }; const body = new ReadableStream( { pull(controller) { observed.reads++; controller.enqueue(new TextEncoder().encode("delayed")); - controller.close(); + if (complete) controller.close(); + else return new Promise(() => {}); }, cancel() { observed.cancelled = true; @@ -64,7 +65,7 @@ afterEach(() => { }); describe("bounded ingress wait", () => { - it("waits through a fifth observer request without reading its body or exceeding active quotas", async () => { + it("reads a queued fifth observer body without exceeding active quotas", async () => { const { app, ingress } = setup(); const hold = deferred(); let peakActive = 0; @@ -87,8 +88,8 @@ describe("bounded ingress wait", () => { ), ); await flush(); - expect(ingress.metrics).toMatchObject({ activeRequests: 5, queuedRequests: 1, retainedRawBytes: 20, refused: 0 }); - expect(input.observed.reads).toBe(0); + expect(ingress.metrics).toMatchObject({ activeRequests: 5, queuedRequests: 1, retainedRawBytes: 27, refused: 0 }); + expect(input.observed.reads).toBe(1); hold.resolve(); await Promise.all(active.map(consume)); await flush(); @@ -119,7 +120,7 @@ describe("bounded ingress wait", () => { await flush(); waiting.push(request("a")); await flush(); - expect(ingress.metrics).toMatchObject({ activeRequests: 2, queuedRequests: 1, retainedRawBytes: 8 }); + expect(ingress.metrics).toMatchObject({ activeRequests: 2, queuedRequests: 1, retainedRawBytes: 12 }); const tenantInput = unreadBody(); const tenantResponse = await app.request( new Request("http://localhost/work", { @@ -135,7 +136,7 @@ describe("bounded ingress wait", () => { expect(ingress.metrics).toMatchObject({ activeRequests: 2, queuedRequests: 1, refused: 1, queueTimeouts: 0 }); waiting.push(request("b")); await flush(); - expect(ingress.metrics).toMatchObject({ activeRequests: 2, queuedRequests: 2, retainedRawBytes: 8 }); + expect(ingress.metrics).toMatchObject({ activeRequests: 2, queuedRequests: 2, retainedRawBytes: 16 }); for (const tenant of ["a", "c"]) { const input = unreadBody(); const response = await app.request( @@ -158,7 +159,7 @@ describe("bounded ingress wait", () => { expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); }); - it("times out an unread queued body after 250ms with retry guidance and no dispatch", async () => { + it("times out a partially read queued body after 250ms with retry guidance and no dispatch", async () => { const { app, ingress } = setup(2, 1); const hold = deferred(); app.post("/hold", async (c) => { @@ -167,7 +168,7 @@ describe("bounded ingress wait", () => { return c.text("held"); }); const active = app.request("/hold", { method: "POST", body: "held" }); - const input = unreadBody(); + const input = unreadBody(false); let waiting: Promise | undefined; try { await flush(); @@ -178,8 +179,8 @@ describe("bounded ingress wait", () => { ); await flush(); await vi.advanceTimersByTimeAsync(249); - expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, refused: 0 }); - expect(input.observed.reads).toBe(0); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 11, refused: 0 }); + expect(input.observed.reads).toBe(1); await vi.advanceTimersByTimeAsync(1); const response = await waiting; expect(response.status).toBe(503); @@ -189,7 +190,7 @@ describe("bounded ingress wait", () => { error: "Request capacity is busy", retryable: true, }); - expect(input.observed).toEqual({ reads: 0, cancelled: true }); + expect(input.observed).toEqual({ reads: 1, cancelled: true }); expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 0, queueTimeouts: 1, refused: 1 }); } finally { hold.resolve(); @@ -231,7 +232,7 @@ describe("bounded ingress wait", () => { } }); - it("cancels a queued request without pulling its body and reuses its pending slot", async () => { + it("cancels a queued body and reuses its pending slot", async () => { const { app, ingress } = setup(2, 1); const hold = deferred(); app.post("/hold", async (c) => { @@ -241,7 +242,7 @@ describe("bounded ingress wait", () => { }); const active = app.request("/hold", { method: "POST", body: "held" }); const abort = new AbortController(); - const input = unreadBody(); + const input = unreadBody(false); const pending: (Response | Promise)[] = []; try { await flush(); @@ -255,11 +256,11 @@ describe("bounded ingress wait", () => { ); pending.push(waiting); await flush(); - expect(ingress.metrics.queuedRequests).toBe(1); + expect(ingress.metrics).toMatchObject({ queuedRequests: 1, retainedRawBytes: 11 }); abort.abort(); await flush(); expect((await waiting).status).toBe(499); - expect(input.observed).toEqual({ reads: 0, cancelled: true }); + expect(input.observed).toEqual({ reads: 1, cancelled: true }); expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 0, aborted: 1 }); const replacement = app.request("/work", { method: "POST", body: "replacement" }); pending.push(replacement); @@ -317,7 +318,7 @@ describe("bounded ingress wait", () => { }); expect(other.status).toBe(200); expect(await other.text()).toBe("independent"); - expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 4 }); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 10 }); } finally { hold.resolve(); await Promise.allSettled([active, ...pending].map(consume)); @@ -364,7 +365,7 @@ describe("bounded ingress wait", () => { const waiting = app.request("/work", { method: "POST", body: "queued" }); pending.push(waiting); await flush(); - expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 4 }); + expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1, retainedRawBytes: 10 }); hold.resolve(); await flush(); expect((await consume(waiting)).status).toBe(200); @@ -376,7 +377,7 @@ describe("bounded ingress wait", () => { expect(ingress.metrics).toMatchObject({ activeRequests: 0, queuedRequests: 0, retainedRawBytes: 0 }); }); - it("keeps a queued request unread until an SSE response releases capacity", async () => { + it("counts a queued body while an SSE response retains capacity", async () => { const { app, ingress } = setup(2, 1); app.post("/events", () => new Response(new ReadableStream(), { headers: { "Content-Type": "text/event-stream" } })); const response = await app.request("/events", { method: "POST", body: "held" }); @@ -387,7 +388,7 @@ describe("bounded ingress wait", () => { try { await flush(); expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 1 }); - expect(input.observed.reads).toBe(0); + expect(input.observed.reads).toBe(1); await response.body!.cancel(); await flush(); expect((await consume(waiting)).status).toBe(200); @@ -430,7 +431,7 @@ describe("bounded ingress wait", () => { expect((await consume(app.request("/work", { method: "POST", body: "reusable" }))).status).toBe(200); }); - it("closes pending admissions without reading them while preserving active retention", async () => { + it("closes pending admissions and releases their bytes while preserving active retention", async () => { const { app, ingress } = setup(2, 1); const hold = deferred(); app.post("/hold", async (c) => { @@ -439,7 +440,7 @@ describe("bounded ingress wait", () => { return c.text("held"); }); const active = app.request("/hold", { method: "POST", body: "held" }); - const input = unreadBody(); + const input = unreadBody(false); let pending: Response | Promise | undefined; try { await flush(); @@ -447,7 +448,7 @@ describe("bounded ingress wait", () => { new Request("http://localhost/work", { method: "POST", body: input.body, duplex: "half" } as RequestInit), ); await flush(); - expect(ingress.metrics.queuedRequests).toBe(1); + expect(ingress.metrics).toMatchObject({ queuedRequests: 1, retainedRawBytes: 11 }); ingress.close(); ingress.close(); await flush(); @@ -455,7 +456,7 @@ describe("bounded ingress wait", () => { expect(response.status).toBe(503); expect(response.headers.get("Retry-After")).toBe("1"); expect(await response.json()).toMatchObject({ code: "ESHUTTINGDOWN", retryable: true }); - expect(input.observed).toEqual({ reads: 0, cancelled: true }); + expect(input.observed).toEqual({ reads: 1, cancelled: true }); expect(ingress.metrics).toMatchObject({ activeRequests: 1, queuedRequests: 0, retainedRawBytes: 4 }); expect((await consume(app.request("/work", { method: "POST", body: "rejected" }))).status).toBe(503); } finally { diff --git a/src/api/tests/unit/worker-admission.test.ts b/src/api/tests/unit/worker-admission.test.ts index 719f8f7d..fec93290 100644 --- a/src/api/tests/unit/worker-admission.test.ts +++ b/src/api/tests/unit/worker-admission.test.ts @@ -1,4 +1,4 @@ -import { describe, expect, it } from "vitest"; +import { describe, expect, it, vi } from "vitest"; import { FairAdmission } from "../../worker-owner/admission.js"; const options = { @@ -12,6 +12,38 @@ const options = { }; describe("bounded tenant admission", () => { + it("notifies only an accepted queue entry and removes it if the hook throws", async () => { + vi.useFakeTimers(); + const admission = new FairAdmission({ ...options, maxQueued: 1 }); + const notified = vi.fn(); + const release = await admission.acquire("active", "active", 1, undefined, false, notified); + try { + expect(notified).not.toHaveBeenCalled(); + await expect( + admission.acquire("broken", "broken", 2, undefined, false, () => { + expect(admission.metrics).toMatchObject({ queued: 1, queuedBytes: 2 }); + throw new Error("queue hook failed"); + }), + ).rejects.toThrow("queue hook failed"); + expect(admission.metrics).toMatchObject({ active: 1, queued: 0, queuedBytes: 0, offered: 2, cancelled: 1 }); + expect(vi.getTimerCount()).toBe(0); + const waiting = admission.acquire("queued", "queued", 2, undefined, false, notified); + expect(notified).toHaveBeenCalledTimes(1); + await expect(admission.acquire("excess", "excess", 2, undefined, false, notified)).rejects.toMatchObject({ + code: "EWORKER_BUSY", + }); + expect(notified).toHaveBeenCalledTimes(1); + release(); + (await waiting)(); + expect(admission.metrics).toMatchObject({ active: 0, queued: 0, queuedBytes: 0 }); + expect(vi.getTimerCount()).toBe(0); + } finally { + admission.close(); + release(); + vi.useRealTimers(); + } + }); + it("gives a queued writer priority over later readers of that sandbox", async () => { const admission = new FairAdmission({ ...options, capacity: 3, maxActivePerTenant: 2, waitMs: 1000 }); const firstReader = await admission.acquire("tenant", "sandbox", 1, undefined, true); diff --git a/src/api/worker-owner/admission.ts b/src/api/worker-owner/admission.ts index 7816f010..a39219fb 100644 --- a/src/api/worker-owner/admission.ts +++ b/src/api/worker-owner/admission.ts @@ -38,7 +38,7 @@ export class FairAdmission { private totalWaitMs = 0; private cancelled = 0; private timedOut = 0; - private readonly waitBuckets = [1, 5, 25, 100, 250, 1000]; + private readonly waitBuckets = [1, 5, 25, 100, 250, 1000, 2500, 5000, 10000, 30000]; private readonly waitCounts = this.waitBuckets.map(() => 0); constructor( @@ -65,7 +65,14 @@ export class FairAdmission { }; } - acquire(tenant: string, key: string, bytes: number, signal?: AbortSignal, shared = false): Promise<() => void> { + acquire( + tenant: string, + key: string, + bytes: number, + signal?: AbortSignal, + shared = false, + onQueued?: () => void, + ): Promise<() => void> { this.offered++; if (this.closed || signal?.aborted) { this.cancelled++; @@ -122,6 +129,13 @@ export class FairAdmission { this.queues.set(tenant, queue); this.queued++; this.queuedBytes += bytes; + try { + onQueued?.(); + } catch (error) { + this.remove(waiter); + this.cancelled++; + reject(error); + } this.drain(); }); } diff --git a/src/api/worker-owner/metrics.ts b/src/api/worker-owner/metrics.ts index cef3749f..0b8ab3b2 100644 --- a/src/api/worker-owner/metrics.ts +++ b/src/api/worker-owner/metrics.ts @@ -32,6 +32,16 @@ const fields = [ ["queue_wait_milliseconds_total", "counter", "totalWaitMs"], ] as const satisfies ReadonlyArray; +function waitHistogram(name: string, snapshot: Pick): string[] { + return [ + `# TYPE ${name} histogram`, + ...snapshot.waitBuckets.map((bucket) => `${name}_bucket{le="${bucket.upperMs}"} ${bucket.count}`), + `${name}_bucket{le="+Inf"} ${snapshot.admitted}`, + `${name}_sum ${snapshot.totalWaitMs}`, + `${name}_count ${snapshot.admitted}`, + ]; +} + export function renderWorkerMetrics(snapshot: Snapshot | undefined, ingress?: IngressAdmission["metrics"]): string { const lines = ["# TYPE sql_fs_workers_enabled gauge", `sql_fs_workers_enabled ${snapshot === undefined ? 0 : 1}`]; if (snapshot !== undefined) { @@ -39,22 +49,21 @@ export function renderWorkerMetrics(snapshot: Snapshot | undefined, ingress?: In const name = `sql_fs_worker_${suffix}`; lines.push(`# TYPE ${name} ${type}`, `${name} ${snapshot[field]}`); } - const histogram = "sql_fs_worker_queue_wait_milliseconds"; - lines.push(`# TYPE ${histogram} histogram`); - for (const bucket of snapshot.waitBuckets) { - lines.push(`${histogram}_bucket{le="${bucket.upperMs}"} ${bucket.count}`); - } - lines.push( - `${histogram}_bucket{le="+Inf"} ${snapshot.admitted}`, - `${histogram}_sum ${snapshot.totalWaitMs}`, - `${histogram}_count ${snapshot.admitted}`, - ); + lines.push(...waitHistogram("sql_fs_worker_queue_wait_milliseconds", snapshot)); } lines.push("# TYPE sql_fs_ingress_enabled gauge", `sql_fs_ingress_enabled ${ingress === undefined ? 0 : 1}`); if (ingress !== undefined) { const ingressFields = [ + ["request_capacity", "gauge", "requestCapacity"], + ["queue_capacity", "gauge", "queueCapacity"], + ["raw_byte_capacity", "gauge", "rawByteCapacity"], + ["queue_wait_limit_milliseconds", "gauge", "queueWaitLimitMs"], ["active_requests", "gauge", "activeRequests"], ["queued_requests", "gauge", "queuedRequests"], + ["offered_total", "counter", "offered"], + ["admitted_total", "counter", "admitted"], + ["completed_total", "counter", "completed"], + ["cancelled_total", "counter", "cancelled"], ["queue_timeouts_total", "counter", "queueTimeouts"], ["mcp_listeners_active", "gauge", "activeMcpListeners"], ["mcp_listeners_queued", "gauge", "queuedMcpListeners"], @@ -69,6 +78,7 @@ export function renderWorkerMetrics(snapshot: Snapshot | undefined, ingress?: In const name = `sql_fs_ingress_${suffix}`; lines.push(`# TYPE ${name} ${type}`, `${name} ${ingress[field]}`); } + lines.push(...waitHistogram("sql_fs_ingress_queue_wait_milliseconds", ingress)); } return `${lines.join("\n")}\n`; }