fix(supersync): make interrupted CONCURRENTLY migrations recoverable

A bare CREATE INDEX CONCURRENTLY aborted mid-build (the in-image step
timeout firing at its 1800s default when a raised MIGRATION_TIMEOUT was
not forwarded, an external stop, or OOM) leaves the migration failed and
an INVALID index of the target name, wedging the deploy. Deployed images
reported only a bare "prisma migrate deploy failed (exit 143)" with no
recovery steps, so operators had no way forward.

- deploy.sh: forward MIGRATE_STEP_TIMEOUT into the migrator so a large
  MIGRATION_TIMEOUT is not silently capped at the image default (1800s)
  and kill a slow CREATE INDEX CONCURRENTLY early (the root cause).
- migrate-deploy.sh: normalize BusyBox `timeout` 143 -> 124 so a step
  timeout hits the timeout branch, not the generic one.
- migrate-deploy.sh: emit_interrupted_recovery_hint() prints copy-paste
  recovery (drop the INVALID index, roll the record back, re-run) for an
  interrupted CONCURRENTLY build, from BOTH the 124 timeout branch (where
  a normalized 143 -- the incident's own signal -- lands) and the generic
  non-gate branch (OOM/137), plus the existing P3009 re-run path. Every
  path prints guidance only and NEVER auto-resolves a bare CREATE.
- env.example: document the now-forwarded MIGRATE_STEP_TIMEOUT knob.
- tests: cover 143 normalization, the incident's 143->124 timeout-branch
  recovery, the P3009 and non-gate bare-create recovery, and the
  forwarded step timeout.

The bare CREATE stays bare and fail-loud on purpose: 20260613000001
ships in v18.11.0-v18.14.0 and is applied natively on healthy deploys,
so converting it to a drop-then-create shape would change its checksum
and break every DB that already applied it.

Recovery for the current wedged deploy (20260613000001):
  DROP INDEX CONCURRENTLY IF EXISTS "operations_entity_ids_gin";
  prisma migrate resolve --rolled-back \
    20260613000001_add_operation_entity_ids_gin_index
then re-run the deploy with the step timeout raised enough for the GIN
build (and clear any idle-in-transaction blocker first).
This commit is contained in:
Johannes Millan 2026-07-17 17:24:40 +02:00
parent 238b91aa59
commit f15a20ba8d
6 changed files with 225 additions and 5 deletions

View file

@ -118,6 +118,13 @@ SMTP_FROM="Super Productivity Sync" <noreply@your-domain.com>
# transactions; raise this for very large tables. Exit code 124 = timed out.
# MIGRATION_TIMEOUT=900
# Per-migration-step timeout (seconds) enforced inside the image. deploy.sh
# derives it from MIGRATION_TIMEOUT (minus a small margin) and forwards it, so
# raising MIGRATION_TIMEOUT is enough for the deploy.sh path. Set this directly
# only for the image CMD / helm initContainer paths, which have no outer host
# timeout. Defaults to 1800 inside the image when unset.
# MIGRATE_STEP_TIMEOUT=
# Safety valve for custom/private images without an
# org.opencontainers.image.revision label. Leave this unset in production; the
# deploy script uses the label to prevent mixing fresh SuperSync deploy inputs

View file

@ -72,3 +72,14 @@ auto-recovered — it fails loudly by gate, deterministically, which is the
intended behavior. This is enforced by `tests/migration-sql.spec.ts` (the
migration has no `DROP`) and `tests/migrate-deploy-script.spec.ts` (a bare
CREATE is refused, never marked applied).
**Bare vs drop-then-create for a _new_ index.** Reserve the bare fail-loud
shape for a _correctness-critical_ index, where an interrupted build should
halt the deploy for a human rather than silently retry. For a
_performance-only_ index that has a correct fallback path — e.g.
`operations_entity_ids_gin`, whose conflict lookups fall back to the scalar
`entity_id` — prefer the auto-recoverable drop-then-create shape so an
interrupted build self-heals on the next deploy instead of wedging it and
requiring manual recovery. Do **not** retro-convert an already-applied bare
CREATE: that changes its checksum and breaks `migrate deploy` on every DB that
has it.

View file

@ -95,7 +95,7 @@ load_env_value() {
export "$key=$value"
}
for env_key in GHCR_USER GHCR_TOKEN DATABASE_URL POSTGRES_SERVICE POSTGRES_WAIT_TIMEOUT MIGRATION_TIMEOUT DEPLOY_WAIT_TIMEOUT SUPERSYNC_SKIP_IMAGE_REVISION_CHECK; do
for env_key in GHCR_USER GHCR_TOKEN DATABASE_URL POSTGRES_SERVICE POSTGRES_WAIT_TIMEOUT MIGRATION_TIMEOUT MIGRATE_STEP_TIMEOUT DEPLOY_WAIT_TIMEOUT SUPERSYNC_SKIP_IMAGE_REVISION_CHECK; do
load_env_value "$env_key"
done
@ -286,7 +286,18 @@ echo ""
# for arbitrarily long. Wrap the migrator with a timeout so a stuck deploy fails
# loudly instead of hanging this script forever. Exit code 124 = timed out.
MIGRATION_TIMEOUT="${MIGRATION_TIMEOUT:-900}"
MIGRATOR_RUN="docker compose $COMPOSE_FILES run --rm --no-deps --interactive=false -T supersync"
# The migrator image caps each migration step at MIGRATE_STEP_TIMEOUT (1800s by
# default inside the image). Left unset it silently overrides a larger
# MIGRATION_TIMEOUT and kills a slow CREATE INDEX CONCURRENTLY early, so forward
# the operator's budget into the container. Keep it just under the host timeout
# so the in-image guard — which prints the precise per-step message — fires
# first, with the host timeout as a hard backstop.
if [ "$MIGRATION_TIMEOUT" -gt 90 ]; then
MIGRATE_STEP_TIMEOUT="${MIGRATE_STEP_TIMEOUT:-$((MIGRATION_TIMEOUT - 30))}"
else
MIGRATE_STEP_TIMEOUT="${MIGRATE_STEP_TIMEOUT:-$MIGRATION_TIMEOUT}"
fi
MIGRATOR_RUN="docker compose $COMPOSE_FILES run --rm --no-deps --interactive=false -T -e MIGRATE_STEP_TIMEOUT=$MIGRATE_STEP_TIMEOUT supersync"
echo "==> Verifying database connectivity from the supersync image..."
set +e
timeout "$POSTGRES_WAIT_TIMEOUT" \

View file

@ -48,7 +48,19 @@ MAX_ATTEMPTS="${MIGRATE_MAX_ATTEMPTS:-6}"
STEP_TIMEOUT="${MIGRATE_STEP_TIMEOUT:-1800}"
if command -v timeout >/dev/null 2>&1; then
with_timeout() { timeout "$STEP_TIMEOUT" "$@"; }
with_timeout() {
wt_rc=0
timeout "$STEP_TIMEOUT" "$@" || wt_rc=$?
# GNU coreutils `timeout` exits 124 on expiry; BusyBox `timeout` (shipped by
# the node:*-alpine runtime image) instead lets the child die from the
# default SIGTERM and returns 128+15=143. Normalize so the single 124
# timeout branch is reached on both. Under this wrapper a 143 is timeout's
# own SIGTERM, not an unrelated external kill.
if [ "$wt_rc" -eq 143 ]; then
wt_rc=124
fi
return "$wt_rc"
}
else
with_timeout() { "$@"; }
fi
@ -129,6 +141,17 @@ is_recoverable_concurrently_migration() {
grep -Eqi 'CREATE[[:space:]]+INDEX[[:space:]]+CONCURRENTLY' "$sql"
}
# The intentionally-fail-loud shape: a bare CREATE INDEX CONCURRENTLY with no
# DROP. Not auto-recovered (an interrupted build leaves an INVALID index that
# must be handled deliberately), but distinguished from a plain non-index
# migration so the loud failure can print the correct manual steps.
is_bare_create_concurrently() {
sql="$1"
[ -f "$sql" ] &&
grep -Eqi 'CREATE[[:space:]]+(UNIQUE[[:space:]]+)?INDEX[[:space:]]+CONCURRENTLY' "$sql" &&
! grep -Eqi 'DROP[[:space:]]+INDEX[[:space:]]+CONCURRENTLY' "$sql"
}
# One statement per line; multi-line statements collapsed to a single line
# (index DDL is whitespace-insensitive and has no line-spanning literals).
split_statements() {
@ -163,6 +186,46 @@ print_manual_recovery() {
echo " npx prisma migrate resolve --applied $(shell_quote "$name") # only after every statement above succeeds"
}
# Copy-paste recovery for an interrupted bare CREATE INDEX CONCURRENTLY. An
# aborted concurrent build leaves an INVALID index of the same name, so a plain
# re-run of the migration fails with "already exists"; the INVALID index must be
# dropped first. Then clear the failed record so the next deploy re-applies the
# migration natively (single-statement CONCURRENTLY needs no out-of-band run).
print_bare_create_recovery() {
name="$1"
sql="$2"
idx="$(grep -Ei 'CREATE[[:space:]]+(UNIQUE[[:space:]]+)?INDEX[[:space:]]+CONCURRENTLY' "$sql" |
grep -oE '"[^"]+"' | head -n1 | tr -d '"')"
echo ""
echo "Manual recovery for $name (interrupted bare CREATE INDEX CONCURRENTLY, copy-paste):"
if [ -n "$idx" ]; then
echo " printf '%s\\n' $(shell_quote "DROP INDEX CONCURRENTLY IF EXISTS \"$idx\";") | npx prisma db execute --schema $SCHEMA --stdin"
else
echo " # Drop any INVALID index left by the interrupted build (see $sql), e.g.:"
echo " # DROP INDEX CONCURRENTLY IF EXISTS \"<index_name>\";"
fi
echo " npx prisma migrate resolve --rolled-back $(shell_quote "$name")"
echo " # Then re-run the deploy; $name re-applies natively."
}
# Print copy-paste recovery for an INTERRUPTED CONCURRENTLY index build (a
# migrate step aborted by a timeout SIGTERM, OOM, or external stop), if — and
# only if — the failing migration is one. An aborted CONCURRENTLY build leaves
# an INVALID index of the target name, so a plain re-run cannot rebuild it. This
# only ever prints guidance; it never resolves a migration, and a non-index or
# unidentifiable failure prints nothing. Safe to call from any failure branch.
emit_interrupted_recovery_hint() {
hint_name="$(parse_failing_migration)"
[ -n "$hint_name" ] || return 0
hint_sql="$(migration_sql_path "$hint_name")"
if is_bare_create_concurrently "$hint_sql"; then
print_bare_create_recovery "$hint_name" "$hint_sql"
elif is_recoverable_concurrently_migration "$hint_sql"; then
echo ""
echo "$hint_name is an auto-recoverable CONCURRENTLY migration; re-run the deploy to finish it (the re-run drops any INVALID index and rebuilds)."
fi
}
fail_loudly() {
echo ""
echo "ERROR: $1"
@ -215,7 +278,13 @@ while :; do
exit 0
fi
if [ "$MIGRATE_STATUS" -eq 124 ]; then
fail_loudly "prisma migrate deploy timed out after ${STEP_TIMEOUT}s (a long-running transaction may be blocking CREATE/DROP INDEX CONCURRENTLY)." 1
# This branch also catches a normalized 143 (with_timeout maps BusyBox's
# SIGTERM exit to 124), i.e. the incident's own signal. A timed-out/aborted
# CONCURRENTLY build leaves an INVALID index + a failed record, so raising
# the timeout alone will not let a plain re-run rebuild it — surface the
# drop-index recovery here so the FIRST failure is actionable.
emit_interrupted_recovery_hint
fail_loudly "prisma migrate deploy timed out after ${STEP_TIMEOUT}s (a long-running transaction may be blocking CREATE/DROP INDEX CONCURRENTLY). Clear the blocker, then raise MIGRATION_TIMEOUT (it forwards to MIGRATE_STEP_TIMEOUT) and re-run." 1
fi
attempt=$((attempt + 1))
@ -224,6 +293,14 @@ while :; do
fi
if ! is_transaction_block_failure && ! is_stuck_failed_migration; then
# A non-P3018/P3009 exit is usually a genuine error (bad SQL, unreachable
# DB), but OOM (137) or another non-timeout kill can also abort an in-flight
# CONCURRENTLY build before Prisma records the failure. (A timeout SIGTERM is
# normalized to 124 above and handled there — it never reaches here.) Surface
# the drop-index recovery when the in-flight migration is a CONCURRENTLY
# build so the FIRST failure is actionable (deploy.sh promises "recovery
# steps above"); guidance only, never auto-resolves.
emit_interrupted_recovery_hint
fail_loudly "prisma migrate deploy failed (exit $MIGRATE_STATUS)."
fi
@ -234,6 +311,9 @@ while :; do
sql="$(migration_sql_path "$name")"
if ! is_recoverable_concurrently_migration "$sql"; then
if is_bare_create_concurrently "$sql"; then
print_bare_create_recovery "$name" "$sql"
fi
fail_loudly "$name is not a recoverable drop-then-create CONCURRENTLY index migration (a bare CREATE is intentionally fail-loud); refusing to auto-resolve."
fi

View file

@ -75,6 +75,16 @@ case "$sub" in
echo "The \\\`$m\\\` migration started at 2026-05-15 failed"
[ -n "\${FAKE_DECOY:-}" ] && echo "Applying migration \\\`\$FAKE_DECOY\\\`"
;;
INTERRUPT)
# A CONCURRENTLY build killed mid-apply (external SIGTERM/OOM):
# the migration name is visible in the "Applying" line, but no
# P3018/P3009 gate marker is emitted and the process exits with
# a non-gate code (137 stands in for any external kill; a raw
# 143 would be normalized to the timeout branch instead).
echo "Applying migration \\\`$m\\\`"
echo "Terminated"
exit 137
;;
*)
echo "Error: P1001"
echo "Can't reach database server"
@ -221,6 +231,99 @@ describe('migrate-deploy.sh generic CONCURRENTLY recovery', () => {
expect(r.resolveApplied).toEqual([]);
});
it('prints copy-paste recovery for a stuck bare CREATE INDEX CONCURRENTLY', () => {
// An interrupted bare CREATE (e.g. a step timeout) leaves the migration
// failed (P3009) and an INVALID index of the same name; the loud failure
// must tell the operator to drop it and roll the record back — never
// auto-resolve it.
const bare = '20260701000000_add_bare_concurrent_index';
const bareSql = `CREATE INDEX CONCURRENTLY "operations_bare_idx"
ON "operations"("user_id", "server_seq");`;
writeMigration(bare, bareSql);
const r = run({ FAKE_FAIL: bare, FAKE_CODE: 'P3009' });
expect(r.status).not.toBe(0);
expect(r.stdout).toContain('not a recoverable drop-then-create');
expect(r.stdout).toContain(
'DROP INDEX CONCURRENTLY IF EXISTS "operations_bare_idx";',
);
expect(r.stdout).toContain(`migrate resolve --rolled-back '${bare}'`);
expect(r.resolveApplied).toEqual([]);
expect(r.resolveRolledBack).toEqual([]);
});
it('reports a BusyBox timeout (exit 143) as a timeout, not a generic failure', () => {
// node:*-alpine ships BusyBox `timeout`, which returns 128+SIGTERM=143 on
// expiry (GNU coreutils returns 124). A fake `timeout` on PATH reproduces
// that: run the wrapped command, then exit 143 as if the step was TERMed.
// migrate-deploy.sh must normalize this to its timeout branch.
const fakeTimeout = join(binDir, 'timeout');
writeFileSync(fakeTimeout, '#!/bin/sh\nshift\n"$@"\nexit 143\n');
chmodSync(fakeTimeout, 0o755);
const r = run({ FAKE_FAIL: '', FAKE_CODE: 'P3018' });
expect(r.status).not.toBe(0);
expect(r.stdout).toContain('timed out after');
expect(r.resolveApplied).toEqual([]);
});
it('prints bare-create recovery when a normalized-143 timeout aborts a bare CONCURRENTLY build (the incident)', () => {
// The reported incident: a bare CREATE INDEX CONCURRENTLY killed by the
// in-image step timeout (BusyBox SIGTERM -> 143 -> normalized to the 124
// timeout branch). That branch must ALSO print the drop-INVALID-index
// recovery, because raising the timeout alone cannot rebuild an INVALID
// index left by the aborted build.
const fakeTimeout = join(binDir, 'timeout');
writeFileSync(fakeTimeout, '#!/bin/sh\nshift\n"$@"\nexit 143\n');
chmodSync(fakeTimeout, 0o755);
const bare = '20260701000000_add_bare_concurrent_index';
const bareSql = `CREATE INDEX CONCURRENTLY "operations_bare_idx"
ON "operations"("user_id", "server_seq");`;
writeMigration(bare, bareSql);
const r = run({ FAKE_FAIL: bare, FAKE_CODE: 'INTERRUPT' });
expect(r.status).not.toBe(0);
expect(r.stdout).toContain('timed out after');
expect(r.stdout).toContain(
'DROP INDEX CONCURRENTLY IF EXISTS "operations_bare_idx";',
);
expect(r.stdout).toContain(`migrate resolve --rolled-back '${bare}'`);
expect(r.resolveApplied).toEqual([]);
expect(r.resolveRolledBack).toEqual([]);
});
it('surfaces bare-create recovery when a CONCURRENTLY build is interrupted (non-gate exit)', () => {
// The user's incident: a bare CREATE INDEX CONCURRENTLY killed mid-build
// exits with a non-P3018/P3009 code before Prisma records the failure. The
// first failure must still print copy-paste recovery for the INVALID index
// (drop it, roll the record back), never a bare exit code.
const bare = '20260701000000_add_bare_concurrent_index';
const bareSql = `CREATE INDEX CONCURRENTLY "operations_bare_idx"
ON "operations"("user_id", "server_seq");`;
writeMigration(bare, bareSql);
const r = run({ FAKE_FAIL: bare, FAKE_CODE: 'INTERRUPT' });
expect(r.status).not.toBe(0);
expect(r.stdout).toContain(
'DROP INDEX CONCURRENTLY IF EXISTS "operations_bare_idx";',
);
expect(r.stdout).toContain(`migrate resolve --rolled-back '${bare}'`);
// Guidance only — the interrupted migration must never be auto-resolved.
expect(r.resolveApplied).toEqual([]);
expect(r.resolveRolledBack).toEqual([]);
});
it('hints a re-run when an auto-recoverable CONCURRENTLY migration is interrupted', () => {
writeMigration(ENCRYPTED_OPS, ENCRYPTED_OPS_SQL);
const r = run({ FAKE_FAIL: ENCRYPTED_OPS, FAKE_CODE: 'INTERRUPT' });
expect(r.status).not.toBe(0);
expect(r.stdout).toContain('re-run the deploy to finish it');
expect(r.resolveApplied).toEqual([]);
expect(r.resolveRolledBack).toEqual([]);
});
it('does NOT mark applied when an out-of-band statement fails', () => {
writeMigration(ENCRYPTED_OPS, ENCRYPTED_OPS_SQL);
const r = run({

View file

@ -217,7 +217,15 @@ describe('performance migrations', () => {
expect(deployScript).toContain('jq is required');
expect(deployScript).toContain('docker compose config --format json failed');
expect(deployScript).toContain('docker image inspect');
expect(deployScript).toContain('run --rm --no-deps --interactive=false -T supersync');
expect(deployScript).toContain(
'run --rm --no-deps --interactive=false -T -e MIGRATE_STEP_TIMEOUT=$MIGRATE_STEP_TIMEOUT supersync',
);
// The host forwards its migration budget into the image so the in-image
// per-step timeout can't silently cap a large MIGRATION_TIMEOUT at the
// image default (1800s) and kill a slow CREATE INDEX CONCURRENTLY early.
expect(deployScript).toContain(
'MIGRATE_STEP_TIMEOUT="${MIGRATE_STEP_TIMEOUT:-$((MIGRATION_TIMEOUT',
);
expect(deployScript).toContain('prisma db execute');
expect(deployScript).toContain(migrationCommand);
expect(deployScript).toContain('Migrator container started');