On 4/7/25 6:41 PM, Melanie Plageman wrote:
On Mon, Feb 3, 2025 at 12:37 AM Sami Imseih <samims...@gmail.com> wrote: I started looking at this, and I like the idea.
Thanks for taking a look!
A few comments: I don't understand what 0002 is. For starters, the commit message says something about pg_stat_database, and there are no changes related to that.
I had originally split this part out while working on the patch to add parallel worker stats in pg_stat_database [1], in order to isolate the common components. In the end, that patch only accounted for user queries.
I merged it into "Implements logging for parallel worker usage in utilities" for v9.
Also, we already have basically identical logging coming from parallel_vacuum_process_all_indexes() and viewable in existing output. Not only does your implementation not replace this, it is odd that setting your new guc to none does not disable this. It seems a bit inconsistent. I'm not sure what the exact right behavior is here, though.
That logging is used for the VERBOSE mode of VACUUM. There was also dicussion to add similar info for parallel index creation.
The use case here is different — the goal is to audit parallel worker usage across the entire instance, without needing every call site to use VACUUM (VERBOSE) along with SET log_min_messages = info.
I avoided reusing that part of the code because I thought the expectation was to aggregate worker counts and display them in parallel_vacuum_end(). Sami also mentionned that using the same log line everywhere in the patch would make parsing easier, which I tought was a good idea.
Since your last update, it seems parallel gin index build has been committed, so perhaps you want to add that.
Thanks for the heads-up! I've added logging in _gin_end_parallel(). You’ll find the updated patch attached. [1] https://commitfest.postgresql.org/patch/5212/ -- Benoit
From 59cd090e78a5833b901ad662d6ae1ae936c3172d Mon Sep 17 00:00:00 2001 From: benoit <benoit.lobr...@dalibo.com> Date: Tue, 8 Oct 2024 12:39:41 +0200 Subject: [PATCH 1/3] Add a guc for parallel worker logging The new guc log_parallel_workers controls whether a log message is produced to display information on the number of workers spawned when a parallel query or utility is executed. The default value is `none` which disables logging. `all` displays information for all parallel queries, whereas `shortage` displays information only when the number of workers launched is lower than the number of planned workers. This new parameter can help database administrators and developers diagnose performance issues related to parallelism and optimize the configuration of the system accordingly. --- doc/src/sgml/config.sgml | 18 ++++++++++++++++++ src/backend/access/transam/parallel.c | 19 +++++++++++++++++++ src/backend/utils/misc/guc_tables.c | 19 +++++++++++++++++++ src/backend/utils/misc/postgresql.conf.sample | 1 + src/include/access/parallel.h | 10 ++++++++++ src/include/utils/guc.h | 1 + 6 files changed, 68 insertions(+) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index c1674c22cb2..b1345d15a84 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -7950,6 +7950,24 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' </listitem> </varlistentry> + <varlistentry id="guc-log-parallel-workers" xreflabel="log_parallel_workers"> + <term><varname>log_parallel_workers</varname> (<type>enum</type>) + <indexterm> + <primary><varname>log_parallel_workers</varname> configuration parameter</primary> + </indexterm> + </term> + <listitem> + <para> + Controls whether a log message about the number of workers is emitted during the + execution of a parallel query or utility statement. The default value is + <literal>none</literal> which disables logging. <literal>all</literal> emits + information for all parallel queries or utilities, whereas <literal>shortage</literal> + emits information only when the number of workers launched is lower than the number + of planned workers. + </para> + </listitem> + </varlistentry> + <varlistentry id="guc-log-parameter-max-length" xreflabel="log_parameter_max_length"> <term><varname>log_parameter_max_length</varname> (<type>integer</type>) <indexterm> diff --git a/src/backend/access/transam/parallel.c b/src/backend/access/transam/parallel.c index 94db1ec3012..77a8deff30d 100644 --- a/src/backend/access/transam/parallel.c +++ b/src/backend/access/transam/parallel.c @@ -1663,3 +1663,22 @@ LookupParallelWorkerFunction(const char *libraryname, const char *funcname) return (parallel_worker_main_type) load_external_function(libraryname, funcname, true, NULL); } + +/* + * If required, emit information about parallel workers usage in + * the logs. + */ +void +LogParallelWorkersIfNeeded(int log_parallel_workers, + int parallel_workers_to_launch, + int parallel_workers_launched) +{ + if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL && + parallel_workers_to_launch > 0) || + (log_parallel_workers == LOG_PARALLEL_WORKERS_SHORTAGE && + parallel_workers_to_launch != parallel_workers_launched)) + ereport(LOG, + (errmsg("launched %i parallel workers (planned: %i)", + parallel_workers_launched, + parallel_workers_to_launch))); +} diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index 60b12446a1c..0e7b3960ad5 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -31,6 +31,7 @@ #include "access/commit_ts.h" #include "access/gin.h" +#include "access/parallel.h" #include "access/slru.h" #include "access/toast_compression.h" #include "access/twophase.h" @@ -432,6 +433,13 @@ static const struct config_enum_entry debug_logical_replication_streaming_option {NULL, 0, false} }; +static const struct config_enum_entry log_parallel_workers_options[] = { + {"none", LOG_PARALLEL_WORKERS_NONE, false}, + {"all", LOG_PARALLEL_WORKERS_ALL, false}, + {"shortage", LOG_PARALLEL_WORKERS_SHORTAGE, false}, + {NULL, 0, false} +}; + StaticAssertDecl(lengthof(ssl_protocol_versions_info) == (PG_TLS1_3_VERSION + 2), "array length mismatch"); @@ -543,6 +551,7 @@ int log_min_duration_statement = -1; int log_parameter_max_length = -1; int log_parameter_max_length_on_error = 0; int log_temp_files = -1; +int log_parallel_workers = LOG_PARALLEL_WORKERS_NONE; double log_statement_sample_rate = 1.0; double log_xact_sample_rate = 0; char *backtrace_functions; @@ -5362,6 +5371,16 @@ struct config_enum ConfigureNamesEnum[] = NULL, NULL, NULL }, + { + {"log_parallel_workers", PGC_SUSET, LOGGING_WHAT, + gettext_noop("Log information about parallel worker usage"), + NULL + }, + &log_parallel_workers, + LOG_PARALLEL_WORKERS_NONE, log_parallel_workers_options, + NULL, NULL, NULL + }, + { {"ssl_min_protocol_version", PGC_SIGHUP, CONN_AUTH_SSL, gettext_noop("Sets the minimum SSL/TLS protocol version to use."), diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 34826d01380..1ccae086b88 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -642,6 +642,7 @@ #log_temp_files = -1 # log temporary files equal or larger # than the specified size in kilobytes; # -1 disables, 0 logs all temp files +#log_parallel_workers = none # none, all, shortage #log_timezone = 'GMT' # - Process Title - diff --git a/src/include/access/parallel.h b/src/include/access/parallel.h index f37be6d5690..f865cd755e3 100644 --- a/src/include/access/parallel.h +++ b/src/include/access/parallel.h @@ -53,6 +53,12 @@ typedef struct ParallelWorkerContext shm_toc *toc; } ParallelWorkerContext; +typedef enum { + LOG_PARALLEL_WORKERS_NONE=0, + LOG_PARALLEL_WORKERS_ALL, + LOG_PARALLEL_WORKERS_SHORTAGE, +} log_parallel_workers_option_list; + extern PGDLLIMPORT volatile sig_atomic_t ParallelMessagePending; extern PGDLLIMPORT int ParallelWorkerNumber; extern PGDLLIMPORT bool InitializingParallelWorker; @@ -78,4 +84,8 @@ extern void ParallelWorkerReportLastRecEnd(XLogRecPtr last_xlog_end); extern void ParallelWorkerMain(Datum main_arg); +extern void LogParallelWorkersIfNeeded(int log_parallel_workers, + int parallel_workers_to_launch, + int parallel_workers_launched); + #endif /* PARALLEL_H */ diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index f619100467d..7986dc3e541 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -279,6 +279,7 @@ extern PGDLLIMPORT int log_temp_files; extern PGDLLIMPORT double log_statement_sample_rate; extern PGDLLIMPORT double log_xact_sample_rate; extern PGDLLIMPORT char *backtrace_functions; +extern PGDLLIMPORT int log_parallel_workers; extern PGDLLIMPORT int temp_file_limit; -- 2.48.1
From 7184271007622c7fe2f1e3c09506a38e4e874187 Mon Sep 17 00:00:00 2001 From: benoit <benoit.lobr...@dalibo.com> Date: Wed, 29 Jan 2025 17:10:57 +0100 Subject: [PATCH 2/3] Implements logging for parallel worker usage in utilities This patch implements logging of parallel worker usage for: * the index cleanup and bulkdelete phases of vacuum; * btree, brin and gin index builds. --- src/backend/access/brin/brin.c | 4 ++++ src/backend/access/gin/gininsert.c | 4 ++++ src/backend/access/nbtree/nbtsort.c | 4 ++++ src/backend/commands/vacuumparallel.c | 13 +++++++++++++ 4 files changed, 25 insertions(+) diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c index 01e1db7f856..b69caeed0ad 100644 --- a/src/backend/access/brin/brin.c +++ b/src/backend/access/brin/brin.c @@ -2552,6 +2552,10 @@ _brin_end_parallel(BrinLeader *brinleader, BrinBuildState *state) /* Shutdown worker processes */ WaitForParallelWorkersToFinish(brinleader->pcxt); + LogParallelWorkersIfNeeded(log_parallel_workers, + brinleader->pcxt->nworkers_to_launch, + brinleader->pcxt->nworkers_launched); + /* * Next, accumulate WAL usage. (This must wait for the workers to finish, * or we might get incomplete data.) diff --git a/src/backend/access/gin/gininsert.c b/src/backend/access/gin/gininsert.c index cfab93ec30c..c2a7ab0b177 100644 --- a/src/backend/access/gin/gininsert.c +++ b/src/backend/access/gin/gininsert.c @@ -1079,6 +1079,10 @@ _gin_end_parallel(GinLeader *ginleader, GinBuildState *state) /* Shutdown worker processes */ WaitForParallelWorkersToFinish(ginleader->pcxt); + LogParallelWorkersIfNeeded(log_parallel_workers, + ginleader->pcxt->nworkers_to_launch, + ginleader->pcxt->nworkers_launched); + /* * Next, accumulate WAL usage. (This must wait for the workers to finish, * or we might get incomplete data.) diff --git a/src/backend/access/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c index 3794cc924ad..e48deed9035 100644 --- a/src/backend/access/nbtree/nbtsort.c +++ b/src/backend/access/nbtree/nbtsort.c @@ -1613,6 +1613,10 @@ _bt_end_parallel(BTLeader *btleader) /* Shutdown worker processes */ WaitForParallelWorkersToFinish(btleader->pcxt); + LogParallelWorkersIfNeeded(log_parallel_workers, + btleader->pcxt->nworkers_to_launch, + btleader->pcxt->nworkers_launched); + /* * Next, accumulate WAL usage. (This must wait for the workers to finish, * or we might get incomplete data.) diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c index 2b9d548cdeb..01dee17741a 100644 --- a/src/backend/commands/vacuumparallel.c +++ b/src/backend/commands/vacuumparallel.c @@ -208,6 +208,9 @@ struct ParallelVacuumState int nindexes_parallel_cleanup; int nindexes_parallel_condcleanup; + int nworkers_to_launch; + int nworkers_launched; + /* Buffer access strategy used by leader process */ BufferAccessStrategy bstrategy; @@ -362,6 +365,9 @@ parallel_vacuum_init(Relation rel, Relation *indrels, int nindexes, if ((vacoptions & VACUUM_OPTION_PARALLEL_COND_CLEANUP) != 0) pvs->nindexes_parallel_condcleanup++; } + pvs->nworkers_to_launch = 0; + pvs->nworkers_launched = 0; + shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_INDEX_STATS, indstats); pvs->indstats = indstats; @@ -437,6 +443,10 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats) { Assert(!IsParallelWorker()); + LogParallelWorkersIfNeeded(log_parallel_workers, + pvs->nworkers_to_launch, + pvs->nworkers_launched); + /* Copy the updated statistics */ for (int i = 0; i < pvs->nindexes; i++) { @@ -738,6 +748,9 @@ parallel_vacuum_process_all_indexes(ParallelVacuumState *pvs, int num_index_scan for (int i = 0; i < pvs->pcxt->nworkers_launched; i++) InstrAccumParallelQuery(&pvs->buffer_usage[i], &pvs->wal_usage[i]); + + pvs->nworkers_to_launch += pvs->pcxt->nworkers_to_launch; + pvs->nworkers_launched += pvs->pcxt->nworkers_launched; } /* -- 2.48.1
From 5938cbfcc7b46c9c5e9c87c64ab81d9af58c7d41 Mon Sep 17 00:00:00 2001 From: benoit <benoit.lobr...@dalibo.com> Date: Wed, 29 Jan 2025 17:15:25 +0100 Subject: [PATCH 3/3] Implements logging for parallel worker usage in queries --- src/backend/executor/execMain.c | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c index 2da848970be..604b002638c 100644 --- a/src/backend/executor/execMain.c +++ b/src/backend/executor/execMain.c @@ -1,5 +1,4 @@ -/*------------------------------------------------------------------------- - * +/*------------------------------------------------------------------------ * execMain.c * top level executor interface routines * @@ -560,6 +559,10 @@ standard_ExecutorEnd(QueryDesc *queryDesc) pgstat_update_parallel_workers_stats((PgStat_Counter) estate->es_parallel_workers_to_launch, (PgStat_Counter) estate->es_parallel_workers_launched); + LogParallelWorkersIfNeeded(log_parallel_workers, + estate->es_parallel_workers_to_launch, + estate->es_parallel_workers_launched); + /* * Check that ExecutorFinish was called, unless in EXPLAIN-only mode or if * execution was aborted. -- 2.48.1