The lock around WAL flush

haeseong1 pts0 comments

The lock around WAL flush

The lock around WAL flush<br>July 18, 2026A wait event that looks like &ldquo;storage is slow&rdquo; can mean two completely different things depending on where the queue forms relative to the slow operation. If the slow part happens inside a lock, one slow IO cascades thousands of stuck backends. If it happens outside, though, the same slowness stays contained. This is the story of why 1193 backends piled up behind a WAL append on a database that barely writes, while 194 backends doing reads stayed fine.<br>We got another Postgres IO incident this week, but this time IORead wasn&rsquo;t the bottleneck. The instance was an AWS RDS on gp3 with 12k provisioned IOPS, and after a few hours EBSIOBalance slowly dropped to 0%.<br>During peak: 9k IOWrite, 6k connections (200 is the baseline), checkpointlag spiked to 4 hours.<br>At the same time, we hit the antiwraparound threshold of 200M and autovacuum was triggered across databases with old frozen XIDs. It started working through 237 databases (yes, the data model in this one is interesting - this instance has 10k+ databases).<br>wait_event_type | wait_event | count<br>-----------------+---------------------+-------<br>LWLock | WALWrite | 1193<br>IO | DataFileRead | 194<br>LWLock | pg_stat_statements | 23<br>| | 23<br>IPC | CheckpointStart | 14<br>IPC | BufferIo | 8<br>Lock | transactionid | 4<br>IO | DataFileWrite | 4<br>Client | ClientRead | 3<br>Lock | frozenid | 2<br>IO | WalSync | 1<br>IO | DataFileExtend | 1<br>IO | SlruRead | 1<br>IPC | CheckpointDone | 1<br>1193 LWLock on WALWrite surprised me. The normal application workload doesn&rsquo;t receive many writes compared to the read load. Most of the load is doing scans on big tables, so at first I thought: Oh, ok, another bad monday because of sequential scans. But that wasn&rsquo;t it.<br>Why are backend processes being locked behind a simple WAL write?<br>Before I looked at pg_stats, my first guess was that autovacuum was the culprit. But only two processes were locked on frozenid - that wasn&rsquo;t it. It wasn&rsquo;t read IO waits as well: only 194 DataFileRead.<br>Another thing: WALWrite is not an IO wait, it&rsquo;s a lock event. Processes were waiting on each other.<br>I remember I thought: but why? A WAL record is small, and writing to it is an append. Well, today, a few days after the incident, I had the chance to dig deeper by reading xlog.c in the source code.<br>The insert path<br>The first thing I found was the insert side.<br>* Inserting to WAL is protected by a small fixed number of WAL insertion<br>* locks. To insert to the WAL, you must hold one of the locks - it doesn't<br>* matter which one.<br>We have 8 NUM_XLOGINSERT_LOCKS. The insert itself is two steps:<br>* 1. Reserve the right amount of space from the WAL. The current head of<br>* reserved space is kept in Insert->CurrBytePos, and is protected by<br>* insertpos_lck.<br>* 2. Copy the record to the reserved WAL space. This involves finding the<br>* correct WAL buffer containing the reserved space, and copying the<br>* record in place. This can be done concurrently in multiple processes.<br>Step 1 is serialized, and they say so in ReserveXLogInsertLocation:<br>* This is the performance critical part of XLogInsert that must be serialized<br>* across backends. The rest can happen mostly in parallel. Try to keep this<br>* section as short as possible, insertpos_lck can be heavily contended on a<br>* busy system.<br>But look at what it does under that spinlock:<br>SpinLockAcquire(&Insert->insertpos_lck);

startbytepos = Insert->CurrBytePos;<br>endbytepos = startbytepos + size;<br>prevbytepos = Insert->PrevBytePos;<br>Insert->CurrBytePos = endbytepos;<br>Insert->PrevBytePos = startbytepos;

SpinLockRelease(&Insert->insertpos_lck);<br>That&rsquo;s only three reads and two writes. Not that much work. If this was the problem, I would&rsquo;ve seen LWLock:WALInsertLock. But I didn&rsquo;t.<br>The flush path<br>The flush path is more interesting:<br>* WALWriteLock: must be held to write WAL buffers to disk (XLogWrite or<br>* XLogFlush).<br>(...)<br>* info_lck is only held long enough to read/update the protected variables,<br>* so it's a plain spinlock. The other locks are held longer (potentially<br>* over I/O operations), so we use LWLocks for them.<br>So flush is 1 lock, exclusive. Very different from the 8 locks of the insert path. Since there&rsquo;s only one WAL stream and one device, this is where successful inserts fall into. It makes sense.<br>XLogWrite does a pg_pwrite under that lock. The write path often only has to copy WAL data into the kernel/page cache, although it can also stall if the kernel/device is already under pressure. After that, we get fsync - issue_xlog_fsync, which goes through the block layer, the driver, across the EBS network. The durable wait is usually the dangerous part. This also makes sense.<br>Out of all those 1193 backends, most were not doing I/O themselves. They were sleeping while waiting for the backend holding WALWriteLock to finish.<br>But shouldn&rsquo;t the kernel have handled this issue? The EBSIOBalance dropping to 0% doesn&rsquo;t signal anything to...

rsquo insert lock flush backends path

Related Articles