On Sat, 20 Apr 2024 at 10:30, Alexander Lakhin <exclus...@gmail.com> wrote: > > Hello Michael and Robert, > > 20.04.2024 05:57, Michael Paquier wrote: > > On Fri, Apr 19, 2024 at 01:57:41PM -0400, Robert Haas wrote: > >> It looks to me like in the first run it took 3 minutes for the > >> replay_lsn to catch up to the desired value, and in the second run, > >> two seconds. I think I have seen previous instances where something > >> similar happened, although in those cases I did not stop to record any > >> details. Have others seen this? Is there something we can/should do > >> about it? > > FWIW, I've also seen delays as well with this test on a few occasions. > > Thanks for mentioning it. > > It reminds me of > https://www.postgresql.org/message-id/858a7622-2c81-1687-d1df-1322dfcb2e72%40gmail.com
Thanks Alexander for the test, I was able to reproduce the issue with the test you shared and also verify that the patch at [1] fixes the same. This is the same issue where the apply worker for test_tab2_sub was getting started after 180 seconds because the common latch (which is used for worker attached, subscription creation/modification and apply worker process exit) was getting reset when the other subscription test_tab1_sub's worker gets started. The same can be seen from the logs: 2024-04-22 20:47:52.009 IST [323280] 026_stats.pl LOG: statement: BEGIN; 2024-04-22 20:47:52.009 IST [323280] 026_stats.pl LOG: statement: SELECT pg_sleep(0.5); 2024-04-22 20:47:52.426 IST [323281] LOG: logical replication apply worker for subscription "test_tab1_sub" has started 2024-04-22 20:47:52.511 IST [323280] 026_stats.pl LOG: statement: CREATE TABLE test_tab2(a int primary key); 2024-04-22 20:47:52.518 IST [323280] 026_stats.pl LOG: statement: INSERT INTO test_tab2 VALUES (1); 2024-04-22 20:47:52.519 IST [323280] 026_stats.pl LOG: statement: COMMIT; 2024-04-22 20:47:52.540 IST [323286] 026_stats.pl LOG: statement: CREATE SUBSCRIPTION test_tab2_sub CONNECTION 'port=56685 host=/tmp/RwzpQrVMYH dbname=postgres' PUBLICATION test_tab2_pub 2024-04-22 20:50:52.658 IST [326265] LOG: logical replication apply worker for subscription "test_tab2_sub" has started 2024-04-22 20:50:52.668 IST [326267] LOG: logical replication table synchronization worker for subscription "test_tab2_sub", table "test_tab2" has started [1] - https://www.postgresql.org/message-id/CALDaNm10R7L0Dxq%2B-J%3DPp3AfM_yaokpbhECvJ69QiGH8-jQquw%40mail.gmail.com Regards, Vignesh
