Thread: Diagnostic comment in LogicalIncreaseXminForSlot
Hi LogicalIncreaseRestartDecodingForSlot() has a debug log to report a new restart_lsn. But the corresponding function for catalog_xmin. Here's a patch to add the same. -- Best Wishes, Ashutosh Bapat
Attachment
On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat <ashutosh.bapat.oss@gmail.com> wrote: > > Hi > LogicalIncreaseRestartDecodingForSlot() has a debug log to report a > new restart_lsn. But the corresponding function for catalog_xmin. > Here's a patch to add the same. > I think this can be useful. One minor comment: + elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin, + (uint32) (current_lsn >> 32), (uint32) current_lsn); Isn't it better to use LSN_FORMAT_ARGS for current_lsn? Also, there doesn't seem to be any urgency for adding this, so you can register it for the next CF so that we can add this when the branch opens for PG-15. -- With Regards, Amit Kapila.
On Fri, May 21, 2021 at 11:26 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:
>
> Hi
> LogicalIncreaseRestartDecodingForSlot() has a debug log to report a
> new restart_lsn. But the corresponding function for catalog_xmin.
> Here's a patch to add the same.
>
I think this can be useful. One minor comment:
+ elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin,
+ (uint32) (current_lsn >> 32), (uint32) current_lsn);
Isn't it better to use LSN_FORMAT_ARGS for current_lsn?
Thanks for reminding me about that. :).
Attached revised patch.
Also, there
doesn't seem to be any urgency for adding this, so you can register it
for the next CF so that we can add this when the branch opens for
PG-15.
It's there in CF. I am fine with PG-15. It will be good to patch the back-branches to have this extra diagnostic information available.
--
Best Wishes,
Ashutosh
Attachment
On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote: > > > > On Fri, May 21, 2021 at 11:26 AM Amit Kapila <amit.kapila16@gmail.com> wrote: >> >> On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat >> <ashutosh.bapat.oss@gmail.com> wrote: >> > >> > Hi >> > LogicalIncreaseRestartDecodingForSlot() has a debug log to report a >> > new restart_lsn. But the corresponding function for catalog_xmin. >> > Here's a patch to add the same. >> > >> >> I think this can be useful. One minor comment: >> + elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin, >> + (uint32) (current_lsn >> 32), (uint32) current_lsn); >> >> Isn't it better to use LSN_FORMAT_ARGS for current_lsn? > > > Thanks for reminding me about that. :). > > Attached revised patch. > >> >> Also, there >> doesn't seem to be any urgency for adding this, so you can register it >> for the next CF so that we can add this when the branch opens for >> PG-15. > > > It's there in CF. I am fine with PG-15. It will be good to patch the back-branches to have this extra diagnostic informationavailable. The patch looks to me. Regards, -- Masahiko Sawada EDB: https://www.enterprisedb.com/
On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote: > > On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat > <ashutosh.bapat@enterprisedb.com> wrote: > > > > > > > > On Fri, May 21, 2021 at 11:26 AM Amit Kapila <amit.kapila16@gmail.com> wrote: > >> > >> On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat > >> <ashutosh.bapat.oss@gmail.com> wrote: > >> > > >> > Hi > >> > LogicalIncreaseRestartDecodingForSlot() has a debug log to report a > >> > new restart_lsn. But the corresponding function for catalog_xmin. > >> > Here's a patch to add the same. > >> > > >> > >> I think this can be useful. One minor comment: > >> + elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin, > >> + (uint32) (current_lsn >> 32), (uint32) current_lsn); > >> > >> Isn't it better to use LSN_FORMAT_ARGS for current_lsn? > > > > > > Thanks for reminding me about that. :). > > > > Attached revised patch. > > > >> > >> Also, there > >> doesn't seem to be any urgency for adding this, so you can register it > >> for the next CF so that we can add this when the branch opens for > >> PG-15. > > > > > > It's there in CF. I am fine with PG-15. It will be good to patch the back-branches to have this extra diagnostic informationavailable. > > The patch looks to me. > Do you or others have any opinion on whether this should be back-patched? I personally prefer it to be a HEAD-only patch. -- With Regards, Amit Kapila.
> On 8 Jul 2021, at 12:56, Amit Kapila <amit.kapila16@gmail.com> wrote: > Do you or others have any opinion on whether this should be > back-patched? I personally prefer it to be a HEAD-only patch. +1 for only applying this to HEAD. The restart_lsn debug elog has been there since 2014 so there doesn’t seem to be any immediate rush. -- Daniel Gustafsson https://vmware.com/
On Thu, Jul 8, 2021 at 8:14 PM Daniel Gustafsson <daniel@yesql.se> wrote: > > > On 8 Jul 2021, at 12:56, Amit Kapila <amit.kapila16@gmail.com> wrote: > > > Do you or others have any opinion on whether this should be > > back-patched? I personally prefer it to be a HEAD-only patch. > > +1 for only applying this to HEAD. The restart_lsn debug elog has been there > since 2014 so there doesn’t seem to be any immediate rush. +1 Regards, -- Masahiko Sawada EDB: https://www.enterprisedb.com/
On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat
> <ashutosh.bapat@enterprisedb.com> wrote:
> >
> > It's there in CF. I am fine with PG-15. It will be good to patch the back-branches to have this extra diagnostic
informationavailable.
>
> The patch looks to me.
>
{
slot->candidate_catalog_xmin = xmin;
slot->candidate_xmin_lsn = current_lsn;
+ elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin,
+ LSN_FORMAT_ARGS(current_lsn));
}
SpinLockRelease(&slot->mutex);
Today, again looking at this patch, I don't think doing elog inside
spinlock is a good idea. We can either release spinlock before it or
use some variable to remember that we need to write such an elog and
do it after releasing the lock. What do you think? I have noticed that
a nearby function LogicalIncreaseRestartDecodingForSlot() logs similar
information after releasing spinlock, so it is better to follow the
same here as well.
--
With Regards,
Amit Kapila.
On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>
> On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat
> <ashutosh.bapat@enterprisedb.com> wrote:
> >
> > It's there in CF. I am fine with PG-15. It will be good to patch the back-branches to have this extra diagnostic information available.
>
> The patch looks to me.
>
{
slot->candidate_catalog_xmin = xmin;
slot->candidate_xmin_lsn = current_lsn;
+ elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin,
+ LSN_FORMAT_ARGS(current_lsn));
}
SpinLockRelease(&slot->mutex);
Today, again looking at this patch, I don't think doing elog inside
spinlock is a good idea. We can either release spinlock before it or
use some variable to remember that we need to write such an elog and
do it after releasing the lock. What do you think?
The elog will be effective only under DEBUG1, otherwise it will be almost a NOOP. I am wondering whether it's worth adding a bool assignment and move the elog out only for DEBUG1. Anyway, will defer it to you.
I have noticed that
a nearby function LogicalIncreaseRestartDecodingForSlot() logs similar
information after releasing spinlock, so it is better to follow the
same here as well.
Now that you mention it, the code their looks rather suspicious :)
We acquire the spinlock at the beginning of the function but do not release it if (restart_lsn <= slot->data.restart_lsn) or if (current_lsn <= slot->data.confirmed_flush). I might be missing something there. But it looks unrelated.
--
Best Wishes,
Ashutosh
On Mon, Jul 12, 2021 at 5:28 PM Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote: > > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila <amit.kapila16@gmail.com> wrote: >> >> I have noticed that >> a nearby function LogicalIncreaseRestartDecodingForSlot() logs similar >> information after releasing spinlock, so it is better to follow the >> same here as well. > > > Now that you mention it, the code their looks rather suspicious :) > We acquire the spinlock at the beginning of the function but do not release it if (restart_lsn <= slot->data.restart_lsn)or if (current_lsn <= slot->data.confirmed_flush). > Note that we end else if with (current_lsn <= slot->data.confirmed_flush) and after that there is a new if. We release lock in both the if/else conditions, so the code is fine as it is. -- With Regards, Amit Kapila.
On Mon, Jul 12, 2021 at 6:23 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
On Mon, Jul 12, 2021 at 5:28 PM Ashutosh Bapat
<ashutosh.bapat@enterprisedb.com> wrote:
>
> On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>>
>> I have noticed that
>> a nearby function LogicalIncreaseRestartDecodingForSlot() logs similar
>> information after releasing spinlock, so it is better to follow the
>> same here as well.
>
>
> Now that you mention it, the code their looks rather suspicious :)
> We acquire the spinlock at the beginning of the function but do not release it if (restart_lsn <= slot->data.restart_lsn) or if (current_lsn <= slot->data.confirmed_flush).
>
Note that we end else if with (current_lsn <=
slot->data.confirmed_flush) and after that there is a new if. We
release lock in both the if/else conditions, so the code is fine as it
is.
Ah! I overlooked the closing else if (). Sorry for the noise.
--
Best Wishes,
Ashutosh
On Mon, Jul 12, 2021 at 5:28 PM Ashutosh Bapat
<ashutosh.bapat@enterprisedb.com> wrote:
>
> On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>>
>> On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:
>> >
>> > On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat
>> > <ashutosh.bapat@enterprisedb.com> wrote:
>> > >
>> > > It's there in CF. I am fine with PG-15. It will be good to patch the back-branches to have this extra diagnostic
informationavailable.
>> >
>> > The patch looks to me.
>> >
>>
>> {
>> slot->candidate_catalog_xmin = xmin;
>> slot->candidate_xmin_lsn = current_lsn;
>> + elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin,
>> + LSN_FORMAT_ARGS(current_lsn));
>> }
>> SpinLockRelease(&slot->mutex);
>>
>> Today, again looking at this patch, I don't think doing elog inside
>> spinlock is a good idea. We can either release spinlock before it or
>> use some variable to remember that we need to write such an elog and
>> do it after releasing the lock. What do you think?
>
>
> The elog will be effective only under DEBUG1, otherwise it will be almost a NOOP. I am wondering whether it's worth
addinga bool assignment and move the elog out only for DEBUG1.
>
If you don't like adding another variable then probably we can release
spinlock in each of if .. else loop. As mentioned previously, it
doesn't seem a good idea to use elog inside spinlock, so we either
need to find some way to avoid that or probably will drop this patch.
Do let me know what you or others prefer here?
--
With Regards,
Amit Kapila.
Hi, On 2021-07-12 17:28:15 +0530, Ashutosh Bapat wrote: > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila <amit.kapila16@gmail.com> wrote: > > > On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada <sawada.mshk@gmail.com> > > Today, again looking at this patch, I don't think doing elog inside > > spinlock is a good idea. We can either release spinlock before it or > > use some variable to remember that we need to write such an elog and > > do it after releasing the lock. What do you think? > > > The elog will be effective only under DEBUG1, otherwise it will be almost a > NOOP. I am wondering whether it's worth adding a bool assignment and move > the elog out only for DEBUG1. Anyway, will defer it to you. It's *definitely* not ok to do an elog() while holding a spinlock. Consider what happens if the elog tries to format the message and runs out of memory. Or if elog detects the stack depth is too deep. An ERROR would be thrown, and we'd loose track of the held spinlock. Greetings, Andres Freund
On Sat, Aug 7, 2021 at 11:40 AM Andres Freund <andres@anarazel.de> wrote:
Hi,
On 2021-07-12 17:28:15 +0530, Ashutosh Bapat wrote:
> On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> > On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada <sawada.mshk@gmail.com>
> > Today, again looking at this patch, I don't think doing elog inside
> > spinlock is a good idea. We can either release spinlock before it or
> > use some variable to remember that we need to write such an elog and
> > do it after releasing the lock. What do you think?
>
>
> The elog will be effective only under DEBUG1, otherwise it will be almost a
> NOOP. I am wondering whether it's worth adding a bool assignment and move
> the elog out only for DEBUG1. Anyway, will defer it to you.
It's *definitely* not ok to do an elog() while holding a spinlock. Consider
what happens if the elog tries to format the message and runs out of
memory. Or if elog detects the stack depth is too deep. An ERROR would be
thrown, and we'd loose track of the held spinlock.
Thanks for the clarification.
Amit,
I will provide the patch changed accordingly.
--
Best Wishes,
Ashutosh
Hi Amit and Andres,
Here's updated patch
On Mon, Aug 9, 2021 at 11:14 AM Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote:
On Sat, Aug 7, 2021 at 11:40 AM Andres Freund <andres@anarazel.de> wrote:Hi,
On 2021-07-12 17:28:15 +0530, Ashutosh Bapat wrote:
> On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> > On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada <sawada.mshk@gmail.com>
> > Today, again looking at this patch, I don't think doing elog inside
> > spinlock is a good idea. We can either release spinlock before it or
> > use some variable to remember that we need to write such an elog and
> > do it after releasing the lock. What do you think?
>
>
> The elog will be effective only under DEBUG1, otherwise it will be almost a
> NOOP. I am wondering whether it's worth adding a bool assignment and move
> the elog out only for DEBUG1. Anyway, will defer it to you.
It's *definitely* not ok to do an elog() while holding a spinlock. Consider
what happens if the elog tries to format the message and runs out of
memory. Or if elog detects the stack depth is too deep. An ERROR would be
thrown, and we'd loose track of the held spinlock.Thanks for the clarification.Amit,I will provide the patch changed accordingly.--Best Wishes,Ashutosh
--
Best Wishes,
Ashutosh
Attachment
On Tue, Aug 17, 2021 at 11:58 AM Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote: > > Hi Amit and Andres, > Here's updated patch > I think we can log the required information immediately after releasing spinlock, otherwise, the other logs from LogicalConfirmReceivedLocation() might interleave. I have made that change and slightly edit the comment and commit message. I am planning to push this tomorrow unless you or others have any comments. -- With Regards, Amit Kapila.
Attachment
Yeah, I agree. Sorry for missing that.
The updated patch looks good to me.
On Mon, Sep 6, 2021 at 3:25 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
On Tue, Aug 17, 2021 at 11:58 AM Ashutosh Bapat
<ashutosh.bapat@enterprisedb.com> wrote:
>
> Hi Amit and Andres,
> Here's updated patch
>
I think we can log the required information immediately after
releasing spinlock, otherwise, the other logs from
LogicalConfirmReceivedLocation() might interleave. I have made that
change and slightly edit the comment and commit message. I am planning
to push this tomorrow unless you or others have any comments.
--
With Regards,
Amit Kapila.
--
Best Wishes,
Ashutosh
On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote: > > Yeah, I agree. Sorry for missing that. > > The updated patch looks good to me. > Pushed! -- With Regards, Amit Kapila.
Thanks Amit. On Tue, Sep 7, 2021 at 11:14 AM Amit Kapila <amit.kapila16@gmail.com> wrote: > > On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat > <ashutosh.bapat@enterprisedb.com> wrote: > > > > Yeah, I agree. Sorry for missing that. > > > > The updated patch looks good to me. > > > > Pushed! > > -- > With Regards, > Amit Kapila. -- Best Wishes, Ashutosh Bapat
On Tue, Sep 07, 2021 at 11:14:23AM +0530, Amit Kapila wrote: > On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat > <ashutosh.bapat@enterprisedb.com> wrote: > > > > Yeah, I agree. Sorry for missing that. > > > > The updated patch looks good to me. > > > > Pushed! > This patch is still on "Needs review"! Should we change it to Committed or is expected something else about it? -- Jaime Casanova Director de Servicios Profesionales SystemGuards - Consultores de PostgreSQL
On Fri, Oct 1, 2021 at 1:45 AM Jaime Casanova <jcasanov@systemguards.com.ec> wrote: > > On Tue, Sep 07, 2021 at 11:14:23AM +0530, Amit Kapila wrote: > > On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat > > <ashutosh.bapat@enterprisedb.com> wrote: > > > > > > Yeah, I agree. Sorry for missing that. > > > > > > The updated patch looks good to me. > > > > > > > Pushed! > > > > This patch is still on "Needs review"! > Should we change it to Committed or is expected something else > about it? Yes, the patch already gets committed (4c347885). So I also think we should mark it as Committed. Regards, -- Masahiko Sawada EDB: https://www.enterprisedb.com/
On Fri, Oct 1, 2021 at 6:36 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote: > > On Fri, Oct 1, 2021 at 1:45 AM Jaime Casanova > <jcasanov@systemguards.com.ec> wrote: > > > > On Tue, Sep 07, 2021 at 11:14:23AM +0530, Amit Kapila wrote: > > > On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat > > > <ashutosh.bapat@enterprisedb.com> wrote: > > > > > > > > Yeah, I agree. Sorry for missing that. > > > > > > > > The updated patch looks good to me. > > > > > > > > > > Pushed! > > > > > > > This patch is still on "Needs review"! > > Should we change it to Committed or is expected something else > > about it? > > Yes, the patch already gets committed (4c347885). So I also think we > should mark it as Committed. > Right, I have changed the status to Committed. -- With Regards, Amit Kapila.