supabase: `prisma migrate dev` sometimes times out (postgres advisory lock)

Question

I have a supabase database (postgres 15.1.0.88) and I'm using prisma as ORM(latest version [email protected]). When trying to apply migrations with prisma migrate dev, the command most of the times returns a timeout error message saying Timed out trying to acquire a postgres advisory lock

pnpm prisma migrate dev results in:

Error: Error: P1002

The database server at `db.***.supabase.co`:`5432` was reached but timed out.

Please try again.

Please make sure your database server is running at `db.***.supabase.co`:`5432`.

Context: Timed out trying to acquire a postgres advisory lock (SELECT pg_advisory_lock(72707369)). Elapsed: 10000ms. See https://pris.ly/d/migrate-advisory-locking for details.

In the logs on supabase I also get this error message, but not sure if it's related to my error:

Event message
relation "_prisma_migrations" does not exist
Severity
ERROR

Timestamp
2023-06-11T09:48:31.165Z

Postgres Username
postgres

Session ID
***

Metadata
{
  "file": null,
  "host": "***",
  "metadata": [],
  "parsed": [
    {
      "application_name": null,
      "backend_type": "client backend",
      "command_tag": "PARSE",
      "connection_from": "***",
      "context": null,
      "database_name": "postgres",
      "detail": null,
      "error_severity": "ERROR",
      "hint": null,
      "internal_query": null,
      "internal_query_pos": null,
      "leader_pid": null,
      "location": null,
      "process_id": 17257,
      "query": "SELECT \"id\", \"checksum\", \"finished_at\", \"migration_name\", \"logs\", \"rolled_back_at\", \"started_at\", \"applied_steps_count\" FROM \"_prisma_migrations\" ORDER BY \"started_at\" ASC",
      "query_id": 0,
      "query_pos": 126,
      "session_id": "***",
      "session_line_num": 4,
      "session_start_time": "2023-06-11 09:48:30 UTC",
      "sql_state_code": "42P01",
      "timestamp": "2023-06-11 09:48:31.165 UTC",
      "transaction_id": 0,
      "user_name": "postgres",
      "virtual_transaction_id": "12/1941"
    }
  ],
  "parsed_from": null,
  "project": null,
  "source_type": null
}

Then, ~2:03 Minutes later, I get 2 more error messages in the supabase postgres logs:

• connection to client lost
• canceling statement due to statement timeout (<- for the SELECT pg_advisory_lock(72707369) command)

When I then wait some time, the command works again, once or even a few times. The same also happens with prisma migrate reset

Answer 1

Prisma uses a PostgreSQL advisory lock with the magic number ID 72707369 that blocks a new migration if the previous one is still connected and idle. This kind of lock only releases when the connection is fully closed and removed from the table pg_stat_activity (an internal PostgreSQL table that shows all active and idle connections in the current instance).

There is another table, pg_lock that contains all the locks, and with a simple SELECT query, you can find in the objid column the lock with the magic number 72707369.

So, the following query must be run every time you do a migration with Prisma (specifically, after the migration step):

SELECT pg_terminate_backend(PSA.pid)
FROM pg_locks AS PL
    INNER JOIN pg_stat_activity AS PSA ON PSA.pid = PL.pid
WHERE PSA.state LIKE 'idle'
    AND PL.objid IN (72707369);

pg_terminate_backend drops the connection and releases every associated lock. This is hardcoded to the magic number of the Prisma lock, because we don't want to drop every current idle connection.

For more information:

• Prisma Migrate: Advisory Locking
• PostgreSQL 9.27.2: Server Signaling Functions
• PostgreSQL 13.3.5: Advisory Locks
• PostgreSQL 54.12: pg_locks