Two deploys in one, and the forty-second gap

Status: shipped and run. The receipt at the bottom of this post is from the first deploy on the new flow, today.

Four days ago we published Deploying an agent platform without losing the schema — five practices, with the reasoning behind each. One of them said this:

Migrations run before the containers roll. That ordering does not remove the schema-skew window; it picks which side of it to take.

That paragraph was describing the intent of the deploy, not its behaviour. Somebody went and read the clock.

What the box actually said

From the container and migration logs of a real deploy:

Read the order. The new image was up and taking traffic forty seconds before the backup finished and fifty-nine seconds before the schema it expects existed. For a minute, on every deploy, the release that had just landed was serving requests against the previous release's schema.

That is the exact failure the earlier post described as the thing the ordering exists to avoid, and it names the expensive part of it plainly: a column the new code selects and the old schema does not have is a 500 at request time, in production, during the one minute nobody is watching because the deploy is "done".

It also means there was a window in which a migration could fail after the app had already swapped — leaving the new code running permanently against a schema it could not use, with no previous container left to fall back to.

And there was a second problem in the same step, unrelated to schema.

The swap killed every open stream

A chat turn in Vocion is a server-sent-events stream. It stays open for as long as the agent is working, which on a document run or a mission is minutes. Replacing the container under it closes the socket.

There is no graceful way for the browser to interpret that. There is no "the server was upgraded" frame. The stream simply ends, and the person who asked a question forty seconds ago watches their answer stop mid-sentence and get replaced with a network error.

Deploys were happening several times a day.

The new flow

The deploy is now a sequence of phases, each of which either gates the next one or explains why it did not. In order:

1. Build the image from the pinned core submodule, baking the core sha in as VOCION_DEPLOY_PIN.
2. Migrate, in its own script, while the previous container is still serving.
3. Drain in-flight requests.
4. Swap the container.
5. Wait for the new container to serve its own pinned sha.
6. Concurrent index builds, after the swap.
7. Apply the workspace.

The reordering is the whole fix, but each phase gained a gate worth describing.

Migrations are their own script now, and they abort the deploy

Migrations moved out of the bootstrap script into a separate one whose default mode is apply_numbered_migrations. It runs before anything touches the running container, which means every one of its failure modes ends with the previous release still serving.

It takes a pg_dump -Fc of the application database first, and both the failure and the empty case are fatal:

if ! docker exec "${PG}" pg_dump -U postgres -Fc vocion > "${backup_file}"; then
  rm -f "${backup_file}"
  log "FATAL: pg_dump failed — refusing to run migrations without a restore point"
  receipt "migrations=failed reason=backup-failed phase=before-swap"
  exit 1
fi
if [ ! -s "${backup_file}" ]; then
  log "FATAL: pg_dump produced an empty file — refusing to run migrations"
  receipt "migrations=failed reason=backup-empty phase=before-swap"
  exit 1
fi

The comment above it records why this is exit 1 and not a warning: an audit on 2026-09-15 found the box had never successfully taken one. A backup step whose exit code is discarded is a backup step that has been failing for a month.

The workflow engine's database is dumped too, and that one is deliberately not fatal — it is a recoverable-by-replay system and refusing to deploy over it would be a worse trade. Seven of each are kept.

Then the migrations apply one file at a time, and the log names the file. Errors are classified rather than counted, because an idempotent migration produces expected noise:

local benign_re='already exists|duplicate key|does not exist|multiple primary keys|is already|cannot drop .* because other objects depend'

Anything that does not match that pattern is a real error. Separately, the script re-reads the schema afterwards and compares it against what the newest migration files declared — every CREATE TABLE and ADD COLUMN checked against information_schema — and counts anything declared-but-absent as a missing object. That check exists because a file full of IF NOT EXISTS is idempotent, which is good, and silent when it does nothing, which is not.

Either count above zero refuses the swap:

