Subject: more descriptive message for process termination due to max_slot_wal_keep_size

From: Kyotaro Horiguchi <[email-masked]>
Date: Tue, 14 Dec 2021 13:04:56 +0900 (JST)

Hello.

As complained in pgsql-bugs [1], when a process is terminated due to
max_slot_wal_keep_size, the related messages don't mention the root
cause for *the termination*.  Note that the third message does not
show for temporary replication slots.

[pid=a] LOG:  terminating process x to release replication slot "s"
[pid=x] LOG:  FATAL:  terminating connection due to administrator command
[pid=a] LOG:  invalidting slot "s" because its restart_lsn X/X exceeds max_slot_wal_keep_size

The attached patch attaches a DETAIL line to the first message.

> [17605] LOG:  terminating process 17614 to release replication slot "s1"
+ [17605] DETAIL:  The slot's restart_lsn 0/2C0000A0 exceeds max_slot_wal_keep_size.
> [17614] FATAL:  terminating connection due to administrator command
> [17605] LOG:  invalidating slot "s1" because its restart_lsn 0/2C0000A0 exceeds max_slot_wal_keep_size

Somewhat the second and fourth lines look inconsistent each other but
that wouldn't be such a problem.  I don't think we want to concatenate
the two lines together as the result is a bit too long.

> LOG:  terminating process 17614 to release replication slot "s1" because it's restart_lsn 0/2C0000A0 exceeds max_slot_wal_keep_size.

What do you think about this?

[1] https://www.postgresql.org/message-id/20211214.101137.379073733372253470.horikyota.ntt%40gmail.com

-- 
Kyotaro Horiguchi
NTT Open Source Software Center

---

From: Ashutosh Bapat <[email-masked]>
Date: Tue, 14 Dec 2021 19:31:21 +0530

> What do you think about this?

Agree. I think we should also specify the restart_lsn value which
would be within max_slot_wal_keep_size for better understanding.

-- 
Best Wishes,
Ashutosh Bapat

---

From: Bharath Rupireddy <[email-masked]>
Date: Tue, 14 Dec 2021 19:43:18 +0530

On Tue, Dec 14, 2021 at 9:35 AM Kyotaro Horiguchi
<[email-masked]> wrote:
> [pid=a] LOG:  "terminating process %d to release replication slot \"%s\""

+1 to give more context to the "terminating process %d to release
replication slot \"%s\"" message.

How about having below, instead of adding errdetail:
"terminating process %d to release replication slot \"%s\" whose
restart_lsn %X/%X exceeds max_slot_wal_keep_size"?

I think we can keep the "invalidating slot \"%s\" because its
restart_lsn %X/%X exceeds max_slot_wal_keep_size" message as-is. We
may not see "terminating process ..." and "invalidation slot ..."
messages together for the same slot, so having slightly different
wording is fine IMO.

Regards,
Bharath Rupireddy.

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Wed, 15 Dec 2021 13:12:18 +0900 (JST)

At Tue, 14 Dec 2021 19:31:21 +0530, Ashutosh Bapat <[email-masked]> wrote in 
> would be within max_slot_wal_keep_size for better understanding.

Thanks!  It seems to me the main message of the "invalidating" log has
no room for further detail.  So I split the reason out to DETAILS line
the same way with the "terminating" message in the attached second
patch. (It is separated from the first patch just for review) I
believe someone can make the DETAIL message simpler or more natural.

The attached patch set emits the following message.

> LOG:  invalidating slot "s1"
> DETAIL:  The slot's restart_lsn 0/10000D68 is behind the limit 0/11000000 defined by max_slot_wal_keep_size.

The second line could be changed like the following or anything other.

> DETAIL:  The slot's restart_lsn 0/10000D68 got behind the limit 0/11000000 determined by max_slot_wal_keep_size.
.....

regards.

---

From: Ashutosh Bapat <[email-masked]>
Date: Thu, 23 Dec 2021 18:08:08 +0530

> > DETAIL:  The slot's restart_lsn 0/10000D68 got behind the limit 0/11000000 determined by max_slot_wal_keep_size.

The second version looks better as it gives more details. I am fine
with either of the above wordings.

I would prefer everything in the same message though since
"invalidating slot ..." is too short a LOG message. Not everybody
enabled details always.

-- 
Best Wishes,
Ashutosh Bapat

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Fri, 24 Dec 2021 13:42:14 +0900 (JST)

At Thu, 23 Dec 2021 18:08:08 +0530, Ashutosh Bapat <[email-masked]> wrote in 
> "invalidating slot ..." is too short a LOG message. Not everybody

