| From: | vignesh C <vignesh21(at)gmail(dot)com> |
|---|---|
| To: | Alexander Lakhin <exclusion(at)gmail(dot)com> |
| Cc: | Michael Paquier <michael(at)paquier(dot)xyz>, Robert Haas <robertmhaas(at)gmail(dot)com>, "pgsql-hackers(at)postgresql(dot)org" <pgsql-hackers(at)postgresql(dot)org>, Amit Kapila <amit(dot)kapila16(at)gmail(dot)com>, Sawada Masahiko <sawada(dot)mshk(at)gmail(dot)com> |
| Subject: | Re: subscription/026_stats test is intermittently slow? |
| Date: | 2024-04-22 15:32:10 |
| Message-ID: | CALDaNm3FoLCmar7C=-qsBrjLdKBO=CbQnfVN2kcy9+V4QB8-=g@mail.gmail.com |
| Views: | Raw Message | Whole Thread | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-hackers |
On Sat, 20 Apr 2024 at 10:30, Alexander Lakhin <exclusion(at)gmail(dot)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
Regards,
Vignesh
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Tom Lane | 2024-04-22 15:41:10 | Re: Cleanup: remove unused fields from nodes |
| Previous Message | Matthias van de Meent | 2024-04-22 15:21:22 | Cleanup: remove unused fields from nodes |