if [ "${missing}" -gt 0 ] || [ "${mig_bad}" -gt 0 ]; then
  receipt "migrations=failed phase=before-swap files=${mig_total} real_errors=${mig_bad} missing_objects=${missing} duration=${duration}s log=${mig_log}"
  if [ "${VOCION_REQUIRE_SCHEMA:-1}" = "1" ]; then
    log "FATAL: the schema is not what this core pin expects (${mig_bad} failed migration(s), ${missing} missing object(s))."
    log "       Refusing to swap the app container — the running one keeps serving."

The override exists (VOCION_REQUIRE_SCHEMA=0) and defaults to refusing. An override you have to type is a different thing from a check you can forget.

One detail that cost a dry run: the post-check block deliberately runs with set +e +o pipefail, because a migration file containing no CREATE/ALTER makes grep exit 1, and under pipefail that killed the deploy on 2026-09-15. A safety check that fails the deploy when it finds nothing to check is not a safety check.

Drain is bounded, and never fatal

In-flight requests are counted through Caddy's admin API, which knows how many requests each upstream currently has open — and a server-sent-events stream is a request that is open:

app_inflight_requests() {
  local out
  out="$(docker exec vocion-caddy wget -qO- http://127.0.0.1:2019/reverse_proxy/upstreams 2>/dev/null || true)"
  if [ -z "${out}" ]; then echo -1; return 0; fi
  printf '%s' "${out}" | jq -r '[.[] | select(.address=="app:3000") | .num_requests] | add // 0' 2>/dev/null || echo -1
}

drain_app_requests polls that every two seconds until it reaches zero or until VOCION_DRAIN_TIMEOUT (default 90 seconds). -1 means "cannot measure", and it says so rather than pretending zero.

Every branch of the function returns success. This is on purpose. A deploy that hangs forever because one long-lived stream will not close is worse than a deploy that interrupts it, and the timeout case is honest about the trade in the log:

log "!! drain: ${n} request(s) still open after ${waited}s — swapping anyway; those turns will see a network error"
receipt "drain=timeout streams_at_start=${first} streams_at_end=${n} waited=${waited}s timeout=${timeout}s"

So the person mid-answer can still lose their stream. What changed is that it now takes ninety seconds of a genuinely stuck request rather than happening on every deploy by default, and when it does happen the receipt says how many and for how long.

The swap has to prove itself

After compose up, the deploy does not continue on the strength of "the container started". It goes inside the new container and asks it what it is serving:

pin="$(docker exec vocion-app wget -qO- http://127.0.0.1:3000/version.txt 2>/dev/null | awk '$1=="deploy-pin"{print $2}' || true)"

and compares it to CORE_SHA, the submodule commit that was baked into the image at build time. Three outcomes, three receipts: swap=ok with the sha and how long it took, swap=pin-mismatch with both shas, swap=unconfirmed reason=no-version-txt if nothing answered within VOCION_APP_READY_TIMEOUT (150 seconds).

The comment above the function explains why none of those are fatal:

Loud but not fatal: the CI health gate makes the same assertion from outside, which is the probe a person can repeat.

The outside probe — the workflow polling https://<host>/version.txt and comparing against git rev-parse HEAD:vocion-core — is fatal to the job. Asserting the same fact twice from two vantage points is deliberate: the inside check tells you the container is correct, the outside check tells you the request path to it is. Those fail separately.

Concurrent index builds go last

CREATE INDEX CONCURRENTLY cannot run inside a transaction and can take minutes on a populated table. It also takes no write lock, and the application is correct without the index — only slower. So this phase runs after the swap, and is explicitly non-fatal.

Each file applies with ON_ERROR_STOP=1 and no --single-transaction, and every file is written to be re-runnable (DROP INDEX IF EXISTS then CREATE ... IF NOT EXISTS), because an interrupted concurrent build leaves the index in place and invalid — present, unusable, and ignored by the planner. So the phase ends by asking Postgres directly:

select string_agg(c.relname, ',') from pg_index i
  join pg_class c on c.oid = i.indexrelid
 where not i.indisvalid

Anything it returns is named in the log and in the receipt's invalid= field.

What it found on the first run

This is the part that justifies the whole exercise.

