Improve description of XLOG_RUNNING_XACTS

On 2022/07/21 10:13, Masahiko Sawada wrote:

Hi,

I realized that standby_desc_running_xacts() in standbydesc.c doesn't
describe subtransaction XIDs. I've attached the patch to improve the
description.

+1

The patch looks good to me.

Regards,

--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION

At Thu, 21 Jul 2022 11:21:09 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

On 2022/07/21 10:13, Masahiko Sawada wrote:

Hi,
I realized that standby_desc_running_xacts() in standbydesc.c doesn't
describe subtransaction XIDs. I've attached the patch to improve the
description.

+1

The patch looks good to me.

The subxids can reach TOTAL_MAX_CACHED_SUBXIDS =
PGPROC_MAX_CACHED_SUBXIDS(=64) * PROCARRAY_MAXPROCS. xact_desc_commit
also shows subtransactions but they are at maximum 64. I feel like
-0.3 if there's no obvious advantage showing them.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

On Thu, Jul 21, 2022 at 4:29 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Thu, 21 Jul 2022 11:21:09 +0900, Fujii Masao <masao.fujii@oss.nttdata.com> wrote in

On 2022/07/21 10:13, Masahiko Sawada wrote:

Hi,
I realized that standby_desc_running_xacts() in standbydesc.c doesn't
describe subtransaction XIDs. I've attached the patch to improve the
description.

+1

The patch looks good to me.

The subxids can reach TOTAL_MAX_CACHED_SUBXIDS =
PGPROC_MAX_CACHED_SUBXIDS(=64) * PROCARRAY_MAXPROCS. xact_desc_commit
also shows subtransactions but they are at maximum 64. I feel like
-0.3 if there's no obvious advantage showing them.

xxx_desc() functions are debugging purpose functions as they are used
by pg_waldump and pg_walinspect etc. I think such functions should
show all contents unless there is reason to hide them. Particularly,
standby_desc_running_xacts() currently shows subtransaction
information only when subtransactions are overflowed, which got me
confused when inspecting WAL records.

Regards,

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

At Thu, 21 Jul 2022 16:58:45 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in

The patch looks good to me.

By the way +1 to this.

The subxids can reach TOTAL_MAX_CACHED_SUBXIDS =
PGPROC_MAX_CACHED_SUBXIDS(=64) * PROCARRAY_MAXPROCS. xact_desc_commit
also shows subtransactions but they are at maximum 64. I feel like
-0.3 if there's no obvious advantage showing them.

xxx_desc() functions are debugging purpose functions as they are used
by pg_waldump and pg_walinspect etc. I think such functions should
show all contents unless there is reason to hide them. Particularly,
standby_desc_running_xacts() currently shows subtransaction
information only when subtransactions are overflowed, which got me
confused when inspecting WAL records.

I'm not sure just confusing can justify that but after finding
logicalmsg_desc dumps the whole content, I no longer feel against to
show subxacts.

Just for information, but as far as I saw, relmap_desc shows only the
length of "data" but doesn't dump all of it. generic_desc behaves the
same way. Thus we could just show "%d subxacts" instead of dumping
out the all subxact ids just to avoid that confusion.

However, again, I no longer object to show all subxids.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Hi

On Thu, Jul 21, 2022 at 6:44 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:

Hi,

I realized that standby_desc_running_xacts() in standbydesc.c doesn't
describe subtransaction XIDs. I've attached the patch to improve the
description. Here is an example by pg_wlaldump:

* HEAD
rmgr: Standby len (rec/tot): 58/ 58, tx: 0, lsn:
0/01D0C608, prev 0/01D0C5D8, desc: RUNNING_XACTS nextXid 1050
latestCompletedXid 1047 oldestRunningXid 1048; 1 xacts: 1048

* w/ patch
rmgr: Standby len (rec/tot): 58/ 58, tx: 0, lsn:
0/01D0C608, prev 0/01D0C5D8, desc: RUNNING_XACTS nextXid 1050
latestCompletedXid 1047 oldestRunningXid 1048; 1 xacts: 1048; 1
subxacts: 1049

I think this is a good addition to debugging info. +1

If we are going to add 64 subxid numbers then it would help if we
could be more verbose and print "subxid overflowed" instead of "subxid
ovf".

--
Best Wishes,
Ashutosh Bapat

On Thu, Jul 21, 2022 at 10:13 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

Hi

On Thu, Jul 21, 2022 at 6:44 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:

Hi,

