Thread: what does this mean: "running xacts with xcnt == 0"
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)?
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
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
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
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
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
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
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.
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.
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