v0.154.0
  1"""One session-level advisory lock serializing schema-changing commands.
  2
  3`plain postgres sync`, `plain migrations apply`, `plain postgres converge`,
  4and `plain postgres drop-unknown-tables` all take the same lock, so concurrent
  5processes (a retried migrate Job, two operators, overlapping release phases)
  6can't interleave schema changes.
  7
  8The lock is held on a dedicated connection, separate from the connection the
  9DDL runs on. Session-level advisory locks aren't bound to a transaction, so
 10non-transactional DDL (CREATE INDEX CONCURRENTLY, VALIDATE CONSTRAINT) runs
 11freely on the working connection while the lock connection just sits there
 12holding it. If the process dies, the session closes and Postgres releases the
 13lock automatically — no stale-lock cleanup step.
 14
 15Advisory locks are per-database, so parallel test databases and multi-tenant
 16clusters don't contend.
 17"""
 18
 19from __future__ import annotations
 20
 21import time
 22from collections.abc import Callable, Iterator
 23from contextlib import contextmanager
 24
 25import psycopg
 26
 27from plain.exceptions import ImproperlyConfigured
 28from plain.logs import get_framework_logger
 29from plain.runtime import settings
 30
 31from .db import get_connection
 32from .sources import build_connection_params
 33
 34logger = get_framework_logger()
 35
 36# Guards against nested schema_lock() in the same process, which would block
 37# on itself until the retry budget ran out (each entry is its own database
 38# session, so Postgres sees two different lock requesters). Commands are
 39# single-threaded, so a module flag is enough.
 40_held_by_this_process = False
 41
 42# Fixed key so every version of Plain computes the same value (mixed-version
 43# deploys must contend on the same lock). Derived once from the lock's name —
 44# zlib.crc32(b"plain/schema") — and frozen as a literal. The name identifies
 45# the concept, not this module, so it stays true if the code moves; any future
 46# Plain advisory lock should follow the same crc32(b"plain/<lock-name>")
 47# convention. Debuggable directly:
 48#   SELECT * FROM pg_locks WHERE locktype = 'advisory' AND objid = 1047265496
 49SCHEMA_LOCK_KEY = 1047265496
 50
 51
 52class SchemaLockTimeout(Exception):
 53    """The schema advisory lock couldn't be acquired within the retry budget."""
 54
 55
 56class SchemaLockLost(Exception):
 57    """The lock session died mid-hold, so the lock may now be held elsewhere."""
 58
 59
 60@contextmanager
 61def schema_lock() -> Iterator[Callable[[], None]]:
 62    """Hold the schema advisory lock for the duration of the block.
 63
 64    Acquisition is non-blocking with retry (`pg_try_advisory_lock`), so a
 65    dead lock holder surfaces as a clear timeout instead of hanging forever.
 66    Retry behavior is controlled by `POSTGRES_SCHEMA_LOCK_RETRY_INTERVAL` and
 67    `POSTGRES_SCHEMA_LOCK_MAX_RETRIES`.
 68
 69    Yields a verify callable: it raises `SchemaLockLost` if the lock session
 70    has died (the lock releases with it, so another process may now hold it).
 71    Multi-phase callers check it between phases — losing the lock mid-phase
 72    is left to the environment guidance in the README (keepalives are enabled;
 73    don't set `idle_session_timeout` on the management role).
 74
 75    Not reentrant: a nested `schema_lock()` raises immediately (it would open
 76    a second session and block on the outer one). Commands take the lock once,
 77    at the top.
 78    """
 79    global _held_by_this_process
 80    if _held_by_this_process:
 81        raise RuntimeError(
 82            "Schema lock is already held by this process — schema_lock() is "
 83            "not reentrant. Take the lock once, at the top of the command."
 84        )
 85
 86    config = get_connection().settings_dict
 87    params = build_connection_params(config)
 88    # The lock connection sits idle while DDL runs elsewhere — TCP keepalives
 89    # stop NAT/LB idle timeouts from silently killing it (and the lock with it).
 90    params["keepalives"] = 1
 91    params["keepalives_idle"] = 30
 92    params["keepalives_interval"] = 10
 93    params["keepalives_count"] = 3
 94
 95    retry_interval: float = settings.POSTGRES_SCHEMA_LOCK_RETRY_INTERVAL
 96    max_retries: int = settings.POSTGRES_SCHEMA_LOCK_MAX_RETRIES
 97    if retry_interval <= 0:
 98        raise ImproperlyConfigured(
 99            "POSTGRES_SCHEMA_LOCK_RETRY_INTERVAL must be greater than 0 "
100            f"(got {retry_interval!r})."
101        )
102    # Warn immediately, then re-warn about once a minute so a long wait
103    # reads as "still waiting" in deploy logs, not a hang.
104    warn_every = max(1, round(60 / retry_interval))
105
106    with psycopg.connect(**params, autocommit=True) as lock_conn:
107        attempts = 0
108        while True:
109            row = lock_conn.execute(
110                "SELECT pg_try_advisory_lock(%s)", [SCHEMA_LOCK_KEY]
111            ).fetchone()
112            assert row is not None
113            if row[0]:
114                break
115
116            attempts += 1
117            # Sleeps happen after this counter bumps, so the elapsed wait is
118            # one interval behind the attempt count.
119            waited_seconds = round((attempts - 1) * retry_interval)
120            if attempts == 1 or attempts % warn_every == 0:
121                logger.warning(
122                    "Waiting for schema lock held by another process",
123                    extra={
124                        "context": {
125                            "holder": _describe_holder(lock_conn),
126                            "waited_seconds": waited_seconds,
127                        }
128                    },
129                )
130            if attempts >= max_retries:
131                raise SchemaLockTimeout(
132                    f"Could not acquire the schema lock after {attempts} attempt(s) "
133                    f"({waited_seconds}s). Another process is running schema "
134                    f"changes: {_describe_holder(lock_conn)}. If that process "
135                    "is gone, its lock releases when its database session closes."
136                )
137            time.sleep(retry_interval)
138
139        def verify() -> None:
140            """Raise SchemaLockLost if the lock session is no longer alive."""
141            try:
142                lock_conn.execute("SELECT 1")
143            except psycopg.Error as e:
144                raise SchemaLockLost(
145                    "The schema lock session died while work was running, so "
146                    "the lock has been released and another process may now be "
147                    "making schema changes. Stopping here — re-run the command."
148                ) from e
149
150        _held_by_this_process = True
151        try:
152            yield verify
153        finally:
154            _held_by_this_process = False
155            # No explicit pg_advisory_unlock: closing the session (the
156            # `with psycopg.connect(...)` exit below) releases the lock, and
157            # an unlock attempt on a connection that died mid-block would
158            # raise here and mask the block's real exception.
159
160
161def _describe_holder(lock_conn: psycopg.Connection) -> str:
162    """Best-effort description of the session currently holding the lock."""
163    # A bigint advisory key shows up in pg_locks split across classid
164    # (high half) and objid (low half), with objsubid = 1.
165    row = lock_conn.execute(
166        """
167        SELECT l.pid, a.application_name, a.usename, a.query_start
168        FROM pg_locks l
169        LEFT JOIN pg_stat_activity a ON a.pid = l.pid
170        WHERE l.locktype = 'advisory'
171          AND l.classid = %s
172          AND l.objid = %s
173          AND l.objsubid = 1
174          AND l.granted
175          AND l.database = (
176            SELECT oid FROM pg_database WHERE datname = current_database()
177          )
178        LIMIT 1
179        """,
180        [SCHEMA_LOCK_KEY >> 32, SCHEMA_LOCK_KEY & 0xFFFFFFFF],
181    ).fetchone()
182
183    if row is None:
184        return "no holder found (it may have just released)"
185
186    pid, application_name, usename, query_start = row
187    details = [f"pid={pid}"]
188    if application_name:
189        details.append(f"application={application_name}")
190    if usename:
191        details.append(f"user={usename}")
192    if query_start:
193        details.append(f"since={query_start:%Y-%m-%d %H:%M:%S}")
194    return ", ".join(details)