Mmm. Right. I have gone too much to the same way with the
process-termination message.

I rearranged the meesages as follows in the attached version. (at master)

> LOG:  terminating process %d to release replication slot \"%s\" because its restart_lsn %X/%X exceeds max_slot_wal_keep_size
> DETAIL:  The slot got behind the limit %X/%X determined by max_slot_wal_keep_size.

> LOG:  invalidating slot \"%s\" because its restart_LSN %X/%X exceeds max_slot_wal_keep_size
c> DETAIL:  The slot got behind the limit %X/%X determined by max_slot_wal_keep_size.

The messages is actually incomplete even in 13 so I think the change
to the errmsg() message of the first message is worth back-patching.

- v3-0001-Make-a-message-on-process-termination-more-dscrip.patch

  Changes only the first main message and it can be back-patched to 14. 

- v3-0001-Make-a-message-on-process-termination-more-dscrip_13.patch

  The same to the above but for 13, which doesn't have LSN_FORMAT_ARGS.

- v3-0002-Add-detailed-information-to-slot-invalidation-mes.patch

  Attaches the DETAIL line shown above to both messages, only for the
  master.

regards.

---

From: Masahiko Sawada <[email-masked]>
Date: Fri, 24 Dec 2021 17:06:57 +0900

> I rearranged the meesages as follows in the attached version. (at master)

Thank you for the patch! +1 for improving the messages.

> c> DETAIL:  The slot got behind the limit %X/%X determined by max_slot_wal_keep_size.

-
LSN_FORMAT_ARGS(restart_lsn))));
+
LSN_FORMAT_ARGS(restart_lsn)),
+                                                errdetail("The slot
got behind the limit %X/%X determined by max_slot_wal_keep_size.",
+
LSN_FORMAT_ARGS(oldestLSN))));

Isn't oldestLSN calculated not only by max_slot_wal_keep_size but also
by wal_keep_size?

Regards,

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

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Fri, 24 Dec 2021 17:30:16 +0900 (JST)

Thank you for the comment.

At Fri, 24 Dec 2021 17:06:57 +0900, Masahiko Sawada <[email-masked]> wrote in 
> Isn't oldestLSN calculated not only by max_slot_wal_keep_size but also

Right. But I believe the two are not assumed to be used at once. One
can set wal_keep_size larger than max_slot_wal_keep_size but it is
actually a kind of ill setting.

LOG:  terminating process %d to release replication slot \"%s\" because its restart_lsn %X/%X exceeds max_slot_wal_keep_size
DETAIL:  The slot got behind the limit %X/%X determined by max_slot_wal_keep_size and wal_keep_size.

Mmm. I don't like this.  I feel we don't need such detail in the
message..  I'd like to hear opinions from others, please.

regards.

---

From: Masahiko Sawada <[email-masked]>
Date: Fri, 24 Dec 2021 20:23:29 +0900

On Fri, Dec 24, 2021 at 5:30 PM Kyotaro Horiguchi
<[email-masked]> wrote:
> message.

How about something like:

LOG:  terminating process %d to release replication slot \"%s\"
because its restart_lsn %X/%X exceeds the limit
DETAIL:  The slot got behind the limit %X/%X
HINT: You might need to increase max_slot_wal_keep_size or wal_keep_size.

Regards,

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Tue, 04 Jan 2022 10:29:31 +0900 (JST)

At Fri, 24 Dec 2021 20:23:29 +0900, Masahiko Sawada <[email-masked]> wrote in 
> HINT: You might need to increase max_slot_wal_keep_size or wal_keep_size.

The message won't be seen when max_slot_wal_keep_size is not set. So
we don't recommend to increase wal_keep_size in that case. We might
need inhibit (or warn)the two parameters from being activated at once,
but it would be another issue.

Another point is how people determine the value for the parameter.  I
suppose (or believe) max_slot_wal_keep_size is not a kind to set to
minimal first then increase later but a kind to set to maximum
allowable first.  On the other hand we suggest as the follows for
too-small max_wal_size so we could do the same for this parameter.

> HINT:  Consider increasing the configuration parameter \"max_wal_size\".

Also, I don't like we have three lines for this message. If the DETAIL
adds only the specific value of the limit, I think it'd better append
it to the main message.

So what do you say if I propose the following?

LOG:  terminating process %d to release replication slot \"%s\"
because its restart_lsn %X/%X exceeds the limit %X/%X
HINT: You might need to increase max_slot_wal_keep_size.

