Обсуждение: Subscription statistics are not dropped at DROP SUBSCRIPTION in some cases

Hi,

We call pgstat_drop_subscription() at the end of DropSubscription()
but we could leave from this function earlier e.g. when no slot is
associated with the subscription. In this case, the statistics entry
for the subscription remains. To fix it, I think we need to call it
earlier, just after removing the catalog tuple. There is a chance the
transaction dropping the subscription fails due to network error etc
but we don't need to worry about it as reporting the subscription drop
is transactional.

I've attached the patch. Feedback is very welcome.

Regards,

-- 
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Mon, May 08, 2023 at 04:23:15PM +0900, Masahiko Sawada wrote:
> We call pgstat_drop_subscription() at the end of DropSubscription()
> but we could leave from this function earlier e.g. when no slot is
> associated with the subscription. In this case, the statistics entry
> for the subscription remains. To fix it, I think we need to call it
> earlier, just after removing the catalog tuple. There is a chance the
> transaction dropping the subscription fails due to network error etc
> but we don't need to worry about it as reporting the subscription drop
> is transactional.

Looks reasonable to me.  IIUC calling pgstat_drop_subscription() earlier
makes no real difference (besides avoiding this bug) because it is uѕing
pgstat_drop_transactional() behind the scenes.

-- 
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

Dear Sawada-san,

Thank you for giving the patch! I confirmed that the problem you raised could be
occurred on the HEAD, and the test you added could reproduce that. When the stats
entry has been removed but pg_stat_get_subscription_stats() is called, the returned
values are set as 0x0.
Additionally, I have checked other pgstat_drop_* functions, and I could not find
any similar problems.

A comment:

```
+       /*
+        * Tell the cumulative stats system that the subscription is getting
+        * dropped.
+        */
+       pgstat_drop_subscription(subid);
```

Isn't it better to write down something you said as comment? Or is it quite trivial?

> There is a chance the
> transaction dropping the subscription fails due to network error etc
> but we don't need to worry about it as reporting the subscription drop
> is transactional.

Best Regards,
Hayato Kuroda
FUJITSU LIMITED

On Wed, May 10, 2023 at 8:58 PM Melih Mutlu <m.melihmutlu@gmail.com> wrote:
>
> Hi,
>
> Masahiko Sawada <sawada.mshk@gmail.com>, 8 May 2023 Pzt, 10:24 tarihinde şunu yazdı:
>>
>> I've attached the patch. Feedback is very welcome.
>
>
> Thanks for the patch, nice catch.
> I can confirm that the issue exists on HEAD and gets resolved by this patch. Also it looks like stats are really not
affectedif transaction fails for some reason, as you explained. 
> IMO, the patch will be OK after commit message is added.

Thank you for reviewing the patch. I'll push the patch early next
week, barring any objections.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Thu, May 11, 2023 at 5:12 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Wed, May 10, 2023 at 8:58 PM Melih Mutlu <m.melihmutlu@gmail.com> wrote:
> >
> > Hi,
> >
> > Masahiko Sawada <sawada.mshk@gmail.com>, 8 May 2023 Pzt, 10:24 tarihinde şunu yazdı:
> >>
> >> I've attached the patch. Feedback is very welcome.
> >
> >
> > Thanks for the patch, nice catch.
> > I can confirm that the issue exists on HEAD and gets resolved by this patch. Also it looks like stats are really
notaffected if transaction fails for some reason, as you explained. 
> > IMO, the patch will be OK after commit message is added.
>
> Thank you for reviewing the patch. I'll push the patch early next
> week, barring any objections.

After thinking more about it, I realized that this is not a problem
specific to HEAD. ISTM the problem is that by commit 7b64e4b3, we drop
the stats entry of subscription that is not associated with a
replication slot for apply worker, but we missed the case where the
subscription is not associated with both replication slots for apply
and tablesync. So IIUC we should backpatch it down to 15.

Since in pg15, since we don't create the subscription stats at CREATE
SUBSCRIPTION time but do when the first error is reported, we cannot
rely on the regression test suite. Also, to check if the subscription
stats is surely removed, using pg_stat_have_stats() is clearer. So I
added a test case to TAP tests (026_stats.pl).

On Tue, May 9, 2023 at 1:51 PM Hayato Kuroda (Fujitsu)
<kuroda.hayato@fujitsu.com> wrote:
>
> A comment:
>
> ```
> +       /*
> +        * Tell the cumulative stats system that the subscription is getting
> +        * dropped.
> +        */
> +       pgstat_drop_subscription(subid);
> ```
>
> Isn't it better to write down something you said as comment? Or is it quite trivial?
>
> > There is a chance the
> > transaction dropping the subscription fails due to network error etc
> > but we don't need to worry about it as reporting the subscription drop
> > is transactional.