I realized that standby_desc_running_xacts() in standbydesc.c doesn't
describe subtransaction XIDs. I've attached the patch to improve the
description. Here is an example by pg_wlaldump:

* HEAD
rmgr: Standby len (rec/tot): 58/ 58, tx: 0, lsn:
0/01D0C608, prev 0/01D0C5D8, desc: RUNNING_XACTS nextXid 1050
latestCompletedXid 1047 oldestRunningXid 1048; 1 xacts: 1048

* w/ patch
rmgr: Standby len (rec/tot): 58/ 58, tx: 0, lsn:
0/01D0C608, prev 0/01D0C5D8, desc: RUNNING_XACTS nextXid 1050
latestCompletedXid 1047 oldestRunningXid 1048; 1 xacts: 1048; 1
subxacts: 1049

I think this is a good addition to debugging info. +1

If we are going to add 64 subxid numbers then it would help if we
could be more verbose and print "subxid overflowed" instead of "subxid
ovf".

Yeah, it looks better so agreed. I've attached an updated patch.

Regards,

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

Thanks Masahiko for the updated patch. It looks good to me.

I wonder whether the logic should be, similar
to ProcArrayApplyRecoveryInfo()
if (xlrec->subxid_overflow)
...
else if (xlrec->subxcnt > 0)
...

But you may ignore it.

--
Best Wishes,
Ashutosh

On Thu, Jul 28, 2022 at 7:41 AM Masahiko Sawada <sawada.mshk@gmail.com>
wrote:

At Thu, 28 Jul 2022 09:56:33 +0530, Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote in

Thanks Masahiko for the updated patch. It looks good to me.

I wonder whether the logic should be, similar
to ProcArrayApplyRecoveryInfo()
if (xlrec->subxid_overflow)
...
else if (xlrec->subxcnt > 0)
...

But you may ignore it.

Either is fine if we asuume the record is sound, but since it is
debugging output, I think we should always output the information *for
both* . The following change doesn't change the output for a sound
record.

====
if (xlrec->subxcnt > 0)
{
appendStringInfo(buf, "; %d subxacts:", xlrec->subxcnt);
for (i = 0; i < xlrec->subxcnt; i++)
appendStringInfo(buf, " %u", xlrec->xids[xlrec->xcnt + i]);
}
- else if (xlrec->subxid_overflow)
+ if (xlrec->subxid_overflow)
appendStringInfoString(buf, "; subxid overflowed");
====

Another point is if the xid/subxid lists get long, I see it annoying
that the "overflowed" messages goes far away to the end of the long
line. Couldn't we rearrange the item order of the line as the follows?

nextXid %u latestCompletedXid %u oldestRunningXid %u;[ subxid overflowed;][ %d xacts: %u %u ...;][ subxacts: %u %u ..]

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

On Thu, Jul 28, 2022 at 3:24 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Thu, 28 Jul 2022 09:56:33 +0530, Ashutosh Bapat <ashutosh.bapat@enterprisedb.com> wrote in

Thanks Masahiko for the updated patch. It looks good to me.

I wonder whether the logic should be, similar
to ProcArrayApplyRecoveryInfo()
if (xlrec->subxid_overflow)
...
else if (xlrec->subxcnt > 0)
...

But you may ignore it.

Either is fine if we asuume the record is sound, but since it is
debugging output, I think we should always output the information *for
both* . The following change doesn't change the output for a sound
record.

====
if (xlrec->subxcnt > 0)
{
appendStringInfo(buf, "; %d subxacts:", xlrec->subxcnt);
for (i = 0; i < xlrec->subxcnt; i++)
appendStringInfo(buf, " %u", xlrec->xids[xlrec->xcnt + i]);
}
- else if (xlrec->subxid_overflow)
+ if (xlrec->subxid_overflow)
appendStringInfoString(buf, "; subxid overflowed");
====

Do you mean that both could be true at the same time? If I read
GetRunningTransactionData() correctly, that doesn't happen.

Regards,

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

At Thu, 28 Jul 2022 15:53:33 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in

Do you mean that both could be true at the same time? If I read
GetRunningTransactionData() correctly, that doesn't happen.

So, I wrote "since it is debugging output", and "fine if we asuume the
record is sound". Is it any trouble with assuming the both *can*
happen at once? If something's broken, it will be reflected in the
output.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

Sorry for the late reply.

On Thu, Jul 28, 2022 at 4:29 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Thu, 28 Jul 2022 15:53:33 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in

Do you mean that both could be true at the same time? If I read
GetRunningTransactionData() correctly, that doesn't happen.