regards.

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Wed, 02 Mar 2022 15:37:19 +0900 (JST)

At Tue, 04 Jan 2022 10:29:31 +0900 (JST), Kyotaro Horiguchi <[email-masked]> wrote in 
> HINT: You might need to increase max_slot_wal_keep_size.

This version emits the following message.

[35785:checkpointer] LOG:  terminating process 36368 to release replication slot "s1" because its restart_lsn 0/1F000148 exceeds the limit 0/21000000
[35785:checkpointer] HINT:  You might need to increase max_slot_wal_keep_size.
[36368:walsender] FATAL:  terminating connection due to administrator command
[36368:walsender] STATEMENT:  START_REPLICATION SLOT "s1" 0/1F000000 TIMELINE 1
[35785:checkpointer] LOG:  invalidating slot "s1" because its restart_lsn 0/1F000148 exceeds the limit 0/21000000
[35785:checkpointer] HINT:  You might need to increase max_slot_wal_keep_size.

We can omit the HINT line from the termination log for non-persistent
slots but I think we don't want to bother that considering its low
frequency.

The CI was confused by the mixed patches for multiple PG versions. In
this version the patchset for master are attached as .patch and that
for PG13 as .txt.

regards.

>From 4909db2893f0b33ab6bca1ffc3ad802cd159c577 Mon Sep 17 00:00:00 2001
From: Kyotaro Horiguchi <[email-masked]>
Date: Fri, 24 Dec 2021 12:52:07 +0900
Subject: [PATCH v4 1/2] Make a message on process termination more dscriptive

The message at process termination due to slot limit doesn't provide
the reason. In the major scenario the message is followed by another
message about slot invalidatation, which shows the detail for the
termination.  However the second message is missing if the slot is
temporary one.

Augment the first message with the reason same as the second message.

Backpatch through to 13 where the message was introduced.

Reported-by: Alex Enachioaie <[email-masked]>
Author: Kyotaro Horiguchi <[email-masked]>
Reviewed-by: Ashutosh Bapat <[email-masked]>
Reviewed-by: Bharath Rupireddy <[email-masked]>
Discussion: https://www.postgresql.org/message-id/17327-89d0efa8b9ae6271%40postgresql.org
Backpatch-through: 13
---
 src/backend/replication/slot.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index caa6b29756..92f19bcb35 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -1300,8 +1300,9 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlot *s, XLogRecPtr oldestLSN,
 			if (last_signaled_pid != active_pid)
 			{
 				ereport(LOG,
-						(errmsg("terminating process %d to release replication slot \"%s\"",
-								active_pid, NameStr(slotname))));
+						(errmsg("terminating process %d to release replication slot \"%s\" because its restart_lsn %X/%X exceeds max_slot_wal_keep_size",
+								active_pid, NameStr(slotname),
+								LSN_FORMAT_ARGS(restart_lsn))));
 
 				(void) kill(active_pid, SIGTERM);
 				last_signaled_pid = active_pid;
-- 
2.27.0

>From f31014f85c7dec160bd42e1c48f1c28a7dc22af2 Mon Sep 17 00:00:00 2001
From: Kyotaro Horiguchi <[email-masked]>
Date: Fri, 24 Dec 2021 12:58:25 +0900
Subject: [PATCH v4 2/2] Add detailed information to slot-invalidation messages

The messages says just "exceeds max_slot_wal_keep_size" but doesn't
tell the concrete LSN of the limit. That information helps operators'
understanding on the issue.

Author: Kyotaro Horiguchi <[email-masked]>
Reviewed-by: Ashutosh Bapat <[email-masked]>
Reviewed-by: Masahiko Sawada <[email-masked]>
Discussion: https://www.postgresql.org/message-id/17327-89d0efa8b9ae6271%40postgresql.org
---
 src/backend/replication/slot.c | 12 ++++++++----
 1 file changed, 8 insertions(+), 4 deletions(-)

diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index 92f19bcb35..be21b62add 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -1300,9 +1300,11 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlot *s, XLogRecPtr oldestLSN,
 			if (last_signaled_pid != active_pid)
 			{
 				ereport(LOG,
-						(errmsg("terminating process %d to release replication slot \"%s\" because its restart_lsn %X/%X exceeds max_slot_wal_keep_size",
+						(errmsg("terminating process %d to release replication slot \"%s\" because its restart_lsn %X/%X exceeds the limit %X/%X",
 								active_pid, NameStr(slotname),
-								LSN_FORMAT_ARGS(restart_lsn))));
+								LSN_FORMAT_ARGS(restart_lsn),
+								LSN_FORMAT_ARGS(oldestLSN)),
+						 errhint("You might need to increase max_slot_wal_keep_size.")));
 
 				(void) kill(active_pid, SIGTERM);
 				last_signaled_pid = active_pid;