I'm not sure it's worth mentioning as we don't have such a comment
around other pgstat_drop_XXX functions.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Tue, May 16, 2023 at 8:00 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Thu, May 11, 2023 at 5:12 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
>
> After thinking more about it, I realized that this is not a problem
> specific to HEAD. ISTM the problem is that by commit 7b64e4b3, we drop
> the stats entry of subscription that is not associated with a
> replication slot for apply worker, but we missed the case where the
> subscription is not associated with both replication slots for apply
> and tablesync. So IIUC we should backpatch it down to 15.
>

I agree that it should be backpatched to 15.

> Since in pg15, since we don't create the subscription stats at CREATE
> SUBSCRIPTION time but do when the first error is reported,
>

AFAICS, the call to pgstat_create_subscription() is present in
CreateSubscription() in 15 as well, so, I don't get your point.

--
With Regards,
Amit Kapila.

On Sat, Jun 17, 2023 at 6:45 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Tue, May 16, 2023 at 8:00 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > On Thu, May 11, 2023 at 5:12 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > >
> >
> > After thinking more about it, I realized that this is not a problem
> > specific to HEAD. ISTM the problem is that by commit 7b64e4b3, we drop
> > the stats entry of subscription that is not associated with a
> > replication slot for apply worker, but we missed the case where the
> > subscription is not associated with both replication slots for apply
> > and tablesync. So IIUC we should backpatch it down to 15.
> >
>
> I agree that it should be backpatched to 15.
>
> > Since in pg15, since we don't create the subscription stats at CREATE
> > SUBSCRIPTION time but do when the first error is reported,
> >
>
> AFAICS, the call to pgstat_create_subscription() is present in
> CreateSubscription() in 15 as well, so, I don't get your point.

IIUC in 15, pgstat_create_subscription() doesn't create the stats
entry. See commit e0b01429590.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Mon, Jun 19, 2023 at 6:50 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Sat, Jun 17, 2023 at 6:45 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> >
> > On Tue, May 16, 2023 at 8:00 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > >
> > > On Thu, May 11, 2023 at 5:12 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > >
> > >
> > > After thinking more about it, I realized that this is not a problem
> > > specific to HEAD. ISTM the problem is that by commit 7b64e4b3, we drop
> > > the stats entry of subscription that is not associated with a
> > > replication slot for apply worker, but we missed the case where the
> > > subscription is not associated with both replication slots for apply
> > > and tablesync. So IIUC we should backpatch it down to 15.
> > >
> >
> > I agree that it should be backpatched to 15.
> >
> > > Since in pg15, since we don't create the subscription stats at CREATE
> > > SUBSCRIPTION time but do when the first error is reported,
> > >
> >
> > AFAICS, the call to pgstat_create_subscription() is present in
> > CreateSubscription() in 15 as well, so, I don't get your point.
>
> IIUC in 15, pgstat_create_subscription() doesn't create the stats
> entry. See commit e0b01429590.
>

Thanks for the clarification. Your changes looks good to me though I
haven't tested it.

--
With Regards,
Amit Kapila.

On Mon, Jun 19, 2023 at 12:37 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> On Mon, Jun 19, 2023 at 6:50 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > On Sat, Jun 17, 2023 at 6:45 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
> > >
> > > On Tue, May 16, 2023 at 8:00 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > >
> > > > On Thu, May 11, 2023 at 5:12 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> > > > >
> > > >
> > > > After thinking more about it, I realized that this is not a problem
> > > > specific to HEAD. ISTM the problem is that by commit 7b64e4b3, we drop
> > > > the stats entry of subscription that is not associated with a
> > > > replication slot for apply worker, but we missed the case where the
> > > > subscription is not associated with both replication slots for apply
> > > > and tablesync. So IIUC we should backpatch it down to 15.
> > > >
> > >
> > > I agree that it should be backpatched to 15.
> > >
> > > > Since in pg15, since we don't create the subscription stats at CREATE
> > > > SUBSCRIPTION time but do when the first error is reported,
> > > >
> > >
> > > AFAICS, the call to pgstat_create_subscription() is present in
> > > CreateSubscription() in 15 as well, so, I don't get your point.
> >
> > IIUC in 15, pgstat_create_subscription() doesn't create the stats
> > entry. See commit e0b01429590.
> >
>
> Thanks for the clarification. Your changes looks good to me though I
> haven't tested it.

Thanks for reviewing the patch. Pushed.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Wednesday, July 5, 2023 2:53 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:

Hi,

> Thanks for reviewing the patch. Pushed.

My colleague Vignesh noticed that the newly added test cases were failing in BF animal sungazer[1].

The test failed to drop the slot which is active on publisher.

--error-log--
This failure is because pg_drop_replication_slot fails with "replication slot "test_tab2_sub" is active for PID
55771638":
2023-09-02 09:00:04.806 UTC [12910732:4] 026_stats.pl LOG:  statement: SELECT
pg_drop_replication_slot('test_tab2_sub')
2023-09-02 09:00:04.807 UTC [12910732:5] 026_stats.pl ERROR:  replication slot "test_tab2_sub" is active for PID
55771638
2023-09-02 09:00:04.807 UTC [12910732:6] 026_stats.pl STATEMENT:  SELECT pg_drop_replication_slot('test_tab2_sub')
-------------

I the reason is that the test DISABLEd the subscription before dropping the
slot, while "ALTER SUBSCRIPTION DISABLE" doesn't wait for the walsender to
release the slot, so it's possible that the walsender is still alive when calling
pg_drop_replication_slot() to drop the slot on publisher(pg_drop_xxxslot() 
doesn't wait for slot to be released).

I think we can wait for the slot to become inactive before dropping like:
    $node_primary->poll_query_until('otherdb',
        "SELECT NOT EXISTS (SELECT 1 FROM pg_replication_slots WHERE active_pid IS NOT NULL)"
    )

Or we can just don't drop the slot as it’s the last testcase.

Another thing might be worth considering is we can add one parameter in
pg_drop_replication_slot() to let user control whether to wait or not, and the
test can be fixed as well by passing nowait=false to the func.

[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=sungazer&dt=2023-09-02%2002%3A17%3A01

Best Regards,
Hou zj

Hi,

On Mon, Sep 4, 2023 at 9:38 PM Zhijie Hou (Fujitsu)
<houzj.fnst@fujitsu.com> wrote:
>
> On Wednesday, July 5, 2023 2:53 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> Hi,
>
> > Thanks for reviewing the patch. Pushed.
>
> My colleague Vignesh noticed that the newly added test cases were failing in BF animal sungazer[1].

Thank you for reporting!

>
> The test failed to drop the slot which is active on publisher.
>
> --error-log--
> This failure is because pg_drop_replication_slot fails with "replication slot "test_tab2_sub" is active for PID
55771638":
> 2023-09-02 09:00:04.806 UTC [12910732:4] 026_stats.pl LOG:  statement: SELECT
pg_drop_replication_slot('test_tab2_sub')
> 2023-09-02 09:00:04.807 UTC [12910732:5] 026_stats.pl ERROR:  replication slot "test_tab2_sub" is active for PID
55771638
> 2023-09-02 09:00:04.807 UTC [12910732:6] 026_stats.pl STATEMENT:  SELECT pg_drop_replication_slot('test_tab2_sub')
> -------------
>
> I the reason is that the test DISABLEd the subscription before dropping the
> slot, while "ALTER SUBSCRIPTION DISABLE" doesn't wait for the walsender to
> release the slot, so it's possible that the walsender is still alive when calling
> pg_drop_replication_slot() to drop the slot on publisher(pg_drop_xxxslot()
> doesn't wait for slot to be released).

I agree with your analysis.

>
> I think we can wait for the slot to become inactive before dropping like:
>         $node_primary->poll_query_until('otherdb',
>                 "SELECT NOT EXISTS (SELECT 1 FROM pg_replication_slots WHERE active_pid IS NOT NULL)"
>         )
>

I prefer this approach but it would be better to specify the slot name
in the query.

> Or we can just don't drop the slot as it’s the last testcase.

Since we might add other tests after that in the future, I think it's
better to drop the replication slot (and subscription).

>
> Another thing might be worth considering is we can add one parameter in
> pg_drop_replication_slot() to let user control whether to wait or not, and the
> test can be fixed as well by passing nowait=false to the func.

While it could be useful in general we cannot use this approach for
this issue since it cannot be backpatched to older branches. We might
want to discuss it on a new thread.

I've attached a draft patch to fix this issue. Feedback is very welcome.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Monday, September 4, 2023 10:42 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:

Hi,

> On Mon, Sep 4, 2023 at 9:38 PM Zhijie Hou (Fujitsu) <houzj.fnst@fujitsu.com>
> wrote:
> >
> > On Wednesday, July 5, 2023 2:53 PM Masahiko Sawada
> <sawada.mshk@gmail.com> wrote:
> >
> > > Thanks for reviewing the patch. Pushed.
> >
> > My colleague Vignesh noticed that the newly added test cases were failing in
> BF animal sungazer[1].
> 
> Thank you for reporting!
> 
> >
> > The test failed to drop the slot which is active on publisher.
> >
> > --error-log--
> > This failure is because pg_drop_replication_slot fails with "replication slot
> "test_tab2_sub" is active for PID 55771638":
> > 2023-09-02 09:00:04.806 UTC [12910732:4] 026_stats.pl LOG:  statement:
> > SELECT pg_drop_replication_slot('test_tab2_sub')
> > 2023-09-02 09:00:04.807 UTC [12910732:5] 026_stats.pl ERROR:
> > replication slot "test_tab2_sub" is active for PID 55771638
> > 2023-09-02 09:00:04.807 UTC [12910732:6] 026_stats.pl STATEMENT:
> > SELECT pg_drop_replication_slot('test_tab2_sub')
> > -------------
> >
> > I the reason is that the test DISABLEd the subscription before
> > dropping the slot, while "ALTER SUBSCRIPTION DISABLE" doesn't wait for
> > the walsender to release the slot, so it's possible that the walsender
> > is still alive when calling
> > pg_drop_replication_slot() to drop the slot on
> > publisher(pg_drop_xxxslot() doesn't wait for slot to be released).
> 
> I agree with your analysis.
> 
> >
> > I think we can wait for the slot to become inactive before dropping like:
> >         $node_primary->poll_query_until('otherdb',
> >                 "SELECT NOT EXISTS (SELECT 1 FROM pg_replication_slots
> WHERE active_pid IS NOT NULL)"
> >         )
> >
> 
> I prefer this approach but it would be better to specify the slot name in the
> query.
> 
> > Or we can just don't drop the slot as it’s the last testcase.
> 
> Since we might add other tests after that in the future, I think it's better to drop
> the replication slot (and subscription).
> 
> >
> > Another thing might be worth considering is we can add one parameter
> > in
> > pg_drop_replication_slot() to let user control whether to wait or not,
> > and the test can be fixed as well by passing nowait=false to the func.
> 
> While it could be useful in general we cannot use this approach for this issue
> since it cannot be backpatched to older branches. We might want to discuss it
> on a new thread.
> 
> I've attached a draft patch to fix this issue. Feedback is very welcome.

Thanks, it looks good to me.

Best Regards,
Hou zj

On Tue, Sep 5, 2023 at 11:32 AM Zhijie Hou (Fujitsu)
<houzj.fnst@fujitsu.com> wrote:
>
> On Monday, September 4, 2023 10:42 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> Hi,
>
> > On Mon, Sep 4, 2023 at 9:38 PM Zhijie Hou (Fujitsu) <houzj.fnst@fujitsu.com>
> > wrote:
> > >
> > > On Wednesday, July 5, 2023 2:53 PM Masahiko Sawada
> > <sawada.mshk@gmail.com> wrote:
> > >
> > > > Thanks for reviewing the patch. Pushed.
> > >
> > > My colleague Vignesh noticed that the newly added test cases were failing in
> > BF animal sungazer[1].
> >
> > Thank you for reporting!
> >
> > >
> > > The test failed to drop the slot which is active on publisher.
> > >
> > > --error-log--
> > > This failure is because pg_drop_replication_slot fails with "replication slot
> > "test_tab2_sub" is active for PID 55771638":
> > > 2023-09-02 09:00:04.806 UTC [12910732:4] 026_stats.pl LOG:  statement:
> > > SELECT pg_drop_replication_slot('test_tab2_sub')
> > > 2023-09-02 09:00:04.807 UTC [12910732:5] 026_stats.pl ERROR:
> > > replication slot "test_tab2_sub" is active for PID 55771638
> > > 2023-09-02 09:00:04.807 UTC [12910732:6] 026_stats.pl STATEMENT:
> > > SELECT pg_drop_replication_slot('test_tab2_sub')
> > > -------------
> > >
> > > I the reason is that the test DISABLEd the subscription before
> > > dropping the slot, while "ALTER SUBSCRIPTION DISABLE" doesn't wait for
> > > the walsender to release the slot, so it's possible that the walsender
> > > is still alive when calling
> > > pg_drop_replication_slot() to drop the slot on
> > > publisher(pg_drop_xxxslot() doesn't wait for slot to be released).
> >
> > I agree with your analysis.
> >
> > >
> > > I think we can wait for the slot to become inactive before dropping like:
> > >         $node_primary->poll_query_until('otherdb',
> > >                 "SELECT NOT EXISTS (SELECT 1 FROM pg_replication_slots
> > WHERE active_pid IS NOT NULL)"
> > >         )
> > >
> >
> > I prefer this approach but it would be better to specify the slot name in the
> > query.
> >
> > > Or we can just don't drop the slot as it’s the last testcase.
> >
> > Since we might add other tests after that in the future, I think it's better to drop
> > the replication slot (and subscription).
> >
> > >
> > > Another thing might be worth considering is we can add one parameter
> > > in
> > > pg_drop_replication_slot() to let user control whether to wait or not,
> > > and the test can be fixed as well by passing nowait=false to the func.
> >
> > While it could be useful in general we cannot use this approach for this issue
> > since it cannot be backpatched to older branches. We might want to discuss it
> > on a new thread.
> >
> > I've attached a draft patch to fix this issue. Feedback is very welcome.
>
> Thanks, it looks good to me.

Thank you for reviewing the patch.

I'll push the attached patch to master, v16, and v15 tomorrow, barring
any objections.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Thu, Sep 7, 2023 at 10:22 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Tue, Sep 5, 2023 at 11:32 AM Zhijie Hou (Fujitsu)
> <houzj.fnst@fujitsu.com> wrote:
> >
> > On Monday, September 4, 2023 10:42 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
> >
> > Hi,
> >
> > > On Mon, Sep 4, 2023 at 9:38 PM Zhijie Hou (Fujitsu) <houzj.fnst@fujitsu.com>
> > > wrote:
> > > >
> > > > On Wednesday, July 5, 2023 2:53 PM Masahiko Sawada
> > > <sawada.mshk@gmail.com> wrote:
> > > >
> > > > > Thanks for reviewing the patch. Pushed.
> > > >
> > > > My colleague Vignesh noticed that the newly added test cases were failing in
> > > BF animal sungazer[1].
> > >
> > > Thank you for reporting!
> > >
> > > >
> > > > The test failed to drop the slot which is active on publisher.
> > > >
> > > > --error-log--
> > > > This failure is because pg_drop_replication_slot fails with "replication slot
> > > "test_tab2_sub" is active for PID 55771638":
> > > > 2023-09-02 09:00:04.806 UTC [12910732:4] 026_stats.pl LOG:  statement:
> > > > SELECT pg_drop_replication_slot('test_tab2_sub')
> > > > 2023-09-02 09:00:04.807 UTC [12910732:5] 026_stats.pl ERROR:
> > > > replication slot "test_tab2_sub" is active for PID 55771638
> > > > 2023-09-02 09:00:04.807 UTC [12910732:6] 026_stats.pl STATEMENT:
> > > > SELECT pg_drop_replication_slot('test_tab2_sub')
> > > > -------------
> > > >
> > > > I the reason is that the test DISABLEd the subscription before
> > > > dropping the slot, while "ALTER SUBSCRIPTION DISABLE" doesn't wait for
> > > > the walsender to release the slot, so it's possible that the walsender
> > > > is still alive when calling
> > > > pg_drop_replication_slot() to drop the slot on
> > > > publisher(pg_drop_xxxslot() doesn't wait for slot to be released).
> > >
> > > I agree with your analysis.
> > >
> > > >
> > > > I think we can wait for the slot to become inactive before dropping like:
> > > >         $node_primary->poll_query_until('otherdb',
> > > >                 "SELECT NOT EXISTS (SELECT 1 FROM pg_replication_slots
> > > WHERE active_pid IS NOT NULL)"
> > > >         )
> > > >
> > >
> > > I prefer this approach but it would be better to specify the slot name in the
> > > query.
> > >
> > > > Or we can just don't drop the slot as it’s the last testcase.
> > >
> > > Since we might add other tests after that in the future, I think it's better to drop
> > > the replication slot (and subscription).
> > >
> > > >
> > > > Another thing might be worth considering is we can add one parameter
> > > > in
> > > > pg_drop_replication_slot() to let user control whether to wait or not,
> > > > and the test can be fixed as well by passing nowait=false to the func.
> > >
> > > While it could be useful in general we cannot use this approach for this issue
> > > since it cannot be backpatched to older branches. We might want to discuss it
> > > on a new thread.
> > >
> > > I've attached a draft patch to fix this issue. Feedback is very welcome.
> >
> > Thanks, it looks good to me.
>
> Thank you for reviewing the patch.
>
> I'll push the attached patch to master, v16, and v15 tomorrow, barring
> any objections.

Pushed.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com