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
add_measure_points.diffs
Description: add_measure_points.diffs
test_r.sh
Description: test_r.sh