@@ -1345,9 +1347,11 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlot *s, XLogRecPtr oldestLSN,
 			ReplicationSlotRelease();
 
 			ereport(LOG,
-					(errmsg("invalidating slot \"%s\" because its restart_lsn %X/%X exceeds max_slot_wal_keep_size",
+					(errmsg("invalidating slot \"%s\" because its restart_lsn %X/%X exceeds the limit %X/%X",
 							NameStr(slotname),
-							LSN_FORMAT_ARGS(restart_lsn))));
+							LSN_FORMAT_ARGS(restart_lsn),
+							LSN_FORMAT_ARGS(oldestLSN)),
+					 errhint("You might need to increase max_slot_wal_keep_size.")));
 
 			/* done with this slot for now */
 			break;
-- 
2.27.0

>From 6c5a680842521b26c0c899c3d0675bd53e58ac11 Mon Sep 17 00:00:00 2001
From: Kyotaro Horiguchi <[email-masked]>
Date: Fri, 24 Dec 2021 13:23:54 +0900
Subject: [PATCH v4] Make a message on process termination more dscriptive

The message at process termination due to slot limit doesn't provide
the reason. In the major scenario the message is followed by another
message about slot invalidatation, which shows the detail for the
termination.  However the second message is missing if the slot is
temporary one.

Augment the first message with the reason same as the second message.

Backpatch through to 13 where the message was introduced.

Reported-by: Alex Enachioaie <[email-masked]>
Author: Kyotaro Horiguchi <[email-masked]>
Reviewed-by: Ashutosh Bapat <[email-masked]>
Reviewed-by: Bharath Rupireddy <[email-masked]>
Discussion: https://www.postgresql.org/message-id/17327-89d0efa8b9ae6271%40postgresql.org
Backpatch-through: 13
---
 src/backend/replication/slot.c | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index 02047ea920..15b8934ae2 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -1228,8 +1228,10 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlot *s, XLogRecPtr oldestLSN,
 			if (last_signaled_pid != active_pid)
 			{
 				ereport(LOG,
-						(errmsg("terminating process %d to release replication slot \"%s\"",
-								active_pid, NameStr(slotname))));
+						(errmsg("terminating process %d to release replication slot \"%s\" because its restart_lsn %X/%X exceeds max_slot_wal_keep_size",
+								active_pid, NameStr(slotname),
+								(uint32) (restart_lsn >> 32),
+								(uint32) restart_lsn)));
 
 				(void) kill(active_pid, SIGTERM);
 				last_signaled_pid = active_pid;
-- 
2.27.0

---

From: "Drouvot, Bertrand" <[email-masked]>
Date: Mon, 5 Sep 2022 11:56:33 +0200

Hi,

On 3/2/22 7:37 AM, Kyotaro Horiguchi wrote:
> At Tue, 04 Jan 2022 10:29:31 +0900 (JST), Kyotaro Horiguchi<[email-masked]>  wrote in

As the hint is to increase max_slot_wal_keep_size, what about reporting 
the difference in size (rather than the limit lsn)? Something along 
those lines?

[35785:checkpointer] LOG:  terminating process 36368 to release replication slot "s1" because its restart_lsn 0/1F000148 exceeds the limit by <NNN MB>.

Regards,

-- 

Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services:https://aws.amazon.com

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Tue, 06 Sep 2022 14:53:36 +0900 (JST)

At Mon, 5 Sep 2022 11:56:33 +0200, "Drouvot, Bertrand" <[email-masked]> wrote in 
> > At Tue, 04 Jan 2022 10:29:31 +0900 (JST), Kyotaro
> > Horiguchi<[email-masked]> wrote in
> > [35785:checkpointer] LOG: terminating process 36368 to release
> > replication slot "s1" because its restart_lsn 0/1F000148 exceeds the
> > limit 0/21000000
> As the hint is to increase max_slot_wal_keep_size, what about
> reporting the difference in size (rather than the limit lsn)?
> Something along those lines?
> 
> [35785:checkpointer] LOG: terminating process 36368 to release
> replication slot "s1" because its restart_lsn 0/1F000148 exceeds the
> limit by <NNN MB>.

Thanks! That might be more sensible exactly for the reason you
mentioned.  One issue doing that is size_pretty is dbsize.c local
function. Since the size is less than kB in many cases, we cannot use
fixed unit for that.

