diff --git a/.github/workflows/impress.yml b/.github/workflows/impress.yml index b0c6fbc31..272f523eb 100644 --- a/.github/workflows/impress.yml +++ b/.github/workflows/impress.yml @@ -128,6 +128,13 @@ jobs: # needed because the postgres container does not provide a healthcheck options: --health-cmd pg_isready --health-interval 10s --health-timeout 5s --health-retries 5 + # message stream for the collaboration server (see the yhub steps below) + valkey: + image: valkey/valkey:alpine + ports: + - 6379:6379 + options: --health-cmd "valkey-cli ping" --health-interval 10s --health-timeout 5s --health-retries 5 + env: DJANGO_CONFIGURATION: Test DJANGO_SETTINGS_MODULE: impress.settings @@ -142,6 +149,12 @@ jobs: AWS_S3_ENDPOINT_URL: http://localhost:9000 AWS_S3_ACCESS_KEY_ID: impress AWS_S3_SECRET_ACCESS_KEY: password + # Collaboration server. The integration tests reach it over this url and + # skip themselves when nothing answers; yhub reads the JWKS back from the + # django server started alongside it, so both sides must share + # JWT_PRIVATE_KEY_FILE. + COLLABORATION_API_URL: http://localhost:3002/collaboration + JWT_PRIVATE_KEY_FILE: ${{ github.workspace }}/data/jwt/private.pem steps: - name: Checkout repository @@ -203,8 +216,61 @@ jobs: sudo apt-get install -y gettext pandoc shared-mime-info sudo wget https://raw.githubusercontent.com/suitenumerique/django-lasuite/refs/heads/main/assets/conf/mime.types -O /etc/mime.types + # --- collaboration server ------------------------------------------- + # The yhub integration tests drive a real collaboration server: it reads + # legacy documents out of MinIO and reads this backend's JWKS back to + # verify the admin token the tests mint, so the two must share the + # signing key. Tests skip themselves when nothing answers on + # COLLABORATION_API_URL. + - name: Generate the JWT signing key + working-directory: . + run: bin/generate-jwt-private-key.sh + + - name: Create the collaboration server database + run: | + PGPASSWORD=pass psql -h localhost -U dinum -d impress \ + -c 'CREATE DATABASE yhub' + PGPASSWORD=pass psql -h localhost -U dinum -d yhub \ + -f ../../docker/files/yhub/initdb/01-yhub.sql + - name: Generate a MO file from strings extracted from the project run: uv run python manage.py compilemessages + - name: Set up Node + uses: actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e # v6 + with: + node-version: "22.x" + + - name: Install the collaboration server + working-directory: src/yhub-server + run: npm ci --omit=dev + + - name: Start the backend for the collaboration server to authenticate against + env: + DJANGO_ALLOWED_HOSTS: "*" + run: | + nohup uv run python manage.py runserver 0.0.0.0:8000 --noreload \ + > /tmp/backend.log 2>&1 & + dockerize -wait http://localhost:8000/api/v1.0/jwks -timeout 60s + + - name: Start the collaboration server + working-directory: src/yhub-server + env: + PORT: 3002 + REDIS: redis://localhost:6379 + POSTGRES: postgres://dinum:pass@localhost:5432/yhub + REDIS_PREFIX: yhub + COLLABORATION_BACKEND_BASE_URL: http://localhost:8000 + COLLABORATION_SERVER_ORIGIN: http://localhost:3000 + AWS_STORAGE_BUCKET_NAME: impress-media-storage + SOFT_MIGRATION: "true" + run: | + nohup node server.js > /tmp/yhub.log 2>&1 & + dockerize -wait tcp://localhost:3002 -timeout 30s + - name: Run tests run: uv run pytest -n 2 + + - name: Collaboration server logs + if: failure() + run: cat /tmp/yhub.log /tmp/backend.log diff --git a/env.d/development/common b/env.d/development/common index 7a294177d..8b406be28 100644 --- a/env.d/development/common +++ b/env.d/development/common @@ -81,6 +81,8 @@ COLLABORATION_BACKEND_BASE_URL=http://app-dev:8000 COLLABORATION_SERVER_ORIGIN=http://localhost:3000 COLLABORATION_WS_URL=ws://localhost:3002/collaboration/ws/v1/docs COLLABORATION_WS_INACTIVITY_TIMEOUT=15 # Seconds +# server-to-server, reached with an admin JWT (aud: yhub) +COLLABORATION_API_URL=http://yhub:3002/collaboration DJANGO_SERVER_TO_SERVER_API_TOKENS=server-api-token Y_PROVIDER_API_BASE_URL=http://y-provider-development-converter:4444/api/ diff --git a/src/backend/core/tests/test_integration_yhub_migration.py b/src/backend/core/tests/test_integration_yhub_migration.py new file mode 100644 index 000000000..36f06c053 --- /dev/null +++ b/src/backend/core/tests/test_integration_yhub_migration.py @@ -0,0 +1,391 @@ +""" +Integration tests for the migration of legacy documents into the collaboration +server (yhub). + +These talk to a *running* yhub, and through it to MinIO. They need no database: +the admin JWT short-circuits yhub's document authorization, so nothing here +creates a ``Document`` row — the fixtures are S3 objects and yhub rooms keyed on +a random uuid. + +Two paths are covered, in the order a real corpus goes through them: + +``soft migration`` + yhub does not know the room, so the first read seeds it from the *newest* + S3 version. The seed carries an author but deliberately no timestamp, so it + contributes no activity entry. + +``full migration`` + ``POST /migrate`` replays *every* S3 version, crediting each with its own S3 + ``LastModified``, so the activity api reports the same timeline as the + backend's ``/documents/{id}/versions/``. +""" + +import base64 +import itertools +import uuid + +from django.conf import settings +from django.core.files.base import ContentFile +from django.core.files.storage import default_storage + +import pytest +import requests + +from core.services.jwt_services import JWTService + +# yhub verifies that its own name is the audience of the token (server.js) +YHUB_AUDIENCE = "yhub" +# the org yhub is configured with; documents live under /docs/{docid} +YHUB_ORG = "docs" +TIMEOUT = 10 +# see _activity: distinct values defeat yhub's few-second response cache +_cache_buster = itertools.count(1000) + + +def _yhub_url(): + """Base url of the collaboration api, or None when it is not configured.""" + return (settings.COLLABORATION_API_URL or "").rstrip("/") or None + + +def _yhub_reachable(): + """Is a collaboration server actually listening? These tests need one.""" + url = _yhub_url() + if url is None: + return False + try: + # any route answers *something*; we only care that the port is served + requests.get(f"{url}/activity/v1/{YHUB_ORG}/nope", timeout=2) + except requests.RequestException: + return False + return True + + +pytestmark = pytest.mark.skipif( + not _yhub_reachable(), + reason=( + "needs a running collaboration server (COLLABORATION_API_URL); " + "start the dev stack with `make run`" + ), +) + + +@pytest.fixture(name="admin_headers") +def admin_headers_fixture(settings): # pylint: disable=redefined-outer-name + """ + Authorization for the backend-to-yhub calls. + + The token is signed with the same key the running yhub validates against + (it fetches the JWKS from this backend), so this only works when both sides + share ``JWT_PRIVATE_KEY`` — which they do in the dev stack and in CI. + """ + if not settings.JWT_PRIVATE_KEY: + pytest.skip("JWT_PRIVATE_KEY is not configured") + token = JWTService().get_admin_token({"aud": YHUB_AUDIENCE}) + return {"Authorization": f"Bearer {token}"} + + +def _write_legacy_versions(docid, updates): + """ + Write `updates` as successive versions of the legacy object `{docid}/file`. + + Mirrors what the Django backend used to do on every content save: the body + is the base64 encoding of a raw Yjs update, and the bucket is versioned, so + each write leaves the previous one behind as an object version. + + Returns the versions oldest first, as (version_id, last_modified). + """ + key = f"{docid}/file" + for update in updates: + default_storage.save(key, ContentFile(base64.b64encode(update))) + + client = default_storage.connection.meta.client + response = client.list_object_versions( + Bucket=default_storage.bucket_name, Prefix=key + ) + versions = [v for v in response.get("Versions", []) if v["Key"] == key] + versions.sort(key=lambda v: v["LastModified"]) + return [(v["VersionId"], v["LastModified"]) for v in versions] + + +def _activity(docid, admin_headers, **params): + """ + The document's activity, one entry per change, oldest first. + + ``Accept: application/json`` opts out of yhub's lib0-any encoding (0.5.0), + which is what lets a python caller read the timeline without a decoder. + ``group=false`` keeps one entry per version: the default grouping merges + changes by the same author less than a second apart. + + ``groupMaxGap`` is a cache buster, not a parameter we care about: yhub + caches activity responses for a few seconds keyed on the full query, and a + test reads the timeline immediately after changing it. With ``group=false`` + the value is never read (``groupDistance = group ? groupMaxGap : 1``), so a + unique one buys a fresh computation without touching the result. + """ + response = requests.get( + f"{_yhub_url()}/activity/v1/{YHUB_ORG}/{docid}", + params={ + "group": "false", + "groupMaxGap": next(_cache_buster), + **params, + }, + headers={**admin_headers, "Accept": "application/json"}, + timeout=TIMEOUT, + ) + assert response.status_code == 200, response.text + assert response.headers["content-type"].startswith("application/json") + return response.json()["activity"] + + +def _read_ydoc(docid, admin_headers): + """Read the room, which is also what triggers the lazy soft migration.""" + return requests.get( + f"{_yhub_url()}/ydoc/v1/{YHUB_ORG}/{docid}", + headers=admin_headers, + timeout=TIMEOUT, + ) + + +def _ydoc_bytes(docid, admin_headers): + """ + The room's Yjs state as raw bytes. + + The response is an envelope around the document, so its size says nothing + on its own; ``Accept: application/json`` renders the field as base64, which + is comparable. + """ + response = requests.get( + f"{_yhub_url()}/ydoc/v1/{YHUB_ORG}/{docid}", + headers={**admin_headers, "Accept": "application/json"}, + timeout=TIMEOUT, + ) + assert response.status_code == 200, response.text + return base64.b64decode(response.json()["doc"]) + + +def _migrate(docid, admin_headers, **params): + """Replay the document's full legacy version history into yhub.""" + return requests.post( + f"{_yhub_url()}/migrate/v1/{YHUB_ORG}/{docid}", + params=params, + headers={**admin_headers, "Accept": "application/json"}, + timeout=60, + ) + + +# Three successive snapshots of one Yjs document, as the legacy store held them: +# each is a full `Y.encodeStateAsUpdate` of the same doc after another insert, +# so they share a lineage and every later one is a superset of the last. +# Generated with @y/y; hardcoded so the tests need no javascript. +LEGACY_SNAPSHOTS = [ + base64.b64decode(b64) + for b64 in ( + "AQG8yr6Vi7ATAAQBDmRvY3VtZW50LXN0b3JlCkFMUEhBLW9uZSAA", + "AQG8yr6Vi7ATAAQBDmRvY3VtZW50LXN0b3JlFEFMUEhBLW9uZSBCUkFWTy10d28gAA==", + "AQG8yr6Vi7ATAAQBDmRvY3VtZW50LXN0b3JlIkFMUEhBLW9uZSBCUkFWTy10d28gQ0hBUkxJRS10aHJlZSAA", + ) +] + + +def test_integration_yhub_soft_migration_seeds_without_a_timestamp(admin_headers): + """ + The first read of an unknown room seeds it from the newest legacy version. + + The seed is a migration artifact, not an editing event: it has no honest + time to report, so it writes no `insertAt` and therefore shows up in no + activity entry. Anything else would put a second, meaningless timestamp on + content the full migration is about to date properly. + """ + docid = str(uuid.uuid4()) + _write_legacy_versions(docid, LEGACY_SNAPSHOTS) + + response = _read_ydoc(docid, admin_headers) + + assert response.status_code == 200, response.text + # seeded, so the room is no longer empty (an empty update is 2 bytes) + assert len(response.content) > 3 + assert _activity(docid, admin_headers) == [] + + +def test_integration_yhub_soft_migration_admits_when_it_cannot_migrate(admin_headers): + """ + A legacy object that cannot be decoded must not lock its document. + + Nobody can repair such an object from the outside, so refusing access would + make the document permanently unopenable. It opens as a new one instead — + the legacy bytes stay in S3, and the server logs that it admitted a caller + without migrating. + """ + docid = str(uuid.uuid4()) + _write_legacy_versions(docid, [b"@@not-a-valid-ydoc@@"]) + + response = _read_ydoc(docid, admin_headers) + + assert response.status_code == 200, response.text + # and what it opens is exactly what a document that never existed opens as + never_existed = str(uuid.uuid4()) + assert _ydoc_bytes(docid, admin_headers) == _ydoc_bytes( + never_existed, admin_headers + ) + assert _activity(docid, admin_headers) == [] + + +def test_integration_yhub_soft_migration_ignores_a_non_main_branch(admin_headers): + """ + Seeding a branch other than main must not consume the document's one seed. + + The legacy store is branchless — ``{docid}/file`` *is* main — and the admin + token is the only identity that can name another branch. Seeding one would + write main's content into an orphan room and, because the "already seeded" + bookkeeping is per document, leave the real room empty. + """ + docid = str(uuid.uuid4()) + _write_legacy_versions(docid, LEGACY_SNAPSHOTS) + + on_a_branch = requests.get( + f"{_yhub_url()}/ydoc/v1/{YHUB_ORG}/{docid}", + params={"branch": "draft"}, + headers=admin_headers, + timeout=TIMEOUT, + ) + assert on_a_branch.status_code == 200, on_a_branch.text + + # main is untouched by that, so it still seeds on its own first read + assert _read_ydoc(docid, admin_headers).status_code == 200 + assert _ydoc_bytes(docid, admin_headers) != _ydoc_bytes( + str(uuid.uuid4()), admin_headers + ) + + +def test_integration_yhub_full_migration_reports_every_s3_version(admin_headers): + """ + The migrate endpoint replays every legacy version, dated by that version. + + This is the property the whole feature exists for: activity and the + backend's version listing describe the same timeline. + """ + docid = str(uuid.uuid4()) + versions = _write_legacy_versions(docid, LEGACY_SNAPSHOTS) + + response = _migrate(docid, admin_headers) + + assert response.status_code == 200, response.text + body = response.json() + assert body["migrated"] is True + assert body["versions"] == len(versions) + assert body["applied"] == len(versions) + assert body["skipped"] == 0 + assert body["dropped"] == 0 + # the decoded size of every snapshot it read, not the base64 on the wire + assert body["bytes"] == sum(len(update) for update in LEGACY_SNAPSHOTS) + + activity = _activity(docid, admin_headers) + + assert len(activity) == len(versions) + for entry, (_, last_modified) in zip(activity, versions, strict=True): + # yhub stores timestamps in milliseconds (lib0 `getUnixTime` is + # `Date.now`), which is what the S3 write time converts to + assert entry["from"] == pytest.approx(last_modified.timestamp() * 1000, abs=1) + assert entry["from"] == entry["to"] + # legacy snapshots carry no author of their own + assert entry["by"] == "system" + + +def test_integration_yhub_full_migration_after_a_soft_migration(admin_headers): + """ + The two migrations compose: seeding first does not duplicate the history. + + The seed writes the legacy bytes unchanged, so its content ids are the ones + the replay regenerates — the replay covers them and, carrying no timestamp + of its own, the seed adds no entry beside them. + """ + docid = str(uuid.uuid4()) + versions = _write_legacy_versions(docid, LEGACY_SNAPSHOTS) + + assert _read_ydoc(docid, admin_headers).status_code == 200 + assert _activity(docid, admin_headers) == [] + + assert _migrate(docid, admin_headers).status_code == 200 + + activity = _activity(docid, admin_headers) + assert len(activity) == len(versions) + assert [entry["from"] for entry in activity] == sorted( + entry["from"] for entry in activity + ) + + +def test_integration_yhub_full_migration_is_idempotent(admin_headers): + """ + A document is migrated once, ever. + + Replaying a second time would attribute the same content twice, so the + docid is remembered in a valkey set and later calls decline. `?force=true` + is the escape hatch, and the clock-0 row it writes conflicts with the first + one, so even that leaves the timeline alone. + """ + docid = str(uuid.uuid4()) + versions = _write_legacy_versions(docid, LEGACY_SNAPSHOTS) + + assert _migrate(docid, admin_headers).json()["migrated"] is True + + again = _migrate(docid, admin_headers) + assert again.status_code == 200 + assert again.json() == {"message": "Already migrated", "migrated": False} + + forced = _migrate(docid, admin_headers, force="true") + assert forced.json()["migrated"] is True + + assert len(_activity(docid, admin_headers)) == len(versions) + + +def test_integration_yhub_migration_without_a_legacy_document(admin_headers): + """ + A document that never had a legacy object is nothing to migrate. + + It answers 2xx all the same, so a backfill driver walking the corpus can + treat every success as "done" without special-casing new documents. + """ + response = _migrate(str(uuid.uuid4()), admin_headers) + + assert response.status_code == 200 + body = response.json() + assert body["migrated"] is False + assert body["message"] == "No legacy document in s3" + assert body["versions"] == 0 + + +def test_integration_yhub_migration_skips_an_unreadable_version(admin_headers): + """ + One corrupt snapshot must not cost the document its whole history. + + Every version is a full snapshot, so the content of an unreadable one + arrives with the next readable version anyway — only its timeline entry is + lost, and the migration reports how many it dropped that way. + """ + docid = str(uuid.uuid4()) + _write_legacy_versions( + docid, + [LEGACY_SNAPSHOTS[0], b"@@not-a-valid-ydoc@@", LEGACY_SNAPSHOTS[2]], + ) + + body = _migrate(docid, admin_headers).json() + + assert body["migrated"] is True + assert body["versions"] == 3 + assert body["skipped"] == 1 + assert body["applied"] == 2 + assert len(_activity(docid, admin_headers)) == 2 + + +def test_integration_yhub_migration_rejects_a_token_for_another_audience(): + """ + An admin token minted for another service must not be replayable here. + + Django's JWTService signs for whoever asks, so the audience is the only + thing separating the converter's token from yhub's. + """ + token = JWTService().get_admin_token({"aud": "y-converter"}) + + response = _migrate(str(uuid.uuid4()), {"Authorization": f"Bearer {token}"}) + + assert response.status_code == 401 diff --git a/src/backend/impress/settings.py b/src/backend/impress/settings.py index 68eaec5aa..8357a108d 100755 --- a/src/backend/impress/settings.py +++ b/src/backend/impress/settings.py @@ -529,6 +529,13 @@ class Base(Configuration): environ_name="COLLABORATION_WS_INACTIVITY_TIMEOUT", environ_prefix=None, ) + # Base url of the collaboration server's REST api, including its route + # prefix (e.g. "http://yhub:3002/collaboration"). Server-to-server only: + # used with an admin JWT to migrate legacy documents and, later, to kick + # connections when permissions change. + COLLABORATION_API_URL = values.Value( + None, environ_name="COLLABORATION_API_URL", environ_prefix=None + ) # JWT # RSA private key (PEM) used to sign the tokens issued by diff --git a/src/yhub-server/README.md b/src/yhub-server/README.md index a980f437e..4be057c33 100644 --- a/src/yhub-server/README.md +++ b/src/yhub-server/README.md @@ -59,7 +59,9 @@ bucket, as UTF-8 text that is the base64 encoding of a raw Yjs update, at key `{document-uuid}/file`. With `SOFT_MIGRATION=true`, this server migrates those documents into yhub lazily, on first access: -1. After a user's document authorization succeeds, the auth plugin checks +1. After a caller's document authorization succeeds — a user's, or the + backend's own admin JWT, so a server-side read never sees an *empty* + document where legacy content exists — the auth plugin checks whether yhub already has content for the room — the migrated set written by the full migration (below), then a bare postgres `SELECT` (persisted rows), then the valkey stream (uncompacted `ydoc:update:v1` messages), then the @@ -94,16 +96,35 @@ Guarantees and failure behavior: - **Missing S3 object is not an error** — that is the brand-new-document case (Django writes no object until the first content save); the room simply starts empty. -- **Everything else fails closed**, and says whether it is worth retrying - (yhub 0.5.0 error semantics): an oversized or corrupt legacy object will fail - the same way forever, so the connection is denied `403`; network errors, - timeouts and momentary seed backpressure answer `503`, which clients retry - with backoff. Either way a `soft-migration` error is logged. A cached failure - verdict prevents retry storms from hammering S3 — permanent failures - (corrupt/oversized objects) for 5 minutes, transient ones (network errors, - timeouts) for 15 seconds, and per-replica seed backpressure (more than 20 - concurrent seeds) is denied without caching so the client's next retry goes - through. +- **Seeding never decides access** — the backend's answer does. What a failure + changes is only what the room contains, and the two kinds are treated + differently (yhub 0.5.0 error semantics): + - **The legacy object cannot be migrated** — it does not decode, or it + exceeds the size we will load. Retrying cannot change that, and nobody can + repair the object from the outside, so refusing would make the document + permanently unopenable. It opens as a *new* document instead. The cause is + logged once per attempt (`seed.failed`, with the bucket, key and stack) and + every subsequent access logs a `seed.skipped` warning, because the caller + is now editing beside legacy content that stayed behind in S3. + - **Everything else** — network error, timeout, seed backpressure, and every + way S3 can refuse (`AccessDenied` on a rotated key, `NoSuchBucket` on a + misconfigured name, a region redirect). The same request later may well + succeed, so it answers `503` and clients retry with backoff. + + The split is deliberately asymmetric: only a failure raised while + *interpreting bytes we already hold* counts as permanent, and it is marked as + such at the throw site. Everything else is retryable by default. An allowlist + of retryable errors would have to enumerate every way the store can say no, + and each case it missed would be read as "this document has no content" and + open the room empty over content that is alive in S3 — one misscoped + credential would fork the corpus. Guessing wrong this way costs a retry; + guessing wrong the other way costs the document. + + A cached failure verdict prevents retry storms from hammering S3 — permanent + failures (corrupt/oversized objects) for 5 minutes, transient ones (network + errors, timeouts) for 15 seconds, and per-replica seed backpressure (more + than 20 concurrent seeds) is not cached at all, so the client's next retry + goes through. - **Seeding is idempotent**: the legacy S3 snapshots are frozen (the frontend no longer PATCHes content snapshots to Django) and share one Yjs lineage with everything in yhub, so duplicate or concurrent seeds merge as diff --git a/src/yhub-server/migration.js b/src/yhub-server/migration.js index 5e42fee89..70401a5c0 100644 --- a/src/yhub-server/migration.js +++ b/src/yhub-server/migration.js @@ -91,7 +91,9 @@ const s3 = SOFT_MIGRATION }); })() : null; -const migrationLog = logger.child({ module: 'soft-migration' }); +// exported so the auth path can report, under the same module name, that it +// admitted a caller to a document it could not migrate +export const migrationLog = logger.child({ module: 'soft-migration' }); // Both keys are derived from the prefix yhub itself resolved, so they cannot // drift from the room keys, and both sit outside its scanned `:room:*` pattern. @@ -118,10 +120,10 @@ const fetchLegacyDoc = async (docid, versionId = null) => { // stream once reading, so a stalled transfer cannot hold the ws upgrade const timeout = new Promise((_, reject) => { const timer = setTimeout(() => { + // unmarked, so it counts as retryable: a slow S3 may recover const err = new Error( `s3 fetch timed out after ${S3_FETCH_TIMEOUT_MS}ms`, ); - err.transient = true; // a slow S3 may recover — cache the failure briefly stream?.destroy(err); reject(err); }, S3_FETCH_TIMEOUT_MS); @@ -159,11 +161,11 @@ const fetchLegacyDoc = async (docid, versionId = null) => { stream.on('data', (chunk) => { received += chunk.byteLength; if (received > MAX_LEGACY_B64_BYTES) { - stream.destroy( - new Error( - `legacy object exceeds the ${MAX_LEGACY_B64_BYTES}B cap`, - ), + const err = new Error( + `legacy object exceeds the ${MAX_LEGACY_B64_BYTES}B cap`, ); + err.permanent = true; // the object will be this big next time too + stream.destroy(err); return; } chunks.push(chunk); @@ -175,9 +177,11 @@ const fetchLegacyDoc = async (docid, versionId = null) => { ]); const decoded = Buffer.from(body.toString('utf8'), 'base64'); if (decoded.byteLength > MAX_LEGACY_BYTES) { - throw new Error( + const err = new Error( `decoded legacy update (${decoded.byteLength}B) exceeds the ${MAX_LEGACY_BYTES}B cap`, ); + err.permanent = true; // the object will be this big next time too + throw err; } // compute-task schema requires an exact Uint8Array (lib0 compares the // constructor) — re-view the Buffer without copying @@ -205,7 +209,6 @@ const listLegacyVersions = async (docid) => { const err = new Error( `s3 version listing timed out after ${S3_LIST_TIMEOUT_MS}ms`, ); - err.transient = true; stream.destroy(err); }, S3_LIST_TIMEOUT_MS); stream.on('data', (obj) => { @@ -265,26 +268,17 @@ const VERDICT_TTL_MS = { exists: 600000, empty: 60000, failed: 300000 }; // transient failures (network blips, timeouts, S3 restarting) are cached just // long enough to blunt a retry storm without turning a hiccup into a lockout const TRANSIENT_TTL_MS = 15000; -const TRANSIENT_CODES = new Set([ - 'ECONNREFUSED', - 'ECONNRESET', - 'ETIMEDOUT', - 'EHOSTUNREACH', - 'ENETUNREACH', - 'ENOTFOUND', - 'EAI_AGAIN', - 'EPIPE', -]); -// Will this failure plausibly resolve on its own? Callers use it twice: to pick -// the verdict TTL below, and — in server.js — to decide whether a denied -// connection reports a permanent 403 or a retryable 503. `noCache` is the -// per-replica seed backpressure, transient by construction (a slot frees up -// within seconds). -export const isTransientFailure = (err) => - err?.transient === true || - err?.noCache === true || - TRANSIENT_CODES.has(err?.code) || - TRANSIENT_CODES.has(err?.cause?.code); +// Is this legacy object beyond saving, as opposed to merely out of reach right +// now? Only a failure raised while *interpreting* bytes we already hold +// qualifies: the object does not decode, or it is larger than we will load. +// Those are marked at the throw site, and nothing else counts — an allowlist +// of retryable errors would have to enumerate every way S3 can say no +// (AccessDenied on a rotated key, NoSuchBucket on a misconfigured name, a +// region redirect), and each one it missed would be read as "this document has +// no content" and open the room empty over content that is alive in S3. +// Guessing wrong in this direction costs a retry; guessing wrong in the other +// costs the document. +export const isPermanentFailure = (err) => err?.permanent === true; const VERDICT_CACHE_MAX = 50000; const verdicts = new Map(); // docid -> { verdict, error, expires } const rememberVerdict = ( @@ -358,6 +352,16 @@ const migrate = async (yhub, room) => { ); return 'empty'; } + // Decode before writing anything: a legacy object that is not a valid + // Yjs update fails here, on this thread, and is the one failure we know + // no retry can fix — so it is marked as such. + let contentids; + try { + contentids = Y.createContentIdsFromUpdate(update); + } catch (err) { + err.permanent = true; + throw err; + } await yhub.stream.addMessage(room, { type: 'ydoc:update:v1', // Deliberately no insertAt/deleteAt. A lazy seed is not an editing @@ -368,12 +372,9 @@ const migrate = async (yhub, room) => { // whichever the row order happened to put last. Content seeded this way // carries an author but no timestamp, so it produces no activity entry // until fullMigrate supplies the history. - // - // Reading the ids also validates the update: a corrupt legacy object - // throws here, on this thread, before anything reaches the stream. contentmap: Y.encodeContentMap( Y.createContentMapFromContentIds( - Y.createContentIdsFromUpdate(update), + contentids, [ Y.createContentAttribute('insert', 'system'), Y.createContentAttribute('insert:migration', 's3'), @@ -428,22 +429,31 @@ export const maybeMigrate = async (yhub, room) => { .then( (verdict) => rememberVerdict(room.docid, verdict), (err) => { - // logged here (once per attempt) rather than per denied connection: - // cached failures deny without new logs until the verdict expires + // The one place the *cause* is recorded, once per attempt rather + // than per access: a cached verdict re-raises this error without + // logging again until it expires. + const permanent = isPermanentFailure(err); migrationLog.error( - { event: 'seed.failed', err, docid: room.docid }, - 'soft migration failed; denying access', + { + event: 'seed.failed', + err, + docid: room.docid, + permanent, + bucket: AWS_STORAGE_BUCKET_NAME, + key: `${room.docid}/file`, + }, + permanent + ? 'soft migration is not possible for this legacy object' + : 'soft migration failed; the caller is asked to retry', ); if (err?.noCache !== true) { - // transient failures get a short TTL so a hiccup cannot lock a - // doc out for the full poison-object window + // a retryable failure is remembered only briefly, so a hiccup + // cannot lock a document out for the full poison-object window rememberVerdict( room.docid, 'failed', err, - isTransientFailure(err) - ? TRANSIENT_TTL_MS - : VERDICT_TTL_MS.failed, + permanent ? VERDICT_TTL_MS.failed : TRANSIENT_TTL_MS, ); } throw err; diff --git a/src/yhub-server/server.js b/src/yhub-server/server.js index 472da12f2..029c9cb1c 100644 --- a/src/yhub-server/server.js +++ b/src/yhub-server/server.js @@ -13,8 +13,9 @@ import { secret } from './env.js'; import { SOFT_MIGRATION, fullMigrate, - isTransientFailure, + isPermanentFailure, maybeMigrate, + migrationLog, } from './migration.js'; const PORT = Number(process.env.PORT || 3002); @@ -73,6 +74,39 @@ const backendFetch = async (path, { cookie, origin }) => { return res.json(); }; +// First access to a room yhub does not know: seed it from the legacy Django S3 +// store before admitting the caller. Awaited inside the upgrade handler, so the +// post-upgrade initial sync (which merges postgres and the stream from clock 0) +// is guaranteed to include the seed. +// +// Seeding never decides whether the caller may read the document — that is the +// backend's answer alone. There are two ways this ends other than a seed: +// +// the legacy object cannot be migrated (it does not decode, or it is bigger +// than we will load) — retrying will not change that, so the room opens as +// a new document. Refusing instead would lock a document nobody can repair +// from the outside. Logged per access, because the caller is now editing +// alongside legacy content that stayed behind in S3. +// the legacy store could not be reached (timeout, network, backpressure) — +// the same request later may well succeed, so it answers 503 rather than +// silently starting an empty document on top of content that exists. +const seedFromLegacyStore = async (room) => { + try { + // `yhub` is declared at the bottom of this file — safe: auth callbacks only + // fire once the server is up, i.e. after that assignment + await maybeMigrate(yhub, room); + } catch (err) { + if (!isPermanentFailure(err)) { + throw apiError(503, 'Legacy document store is unavailable'); + } + // why it failed was logged once, at the attempt, inside maybeMigrate + migrationLog.warn( + { event: 'seed.skipped', docid: room.docid, err: err?.message }, + 'admitting caller to a document that could not be migrated; it opens as new', + ); + } +}; + const auth = createAuthPlugin({ // uws req is only valid synchronously — read headers AND query before first await. async readAuthInfo(req) { @@ -150,10 +184,35 @@ const auth = createAuthPlugin({ } }, async getAccessType(authInfo, { org, docid, branch }, purpose) { - if (authInfo.admin === true) return 'rw'; // Django's admin token: full access + if (authInfo.admin === true) { + // Django's admin token: full access. It still goes through the legacy + // seed, on the same terms as a user (default purpose only, so a + // `migrate` call is not seeded out from under fullMigrate). Without it a + // backend read of an unmigrated document would answer with an *empty* + // doc, and a create-ydoc against one would write a second lineage next + // to the legacy content the first user access is about to seed in. + // Access itself is never in question here — the token already granted it. + // The same org/branch fence the user path applies below. The admin token + // is the only identity that can name an arbitrary org or branch, and the + // legacy store is branchless — `{docid}/file` *is* main — so seeding any + // other room would write main's content into an orphan room, and the + // per-docid verdict cache would then report that docid as done and leave + // the real room empty. + if ( + SOFT_MIGRATION && + purpose == null && + org === ORG && + branch === 'main' && + UUID4.test(docid) + ) { + await seedFromLegacyStore({ org, docid, branch }); + } + return 'rw'; + } // Regular users only get access for the default purpose — custom-endpoint - // purposes (reset-connections) are backend-internal. Loose != on purpose: - // ws upgrades and rechecks pass undefined, built-in rest endpoints null. + // purposes (reset-connections, migrate) are backend-internal. Loose != on + // purpose: ws upgrades and rechecks pass undefined, built-in rest + // endpoints null. if ( org !== ORG || branch !== 'main' || @@ -177,29 +236,10 @@ const auth = createAuthPlugin({ if (!doc.abilities?.retrieve) { return null; } + // the backend has already decided the caller may read this document; the + // seed only decides what is in it if (SOFT_MIGRATION) { - // First access to a room yhub does not know: seed it from the legacy - // Django S3 store before admitting the connection. Awaited inside the - // upgrade handler, so the post-upgrade initial sync (which merges - // postgres and the stream from clock 0) is guaranteed to include the - // seed. Runs only for authorized readers. A missing S3 object is the - // brand-new-document case and allows an empty room; a real S3/compute - // failure denies access, either way already logged (once per attempt) - // inside maybeMigrate. - try { - // `yhub` is declared at the bottom of this file — safe: auth callbacks - // only fire once the server is up, i.e. after that assignment - await maybeMigrate(yhub, { org, docid, branch }); - } catch (err) { - // A corrupt or oversized legacy object will fail the same way forever, - // so that denial is permanent (403). An S3 timeout, a network blip or - // momentary seed backpressure will not — 503 tells the caller to come - // back rather than to treat the document as unreadable. - if (isTransientFailure(err)) { - throw apiError(503, 'Legacy document store is unavailable'); - } - return null; - } + await seedFromLegacyStore({ org, docid, branch }); } return doc.abilities.update ? 'rw' : 'r'; },