So, I wrote "since it is debugging output", and "fine if we asuume the
record is sound". Is it any trouble with assuming the both *can*
happen at once? If something's broken, it will be reflected in the
output.

Fair point. We may not need to interpret the contents.

On Thu, Jul 28, 2022 at 3:24 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

Another point is if the xid/subxid lists get long, I see it annoying
that the "overflowed" messages goes far away to the end of the long
line. Couldn't we rearrange the item order of the line as the follows?

nextXid %u latestCompletedXid %u oldestRunningXid %u;[ subxid overflowed;][ %d xacts: %u %u ...;][ subxacts: %u %u ..]

I'm concerned that we have two information of subxact apart. Given
that showing both individual subxacts and "overflow" is a bug, I think
we can output like:

if (xlrec->subxcnt > 0)
{
appendStringInfo(buf, "; %d subxacts:", xlrec->subxcnt);
for (i = 0; i < xlrec->subxcnt; i++)
appendStringInfo(buf, " %u", xlrec->xids[xlrec->xcnt + i]);
}

if (xlrec->subxid_overflow)
appendStringInfoString(buf, "; subxid overflowed");

Or we can output the "subxid overwlowed" first.

Regards,

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

At Mon, 15 Aug 2022 11:16:56 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in

Sorry for the late reply.

No worries. Anyway I was in a long (as a Japanese:) vacation.

On Thu, Jul 28, 2022 at 4:29 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

record is sound". Is it any trouble with assuming the both *can*
happen at once? If something's broken, it will be reflected in the
output.

Fair point. We may not need to interpret the contents.

Yeah.

On Thu, Jul 28, 2022 at 3:24 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

Another point is if the xid/subxid lists get long, I see it annoying
that the "overflowed" messages goes far away to the end of the long
line. Couldn't we rearrange the item order of the line as the follows?

nextXid %u latestCompletedXid %u oldestRunningXid %u;[ subxid overflowed;][ %d xacts: %u %u ...;][ subxacts: %u %u ..]

I'm concerned that we have two information of subxact apart. Given
that showing both individual subxacts and "overflow" is a bug, I think

Bug or every kind of breakage of the file. So if "overflow"ed, we
don't need to show a subxid there but I thought that there's no need
to change behavior in that case since it scarcely happens.

we can output like:

if (xlrec->subxcnt > 0)
{
appendStringInfo(buf, "; %d subxacts:", xlrec->subxcnt);
for (i = 0; i < xlrec->subxcnt; i++)
appendStringInfo(buf, " %u", xlrec->xids[xlrec->xcnt + i]);
}

if (xlrec->subxid_overflow)
appendStringInfoString(buf, "; subxid overflowed");

Yea, it seems like what I proposed upthread. I'm fine with that since
it is an abonormal situation.

Or we can output the "subxid overwlowed" first.

(I prefer this, as that doesn't change the output in the normal case
but the anormality will be easilly seen if happens.)

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

On Tue, Aug 23, 2022 at 11:53 AM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Mon, 15 Aug 2022 11:16:56 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in

Sorry for the late reply.

No worries. Anyway I was in a long (as a Japanese:) vacation.

On Thu, Jul 28, 2022 at 4:29 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

record is sound". Is it any trouble with assuming the both *can*
happen at once? If something's broken, it will be reflected in the
output.

Fair point. We may not need to interpret the contents.

Yeah.

On Thu, Jul 28, 2022 at 3:24 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

Another point is if the xid/subxid lists get long, I see it annoying
that the "overflowed" messages goes far away to the end of the long
line. Couldn't we rearrange the item order of the line as the follows?

nextXid %u latestCompletedXid %u oldestRunningXid %u;[ subxid overflowed;][ %d xacts: %u %u ...;][ subxacts: %u %u ..]

I'm concerned that we have two information of subxact apart. Given
that showing both individual subxacts and "overflow" is a bug, I think

Bug or every kind of breakage of the file. So if "overflow"ed, we
don't need to show a subxid there but I thought that there's no need
to change behavior in that case since it scarcely happens.

we can output like:

if (xlrec->subxcnt > 0)
{
appendStringInfo(buf, "; %d subxacts:", xlrec->subxcnt);
for (i = 0; i < xlrec->subxcnt; i++)
appendStringInfo(buf, " %u", xlrec->xids[xlrec->xcnt + i]);
}

if (xlrec->subxid_overflow)
appendStringInfoString(buf, "; subxid overflowed");

Yea, it seems like what I proposed upthread. I'm fine with that since
it is an abonormal situation.