0001 and 0002 are the same with v5.

0003 exposes byte_size_pretty() to other modules.
0004 does the change by using byte_size_pretty()

After 0004 applied, they look like this.

> LOG:  terminating process 108413 to release replication slot "rep3" because its restart_lsn 0/7000D8 exceeds the limit by 1024 kB

The reason for "1024 kB" instead of "1 MB" is the precise value is a
bit less than 1024 * 1024.

regards.

- 
Kyotaro Horiguchi

---

From: "Drouvot, Bertrand" <[email-masked]>
Date: Tue, 6 Sep 2022 10:54:35 +0200

Hi,

On 9/6/22 7:53 AM, Kyotaro Horiguchi wrote:
> At Mon, 5 Sep 2022 11:56:33 +0200, "Drouvot, Bertrand"<[email-masked]>  wrote in
>> Hi,
>>

Thanks for the new patch version!. I did not realized (sorry about that) 
that we'd need to expose byte_size_pretty(). Now I wonder if we should 
not simply report the number of bytes (like I can see it is done in many 
places). So something like:

@@ -1298,9 +1298,9 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlot *s, 
XLogRecPtr oldestLSN,
                                 byte_size_pretty(buf, sizeof(buf),
oldestLSN - restart_lsn);
                                 ereport(LOG,
- (errmsg("terminating process %d to release replication slot \"%s\" 
because its restart_lsn %X/%X exceeds the limit by %s",
+ (errmsg("terminating process %d to release replication slot \"%s\" 
because its restart_lsn %X/%X exceeds the limit by %lu bytes",
active_pid, NameStr(slotname),
- LSN_FORMAT_ARGS(restart_lsn), buf),
+ LSN_FORMAT_ARGS(restart_lsn), oldestLSN - restart_lsn),
                                                  errhint("You might 
need to increase max_slot_wal_keep_size.")));

and then forget about exposing/using byte_size_pretty() (that would be 
more consistent with the same kind of reporting in the existing code).

What do you think?

Regards,

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Wed, 07 Sep 2022 11:20:19 +0900 (JST)

(I noticed I sent a wrong version..)

At Tue, 6 Sep 2022 10:54:35 +0200, "Drouvot, Bertrand" <[email-masked]> wrote in 
> Thanks for the new patch version!. I did not realized (sorry about
> that) that we'd need to expose byte_size_pretty(). Now I wonder if we

I didn't think we need the units larger than MB, but I used
pretty_print to prevent small number from rounding to exactly zero. On
the other hand, in typical cases it is longer than 6 digits in bytes,
which is a bit hard to read a glance.

> LOG:  terminating process 16034 to release replication slot "rep1" because its restart_lsn 0/3158000 exceeds the limit by 15368192 bytes

> should not simply report the number of bytes (like I can see it is
> done in many places). So something like:
..
> because its restart_lsn %X/%X exceeds the limit by %lu bytes",
..
> more consistent with the same kind of reporting in the existing code).

An alterntive would be rounding up to the whole MB, or a sub-MB.

>        ereport(LOG,
>            (errmsg("terminating process %d to release replication slot \"%s\" because its restart_lsn %X/%X exceeds the limit by %.1lf MB",
>                LSN_FORMAT_ARGS(restart_lsn),
>                /* round-up at sub-MB */
>                ceil((double) (oldestLSN - restart_lsn) / 1024 / 102.4) / 10),

> LOG:  terminating process 49539 to release replication slot "rep1" because its restart_lsn 0/3038000 exceeds the limit by 15.8 MB

If the distance were 1 byte, it is shown as "0.1 MB".

regards.

---

From: "Drouvot, Bertrand" <[email-masked]>
Date: Wed, 7 Sep 2022 12:16:29 +0200

Hi,

On 9/7/22 4:20 AM, Kyotaro Horiguchi wrote:
> At Tue, 6 Sep 2022 10:54:35 +0200, "Drouvot, Bertrand"<[email-masked]>  wrote in
> pretty_print to prevent small number from rounding to exactly zero.

Yeah makes sense.

Also, rounding to zero wouldn't occur with "just" displaying "oldestLSN 
- restart_lsn" (as proposed upthread).

> On

Yeah right, but that's already the case in some part of the code, like 
for example in arrayfuncs.c:

                 ereport(ERROR,
                         (errcode(ERRCODE_PROGRAM_LIMIT_EXCEEDED),
                          errmsg("array size exceeds the maximum allowed 
(%d)",
                                 (int) MaxAllocSize)));

>>                 ceil((double) (oldestLSN - restart_lsn) / 1024 / 102.4) / 10),

typo "/ 102.4" ?

> If the distance were 1 byte, it is shown as "0.1 MB".

Right and I'm -1 on it, I think we should stick to the "pretty" or the 
"bytes only" approach (my preference being the bytes only one).

Regards,

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Thu, 08 Sep 2022 13:40:20 +0900 (JST)

At Wed, 7 Sep 2022 12:16:29 +0200, "Drouvot, Bertrand" <[email-masked]> wrote in 
> Also, rounding to zero wouldn't occur with "just" displaying
> "oldestLSN - restart_lsn" (as proposed upthread).
..
> for example in arrayfuncs.c:

Fair points.

> >>         ereport(LOG,
> >>             (errmsg("terminating process %d to release replication slot
> >>             \"%s\" because its restart_lsn %X/%X exceeds the limit by %.1lf
> >>             MB",

No, it rounds the difference up to one decimal place. So it is devided
by 10 after ceil():p

> >> LOG: terminating process 49539 to release replication slot "rep1"
> >> because its restart_lsn 0/3038000 exceeds the limit by 15.8 MB

Okay. the points you brought up above are sufficient grounds for not
doing so.  Now they are in the following format.

>> LOG: terminating process 16034 to release replication slot "rep1"
>> because its restart_lsn 0/3158000 exceeds the limit by 15368192 bytes

Thank you for the discussion, Bertrand!

regards.

---

From: "Drouvot, Bertrand" <[email-masked]>
Date: Thu, 8 Sep 2022 11:29:38 +0200

Hi,

On 9/8/22 6:40 AM, Kyotaro Horiguchi wrote:
> At Wed, 7 Sep 2022 12:16:29 +0200, "Drouvot, Bertrand"<[email-masked]>  wrote in

You are welcome, thanks for the patch!

It looks good to me, barring any objections i think we can mark the CF 
entry as Ready for Committer.

Regards,

---

From: Tom Lane <[email-masked]>
Date: Wed, 28 Sep 2022 16:30:37 -0400

> because its restart_lsn 0/3158000 exceeds the limit by 15368192 bytes

This seems to me to be a pretty blatant violation of our first message
style guideline [1]:

    The primary message should be short, factual, and avoid reference to
    implementation details such as specific function names. “Short” means
    “should fit on one line under normal conditions”. Use a detail message
    if needed to keep the primary message short ...

I think you should leave the primary message alone and add a DETAIL,
as the first version of the patch did.

The existing "invalidating slot" message is already in violation
of this guideline, so splitting off a DETAIL from that seems
indicated as well.

			regards, tom lane

[1] https://www.postgresql.org/docs/devel/error-style-guide.html

---

From: Tom Lane <[email-masked]>
Date: Wed, 28 Sep 2022 16:38:51 -0400

... oh, one other point is that using %ld to print an int64 is entirely
not portable, as indeed the cfbot is complaining about.

I think our best practice on that is to put %lld in the format string
and explicitly cast the corresponding argument to "long long".

			regards, tom lane

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Thu, 29 Sep 2022 14:27:53 +0900 (JST)

At Wed, 28 Sep 2022 16:30:37 -0400, Tom Lane <[email-masked]> wrote in 
> This seems to me to be a pretty blatant violation of our first message

Thanks! It seems that I was waiting for a comment on that line.  I
thought that way at first but finally returned to the current message
as the result of discussion (in my memory). I will happily make the
main message shorter.

> of this guideline, so splitting off a DETAIL from that seems

So I'm going to change the mssage as:

LOG:  terminating process %d to release replication slot \"%s\"
DETAIL:  The slot's restart_lsn %X/%X exceeds the limit by %lld bytes.
HINT:  You might need to increase max_slot_wal_keep_size.

LOG:  invalidating *replication* slot \"%s\"
DETAILS:  (ditto)
HINTS:  (ditto)

It seems that it's no longer useful to split out the first patch so I
merged them into one.

regards.

---

From: Tom Lane <[email-masked]>
Date: Thu, 29 Sep 2022 13:31:00 -0400

> LOG:  invalidating *replication* slot \"%s\"

I thought the latter was a little *too* short; the primary message
should at least give you some clue why that happened, even if it
doesn't offer all the detail.  After some thought I changed it to

LOG:  invalidating obsolete replication slot \"%s\"

and pushed it that way.

			regards, tom lane

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Fri, 30 Sep 2022 11:15:19 +0900 (JST)

At Thu, 29 Sep 2022 13:31:00 -0400, Tom Lane <[email-masked]> wrote in 
> doesn't offer all the detail.  After some thought I changed it to

Yeah, agreed. It looks better. (I was about to spell it as
"invalidating slot "%s"" then changed my mind to add "replication". I
felt that it is a bit too short but didn't think about further
streaching that by adding "obsolete"..).

> LOG:  invalidating obsolete replication slot \"%s\"

Thanks. And thanks for fixing the test script, too.

By the way, I didn't notice at that time (and forgot about the
policy), but the HINT message has variations differing only by the
variable name.

What do you think about the attached?

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center
diff --git a/src/backend/replication/logical/launcher.c b/src/backend/replication/logical/launcher.c
index 3bbd522724..2106a8d41d 100644
--- a/src/backend/replication/logical/launcher.c
+++ b/src/backend/replication/logical/launcher.c
@@ -363,7 +363,8 @@ retry:
 		ereport(WARNING,
 				(errcode(ERRCODE_CONFIGURATION_LIMIT_EXCEEDED),
 				 errmsg("out of logical replication worker slots"),
-				 errhint("You might need to increase max_logical_replication_workers.")));
+				 errhint("You might need to increase %s.",
+						 "max_logical_replication_workers")));
 		return;
 	}
 
@@ -420,7 +421,8 @@ retry:
 		ereport(WARNING,
 				(errcode(ERRCODE_CONFIGURATION_LIMIT_EXCEEDED),
 				 errmsg("out of background worker slots"),
-				 errhint("You might need to increase max_worker_processes.")));
+				 errhint("You might need to increase %s.",
+						 "max_worker_processes")));
 		return;
 	}
 
diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index e9328961dd..5ea9b73980 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -1298,7 +1298,8 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlot *s, XLogRecPtr oldestLSN,
 						errdetail("The slot's restart_lsn %X/%X exceeds the limit by %llu bytes.",
 								  LSN_FORMAT_ARGS(restart_lsn),
 								  (unsigned long long) (oldestLSN - restart_lsn)),
-						errhint("You might need to increase max_slot_wal_keep_size."));
+						errhint("You might need to increase %s.",
+								"max_slot_wal_keep_size"));
 
 				(void) kill(active_pid, SIGTERM);
 				last_signaled_pid = active_pid;
@@ -1340,7 +1341,8 @@ InvalidatePossiblyObsoleteSlot(ReplicationSlot *s, XLogRecPtr oldestLSN,
 					errdetail("The slot's restart_lsn %X/%X exceeds the limit by %llu bytes.",
 							  LSN_FORMAT_ARGS(restart_lsn),
 							  (unsigned long long) (oldestLSN - restart_lsn)),
-					errhint("You might need to increase max_slot_wal_keep_size."));
+					errhint("You might need to increase %s.",
+							"max_slot_wal_keep_size"));
 
 			/* done with this slot for now */
 			break;
diff --git a/src/backend/storage/lmgr/lock.c b/src/backend/storage/lmgr/lock.c
index 5f5803f681..5a29f4d346 100644
--- a/src/backend/storage/lmgr/lock.c
+++ b/src/backend/storage/lmgr/lock.c
@@ -980,7 +980,8 @@ LockAcquireExtended(const LOCKTAG *locktag,
 				ereport(ERROR,
 						(errcode(ERRCODE_OUT_OF_MEMORY),
 						 errmsg("out of shared memory"),
-						 errhint("You might need to increase max_locks_per_transaction.")));
+						 errhint("You might need to increase %s.",
+								 "max_locks_per_transaction")));
 			else
 				return LOCKACQUIRE_NOT_AVAIL;
 		}
