fix(migrations): retry a marked migration that lost a deadlock

A marked migration's DO block holds the locks it takes until it commits,
so an app transaction taking two of its tables in the other order can
deadlock with it. The block then rolled back whole, exactly as on a lock
timeout, so the boot retries 40P01 for marked migrations as it does 55P03.
Corrects 0415's note that the drops hold their lock for an instant.

docs/ops/deploy.md

@@ -68,6 +68,11 @@ Database error code: 55P03
 HealthLog: migration 0412_measurement_hot_updates timed out waiting for a lock (55P03) and changed nothing; marking it rolled back and retrying in 15s (retry 1 of 5).
 ```
 
+A marked migration that loses a deadlock against an app transaction
+(`Database error code: 40P01`) is in the same state, its block rolled back
+whole, and is handled the same way; the entrypoint's line then says
+`was cancelled in a deadlock (40P01)`.
+
 What happens on its own: such a migration is written so that a timed-out
 attempt changes nothing, and it says so in its file
 (`-- @retry-on-lock-timeout`). The entrypoint then marks that one migration

prisma/migrations/0415_foreign_key_and_prefix_indexes/migration.sql

@@ -20,13 +20,19 @@
 --
 -- Lock wait. `CREATE INDEX` takes SHARE on its table (reads go on, writes
 -- wait while it builds; every table here is small, so the build is quick)
--- and `DROP INDEX` takes ACCESS EXCLUSIVE for the instant the catalog
--- changes. `CREATE INDEX CONCURRENTLY` cannot share a migration file with
--- any other statement (0416), so the whole set runs in one `DO` block: one
--- statement that commits or rolls back whole, with the lock wait bounded at
--- five seconds so a long reader cannot queue the tables' writes behind the
--- migration. Every statement is `IF [NOT] EXISTS`, so a lock timeout leaves
--- the file safe to apply again, which the marker declares
+-- and `DROP INDEX` takes ACCESS EXCLUSIVE. `CREATE INDEX CONCURRENTLY`
+-- cannot share a migration file with any other statement, so the whole set
+-- runs in one `DO` block: one statement that commits or rolls back whole,
+-- with each lock wait bounded at five seconds so a long reader cannot queue
+-- the tables' writes behind the migration. Inside the block every lock is
+-- held until it commits, not just while its statement runs: the SHARE locks
+-- of the builds stay through the drops, and the drops come last so their
+-- ACCESS EXCLUSIVE locks are held only for the rest of the block. An app
+-- transaction that takes two of these tables in the other order can
+-- therefore deadlock with it; Postgres cancels one side, and when that is the
+-- migration its block has rolled back whole, as on a lock timeout. Every
+-- statement is `IF [NOT] EXISTS`, so either failure leaves the file safe to
+-- apply again, which the marker declares and the boot acts on for both
 -- (docs/ops/deploy.md, "A migration that timed out on a lock").
 --
 -- @retry-on-lock-timeout

scripts/__tests__/migrate-deploy.test.ts

@@ -47,6 +47,11 @@ const P3018_UNIQUE = P3018_LOCK.replace("55P03", "23505").replace(
   'duplicate key value violates unique constraint "x"',
 );
 
+const P3018_DEADLOCK = P3018_LOCK.replace("55P03", "40P01").replace(
+  "canceling statement due to lock timeout",
+  "deadlock detected",
+);
+
 const P3009 = `Error: P3009
 
 migrate found failed migrations in the target database, new migrations will not be applied. Read more about how to resolve migration issues in a production database: https://pris.ly/d/migrate-resolve
@@ -78,7 +83,11 @@ describe("which failure is retried", () => {
         failedRows: null,
         readMigration: reader(MARKED),
       }),
-    ).toEqual({ retry: true, migration: "0412_measurement_hot_updates" });
+    ).toEqual({
+      retry: true,
+      migration: "0412_measurement_hot_updates",
+      code: "55P03",
+    });
   });
 
   it("does not retry a lock timeout of an unmarked migration", () => {
@@ -93,6 +102,31 @@ describe("which failure is retried", () => {
     });
   });
 
