Re: Handing off SLRU fsyncs to the checkpointer

Hi Thomas / hackers,

>> The append-only bottleneck appears to be limited by syscalls/s due to small block size even with everything in FS cache (but not in shared buffers, please compare with TEST1 as there was no such bottleneck at all):
>>
>> 29.62% postgres [kernel.kallsyms] [k] copy_user_enhanced_fast_string
>> ---copy_user_enhanced_fast_string
>> |--17.98%--copyin
>> [..]
>> | __pwrite_nocancel
>> | FileWrite
>> | mdwrite
>> | FlushBuffer
>> | ReadBuffer_common
>> | ReadBufferWithoutRelcache
>> | XLogReadBufferExtended
>> | XLogReadBufferForRedoExtended
>> | --17.57%--btree_xlog_insert
>
> To move these writes out of recovery's way, we should probably just
> run the bgwriter process during crash recovery. I'm going to look
> into that.

Sounds awesome. Also as this thread is starting to derail the SLRU fsync topic - maybe we should change subject? However, to add some data to the separate bgwriter: on 14master (already with lseek() caching, SLRU fsyncs out of way, better sorting), I've measured the same configuration as last time with still the same append-only WAL workload on NVMe and compared with various shared_buffers settings (and buffers description sizing from pg_shmem_allocations which as You stated is wrongly reported(?) which I'm stating only for reference just in case):

shared_buffers=128MB buffers_desc=1024kB 96.778, 0.438 [a]
shared_buffers=256MB buffers_desc=2048kB 62.755, 0.577 [a]
shared_buffers=512MB buffers_desc=4096kB 33.167, 0.62 [a]
shared_buffers=1GB buffers_desc=8192kB 27.303, 0.929
shared_buffers=4GB buffers_desc=32MB 27.185, 1.166
shared_buffers=8GB buffers_desc=64MB 27.649, 1.088
shared_buffers=16GB buffers_desc=128MB 27.584, 1.201 [b]
shared_buffers=32GB buffers_desc=256MB 32.314, 1.171 [b]
shared_buffers=48GB buffers_desc=384 MB 31.95, 1.217
shared_buffers=64GB buffers_desc=512 MB 31.276, 1.349
shared_buffers=72GB buffers_desc=576 MB 31.925, 1.284
shared_buffers=80GB buffers_desc=640 MB 31.809, 1.413

The amount of WAL to be replayed was ~2.8GB. To me it looks like that
a) flushing dirty buffers by StartupXLog might be a real problem but please read-on.
b) there is very low impact by this L2/L3 hypothesis you mention (?), but it's not that big and it's not degrading linearly as one would expect (??) L1d:L1d:L2:L3 cache sizes on this machine are as follows on this machine: 32K/32K/256K/46080K. Maybe the DB size is too small.

I've double-checked that in condition [a] (shared_buffers=128MB) there was a lot of FlushBuffer() invocations per second (perf stat -e probe_postgres:FlushBuffer -I 1000), e.g:
# time counts unit events
1.000485217 79,494 probe_postgres:FlushBuffer
2.000861366 75,305 probe_postgres:FlushBuffer
3.001263163 79,662 probe_postgres:FlushBuffer
4.001650795 80,317 probe_postgres:FlushBuffer
5.002033273 79,951 probe_postgres:FlushBuffer
6.002418646 79,993 probe_postgres:FlushBuffer
while at 1GB shared_buffers it sits nearly at zero all the time. So there is like 3x speed-up possible when StartupXLog wouldn't have to care too much about dirty buffers in the critical path (bgwriter would as you say?) at least in append-only scenarios. But ... I've checked some real systems (even older versions of PostgreSQL not doing that much of replication, and indeed it's e.g. happening 8-12k/s FlushBuffer's() and shared buffers are pretty huge (>100GB, 0.5TB RAM) but they are *system-wide* numbers, work is really performed by bgwriter not by startup/recovering as in this redo-bench case when DB is open for reads and replicating-- so it appears that this isn't optimization for hot standby case , but for the DB-closed startup recovery/restart/disaster/PITR scenario).

As for the 24GB shared_buffers scenario where dirty buffers are not at all a problem with given top profile (output trimmed), again as expected:

13.41% postgres postgres [.] hash_search_with_hash_value
|--8.31%--BufTableLookup <- ReadBuffer_common <- ReadBufferWithoutRelcache
--5.11%--smgropen
|--2.77%--XLogReadBufferExtended
--2.34%--ReadBufferWithoutRelcache
7.88% postgres postgres [.] MarkBufferDirty

I've tried to get cache misses ratio via PMCs, apparently on EC2 they are (even on bigger) reporting as not-supported or zeros. However interestingly the workload has IPC of 1.40 (instruction bound) which to me is strange as I would expect BufTableLookup() to be actually heavy memory bound (?) Maybe I'll try on some different hardware one day.

>> __pread_nocancel
>> --11.44%--FileRead
>> mdread
>> ReadBuffer_common
>> ReadBufferWithoutRelcache
>> XLogReadBufferExtended
>> XLogReadBufferForRedoExtended
>
> For these reads, the solution should be WAL prefetching,(..) But... when combined with Andres's work-in-progress AIO stuff (..)

Yes, I've heard a thing or two about those :) I hope I'll be able to deliver some measurements sooner or later of those two together (AIO+WALprefetch).

-Jakub Wartak.