Or we can output the "subxid overwlowed" first.

(I prefer this, as that doesn't change the output in the normal case
but the anormality will be easilly seen if happens.)

Updated the patch accordingly.

Regards,

--
Masahiko Sawada

At Fri, 9 Sep 2022 09:48:05 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in

On Tue, Aug 23, 2022 at 11:53 AM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:

At Mon, 15 Aug 2022 11:16:56 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in

Or we can output the "subxid overwlowed" first.

(I prefer this, as that doesn't change the output in the normal case
but the anormality will be easilly seen if happens.)

Updated the patch accordingly.

Thanks! Considering the discussion so far, how about adding a comment
like this?

 +		appendStringInfoString(buf, "; subxid overflowed");
 +
++	/*
++	 * subxids and subxid_overflow are mutually exclusive, but we deliberitely
++	 * print the both simultaneously in case the record is broken.
++	 */
 +	if (xlrec->subxcnt > 0)
 +	{
 +		appendStringInfo(buf, "; %d subxacts:", xlrec->subxcnt);
 +		for (i = 0; i < xlrec->subxcnt; i++)
 +			appendStringInfo(buf, " %u", xlrec->xids[xlrec->xcnt + i]);
 +	}

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

On Fri, Sep 9, 2022 at 6:18 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:

Updated the patch accordingly.

I have created two xacts each with savepoints and after your patch,
the record will show xacts/subxacts information as below:

rmgr: Standby len (rec/tot): 74/ 74, tx: 0, lsn:
0/014AC238, prev 0/014AC1F8, desc: RUNNING_XACTS nextXid 733
latestCompletedXid 726 oldestRunningXid 727; 2 xacts: 729 727; 4
subxacts: 730 731 728 732

There is no way to associate which subxacts belong to which xact, so
will it be useful, and if so, how? I guess we probably don't need it
here because the describe records just display the record information.

--
With Regards,
Amit Kapila.

Hi,

When translating error messages, Alexander Lakhin
(<exclusion@gmail.com>) noticed some inconsistencies so I prepared a
small patch to fix those.

Please see attached.

--
Ekaterina Kiryanova
Technical Writer
Postgres Professional
the Russian PostgreSQL Company

On Wed, Sep 14, 2022 at 5:01 PM Ekaterina Kiryanova
<e.kiryanova@postgrespro.ru> wrote:

Hi,

When translating error messages, Alexander Lakhin
(<exclusion@gmail.com>) noticed some inconsistencies so I prepared a
small patch to fix those.

+1

This one

- errmsg("background worker \"%s\": background worker without shared
memory access are not supported",
+ errmsg("background worker \"%s\": background workers without shared
memory access are not supported",

is a grammar error so worth backpatching, but the rest are cosmetic.

Will commit this way unless there are objections.

--
John Naylor
EDB: http://www.enterprisedb.com

On 2022-Sep-14, John Naylor wrote:

This one

+ errmsg("background worker \"%s\": background workers without shared
memory access are not supported",

is a grammar error so worth backpatching, but the rest are cosmetic.

Will commit this way unless there are objections.

+1

--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/
"I dream about dreams about dreams", sang the nightingale
under the pale moon (Sandman)

On Wed, Sep 14, 2022 at 6:33 PM Amit Kapila <amit.kapila16@gmail.com> wrote:

On Fri, Sep 9, 2022 at 6:18 AM Masahiko Sawada <sawada.mshk@gmail.com> wrote:

Updated the patch accordingly.

I have created two xacts each with savepoints and after your patch,
the record will show xacts/subxacts information as below:

rmgr: Standby len (rec/tot): 74/ 74, tx: 0, lsn:
0/014AC238, prev 0/014AC1F8, desc: RUNNING_XACTS nextXid 733
latestCompletedXid 726 oldestRunningXid 727; 2 xacts: 729 727; 4
subxacts: 730 731 728 732

There is no way to associate which subxacts belong to which xact, so
will it be useful, and if so, how? I guess we probably don't need it
here because the describe records just display the record information.

I think it's useful for debugging purposes. For instance, when I was
working on the fix 68dcce247f1a13318613a0e27782b2ca21a4ceb7
(REL_14_STABLE), I checked if all initial running transactions
including subtransactions are properly stored and purged by checking
the debug logs and pg_waldump output. Actually, until I realize that
the description of RUNNING_XACTS doesn't show subtransaction
information, I was confused by the fact that the saved initial running
transactions didn't match the description shown by pg_waldump.

Regards,

--
Masahiko Sawada
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com