Thread: Re: log_min_messages per backend type
Hello Euler, On 2024-Dec-17, Euler Taveira wrote: > Sometimes you need to inspect some debug messages from autovacuum worker but > you cannot apply the same setting for backends (that could rapidly fill the log > file). This proposal aims to change log_min_messages to have different log > levels depending on which backend type the message comes from. > > The syntax was changed from enum to string and it accepts a list of elements. > > Instead of enum, it now accepts a comma-separated list of elements (string). > Each element is LOGLEVEL:BACKENDTYPE. This format seems unintuitive. I would have thought you do it the other way around, "backendtype:loglevel" ... that seems more natural because it's like assigning the 'loglevel' value to the 'backendtype' element. SET log_min_messages TO 'checkpointer:debug2, autovacuum:debug1'; I dislike the array of names in variable.c. We already have an array in launch_backend.c (child_process_kinds), plus GetBackendTypeDesc in miscinit.c. Maybe not for this patch to clean up though. I think it should be acceptable to configure one global setting with exceptions for particular backend types: log_min_messages = WARNING, autovacuum:DEBUG1 Right now I think the code only accepts the unadorned log level if there are no other items in the list. I think the proposal downthread is to use the keyword ALL for this, log_min_messages = all:WARNING, autovacuum:DEBUG1 # I don't like this but I think it's inferior, because then "all" is not really "all", and I think it would be different if I had said log_min_messages = autovacuum:DEBUG1, all:WARNING # I don't like this because it looks like the "all" entry should override the one I set for autovacuum before, which frankly would not make sense to me. So I think these two lines, log_min_messages = WARNING, autovacuum:DEBUG1 log_min_messages = autovacuum:DEBUG1, WARNING should behave identically and mean "set the level for autovacuum to DEBUG1, and to any other backend type to WARNING. Also, I think it'd be better to reject duplicates in the list. Right now it looks like the last entry for one backend type overrides prior ones. I mean log_min_messages = autovacuum:DEBUG1, autovacuum:ERROR would set autovacuum to error, but that might be mistake prone if your string is long. So implementation-wise I suggest to initialize the whole newlogminmsgs array to -1, then scan the list of entries (saving an entry without backend type as the one to use later and) setting every backend type to the number specified; if we see trying to set a value that's already different from -1, throw error. After scanning the whole log_min_messages array, we scan the newlogminmsgs and set any entries that are still -1 to the value that we saved before. The new code in variable.c should be before the /* DATESTYLE */ comment rather than at the end of the file. You still have many XXX comments. Also, postgresql.conf should list the valid values for backendtype, as well as show an example of a valid setting. Please don't use ALLCAPS backend types in the docs, this looks ugly: > + Valid <literal>BACKENDTYPE</literal> values are <literal>ARCHIVER</literal>, > + <literal>AUTOVACUUM</literal>, <literal>BACKEND</literal>, > + <literal>BGWORKER</literal>, <literal>BGWRITER</literal>, > + <literal>CHECKPOINTER</literal>, <literal>LOGGER</literal>, > + <literal>SLOTSYNCWORKER</literal>, <literal>WALRECEIVER</literal>, > + <literal>WALSENDER</literal>, <literal>WALSUMMARIZER</literal>, and > + <literal>WALWRITER</literal>. -- Álvaro Herrera Breisgau, Deutschland — https://www.EnterpriseDB.com/ "No necesitamos banderas No reconocemos fronteras" (Jorge González)
On Wed, Feb 5, 2025, at 3:51 PM, Álvaro Herrera wrote:
On 2024-Dec-17, Euler Taveira wrote:> Sometimes you need to inspect some debug messages from autovacuum worker but> you cannot apply the same setting for backends (that could rapidly fill the log> file). This proposal aims to change log_min_messages to have different log> levels depending on which backend type the message comes from.>> The syntax was changed from enum to string and it accepts a list of elements.>> Instead of enum, it now accepts a comma-separated list of elements (string).> Each element is LOGLEVEL:BACKENDTYPE.This format seems unintuitive. I would have thought you do it the otherway around, "backendtype:loglevel" ... that seems more natural becauseit's like assigning the 'loglevel' value to the 'backendtype' element.SET log_min_messages TO 'checkpointer:debug2, autovacuum:debug1';
Alvaro, thanks for your feedback. Your suggestion makes sense to me.
I dislike the array of names in variable.c. We already have an array inlaunch_backend.c (child_process_kinds), plus GetBackendTypeDesc inmiscinit.c. Maybe not for this patch to clean up though.
I thought about using child_process_kinds but two details made me give
up on the idea: (a) multiple names per backend type (for example,
B_BACKEND, B_DEAD_END_BACKEND, B_STANDALONE_BACKEND) and (b) spaces into
names. Maybe we should have a group into child_process_kinds but as you
said it seems material for another patch.
I think it should be acceptable to configure one global setting withexceptions for particular backend types:log_min_messages = WARNING, autovacuum:DEBUG1Right now I think the code only accepts the unadorned log level if thereare no other items in the list. I think the proposal downthread is touse the keyword ALL for this,log_min_messages = all:WARNING, autovacuum:DEBUG1 # I don't like thisbut I think it's inferior, because then "all" is not really "all", and Ithink it would be different if I had saidlog_min_messages = autovacuum:DEBUG1, all:WARNING # I don't like thisbecause it looks like the "all" entry should override the one I set forautovacuum before, which frankly would not make sense to me.
Good point. After reflection, I agree that "all" is not a good keyword.
This patch turns backend type as optional so WARNING means apply this
log level as a final step to the backend types that are not specified in
the list.
So I think these two lines,log_min_messages = WARNING, autovacuum:DEBUG1log_min_messages = autovacuum:DEBUG1, WARNINGshould behave identically and mean "set the level for autovacuum toDEBUG1, and to any other backend type to WARNING.
Done.
Also, I think it'd be better to reject duplicates in the list. Rightnow it looks like the last entry for one backend type overrides priorones. I meanlog_min_messages = autovacuum:DEBUG1, autovacuum:ERRORwould set autovacuum to error, but that might be mistake prone if yourstring is long. So implementation-wise I suggest to initialize thewhole newlogminmsgs array to -1, then scan the list of entries (savingan entry without backend type as the one to use later and) setting everybackend type to the number specified; if we see trying to set a valuethat's already different from -1, throw error. After scanning the wholelog_min_messages array, we scan the newlogminmsgs and set any entriesthat are still -1 to the value that we saved before.The new code in variable.c should be before the /* DATESTYLE */ commentrather than at the end of the file.
It was added into the MISCELLANEOUS section.
You still have many XXX comments. Also, postgresql.conf should list thevalid values for backendtype, as well as show an example of a validsetting. Please don't use ALLCAPS backend types in the docs, this looksugly:> + Valid <literal>BACKENDTYPE</literal> values are <literal>ARCHIVER</literal>,> + <literal>AUTOVACUUM</literal>, <literal>BACKEND</literal>,> + <literal>BGWORKER</literal>, <literal>BGWRITER</literal>,> + <literal>CHECKPOINTER</literal>, <literal>LOGGER</literal>,> + <literal>SLOTSYNCWORKER</literal>, <literal>WALRECEIVER</literal>,> + <literal>WALSENDER</literal>, <literal>WALSUMMARIZER</literal>, and> + <literal>WALWRITER</literal>.
Done.
Just to recap what was changed:
- patch was rebased
- backend type is optional and means all unspecified backend types
- generic log level (without backend type) is mandatory and the order it
ppears is not important (it is applied for the remaining backend types)
- fix Windows build
- new tests to cover the changes
Attachment
On 2025-03-04 Tu 7:33 PM, Euler Taveira wrote:
I think it should be acceptable to configure one global setting withexceptions for particular backend types:log_min_messages = WARNING, autovacuum:DEBUG1Right now I think the code only accepts the unadorned log level if thereare no other items in the list. I think the proposal downthread is touse the keyword ALL for this,log_min_messages = all:WARNING, autovacuum:DEBUG1 # I don't like thisbut I think it's inferior, because then "all" is not really "all", and Ithink it would be different if I had saidlog_min_messages = autovacuum:DEBUG1, all:WARNING # I don't like thisbecause it looks like the "all" entry should override the one I set forautovacuum before, which frankly would not make sense to me.
Good point. After reflection, I agree that "all" is not a good keyword.
This patch turns backend type as optional so WARNING means apply this
log level as a final step to the backend types that are not specified in
the list.
So I think these two lines,log_min_messages = WARNING, autovacuum:DEBUG1log_min_messages = autovacuum:DEBUG1, WARNINGshould behave identically and mean "set the level for autovacuum toDEBUG1, and to any other backend type to WARNING.
Done.
Just bikeshedding a bit ...
I'm not mad keen on this design. I think the value should be either a single setting like "WARNING" or a set of type:setting pairs. I agree that "all" is a bad name, but I think "default" would make sense.
I can live with it but I think this just looks a bit odd.
cheers
andrew
-- Andrew Dunstan EDB: https://www.enterprisedb.com
On 2025/03/05 9:33, Euler Taveira wrote: >> > + Valid <literal>BACKENDTYPE</literal> values are <literal>ARCHIVER</literal>, >> > + <literal>AUTOVACUUM</literal>, <literal>BACKEND</literal>, >> > + <literal>BGWORKER</literal>, <literal>BGWRITER</literal>, >> > + <literal>CHECKPOINTER</literal>, <literal>LOGGER</literal>, >> > + <literal>SLOTSYNCWORKER</literal>, <literal>WALRECEIVER</literal>, >> > + <literal>WALSENDER</literal>, <literal>WALSUMMARIZER</literal>, and >> > + <literal>WALWRITER</literal>. What about postmaster? For parallel workers launched for parallel queries, should they follow the backend's log level or the background worker's? Since they operate as part of a parallel query executed by a backend, it seems more logical for them to follow the backend's setting. + [B_CHECKPOINTER] = "checkpointer", + [B_STARTUP] = "backend", /* XXX same as backend? */ I like the idea of allowing log levels to be set per process. There were times I wanted to use debug5 specifically for the startup process when troubleshooting WAL replay. It would be helpful to distinguish the startup process from a regular backend, so we can set its log level independently. Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION
Hi, > > On 2025-03-04 Tu 7:33 PM, Euler Taveira wrote: >>> I think it should be acceptable to configure one global setting with >>> exceptions for particular backend types: >>> >>> log_min_messages = WARNING, autovacuum:DEBUG1 >>> >>> Right now I think the code only accepts the unadorned log level if >>> there >>> are no other items in the list. I think the proposal downthread is to >>> use the keyword ALL for this, >>> >>> log_min_messages = all:WARNING, autovacuum:DEBUG1 # I don't >>> like this >>> >>> but I think it's inferior, because then "all" is not really "all", >>> and I >>> think it would be different if I had said >>> >>> log_min_messages = autovacuum:DEBUG1, all:WARNING # I don't >>> like this >>> >>> because it looks like the "all" entry should override the one I set >>> for >>> autovacuum before, which frankly would not make sense to me. >> >> Good point. After reflection, I agree that "all" is not a good keyword. >> This patch turns backend type as optional so WARNING means apply this >> log level as a final step to the backend types that are not >> specified in >> the list. >> >>> So I think these two lines, >>> >>> log_min_messages = WARNING, autovacuum:DEBUG1 >>> log_min_messages = autovacuum:DEBUG1, WARNING >>> >>> should behave identically and mean "set the level for autovacuum to >>> DEBUG1, and to any other backend type to WARNING. >> >> Done. > > > Just bikeshedding a bit ... > > I'm not mad keen on this design. I think the value should be either a > single setting like "WARNING" or a set of type:setting pairs. I agree > that "all" is a bad name, but I think "default" would make sense. > > I can live with it but I think this just looks a bit odd. > Just bringing some thoughts about it... How about using something like *:WARNING? I'm not sure if it could also be confusing as the "all" keyword, but I think it could also be interpreted as "anything else use WARNING". -- Matheus Alcantara
Hi,
On 2025-03-04 21:33:39 -0300, Euler Taveira wrote:
> +/*
> + * This must match enum BackendType! It should be static, but
> + * commands/variable.c needs to get at this.
> + */
> +int log_min_messages[] = {
> + [B_INVALID] = WARNING,
> + [B_BACKEND] = WARNING,
> + [B_DEAD_END_BACKEND] = WARNING,
> + [B_AUTOVAC_LAUNCHER] = WARNING,
> + [B_AUTOVAC_WORKER] = WARNING,
> + [B_BG_WORKER] = WARNING,
> + [B_WAL_SENDER] = WARNING,
> + [B_SLOTSYNC_WORKER] = WARNING,
> + [B_STANDALONE_BACKEND] = WARNING,
> + [B_ARCHIVER] = WARNING,
> + [B_BG_WRITER] = WARNING,
> + [B_CHECKPOINTER] = WARNING,
> + [B_STARTUP] = WARNING,
> + [B_WAL_RECEIVER] = WARNING,
> + [B_WAL_SUMMARIZER] = WARNING,
> + [B_WAL_WRITER] = WARNING,
> + [B_LOGGER] = WARNING,
> +};
> +StaticAssertDecl(lengthof(log_min_messages) == BACKEND_NUM_TYPES,
> + "array length mismatch");
> +
> +/*
> + * This must match enum BackendType! It might be in commands/variable.c but for
> + * convenience it is near log_min_messages.
> + */
> +const char *const log_min_messages_backend_types[] = {
> + [B_INVALID] = "backend", /* XXX same as backend? */
> + [B_BACKEND] = "backend",
> + [B_DEAD_END_BACKEND] = "backend", /* XXX same as backend? */
> + [B_AUTOVAC_LAUNCHER] = "autovacuum",
> + [B_AUTOVAC_WORKER] = "autovacuum",
> + [B_BG_WORKER] = "bgworker",
> + [B_WAL_SENDER] = "walsender",
> + [B_SLOTSYNC_WORKER] = "slotsyncworker",
> + [B_STANDALONE_BACKEND] = "backend", /* XXX same as backend? */
> + [B_ARCHIVER] = "archiver",
> + [B_BG_WRITER] = "bgwriter",
> + [B_CHECKPOINTER] = "checkpointer",
> + [B_STARTUP] = "backend", /* XXX same as backend? */
Huh, the startup process is among the most crucial things to monitor?
> + [B_WAL_RECEIVER] = "walreceiver",
> + [B_WAL_SUMMARIZER] = "walsummarizer",
> + [B_WAL_WRITER] = "walwriter",
> + [B_LOGGER] = "logger",
> +};
> +
> +StaticAssertDecl(lengthof(log_min_messages_backend_types) == BACKEND_NUM_TYPES,
> + "array length mismatch");
> +
I don't know what I think about the whole patch, but I do want to voice
*strong* opposition to duplicating a list of all backend types into multiple
places. It's already painfull enough to add a new backend type, without having
to pointlessly go around and manually add a new backend type to mulltiple
arrays that have completely predictable content.
Greetings,
Andres Freund
On Wed, Mar 5, 2025, at 11:53 PM, Fujii Masao wrote:
On 2025/03/05 9:33, Euler Taveira wrote:>> > + Valid <literal>BACKENDTYPE</literal> values are <literal>ARCHIVER</literal>,>> > + <literal>AUTOVACUUM</literal>, <literal>BACKEND</literal>,>> > + <literal>BGWORKER</literal>, <literal>BGWRITER</literal>,>> > + <literal>CHECKPOINTER</literal>, <literal>LOGGER</literal>,>> > + <literal>SLOTSYNCWORKER</literal>, <literal>WALRECEIVER</literal>,>> > + <literal>WALSENDER</literal>, <literal>WALSUMMARIZER</literal>, and>> > + <literal>WALWRITER</literal>.What about postmaster?
It is B_INVALID that is currently mapped to "backend". This state is used as an
initial phase for the child process. There might be messages before
MyBackendType is assigned (see ProcessStartupPacket, for example). Hence, I
refrain to create a special backend type for postmaster. Should we map it to
generic log level instead of backend?
For parallel workers launched for parallel queries, should they followthe backend's log level or the background worker's? Since they operateas part of a parallel query executed by a backend, it seems more logicalfor them to follow the backend's setting.
Since we are using enum BackendType and there is no special entry for parallel
query processes. I'm afraid that introducing conditional logic for checking
special cases like the bgw_type for parallel queries or MyProcPid ==
PostmasterPid might slowdown that code path. (See that should_output_to_server
is an inline function.) I will run some tests to see if there is a considerable
impact.
+ [B_CHECKPOINTER] = "checkpointer",+ [B_STARTUP] = "backend", /* XXX same as backend? */I like the idea of allowing log levels to be set per process.There were times I wanted to use debug5 specifically forthe startup process when troubleshooting WAL replay. It would behelpful to distinguish the startup process from a regular backend,so we can set its log level independently.
Although startup process is mapped to backend (hence, the XXX), we can
certainly create a separate backend type for it.
On Wed, Mar 5, 2025, at 1:40 PM, Andrew Dunstan wrote:
Just bikeshedding a bit ...
I'm not mad keen on this design. I think the value should be either a single setting like "WARNING" or a set of type:setting pairs. I agree that "all" is a bad name, but I think "default" would make sense.
One of my main concerns was a clear interface. I think "default" is less
confusing than "all". Your suggestion about single or list is aligned with what
Alvaro suggested. IIUC you are suggesting default:loglevel only if it is part
of the list; the single loglevel shouldn't contain the backend type to keep the
backward compatibility. The advantage of your proposal is that it make it clear
what the fallback log level is. However, someone could be confused asking if
the "default" is a valid backend type and if there is a difference between
WARNING and default:WARNING (both is a fallback for non-specified backend type
elements).