Here is a new version that fixes the aforementioned problems.
If this patch is accepted in this form, the counters could be used for
the patch in pg_stat_database. [1]
[1]
https://www.postgresql.org/message-id/flat/783bc7f7-659a-42fa-99dd-ee0565644...@dalibo.com
--
Benoit Lobréau
Consultant
http://dalibo.com
From d82cea62d4ab53d3d77054286cddb1536172c8c0 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobr...@dalibo.com>
Date: Mon, 26 Aug 2024 13:48:44 +0200
Subject: [PATCH] Add logging for parallel worker usage
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 `failures` 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/brin/brin.c | 8 ++++++++
src/backend/access/nbtree/nbtsort.c | 8 ++++++++
src/backend/commands/vacuumparallel.c | 17 +++++++++++++++++
src/backend/executor/execMain.c | 12 ++++++++++++
src/backend/executor/execUtils.c | 6 ++++++
src/backend/executor/nodeGather.c | 8 ++++++++
src/backend/executor/nodeGatherMerge.c | 8 ++++++++
src/backend/utils/misc/guc_tables.c | 12 ++++++++++++
src/backend/utils/misc/postgresql.conf.sample | 1 +
src/include/access/parallel.h | 15 +++++++++++++++
src/include/nodes/execnodes.h | 6 ++++++
12 files changed, 119 insertions(+)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 0aec11f443..b687bf3507 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7696,6 +7696,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 is produced to display information on
the number of
+ workers spawned when a parallel query or utility is executed. The
default value is
+ <literal>none</literal> which disables logging. <literal>all</literal>
displays
+ information for all parallel queries, whereas
<literal>failures</literal> displays
+ 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/brin/brin.c b/src/backend/access/brin/brin.c
index 60853a0f6a..2a516911e7 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2540,6 +2540,14 @@ _brin_end_parallel(BrinLeader *brinleader,
BrinBuildState *state)
/* Shutdown worker processes */
WaitForParallelWorkersToFinish(brinleader->pcxt);
+ if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+ brinleader->pcxt->nworkers_to_launch > 0) ||
+ (log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+ brinleader->pcxt->nworkers_to_launch >
brinleader->pcxt->nworkers_launched))
+ elog(LOG, "%i workers planned (%i workers launched)",
+ 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/nbtree/nbtsort.c
b/src/backend/access/nbtree/nbtsort.c
index f5d7b3b0c3..eaa3e1bac1 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1611,6 +1611,14 @@ _bt_end_parallel(BTLeader *btleader)
/* Shutdown worker processes */
WaitForParallelWorkersToFinish(btleader->pcxt);
+ if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+ btleader->pcxt->nworkers_to_launch > 0) ||
+ (log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+ btleader->pcxt->nworkers_to_launch >
btleader->pcxt->nworkers_launched))
+ elog(LOG, "%i workers planned (%i workers launched)",
+ 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 22c057fe61..6347a6b519 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -207,6 +207,9 @@ struct ParallelVacuumState
int nindexes_parallel_cleanup;
int nindexes_parallel_condcleanup;
+ int nworkers_planned;
+ int nworkers_launched;
+
/* Buffer access strategy used by leader process */
BufferAccessStrategy bstrategy;
@@ -361,6 +364,9 @@ parallel_vacuum_init(Relation rel, Relation *indrels, int
nindexes,
if ((vacoptions & VACUUM_OPTION_PARALLEL_COND_CLEANUP) != 0)
pvs->nindexes_parallel_condcleanup++;
}
+ pvs->nworkers_planned = 0;
+ pvs->nworkers_launched = 0;
+
shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_INDEX_STATS, indstats);
pvs->indstats = indstats;
@@ -435,6 +441,14 @@ parallel_vacuum_end(ParallelVacuumState *pvs,
IndexBulkDeleteResult **istats)
{
Assert(!IsParallelWorker());
+ if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+ pvs->nworkers_planned > 0) ||
+ (log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+ pvs->nworkers_planned > pvs->nworkers_launched))
+ elog(LOG, "%i workers planned for index cleanup and bulkdelete
(%i workers launched)",
+ pvs->nworkers_planned,
+ pvs->nworkers_launched);
+
/* Copy the updated statistics */
for (int i = 0; i < pvs->nindexes; i++)
{
@@ -737,6 +751,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_planned += pvs->pcxt->nworkers_to_launch;
+ pvs->nworkers_launched += pvs->pcxt->nworkers_launched;
}
/*
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 713cf3e802..fd18642692 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -492,6 +492,18 @@ standard_ExecutorEnd(QueryDesc *queryDesc)
Assert(estate != NULL);
+ if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+ estate->es_workers_planned > 0) ||
+ (log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+ estate->es_workers_planned != estate->es_workers_launched))
+ elog(LOG, "%i parallel nodes planned (%i obtained all their
workers, %i obtained none), "
+ "%i workers planned (%i workers launched)",
+ estate->es_parallelized_nodes,
+ estate->es_parallelized_nodes_success,
+ estate->es_parallelized_nodes_no_workers,
+ estate->es_workers_planned,
+ estate->es_workers_launched);
+
/*
* Check that ExecutorFinish was called, unless in EXPLAIN-only mode.
This
* Assert is needed because ExecutorFinish is new as of 9.1, and callers
diff --git a/src/backend/executor/execUtils.c b/src/backend/executor/execUtils.c
index 5737f9f4eb..9d1cef6d28 100644
--- a/src/backend/executor/execUtils.c
+++ b/src/backend/executor/execUtils.c
@@ -162,6 +162,12 @@ CreateExecutorState(void)
estate->es_jit_flags = 0;
estate->es_jit = NULL;
+ estate->es_parallelized_nodes = 0;
+ estate->es_parallelized_nodes_success = 0;
+ estate->es_parallelized_nodes_no_workers = 0;
+ estate->es_workers_launched = 0;
+ estate->es_workers_planned = 0;
+
/*
* Return the executor state structure
*/
diff --git a/src/backend/executor/nodeGather.c
b/src/backend/executor/nodeGather.c
index 5d4ffe989c..8a8994c19a 100644
--- a/src/backend/executor/nodeGather.c
+++ b/src/backend/executor/nodeGather.c
@@ -181,6 +181,13 @@ ExecGather(PlanState *pstate)
LaunchParallelWorkers(pcxt);
/* We save # workers launched for the benefit of
EXPLAIN */
node->nworkers_launched = pcxt->nworkers_launched;
+ /* We save the total # of workers launched for logging
purposes */
+ estate->es_workers_launched += pcxt->nworkers_launched;
+ estate->es_workers_planned += pcxt->nworkers_to_launch;
+ estate->es_parallelized_nodes += 1;
+
+ if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+ estate->es_parallelized_nodes_success += 1;
/* Set up tuple queue readers to read the results. */
if (pcxt->nworkers_launched > 0)
@@ -198,6 +205,7 @@ ExecGather(PlanState *pstate)
/* No workers? Then never mind. */
node->nreaders = 0;
node->reader = NULL;
+ estate->es_parallelized_nodes_no_workers += 1;
}
node->nextreader = 0;
}
diff --git a/src/backend/executor/nodeGatherMerge.c
b/src/backend/executor/nodeGatherMerge.c
index 45f6017c29..83611bd503 100644
--- a/src/backend/executor/nodeGatherMerge.c
+++ b/src/backend/executor/nodeGatherMerge.c
@@ -222,6 +222,13 @@ ExecGatherMerge(PlanState *pstate)
LaunchParallelWorkers(pcxt);
/* We save # workers launched for the benefit of
EXPLAIN */
node->nworkers_launched = pcxt->nworkers_launched;
+ /* We save the total # of workers launched for logging
purposes */
+ estate->es_workers_launched += pcxt->nworkers_launched;
+ estate->es_workers_planned += pcxt->nworkers_to_launch;
+ estate->es_parallelized_nodes += 1;
+
+ if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+ estate->es_parallelized_nodes_success += 1;
/* Set up tuple queue readers to read the results. */
if (pcxt->nworkers_launched > 0)
@@ -239,6 +246,7 @@ ExecGatherMerge(PlanState *pstate)
/* No workers? Then never mind. */
node->nreaders = 0;
node->reader = NULL;
+ estate->es_parallelized_nodes_no_workers += 1;
}
}
diff --git a/src/backend/utils/misc/guc_tables.c
b/src/backend/utils/misc/guc_tables.c
index 686309db58..1f9e2b1a33 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -482,6 +482,7 @@ extern const struct config_enum_entry
archive_mode_options[];
extern const struct config_enum_entry recovery_target_action_options[];
extern const struct config_enum_entry wal_sync_method_options[];
extern const struct config_enum_entry dynamic_shared_memory_options[];
+extern const struct config_enum_entry log_parallel_workers_options[];
/*
* GUC option variables that are exported from this module
@@ -526,6 +527,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;
@@ -5196,6 +5198,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
+ },
+
/* End-of-list marker */
{
{NULL, 0, 0, NULL, NULL}, NULL, 0, NULL, NULL, NULL, NULL
diff --git a/src/backend/utils/misc/postgresql.conf.sample
b/src/backend/utils/misc/postgresql.conf.sample
index 667e0dc40a..7cd9c0f3f8 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -619,6 +619,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, failure
#log_timezone = 'GMT'
# - Process Title -
diff --git a/src/include/access/parallel.h b/src/include/access/parallel.h
index 69ffe5498f..ed33e545d7 100644
--- a/src/include/access/parallel.h
+++ b/src/include/access/parallel.h
@@ -19,6 +19,20 @@
#include "postmaster/bgworker.h"
#include "storage/shm_mq.h"
#include "storage/shm_toc.h"
+#include "utils/guc.h"
+
+typedef enum log_parallel_workers_option_list {
+ LOG_PARALLEL_WORKERS_NONE=0,
+ LOG_PARALLEL_WORKERS_ALL,
+ LOG_PARALLEL_WORKERS_FAILURE,
+} log_parallel_workers_option_list;
+
+static const struct config_enum_entry log_parallel_workers_options[] = {
+ {"none", LOG_PARALLEL_WORKERS_NONE, false},
+ {"all", LOG_PARALLEL_WORKERS_ALL, false},
+ {"failure", LOG_PARALLEL_WORKERS_FAILURE, false},
+ {NULL, 0, false}
+};
typedef void (*parallel_worker_main_type) (dsm_segment *seg, shm_toc *toc);
@@ -56,6 +70,7 @@ typedef struct ParallelWorkerContext
extern PGDLLIMPORT volatile sig_atomic_t ParallelMessagePending;
extern PGDLLIMPORT int ParallelWorkerNumber;
extern PGDLLIMPORT bool InitializingParallelWorker;
+extern PGDLLEXPORT int log_parallel_workers;
#define IsParallelWorker() (ParallelWorkerNumber
>= 0)
diff --git a/src/include/nodes/execnodes.h b/src/include/nodes/execnodes.h
index 88467977f8..b02d3c8f0c 100644
--- a/src/include/nodes/execnodes.h
+++ b/src/include/nodes/execnodes.h
@@ -727,6 +727,12 @@ typedef struct EState
*/
List *es_insert_pending_result_relations;
List *es_insert_pending_modifytables;
+
+ int es_parallelized_nodes;
+ int es_parallelized_nodes_success;
+ int es_parallelized_nodes_no_workers;
+ int es_workers_launched;
+ int es_workers_planned;
} EState;
--
2.45.2
