fix(migrations): retire the measurements prefix index without waiting at boot

0416 ran DROP INDEX CONCURRENTLY at boot, which waits without bound for
every transaction on the table; a pg_dump or a backfill outlasted the
start period and the next boot stopped at P3009. The migration now tries
a plain drop with a two-second lock wait and tolerates the timeout, and
the nightly measurement maintenance drops what is left concurrently under
a bounded wait, retrying the next night. A fresh or shadow database takes
the lock at once, so the history still ends where the schema does. The
guard refuses a concurrent drop in a migration and ties every retired
index to a tolerant one.
This commit is contained in:
Marc-André Bombeck committed 2026-10-20 16:06:10 +02:00
1 parent a275a5bb65
commit 2b81b4f23e
5 files changed
+388 -19

No files matched your search

+59 -1
View File
@@ -151,7 +151,8 @@ SELECT pg_size_pretty(pg_total_relation_size('measurements')) AS total,
## The nightly check
Since v1.43.7 the same queue also runs by itself at 03:40 (Europe/Berlin).
That run names no steps and changes nothing: vacuuming the table is
That run names no steps and changes nothing beyond dropping a retired index
(next section): vacuuming the table is
autovacuum's job, which migration 0412 starts at 5 % dead rows instead of
Postgres's 20 %. The check reads the table's live and dead rows and warns
(`maintenance_autovacuum_behind` on the wide event) when there are at least
@@ -185,6 +186,63 @@ FROM pg_stat_user_tables WHERE relname = 'measurements';
applies to pages written after the migration; a `VACUUM FULL` after the
upgrade applies it to the whole table.
## Retired indexes
An index the schema no longer declares has to leave the database too, and on
`measurements` the obvious migration is the wrong one. A plain `DROP INDEX`
needs an exclusive lock on the table; `DROP INDEX CONCURRENTLY` blocks nobody
but waits, without limit, for every transaction already running on the
table. A migration runs at boot, so either one waits for whatever holds the
table (a `pg_dump`, a long backfill, a `VACUUM FULL`); past the container's
start period the container is replaced with the migration half done, and the
next boot stops at `P3009` until someone runs `prisma migrate resolve`.
So an index is retired in two halves (v1.43.8, migration 0416, for
`measurements_user_id_type_measured_at_idx`):
1. The migration tries a plain `DROP INDEX IF EXISTS` inside a `DO` block with
a two-second `lock_timeout` and catches the timeout
(`EXCEPTION WHEN lock_not_available`). When nothing holds the table the
index is gone at once; otherwise the migration still succeeds and the
index stays. The longest the table's other statements can wait behind the
attempt is those two seconds. A new database and Prisma's shadow database
always take the lock, so the migration history ends without the index,
exactly as the schema does, and `prisma migrate dev` / `migrate diff` see
no drift and generate nothing.
2. The index name goes into `RETIRED_MEASUREMENT_INDEXES` in
`src/lib/jobs/measurement-maintenance.ts`. Every run of this job, the
nightly 03:40 check included, drops each name still present with
`DROP INDEX CONCURRENTLY IF EXISTS`, waiting at most 60 seconds for its
locks. A run that runs out of time leaves the index (possibly marked
invalid, which the next drop finishes), sets
`maintenance_retired_index_pending` on the wide event with a warning, and
the next night tries again. The index costs writes until then, as it did
before the release; nothing reads it.
Until the job has run, the database holds one index the schema does not
declare. Nothing compares the two at runtime, and the only place they are
compared, a `migrate diff` against the migration history, never sees it. To
check by hand:
```sql
SELECT indexname FROM pg_indexes
WHERE tablename = 'measurements'
AND indexname = 'measurements_user_id_type_measured_at_idx';
```
No row: it is gone. To drop it now rather than at night, start a run from the
admin card (any steps), or run the same statement yourself:
```sql
SET lock_timeout = '60s';
DROP INDEX CONCURRENTLY IF EXISTS "measurements_user_id_type_measured_at_idx";
```
For the next large index, follow the same two halves.
`src/__tests__/migration-lock-timeout-guard.test.ts` refuses a
`DROP INDEX CONCURRENTLY` in any migration and requires every retired name to
have a migration that bounds its wait and catches the timeout.
## "could not resize shared memory segment"
Up to v1.42.0 the run could stop at once with `could not resize shared memory
@@ -1,4 +1,4 @@
-- Drop `measurements_user_id_type_measured_at_idx`.
-- Retire `measurements_user_id_type_measured_at_idx`.
--
-- `(user_id, type, measured_at)` is the leading part of the unique key
-- `(user_id, type, measured_at, source, sleep_stage)`, and live reads have
@@ -8,10 +8,28 @@
-- seeded table). The index cost every write to the densest table in the
-- schema and, on a bloated instance, more space than the table itself.
--
-- `DROP INDEX CONCURRENTLY` takes no lock that blocks reads or writes: it
-- waits for the transactions already using the index to finish and then
-- removes it. It refuses to run inside a transaction block, and under
-- `migrate deploy` it does so whenever the file holds any other statement
-- (Prisma 7 on Postgres 16 reports 25001), so this file holds exactly this
-- one statement. `IF EXISTS` makes a re-run a no-op.
DROP INDEX CONCURRENTLY IF EXISTS "measurements_user_id_type_measured_at_idx";
-- This runs at boot, so it must not wait on the table. A plain `DROP INDEX`
-- needs ACCESS EXCLUSIVE on `measurements`, held for the instant the catalog
-- changes; `DROP INDEX CONCURRENTLY` blocks nobody but waits, without bound,
-- for every transaction on the table (a pg_dump, a backfill), long enough for
-- the container to be replaced mid-migration and the next boot to stop at
-- P3009. So the drop is tried once with a two-second lock wait (the most the
-- table's other statements can queue behind the request), and a timeout is
-- swallowed: the migration then succeeds with the index still there, and
-- the nightly measurement maintenance drops it with
-- `DROP INDEX CONCURRENTLY IF EXISTS` (`RETIRED_MEASUREMENT_INDEXES` in
-- `src/lib/jobs/measurement-maintenance.ts`). A fresh database and Prisma's
-- shadow database take the lock at once, so the migration history ends
-- without the index, as the schema does. The pattern, for the next large
-- index: docs/ops/measurement-maintenance.md, "Retired indexes".
--
-- @retry-on-lock-timeout
DO $migration$
BEGIN
PERFORM set_config('lock_timeout', '2s', true);
DROP INDEX IF EXISTS "measurements_user_id_type_measured_at_idx";
EXCEPTION WHEN lock_not_available THEN
RAISE NOTICE 'measurements_user_id_type_measured_at_idx is in use; the nightly measurement maintenance drops it';
END
$migration$;
@@ -23,6 +23,8 @@ import { readdirSync, readFileSync, existsSync } from "node:fs";
import { join } from "node:path";
import { describe, expect, it } from "vitest";
import { RETIRED_MEASUREMENT_INDEXES } from "@/lib/jobs/measurement-maintenance";
import { RETRY_MARKER } from "../../scripts/migrate-deploy.mjs";
const MIGRATIONS_DIR = join(process.cwd(), "prisma", "migrations");
@@ -114,13 +116,14 @@ describe("concurrent index statements", () => {
expect(found, found.join("\n")).toEqual([]);
});
it("sees the concurrent migrations there are", () => {
const concurrent = migrations()
.filter(({ sql }) =>
/\bCONCURRENTLY\b/i.test(topLevelStatements(sql).join(";")),
)
.map(({ name }) => name);
expect(concurrent).toContain("0416_drop_measurements_type_prefix_index");
it("reads the statements there are", () => {
// No migration holds a concurrent statement since 0416 stopped dropping
// concurrently; the rule stands for the next one. A reader that stopped
// splitting statements would see none and pass, so it must see many.
const statements = migrations().flatMap(({ sql }) =>
topLevelStatements(sql),
);
expect(statements.length).toBeGreaterThan(1000);
});
it("refuses a concurrent statement beside another one", () => {
@@ -139,6 +142,58 @@ describe("concurrent index statements", () => {
});
});
/**
* `DROP INDEX CONCURRENTLY` blocks no reader or writer, but it waits without
* bound for every transaction on the table, and in a migration that wait is
* the boot's: a pg_dump or a backfill outlasts the container's start period,
* the half-applied migration is left on record, and the next boot stops at
* P3009. An index is retired instead by a bounded `DROP INDEX` that tolerates
* the timeout, finished by the nightly measurement maintenance (0416).
*/
function concurrentDropViolations(name: string, sql: string): string[] {
return topLevelStatements(sql).some((statement) =>
/^DROP INDEX CONCURRENTLY\b/i.test(statement),
)
? [`${name}: DROP INDEX CONCURRENTLY waits on the table at boot`]
: [];
}
describe("retired indexes", () => {
it("are never dropped concurrently in the boot path", () => {
const found = migrations().flatMap(({ name, sql }) =>
concurrentDropViolations(name, sql),
);
expect(found, found.join("\n")).toEqual([]);
});
it("are each dropped by a migration that bounds its wait and tolerates the timeout", () => {
expect(RETIRED_MEASUREMENT_INDEXES.length).toBeGreaterThan(0);
for (const index of RETIRED_MEASUREMENT_INDEXES) {
const owner = migrations().find(({ sql }) =>
new RegExp(`DROP INDEX IF EXISTS "${index}"`).test(sql),
);
expect(owner, index).toBeDefined();
expect(owner?.sql).toMatch(/set_config\(\s*'lock_timeout'/);
expect(owner?.sql).toMatch(/EXCEPTION WHEN lock_not_available THEN/);
}
});
it("counter-check: refuses a concurrent drop, not one in a comment", () => {
expect(
concurrentDropViolations(
"a",
'DROP INDEX CONCURRENTLY IF EXISTS "measurements_x_idx";',
),
).toHaveLength(1);
expect(
concurrentDropViolations(
"b",
'-- DROP INDEX CONCURRENTLY "x";\nDROP INDEX IF EXISTS "x";',
),
).toEqual([]);
});
});
describe("migration lock waits", () => {
it("bounds lock waits where they take effect and marks only repeatable files", () => {
const found = migrations().flatMap(({ name, sql }) =>
@@ -154,6 +209,7 @@ describe("migration lock waits", () => {
expect(marked).toContain("0412_measurement_hot_updates");
expect(marked).toContain("0414_drop_medication_compliance_rollups");
expect(marked).toContain("0415_foreign_key_and_prefix_indexes");
expect(marked).toContain("0416_drop_measurements_type_prefix_index");
});
it("catches each shape it exists to refuse", () => {
+100 -3
View File
@@ -46,6 +46,15 @@
* before the first rebuild.
* - Every step's size before and after, and its duration, are on the run's
* wide event; the totals are job facts.
*
* Retired indexes. An index the schema no longer declares is dropped by the
* migration that retires it only when the lock is there at once (a `DO`
* block with a two-second `lock_timeout` that swallows the timeout), so the
* boot never waits on a long reader of the table. Where the migration had to
* leave it, every run of this job, the nightly tick included, drops it with
* `DROP INDEX CONCURRENTLY IF EXISTS` under a bounded lock wait and tries
* again the next night if the wait runs out. Runbook:
* `docs/ops/measurement-maintenance.md`, "Retired indexes".
*/
import { Client } from "pg";
import type { Job } from "pg-boss";
@@ -153,6 +162,22 @@ export function maintenanceSessionStatements(): string[] {
});
}
/**
* Indexes on `measurements` the schema no longer declares, which a run drops
* when the migration that retired them could not. Each one's migration names
* it; `IF EXISTS` makes the drop a no-op once it is gone.
*/
export const RETIRED_MEASUREMENT_INDEXES: readonly string[] = [
// 0416: a prefix of the unique key `(user_id, type, measured_at, source,
// sleep_stage)`, which plans every query it served at the same cost.
"measurements_user_id_type_measured_at_idx",
];
/** How long a run waits for the locks that drop a retired index. */
export const RETIRED_INDEX_LOCK_TIMEOUT = "60s";
const LOCK_TIMEOUT_VALUE = /^\d{1,6}(ms|s)$/;
/** The only shape an index name may have before it is spliced into SQL. */
const INDEX_NAME = /^[a-z0-9_]{1,63}$/;
@@ -162,7 +187,7 @@ const CONCURRENT_COPY = /_ccnew\d*$|_ccold\d*$/;
const PURGE_QUEUE = "compaction-tombstone-purge";
export interface MaintenanceStep {
step: "vacuum" | "reindex" | "drop_invalid";
step: "vacuum" | "reindex" | "drop_invalid" | "drop_retired";
target: string;
bytesBefore: number;
bytesAfter: number;
@@ -336,6 +361,62 @@ async function dropInvalidCopies(
}
}
/**
* Drop every retired index still present. `DROP INDEX CONCURRENTLY` takes no
* lock that stops reads or writes, but it waits for every transaction that
* may use the index, so the wait is bounded for the statement and the
* session's own setting is put back after it. A timed-out drop may leave the
* index marked invalid; the next run's `IF EXISTS` drop finishes it.
*/
export async function dropRetiredIndexes(
db: MaintenanceConnection,
steps: MaintenanceStep[],
lockTimeout: string = RETIRED_INDEX_LOCK_TIMEOUT,
): Promise<void> {
if (!LOCK_TIMEOUT_VALUE.test(lockTimeout)) {
throw new Error(`refusing lock timeout of unexpected shape`);
}
for (const name of RETIRED_MEASUREMENT_INDEXES) {
const bytesBefore = await indexBytes(db, name);
const { rows } = await db.query<{ present: boolean }>(
`SELECT to_regclass($1) IS NOT NULL AS present`,
[name],
);
if (!rows[0]?.present) continue;
const { rows: setting } = await db.query<{ value: string }>(
`SELECT current_setting('lock_timeout') AS value`,
);
const startedAt = Date.now();
try {
await db.query(`SET lock_timeout = '${lockTimeout}'`);
await db.query(`DROP INDEX CONCURRENTLY IF EXISTS ${quoted(name)}`);
steps.push({
step: "drop_retired",
target: name,
bytesBefore,
bytesAfter: 0,
durationMs: Date.now() - startedAt,
ok: true,
});
} catch (err) {
logCaught("measurements.maintenance.drop_retired_failed", err);
steps.push({
step: "drop_retired",
target: name,
bytesBefore,
bytesAfter: await indexBytes(db, name),
durationMs: Date.now() - startedAt,
ok: false,
error: errorText(err),
});
} finally {
await db.query(`SELECT set_config('lock_timeout', $1, false)`, [
setting[0]?.value ?? "0",
]);
}
}
}
/**
* The pass itself, on a connection the caller opened with
* {@link MAINTENANCE_SESSION_OPTIONS}. Exported for the integration test.
@@ -343,7 +424,7 @@ async function dropInvalidCopies(
export async function runMeasurementMaintenance(
db: MaintenanceConnection,
payload: MaintenanceSteps,
options: { shouldStop?: () => boolean } = {},
options: { shouldStop?: () => boolean; retiredLockTimeout?: string } = {},
): Promise<MeasurementMaintenanceSummary> {
const before = await relationSizes(db);
const steps: MaintenanceStep[] = [];
@@ -359,6 +440,10 @@ export async function runMeasurementMaintenance(
indexBytesAfter: after.indexes,
});
// Every run, the nightly tick included: a retired index costs every write
// until it is gone, and the drop blocks no reader or writer.
await dropRetiredIndexes(db, steps, options.retiredLockTimeout);
if (!payload.vacuum && !payload.reindex) return summary("nothing_due");
// The queue table exists wherever a worker has started; a database without
@@ -406,7 +491,10 @@ export async function runMeasurementMaintenance(
if (payload.reindex) {
await dropInvalidCopies(db, steps);
const targets = (await measurementIndexes(db)).filter(
(index) => index.valid && !CONCURRENT_COPY.test(index.name),
(index) =>
index.valid &&
!CONCURRENT_COPY.test(index.name) &&
!RETIRED_MEASUREMENT_INDEXES.includes(index.name),
);
for (const index of targets) {
if (options.shouldStop?.()) break;
@@ -509,6 +597,15 @@ export async function handleMeasurementMaintenance(
);
}
}
const retiredLeft = result.steps.filter(
(s) => s.step === "drop_retired" && !s.ok,
);
if (retiredLeft.length > 0) {
evt.addMeta("maintenance_retired_index_pending", true);
evt.addWarning(
`retired index ${retiredLeft.map((s) => s.target).join(", ")} could not be dropped within ${RETIRED_INDEX_LOCK_TIMEOUT} (a long transaction on measurements); the next nightly run tries again`,
);
}
evt.addMeta("maintenance_table_bytes_before", result.tableBytesBefore);
evt.addMeta("maintenance_table_bytes_after", result.tableBytesAfter);
evt.addMeta("maintenance_index_bytes_before", result.indexBytesBefore);
@@ -0,0 +1,140 @@
/**
* Retiring an index on `measurements` without the boot waiting on the table.
*
* Migration 0416 drops `measurements_user_id_type_measured_at_idx` only when
* the lock is there at once and otherwise leaves it, successfully; the
* nightly measurement maintenance drops what is left with
* `DROP INDEX CONCURRENTLY IF EXISTS` under a bounded lock wait. Proven here
* against Postgres, each with the transaction that used to hold the boot:
* the migration finishes while a reader holds the table and drops the index
* once it does not; the maintenance step gives up within its wait, puts the
* session's lock timeout back, and drops the index on the next run.
*/
import { readFileSync } from "node:fs";
import { join } from "node:path";
import { Client } from "pg";
import { afterEach, beforeEach, describe, expect, it } from "vitest";
import {
MAINTENANCE_SESSION_OPTIONS,
RETIRED_MEASUREMENT_INDEXES,
runMeasurementMaintenance,
} from "@/lib/jobs/measurement-maintenance";
const INDEX = "measurements_user_id_type_measured_at_idx";
const MIGRATION = readFileSync(
join(
process.cwd(),
"prisma/migrations/0416_drop_measurements_type_prefix_index/migration.sql",
),
"utf8",
);
function connect(options?: string): Client {
const url = new URL(process.env.DATABASE_URL ?? "");
url.searchParams.delete("schema");
return new Client({ connectionString: url.toString(), options });
}
async function present(db: Client): Promise<boolean> {
const { rows } = await db.query<{ present: boolean }>(
`SELECT to_regclass($1) IS NOT NULL AS present`,
[INDEX],
);
return rows[0].present;
}
let db: Client;
let holder: Client;
beforeEach(async () => {
db = connect(MAINTENANCE_SESSION_OPTIONS);
holder = connect();
await db.connect();
await holder.connect();
// The state on an instance that has not run 0416 yet.
await db.query(
`CREATE INDEX IF NOT EXISTS "${INDEX}" ON "measurements" ("user_id", "type", "measured_at")`,
);
});
afterEach(async () => {
await holder.query("ROLLBACK").catch(() => {});
await holder.end();
await db.query(`DROP INDEX IF EXISTS "${INDEX}"`);
await db.end();
});
describe("migration 0416", () => {
it("finishes while a reader holds the table and leaves the index", async () => {
await holder.query("BEGIN");
await holder.query(`SELECT count(*) FROM "measurements"`);
const startedAt = Date.now();
await db.query(MIGRATION);
expect(Date.now() - startedAt).toBeLessThan(10_000);
expect(await present(db)).toBe(true);
});
it("counter-check: drops the index when nothing holds the table", async () => {
await db.query(MIGRATION);
expect(await present(db)).toBe(false);
// And again, as a retried boot would.
await db.query(MIGRATION);
});
});
describe("the maintenance step for a retired index", () => {
it("names the index the migration retires", () => {
expect(RETIRED_MEASUREMENT_INDEXES).toContain(INDEX);
});
it("gives up within its wait, restores the session, and drops it on the next run", async () => {
await holder.query("BEGIN");
await holder.query(
`LOCK TABLE "measurements" IN SHARE UPDATE EXCLUSIVE MODE`,
);
const blocked = await runMeasurementMaintenance(
db,
{ vacuum: false, reindex: false },
{ retiredLockTimeout: "300ms" },
);
expect(blocked.outcome).toBe("nothing_due");
expect(blocked.steps).toEqual([
expect.objectContaining({
step: "drop_retired",
target: INDEX,
ok: false,
error: expect.stringContaining("55P03"),
}),
]);
// The session's own wait (five minutes) is back for the rest of the run.
const { rows } = await db.query<{ value: string }>(
`SELECT current_setting('lock_timeout') AS value`,
);
expect(rows[0].value).toBe("5min");
await holder.query("ROLLBACK");
const next = await runMeasurementMaintenance(db, {
vacuum: false,
reindex: false,
});
expect(next.steps).toEqual([
expect.objectContaining({
step: "drop_retired",
target: INDEX,
ok: true,
}),
]);
expect(await present(db)).toBe(false);
// Gone: the run after that has nothing to do.
const after = await runMeasurementMaintenance(db, {
vacuum: false,
reindex: false,
});
expect(after.steps).toEqual([]);
});
});