Re: Emit extra debug message when executing extension script.

From: Alvaro Herrera <alvherre(at)alvh(dot)no-ip(dot)org>
To: Robert Haas <robertmhaas(at)gmail(dot)com>
Cc: Peter Eisentraut <peter(dot)eisentraut(at)enterprisedb(dot)com>, Jeff Davis <pgsql(at)j-davis(dot)com>, "pgsql-hackers(at)postgresql(dot)org" <pgsql-hackers(at)postgresql(dot)org>
Subject: Re: Emit extra debug message when executing extension script.
Date: 2022-07-05 19:26:00
Message-ID: 20220705192600.iczqo5crqjdvkml5@alvherre.pgsql
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

On 2022-Jul-05, Robert Haas wrote:

> On Mon, Jul 4, 2022 at 5:27 AM Alvaro Herrera <alvherre(at)alvh(dot)no-ip(dot)org> wrote:
> > On 2022-Jun-29, Robert Haas wrote:

> > > Why?
> >
> > The reason is that errmsg() marks the message for translation, and we
> > don't want to burden translators with messages that are of little
> > interest to most users. Using either elog() or errmsg_internal()
> > avoids that.
>
> Yeah, I'm aware of that in general, but I'm not quite clear on how we
> decide that. Do we take the view that all debug-level messages need
> not be translated?

Yes. I don't know about others, but I do.

I notice that we have a small number of other errmsg() uses in DEBUG
messages already. I don't think they're quite worth it. I mean, would
a user ever run amcheck with log level set to DEBUG, and care about
any of these messages? I think I wouldn't care.

contrib/amcheck/verify_heapam.c: ereport(DEBUG1,
contrib/amcheck/verify_heapam.c- (errcode(ERRCODE_READ_ONLY_SQL_TRANSACTION),
contrib/amcheck/verify_heapam.c- errmsg("cannot verify unlogged relation \"%s\" during recovery, skipping",

contrib/amcheck/verify_nbtree.c: ereport(DEBUG1,
contrib/amcheck/verify_nbtree.c- (errcode(ERRCODE_READ_ONLY_SQL_TRANSACTION),
contrib/amcheck/verify_nbtree.c- errmsg("cannot verify unlogged index \"%s\" during recovery, skipping",

Why are these basic_archive messages translatable? Seems pointless.

contrib/basic_archive/basic_archive.c: ereport(DEBUG3,
contrib/basic_archive/basic_archive.c- (errmsg("archiving \"%s\" via basic_archive", file)));

contrib/basic_archive/basic_archive.c: ereport(DEBUG3,
contrib/basic_archive/basic_archive.c- (errmsg("archive file \"%s\" already exists with identical contents",

contrib/basic_archive/basic_archive.c: ereport(DEBUG1,
contrib/basic_archive/basic_archive.c- (errmsg("archived \"%s\" via basic_archive", file)));

We also have a small number in the backend:

src/backend/access/heap/vacuumlazy.c: ereport(DEBUG2,
src/backend/access/heap/vacuumlazy.c- (errmsg("table \"%s\": removed %lld dead item identifiers in %u pages",
src/backend/access/heap/vacuumlazy.c- vacrel->relname, (long long) index, vacuumed_pages)));

Why is this one unconditional DEBUG2 instead of depending on
LVRelState->message_level (ie. turn into INFO when VERBOSE is used),
like every other message from vacuum? It seems to me that if I say
VERBOSE, then I may be interested in this message also. While at it,
why are the index vacuuming routines not using LVRelState->message_level
either but instead hardcode DEBUG2? Aren't they all mistakes?

src/backend/replication/logical/worker.c: ereport(DEBUG1,
src/backend/replication/logical/worker.c- (errmsg("logical replication apply worker for subscription \"%s\" two_phase is %s",
src/backend/replication/logical/worker.c- MySubscription->name,

Not sure why anybody cares about this. Why not remove the message?

src/backend/utils/activity/pgstat.c: ereport(DEBUG2,
src/backend/utils/activity/pgstat.c- (errcode_for_file_access(),
src/backend/utils/activity/pgstat.c- errmsg("unlinked permanent statistics file \"%s\"",

Hmm, why is there an errcode here, after the operation succeeds? ISTM
this could be an elog().

Then we have this one:

ereport(DEBUG1,
(errcode(ERRCODE_INTERNAL_ERROR),
errmsg("picksplit method for column %d of index \"%s\" failed",
attno + 1, RelationGetRelationName(r)),
errhint("The index is not optimal. To optimize it, contact a developer, or try to use the column as the second one in the CREATE INDEX command.")));

I cannot understand how is DEBUG1 a useful log level for this message.
How is the user going to find out that there is a problem, when this
message is hidden from them? Do we tell people to run their insert
queries for tables with GiST indexes under DEBUG1, in case the picksplit
method fails, so that they can contact a developer? How many
user-defined picksplit methods have been improved to cope with this
problem, since commit 09368d23dbf4 added this bit in April 2009? How
many of them have been presenting the problem since then, and not been
fixed because nobody has noticed that there is a problem?

--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/

In response to

Browse pgsql-hackers by date

  From Date Subject
Next Message Peter Geoghegan 2022-07-05 19:41:00 Re: [UNVERIFIED SENDER] Re: pg_upgrade can result in early wraparound on databases with high transaction load
Previous Message Przemysław Sztoch 2022-07-05 19:24:49 Re: [PATCH] Completed unaccent dictionary with many missing characters