1993 backends on WALWrite

DRAFT

Take a look at this wait-event table:

wait_event_type | wait_event    | coun
----------------+---------------+-------
LWLock          | WALWrite      |  1193
IO              | DataFileRead  |   194
IO              | DataFileWrite |     4
Lock            | frozenid      |     2
IO              | WalSync       |     1

1193 backends on WALWrite made no sense at all. This was a Postgres whose normal workload barely wrote anything. IOPS had exhausted a few hours earlier. Since writes seemed to be bonking the database, I needed to understand why. Postgres was running on the baseline IOPS (~4k at that moment), so any IO operations would wait, but reads and writes apparently do not wait in the same way.

I found out one interesting thing xlog.c: Postgres flushes into WAL while holding WALWriteLock.

* WALWriteLock: must be held to write WAL buffers to disk (XLogWrite or
* XLogFlush).
(...)
* info_lck is only held long enough to read/update the protected variables,
* so it's a plain spinlock. The other locks are held longer (potentially
* over I/O operations), so we use LWLocks for them.

XLogWrite does a pg_pwrite under the 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 on issue_xlog_fsync, which goes through the block layer, driver, maybe across the network.

So it took only one flush in a lock to hold all those 1193 backends. Why not just split the flush lock, then?

I searched. Someone tried exactly this in a 2016 pgsql-hackers thread. The idea was to move the flush out of WALWriteLock and into a separate WALFlushLock, so an OS write could happen while a fsync was still in progress.

But it made things worse. Throughput dropped 10 to 12% because the contention split and, at the same time, grew. In their own words:

But, we didn't see any performance improvements, rather it decreased by 10%-12%.
Hence to measure the wait events, we performed a run for 30 minutes with 64 clients.

...

Due to reduced contention on WAL Write Lock, lot of backends are going for small os writes,
sometimes on same 8KB page, i.e., write calls are not properly accumulated.

There were two reasons: the cost for lock acquire/release was now double, and splitting the lock broke batching - “when fsync is going, we are not able to accumulate sufficient data for the next fsync”. The single fsync model is useful because it covers many commits (group commit). Splitting fsync means we now have to deal with batching in another way.

Worth a caution, though: seeing WALWrite in the wait events doesn’t prove the lock itself is the ceiling. Andres Freund, on a later report of the same contention, doubted the lock was the prime issue and noted Postgres scaling further without it dominating.