Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Fri, Oct 1, 2021 at 6:36 AM Masahiko Sawada wrote: > > On Fri, Oct 1, 2021 at 1:45 AM Jaime Casanova > 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 > > > 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.
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Fri, Oct 1, 2021 at 1:45 AM Jaime Casanova 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 > > 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/
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Tue, Sep 07, 2021 at 11:14:23AM +0530, Amit Kapila wrote: > On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat > 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
Re: Diagnostic comment in LogicalIncreaseXminForSlot
Thanks Amit. On Tue, Sep 7, 2021 at 11:14 AM Amit Kapila wrote: > > On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat > wrote: > > > > Yeah, I agree. Sorry for missing that. > > > > The updated patch looks good to me. > > > > Pushed! > > -- > With Regards, > Amit Kapila. -- Best Wishes, Ashutosh Bapat
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Mon, Sep 6, 2021 at 5:29 PM Ashutosh Bapat wrote: > > Yeah, I agree. Sorry for missing that. > > The updated patch looks good to me. > Pushed! -- With Regards, Amit Kapila.
Re: Diagnostic comment in LogicalIncreaseXminForSlot
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 wrote: > On Tue, Aug 17, 2021 at 11:58 AM Ashutosh Bapat > 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
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Tue, Aug 17, 2021 at 11:58 AM Ashutosh Bapat 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. 0001-Log-new-catalog-xmin-candidate-in-LogicalIncreaseXmi.patch Description: Binary data
Re: Diagnostic comment in LogicalIncreaseXminForSlot
Hi Amit and Andres, Here's updated patch On Mon, Aug 9, 2021 at 11:14 AM Ashutosh Bapat < ashutosh.ba...@enterprisedb.com> wrote: > > > On Sat, Aug 7, 2021 at 11:40 AM Andres Freund wrote: > >> Hi, >> >> On 2021-07-12 17:28:15 +0530, Ashutosh Bapat wrote: >> > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila >> wrote: >> > >> > > On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada < >> sawada.m...@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 From 0a2f2c1f530d72219d9db7bd1ff77c1ae8c4ffe4 Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat Date: Thu, 13 May 2021 13:40:33 +0530 Subject: [PATCH] Report new catalog_xmin candidate in LogicalIncreaseXminForSlot() Similar to LogicalIncreaseRestartDecodingForSlot() add a debug message to LogicalIncreaseXminForSlot() reporting a new catalog_xmin candidate. --- src/backend/replication/logical/logical.c | 11 +++ 1 file changed, 11 insertions(+) diff --git a/src/backend/replication/logical/logical.c b/src/backend/replication/logical/logical.c index 64b8280c13..6c8c387e73 100644 --- a/src/backend/replication/logical/logical.c +++ b/src/backend/replication/logical/logical.c @@ -1565,6 +1565,7 @@ LogicalIncreaseXminForSlot(XLogRecPtr current_lsn, TransactionId xmin) { bool updated_xmin = false; ReplicationSlot *slot; + bool got_new_xmin = false; slot = MyReplicationSlot; @@ -1602,12 +1603,22 @@ LogicalIncreaseXminForSlot(XLogRecPtr current_lsn, TransactionId xmin) { slot->candidate_catalog_xmin = xmin; slot->candidate_xmin_lsn = current_lsn; + + /* + * Add a line about new xmin in server logs at an appropriate log level + * after releasing the spinlock. + */ + got_new_xmin = true; } SpinLockRelease(>mutex); /* candidate already valid with the current flush position, apply */ if (updated_xmin) LogicalConfirmReceivedLocation(slot->data.confirmed_flush); + + if (got_new_xmin) + elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin, + LSN_FORMAT_ARGS(current_lsn)); } /* -- 2.25.1
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Sat, Aug 7, 2021 at 11:40 AM Andres Freund wrote: > Hi, > > On 2021-07-12 17:28:15 +0530, Ashutosh Bapat wrote: > > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila > wrote: > > > > > On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada > > > > 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
Re: Diagnostic comment in LogicalIncreaseXminForSlot
Hi, On 2021-07-12 17:28:15 +0530, Ashutosh Bapat wrote: > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila wrote: > > > On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada > > 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
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Mon, Jul 12, 2021 at 5:28 PM Ashutosh Bapat wrote: > > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila wrote: >> >> On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada >> wrote: >> > >> > On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat >> > 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(>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. > 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.
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Mon, Jul 12, 2021 at 6:23 PM Amit Kapila wrote: > On Mon, Jul 12, 2021 at 5:28 PM Ashutosh Bapat > wrote: > > > > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila > 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
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Mon, Jul 12, 2021 at 5:28 PM Ashutosh Bapat wrote: > > On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila 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.
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Mon, Jul 12, 2021 at 8:39 AM Amit Kapila wrote: > On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada > wrote: > > > > On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat > > 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(>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
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada wrote: > > On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat > 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(>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.
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Thu, Jul 8, 2021 at 8:14 PM Daniel Gustafsson wrote: > > > On 8 Jul 2021, at 12:56, Amit Kapila 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/
Re: Diagnostic comment in LogicalIncreaseXminForSlot
> On 8 Jul 2021, at 12:56, Amit Kapila 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/
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Mon, Jul 5, 2021 at 12:54 PM Masahiko Sawada wrote: > > On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat > wrote: > > > > > > > > On Fri, May 21, 2021 at 11:26 AM Amit Kapila > > wrote: > >> > >> On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat > >> 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. > > 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.
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Fri, May 21, 2021 at 6:00 PM Ashutosh Bapat wrote: > > > > On Fri, May 21, 2021 at 11:26 AM Amit Kapila wrote: >> >> On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat >> 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. The patch looks to me. Regards, -- Masahiko Sawada EDB: https://www.enterprisedb.com/
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Fri, May 21, 2021 at 11:26 AM Amit Kapila wrote: > On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat > 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 From edc05ab21445e859ba6f80bf2c97563c94a1e66b Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat Date: Thu, 13 May 2021 13:40:33 +0530 Subject: [PATCH] Report new catalog_xmin candidate in LogicalIncreaseXminForSlot() Similar to LogicalIncreaseRestartDecodingForSlot() add a debug message to LogicalIncreaseXminForSlot() reporting a new catalog_xmin candidate. We should submit this to the community. BDR-723 --- src/backend/replication/logical/logical.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/backend/replication/logical/logical.c b/src/backend/replication/logical/logical.c index ffc6160e9f..a776c54c01 100644 --- a/src/backend/replication/logical/logical.c +++ b/src/backend/replication/logical/logical.c @@ -1573,6 +1573,8 @@ LogicalIncreaseXminForSlot(XLogRecPtr current_lsn, TransactionId xmin) { 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(>mutex); -- 2.25.1
Re: Diagnostic comment in LogicalIncreaseXminForSlot
On Thu, May 20, 2021 at 5:43 PM Ashutosh Bapat 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.
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 From 5d211016367fe352871647225ead64a2215c3184 Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat Date: Thu, 13 May 2021 13:40:33 +0530 Subject: [PATCH 1/2] Report new catalog_xmin candidate in LogicalIncreaseXminForSlot() Similar to LogicalIncreaseRestartDecodingForSlot() add a debug message to LogicalIncreaseXminForSlot() reporting a new catalog_xmin candidate. We should submit this to the community. BDR-723 --- src/backend/replication/logical/logical.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/backend/replication/logical/logical.c b/src/backend/replication/logical/logical.c index a43df58537..59fd16d1ef 100644 --- a/src/backend/replication/logical/logical.c +++ b/src/backend/replication/logical/logical.c @@ -1562,6 +1562,8 @@ LogicalIncreaseXminForSlot(XLogRecPtr current_lsn, TransactionId xmin) { slot->candidate_catalog_xmin = xmin; slot->candidate_xmin_lsn = current_lsn; + elog(DEBUG1, "got new catalog_xmin %u at %X/%X", xmin, + (uint32) (current_lsn >> 32), (uint32) current_lsn); } SpinLockRelease(>mutex); -- 2.25.1