@@ -1018,7 +1019,8 @@ LockAcquireExtended(const LOCKTAG *locktag,
 			ereport(ERROR,
 					(errcode(ERRCODE_OUT_OF_MEMORY),
 					 errmsg("out of shared memory"),
-					 errhint("You might need to increase max_locks_per_transaction.")));
+					 errhint("You might need to increase %s.",
+							 "max_locks_per_transaction")));
 		else
 			return LOCKACQUIRE_NOT_AVAIL;
 	}
@@ -2843,7 +2845,8 @@ FastPathGetRelationLockEntry(LOCALLOCK *locallock)
 			ereport(ERROR,
 					(errcode(ERRCODE_OUT_OF_MEMORY),
 					 errmsg("out of shared memory"),
-					 errhint("You might need to increase max_locks_per_transaction.")));
+					 errhint("You might need to increase %s.",
+							 "max_locks_per_transaction")));
 		}
 		GrantLock(proclock->tag.myLock, proclock, lockmode);
 		FAST_PATH_CLEAR_LOCKMODE(MyProc, f, lockmode);
@@ -4257,7 +4260,8 @@ lock_twophase_recover(TransactionId xid, uint16 info,
 		ereport(ERROR,
 				(errcode(ERRCODE_OUT_OF_MEMORY),
 				 errmsg("out of shared memory"),
-				 errhint("You might need to increase max_locks_per_transaction.")));
+				 errhint("You might need to increase %s.",
+						 "max_locks_per_transaction")));
 	}
 
 	/*
@@ -4322,7 +4326,8 @@ lock_twophase_recover(TransactionId xid, uint16 info,
 		ereport(ERROR,
 				(errcode(ERRCODE_OUT_OF_MEMORY),
 				 errmsg("out of shared memory"),
-				 errhint("You might need to increase max_locks_per_transaction.")));
+				 errhint("You might need to increase %s.",
+						 "max_locks_per_transaction")));
 	}
 
 	/*
@@ -4672,7 +4677,8 @@ VirtualXactLock(VirtualTransactionId vxid, bool wait)
 			ereport(ERROR,
 					(errcode(ERRCODE_OUT_OF_MEMORY),
 					 errmsg("out of shared memory"),
-					 errhint("You might need to increase max_locks_per_transaction.")));
+					 errhint("You might need to increase %s.",
+							 "max_locks_per_transaction")));
 		}
 		GrantLock(proclock->tag.myLock, proclock, ExclusiveLock);
 
diff --git a/src/backend/storage/lmgr/predicate.c b/src/backend/storage/lmgr/predicate.c
index e8120174d6..6ea1052ba6 100644
--- a/src/backend/storage/lmgr/predicate.c
+++ b/src/backend/storage/lmgr/predicate.c
@@ -2471,7 +2471,8 @@ CreatePredicateLock(const PREDICATELOCKTARGETTAG *targettag,
 		ereport(ERROR,
 				(errcode(ERRCODE_OUT_OF_MEMORY),
 				 errmsg("out of shared memory"),
-				 errhint("You might need to increase max_pred_locks_per_transaction.")));
+				 errhint("You might need to increase %s.",
+						 "max_pred_locks_per_transaction")));
 	if (!found)
 		SHMQueueInit(&(target->predicateLocks));
 
@@ -2486,7 +2487,8 @@ CreatePredicateLock(const PREDICATELOCKTARGETTAG *targettag,
 		ereport(ERROR,
 				(errcode(ERRCODE_OUT_OF_MEMORY),
 				 errmsg("out of shared memory"),
-				 errhint("You might need to increase max_pred_locks_per_transaction.")));
+				 errhint("You might need to increase %s.",
+						 "max_pred_locks_per_transaction")));
 
 	if (!found)
 	{
@@ -3968,7 +3970,8 @@ ReleaseOneSerializableXact(SERIALIZABLEXACT *sxact, bool partial,
 				ereport(ERROR,
 						(errcode(ERRCODE_OUT_OF_MEMORY),
 						 errmsg("out of shared memory"),
-						 errhint("You might need to increase max_pred_locks_per_transaction.")));
+						 errhint("You might need to increase %s.",
+								 "max_pred_locks_per_transaction")));
 			if (found)
 			{
 				Assert(predlock->commitSeqNo != 0);

---

From: Tom Lane <[email-masked]>
Date: Thu, 29 Sep 2022 22:49:00 -0400

> What do you think about the attached?

Hmm, maybe, but a quick grep for 'You might need to increase'
finds about a dozen other cases, and none of them are using %s.
If we do this we should change all of them, and they probably
need "translator:" hints.  I'm not sure whether abstracting
away the variable names will make translation harder.

			regards, tom lane

---

From: Kyotaro Horiguchi <[email-masked]>
Date: Fri, 30 Sep 2022 13:49:51 +0900 (JST)

At Thu, 29 Sep 2022 22:49:00 -0400, Tom Lane <[email-masked]> wrote in 
> finds about a dozen other cases, and none of them are using %s.
(Mmm. I didn't find others only in po files..)
> away the variable names will make translation harder.

I expect that dedicated po-editing tools can lookup corresponding code
lines, which gives the answer if no hint is attached at least in this
specific case.

Anyway, thinking calmly, since we are not about to edit these
messages, it's unlikely to happen on purpose, I think. So I don't mean
to push this so hard.

Thanks for the comment!

regards.