+  it("retries a deadlock of a marked migration, which rolled back whole", () => {
+    expect(lockTimeoutInReport(P3018_DEADLOCK)).toBe(
+      "0412_measurement_hot_updates",
+    );
+    expect(
+      decideLockRetry({
+        output: P3018_DEADLOCK,
+        failedRows: null,
+        readMigration: reader(MARKED),
+      }),
+    ).toEqual({
+      retry: true,
+      migration: "0412_measurement_hot_updates",
+      code: "40P01",
+    });
+    // Unmarked, a deadlock stays fatal like a lock timeout.
+    expect(
+      decideLockRetry({
+        output: P3018_DEADLOCK,
+        failedRows: null,
+        readMigration: reader(UNMARKED),
+      }).retry,
+    ).toBe(false);
+  });
+
   it("does not retry any other database error", () => {
     expect(
       decideLockRetry({
@@ -123,7 +157,11 @@ describe("which failure is retried", () => {
         failedRows,
         readMigration: reader(MARKED),
       }),
-    ).toEqual({ retry: true, migration: "0412_measurement_hot_updates" });
+    ).toEqual({
+      retry: true,
+      migration: "0412_measurement_hot_updates",
+      code: "55P03",
+    });
     // A stored failure of another kind stays fatal.
     expect(
       decideLockRetry({
@@ -295,6 +333,24 @@ process.exit(0);
     expect(result.stdout).toContain("timed out waiting for a lock (55P03)");
   });
 
+  it("does the same for a deadlock, and names it", () => {
+    const { run, calls } = setup(
+      [
+        [1, P3018_DEADLOCK],
+        [0, "All migrations have been successfully applied."],
+      ],
+      MARKED,
+    );
+    const result = run();
+    expect(result.status).toBe(0);
+    expect(calls()).toEqual([
+      "migrate deploy --schema x",
+      "migrate resolve --rolled-back 0412_measurement_hot_updates --schema x",
+      "migrate deploy --schema x",
+    ]);
+    expect(result.stdout).toContain("was cancelled in a deadlock (40P01)");
+  });
+
   it("gives up after the last delay with Prisma's exit code", () => {
     const { run, calls } = setup(
       [

scripts/migrate-deploy.mjs

@@ -21,9 +21,15 @@
  * back whole. `src/__tests__/migration-lock-timeout-guard.test.ts` holds the
  * migrations to that.
  *
- * So: on a 55P03 failure of a migration carrying the marker, mark that one
- * migration rolled back and run `migrate deploy` again after a backoff (15,
- * 30, 60, 120, 240 seconds). Any other failure, a lock timeout of a migration
+ * A deadlock (40P01) is the same failure seen from the other side: a marked
+ * migration's `DO` block holds the locks it took until it commits, and an app
+ * transaction that took two of the same tables in the other order makes
+ * Postgres cancel one of the two. When the migration is the one cancelled,
+ * its block rolled back whole, exactly as on a lock timeout.
+ *
+ * So: on a 55P03 or 40P01 failure of a migration carrying the marker, mark
+ * that one migration rolled back and run `migrate deploy` again after a
+ * backoff (15, 30, 60, 120, 240 seconds). Any other failure, a lock timeout of a migration
  * without the marker, or a fifth lock timeout in a row, ends the boot with
  * Prisma's exit code exactly as before. The failure is read from Prisma's
  * own report (`Migration name:` and `Database error code:`), or, on a boot
@@ -58,20 +64,27 @@ const DEFAULT_RETRY_DELAYS_S = [15, 30, 60, 120, 240];
 /** The line a migration carries when a lock-timeout retry is safe for it. */
 export const RETRY_MARKER = /^--\s*@retry-on-lock-timeout\s*$/m;
 
-const LOCK_TIMEOUT = "55P03";
+/** Lock timeout and deadlock: both leave a marked migration unapplied. */
+const LOCK_FAILURES = new Set(["55P03", "40P01"]);
 const TIME_ZONE_OPTION = "-c TimeZone=UTC";
 const MIGRATION_NAME = /^[A-Za-z0-9_]+$/;
 
+/** The SQLSTATE a P3018 report gives, or null. */
+export function errorCodeInReport(text) {
+  if (typeof text !== "string") return null;
+  return /^Database error code: (\S+)\s*$/m.exec(text)?.[1] ?? null;
+}
+
 /**
- * The migration a P3018 report says failed on a lock timeout, or null.
- * Prisma prints `Migration name: <name>` and `Database error code: <state>`
- * for a migration that failed to apply.
+ * The migration a P3018 report says failed on a lock (a lock timeout or a
+ * deadlock), or null. Prisma prints `Migration name: <name>` and
+ * `Database error code: <state>` for a migration that failed to apply.
  */
 export function lockTimeoutInReport(text) {
   if (typeof text !== "string") return null;
   const name = /^Migration name: (\S+)\s*$/m.exec(text)?.[1];
-  const code = /^Database error code: (\S+)\s*$/m.exec(text)?.[1];
-  return name && code === LOCK_TIMEOUT ? name : null;
+  const code = errorCodeInReport(text);
+  return name && code !== null && LOCK_FAILURES.has(code) ? name : null;
 }
 
 /** Whether Prisma refused to start because a failed migration is on record. */
@@ -89,14 +102,16 @@ function isFailedMigrationOnRecord(output) {
  *   when they were not read
  * @param {(name: string) => string | null} input.readMigration
  *   the migration's SQL, or null when the image does not ship it
- * @returns {{ retry: true, migration: string } | { retry: false, reason: string }}
+ * @returns {{ retry: true, migration: string, code: string } | { retry: false, reason: string }}
  */
 export function decideLockRetry({ output, failedRows, readMigration }) {
   let migration = lockTimeoutInReport(output);
+  let code = migration ? errorCodeInReport(output) : null;
   if (!migration && isFailedMigrationOnRecord(output) && failedRows) {
     // More than one failed row is not a state this boot can reason about.
     if (failedRows.length === 1) {
       migration = lockTimeoutInReport(failedRows[0].logs);
+      code = migration ? errorCodeInReport(failedRows[0].logs) : null;
     }
   }
   if (!migration) {
@@ -115,7 +130,7 @@ export function decideLockRetry({ output, failedRows, readMigration }) {
       reason: `${migration} timed out on a lock but is not marked safe to re-run`,
     };
   }
-  return { retry: true, migration };
+  return { retry: true, migration, code };
 }
 
 /** The backoff schedule, from the environment or the default. */
@@ -272,9 +287,13 @@ async function main({
       return deploy.code;
     }
     const delay = delays[attempt];
+    const cause =
+      decision.code === "40P01"
+        ? "was cancelled in a deadlock (40P01)"
+        : "timed out waiting for a lock (55P03)";
     console.log(
-      `HealthLog: migration ${decision.migration} timed out waiting for a lock ` +
-        `(55P03) and changed nothing; marking it rolled back and retrying in ` +
+      `HealthLog: migration ${decision.migration} ${cause} ` +
+        `and changed nothing; marking it rolled back and retrying in ` +
         `${delay}s (retry ${attempt + 1} of ${delays.length}).`,
     );
     const resolve = await runPrisma(cli, [