what does this mean: "running xacts with xcnt == 0"

Started by Peter Eisentrautabout 11 years ago10 messages
#1Peter Eisentraut
peter_e@gmx.net

Could someone translate this detail message to English:

ereport(LOG,
(errmsg("logical decoding found consistent point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail("running xacts with xcnt == 0")));

(or downgrade to debug message, if appropriate)?

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#2Andres Freund
andres@2ndquadrant.com
In reply to: Peter Eisentraut (#1)
Re: what does this mean: "running xacts with xcnt == 0"

Hi,

On 2014-11-12 09:03:40 -0500, Peter Eisentraut wrote:

Could someone translate this detail message to English:

ereport(LOG,
(errmsg("logical decoding found consistent point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail("running xacts with xcnt == 0")));

It means there a xl_running_xacts record was encountered that had xcnt =
0 - allowing logical decoding to find a consistent start point

(or downgrade to debug message, if appropriate)?

The message generally is quite relevant, as the process of finding a
consistent start point can take quite a while. we don't really have a
nice way to make errdetail() only be logged on a certain severity level
as far as I am aware off.

So maybe 'Encountered xl_running_xacts record with xcnt = 0.'?

Greetings,

Andres Freund

--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#3Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Andres Freund (#2)
Re: what does this mean: "running xacts with xcnt == 0"

Andres Freund wrote:

Hi,

On 2014-11-12 09:03:40 -0500, Peter Eisentraut wrote:

Could someone translate this detail message to English:

ereport(LOG,
(errmsg("logical decoding found consistent point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail("running xacts with xcnt == 0")));

It means there a xl_running_xacts record was encountered that had xcnt =
0 - allowing logical decoding to find a consistent start point

(or downgrade to debug message, if appropriate)?

The message generally is quite relevant, as the process of finding a
consistent start point can take quite a while. we don't really have a
nice way to make errdetail() only be logged on a certain severity level
as far as I am aware off.

Can we do just the errmsg() and remove with the errdetail?

So maybe 'Encountered xl_running_xacts record with xcnt = 0.'?

That's not very user-facing, is it -- I mean, why bother the user with
the names of structs and members thereof? It seems better to describe
what the condition is; something like "found point in time with no
running transaction". Maybe "point in time" should be "WAL record"
instead.

--
�lvaro Herrera http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#4Andres Freund
andres@2ndquadrant.com
In reply to: Alvaro Herrera (#3)
Re: what does this mean: "running xacts with xcnt == 0"

On 2014-11-12 11:56:01 -0300, Alvaro Herrera wrote:

Andres Freund wrote:

Hi,

On 2014-11-12 09:03:40 -0500, Peter Eisentraut wrote:

Could someone translate this detail message to English:

ereport(LOG,
(errmsg("logical decoding found consistent point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail("running xacts with xcnt == 0")));

It means there a xl_running_xacts record was encountered that had xcnt =
0 - allowing logical decoding to find a consistent start point

(or downgrade to debug message, if appropriate)?

The message generally is quite relevant, as the process of finding a
consistent start point can take quite a while. we don't really have a
nice way to make errdetail() only be logged on a certain severity level
as far as I am aware off.

Can we do just the errmsg() and remove with the errdetail?

No, I really don't want to do that. When trying to see whether logical
replication started that's imo quite an importantdetail. Especially when
first seing
ereport(LOG,
(errmsg("logical decoding found initial starting point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail_plural("%u transaction needs to finish.",
"%u transactions need to finish.",
builder->running.xcnt,
(uint32) builder->running.xcnt)));

Btw, Peter, why did you add a (uint32) to one, but not both,
builder->running.xcnt references?

So maybe 'Encountered xl_running_xacts record with xcnt = 0.'?

That's not very user-facing, is it -- I mean, why bother the user with
the names of structs and members thereof? It seems better to describe
what the condition is; something like "found point in time with no
running transaction". Maybe "point in time" should be "WAL record"
instead.

Is that really a win in clarity? When analyzing a problem I'd much
rather have a concrete hint than something fuzzy.

Greetings,

Andres Freund

--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#5Robert Haas
robertmhaas@gmail.com
In reply to: Andres Freund (#4)
Re: what does this mean: "running xacts with xcnt == 0"

On Wed, Nov 12, 2014 at 10:59 AM, Andres Freund <andres@2ndquadrant.com> wrote:

On 2014-11-12 11:56:01 -0300, Alvaro Herrera wrote:

Andres Freund wrote:

Hi,

On 2014-11-12 09:03:40 -0500, Peter Eisentraut wrote:

Could someone translate this detail message to English:

ereport(LOG,
(errmsg("logical decoding found consistent point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail("running xacts with xcnt == 0")));

It means there a xl_running_xacts record was encountered that had xcnt =
0 - allowing logical decoding to find a consistent start point

(or downgrade to debug message, if appropriate)?

The message generally is quite relevant, as the process of finding a
consistent start point can take quite a while. we don't really have a
nice way to make errdetail() only be logged on a certain severity level
as far as I am aware off.

Can we do just the errmsg() and remove with the errdetail?

No, I really don't want to do that. When trying to see whether logical
replication started that's imo quite an importantdetail. Especially when
first seing
ereport(LOG,
(errmsg("logical decoding found initial starting point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail_plural("%u transaction needs to finish.",
"%u transactions need to finish.",
builder->running.xcnt,
(uint32) builder->running.xcnt)));

Btw, Peter, why did you add a (uint32) to one, but not both,
builder->running.xcnt references?

So maybe 'Encountered xl_running_xacts record with xcnt = 0.'?

That's not very user-facing, is it -- I mean, why bother the user with
the names of structs and members thereof? It seems better to describe
what the condition is; something like "found point in time with no
running transaction". Maybe "point in time" should be "WAL record"
instead.

Is that really a win in clarity? When analyzing a problem I'd much
rather have a concrete hint than something fuzzy.

You can't phrase error messages in terms of internal concepts that 99%
of users won't understand or care about. Like Peter says, user-facing
error messages need to be written in English, not C.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#6Andres Freund
andres@2ndquadrant.com
In reply to: Robert Haas (#5)
Re: what does this mean: "running xacts with xcnt == 0"

On 2014-11-12 12:40:41 -0500, Robert Haas wrote:

On Wed, Nov 12, 2014 at 10:59 AM, Andres Freund <andres@2ndquadrant.com> wrote:

On 2014-11-12 11:56:01 -0300, Alvaro Herrera wrote:

Andres Freund wrote:

Hi,

On 2014-11-12 09:03:40 -0500, Peter Eisentraut wrote:

Could someone translate this detail message to English:

ereport(LOG,
(errmsg("logical decoding found consistent point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail("running xacts with xcnt == 0")));

It means there a xl_running_xacts record was encountered that had xcnt =
0 - allowing logical decoding to find a consistent start point

(or downgrade to debug message, if appropriate)?

The message generally is quite relevant, as the process of finding a
consistent start point can take quite a while. we don't really have a
nice way to make errdetail() only be logged on a certain severity level
as far as I am aware off.

Can we do just the errmsg() and remove with the errdetail?

No, I really don't want to do that. When trying to see whether logical
replication started that's imo quite an importantdetail. Especially when
first seing
ereport(LOG,
(errmsg("logical decoding found initial starting point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail_plural("%u transaction needs to finish.",
"%u transactions need to finish.",
builder->running.xcnt,
(uint32) builder->running.xcnt)));

Btw, Peter, why did you add a (uint32) to one, but not both,
builder->running.xcnt references?

So maybe 'Encountered xl_running_xacts record with xcnt = 0.'?

That's not very user-facing, is it -- I mean, why bother the user with
the names of structs and members thereof? It seems better to describe
what the condition is; something like "found point in time with no
running transaction". Maybe "point in time" should be "WAL record"
instead.

Is that really a win in clarity? When analyzing a problem I'd much
rather have a concrete hint than something fuzzy.

You can't phrase error messages in terms of internal concepts that 99%
of users won't understand or care about. Like Peter says, user-facing
error messages need to be written in English, not C.

That's not the actual message, but an errdetail() - and lots of those
refer to internals? And it's not an error, but a log message? E.g. we
add error contexts for wal replay errors that print the internals
literaly? And it's *really* helpful?

Greetings,

Andres Freund

--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#7Robert Haas
robertmhaas@gmail.com
In reply to: Andres Freund (#6)
Re: what does this mean: "running xacts with xcnt == 0"

On Wed, Nov 12, 2014 at 12:47 PM, Andres Freund <andres@2ndquadrant.com> wrote:

So maybe 'Encountered xl_running_xacts record with xcnt = 0.'?

That's not very user-facing, is it -- I mean, why bother the user with
the names of structs and members thereof? It seems better to describe
what the condition is; something like "found point in time with no
running transaction". Maybe "point in time" should be "WAL record"
instead.

Is that really a win in clarity? When analyzing a problem I'd much
rather have a concrete hint than something fuzzy.

You can't phrase error messages in terms of internal concepts that 99%
of users won't understand or care about. Like Peter says, user-facing
error messages need to be written in English, not C.

That's not the actual message, but an errdetail() - and lots of those
refer to internals? And it's not an error, but a log message? E.g. we
add error contexts for wal replay errors that print the internals
literaly? And it's *really* helpful?

Like what? That's the only errdetail() currently in the tree that
contains ==, for example.

I see there are three different detail messages associated with this
error message. You don't really need these messages to be phrased in
any; it's enough to have the messages be different from each other.

1. found initial snapshot in snapbuild file
2. Transaction ID %u finished; no more running transactions.
3. running xacts with xcnt == 0

The second one follows style guidelines, but the other two do not.

I suggest:

1. Logical decoding will begin using saved snapshot.
2. Transaction ID %u finished; no more running transactions.
3. There are no running transactions.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#8Peter Eisentraut
peter_e@gmx.net
In reply to: Andres Freund (#4)
Re: what does this mean: "running xacts with xcnt == 0"

On 11/12/14 10:59 AM, Andres Freund wrote:

No, I really don't want to do that. When trying to see whether logical
replication started that's imo quite an importantdetail. Especially when
first seing
ereport(LOG,
(errmsg("logical decoding found initial starting point at %X/%X",
(uint32) (lsn >> 32), (uint32) lsn),
errdetail_plural("%u transaction needs to finish.",
"%u transactions need to finish.",
builder->running.xcnt,
(uint32) builder->running.xcnt)));

Btw, Peter, why did you add a (uint32) to one, but not both,
builder->running.xcnt references?

The cast on the second reference was already there, presumably to match
the %u format. (The compiler might complain otherwise.) The first
argument doesn't need a cast, because it's a declared (not variadic)
argument, and so the compiler will cast it automatically.

That's not very user-facing, is it -- I mean, why bother the user with
the names of structs and members thereof? It seems better to describe
what the condition is; something like "found point in time with no
running transaction". Maybe "point in time" should be "WAL record"
instead.

Is that really a win in clarity? When analyzing a problem I'd much
rather have a concrete hint than something fuzzy.

If the output is primarily useful to you only, then it should be a
debug-level message.

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#9Peter Eisentraut
peter_e@gmx.net
In reply to: Robert Haas (#7)
Re: what does this mean: "running xacts with xcnt == 0"

On 11/12/14 1:04 PM, Robert Haas wrote:

I suggest:

1. Logical decoding will begin using saved snapshot.
2. Transaction ID %u finished; no more running transactions.
3. There are no running transactions.

I went with that. Thank you.

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#10Andres Freund
andres@2ndquadrant.com
In reply to: Peter Eisentraut (#9)
Re: what does this mean: "running xacts with xcnt == 0"

On 2014-11-13 21:03:57 -0500, Peter Eisentraut wrote:

On 11/12/14 1:04 PM, Robert Haas wrote:

I suggest:

1. Logical decoding will begin using saved snapshot.
2. Transaction ID %u finished; no more running transactions.
3. There are no running transactions.

I went with that. Thank you.

Thanks!

I was about to push those too..

Greetings,

Andres Freund

--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers