An attempt to reduce WALWriteLock contention

Hello all,

In a recent post[1] by Robert, wait events for different LWLOCKS have been
analyzed. The results clearly indicate a significant lock contention
overhead on WAL Write locks. To get an idea of this overhead, we did the
following two tests.

1. Hacked the code to comment out WAL write and flush calls to see the
overhead of WAL writing. The TPS for read-write pgbench tests at 300 scale
factor with 64 client count increased from 27871 to 45068.

2. Hacked the code to comment out WAL flush calls to see the overhead of
WAL flushing (fsync=off). The TPS for read-write pgbench tests at 300 scale
factor with 64 client count increased from 27871 to 41835.

All the tests have been performed for 15 minutes with following pg
configurations:
max_wal_size: 40GB
checkpoint_timeout: 15mins
maintenance_work_mem: 4GB
checkpoint_completion_target: 0.9
Shared buffer: 8GB
(Other settings have default values)

From above experiments, it is clear that flush is the main cost in WAL
writing which is no surprise, but still, the above data shows the exact
overhead of flush. Robert and Amit suggested (in offline discussions) using
separate WALFlushLock to flush the WAL data. The idea is to take WAL flush
calls out of WAL Write Lock and introduce a new lock (WAL Flush Lock) to
flush the data. This should allow simultaneous os writes when a fsync is in
progress. LWLockAcquireOrWait is used for the newly introduced WAL Flush
Lock to accumulate flush calls. We did a pgbench read/write (s.f. 300) test
with above configurations for various clients. 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.

\t
select wait_event_type, wait_event from pg_stat_activity where pid !=
pg_backend_pid();
\watch 0.5
HEAD
------------------------
48642 LWLockNamed | WALWriteLock

With Patch
----------------------------------
31889 LWLockNamed | WALFlushLock
25212 LWLockNamed | WALWriteLock

The contention on WAL Write Lock was reduced, but together with WAL Flush
lock, the total contention got increased. We also measured the number of
times fsync() and write() have been called for a 10-minutes pgbench
read/write test with 16 clients. We noticed a huge increase in write()
system calls and this is happening as we've reduced the contention on WAL
Write Lock.

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. For example,
backend 1 - 1 KB write() - 15-20 micro secs
backend 2 - 1 KB write() - 15-20 micro secs
backend 3 - 1 KB write() - 15-20 micro secs
backend 4 - 1 KB write() - 15-20 micro secs
But, if we accumulate these 4 requests, 4KB can be written in 50-60 micro
secs. Apart from that, we are also paying for lock acquire and lock release
for os write and lseek(). For the same reason, when a fsync is going, we
are not able to accumulate sufficient data for next fsync. This also
increases the contention on WAL Flush Lock. So, we tried adding
delay(pg_usleep) before flush/write to accumulate data. But, this severely
increases the contention on WAL flush locks.

To reduce the contention on WAL Write Lock further, Amit suggested the
following change on top of the existing patch:
Backend as Write Leader:
Except one proc, all other proc's will wait for their write location to be
written in OS buffer. Each proc will advertise it's write location and wait
on the semaphore to check whether it's write location has been completed.
Only the leader will compete for WALWriteLock.After data is written, it
wakes all the procs for which it has written the WAL and once done with
waking it will release the WALWriteLock. Ashutosh and Amit have helped a
lot for the implementation of the above idea. Even after this idea, we
didn't see any noticeable performance improvement with
synchronous_commit=on mode, however there was no regression. Again, to
measure the wait events, we performed a 30 minutes run with 64 clients.
(pgbench r/w test with s.f. 300)

\t
select wait_event_type, wait_event from pg_stat_activity where pid !=
pg_backend_pid();
\watch 0.5
HEAD
------------------------
48642 LWLockNamed | WALWriteLock

With Patch
----------------------------------
38952 LWLockNamed | WALFlushLock
1679 LWLockNamed | WALWriteLock

We reduced the contention on WAL write locks. The reason is that only the
group leader is competing for write lock on behalf of a group of procs.
Still, the number of small write requests is not reduced.

Finally, we performed some tests with synchronous_commit=off and data
doesn't fit in shared buffer. This should accumulate the data properly for
write without waiting on some locks or semaphores. Besides, write and fsync
can be done simultaneously. Next results are for various scale factors and
shared buffers. (Please see below for system configuration):

./pgbench -c $threads -j $threads -T 900 -M prepared postgres
non default param:
Scale Factor=1000
shared_buffers=10GB
max_connections=200

threads HEAD PATCH %diff
48 18585 18618 +0.1
64 19631 19735 +0.5
128 19332 20556 +6.3

./pgbench -c $threads -j $threads -T 900 -M prepared postgres
non default param:
Scale Factor=1000
shared_buffers=14GB
max_connections=200

threads HEAD PATCH %diff
48 42156 47398 +12.4
64 41737 45288 +8.36
128 37983 47443 +24.9

./pgbench -c $threads -j $threads -T 900 -M prepared postgres
non default param:
Scale Factor=300
shared_buffers=4GB
max_connections=200

threads HEAD PATCH %diff
48 48151 48665 +1.06
64 52651 52789 +0.2
128 56656 60691 +7.1

We noticed some good improvement when most of the data fits in shared
buffer. Apart from that, the improvements are not significant. It may
happen due to high io for buffer evictions in less shared buffer.

In conclusions, we tried to take flush calls out of WAL write lock so that
we can allow simultaneous os writes when fsync is going on. For
synchronous_commit=off, we improved the performance significantly. For
other cases, the reason may be that we are not accumulating write calls
properly and thus issuing a lot of small write requests. Another
possibility could be the overhead of adding an extra lock.

Thanks to Amit Kapila, Ashutosh Sharma and Robert Haas for helping me
throughout the process with their valuable inputs.

I've attached the prototype patch as well. PFA. Any suggestions or comments
will really be helpful in this regard.

System Configuration:

Model name: Intel(R) Xeon(R) CPU E5-2695 v3 @ 2.30GHz
CPU(s): 56
Thread(s) per core: 2
Core(s) per socket: 14
Socket(s): 2
NUMA node(s): 2
Kernel: 3.10.0-327.36.1.el7.x86_64
pg_wal on /mnt/ssd type ext4 (rw,relatime,data=ordered)

[1] [HACKERS] pgbench vs. wait events
<https://www.postgresql.org/message-id/flat/CAMkU%3D1yVzuJA7sTW-3Ddyn9QYqAbAYG61OWwsfP-WU8f6KUGvg%40mail(dot)gmail(dot)com#CAMkU=1yVzuJA7sTW-3Ddyn9QYqAbAYG61OWwsfP-WU8f6KUGvg(at)mail(dot)gmail(dot)com>

--
Thanks & Regards,
Kuntal Ghosh
EnterpriseDB: http://www.enterprisedb.com