BUG #19712: MultiXact Recovery Deadlock - Mailing list pgsql-bugs
| From | PG Bug reporting form |
|---|---|
| Subject | BUG #19712: MultiXact Recovery Deadlock |
| Date | |
| Msg-id | 19712-6b44bbf7f67d98e5@postgresql.org Whole thread |
| Responses |
Re: BUG #19712: MultiXact Recovery Deadlock
|
| List | pgsql-bugs |
The following bug has been logged on the website: Bug reference: 19712 Logged by: Sergi Porta Email address: sergi.porta@gmail.com PostgreSQL version: 15.18 Operating system: Oracle Linux 8.10 Description: NOTE: This is generated by an IA, I lack the amount of knowledge required to perform this analysis on this issue in this way and reach this conclusions. While creating a StandBy I had many attempts fail with same behaviour, WAL Replay hanging on some file, without any explanation, just hang up. After many attempts, finally asked the IA what was happening, it gave some commands to execute, I did it and provided it with all the answers to its questions, and this is what happened. Sorry if it's wrong. # Bug Report: Self-deadlock in `RecordNewMultiXact()` during recovery of WAL generated by pre-15.16 servers ## Summary When a PostgreSQL **15.16+** server (tested on **15.18**) performs archive recovery (via `restore_command`, e.g. pgBackRest) on WAL that was generated by a **pre-15.16** server (tested primary: **15.14**), the startup process permanently self-deadlocks the first time `RecordNewMultiXact()` needs to initialize the *next* MultiXact offset page during replay of a `multixact_redo` record. The startup process acquires `MultiXactOffsetSLRULock` in exclusive mode, then — under a compatibility branch added in 15.16 to support replay of WAL from older minor versions — calls `SimpleLruWriteAll(MultiXactOffsetCtl, false)`, which unconditionally tries to acquire the very same `ControlLock` (`MultiXactOffsetSLRULock`) again. Because `LWLock`s are not reentrant and PostgreSQL backends are single-threaded, this second acquisition can never succeed, and the process hangs forever. The hang is **fully deterministic**: it reproduces at the exact same WAL LSN across independent, from-scratch restarts of recovery (including after changing `checkpoint_timeout` / `max_wal_size` / `min_wal_size`), and is tied to replaying pre-15.16-format WAL, not to timing or resource pressure. ## Affected versions - Confirmed present: PostgreSQL **15.16, 15.17, 15.18** (the compatibility code was introduced in 15.16; absent in 15.14/15.15, per source comparison of `src/backend/access/transam/multixact.c` across tags `REL_15_14`, `REL_15_15`, `REL_15_16`, `REL_15_17`, `REL_15_18`). - Likely also affects any other major branch that received the same 15.16 fix (need to check 12–17 changelogs for the equivalent commit by Andrey Borodin, referenced below). - Not reproducible when both primary and standby run 15.14/15.15 (the compatibility branch does not exist in those versions). ## Root cause The 15.16 release notes state: > "Set next multixid's offset when creating a new multixid, to remove the > wait loop that was needed in corner cases (Andrey Borodin). The previous > logic could get stuck waiting for an update that would never occur." > — https://www.postgresql.org/docs/release/15.16/ This changed how `RecordNewMultiXact()` initializes the *next* MultiXact's offset page. To remain able to replay WAL produced by a server that predates this change, 15.16+ added a fallback/compatibility path in `RecordNewMultiXact()` (`src/backend/access/transam/multixact.c`): ```c static void RecordNewMultiXact(MultiXactId multi, MultiXactOffset offset, int nmembers, MultiXactMember *members) { ... LWLockAcquire(MultiXactOffsetSLRULock, LW_EXCLUSIVE); // (1) lock acquired ... /* hack to deal with WAL generated with older minor versions */ if (InRecovery && next_pageno != pageno) { bool init_needed; ... if (last_initialized_offsets_page == -1) { SimpleLruWriteAll(MultiXactOffsetCtl, false); // (2) called while lock (1) is held init_needed = !SimpleLruDoesPhysicalPageExist(MultiXactOffsetCtl, next_pageno); } ... ``` (See `src/backend/access/transam/multixact.c`, function `RecordNewMultiXact`, PG15.18 tag `REL_15_18`, lines ~876–970.) `SimpleLruWriteAll()` (`src/backend/access/transam/slru.c`) does: ```c void SimpleLruWriteAll(SlruCtl ctl, bool allow_redirtied) { ... LWLockAcquire(shared->ControlLock, LW_EXCLUSIVE); // (3) same lock as (1) ... ``` For `MultiXactOffsetCtl`, `shared->ControlLock` **is** `MultiXactOffsetSLRULock` — the same lock acquired at (1). Because the calling process already holds this lock exclusively, the acquisition at (3) can never succeed: no other backend can release a lock this process itself is holding. The startup process hangs indefinitely. This branch is explicitly documented to fire **"at most once after starting WAL recovery"** (per its own comment, gated by `last_initialized_offsets_page == -1`), which explains why the hang is 100% reproducible at the exact same WAL position on every fresh restart attempt, but was presumably missed in testing because it only triggers when: (a) the WAL being replayed predates 15.16, and (b) the very first MultiXact page-boundary crossing during that recovery run coincides with this compatibility branch actually needing to write/verify the next page. ## Environment - PostgreSQL (standby, exhibiting the hang): **15.18** (`/usr/pgsql-15/bin/postgres --version` → `postgres (PostgreSQL) 15.18`) - PostgreSQL (primary, WAL source): **15.14** - OS: RHEL/Oracle Linux 8 derivative, kernel `5.15.0-319.201.4.4.el8uek.x86_64` - Backup/restore tool: pgBackRest 2.58.0, S3 repository backend - Storage: AWS EBS gp3 (confirmed not a factor — see evidence below) - RAM: 256GB; `shared_buffers = 63232MB` (baseline; also tested at 64GB) - Recovery method: pgBackRest restore + `restore_command`, standard archive-based recovery (not streaming replication) ## Reproduction 1. Take a pgBackRest backup of a 15.14 primary that has active MultiXact usage (in our case, a single large transaction performing many row-level `UPDATE`s that acquire shared/multi-transaction row locks, generating a large number of new MultiXacts). 2. Restore the backup onto a host running PostgreSQL **15.16 or later** (tested 15.18) using pgBackRest's `restore_command` for archive recovery. 3. Start PostgreSQL and let it replay WAL forward. 4. Recovery reliably stalls forever at the same WAL LSN (`000000010003226B0000006E` / around LSN `3226B/6EFFF...` in our case) every single time, regardless of: - `checkpoint_timeout` (`30min` vs. `15min`) - `max_wal_size` / `min_wal_size` (`64GB`/`16GB` vs. `12GB`/`4GB`) - Full `pg_ctl stop -m immediate` + fresh restart (recovery resumes from the last completed restartpoint and still hangs at the exact same later LSN) ## Evidence collected ### 1. Startup process backtrace (hung, PID varies per attempt) ``` #0 0x00007f6f8fa0caa6 in do_futex_wait.constprop () from /lib64/libpthread.so.0 #1 0x00007f6f8fa0cb98 in __new_sem_wait_slow.constprop.0 () from /lib64/libpthread.so.0 #2 0x0000000000788772 in PGSemaphoreLock () #3 0x0000000000804d1c in LWLockAcquire () #4 0x000000000058cb88 in SimpleLruWriteAll () #5 0x0000000000586b97 in RecordNewMultiXact () #6 0x0000000000589740 in multixact_redo () #7 0x00000000005aaf58 in PerformWalRecovery () #8 0x000000000059ee5a in StartupXLOG () #9 0x00000000007968b6 in StartupProcessMain () #10 0x000000000078ccc5 in AuxiliaryProcessMain () #11 0x0000000000791cc5 in StartChildProcess () #12 0x0000000000795cd0 in PostmasterMain () #13 0x0000000000506888 in main () ``` This backtrace was captured **identically across two independent, from-scratch recovery attempts** (different PIDs, different checkpoint settings), confirming the hang is deterministic and tied to WAL content, not timing. ### 2. Proof the process is truly stalled, not just slow `/proc/<startup_pid>/io` sampled twice, ~60 seconds apart, during the hang — byte-for-byte identical, confirming zero I/O activity (no writes issued at all, not merely slow/paced writes): ``` rchar: 3922365210 wchar: 2801408015 syscr: 627045 syscw: 6505 read_bytes: 0 write_bytes: 2800066560 cancelled_write_bytes: 4026368 ``` (second sample, ~60s later: identical values) Corresponding kernel stack (`/proc/<pid>/stack`) both times: ``` [<0>] futex_wait_queue_me+0xa1/0x102 [<0>] futex_wait+0xfb/0x255 [<0>] do_futex+0x18a/0x24c [<0>] __x64_sys_futex+0x8e/0x1ec [<0>] do_syscall_64+0x35/0x87 [<0>] entry_SYSCALL_64_after_hwframe+0x6e/0x0 ``` `State: S (sleeping)` — confirmed genuinely parked, not busy/spinning. Host-level `iostat -x 10 6` (60 seconds, 10s buckets) during the hang showed **zero** reads/writes across all data volumes in every bucket, and `free -h` confirmed no memory pressure or swap usage (`Swap: 0B 0B 0B`), ruling out I/O contention or memory exhaustion as the cause. ### 3. First occurrence — checkpointer independently blocked on the same lock class In one observed instance, the checkpointer process (performing a restartpoint concurrently) was captured with this backtrace: ``` #0 0x00007f6241506aa6 in do_futex_wait.constprop () from /lib64/libpthread.so.0 #1 0x00007f6241506b98 in __new_sem_wait_slow.constprop.0 () from /lib64/libpthread.so.0 #2 0x0000000000788772 in PGSemaphoreLock () #3 0x0000000000804d1c in LWLockAcquire () #4 0x000000000058cb88 in SimpleLruWriteAll () #5 0x00000000005885da in CheckPointMultiXact () #6 0x0000000000597445 in CheckPointGuts () #7 0x000000000059a6db in CreateRestartPoint () #8 0x000000000078ed18 in CheckpointerMain () ``` This is consistent with the checkpointer being a secondary victim: once the startup process self-deadlocks while holding `MultiXactOffsetSLRULock` forever, any other backend (here, the checkpointer performing `CheckPointMultiXact`) that subsequently needs the same lock also blocks forever, since it will never be released. ### 4. Source comparison confirming the introduced code `src/backend/access/transam/multixact.c` file SHA comparison across tags: | Tag | File SHA | |---|---| | `REL_15_14` | `136065125eab4bcaeafc1329742bcdf3e27300e6` | | `REL_15_15` | `136065125eab4bcaeafc1329742bcdf3e27300e6` (identical to 15.14) | | `REL_15_16` | `64bb9bbea3678816b2bb431eebf6788dbb29174d` (changed) | | `REL_15_17` | `53b3274a032653e352aaaa99d6bafdeb4216ea52` | | `REL_15_18` | `0af1c61a4ccd2742b08e3e7ae1ffafda99e89a65` | The string `"hack to deal with WAL generated with older minor versions"` and the `last_initialized_offsets_page` logic first appear in `REL_15_16` and are present through `REL_15_18`; they are entirely absent from `REL_15_14` / `REL_15_15`. ### 5. PostgreSQL log excerpt around the hang ``` 2026-09-22 06:56:23 UTC [...]: LOG: restored log file "000000010003226B0000006E" from archive -- (no further "restored log file" or checkpoint-related log lines for 30+ minutes) 2026-09-22 07:22:35 UTC [...]: LOG: restartpoint complete: wrote 4993377 buffers (61.7%); ... 2026-09-22 07:22:35 UTC [...]: LOG: recovery restart point at 3226A/C7575C50 2026-09-22 07:25:32 UTC [...]: LOG: restartpoint starting: time -- (hang recurs; no further progress for 36+ minutes until manually killed) ``` ## Suggested fix direction (for upstream discussion) `SimpleLruWriteAll()` should not unconditionally acquire `shared->ControlLock` when it may already be held by the calling backend. Options include: - Adding a variant of `SimpleLruWriteAll()` (or a parameter) for callers that already hold the relevant `ControlLock`, which skips the internal `LWLockAcquire`/`LWLockRelease` pair. - Restructuring `RecordNewMultiXact()`'s compatibility branch to release `MultiXactOffsetSLRULock` before calling `SimpleLruWriteAll()`, and re-acquire it afterward if still needed. ## Suggested workaround (for anyone else hitting this) Ensure the PostgreSQL minor version used to **replay** WAL is the same (or older, if that were possible — it isn't, WAL is forward-compatible only) as the version that **generated** it, at least until this is fixed. Concretely: when standing up a new replica/standby intended to later become primary via a version-skew build (standby on a newer 15.x minor than the primary), first bring it up on the *same* minor version as the primary to complete the initial WAL replay, and only upgrade the minor version afterward once the instance is out of recovery.
pgsql-bugs by date: