Обсуждение: Excessive number of replication slots for 12->14 logical replication

Поиск
Список
Период
Сортировка

Excessive number of replication slots for 12->14 logical replication

От
hubert depesz lubaczewski
Дата:
Hi,
We're using logical replication to replicate database from pg 12.9 to
14.4.

Given the number of objects we made decision to use 10 separate
publications, each containing subset of tables.

So, we have:

$ select pubname, count(*) from pg_publication_tables where pubname ~ 'focal' group by pubname;
  pubname   │ count 
════════════╪═══════
 focal14_1  │   412
 focal14_10 │ 15580
 focal14_2  │ 14316
 focal14_3  │ 14352
 focal14_4  │ 14367
 focal14_5  │ 15187
 focal14_6  │ 15171
 focal14_7  │ 15187
 focal14_8  │ 15169
 focal14_9  │ 15578
(10 rows)

On both sides we have max_sync_workers_per_subscription set to 2.

So, I would assume that during initial subscription, we can go up to 30
connections. To make it safe we set limit to 50, but apparently it's not
enough.

I'm getting *LOTS* of errors about number of replication slots:

2022-07-14 11:40:30.612 UTC,"upgrayedd","dbname",11829,"10.1.191.34:37394",62d000ae.2e35,5,"idle in
transaction",2022-07-1411:40:30 UTC,38/350893,0,ERROR,53400,"all replication slots are in use",,"Free one or increase
max_replication_slots.",,,,"CREATE_REPLICATION_SLOT""pg_1337070_sync_189406_7119125406647933415"" LOGICAL pgoutput
USE_SNAPSHOT",,,"pg_1337070_sync_189406_7119125406647933415"

We're getting them (in the beginning of sync) to the tune of 2-4 thousand per minute.!

Took a snapshot of pg_replication_slots and it looked like this:

#v+
                 slot_name                  │  plugin  │ slot_type │ datoid  │ database │ temporary │ active │
active_pid│  xmin  │ catalog_xmin │ restart_lsn  │ confirmed_flush_lsn 
 

════════════════════════════════════════════╪══════════╪═══════════╪═════════╪══════════╪═══════════╪════════╪════════════╪════════╪══════════════╪══════════════╪═════════════════════
 focal14_1                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11306│ [null] │    175118841 │ BAD/BAC6D98  │ BAD/BACFFF0
 
 focal14_9                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11413│ [null] │    175118841 │ BAD/BAC6E08  │ BAD/BACFFF0
 
 focal14_5                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11400│ [null] │    175118841 │ BAD/BAC6DD0  │ BAD/BACFFF0
 
 focal14_2                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11395│ [null] │    175118841 │ BAD/BAC6E08  │ BAD/BACFFF0
 
 focal14_3                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11397│ [null] │    175118841 │ BAD/BAC6DD0  │ BAD/BACFFF0
 
 focal14_4                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11398│ [null] │    175118841 │ BAD/BAC6DD0  │ BAD/BACFFF0
 
 pg_1337073_sync_570162_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAABB10  │ BAD/BAB2EF8
 
 focal14_6                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11401│ [null] │    175118841 │ BAD/BAC6DD0  │ BAD/BACFFF0
 
 focal14_7                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11403│ [null] │    175118841 │ BAD/BAC6D98  │ BAD/BACFFF0
 
 focal14_8                                  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
11406│ [null] │    175118841 │ BAD/BAC6DD0  │ BAD/BACFFF0
 
 pg_1336982_sync_443064_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAAB8E0  │ BAD/BAB2EF8
 
 pg_1337042_sync_41643_7119125406647933415  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAAB918  │ BAD/BAB2EF8
 
 pg_1337072_sync_884811_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118843 │ BAD/BAE5668  │ BAD/BAEC2C0
 
 pg_1336981_sync_392740_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFE90  │ BAD/BAC6D98
 
 pg_1337042_sync_139273_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFEC8  │ BAD/BAC6D98
 
 pg_1337056_sync_648956_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAAB9F8  │ BAD/BAB2EF8
 
 pg_1337055_sync_423485_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAABA30  │ BAD/BAB2EF8
 
 pg_1337072_sync_448264_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAABA68  │ BAD/BAB2EF8
 
 pg_1336982_sync_271954_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118838 │ BAD/BAB6650  │ BAD/BABD7B8
 
 pg_1337071_sync_82458_7119125406647933415  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAABAD8  │ BAD/BAB2EF8
 
 pg_1337072_sync_550946_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAABB48  │ BAD/BAB2EF8
 
 focal14_10                                 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ t      │
12859│ [null] │    175118805 │ BAD/B916658  │ BAD/B916690
 
 pg_1337056_sync_553531_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAABB80  │ BAD/BAB2EF8
 
 pg_1336982_sync_920960_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFC98  │ BAD/BAC6D98
 
 pg_1337072_sync_150987_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFF00  │ BAD/BAC6D98
 
 pg_1337071_sync_199748_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118837 │ BAD/BAABC28  │ BAD/BAB2EF8
 
 pg_1337055_sync_790318_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFF38  │ BAD/BAC6D98
 
 pg_1337056_sync_79981_7119125406647933415  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFF70  │ BAD/BAC6D98
 
 pg_1337042_sync_919197_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFFA8  │ BAD/BAC6D98
 
 pg_1337055_sync_671382_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BABFFE0  │ BAD/BAC6D98 
 pg_1337072_sync_937506_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC0030  │ BAD/BAC6D98
 
 pg_1337070_sync_89436_7119125406647933415  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC0068  │ BAD/BAC6D98
 
 pg_1337071_sync_92364_7119125406647933415  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC00A0  │ BAD/BAC6D98
 
 pg_1336982_sync_237037_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC00D8  │ BAD/BAC6D98
 
 pg_1337056_sync_473314_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC0110  │ BAD/BAC6D98
 
 pg_1337071_sync_559400_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC0148  │ BAD/BAC6D98
 
 pg_1337070_sync_521659_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC0180  │ BAD/BAC6D98
 
 pg_1337073_sync_342687_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC01B8  │ BAD/BAC6D98
 
 pg_1337073_sync_668407_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118839 │ BAD/BAC01F0  │ BAD/BAC6D98
 
 pg_1337056_sync_737045_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118844 │ BAD/BAEE5D8  │ BAD/BAF4168
 
 pg_1337073_sync_477925_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118841 │ BAD/BAD2E88  │ BAD/BAD87D0
 
 pg_1336981_sync_393379_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118843 │ BAD/BAE5710  │ BAD/BAEC2C0
 
 pg_1337070_sync_22486_7119125406647933415  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118841 │ BAD/BAD2EF8  │ BAD/BAD87D0
 
 pg_1337071_sync_618386_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118843 │ BAD/BAE57F0  │ BAD/BAEC2C0
 
 pg_1337056_sync_706794_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118843 │ BAD/BAE5780  │ BAD/BAEC2C0
 
 pg_1337070_sync_266887_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118843 │ BAD/BAE55C0  │ BAD/BAEC2C0
 
 pg_1337072_sync_845361_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118841 │ BAD/BAD2FA0  │ BAD/BAD87D0
 
 pg_1337056_sync_75850_7119125406647933415  │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118841 │ BAD/BAD2FD8  │ BAD/BAD87D0
 
 pg_1337055_sync_792553_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118843 │ BAD/BAE55F8  │ BAD/BAEC2C0
 
 pg_1336982_sync_760909_7119125406647933415 │ pgoutput │ logical   │ 7436115 │ dbname   │ f         │ f      │
[null]│ [null] │    175118843 │ BAD/BAE5748  │ BAD/BAEC2C0
 
#v-

What is happening, and why Pg is trying to get more than 30 concurrent
slots in this case?

Best regards,

depesz




Re: Excessive number of replication slots for 12->14 logical replication

От
Kyotaro Horiguchi
Дата:
At Thu, 14 Jul 2022 13:51:55 +0200, hubert depesz lubaczewski <depesz@depesz.com> wrote in 
> Hi,
> We're using logical replication to replicate database from pg 12.9 to
> 14.4.
> 
> Given the number of objects we made decision to use 10 separate
> publications, each containing subset of tables.
> 
> So, we have:

(10 publications with an average of 15000 talbes)
> 
> On both sides we have max_sync_workers_per_subscription set to 2.
> 
> So, I would assume that during initial subscription, we can go up to 30
> connections. To make it safe we set limit to 50, but apparently it's not
> enough.

> I'm getting *LOTS* of errors about number of replication slots:

Yeah, the limitation by max_sync_workers_per_subscription is performed
on subscriber, but replication slot drops happen not on the
subscriber, but at the termination of corresponding walsender process
on publisher. So, there's a lag between the finish of subscription
worker and the corresponding slot's drop.  Thus, a new sync worker can
be created while the walsenders corresponding to some already finished
sync workers is still going to finish.

> What is happening, and why Pg is trying to get more than 30
concurrent
> slots in this case?

Thus, not just about logical replication, some spare slots are
necessary to keep things running smoothly.  I guess that it is
widely(?)  recommended to provide at least one or two spare slots to
allow replication reconnection in case of silent disconnections, but I
haven't found something like that in the documentation.. In your case,
it seems to me larger number of spare slots makes the server run more
smoothly, *I* don't think 10 spare slots affect anything badly.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center

  



Re: Excessive number of replication slots for 12->14 logical replication

От
hubert depesz lubaczewski
Дата:
On Fri, Jul 15, 2022 at 01:55:32PM +0900, Kyotaro Horiguchi wrote:
> Thus, not just about logical replication, some spare slots are
> necessary to keep things running smoothly.  I guess that it is
> widely(?)  recommended to provide at least one or two spare slots to
> allow replication reconnection in case of silent disconnections, but I
> haven't found something like that in the documentation.. In your case,
> it seems to me larger number of spare slots makes the server run more
> smoothly, *I* don't think 10 spare slots affect anything badly.

OK. The explanation makes sense, but leads to problem - we have 50
max replication slots, which gives me 20 spare slots.

And I'm not sure how much should I increase it so that it will still
work.

Plus - there is the problem that increasing max_replication_slots
requires restart :(

Anyway, will deal with it, now that I understand the issue. Thanks
a lot.

Best regards,

depesz




Re: Excessive number of replication slots for 12->14 logical replication

От
Andres Freund
Дата:
Hi,

On 2022-07-15 13:55:32 +0900, Kyotaro Horiguchi wrote:
> Yeah, the limitation by max_sync_workers_per_subscription is performed
> on subscriber, but replication slot drops happen not on the
> subscriber, but at the termination of corresponding walsender process
> on publisher. So, there's a lag between the finish of subscription
> worker and the corresponding slot's drop.  Thus, a new sync worker can
> be created while the walsenders corresponding to some already finished
> sync workers is still going to finish.

Why are we relying on the slots being dropped at the end of connection? That
doesn't seem like a good idea to me. Can't we just do that explicitly? We
still need the on-connection-close cleanup to deal with network failures etc,
but that doesn't mean we can do something else in the happy path.

Greetings,

Andres Freund



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Thu, Jul 14, 2022 at 5:22 PM hubert depesz lubaczewski
<depesz@depesz.com> wrote:
>
> Hi,
> We're using logical replication to replicate database from pg 12.9 to
> 14.4.
>
> Given the number of objects we made decision to use 10 separate
> publications, each containing subset of tables.
>
> So, we have:
>
...
>
> On both sides we have max_sync_workers_per_subscription set to 2.
>
> So, I would assume that during initial subscription, we can go up to 30
> connections. To make it safe we set limit to 50, but apparently it's not
> enough.
>
> I'm getting *LOTS* of errors about number of replication slots:
>
> 2022-07-14 11:40:30.612 UTC,"upgrayedd","dbname",11829,"10.1.191.34:37394",62d000ae.2e35,5,"idle in
transaction",2022-07-1411:40:30 UTC,38/350893,0,ERROR,53400,"all replication slots are in use",,"Free one or increase
max_replication_slots.",,,,"CREATE_REPLICATION_SLOT""pg_1337070_sync_189406_7119125406647933415"" LOGICAL pgoutput
USE_SNAPSHOT",,,"pg_1337070_sync_189406_7119125406647933415"
>
> We're getting them (in the beginning of sync) to the tune of 2-4 thousand per minute.!
>
...
>
> What is happening, and why Pg is trying to get more than 30 concurrent
> slots in this case?
>

As per my understanding, each subscription will use three slots (one
for apply worker and one for each of the sync workers) in your case in
the sync phase. So, in your case, if you have 10 subscriptions then
ideally it should be no more than 30. Can you please check and share
the subscriber logs to see if there are any errors in the initial sync
phase? Also, please confirm the number of subscriptions you create on
the subscriber?

--
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Sat, Jul 16, 2022 at 3:44 AM Andres Freund <andres@anarazel.de> wrote:
>
> On 2022-07-15 13:55:32 +0900, Kyotaro Horiguchi wrote:
> > Yeah, the limitation by max_sync_workers_per_subscription is performed
> > on subscriber, but replication slot drops happen not on the
> > subscriber, but at the termination of corresponding walsender process
> > on publisher.

We do drop the replication slots on subscribers since commit
ce0fdbfe97 once the initial sync is complete.

> > So, there's a lag between the finish of subscription
> > worker and the corresponding slot's drop.  Thus, a new sync worker can
> > be created while the walsenders corresponding to some already finished
> > sync workers is still going to finish.
>
> Why are we relying on the slots being dropped at the end of connection? That
> doesn't seem like a good idea to me. Can't we just do that explicitly?
>

We do that explicitly once the initial sync in finished.

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
hubert depesz lubaczewski
Дата:
On Mon, Jul 18, 2022 at 09:07:35AM +0530, Amit Kapila wrote:
> As per my understanding, each subscription will use three slots (one
> for apply worker and one for each of the sync workers) in your case in
> the sync phase. So, in your case, if you have 10 subscriptions then
> ideally it should be no more than 30. Can you please check and share
> the subscriber logs to see if there are any errors in the initial sync
> phase? Also, please confirm the number of subscriptions you create on
> the subscriber?

Hi,
I'm 100% sure we create 10, with the table distribution as shown in
original post.

Will reset the whole thing from scratch, and check for other errors, but
it will take "a while".

Best regards,

depesz




Re: Excessive number of replication slots for 12->14 logical replication

От
hubert depesz lubaczewski
Дата:
On Mon, Jul 18, 2022 at 09:07:35AM +0530, Amit Kapila wrote:
> As per my understanding, each subscription will use three slots (one
> for apply worker and one for each of the sync workers) in your case in
> the sync phase. So, in your case, if you have 10 subscriptions then
> ideally it should be no more than 30. Can you please check and share
> the subscriber logs to see if there are any errors in the initial sync
> phase? Also, please confirm the number of subscriptions you create on
> the subscriber?

Ok. In next test I did:

@09:21:16 AM UTC, on source
All the "create publication" for focal14_1 to focal14_10 sets.

@09:21:53 (immediately after), on recipient:
create subscription focal14_1 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_1;
create subscription focal14_2 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_2;
create subscription focal14_3 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_3;
create subscription focal14_4 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_4;
create subscription focal14_5 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_5;
create subscription focal14_6 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_6;
create subscription focal14_7 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_7;
create subscription focal14_8 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_8;
create subscription focal14_9 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_9;
create subscription focal14_10 connection 'host=10.10.10.10 port=5432 user=upgrayedd dbname=dbname' publication
focal14_10;

This script has ened at 09:21:56

First error:
#v+
2022-07-18 09:22:07.046 UTC,,,4145917,,62d5263f.3f42fd,2,,2022-07-18 09:22:07 UTC,28/21641,1219146,ERROR,53400,"could
notfind free replication state slot for replication origin with OID 51",,"Increase max_replication_slots and try
again.",,,,,,,"","logicalreplication worker",,0
 
#v-

Nothing else errored out before, no warning, no fatals.

from the first ERROR I was getting them in the range of 40-70 per minute.

At the same time I was logging data from `select now(), * from pg_replication_slots`, every 2 seconds.

Then, i grouped it into 4 groups:
slots with name focal* with active = true
slots with name focal* with active = false
slots with name *sync* with active = true
slots with name *sync* with active = false

How it looked in time:
09:21:54:  5 total; focal:  1 active,  2 inactive; sync:  1 active,  1 inactive
09:21:56: 11 total; focal:  1 active,  9 inactive; sync:  1 active,  0 inactive
09:21:58: 11 total; focal:  1 active,  8 inactive; sync:  1 active,  1 inactive
09:22:00: 23 total; focal: 10 active,  0 inactive; sync:  0 active, 13 inactive
09:22:03: 28 total; focal: 10 active,  0 inactive; sync:  9 active,  9 inactive
09:22:05: 21 total; focal: 10 active,  0 inactive; sync:  7 active,  4 inactive
09:22:07: 20 total; focal: 10 active,  0 inactive; sync:  7 active,  3 inactive
09:22:09: 27 total; focal: 10 active,  0 inactive; sync:  9 active,  8 inactive
09:22:11: 30 total; focal: 10 active,  0 inactive; sync: 10 active, 10 inactive
09:22:13: 49 total; focal: 10 active,  0 inactive; sync:  5 active, 34 inactive
09:22:15: 50 total; focal: 10 active,  0 inactive; sync:  0 active, 40 inactive
09:22:17: 49 total; focal: 10 active,  0 inactive; sync:  0 active, 39 inactive
09:22:19: 44 total; focal: 10 active,  0 inactive; sync:  1 active, 33 inactive
09:22:21: 43 total; focal: 10 active,  0 inactive; sync:  2 active, 31 inactive
09:22:23: 44 total; focal: 10 active,  0 inactive; sync:  1 active, 33 inactive
09:22:25: 43 total; focal: 10 active,  0 inactive; sync:  1 active, 32 inactive

So, it looks that there are up to 10 focal slots, all active, and then there are sync slots with weirdly high counts
forinactive ones.
 

At most, I had 11 active sync slots.

Looks like some kind of timing issue, which would be inline with what
Kyotaro Horiguchi wrote initially.

The thing is that after some time, the data *gets* replicated, and it
seems to be full on publication side, but the errors are unnerving :)

depesz



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Mon, Jul 18, 2022 at 3:13 PM hubert depesz lubaczewski
<depesz@depesz.com> wrote:
>
> On Mon, Jul 18, 2022 at 09:07:35AM +0530, Amit Kapila wrote:
>
> First error:
> #v+
> 2022-07-18 09:22:07.046 UTC,,,4145917,,62d5263f.3f42fd,2,,2022-07-18 09:22:07 UTC,28/21641,1219146,ERROR,53400,"could
notfind free replication state slot for replication origin with OID 51",,"Increase max_replication_slots and try
again.",,,,,,,"","logicalreplication worker",,0 
> #v-
>
> Nothing else errored out before, no warning, no fatals.
>
> from the first ERROR I was getting them in the range of 40-70 per minute.
>
> At the same time I was logging data from `select now(), * from pg_replication_slots`, every 2 seconds.
>
...
>
> So, it looks that there are up to 10 focal slots, all active, and then there are sync slots with weirdly high counts
forinactive ones. 
>
> At most, I had 11 active sync slots.
>
> Looks like some kind of timing issue, which would be inline with what
> Kyotaro Horiguchi wrote initially.
>

I think this is a timing issue similar to what Horiguchi-San has
pointed out but due to replication origins. We drop the replication
origin after the sync worker that has used it is finished. This is
done by the apply worker because we don't allow to drop the origin
till the process owning the origin is alive. I am not sure of
repercussions but maybe we can allow dropping the origin by the
process that owns it.

I think this will also be addressed once we start resuing
workers/slots/origin to copy multiple tables in the initial sync phase
as is being discussed in the thread [1].

[1] - https://www.postgresql.org/message-id/CAGPVpCTq%3DrUDd4JUdaRc1XUWf4BrH2gdSNf3rtOMUGj9rPpfzQ%40mail.gmail.com

--
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Sun, Jul 24, 2022 at 6:12 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Mon, Jul 18, 2022 at 3:13 PM hubert depesz lubaczewski
> <depesz@depesz.com> wrote:
> >
> > On Mon, Jul 18, 2022 at 09:07:35AM +0530, Amit Kapila wrote:
> >
> > First error:
> > #v+
> > 2022-07-18 09:22:07.046 UTC,,,4145917,,62d5263f.3f42fd,2,,2022-07-18 09:22:07
UTC,28/21641,1219146,ERROR,53400,"couldnot find free replication state slot for replication origin with OID
51",,"Increasemax_replication_slots and try again.",,,,,,,"","logical replication worker",,0 
> > #v-
> >
> > Nothing else errored out before, no warning, no fatals.
> >
> > from the first ERROR I was getting them in the range of 40-70 per minute.
> >
> > At the same time I was logging data from `select now(), * from pg_replication_slots`, every 2 seconds.
> >
> ...
> >
> > So, it looks that there are up to 10 focal slots, all active, and then there are sync slots with weirdly high
countsfor inactive ones. 
> >
> > At most, I had 11 active sync slots.
> >
> > Looks like some kind of timing issue, which would be inline with what
> > Kyotaro Horiguchi wrote initially.
> >
>
> I think this is a timing issue similar to what Horiguchi-San has
> pointed out but due to replication origins. We drop the replication
> origin after the sync worker that has used it is finished. This is
> done by the apply worker because we don't allow to drop the origin
> till the process owning the origin is alive. I am not sure of
> repercussions but maybe we can allow dropping the origin by the
> process that owns it.
>

I have written a patch which will do the dropping of replication
origins in the sync worker itself.
I had to reset the origin session (which also resets the owned by
flag) prior to the dropping of the slots.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

RE: Excessive number of replication slots for 12->14 logical replication

От
"houzj.fnst@fujitsu.com"
Дата:
On Sunday, July 24, 2022 4:17 PM Ajin Cherian <itsajin@gmail.com> wrote:
> On Sun, Jul 24, 2022 at 6:12 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > On Mon, Jul 18, 2022 at 3:13 PM hubert depesz lubaczewski
> > <depesz@depesz.com> wrote:
> > >
> > > On Mon, Jul 18, 2022 at 09:07:35AM +0530, Amit Kapila wrote:
> > >
> > > First error:
> > > #v+
> > > 2022-07-18 09:22:07.046 UTC,,,4145917,,62d5263f.3f42fd,2,,2022-07-18
> > > 09:22:07 UTC,28/21641,1219146,ERROR,53400,"could not find free
> > > replication state slot for replication origin with OID
> > > 51",,"Increase max_replication_slots and try
> > > again.",,,,,,,"","logical replication worker",,0
> > > #v-
> > >
> > > Nothing else errored out before, no warning, no fatals.
> > >
> > > from the first ERROR I was getting them in the range of 40-70 per minute.
> > >
> > > At the same time I was logging data from `select now(), * from
> pg_replication_slots`, every 2 seconds.
> > >
> > ...
> > >
> > > So, it looks that there are up to 10 focal slots, all active, and then there are
> sync slots with weirdly high counts for inactive ones.
> > >
> > > At most, I had 11 active sync slots.
> > >
> > > Looks like some kind of timing issue, which would be inline with
> > > what Kyotaro Horiguchi wrote initially.
> > >
> >
> > I think this is a timing issue similar to what Horiguchi-San has
> > pointed out but due to replication origins. We drop the replication
> > origin after the sync worker that has used it is finished. This is
> > done by the apply worker because we don't allow to drop the origin
> > till the process owning the origin is alive. I am not sure of
> > repercussions but maybe we can allow dropping the origin by the
> > process that owns it.
> >
> 
> I have written a patch which will do the dropping of replication origins in the
> sync worker itself.
> I had to reset the origin session (which also resets the owned by
> flag) prior to the dropping of the slots.

Thanks for the patch.

I tried the patch and confirmed that we won't get the ERROR "could not find
free replication state slot for replication origin with OID" again after
applying the patch.

I tested the patch by letting the apply worker wait for a bit more time after
setting the state to SUBREL_STATE_CATCHUP. In this case(before the patch) the
table sync worker will exit before the apply worker drop the replorigin, and
the apply worker will try to start another worker which would cause the
ERROR(before the patch).

Few comments:

1)
-                 * There is a chance that the user is concurrently performing
-                 * refresh for the subscription where we remove the table
-                 * state and its origin and by this time the origin might be
-                 * already removed. So passing missing_ok = true.
-                 */

I think it would be better if we can move these comments to the new place where
we drop the replorigin.


2)

-                replorigin_drop_by_name(originname, true, false);
 
                 /*
                  * Update the state to READY only after the origin cleanup.

Do we need to slightly modify the comment here as the origin drop code has been
moved to other places. Maybe "It's safe to update the state to READY as the
origin should have been dropped by table sync worker".

Best regards,
Hou zj

Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Mon, Jul 25, 2022 at 7:48 PM houzj.fnst@fujitsu.com
<houzj.fnst@fujitsu.com> wrote:
>
> On Sunday, July 24, 2022 4:17 PM Ajin Cherian <itsajin@gmail.com> wrote:
> I tried the patch and confirmed that we won't get the ERROR "could not find
> free replication state slot for replication origin with OID" again after
> applying the patch.
>
> I tested the patch by letting the apply worker wait for a bit more time after
> setting the state to SUBREL_STATE_CATCHUP. In this case(before the patch) the
> table sync worker will exit before the apply worker drop the replorigin, and
> the apply worker will try to start another worker which would cause the
> ERROR(before the patch).

Thanks for testing the patch.

>
> Few comments:
>
> 1)
> -                                * There is a chance that the user is concurrently performing
> -                                * refresh for the subscription where we remove the table
> -                                * state and its origin and by this time the origin might be
> -                                * already removed. So passing missing_ok = true.
> -                                */
>
> I think it would be better if we can move these comments to the new place where
> we drop the replorigin.

Fixed this.


>
> 2)
>
> -                               replorigin_drop_by_name(originname, true, false);
>
>                                 /*
>                                  * Update the state to READY only after the origin cleanup.
>
> Do we need to slightly modify the comment here as the origin drop code has been
> moved to other places. Maybe "It's safe to update the state to READY as the
> origin should have been dropped by table sync worker".
>

Fixed this.
Added an updated patch.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Peter Smith
Дата:
Here are some review comments for the v2-0001 patch:

======

1. Commit message

The commit message should give some reason why relocating the origin
slot drop code is expected to fix the reported problem.

======

2. src/backend/replication/logical/tablesync.c

+ /* reset the origin session before dropping */
+ replorigin_session_reset();
+
+ replorigin_session_origin = InvalidRepOriginId;
+ replorigin_session_origin_lsn = InvalidXLogRecPtr;
+ replorigin_session_origin_timestamp = 0;

2a.
Uppercase comment

2b.
IIUC you are not doing the reset because you particularly want to do a
reset, but really because this is the only (?) way to dis-associate
the current process from owning the slot. Otherwise, the slot would be
considered still "busy" and the subsequent replorigin_drop_by_name
would be rejected. I thought the current comment should be expanded to
explain all this background.

2c.
Perhaps it is non-standard to do so, but I wondered if you can just
call pg_replication_origin_session_reset instead of
replorigin_session_reset here so that there would only be 1 LOC
instead of 4.

~~~

3. src/backend/replication/logical/tablesync.c

+ /*
  * Cleanup the tablesync slot.
  *
  * This has to be done after updating the state because otherwise if

Doesn't the same note ("This has to be done after...") also apply to
the code dropping the origin slot? Maybe this note needs to be either
duplicated or just put a common note about this above both of those
slot drops.

------
Kind Regards,
Peter Smith.
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Thu, Jul 28, 2022 at 11:56 AM Peter Smith <smithpb2250@gmail.com> wrote:
>
> Here are some review comments for the v2-0001 patch:
>
> ======
>
> 1. Commit message
>
> The commit message should give some reason why relocating the origin
> slot drop code is expected to fix the reported problem.
>
> ======
>

Updated.

> 2. src/backend/replication/logical/tablesync.c
>
> + /* reset the origin session before dropping */
> + replorigin_session_reset();
> +
> + replorigin_session_origin = InvalidRepOriginId;
> + replorigin_session_origin_lsn = InvalidXLogRecPtr;
> + replorigin_session_origin_timestamp = 0;
>
> 2a.
> Uppercase comment

Fixed.

>
> 2b.
> IIUC you are not doing the reset because you particularly want to do a
> reset, but really because this is the only (?) way to dis-associate
> the current process from owning the slot. Otherwise, the slot would be
> considered still "busy" and the subsequent replorigin_drop_by_name
> would be rejected. I thought the current comment should be expanded to
> explain all this background.

Updated.

>
> 2c.
> Perhaps it is non-standard to do so, but I wondered if you can just
> call pg_replication_origin_session_reset instead of
> replorigin_session_reset here so that there would only be 1 LOC
> instead of 4.

That is a psql function, invoking that indirectly is not really a
standard practice.

>
> ~~~
>
> 3. src/backend/replication/logical/tablesync.c
>
> + /*
>   * Cleanup the tablesync slot.
>   *
>   * This has to be done after updating the state because otherwise if
>
> Doesn't the same note ("This has to be done after...") also apply to
> the code dropping the origin slot? Maybe this note needs to be either
> duplicated or just put a common note about this above both of those
> slot drops.
>

Updated.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Peter Smith
Дата:
Here are some comments for v3-0001:

(all cosmetic / comments)

======

0. <apply>

There were multiple whitespace warnings reported by git apply.

[postgres@CentOS7-x64 oss_postgres_misc]$ git apply
../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch
../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:36:
indent with spaces.
        /*
../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:37:
indent with spaces.
         * Cleanup the tablesync slot and the origin tracking if exists.
../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:38:
indent with spaces.
         *
../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:39:
indent with spaces.
         * This has to be done after updating the state because otherwise if
../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:40:
indent with spaces.
         * there is an error while doing the database operations we won't be
warning: squelched 3 whitespace errors
warning: 8 lines add whitespace errors.

======

1. Commit message

I think the Replication Origin tracking is maybe not strictly speaking
a "slot", even though it does use the same GUC as true slots. With
that in mind, perhaps the following text is more accurate.

SUGGESTION
The replication origin tracking uses the same GUC
(max_replication_slots) as the tablesync slots for limiting resources.

In the current (HEAD) code the replication origin tracking of the
completed tablesync worker is dropped by the apply worker, but this
means there can be a small lag between when the tablesync worker
exited, and when its origin tracking is actually dropped.

Meanwhile, new tablesync workers can be launched and will immediately
try to acquire new slots and origin tracking. If this happens before
the worker's origin tracking gets dropped then the available number of
slots (max_replication_slots) can be exceeded, leading to the error as
reported.

To avoid this lag, the dropping of replicating origin tracking is
moved to the tablesync worker where it exits.

======

2. src/backend/replication/logical/tablesync.c - process_syncing_tables_for_sync

@@ -315,13 +316,43 @@ process_syncing_tables_for_sync(XLogRecPtr current_lsn)
  */
  walrcv_endstreaming(LogRepWorkerWalRcvConn, &tli);

+        /*
+         * Cleanup the tablesync slot and the origin tracking if exists.
+         *

Consider reversing that comment's first sentence so that it describes
what it will do in the same order as the code logic.

SUGGESTION
Cleanup the origin tracking and tablesync slot.

~~~

3.

+ /*
+ * Reset the origin session before dropping.
  *
- * This has to be done after updating the state because otherwise if
- * there is an error while doing the database operations we won't be
- * able to rollback dropped slot.
+ * This is required to reset the ownership of the slot
+ * and allow the slot to be dropped.
  */

"slot to be dropped" -> "origin to be dropped" (maybe?)

~~~

4. src/backend/replication/logical/tablesync.c -
process_syncing_tables_for_apply

@@ -451,27 +480,9 @@ process_syncing_tables_for_apply(XLogRecPtr current_lsn)
  started_tx = true;
  }

- /*
- * Remove the tablesync origin tracking if exists.
- *
- * The normal case origin drop is done here instead of in the
- * process_syncing_tables_for_sync function because we don't
- * allow to drop the origin till the process owning the origin
- * is alive.
- *
- * There is a chance that the user is concurrently performing
- * refresh for the subscription where we remove the table
- * state and its origin and by this time the origin might be
- * already removed. So passing missing_ok = true.
- */
- ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
-   rstate->relid,
-   originname,
-   sizeof(originname));
- replorigin_drop_by_name(originname, true, false);

  /*


This change results in a double blank line remaining instead of just a
single blank line.

------
Kind Regards,
Peter Smith
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Fri, Jul 29, 2022 at 7:37 PM Peter Smith <smithpb2250@gmail.com> wrote:
>
> Here are some comments for v3-0001:
>
> (all cosmetic / comments)
>
> ======
>
> 0. <apply>
>
> There were multiple whitespace warnings reported by git apply.
>
> [postgres@CentOS7-x64 oss_postgres_misc]$ git apply
> ../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch
> ../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:36:
> indent with spaces.
>         /*
> ../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:37:
> indent with spaces.
>          * Cleanup the tablesync slot and the origin tracking if exists.
> ../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:38:
> indent with spaces.
>          *
> ../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:39:
> indent with spaces.
>          * This has to be done after updating the state because otherwise if
> ../patches_misc/v3-0001-fix-excessive-replicating-origin-slots-issue.patch:40:
> indent with spaces.
>          * there is an error while doing the database operations we won't be
> warning: squelched 3 whitespace errors
> warning: 8 lines add whitespace errors.
>
> ======
>

Fixed.

> 1. Commit message
>
> I think the Replication Origin tracking is maybe not strictly speaking
> a "slot", even though it does use the same GUC as true slots. With
> that in mind, perhaps the following text is more accurate.
>
> SUGGESTION
> The replication origin tracking uses the same GUC
> (max_replication_slots) as the tablesync slots for limiting resources.
>
> In the current (HEAD) code the replication origin tracking of the
> completed tablesync worker is dropped by the apply worker, but this
> means there can be a small lag between when the tablesync worker
> exited, and when its origin tracking is actually dropped.
>
> Meanwhile, new tablesync workers can be launched and will immediately
> try to acquire new slots and origin tracking. If this happens before
> the worker's origin tracking gets dropped then the available number of
> slots (max_replication_slots) can be exceeded, leading to the error as
> reported.
>
> To avoid this lag, the dropping of replicating origin tracking is
> moved to the tablesync worker where it exits.
>
> ======

Updated as suggested.

>
> 2. src/backend/replication/logical/tablesync.c - process_syncing_tables_for_sync
>
> @@ -315,13 +316,43 @@ process_syncing_tables_for_sync(XLogRecPtr current_lsn)
>   */
>   walrcv_endstreaming(LogRepWorkerWalRcvConn, &tli);
>
> +        /*
> +         * Cleanup the tablesync slot and the origin tracking if exists.
> +         *
>
> Consider reversing that comment's first sentence so that it describes
> what it will do in the same order as the code logic.
>
> SUGGESTION
> Cleanup the origin tracking and tablesync slot.
>
> ~~~

Fixed.
>
> 3.
>
> + /*
> + * Reset the origin session before dropping.
>   *
> - * This has to be done after updating the state because otherwise if
> - * there is an error while doing the database operations we won't be
> - * able to rollback dropped slot.
> + * This is required to reset the ownership of the slot
> + * and allow the slot to be dropped.
>   */
>
> "slot to be dropped" -> "origin to be dropped" (maybe?)
>
> ~~~

Fixed

>
> 4. src/backend/replication/logical/tablesync.c -
> process_syncing_tables_for_apply
>
> @@ -451,27 +480,9 @@ process_syncing_tables_for_apply(XLogRecPtr current_lsn)
>   started_tx = true;
>   }
>
> - /*
> - * Remove the tablesync origin tracking if exists.
> - *
> - * The normal case origin drop is done here instead of in the
> - * process_syncing_tables_for_sync function because we don't
> - * allow to drop the origin till the process owning the origin
> - * is alive.
> - *
> - * There is a chance that the user is concurrently performing
> - * refresh for the subscription where we remove the table
> - * state and its origin and by this time the origin might be
> - * already removed. So passing missing_ok = true.
> - */
> - ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
> -   rstate->relid,
> -   originname,
> -   sizeof(originname));
> - replorigin_drop_by_name(originname, true, false);
>
>   /*
>
>
> This change results in a double blank line remaining instead of just a
> single blank line.
>

Fixed.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Peter Smith
Дата:
Here is my review comment for v4-0001.

(Just a nitpick about comments)

======

1. src/backend/replication/logical/tablesync.c - process_syncing_tables_for_sync

There are really just 2 main things that are being done for the cleanup here:
- Drop the origin tracking
- Drop the tablesync slot

So, IMO the code will have more clarity by having one bigger comment
for each of those drops, instead of commenting every step separately.

e.g.

BEFORE
/*
* Cleanup the tablesync origin tracking if exists.
*/
ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
  MyLogicalRepWorker->relid,
  originname,
  sizeof(originname));

/*
* Reset the origin session before dropping.
*
* This is required to reset the ownership of the slot
* and allow the origin to be dropped.
*/
replorigin_session_reset();

replorigin_session_origin = InvalidRepOriginId;
replorigin_session_origin_lsn = InvalidXLogRecPtr;
replorigin_session_origin_timestamp = 0;

/*
* There is a chance that the user is concurrently performing
* refresh for the subscription where we remove the table
* state and its origin and by this time the origin might be
* already removed. So passing missing_ok = true.
*/
replorigin_drop_by_name(originname, true, false);

/* Cleanup the tablesync slot. */
ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
MyLogicalRepWorker->relid,
syncslotname,
sizeof(syncslotname));

/*
* It is important to give an error if we are unable to drop the slot,
* otherwise, it won't be dropped till the corresponding subscription
* is dropped. So passing missing_ok = false.
*/
ReplicationSlotDropAtPubNode(LogRepWorkerWalRcvConn, syncslotname, false);


SUGGESTION

/*
* Cleanup the tablesync origin tracking.
*
* Resetting the origin session removes the ownership of the slot.
* This is needed to allow the origin to be dropped.
*
* Also, there is a chance that the user is concurrently performing
* refresh for the subscription where we remove the table
* state and its origin and by this time the origin might be
* already removed. So passing missing_ok = true.
*/
ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
  MyLogicalRepWorker->relid,
  originname,
  sizeof(originname));
replorigin_session_reset();
replorigin_session_origin = InvalidRepOriginId;
replorigin_session_origin_lsn = InvalidXLogRecPtr;
replorigin_session_origin_timestamp = 0;

replorigin_drop_by_name(originname, true, false);

/*
* Cleanup the tablesync slot.
*
* It is important to give an error if we are unable to drop the slot,
* otherwise, it won't be dropped till the corresponding subscription
* is dropped. So passing missing_ok = false.
*/
ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
MyLogicalRepWorker->relid,
syncslotname,
sizeof(syncslotname));
ReplicationSlotDropAtPubNode(LogRepWorkerWalRcvConn, syncslotname, false);


------
Kind Regards,
Peter Smith.
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Mon, Aug 1, 2022 at 11:50 AM Peter Smith <smithpb2250@gmail.com> wrote:
>
> Here is my review comment for v4-0001.
>
> (Just a nitpick about comments)
>
> ======
>
> 1. src/backend/replication/logical/tablesync.c - process_syncing_tables_for_sync
>
> There are really just 2 main things that are being done for the cleanup here:
> - Drop the origin tracking
> - Drop the tablesync slot
>
> So, IMO the code will have more clarity by having one bigger comment
> for each of those drops, instead of commenting every step separately.
>
> e.g.
>
> BEFORE
> /*
> * Cleanup the tablesync origin tracking if exists.
> */
> ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
>   MyLogicalRepWorker->relid,
>   originname,
>   sizeof(originname));
>
> /*
> * Reset the origin session before dropping.
> *
> * This is required to reset the ownership of the slot
> * and allow the origin to be dropped.
> */
> replorigin_session_reset();
>
> replorigin_session_origin = InvalidRepOriginId;
> replorigin_session_origin_lsn = InvalidXLogRecPtr;
> replorigin_session_origin_timestamp = 0;
>
> /*
> * There is a chance that the user is concurrently performing
> * refresh for the subscription where we remove the table
> * state and its origin and by this time the origin might be
> * already removed. So passing missing_ok = true.
> */
> replorigin_drop_by_name(originname, true, false);
>
> /* Cleanup the tablesync slot. */
> ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
> MyLogicalRepWorker->relid,
> syncslotname,
> sizeof(syncslotname));
>
> /*
> * It is important to give an error if we are unable to drop the slot,
> * otherwise, it won't be dropped till the corresponding subscription
> * is dropped. So passing missing_ok = false.
> */
> ReplicationSlotDropAtPubNode(LogRepWorkerWalRcvConn, syncslotname, false);
>
>
> SUGGESTION
>
> /*
> * Cleanup the tablesync origin tracking.
> *
> * Resetting the origin session removes the ownership of the slot.
> * This is needed to allow the origin to be dropped.
> *
> * Also, there is a chance that the user is concurrently performing
> * refresh for the subscription where we remove the table
> * state and its origin and by this time the origin might be
> * already removed. So passing missing_ok = true.
> */
> ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
>   MyLogicalRepWorker->relid,
>   originname,
>   sizeof(originname));
> replorigin_session_reset();
> replorigin_session_origin = InvalidRepOriginId;
> replorigin_session_origin_lsn = InvalidXLogRecPtr;
> replorigin_session_origin_timestamp = 0;
>
> replorigin_drop_by_name(originname, true, false);
>
> /*
> * Cleanup the tablesync slot.
> *
> * It is important to give an error if we are unable to drop the slot,
> * otherwise, it won't be dropped till the corresponding subscription
> * is dropped. So passing missing_ok = false.
> */
> ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
> MyLogicalRepWorker->relid,
> syncslotname,
> sizeof(syncslotname));
> ReplicationSlotDropAtPubNode(LogRepWorkerWalRcvConn, syncslotname, false);
>
Updated.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Peter Smith
Дата:
The patch v5-0001 looks good to me.

------
Kind Regards,
Peter Smith.
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Mon, Aug 1, 2022 at 3:46 PM Ajin Cherian <itsajin@gmail.com> wrote:
>
> On Mon, Aug 1, 2022 at 11:50 AM Peter Smith <smithpb2250@gmail.com> wrote:
> >
> > Here is my review comment for v4-0001.
> >
> > (Just a nitpick about comments)
> >
> > ======
> >
> > 1. src/backend/replication/logical/tablesync.c - process_syncing_tables_for_sync
> >
> > There are really just 2 main things that are being done for the cleanup here:
> > - Drop the origin tracking
> > - Drop the tablesync slot
> >
> > So, IMO the code will have more clarity by having one bigger comment
> > for each of those drops, instead of commenting every step separately.
> >
> > e.g.
> >
> > BEFORE
> > /*
> > * Cleanup the tablesync origin tracking if exists.
> > */
> > ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
> >   MyLogicalRepWorker->relid,
> >   originname,
> >   sizeof(originname));
> >
> > /*
> > * Reset the origin session before dropping.
> > *
> > * This is required to reset the ownership of the slot
> > * and allow the origin to be dropped.
> > */
> > replorigin_session_reset();
> >
> > replorigin_session_origin = InvalidRepOriginId;
> > replorigin_session_origin_lsn = InvalidXLogRecPtr;
> > replorigin_session_origin_timestamp = 0;
> >
> > /*
> > * There is a chance that the user is concurrently performing
> > * refresh for the subscription where we remove the table
> > * state and its origin and by this time the origin might be
> > * already removed. So passing missing_ok = true.
> > */
> > replorigin_drop_by_name(originname, true, false);
> >
> > /* Cleanup the tablesync slot. */
> > ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
> > MyLogicalRepWorker->relid,
> > syncslotname,
> > sizeof(syncslotname));
> >
> > /*
> > * It is important to give an error if we are unable to drop the slot,
> > * otherwise, it won't be dropped till the corresponding subscription
> > * is dropped. So passing missing_ok = false.
> > */
> > ReplicationSlotDropAtPubNode(LogRepWorkerWalRcvConn, syncslotname, false);
> >
> >
> > SUGGESTION
> >
> > /*
> > * Cleanup the tablesync origin tracking.
> > *
> > * Resetting the origin session removes the ownership of the slot.
> > * This is needed to allow the origin to be dropped.
> > *
> > * Also, there is a chance that the user is concurrently performing
> > * refresh for the subscription where we remove the table
> > * state and its origin and by this time the origin might be
> > * already removed. So passing missing_ok = true.
> > */
> > ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
> >   MyLogicalRepWorker->relid,
> >   originname,
> >   sizeof(originname));
> > replorigin_session_reset();
> > replorigin_session_origin = InvalidRepOriginId;
> > replorigin_session_origin_lsn = InvalidXLogRecPtr;
> > replorigin_session_origin_timestamp = 0;
> >
> > replorigin_drop_by_name(originname, true, false);
> >
> > /*
> > * Cleanup the tablesync slot.
> > *
> > * It is important to give an error if we are unable to drop the slot,
> > * otherwise, it won't be dropped till the corresponding subscription
> > * is dropped. So passing missing_ok = false.
> > */
> > ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
> > MyLogicalRepWorker->relid,
> > syncslotname,
> > sizeof(syncslotname));
> > ReplicationSlotDropAtPubNode(LogRepWorkerWalRcvConn, syncslotname, false);
> >
> Updated.

Thank you for working on this. I have a comment and a question:

                  * This has to be done after updating the state
because otherwise if
                  * there is an error while doing the database
operations we won't be
-                 * able to rollback dropped slot.
+                 * able to rollback dropped slot or origin tracking.

I think we can actually roll back dropping the replication origin. So
the above comment is true for only replication slots.

---
+       replorigin_session_reset();
+       replorigin_session_origin = InvalidRepOriginId;
+       replorigin_session_origin_lsn = InvalidXLogRecPtr;
+       replorigin_session_origin_timestamp = 0;
+
+       replorigin_drop_by_name(originname, true, false);

With this change, the committing the ongoing transaction will be done
without replication origin. Is this okay? it's probably okay, but
since tablesync worker commits other changes with replication origin
I'm concerned a bit there might be a corner case.

Regards,

--
Masahiko Sawada
EDB:  https://www.enterprisedb.com/



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Thu, Aug 4, 2022 at 1:12 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> Thank you for working on this. I have a comment and a question:
>
>                   * This has to be done after updating the state
> because otherwise if
>                   * there is an error while doing the database
> operations we won't be
> -                 * able to rollback dropped slot.
> +                 * able to rollback dropped slot or origin tracking.
>
> I think we can actually roll back dropping the replication origin. So
> the above comment is true for only replication slots.
>

Right, this comment should be updated.

> ---
> +       replorigin_session_reset();
> +       replorigin_session_origin = InvalidRepOriginId;
> +       replorigin_session_origin_lsn = InvalidXLogRecPtr;
> +       replorigin_session_origin_timestamp = 0;
> +
> +       replorigin_drop_by_name(originname, true, false);
>
> With this change, the committing the ongoing transaction will be done
> without replication origin. Is this okay? it's probably okay, but
> since tablesync worker commits other changes with replication origin
> I'm concerned a bit there might be a corner case.
>

AFAICS, we always apply the changes and commit/rollback those before
calling process_syncing_tables(). For example, see
apply_handle_commit(). So, I don't see how we can miss a corner case.
It seems to me that we shouldn't be in a transaction in
process_syncing_tables().

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Thu, Aug 4, 2022 at 9:47 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Thu, Aug 4, 2022 at 1:12 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > Thank you for working on this. I have a comment and a question:
> >
> >                   * This has to be done after updating the state
> > because otherwise if
> >                   * there is an error while doing the database
> > operations we won't be
> > -                 * able to rollback dropped slot.
> > +                 * able to rollback dropped slot or origin tracking.
> >
> > I think we can actually roll back dropping the replication origin. So
> > the above comment is true for only replication slots.
> >
>
> Right, this comment should be updated.
>
> > ---
> > +       replorigin_session_reset();
> > +       replorigin_session_origin = InvalidRepOriginId;
> > +       replorigin_session_origin_lsn = InvalidXLogRecPtr;
> > +       replorigin_session_origin_timestamp = 0;
> > +
> > +       replorigin_drop_by_name(originname, true, false);
> >
> > With this change, the committing the ongoing transaction will be done
> > without replication origin. Is this okay? it's probably okay, but
> > since tablesync worker commits other changes with replication origin
> > I'm concerned a bit there might be a corner case.
> >
>
> AFAICS, we always apply the changes and commit/rollback those before
> calling process_syncing_tables(). For example, see
> apply_handle_commit(). So, I don't see how we can miss a corner case.
> It seems to me that we shouldn't be in a transaction in
> process_syncing_tables().

I checked the code again and agreed with that.

Regards,

--
Masahiko Sawada
EDB:  https://www.enterprisedb.com/



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Thu, Aug 4, 2022 at 5:42 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> Thank you for working on this. I have a comment and a question:
>
>                   * This has to be done after updating the state
> because otherwise if
>                   * there is an error while doing the database
> operations we won't be
> -                 * able to rollback dropped slot.
> +                 * able to rollback dropped slot or origin tracking.
>
> I think we can actually roll back dropping the replication origin. So
> the above comment is true for only replication slots.
>

Fixed this.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Fri, Aug 12, 2022 at 12:04 AM Ajin Cherian <itsajin@gmail.com> wrote:
>
> On Thu, Aug 4, 2022 at 5:42 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > Thank you for working on this. I have a comment and a question:
> >
> >                   * This has to be done after updating the state
> > because otherwise if
> >                   * there is an error while doing the database
> > operations we won't be
> > -                 * able to rollback dropped slot.
> > +                 * able to rollback dropped slot or origin tracking.
> >
> > I think we can actually roll back dropping the replication origin. So
> > the above comment is true for only replication slots.
> >
>
> Fixed this.

Thank you for updating the patch.

                 /*
-                 * Cleanup the tablesync slot.
+                 * Cleanup the origin tracking and tablesync slot.
                  *
                  * This has to be done after updating the state
because otherwise if
                  * there is an error while doing the database
operations we won't be
                  * able to rollback dropped slot.
                  */

The first paragraph mentioned the cleanup of both tablesync slot and
origin, but the second paragraph mentioned only the tablesync slot
despite "this" probably meaning the cleanup of both. I think that we
can just add the comment for dropping the origin while not touching
the comment for dropping the slot.

The rest looks good to me.

Regards,

-- 
Masahiko Sawada
EDB:  https://www.enterprisedb.com/



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Fri, Aug 12, 2022 at 11:28 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Fri, Aug 12, 2022 at 12:04 AM Ajin Cherian <itsajin@gmail.com> wrote:
> >
> > On Thu, Aug 4, 2022 at 5:42 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > >
> > > Thank you for working on this. I have a comment and a question:
> > >
> > >                   * This has to be done after updating the state
> > > because otherwise if
> > >                   * there is an error while doing the database
> > > operations we won't be
> > > -                 * able to rollback dropped slot.
> > > +                 * able to rollback dropped slot or origin tracking.
> > >
> > > I think we can actually roll back dropping the replication origin. So
> > > the above comment is true for only replication slots.
> > >
> >
> > Fixed this.
>
> Thank you for updating the patch.
>
>                  /*
> -                 * Cleanup the tablesync slot.
> +                 * Cleanup the origin tracking and tablesync slot.
>                   *
>                   * This has to be done after updating the state
> because otherwise if
>                   * there is an error while doing the database
> operations we won't be
>                   * able to rollback dropped slot.
>                   */
>
> The first paragraph mentioned the cleanup of both tablesync slot and
> origin, but the second paragraph mentioned only the tablesync slot
> despite "this" probably meaning the cleanup of both. I think that we
> can just add the comment for dropping the origin while not touching
> the comment for dropping the slot.
>
> The rest looks good to me.
>

Updated.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Fri, Aug 12, 2022 at 12:44 PM Ajin Cherian <itsajin@gmail.com> wrote:
>
> On Fri, Aug 12, 2022 at 11:28 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > On Fri, Aug 12, 2022 at 12:04 AM Ajin Cherian <itsajin@gmail.com> wrote:
> > >
> > > On Thu, Aug 4, 2022 at 5:42 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > >
> > > > Thank you for working on this. I have a comment and a question:
> > > >
> > > >                   * This has to be done after updating the state
> > > > because otherwise if
> > > >                   * there is an error while doing the database
> > > > operations we won't be
> > > > -                 * able to rollback dropped slot.
> > > > +                 * able to rollback dropped slot or origin tracking.
> > > >
> > > > I think we can actually roll back dropping the replication origin. So
> > > > the above comment is true for only replication slots.
> > > >
> > >
> > > Fixed this.
> >
> > Thank you for updating the patch.
> >
> >                  /*
> > -                 * Cleanup the tablesync slot.
> > +                 * Cleanup the origin tracking and tablesync slot.
> >                   *
> >                   * This has to be done after updating the state
> > because otherwise if
> >                   * there is an error while doing the database
> > operations we won't be
> >                   * able to rollback dropped slot.
> >                   */
> >
> > The first paragraph mentioned the cleanup of both tablesync slot and
> > origin, but the second paragraph mentioned only the tablesync slot
> > despite "this" probably meaning the cleanup of both. I think that we
> > can just add the comment for dropping the origin while not touching
> > the comment for dropping the slot.
> >
> > The rest looks good to me.
> >
>
> Updated.

Thank you for updating the patch.

        /*
-        * Cleanup the tablesync slot.
+        * Cleanup the origin tracking and tablesync slot.
         *
         * This has to be done after updating the state because otherwise if
         * there is an error while doing the database operations we won't be
-        * able to rollback dropped slot.
+        * able to rollback the dropped slot. Origin tracking is dropped before
+        * the tablesync slot is dropped.
         */

ISTM that the "This" in the first sentence in the second paragraph
still indicates the cleanup of the origin tracking and table sync
slot. How about not having the common comment for both like the patch
I've attached? In addition to this change, I moved the code to drop
the origin before stopping the streaming so that it can be close to
the slot drop. But feel free to revert this change.

Regards,

-- 
Masahiko Sawada
EDB:  https://www.enterprisedb.com/

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Fri, Aug 12, 2022 at 3:22 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> ISTM that the "This" in the first sentence in the second paragraph
> still indicates the cleanup of the origin tracking and table sync
> slot. How about not having the common comment for both like the patch
> I've attached? In addition to this change, I moved the code to drop
> the origin before stopping the streaming so that it can be close to
> the slot drop. But feel free to revert this change.
>

This looks fine to me.

regards,
Ajin Cherian
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Fri, Aug 12, 2022 at 10:52 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Fri, Aug 12, 2022 at 12:44 PM Ajin Cherian <itsajin@gmail.com> wrote:
> >
>
> ISTM that the "This" in the first sentence in the second paragraph
> still indicates the cleanup of the origin tracking and table sync
> slot. How about not having the common comment for both like the patch
> I've attached? In addition to this change, I moved the code to drop
> the origin before stopping the streaming so that it can be close to
> the slot drop. But feel free to revert this change.
>

After this change, won't the code in AlterSubscription_refresh()
related to origin drop [1] needs to be updated? Firstly, now even if
the state is SYNCDONE, we would have already dropped the origin. Then,
I think the race mentioned in the comments no longer remains true
because before dropping the origin in tablesync worker, we would have
taken a conflicting lock on pg_subscription_rel.

[1] -
/*
* For READY state, we would have already dropped the
* tablesync origin.
*/
if (state != SUBREL_STATE_READY)
{
char originname[NAMEDATALEN];

/*
* Drop the tablesync's origin tracking if exists.
*
* It is possible that the origin is not yet created for
* tablesync worker, this can happen for the states before
* SUBREL_STATE_FINISHEDCOPY. The apply worker can also
* concurrently try to drop the origin and by this time
* the origin might be already removed. For these reasons,
* passing missing_ok = true.
*/
ReplicationOriginNameForTablesync(sub->oid, relid, originname,
  sizeof(originname));
replorigin_drop_by_name(originname, true, false);
}

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Tue, Aug 16, 2022 at 8:36 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Fri, Aug 12, 2022 at 10:52 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > On Fri, Aug 12, 2022 at 12:44 PM Ajin Cherian <itsajin@gmail.com> wrote:
> > >
> >
> > ISTM that the "This" in the first sentence in the second paragraph
> > still indicates the cleanup of the origin tracking and table sync
> > slot. How about not having the common comment for both like the patch
> > I've attached? In addition to this change, I moved the code to drop
> > the origin before stopping the streaming so that it can be close to
> > the slot drop. But feel free to revert this change.
> >
>
> After this change, won't the code in AlterSubscription_refresh()
> related to origin drop [1] needs to be updated? Firstly, now even if
> the state is SYNCDONE, we would have already dropped the origin. Then,
> I think the race mentioned in the comments no longer remains true
> because before dropping the origin in tablesync worker, we would have
> taken a conflicting lock on pg_subscription_rel.

Right.

Probably the same is true for DropSubscription()? That is, we can skip
removing the origin if the state is SYNCDONE (READ-state relations are
already filtered by GetSubscriptionRelations()).

Regards,

-- 
Masahiko Sawada
EDB:  https://www.enterprisedb.com/



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Wed, Aug 17, 2022 at 1:37 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Tue, Aug 16, 2022 at 8:36 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > On Fri, Aug 12, 2022 at 10:52 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > >
> > > On Fri, Aug 12, 2022 at 12:44 PM Ajin Cherian <itsajin@gmail.com> wrote:
> > > >
> > >
> > > ISTM that the "This" in the first sentence in the second paragraph
> > > still indicates the cleanup of the origin tracking and table sync
> > > slot. How about not having the common comment for both like the patch
> > > I've attached? In addition to this change, I moved the code to drop
> > > the origin before stopping the streaming so that it can be close to
> > > the slot drop. But feel free to revert this change.
> > >
> >
> > After this change, won't the code in AlterSubscription_refresh()
> > related to origin drop [1] needs to be updated? Firstly, now even if
> > the state is SYNCDONE, we would have already dropped the origin. Then,
> > I think the race mentioned in the comments no longer remains true
> > because before dropping the origin in tablesync worker, we would have
> > taken a conflicting lock on pg_subscription_rel.
>
> Right.
>
> Probably the same is true for DropSubscription()?
>

Yes.

> That is, we can skip
> removing the origin if the state is SYNCDONE (READ-state relations are
> already filtered by GetSubscriptionRelations()).
>

I think we can pass the second parameter as false in
GetSubscriptionRelations() and then filter outside for both READY and
SYNCDONE states.

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Wed, Aug 17, 2022 at 6:47 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Wed, Aug 17, 2022 at 1:37 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > On Tue, Aug 16, 2022 at 8:36 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> > >
> > > On Fri, Aug 12, 2022 at 10:52 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > >
> > > > On Fri, Aug 12, 2022 at 12:44 PM Ajin Cherian <itsajin@gmail.com> wrote:
> > > > >
> > > >
> > > > ISTM that the "This" in the first sentence in the second paragraph
> > > > still indicates the cleanup of the origin tracking and table sync
> > > > slot. How about not having the common comment for both like the patch
> > > > I've attached? In addition to this change, I moved the code to drop
> > > > the origin before stopping the streaming so that it can be close to
> > > > the slot drop. But feel free to revert this change.
> > > >
> > >
> > > After this change, won't the code in AlterSubscription_refresh()
> > > related to origin drop [1] needs to be updated? Firstly, now even if
> > > the state is SYNCDONE, we would have already dropped the origin. Then,
> > > I think the race mentioned in the comments no longer remains true
> > > because before dropping the origin in tablesync worker, we would have
> > > taken a conflicting lock on pg_subscription_rel.
> >
> > Right.
> >
> > Probably the same is true for DropSubscription()?
> >
>
> Yes.
>
> > That is, we can skip
> > removing the origin if the state is SYNCDONE (READ-state relations are
> > already filtered by GetSubscriptionRelations()).
> >
>
> I think we can pass the second parameter as false in
> GetSubscriptionRelations() and then filter outside for both READY and
> SYNCDONE states.

Agreed.

Ajin Cherian, do you want to update the patch according to these
comments? or shall I?

Regards,

-- 
Masahiko Sawada
EDB:  https://www.enterprisedb.com/



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Thu, Aug 18, 2022 at 10:50 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
>
> Ajin Cherian, do you want to update the patch according to these
> comments? or shall I?
>
> Regards,
>

I will create a patch for this in a short while.

regards,
Ajin Cherian
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Thu, Aug 18, 2022 at 11:38 AM Ajin Cherian <itsajin@gmail.com> wrote:
>
> On Thu, Aug 18, 2022 at 10:50 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> >
> > Ajin Cherian, do you want to update the patch according to these
> > comments? or shall I?
> >
> > Regards,
> >
>
> I will create a patch for this in a short while.

Great, thanks!

Regards,

-- 
Masahiko Sawada
EDB:  https://www.enterprisedb.com/



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Thu, Aug 18, 2022 at 12:40 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Thu, Aug 18, 2022 at 11:38 AM Ajin Cherian <itsajin@gmail.com> wrote:
> >
> > On Thu, Aug 18, 2022 at 10:50 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > >
> > >
> > > Ajin Cherian, do you want to update the patch according to these
> > > comments? or shall I?
> > >
> > > Regards,
> > >
> >
> > I will create a patch for this in a short while.
>
> Great, thanks!
>
> Regards,
>

Attached a patch with the changes. In DropSubscription(), I have let
GetSubscriptionRelations()
filter the READY state relations but added a check for !SYNCDONE state
while cleaning up origin
tracking. This matches with the logic used for clean-up of tablesync
slots below in the same function.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Thu, Aug 18, 2022 at 12:44 PM Ajin Cherian <itsajin@gmail.com> wrote:
>
> On Thu, Aug 18, 2022 at 12:40 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > On Thu, Aug 18, 2022 at 11:38 AM Ajin Cherian <itsajin@gmail.com> wrote:
> > >
> > > On Thu, Aug 18, 2022 at 10:50 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > >
> > > >
> > > > Ajin Cherian, do you want to update the patch according to these
> > > > comments? or shall I?
> > > >
> > > > Regards,
> > > >
> > >
> > > I will create a patch for this in a short while.
> >
> > Great, thanks!
> >
> > Regards,
> >
>
> Attached a patch with the changes.

Thank you for updating the patch!

> In DropSubscription(), I have let
> GetSubscriptionRelations()
> filter the READY state relations but added a check for !SYNCDONE state
> while cleaning up origin
> tracking. This matches with the logic used for clean-up of tablesync
> slots below in the same function.

Looks good.

I have one minor comment:

-                    * SUBREL_STATE_FINISHEDCOPY. The apply worker can also
-                    * concurrently try to drop the origin and by this time
-                    * the origin might be already removed. For these reasons,
-                    * passing missing_ok = true.
+                    * SUBREL_STATE_FINISHEDCOPY. So passing missing_ok = true.

I think we should change "the apply worker" to "the tablesync worker"
but should not remove this sentence. The fact that another process
could concurrently try to drop the origin is still true.

The rest looks good to me.

Regards,

--
Masahiko Sawada
EDB:  https://www.enterprisedb.com/



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Thu, Aug 18, 2022 at 3:46 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> Looks good.
>
> I have one minor comment:
>
> -                    * SUBREL_STATE_FINISHEDCOPY. The apply worker can also
> -                    * concurrently try to drop the origin and by this time
> -                    * the origin might be already removed. For these reasons,
> -                    * passing missing_ok = true.
> +                    * SUBREL_STATE_FINISHEDCOPY. So passing missing_ok = true.
>
> I think we should change "the apply worker" to "the tablesync worker"
> but should not remove this sentence. The fact that another process
> could concurrently try to drop the origin is still true.
>
> The rest looks good to me.
>

Updated as described.

regards,
Ajin Cherian
Fujitsu Australia

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Thu, Aug 18, 2022 at 11:28 AM Ajin Cherian <itsajin@gmail.com> wrote:
>
> Updated as described.
>

Hubert, will you be able to verify if the proposed patch works in your
exact scenario?

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
hubert depesz lubaczewski
Дата:
On Thu, Aug 18, 2022 at 04:00:29PM +0530, Amit Kapila wrote:
> Hubert, will you be able to verify if the proposed patch works in your
> exact scenario?

Not really, sorry, the environment in which I'm doing the tests is
pretty closed, and adding custom code would be virtually impossible.

Best regards,

depesz




Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Thu, Aug 18, 2022 at 11:28 AM Ajin Cherian <itsajin@gmail.com> wrote:
>
> On Thu, Aug 18, 2022 at 3:46 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > Looks good.
> >
> > I have one minor comment:
> >
> > -                    * SUBREL_STATE_FINISHEDCOPY. The apply worker can also
> > -                    * concurrently try to drop the origin and by this time
> > -                    * the origin might be already removed. For these reasons,
> > -                    * passing missing_ok = true.
> > +                    * SUBREL_STATE_FINISHEDCOPY. So passing missing_ok = true.
> >
> > I think we should change "the apply worker" to "the tablesync worker"
> > but should not remove this sentence. The fact that another process
> > could concurrently try to drop the origin is still true.
> >
> > The rest looks good to me.
> >
>
> Updated as described.
>

The patch looks good to me though I would like to test it a bit more
before pushing. Do we want to back-patch this? It is a clear
improvement as compared to the current implementation but OTOH, users
can use the workaround of increasing max_replication_slots, so, one
can say that it is okay to just make this change in HEAD. What do you
think?

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Wed, Aug 24, 2022 at 12:26 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Thu, Aug 18, 2022 at 11:28 AM Ajin Cherian <itsajin@gmail.com> wrote:
> >
> > On Thu, Aug 18, 2022 at 3:46 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > Looks good.
> > >
> > > I have one minor comment:
> > >
> > > -                    * SUBREL_STATE_FINISHEDCOPY. The apply worker can also
> > > -                    * concurrently try to drop the origin and by this time
> > > -                    * the origin might be already removed. For these reasons,
> > > -                    * passing missing_ok = true.
> > > +                    * SUBREL_STATE_FINISHEDCOPY. So passing missing_ok = true.
> > >
> > > I think we should change "the apply worker" to "the tablesync worker"
> > > but should not remove this sentence. The fact that another process
> > > could concurrently try to drop the origin is still true.
> > >
> > > The rest looks good to me.
> > >
> >
> > Updated as described.
> >
>
> The patch looks good to me though I would like to test it a bit more
> before pushing. Do we want to back-patch this? It is a clear
> improvement as compared to the current implementation but OTOH, users
> can use the workaround of increasing max_replication_slots, so, one
> can say that it is okay to just make this change in HEAD. What do you
> think?
>

I agree. Let's just add the change to HEAD since there is a workaround.

regards,
Ajin Cherian
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Tue, Aug 23, 2022 at 7:56 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Thu, Aug 18, 2022 at 11:28 AM Ajin Cherian <itsajin@gmail.com> wrote:
> >
> > On Thu, Aug 18, 2022 at 3:46 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > Looks good.
> > >
> > > I have one minor comment:
> > >
> > > -                    * SUBREL_STATE_FINISHEDCOPY. The apply worker can also
> > > -                    * concurrently try to drop the origin and by this time
> > > -                    * the origin might be already removed. For these reasons,
> > > -                    * passing missing_ok = true.
> > > +                    * SUBREL_STATE_FINISHEDCOPY. So passing missing_ok = true.
> > >
> > > I think we should change "the apply worker" to "the tablesync worker"
> > > but should not remove this sentence. The fact that another process
> > > could concurrently try to drop the origin is still true.
> > >
> > > The rest looks good to me.
> > >
> >
> > Updated as described.
> >
>
> The patch looks good to me though I would like to test it a bit more
> before pushing.
>

While testing/reviewing it further, I noticed that the patch has used
missing_ok as true when dropping origin via tablesync worker. I don't
think that is correct because the concurrent operations that remove
origin like a refresh for the subscription take an access exclusive
lock on pg_subscription which prevent the previous operation to update
the rel state to SUBREL_STATE_SYNCDONE to succeed. So, I think we
should pass missing_ok as false which would be consistent with slot
handling. I have changed that and comments a few places. What do you
think of the attached?

-- 
With Regards,
Amit Kapila.

Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Ajin Cherian
Дата:
On Wed, Aug 24, 2022 at 3:54 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Tue, Aug 23, 2022 at 7:56 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > On Thu, Aug 18, 2022 at 11:28 AM Ajin Cherian <itsajin@gmail.com> wrote:
> > >
> > > On Thu, Aug 18, 2022 at 3:46 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > > Looks good.
> > > >
> > > > I have one minor comment:
> > > >
> > > > -                    * SUBREL_STATE_FINISHEDCOPY. The apply worker can also
> > > > -                    * concurrently try to drop the origin and by this time
> > > > -                    * the origin might be already removed. For these reasons,
> > > > -                    * passing missing_ok = true.
> > > > +                    * SUBREL_STATE_FINISHEDCOPY. So passing missing_ok = true.
> > > >
> > > > I think we should change "the apply worker" to "the tablesync worker"
> > > > but should not remove this sentence. The fact that another process
> > > > could concurrently try to drop the origin is still true.
> > > >
> > > > The rest looks good to me.
> > > >
> > >
> > > Updated as described.
> > >
> >
> > The patch looks good to me though I would like to test it a bit more
> > before pushing.
> >
>
> While testing/reviewing it further, I noticed that the patch has used
> missing_ok as true when dropping origin via tablesync worker. I don't
> think that is correct because the concurrent operations that remove
> origin like a refresh for the subscription take an access exclusive
> lock on pg_subscription which prevent the previous operation to update
> the rel state to SUBREL_STATE_SYNCDONE to succeed. So, I think we
> should pass missing_ok as false which would be consistent with slot
> handling. I have changed that and comments a few places. What do you
> think of the attached?
>

Yes, this makes sense. I tested with a debugger to create simultaneous
alter subscription refresh publication AND tablesync worker
deleting the tracking origin. What I see is that the alter subscription command
gets the lock on SubscriptionRelRelationId  and then actually goes on to
kill the tablesync worker. Even if the tablesync worker is waiting for
the same lock,
it looks like the SIGTERM is being handled and the worker is killed.

From my testing, there doesn't seem to be a case where the tablesync worker
would try and drop a previously dropped origin. So, I think we can pass
missing_ok as 'false' while dropping origin. The patch looks good to me.

regards,
Ajin Cherian
Fujitsu Australia



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Thu, Aug 25, 2022 at 7:38 PM Ajin Cherian <itsajin@gmail.com> wrote:
>
> On Wed, Aug 24, 2022 at 3:54 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > On Tue, Aug 23, 2022 at 7:56 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> > >
> > > On Thu, Aug 18, 2022 at 11:28 AM Ajin Cherian <itsajin@gmail.com> wrote:
> > > >
> > > > On Thu, Aug 18, 2022 at 3:46 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > > > Looks good.
> > > > >
> > > > > I have one minor comment:
> > > > >
> > > > > -                    * SUBREL_STATE_FINISHEDCOPY. The apply worker can also
> > > > > -                    * concurrently try to drop the origin and by this time
> > > > > -                    * the origin might be already removed. For these reasons,
> > > > > -                    * passing missing_ok = true.
> > > > > +                    * SUBREL_STATE_FINISHEDCOPY. So passing missing_ok = true.
> > > > >
> > > > > I think we should change "the apply worker" to "the tablesync worker"
> > > > > but should not remove this sentence. The fact that another process
> > > > > could concurrently try to drop the origin is still true.
> > > > >
> > > > > The rest looks good to me.
> > > > >
> > > >
> > > > Updated as described.
> > > >
> > >
> > > The patch looks good to me though I would like to test it a bit more
> > > before pushing.
> > >
> >
> > While testing/reviewing it further, I noticed that the patch has used
> > missing_ok as true when dropping origin via tablesync worker. I don't
> > think that is correct because the concurrent operations that remove
> > origin like a refresh for the subscription take an access exclusive
> > lock on pg_subscription which prevent the previous operation to update
> > the rel state to SUBREL_STATE_SYNCDONE to succeed. So, I think we
> > should pass missing_ok as false which would be consistent with slot
> > handling. I have changed that and comments a few places. What do you
> > think of the attached?
> >
>
> Yes, this makes sense. I tested with a debugger to create simultaneous
> alter subscription refresh publication AND tablesync worker
> deleting the tracking origin. What I see is that the alter subscription command
> gets the lock on SubscriptionRelRelationId  and then actually goes on to
> kill the tablesync worker. Even if the tablesync worker is waiting for
> the same lock,
> it looks like the SIGTERM is being handled and the worker is killed.
>
> From my testing, there doesn't seem to be a case where the tablesync worker
> would try and drop a previously dropped origin. So, I think we can pass
> missing_ok as 'false' while dropping origin. The patch looks good to me.
>

Thanks for the testing. I'll push this sometime early next week (by
Tuesday) unless Sawada-San or someone else has any comments on it.

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Fri, Aug 26, 2022 at 7:04 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> Thanks for the testing. I'll push this sometime early next week (by
> Tuesday) unless Sawada-San or someone else has any comments on it.
>

Pushed.

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
hubert depesz lubaczewski
Дата:
On Tue, Aug 30, 2022 at 12:14:00PM +0530, Amit Kapila wrote:
> > Thanks for the testing. I'll push this sometime early next week (by
> > Tuesday) unless Sawada-San or someone else has any comments on it.
> Pushed.

Thank you very much.

Best regards,

depesz




Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Tue, Aug 30, 2022 at 3:44 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Fri, Aug 26, 2022 at 7:04 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > Thanks for the testing. I'll push this sometime early next week (by
> > Tuesday) unless Sawada-San or someone else has any comments on it.
> >
>
> Pushed.

Tom reported buildfarm failures[1] and I've investigated the cause and
concluded this commit is relevant.

In process_syncing_tables_for_sync(), we have the following code:

        UpdateSubscriptionRelState(MyLogicalRepWorker->subid,
                                   MyLogicalRepWorker->relid,
                                   MyLogicalRepWorker->relstate,
                                   MyLogicalRepWorker->relstate_lsn);

        ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
                                          MyLogicalRepWorker->relid,
                                          originname,
                                          sizeof(originname));
        replorigin_session_reset();
        replorigin_session_origin = InvalidRepOriginId;
        replorigin_session_origin_lsn = InvalidXLogRecPtr;
        replorigin_session_origin_timestamp = 0;

        /*
         * We expect that origin must be present. The concurrent operations
         * that remove origin like a refresh for the subscription take an
         * access exclusive lock on pg_subscription which prevent the previou
         * operation to update the rel state to SUBREL_STATE_SYNCDONE to
         * succeed.
         */
        replorigin_drop_by_name(originname, false, false);

        /*
         * End streaming so that LogRepWorkerWalRcvConn can be used to drop
         * the slot.
         */
        walrcv_endstreaming(LogRepWorkerWalRcvConn, &tli);

        /*
         * Cleanup the tablesync slot.
         *
         * This has to be done after the data changes because otherwise if
         * there is an error while doing the database operations we won't be
         * able to rollback dropped slot.
         */
        ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
                                        MyLogicalRepWorker->relid,
                                        syncslotname,
                                        sizeof(syncslotname));

If the table sync worker errored at walrcv_endstreaming(), we assumed
that both dropping the replication origin and updating relstate are
rolled back, which however was wrong. Indeed, the replication origin
is not dropped but the in-memory state is reset. Therefore, after the
tablesync worker restarts, it starts logical replication with starting
point 0/0. Consequently, it  ends up applying the transaction that has
already been applied.

Regards,

[1] https://www.postgresql.org/message-id/115136.1662733870%40sss.pgh.pa.us

--
Masahiko Sawada



RE: Excessive number of replication slots for 12->14 logical replication

От
"houzj.fnst@fujitsu.com"
Дата:
On Saturday, September 10, 2022 5:49 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> 
> On Tue, Aug 30, 2022 at 3:44 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > On Fri, Aug 26, 2022 at 7:04 AM Amit Kapila <amit.kapila16@gmail.com>
> wrote:
> > >
> > > Thanks for the testing. I'll push this sometime early next week (by
> > > Tuesday) unless Sawada-San or someone else has any comments on it.
> > >
> >
> > Pushed.
> 
> Tom reported buildfarm failures[1] and I've investigated the cause and
> concluded this commit is relevant.
> 
> In process_syncing_tables_for_sync(), we have the following code:
> 
>         UpdateSubscriptionRelState(MyLogicalRepWorker->subid,
>                                    MyLogicalRepWorker->relid,
>                                    MyLogicalRepWorker->relstate,
>                                    MyLogicalRepWorker->relstate_lsn);
> 
>         ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
>                                           MyLogicalRepWorker->relid,
>                                           originname,
>                                           sizeof(originname));
>         replorigin_session_reset();
>         replorigin_session_origin = InvalidRepOriginId;
>         replorigin_session_origin_lsn = InvalidXLogRecPtr;
>         replorigin_session_origin_timestamp = 0;
> 
>         /*
>          * We expect that origin must be present. The concurrent operations
>          * that remove origin like a refresh for the subscription take an
>          * access exclusive lock on pg_subscription which prevent the previou
>          * operation to update the rel state to SUBREL_STATE_SYNCDONE to
>          * succeed.
>          */
>         replorigin_drop_by_name(originname, false, false);
> 
>         /*
>          * End streaming so that LogRepWorkerWalRcvConn can be used to
> drop
>          * the slot.
>          */
>         walrcv_endstreaming(LogRepWorkerWalRcvConn, &tli);
> 
>         /*
>          * Cleanup the tablesync slot.
>          *
>          * This has to be done after the data changes because otherwise if
>          * there is an error while doing the database operations we won't be
>          * able to rollback dropped slot.
>          */
>         ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
>                                         MyLogicalRepWorker->relid,
>                                         syncslotname,
>                                         sizeof(syncslotname));
> 
> If the table sync worker errored at walrcv_endstreaming(), we assumed that both
> dropping the replication origin and updating relstate are rolled back, which
> however was wrong. Indeed, the replication origin is not dropped but the
> in-memory state is reset. Therefore, after the tablesync worker restarts, it starts
> logical replication with starting point 0/0. Consequently, it  ends up applying
> the transaction that has already been applied.

Thanks for the analysis !

I think you are right. The replorigin_drop_by_name() will clear the
remote_lsn/local_lsn in shared memory which won't be rollback if we fail to
drop the origin.

Per off-list discussion with Amit. To fix this problem, I think we need to drop
the origin in table sync worker after committing the transaction which set the
relstate to SYNCDONE. Because it can make sure that the worker won’t be
restarted even if we fail to drop the origin. Besides, we need to add the
origin drop code back in apply worker in case the table sync worker failed to
drop the origin before it exits(which seems a rare case). I will share the
patch if we agree with the fix.

Best regards,
Hou zj


Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Sat, Sep 10, 2022 at 3:19 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Tue, Aug 30, 2022 at 3:44 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > Pushed.
>
> Tom reported buildfarm failures[1] and I've investigated the cause and
> concluded this commit is relevant.
>

I was checking the failure logs at [1]. In below logs from 100_bugs_twoways.log:

2022-09-09 09:30:18.950 EDT [631b3fea.1c0:24]
pg_16400_sync_16392_7141371862484106124 STATEMENT:  START_REPLICATION
SLOT "pg_16400_sync_16392_7141371862484106124" LOGICAL 0/1CC9510
(proto_version '3', origin 'any', publication_names '"testpub"')
2022-09-09 09:30:18.952 EDT [631b3fea.1c0:25]
pg_16400_sync_16392_7141371862484106124 ERROR:  could not find record
while sending logically-decoded data: missing contrecord at 0/1CCF9F0
2022-09-09 09:30:18.952 EDT [631b3fea.1c0:26]
pg_16400_sync_16392_7141371862484106124 STATEMENT:  START_REPLICATION
SLOT "pg_16400_sync_16392_7141371862484106124" LOGICAL 0/1CC9510
(proto_version '3', origin 'any', publication_names '"testpub"')
ERROR:  could not find record while sending logically-decoded data:
missing contrecord at 0/1CCF9F0
2022-09-09 09:30:18.952 EDT [631b3fea.2b14:2] ERROR:  error while
shutting down streaming COPY: ERROR:  could not find record while
sending logically-decoded data: missing contrecord at 0/1CCF9F0
2022-09-09 09:30:18.953 EDT [631b3fea.1c0:27]
pg_16400_sync_16392_7141371862484106124 LOG:  disconnection: session
time: 0:00:00.168 user=pgrunner database=d1 host=127.0.0.1 port=53881
2022-09-09 09:30:18.965 EDT [631b3fe6.137c:4] LOG:  background worker
"logical replication worker" (PID 11028) exited with exit code 1
....
.....
2022-09-09 09:30:19.437 EDT [631b3feb.26e8:1] LOG:  logical
replication table synchronization worker for subscription "testsub",
table "t" has started
....
....
2022-09-09 09:30:19.513 EDT [631b3feb.840:5]
pg_16400_sync_16392_7141371862484106124 LOG:  received replication
command: START_REPLICATION SLOT
"pg_16400_sync_16392_7141371862484106124" LOGICAL 0/0 (proto_version
'3', origin 'any', publication_names '"testpub"')
2022-09-09 09:30:19.513 EDT [631b3feb.840:6]
pg_16400_sync_16392_7141371862484106124 STATEMENT:  START_REPLICATION
SLOT "pg_16400_sync_16392_7141371862484106124" LOGICAL 0/0
(proto_version '3', origin 'any', publication_names '"testpub"')
2022-09-09 09:30:19.515 EDT [631b3feb.840:7]
pg_16400_sync_16392_7141371862484106124 LOG:  starting logical
decoding for slot "pg_16400_sync_16392_7141371862484106124"
2022-09-09 09:30:19.515 EDT [631b3feb.840:8]
pg_16400_sync_16392_7141371862484106124 DETAIL:  Streaming
transactions committing after 0/1CCF9F0, reading WAL from 0/1CC94D8.


One thing is not clear to me how the first time error: "could not find
record while sending logically-decoded data ..." can happen due to
this commit? Also, based on the origin even if the client sends a
prior location (0/0 in this case) but the server will still start from
the location where the client has confirmed the commit (aka
confirmed_flush location). Isn't that the reason why the above LOG
says (reading WAL from 0/1CC94D8)? See the below code in
CreateDecodingContext():

if (start_lsn == InvalidXLogRecPtr)
{
/* continue from last position */
start_lsn = slot->data.confirmed_flush;

If this theory is correct then this commit won't be the cause of BF
failure but it is quite possible that I am missing something here.

[1] - https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=jacana&dt=2022-09-09+12%3A03%3A46

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Sat, Sep 10, 2022 at 11:06 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Sat, Sep 10, 2022 at 3:19 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > On Tue, Aug 30, 2022 at 3:44 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> > >
> > > Pushed.
> >
> > Tom reported buildfarm failures[1] and I've investigated the cause and
> > concluded this commit is relevant.
> >
>
> I was checking the failure logs at [1]. In below logs from 100_bugs_twoways.log:
>
> 2022-09-09 09:30:18.950 EDT [631b3fea.1c0:24]
> pg_16400_sync_16392_7141371862484106124 STATEMENT:  START_REPLICATION
> SLOT "pg_16400_sync_16392_7141371862484106124" LOGICAL 0/1CC9510
> (proto_version '3', origin 'any', publication_names '"testpub"')
> 2022-09-09 09:30:18.952 EDT [631b3fea.1c0:25]
> pg_16400_sync_16392_7141371862484106124 ERROR:  could not find record
> while sending logically-decoded data: missing contrecord at 0/1CCF9F0
> 2022-09-09 09:30:18.952 EDT [631b3fea.1c0:26]
> pg_16400_sync_16392_7141371862484106124 STATEMENT:  START_REPLICATION
> SLOT "pg_16400_sync_16392_7141371862484106124" LOGICAL 0/1CC9510
> (proto_version '3', origin 'any', publication_names '"testpub"')
> ERROR:  could not find record while sending logically-decoded data:
> missing contrecord at 0/1CCF9F0
> 2022-09-09 09:30:18.952 EDT [631b3fea.2b14:2] ERROR:  error while
> shutting down streaming COPY: ERROR:  could not find record while
> sending logically-decoded data: missing contrecord at 0/1CCF9F0
> 2022-09-09 09:30:18.953 EDT [631b3fea.1c0:27]
> pg_16400_sync_16392_7141371862484106124 LOG:  disconnection: session
> time: 0:00:00.168 user=pgrunner database=d1 host=127.0.0.1 port=53881
> 2022-09-09 09:30:18.965 EDT [631b3fe6.137c:4] LOG:  background worker
> "logical replication worker" (PID 11028) exited with exit code 1
> ....
> .....
> 2022-09-09 09:30:19.437 EDT [631b3feb.26e8:1] LOG:  logical
> replication table synchronization worker for subscription "testsub",
> table "t" has started
> ....
> ....
> 2022-09-09 09:30:19.513 EDT [631b3feb.840:5]
> pg_16400_sync_16392_7141371862484106124 LOG:  received replication
> command: START_REPLICATION SLOT
> "pg_16400_sync_16392_7141371862484106124" LOGICAL 0/0 (proto_version
> '3', origin 'any', publication_names '"testpub"')
> 2022-09-09 09:30:19.513 EDT [631b3feb.840:6]
> pg_16400_sync_16392_7141371862484106124 STATEMENT:  START_REPLICATION
> SLOT "pg_16400_sync_16392_7141371862484106124" LOGICAL 0/0
> (proto_version '3', origin 'any', publication_names '"testpub"')
> 2022-09-09 09:30:19.515 EDT [631b3feb.840:7]
> pg_16400_sync_16392_7141371862484106124 LOG:  starting logical
> decoding for slot "pg_16400_sync_16392_7141371862484106124"
> 2022-09-09 09:30:19.515 EDT [631b3feb.840:8]
> pg_16400_sync_16392_7141371862484106124 DETAIL:  Streaming
> transactions committing after 0/1CCF9F0, reading WAL from 0/1CC94D8.
>
>
> One thing is not clear to me how the first time error: "could not find
> record while sending logically-decoded data ..." can happen due to
> this commit? Also, based on the origin even if the client sends a
> prior location (0/0 in this case) but the server will still start from
> the location where the client has confirmed the commit (aka
> confirmed_flush location).
>

I missed the point that if the 'origin_lsn' is ahead of the
'confirmed_flush' location then it will start from some prior location
which I think will be problematic.

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Sat, Sep 10, 2022 at 11:45 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Sat, Sep 10, 2022 at 11:06 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > On Sat, Sep 10, 2022 at 3:19 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > One thing is not clear to me how the first time error: "could not find
> > record while sending logically-decoded data ..." can happen due to
> > this commit? Also, based on the origin even if the client sends a
> > prior location (0/0 in this case) but the server will still start from
> > the location where the client has confirmed the commit (aka
> > confirmed_flush location).
> >
>
> I missed the point that if the 'origin_lsn' is ahead of the
> 'confirmed_flush' location then it will start from some prior location
> which I think will be problematic.
>

I am able to reproduce the behavior as seen in BF failure with the
help of a debugger by introducing an artificial error in
libpqrcv_endstreaming and by ensuring that apply worker skips the
transaction that performs an operation on a table for which the sync
worker is copying the table. I have to also suppress keep_alive
messages from the publisher, otherwise, they move the confirm_flush
location ahead of origin_lsn. So, it is clear that this commit has
caused the BF failure even though the first error seen: "ERROR:  could
not find record while sending logically-decoded data: missing
contrecord at 0/1CCF9F0" was not due to this commit.

I don't have any better ideas to solve this at this stage than what
Hou-San has mentioned in his email [1]. What do you think?

[1] -
https://www.postgresql.org/message-id/OS0PR01MB5716E128E78C6CECD15C718394429%40OS0PR01MB5716.jpnprd01.prod.outlook.com

-- 
With Regards,
Amit Kapila.



RE: Excessive number of replication slots for 12->14 logical replication

От
"houzj.fnst@fujitsu.com"
Дата:
On Saturday, September 10, 2022 11:41 AM houzj.fnst@fujitsu.com wrote:
> 
> On Saturday, September 10, 2022 5:49 AM Masahiko Sawada
> <sawada.mshk@gmail.com> wrote:
> >
> > On Tue, Aug 30, 2022 at 3:44 PM Amit Kapila <amit.kapila16@gmail.com>
> wrote:
> > >
> > > On Fri, Aug 26, 2022 at 7:04 AM Amit Kapila
> > > <amit.kapila16@gmail.com>
> > wrote:
> > > >
> > > > Thanks for the testing. I'll push this sometime early next week
> > > > (by
> > > > Tuesday) unless Sawada-San or someone else has any comments on it.
> > > >
> > >
> > > Pushed.
> >
> > Tom reported buildfarm failures[1] and I've investigated the cause and
> > concluded this commit is relevant.
> >
> > In process_syncing_tables_for_sync(), we have the following code:
> >
> >         UpdateSubscriptionRelState(MyLogicalRepWorker->subid,
> >                                    MyLogicalRepWorker->relid,
> >                                    MyLogicalRepWorker->relstate,
> >                                    MyLogicalRepWorker->relstate_lsn);
> >
> >         ReplicationOriginNameForTablesync(MyLogicalRepWorker->subid,
> >                                           MyLogicalRepWorker->relid,
> >                                           originname,
> >                                           sizeof(originname));
> >         replorigin_session_reset();
> >         replorigin_session_origin = InvalidRepOriginId;
> >         replorigin_session_origin_lsn = InvalidXLogRecPtr;
> >         replorigin_session_origin_timestamp = 0;
> >
> >         /*
> >          * We expect that origin must be present. The concurrent operations
> >          * that remove origin like a refresh for the subscription take an
> >          * access exclusive lock on pg_subscription which prevent the previou
> >          * operation to update the rel state to SUBREL_STATE_SYNCDONE to
> >          * succeed.
> >          */
> >         replorigin_drop_by_name(originname, false, false);
> >
> >         /*
> >          * End streaming so that LogRepWorkerWalRcvConn can be used to
> > drop
> >          * the slot.
> >          */
> >         walrcv_endstreaming(LogRepWorkerWalRcvConn, &tli);
> >
> >         /*
> >          * Cleanup the tablesync slot.
> >          *
> >          * This has to be done after the data changes because otherwise if
> >          * there is an error while doing the database operations we won't be
> >          * able to rollback dropped slot.
> >          */
> >         ReplicationSlotNameForTablesync(MyLogicalRepWorker->subid,
> >                                         MyLogicalRepWorker->relid,
> >                                         syncslotname,
> >                                         sizeof(syncslotname));
> >
> > If the table sync worker errored at walrcv_endstreaming(), we assumed
> > that both dropping the replication origin and updating relstate are
> > rolled back, which however was wrong. Indeed, the replication origin
> > is not dropped but the in-memory state is reset. Therefore, after the
> > tablesync worker restarts, it starts logical replication with starting
> > point 0/0. Consequently, it  ends up applying the transaction that has already
> been applied.
> 
> Thanks for the analysis !
> 
> I think you are right. The replorigin_drop_by_name() will clear the
> remote_lsn/local_lsn in shared memory which won't be rollback if we fail to drop
> the origin.
> 
> Per off-list discussion with Amit. To fix this problem, I think we need to drop the
> origin in table sync worker after committing the transaction which set the
> relstate to SYNCDONE. Because it can make sure that the worker won’t be
> restarted even if we fail to drop the origin. Besides, we need to add the origin
> drop code back in apply worker in case the table sync worker failed to drop the
> origin before it exits(which seems a rare case). I will share the patch if we agree
> with the fix.

Here is the draft patch. Share it here so that others can take a look at the basic logic.
I will keep testing and improving it.

Best regards,
Hou zj




Вложения

RE: Excessive number of replication slots for 12->14 logical replication

От
"houzj.fnst@fujitsu.com"
Дата:
On Saturday, September 10, 2022 6:34 PM houzj.fnst@fujitsu.com wrote:
> 
> On Saturday, September 10, 2022 11:41 AM houzj.fnst@fujitsu.com wrote:
> >
> > On Saturday, September 10, 2022 5:49 AM Masahiko Sawada
> > <sawada.mshk@gmail.com> wrote:
> > >
> > > On Tue, Aug 30, 2022 at 3:44 PM Amit Kapila
> > > <amit.kapila16@gmail.com>
> > wrote:
> > > >
> > > > On Fri, Aug 26, 2022 at 7:04 AM Amit Kapila
> > > > <amit.kapila16@gmail.com>
> > > wrote:
> > > > >
> > > > > Thanks for the testing. I'll push this sometime early next week
> > > > > (by
> > > > > Tuesday) unless Sawada-San or someone else has any comments on it.
> > > > >
> > > >
> > > > Pushed.
> > >
> > > Tom reported buildfarm failures[1] and I've investigated the cause
> > > and concluded this commit is relevant.
> > >
> > >
> > > If the table sync worker errored at walrcv_endstreaming(), we
> > > assumed that both dropping the replication origin and updating
> > > relstate are rolled back, which however was wrong. Indeed, the
> > > replication origin is not dropped but the in-memory state is reset.
> > > Therefore, after the tablesync worker restarts, it starts logical
> > > replication with starting point 0/0. Consequently, it  ends up
> > > applying the transaction that has already
> > been applied.
> >
> > Thanks for the analysis !
> >
> > I think you are right. The replorigin_drop_by_name() will clear the
> > remote_lsn/local_lsn in shared memory which won't be rollback if we
> > fail to drop the origin.
> >
> > Per off-list discussion with Amit. To fix this problem, I think we
> > need to drop the origin in table sync worker after committing the
> > transaction which set the relstate to SYNCDONE. Because it can make
> > sure that the worker won’t be restarted even if we fail to drop the
> > origin. Besides, we need to add the origin drop code back in apply
> > worker in case the table sync worker failed to drop the origin before
> > it exits(which seems a rare case). I will share the patch if we agree with the fix.
> 
> Here is the draft patch. Share it here so that others can take a look at the basic
> logic. I will keep testing and improving it.

I tried to reproduce the reported problem by a) using gdb attach the table sync
worker and block it. b) then I start another session to begin a transaction to
write some data(INSERT 1111111) to the publisher table and commit it. c)
release the table sync worker and let it apply the changes d) Stop at the table
sync worker after dropping the origin and before dropping the slot, and jump
the code into an error path so that the table sync worker will error out and
restart. Then I see an error which shows that the same data is applied twice.

2022-09-10 19:27:51.205 CST [2830699] ERROR:  duplicate key value violates unique constraint "test_tab_pkey"
2022-09-10 19:27:51.205 CST [2830699] DETAIL:  Key (a)=(1111111) already exists.

And with the same steps it works fine after applying the patch.

Attach the patch again with some cosmetic changes.

Best regards,
Hou zj




Вложения

Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Sun, Sep 11, 2022 at 11:55 PM houzj.fnst@fujitsu.com
<houzj.fnst@fujitsu.com> wrote:
>
> On Saturday, September 10, 2022 6:34 PM houzj.fnst@fujitsu.com wrote:
> >
> > On Saturday, September 10, 2022 11:41 AM houzj.fnst@fujitsu.com wrote:
> > >
> > > On Saturday, September 10, 2022 5:49 AM Masahiko Sawada
> > > <sawada.mshk@gmail.com> wrote:
> > > >
> > > > On Tue, Aug 30, 2022 at 3:44 PM Amit Kapila
> > > > <amit.kapila16@gmail.com>
> > > wrote:
> > > > >
> > > > > On Fri, Aug 26, 2022 at 7:04 AM Amit Kapila
> > > > > <amit.kapila16@gmail.com>
> > > > wrote:
> > > > > >
> > > > > > Thanks for the testing. I'll push this sometime early next week
> > > > > > (by
> > > > > > Tuesday) unless Sawada-San or someone else has any comments on it.
> > > > > >
> > > > >
> > > > > Pushed.
> > > >
> > > > Tom reported buildfarm failures[1] and I've investigated the cause
> > > > and concluded this commit is relevant.
> > > >
> > > >
> > > > If the table sync worker errored at walrcv_endstreaming(), we
> > > > assumed that both dropping the replication origin and updating
> > > > relstate are rolled back, which however was wrong. Indeed, the
> > > > replication origin is not dropped but the in-memory state is reset.
> > > > Therefore, after the tablesync worker restarts, it starts logical
> > > > replication with starting point 0/0. Consequently, it  ends up
> > > > applying the transaction that has already
> > > been applied.
> > >
> > > Thanks for the analysis !
> > >
> > > I think you are right. The replorigin_drop_by_name() will clear the
> > > remote_lsn/local_lsn in shared memory which won't be rollback if we
> > > fail to drop the origin.
> > >
> > > Per off-list discussion with Amit. To fix this problem, I think we
> > > need to drop the origin in table sync worker after committing the
> > > transaction which set the relstate to SYNCDONE. Because it can make
> > > sure that the worker won’t be restarted even if we fail to drop the
> > > origin. Besides, we need to add the origin drop code back in apply
> > > worker in case the table sync worker failed to drop the origin before
> > > it exits(which seems a rare case). I will share the patch if we agree with the fix.
> >
> > Here is the draft patch. Share it here so that others can take a look at the basic
> > logic. I will keep testing and improving it.
>
> I tried to reproduce the reported problem by a) using gdb attach the table sync
> worker and block it. b) then I start another session to begin a transaction to
> write some data(INSERT 1111111) to the publisher table and commit it. c)
> release the table sync worker and let it apply the changes d) Stop at the table
> sync worker after dropping the origin and before dropping the slot, and jump
> the code into an error path so that the table sync worker will error out and
> restart. Then I see an error which shows that the same data is applied twice.
>
> 2022-09-10 19:27:51.205 CST [2830699] ERROR:  duplicate key value violates unique constraint "test_tab_pkey"
> 2022-09-10 19:27:51.205 CST [2830699] DETAIL:  Key (a)=(1111111) already exists.
>
> And with the same steps it works fine after applying the patch.
>
> Attach the patch again with some cosmetic changes.

Thank you for the patch!

I agree with the approach of the patch to fix this issue. And I've
confirmed the issue doesn't happen with this patch. Here are some
review comments:

                /*
                 * UpdateSubscriptionRelState must be called within a
transaction.
-                * That transaction will be ended within the
finish_sync_worker().
                 */

I think we can move the removed sentence to where we added
StartTransactionCommand(). For example,

* Start a new transaction to cleanup the tablesync origin tracking.
* That transaction will be ended within the finish_sync_worker().

---
        * This has to be done after the data changes because otherwise if

I think we can change this sentence back to the one we had before:

        * This has to be done after updating the state because otherwise if

---
+       CommitTransactionCommand();
+

We need to do pgstat_report_stat() since we performed DML.

---
+       /*
+        * Start a new transaction to cleanup the tablesync origin tracking.
+        *
+        * We need to do this after the table state is set to SYNCDONE,
+        * otherwise if an error occurs while performing the database
+        * operation, the worker will be restarted, but the in-memory
+        * replication progress(remote_lsn) has been cleaned and will not be
+        * rolledback, so the restarted worker will use invalid replication
+        * progress resulting in replay of transactions that have already been
+        * applied.
+        */

How about mentioning that even if the tablesync worker failed to drop
the replication origin, the tablesync worker won't restart but the
apply worker will do that?

Regards,

--
Masahiko Sawada



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Mon, Sep 12, 2022 at 10:22 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
>
> Thank you for the patch!
>
> I agree with the approach of the patch to fix this issue. And I've
> confirmed the issue doesn't happen with this patch. Here are some
> review comments:
>
>                 /*
>                  * UpdateSubscriptionRelState must be called within a
> transaction.
> -                * That transaction will be ended within the
> finish_sync_worker().
>                  */
>
> I think we can move the removed sentence to where we added
> StartTransactionCommand(). For example,
>
> * Start a new transaction to cleanup the tablesync origin tracking.
> * That transaction will be ended within the finish_sync_worker().
>
> ---
>         * This has to be done after the data changes because otherwise if
>
> I think we can change this sentence back to the one we had before:
>
>         * This has to be done after updating the state because otherwise if
>

Changed as per suggestions.

> ---
> +       CommitTransactionCommand();
> +
>
> We need to do pgstat_report_stat() since we performed DML.
>

Right, so called pgstat_report_stat() with 'force' as false because we
will anyway do that later in finish_sync_worker().

> ---
> +       /*
> +        * Start a new transaction to cleanup the tablesync origin tracking.
> +        *
> +        * We need to do this after the table state is set to SYNCDONE,
> +        * otherwise if an error occurs while performing the database
> +        * operation, the worker will be restarted, but the in-memory
> +        * replication progress(remote_lsn) has been cleaned and will not be
> +        * rolledback, so the restarted worker will use invalid replication
> +        * progress resulting in replay of transactions that have already been
> +        * applied.
> +        */
>
> How about mentioning that even if the tablesync worker failed to drop
> the replication origin, the tablesync worker won't restart but the
> apply worker will do that?
>

Changed this and a few other comments in the patch. Kindly let me know
what you think of the attached.

-- 
With Regards,
Amit Kapila.

Вложения

RE: Excessive number of replication slots for 12->14 logical replication

От
"houzj.fnst@fujitsu.com"
Дата:
On Monday, September 12, 2022 2:15 PM Amit Kapila <amit.kapila16@gmail.com>
> 
> On Mon, Sep 12, 2022 at 10:22 AM Masahiko Sawada
> <sawada.mshk@gmail.com> wrote:
> >
> >
> > Thank you for the patch!
> >
> > I agree with the approach of the patch to fix this issue. And I've
> > confirmed the issue doesn't happen with this patch. Here are some
> > review comments:
> >
> >                 /*
> >                  * UpdateSubscriptionRelState must be called within a
> > transaction.
> > -                * That transaction will be ended within the
> > finish_sync_worker().
> >                  */
> >
> > I think we can move the removed sentence to where we added
> > StartTransactionCommand(). For example,
> >
> > * Start a new transaction to cleanup the tablesync origin tracking.
> > * That transaction will be ended within the finish_sync_worker().
> >
> > ---
> >         * This has to be done after the data changes because otherwise
> > if
> >
> > I think we can change this sentence back to the one we had before:
> >
> >         * This has to be done after updating the state because
> > otherwise if
> >
> 
> Changed as per suggestions.
> 
> > ---
> > +       CommitTransactionCommand();
> > +
> >
> > We need to do pgstat_report_stat() since we performed DML.
> >
> 
> Right, so called pgstat_report_stat() with 'force' as false because we will anyway
> do that later in finish_sync_worker().
> 
> > ---
> > +       /*
> > +        * Start a new transaction to cleanup the tablesync origin tracking.
> > +        *
> > +        * We need to do this after the table state is set to SYNCDONE,
> > +        * otherwise if an error occurs while performing the database
> > +        * operation, the worker will be restarted, but the in-memory
> > +        * replication progress(remote_lsn) has been cleaned and will not be
> > +        * rolledback, so the restarted worker will use invalid replication
> > +        * progress resulting in replay of transactions that have already been
> > +        * applied.
> > +        */
> >
> > How about mentioning that even if the tablesync worker failed to drop
> > the replication origin, the tablesync worker won't restart but the
> > apply worker will do that?
> >
> 
> Changed this and a few other comments in the patch. Kindly let me know what
> you think of the attached.

Thanks! The comments and changes look good to me.

Best regards,
Hou zj

Re: Excessive number of replication slots for 12->14 logical replication

От
Masahiko Sawada
Дата:
On Mon, Sep 12, 2022 at 3:15 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Mon, Sep 12, 2022 at 10:22 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> >
> > Thank you for the patch!
> >
> > I agree with the approach of the patch to fix this issue. And I've
> > confirmed the issue doesn't happen with this patch. Here are some
> > review comments:
> >
> >                 /*
> >                  * UpdateSubscriptionRelState must be called within a
> > transaction.
> > -                * That transaction will be ended within the
> > finish_sync_worker().
> >                  */
> >
> > I think we can move the removed sentence to where we added
> > StartTransactionCommand(). For example,
> >
> > * Start a new transaction to cleanup the tablesync origin tracking.
> > * That transaction will be ended within the finish_sync_worker().
> >
> > ---
> >         * This has to be done after the data changes because otherwise if
> >
> > I think we can change this sentence back to the one we had before:
> >
> >         * This has to be done after updating the state because otherwise if
> >
>
> Changed as per suggestions.
>
> > ---
> > +       CommitTransactionCommand();
> > +
> >
> > We need to do pgstat_report_stat() since we performed DML.
> >
>
> Right, so called pgstat_report_stat() with 'force' as false because we
> will anyway do that later in finish_sync_worker().
>
> > ---
> > +       /*
> > +        * Start a new transaction to cleanup the tablesync origin tracking.
> > +        *
> > +        * We need to do this after the table state is set to SYNCDONE,
> > +        * otherwise if an error occurs while performing the database
> > +        * operation, the worker will be restarted, but the in-memory
> > +        * replication progress(remote_lsn) has been cleaned and will not be
> > +        * rolledback, so the restarted worker will use invalid replication
> > +        * progress resulting in replay of transactions that have already been
> > +        * applied.
> > +        */
> >
> > How about mentioning that even if the tablesync worker failed to drop
> > the replication origin, the tablesync worker won't restart but the
> > apply worker will do that?
> >
>
> Changed this and a few other comments in the patch. Kindly let me know
> what you think of the attached.

Thank you for updating the patch. It looks good to me.

Regards,

-- 
Masahiko Sawada



Re: Excessive number of replication slots for 12->14 logical replication

От
Amit Kapila
Дата:
On Mon, Sep 12, 2022 at 12:25 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Mon, Sep 12, 2022 at 3:15 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > Changed this and a few other comments in the patch. Kindly let me know
> > what you think of the attached.
>
> Thank you for updating the patch. It looks good to me.
>

Thanks for the verification. Pushed!

-- 
With Regards,
Amit Kapila.



Re: Excessive number of replication slots for 12->14 logical replication

От
Bowen Shi
Дата:
Dears,

I encountered a similar problem when I used logical replication to replicate databases from pg 16 to pg 16.  

I started 3 subscription in parallel, and  subscriber's postgresql.conf is following:
max_replication_slots = 10
max_sync_workers_per_subscription = 2

However, after 3 minutes, I found three COPY errors in subscriber:
"error while shutting down streaming COPY: ERROR:  could not find record while sending logically-decoded data: missing contrecord at xxxx/xxxxxxxxx""
Then,  the subscriber began to print a large number of errors: "could not find free replication state slot for replication origin with ID 11, Increase max_replication_slots and try again."
 
And the publisher was full of pg_xxx_sync_xxxxxxx slots, printing lots of "all replication slots are in use, Free one or increase max_replication_slots."

This question is very similar to https://www.postgresql.org/message-id/flat/20220714115155.GA5439%40depesz.com . When the table sync worker encounters an error and exits while copying a table, the replication origin will not be deleted. And new table sync workers would create sync slot in the publisher and then exit without dropping them.

Bowen Shi

Amit Kapila <amit.kapila16@gmail.com> 于2024年1月18日周四 15:02写道:
On Mon, Sep 12, 2022 at 12:25 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Mon, Sep 12, 2022 at 3:15 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > Changed this and a few other comments in the patch. Kindly let me know
> > what you think of the attached.
>
> Thank you for updating the patch. It looks good to me.
>

Thanks for the verification. Pushed!

--
With Regards,
Amit Kapila.




Re: Excessive number of replication slots for 12->14 logical replication

От
vignesh C
Дата:
On Thu, 18 Jan 2024 at 13:00, Bowen Shi <zxwsbg12138@gmail.com> wrote:
>
> Dears,
>
> I encountered a similar problem when I used logical replication to replicate databases from pg 16 to pg 16.
>
> I started 3 subscription in parallel, and  subscriber's postgresql.conf is following:
> max_replication_slots = 10
> max_sync_workers_per_subscription = 2
>
> However, after 3 minutes, I found three COPY errors in subscriber:
> "error while shutting down streaming COPY: ERROR:  could not find record while sending logically-decoded data:
missingcontrecord at xxxx/xxxxxxxxx"" 
> Then,  the subscriber began to print a large number of errors: "could not find free replication state slot for
replicationorigin with ID 11, Increase max_replication_slots and try again." 
>
> And the publisher was full of pg_xxx_sync_xxxxxxx slots, printing lots of "all replication slots are in use, Free one
orincrease max_replication_slots." 
>
> This question is very similar to https://www.postgresql.org/message-id/flat/20220714115155.GA5439%40depesz.com . When
thetable sync worker encounters an error and exits while copying a table, the replication origin will not be deleted.
Andnew table sync workers would create sync slot in the publisher and then exit without dropping them. 

I had tried various tests with the suggested configuration, but I did
not hit this scenario. I was able to simulate this problem with a
lesser number of max_replication_slots, but the behavior is as
expected in this case.
If you have a test case or logs for this, can you share it please. It
will be easier to generate the sequence of things that is happening
and to project a clear picture of what is happening.

Regards,
Vignesh



RE: Excessive number of replication slots for 12->14 logical replication

От
"Zhijie Hou (Fujitsu)"
Дата:
On Saturday, January 20, 2024 12:40 AM vignesh C <vignesh21@gmail.com> wrote:

Hi,

> 
> On Thu, 18 Jan 2024 at 13:00, Bowen Shi <zxwsbg12138@gmail.com> wrote:
> >
> > Dears,
> >
> > I encountered a similar problem when I used logical replication to replicate
> databases from pg 16 to pg 16.
> >
> > I started 3 subscription in parallel, and  subscriber's postgresql.conf is
> following:
> > max_replication_slots = 10
> > max_sync_workers_per_subscription = 2
> >
> > However, after 3 minutes, I found three COPY errors in subscriber:
> > "error while shutting down streaming COPY: ERROR:  could not find record
> while sending logically-decoded data: missing contrecord at xxxx/xxxxxxxxx""
> > Then,  the subscriber began to print a large number of errors: "could not find
> free replication state slot for replication origin with ID 11, Increase
> max_replication_slots and try again."
> >
> > And the publisher was full of pg_xxx_sync_xxxxxxx slots, printing lots of "all
> replication slots are in use, Free one or increase max_replication_slots."
> >
> > This question is very similar to
> https://www.postgresql.org/message-id/flat/20220714115155.GA5439%40depe
> sz.com . When the table sync worker encounters an error and exits while copying
> a table, the replication origin will not be deleted. And new table sync workers
> would create sync slot in the publisher and then exit without dropping them.
> 
> I had tried various tests with the suggested configuration, but I did not hit this
> scenario. I was able to simulate this problem with a lesser number of
> max_replication_slots, but the behavior is as expected in this case.
> If you have a test case or logs for this, can you share it please. It will be easier to
> generate the sequence of things that is happening and to project a clear picture
> of what is happening.

I think the reason for these origin/slots ERRORs could be that the table sync worker
don't drop the origin and slot on ERROR (The table sync worker only drop these
after finishing the sync in process_syncing_tables_for_sync).

So, if one table sync worker exited due to ERROR, and the apply worker may be trying
to start more workers but the origin number of previous errored table sync
worker has not been dropped, causing a bunch of origin/slots ERRORs.

If the above reason is correct, maybe we could somehow drop the origin and
slots on ERROR exit as well, although it needs some analysis.

BTW, for the first root ERROR("COPY: ERROR:  could not find record while
sending logically-decoded data: missing contrecord at xxxx/xxxxxxxxx") which
causes the following slot/origin, I am not sure what would cause this.

As Vignesh mentioned, it would be better to provide log file in both publisher and
subscriber to do further analysis.

Best Regards,
Hou zj

Re: Excessive number of replication slots for 12->14 logical replication

От
Bowen Shi
Дата:
> I think the reason for these origin/slots ERRORs could be that the table sync worker
> don't drop the origin and slot on ERROR (The table sync worker only drop these
> after finishing the sync in process_syncing_tables_for_sync).

> So, if one table sync worker exited due to ERROR, and the apply worker may be trying
> to start more workers but the origin number of previous errored table sync
> worker has not been dropped, causing a bunch of origin/slots ERRORs.

Right, that's the problem.

> BTW, for the first root ERROR("COPY: ERROR:  could not find record while
> sending logically-decoded data: missing contrecord at xxxx/xxxxxxxxx") which
> causes the following slot/origin, I am not sure what would cause this.

This is not important, it is just a statement of the problem that occurred at that time. Other errors could also lead to the same results mentioned above.

Bowen Shi

Zhijie Hou (Fujitsu) <houzj.fnst@fujitsu.com> 于2024年1月21日周日 21:32写道:
On Saturday, January 20, 2024 12:40 AM vignesh C <vignesh21@gmail.com> wrote:

Hi,

>
> On Thu, 18 Jan 2024 at 13:00, Bowen Shi <zxwsbg12138@gmail.com> wrote:
> >
> > Dears,
> >
> > I encountered a similar problem when I used logical replication to replicate
> databases from pg 16 to pg 16.
> >
> > I started 3 subscription in parallel, and  subscriber's postgresql.conf is
> following:
> > max_replication_slots = 10
> > max_sync_workers_per_subscription = 2
> >
> > However, after 3 minutes, I found three COPY errors in subscriber:
> > "error while shutting down streaming COPY: ERROR:  could not find record
> while sending logically-decoded data: missing contrecord at xxxx/xxxxxxxxx""
> > Then,  the subscriber began to print a large number of errors: "could not find
> free replication state slot for replication origin with ID 11, Increase
> max_replication_slots and try again."
> >
> > And the publisher was full of pg_xxx_sync_xxxxxxx slots, printing lots of "all
> replication slots are in use, Free one or increase max_replication_slots."
> >
> > This question is very similar to
> https://www.postgresql.org/message-id/flat/20220714115155.GA5439%40depe
> sz.com . When the table sync worker encounters an error and exits while copying
> a table, the replication origin will not be deleted. And new table sync workers
> would create sync slot in the publisher and then exit without dropping them.
>
> I had tried various tests with the suggested configuration, but I did not hit this
> scenario. I was able to simulate this problem with a lesser number of
> max_replication_slots, but the behavior is as expected in this case.
> If you have a test case or logs for this, can you share it please. It will be easier to
> generate the sequence of things that is happening and to project a clear picture
> of what is happening.

I think the reason for these origin/slots ERRORs could be that the table sync worker
don't drop the origin and slot on ERROR (The table sync worker only drop these
after finishing the sync in process_syncing_tables_for_sync).

So, if one table sync worker exited due to ERROR, and the apply worker may be trying
to start more workers but the origin number of previous errored table sync
worker has not been dropped, causing a bunch of origin/slots ERRORs.

If the above reason is correct, maybe we could somehow drop the origin and
slots on ERROR exit as well, although it needs some analysis.

BTW, for the first root ERROR("COPY: ERROR:  could not find record while
sending logically-decoded data: missing contrecord at xxxx/xxxxxxxxx") which
causes the following slot/origin, I am not sure what would cause this.

As Vignesh mentioned, it would be better to provide log file in both publisher and
subscriber to do further analysis.

Best Regards,
Hou zj