Dear hackers,
> Hmm. It requires additional debug messages. Let me consider.
I did further performance testing to see the re-building time, and confirmed that
the decoding time of second INSERT part became around 1/10. In this test number
of partitions was also varied. Each cell is a median of 5 runs.
number of partitions HEAD [micro second] v4 patched [micro second]
--------------------------------------------------------------------------------
1000 6030 635
5000 33456 3555
15000 106688 14049
Workload
======
Workload is mostly the same, but I ensured that step6 is done within a same transaction.
I also attached just in case.
Used source
========
Attached diff file was applied atop HEAD (d611f8) and v4 patchset. Patched source outputs
current timestamp (in micro seconds) when 1) INSERT is decoded, 2) invalidation
happens or 3) WAL processing is finished for the transaction.
Also, it has a ratchet mechanism not to log every time: continuous INSERT or
INVALIDATION is ignored. Typically, the output is like below:
```
postgres=# SELECT count(*) FROM pg_logical_slot_peek_binary_changes('test', NULL, NULL, 'proto_version', '4',
'publication_names','pub1');
NOTICE: XXX start inserting. Time 794645780406191
NOTICE: XXX start invalidating. Time 794645780407423
NOTICE: XXX start inserting. Time 794645780407448 // (a)
NOTICE: XXX finish processing. Time 794645780407488 // (b)
count
-------
7
(1 row)
```
How I compared
===========
We can obtain the elapsed time for second INSERT part, by (b) - (a).
I took the calculated data for each runs and noted a median in above table.
Best regards,
Hayato Kuroda
FUJITSU LIMITED