vocion-core/packages/core/migrations/concurrent/ holds the index builds that the repo's own migration conventions require to be separated out — the rule enforced in CI by npm run check:migrations, which refuses a migration that would take a write lock on a populated table.

Verified read-only on the box on 2026-09-19: all nine indexes declared in those files were missing in production. Eight files, nine indexes, zero of them applied, for as long as the directory had existed.

Which is precisely the failure the conventions document warns a hand-rolled applier about. The applier talks to psql directly and keeps its own ledger of applied filenames, because the ORM's migrate command is a development dependency that gets trimmed out of the production image. A hand-rolled applier that iterates migrations/*.sql does not descend into migrations/concurrent/, and nothing anywhere said so. The indexes were correct, reviewed, merged, convention-compliant — and never run.

Nobody would have found this by looking at a deploy log, because the deploy log had nothing to say about a step that did not exist.

The receipt

Every phase prints one line, from a function that is two words long and defined identically in both scripts:

receipt() { echo "[deploy-receipt] $*"; }

There are twelve distinct receipt lines across the two scripts — success and each named failure for migrations, drain, swap and indexes. Here is today's first run on the new flow, verbatim:

[deploy-receipt] migrations=ok phase=before-swap files=126 real_errors=0 missing_objects=0 duration=76s
[deploy-receipt] drain=ok streams_at_start=0 streams_at_end=0 waited=0s
[deploy-receipt] swap=ok serving=4eee5c359bfb5f8ed844626a63fefe2e8762be3a ready_in=3s
[deploy-receipt] concurrent_indexes=applied files=8 failed=0 invalid=none duration=2s

Four lines. Read them in order and you know: 126 migration files applied cleanly before anything swapped, with the schema post-check finding nothing missing; there was nothing in flight so the drain cost nothing; the container that came up is serving 4eee5c35 — the commit that was pinned — and took three seconds to say so; and eight index files applied with none left invalid.

phase=before-swap is in the migrations line because that fact is the entire point of the rewrite, and a receipt that omitted it would be describing the bug as though it were still present.

streams_at_start=0 is the least interesting number on a quiet afternoon and the most interesting one on a busy morning. It is also the number that tells you whether the interrupted stream somebody is complaining about was this deploy's fault.

The lesson

A deploy that cannot say what it did is a deploy you cannot debug.

Everything in this post was diagnosable only because someone correlated three timestamps from two different logs by hand. The container start time was in one place, the dump completion in another, the migration log in a third, and the relationship between them — which is the only thing that mattered — existed nowhere.

The receipt does not make the deploy safer. The ordering does that. What the receipt does is make the next wrong assumption findable in one grep instead of an afternoon, and make a claim like "migrations run before the swap" checkable rather than believed. We published that claim four days ago in good faith and it was not true. The line that would have caught it costs one echo.

The general version, for anyone running a deploy script of their own: for each phase, ask what a person would need to know if the next phase behaved strangely, and print exactly that, in a grep-able prefix, whether the phase succeeded or not. A log line on failure is table stakes. The line on success is the one that turns out to be load-bearing, because the failures you actually hit are the ones where every step reported OK.

Where this lives in the repo

Public and citable:

• packages/core/migrations/CONVENTIONS.md in vocion-core — the rules the concurrent directory exists to satisfy, and the CI job npm run check:migrations that enforces them
• packages/core/migrations/concurrent/ — the eight files, nine indexes, now applied

Deliberately uncited, as in the earlier post: the bootstrap script, the migration script, the workspace applier and the deploy workflow live in a private deployment repository. The function names above — apply_numbered_migrations, apply_concurrent_indexes, drain_app_requests, app_inflight_requests, wait_for_app — and the receipt grammar are given because the reasoning is the transferable part. The paths are not yours to use anyway.

Not verified: the drain=timeout branch has not fired on a real deploy — every run since the change has drained in zero seconds, so the ninety-second bound is untested against a genuinely stuck stream. swap=pin-mismatch has likewise never fired outside a deliberate test. Both are claims about code that has run, not about behaviour that has been observed in anger.

Related: Deploying an agent platform without losing the schema and A sync that tells you what it did.