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

Attachment: add_measure_points.diffs
Description: add_measure_points.diffs

Attachment: test_r.sh
Description: test_r.sh

Reply via email to