Logging parallel worker draught

Started by Benoit Lobréauover 2 years ago43 messages
#1Benoit Lobréau
benoit.lobreau@dalibo.com
1 attachment(s)

Hi hackers,

Following my previous mail about adding stats on parallelism[1]/messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com, this
patch introduces the log_parallel_worker_draught parameter, which
controls whether a log message is produced when a backend attempts to
spawn a parallel worker but fails due to insufficient worker slots. The
shortage can stem from insufficent settings for max_worker_processes,
max_parallel_worker or max_parallel_maintenance_workers. It could also
be caused by another pool (max_logical_replication_workers) or an
extention using bg worker slots. This new parameter can help database
administrators and developers diagnose performance issues related to
parallelism and optimize the configuration of the system accordingly.

Here is a test script:

```
psql << _EOF_

SET log_parallel_worker_draught TO on;

-- Index creation
DROP TABLE IF EXISTS test_pql;
CREATE TABLE test_pql(i int, j int);
INSERT INTO test_pql SELECT x,x FROM generate_series(1,1000000) as F(x);

SET max_parallel_workers TO 0;

CREATE INDEX ON test_pql(i);
REINDEX TABLE test_pql;

RESET max_parallel_workers;

-- VACUUM
CREATE INDEX ON test_pql(j);
CREATE INDEX ON test_pql(i,j);
ALTER TABLE test_pql SET (autovacuum_enabled = off);
DELETE FROM test_pql WHERE i BETWEEN 1000 AND 2000;

SET max_parallel_workers TO 1;

VACUUM (PARALLEL 2, VERBOSE) test_pql;

RESET max_parallel_workers;

-- SELECT
SET min_parallel_table_scan_size TO 0;
SET parallel_setup_cost TO 0;
SET max_parallel_workers TO 1;

EXPLAIN (ANALYZE) SELECT i, avg(j) FROM test_pql GROUP BY i;

_EOF_
```

Which produces the following logs:

```
LOG: Parallel Worker draught during statement execution: workers
spawned 0, requested 1
STATEMENT: CREATE INDEX ON test_pql(i);

LOG: Parallel Worker draught during statement execution: workers
spawned 0, requested 1
STATEMENT: REINDEX TABLE test_pql;

LOG: Parallel Worker draught during statement execution: workers
spawned 1, requested 2
CONTEXT: while scanning relation "public.test_pql"
STATEMENT: VACUUM (PARALLEL 2, VERBOSE) test_pql;

LOG: Parallel Worker draught during statement execution: workers
spawned 1, requested 2
STATEMENT: EXPLAIN (ANALYZE) SELECT i, avg(j) FROM test_pql GROUP BY i;
```

[1]: /messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com
/messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

0001-Add-logging-for-exceeded-parallel-worker-slot-limits.patch_v1text/plain; charset=UTF-8; name=0001-Add-logging-for-exceeded-parallel-worker-slot-limits.patch_v1Download
From f7d3dae918df2dbbe7fd18cf48f7ca39d5716c73 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 3 Mar 2023 10:47:50 +0100
Subject: [PATCH] Add logging for exceeded parallel worker slot limits

Introduce the log_parallel_worker_draught parameter, which controls
whether a log message is produced when a backend attempts to spawn a
parallel worker but fails due to insufficient worker slots. The shortage
can stem from max_worker_processes, max_parallel_worker, or
max_parallel_maintenance_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                      | 16 ++++++++++++++++
 src/backend/access/transam/parallel.c         |  6 ++++++
 src/backend/utils/misc/guc_tables.c           | 10 ++++++++++
 src/backend/utils/misc/postgresql.conf.sample |  2 ++
 src/include/access/parallel.h                 |  1 +
 5 files changed, 35 insertions(+)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index bcc49aec45..0fe0c7796e 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7499,6 +7499,22 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
       </listitem>
      </varlistentry>
 
+     <varlistentry id="guc-log-parallel-worker-draught" xreflabel="log_parallel_worker_draught">
+      <term><varname>log_parallel_worker_draught</varname> (<type>boolean</type>)
+      <indexterm>
+       <primary><varname>log_parallel_worker_draught</varname> configuration parameter</primary>
+      </indexterm>
+      </term>
+      <listitem>
+       <para>
+        Controls whether a log message is produced when a backend tries to
+        spawn a parallel worker but is not successful because either
+        <varname>max_worker_processes</varname>, <varname>max_parallel_worker</varname>
+        or <varname>max_parallel_maintenance_workers</varname> is reached.
+       </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 b26f2a64fb..d86ba5a838 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -630,6 +630,12 @@ LaunchParallelWorkers(ParallelContext *pcxt)
 		pcxt->nknown_attached_workers = 0;
 	}
 
+	if (log_parallel_worker_draught &&
+		pcxt->nworkers_launched < pcxt->nworkers_to_launch)
+			ereport(LOG,
+				(errmsg("Parallel Worker draught during statement execution: workers spawned %d, requested %d",
+					pcxt->nworkers_launched, pcxt->nworkers_to_launch)));
+
 	/* Restore previous memory context. */
 	MemoryContextSwitchTo(oldcontext);
 }
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 8062589efd..dcc1926236 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -512,6 +512,7 @@ int			log_min_messages = WARNING;
 int			client_min_messages = NOTICE;
 int			log_min_duration_sample = -1;
 int			log_min_duration_statement = -1;
+bool		log_parallel_worker_draught = false;
 int			log_parameter_max_length = -1;
 int			log_parameter_max_length_on_error = 0;
 int			log_temp_files = -1;
@@ -1991,6 +1992,15 @@ struct config_bool ConfigureNamesBool[] =
 		NULL, NULL, NULL
 	},
 
+	{
+		{"log_parallel_worker_draught", PGC_SUSET, LOGGING_WHAT,
+			gettext_noop("Log when a backend couldn't get the parallel workers it requested."),
+		},
+		&log_parallel_worker_draught,
+		false,
+		NULL, NULL, NULL
+	},
+
 	/* End-of-list marker */
 	{
 		{NULL, 0, 0, NULL, NULL}, NULL, false, NULL, NULL, NULL
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index ee49ca3937..1a47012e8e 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -597,6 +597,8 @@
 #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_worker_draught = off	# Log when a backend couldn't get the
+					# parallel workers it requested.
 #log_timezone = 'GMT'
 
 # - Process Title -
diff --git a/src/include/access/parallel.h b/src/include/access/parallel.h
index 061f8a4c4c..df889b36b8 100644
--- a/src/include/access/parallel.h
+++ b/src/include/access/parallel.h
@@ -57,6 +57,7 @@ typedef struct ParallelWorkerContext
 extern PGDLLIMPORT volatile sig_atomic_t ParallelMessagePending;
 extern PGDLLIMPORT int ParallelWorkerNumber;
 extern PGDLLIMPORT bool InitializingParallelWorker;
+extern PGDLLIMPORT bool log_parallel_worker_draught;
 
 #define		IsParallelWorker()		(ParallelWorkerNumber >= 0)
 
-- 
2.39.2

#2Amit Kapila
amit.kapila16@gmail.com
In reply to: Benoit Lobréau (#1)
Re: Logging parallel worker draught

On Fri, Apr 21, 2023 at 6:34 PM Benoit Lobréau
<benoit.lobreau@dalibo.com> wrote:

Following my previous mail about adding stats on parallelism[1], this
patch introduces the log_parallel_worker_draught parameter, which
controls whether a log message is produced when a backend attempts to
spawn a parallel worker but fails due to insufficient worker slots.

I don't think introducing a GUC for this is a good idea. We can
directly output this message in the server log either at LOG or DEBUG1
level.

--
With Regards,
Amit Kapila.

#3Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Amit Kapila (#2)
Re: Logging parallel worker draught

On 4/22/23 13:06, Amit Kapila wrote:

I don't think introducing a GUC for this is a good idea. We can
directly output this message in the server log either at LOG or DEBUG1
level.

Hi,

Sorry for the delayed answer, I was away from my computer for a few
days. I don't mind removing the guc, but I would like to keep it at the
LOG level. When I do audits most client are at that level and setting it
to DEBUG1 whould add too much log for them on the long run.

I'll post the corresponding patch asap.

--
Benoit Lobréau
Consultant
http://dalibo.com

#4Robert Haas
robertmhaas@gmail.com
In reply to: Amit Kapila (#2)
Re: Logging parallel worker draught

On Sat, Apr 22, 2023 at 7:06 AM Amit Kapila <amit.kapila16@gmail.com> wrote:

I don't think introducing a GUC for this is a good idea. We can
directly output this message in the server log either at LOG or DEBUG1
level.

Why not? It seems like something some people might want to log and
others not. Running the whole server at DEBUG1 to get this information
doesn't seem like a suitable answer.

What I was wondering was whether we would be better off putting this
into the statistics collector, vs. doing it via logging. Both
approaches seem to have pros and cons.

--
Robert Haas
EDB: http://www.enterprisedb.com

#5Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Robert Haas (#4)
1 attachment(s)
Re: Logging parallel worker draught

On 5/1/23 18:33, Robert Haas wrote:

Why not? It seems like something some people might want to log and
others not. Running the whole server at DEBUG1 to get this information
doesn't seem like a suitable answer.

Since the statement is also logged, it could spam the log with huge
queries, which might also be a reason to stop logging this kind of
problems until the issue is fixed.

I attached the patch without the guc anyway just in case.

What I was wondering was whether we would be better off putting this
into the statistics collector, vs. doing it via logging. Both
approaches seem to have pros and cons.

We tried to explore different options with my collegues in another
thread [1]/messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com. I feel like both solutions are worthwhile, and would be
helpful. I plan to take a look at the pg_stat_statement patch [2]/messages/by-id/6acbe570-068e-bd8e-95d5-00c737b865e8@gmail.com next.

Since it's my first patch, I elected to choose the easiest solution to
implement first. I also proposed this because I think logging can help
pinpoint a lot of problems at a minimal cost, since it is easy to setup
and exploit for everyone, everywhere

[1]: /messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com
/messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com

[2]: /messages/by-id/6acbe570-068e-bd8e-95d5-00c737b865e8@gmail.com
/messages/by-id/6acbe570-068e-bd8e-95d5-00c737b865e8@gmail.com

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

0001-Add-logging-for-exceeded-parallel-worker-slot-limits.patch_v2_no_guctext/plain; charset=UTF-8; name=0001-Add-logging-for-exceeded-parallel-worker-slot-limits.patch_v2_no_gucDownload
From fc71ef40f33f94b0506a092fb5b3dcde6de6d60a Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 2 May 2023 10:08:00 +0200
Subject: [PATCH] Add logging for exceeded parallel worker slot limits

Procude a log message when a backend attempts to spawn a parallel worker
but fails due to insufficient worker slots. The shortage can stem from
max_worker_processes, max_parallel_worker, or
max_parallel_maintenance_workers. The log message can help database
administrators and developers diagnose performance issues related to
parallelism and optimize the configuration of the system accordingly.
---
 src/backend/access/transam/parallel.c | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/src/backend/access/transam/parallel.c b/src/backend/access/transam/parallel.c
index b26f2a64fb..c60d1bd739 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -630,6 +630,11 @@ LaunchParallelWorkers(ParallelContext *pcxt)
 		pcxt->nknown_attached_workers = 0;
 	}
 
+	if (pcxt->nworkers_launched < pcxt->nworkers_to_launch)
+			ereport(LOG,
+				(errmsg("Parallel Worker draught during statement execution: workers spawned %d, requested %d",
+					pcxt->nworkers_launched, pcxt->nworkers_to_launch)));
+
 	/* Restore previous memory context. */
 	MemoryContextSwitchTo(oldcontext);
 }
-- 
2.39.2

#6Amit Kapila
amit.kapila16@gmail.com
In reply to: Robert Haas (#4)
Re: Logging parallel worker draught

On Mon, May 1, 2023 at 10:03 PM Robert Haas <robertmhaas@gmail.com> wrote:

On Sat, Apr 22, 2023 at 7:06 AM Amit Kapila <amit.kapila16@gmail.com> wrote:

I don't think introducing a GUC for this is a good idea. We can
directly output this message in the server log either at LOG or DEBUG1
level.

Why not? It seems like something some people might want to log and
others not. Running the whole server at DEBUG1 to get this information
doesn't seem like a suitable answer.

We can output this at the LOG level to avoid running the server at
DEBUG1 level. There are a few other cases where we are not able to
spawn the worker or process and those are logged at the LOG level. For
example, "could not fork autovacuum launcher process .." or "too many
background workers". So, not sure, if this should get a separate
treatment. If we fear this can happen frequently enough that it can
spam the LOG then a GUC may be worthwhile.

What I was wondering was whether we would be better off putting this
into the statistics collector, vs. doing it via logging. Both
approaches seem to have pros and cons.

I think it could be easier for users to process the information if it
is available via some view, so there is a benefit in putting this into
the stats subsystem.

--
With Regards,
Amit Kapila.

#7Robert Haas
robertmhaas@gmail.com
In reply to: Amit Kapila (#6)
Re: Logging parallel worker draught

On Tue, May 2, 2023 at 6:57 AM Amit Kapila <amit.kapila16@gmail.com> wrote:

We can output this at the LOG level to avoid running the server at
DEBUG1 level. There are a few other cases where we are not able to
spawn the worker or process and those are logged at the LOG level. For
example, "could not fork autovacuum launcher process .." or "too many
background workers". So, not sure, if this should get a separate
treatment. If we fear this can happen frequently enough that it can
spam the LOG then a GUC may be worthwhile.

I think we should definitely be afraid of that. I am in favor of a separate GUC.

What I was wondering was whether we would be better off putting this
into the statistics collector, vs. doing it via logging. Both
approaches seem to have pros and cons.

I think it could be easier for users to process the information if it
is available via some view, so there is a benefit in putting this into
the stats subsystem.

Unless we do this instead.

--
Robert Haas
EDB: http://www.enterprisedb.com

#8Imseih (AWS), Sami
simseih@amazon.com
In reply to: Robert Haas (#7)
Re: Logging parallel worker draught

Hi,

This thread has been quiet for a while, but I'd like to share some
thoughts.

+1 to the idea of improving visibility into parallel worker saturation.
But overall, we should improve parallel processing visibility, so DBAs can
detect trends in parallel usage ( is the workload doing more parallel, or doing less )
and have enough data to either tune the workload or change parallel GUCs.

We can output this at the LOG level to avoid running the server at
DEBUG1 level. There are a few other cases where we are not able to
spawn the worker or process and those are logged at the LOG level. For
example, "could not fork autovacuum launcher process .." or "too many
background workers". So, not sure, if this should get a separate
treatment. If we fear this can happen frequently enough that it can
spam the LOG then a GUC may be worthwhile.

I think we should definitely be afraid of that. I am in favor of a separate GUC.

Currently explain ( analyze ) will give you the "Workers Planned"
and "Workers launched". Logging this via auto_explain is possible, so I am
not sure we need additional GUCs or debug levels for this info.

-> Gather (cost=10430.00..10430.01 rows=2 width=8) (actual tim
e=131.826..134.325 rows=3 loops=1)
Workers Planned: 2
Workers Launched: 2

What I was wondering was whether we would be better off putting this
into the statistics collector, vs. doing it via logging. Both
approaches seem to have pros and cons.

I think it could be easier for users to process the information if it
is available via some view, so there is a benefit in putting this into
the stats subsystem.

Unless we do this instead.

Adding cumulative stats is a much better idea.

3 new columns can be added to pg_stat_database:
workers_planned,
workers_launched,
parallel_operations - There could be more than 1 operation
per query, if for example there are multiple Parallel Gather
operations in a plan.

With these columns, monitoring tools can trend if there is more
or less parallel work happening over time ( by looking at parallel
operations ) or if the workload is suffering from parallel saturation.
workers_planned/workers_launched < 1 means there is a lack
of available worker processes.

Also, We could add this information on a per query level as well
in pg_stat_statements, but this can be taken up in a seperate
discussion.

Regards,

--
Sami Imseih
Amazon Web Services (AWS)

#9Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Imseih (AWS), Sami (#8)
Re: Logging parallel worker draught

On 2023-Oct-09, Imseih (AWS), Sami wrote:

I think we should definitely be afraid of that. I am in favor of a
separate GUC.

I agree.

Currently explain ( analyze ) will give you the "Workers Planned"
and "Workers launched". Logging this via auto_explain is possible, so I am
not sure we need additional GUCs or debug levels for this info.

-> Gather (cost=10430.00..10430.01 rows=2 width=8) (actual tim
e=131.826..134.325 rows=3 loops=1)
Workers Planned: 2
Workers Launched: 2

I don't think autoexplain is a good substitute for the originally
proposed log line. The possibility for log bloat is enormous. Some
explain plans are gigantic, and I doubt people can afford that kind of
log traffic just in case these numbers don't match.

Adding cumulative stats is a much better idea.

Well, if you read Benoit's earlier proposal at [1]/messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com you'll see that he
does propose to have some cumulative stats; this LOG line he proposes
here is not a substitute for stats, but rather a complement. I don't
see any reason to reject this patch even if we do get stats.

Also, we do have a patch on stats, by Sotolongo and Bonne here [2]/messages/by-id/6acbe570-068e-bd8e-95d5-00c737b865e8@gmail.com. I
think there was some drift on the scope, so eventually they gave up (I
don't blame them). If you have concrete ideas on what direction that
effort should take, I think that thread would welcome that. I have not
reviewed it myself, and I'm not sure when I'll have time for that.

[1]: /messages/by-id/d657df20-c4bf-63f6-e74c-cb85a81d0383@dalibo.com
[2]: /messages/by-id/6acbe570-068e-bd8e-95d5-00c737b865e8@gmail.com

--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/
"I'm impressed how quickly you are fixing this obscure issue. I came from
MS SQL and it would be hard for me to put into words how much of a better job
you all are doing on [PostgreSQL]."
Steve Midgley, http://archives.postgresql.org/pgsql-sql/2008-08/msg00000.php

#10Imseih (AWS), Sami
simseih@amazon.com
In reply to: Alvaro Herrera (#9)
Re: Logging parallel worker draught

Currently explain ( analyze ) will give you the "Workers Planned"
and "Workers launched". Logging this via auto_explain is possible, so I am
not sure we need additional GUCs or debug levels for this info.

-> Gather (cost=10430.00..10430.01 rows=2 width=8) (actual tim
e=131.826..134.325 rows=3 loops=1)
Workers Planned: 2
Workers Launched: 2

I don't think autoexplain is a good substitute for the originally
proposed log line. The possibility for log bloat is enormous. Some
explain plans are gigantic, and I doubt people can afford that kind of
log traffic just in case these numbers don't match.

Correct, that is a downside of auto_explain in general.

The logging traffic can be controlled by
auto_explain.log_min_duration/auto_explain.sample_rate/etc.
of course.

Well, if you read Benoit's earlier proposal at [1] you'll see that he
does propose to have some cumulative stats; this LOG line he proposes
here is not a substitute for stats, but rather a complement. I don't
see any reason to reject this patch even if we do get stats.

Also, we do have a patch on stats, by Sotolongo and Bonne here [2]. I

Thanks. I will review the threads in depth and see if the ideas can be combined
in a comprehensive proposal.

Regarding the current patch, the latest version removes the separate GUC,
but the user should be able to control this behavior.

Query text is logged when log_min_error_statement > default level of "error".

This could be especially problematic when there is a query running more than 1 Parallel
Gather node that is in draught. In those cases each node will end up
generating a log with the statement text. So, a single query execution could end up
having multiple log lines with the statement text.

i.e.
LOG: Parallel Worker draught during statement execution: workers spawned 0, requested 2
STATEMENT: select (select count(*) from large) as a, (select count(*) from large) as b, (select count(*) from large) as c ;
LOG: Parallel Worker draught during statement execution: workers spawned 0, requested 2
STATEMENT: select (select count(*) from large) as a, (select count(*) from large) as b, (select count(*) from large) as c ;
LOG: Parallel Worker draught during statement execution: workers spawned 0, requested 2
STATEMENT: select (select count(*) from large) as a, (select count(*) from large) as b, (select count(*) from large) as c ;

I wonder if it will be better to accumulate the total # of workers planned and # of workers launched and
logging this information at the end of execution?

Regards,

Sami

#11Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Imseih (AWS), Sami (#10)
Re: Logging parallel worker draught

On 10/11/23 17:26, Imseih (AWS), Sami wrote:

Thank you for resurrecting this thread.

Well, if you read Benoit's earlier proposal at [1] you'll see that he
does propose to have some cumulative stats; this LOG line he proposes
here is not a substitute for stats, but rather a complement. I don't
see any reason to reject this patch even if we do get stats.

I believe both cumulative statistics and logs are needed. Logs excel in
pinpointing specific queries at precise times, while statistics provide
a broader overview of the situation. Additionally, I often encounter
situations where clients lack pg_stat_statements and can't restart their
production promptly.

Regarding the current patch, the latest version removes the separate GUC,
but the user should be able to control this behavior.

I created this patch in response to Amit Kapila's proposal to keep the
discussion ongoing. However, I still favor the initial version with the
GUCs.

Query text is logged when log_min_error_statement > default level of "error".

This could be especially problematic when there is a query running more than 1 Parallel
Gather node that is in draught. In those cases each node will end up
generating a log with the statement text. So, a single query execution could end up
having multiple log lines with the statement text.
...
I wonder if it will be better to accumulate the total # of workers planned and # of workers launched and
logging this information at the end of execution?

log_temp_files exhibits similar behavior when a query involves multiple
on-disk sorts. I'm uncertain whether this is something we should or need
to address. I'll explore whether the error message can be made more
informative.

[local]:5437 postgres@postgres=# SET work_mem to '125kB';
[local]:5437 postgres@postgres=# SET log_temp_files TO 0;
[local]:5437 postgres@postgres=# SET client_min_messages TO log;
[local]:5437 postgres@postgres=# WITH a AS ( SELECT x FROM
generate_series(1,10000) AS F(x) ORDER BY 1 ) , b AS (SELECT x FROM
generate_series(1,10000) AS F(x) ORDER BY 1 ) SELECT * FROM a,b;
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.20", size
122880 => First sort
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.19", size 140000
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.23", size 140000
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.22", size
122880 => Second sort
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.21", size 140000

--
Benoit Lobréau
Consultant
http://dalibo.com

#12Imseih (AWS), Sami
simseih@amazon.com
In reply to: Benoit Lobréau (#11)
Re: Logging parallel worker draught

I believe both cumulative statistics and logs are needed. Logs excel in
pinpointing specific queries at precise times, while statistics provide
a broader overview of the situation. Additionally, I often encounter
situations where clients lack pg_stat_statements and can't restart their
production promptly.

I agree that logging will be very useful here.
Cumulative stats/pg_stat_statements can be handled in a separate discussion.

log_temp_files exhibits similar behavior when a query involves multiple
on-disk sorts. I'm uncertain whether this is something we should or need
to address. I'll explore whether the error message can be made more
informative.

[local]:5437 postgres@postgres=# SET work_mem to '125kB';
[local]:5437 postgres@postgres=# SET log_temp_files TO 0;
[local]:5437 postgres@postgres=# SET client_min_messages TO log;
[local]:5437 postgres@postgres=# WITH a AS ( SELECT x FROM
generate_series(1,10000) AS F(x) ORDER BY 1 ) , b AS (SELECT x FROM
generate_series(1,10000) AS F(x) ORDER BY 1 ) SELECT * FROM a,b;
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.20", size
122880 => First sort
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.19", size 140000
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.23", size 140000
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.22", size
122880 => Second sort
LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp138850.21", size 140000

That is true.

Users should also control if they want this logging overhead or not,
The best answer is a new GUC that is OFF by default.

I am also not sure if we want to log draught only. I think it's important
to not only see which operations are in parallel draught, but to also log
operations are using 100% of planned workers.
This will help the DBA tune queries that are eating up the parallel workers.

Regards,

Sami

#13Tomas Vondra
tomas.vondra@enterprisedb.com
In reply to: Imseih (AWS), Sami (#12)
Re: Logging parallel worker draught

Hi,

I see the thread went a bit quiet, but I think it'd be very useful (and
desirable) to have this information in log. So let me share my thoughts
about the patch / how it should work.

The patch is pretty straightforward, I don't have any comments about the
code as is. Obviously, some of the following comments might require
changes to the patch, etc.

I see there was discussion about logging vs. adding this to the pgstats
system. I agree with Alvaro it should not be one or the other - these
are complementary approaches, used by different tools. The logging is
needed for tools like pgbadger etc. for example.

I do see a lot of value in adding this to the statistics collector, and
to things like pg_stat_statements, but that's being discussed in a
separate thread, so I'll comment on that there.

As for whether to have a GUC for this, I certainly think we should have
one. We have GUC for logging stuff that we generally expect to happen,
like lock waits, temp files, etc.

True, there are similar cases that we just log every time, like when we
can't fork a process ("could not fork autovacuum launcher process"), but
I'd say those are unexpected to happen in general / seem more like an
error in the environment. While we may exhaust parallel workers pretty
easily / often, especially on busy systems.

There's a couple things I'm not quite sure about:

1) name of the GUC

I find the "log_parallel_worker_draught" to be rather unclear :-( Maybe
it's just me and everyone else just immediately understands what this
does / what will happen after it's set to "on", but I find it rather
non-intuitive.

2) logging just the failures provides an incomplete view

As a DBA trying to evaluate if I need to bump up the number of workers,
I'd be interested what fraction of parallel workers fails to start. If
it's 1%, that's probably a short spike and I don't need to do anything.
If it's 50%, well, that might have unpredictable impact on user queries,
and thus something I may need to look into. But if we only log the
failures, that's not possible.

I may be able to approximate this somehow by correlating this with the
query/transaction rate, or something, but ideally I'd like to know how
many parallel workers we planned to use, and how many actually started.

Obviously, logging this for every Gather [Merge] node, even when all the
workers start, that may be a lot of data. Perhaps the GUC should not be
on/off, but something like

log_parallel_workers = {none | failures | all}

where "failures" only logs when at least one worker fails to start, and
"all" logs everything.

AFAIK Sami made the same observation/argument in his last message [1]/messages/by-id/D04977E3-9F54-452C-A4C4-CDA67F392BD1@amazon.com.

3) node-level or query-level?

There's a brief discussion about whether this should be a node-level or
query-level thing in [2]/messages/by-id/11e34b80-b0a6-e2e4-1606-1f5077379a34@dalibo.com -- Tomas Vondra EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company:

I wonder if it will be better to accumulate the total # of workers
planned and # of workers launched and logging this information at the
end of execution?

And there's a reference to log_temp_files, but it's not clear to me if
that's meant to be an argument for doing it the same way (node-level).

I think we should not do node-level logging just because that's what
log_temp_files=on dies. I personally think log_temp_files was
implemented like this mostly because it was simple.

There's no value in having information about every individual temp file,
because we don't even know which node produced it. It'd be perfectly
sufficient to log some summary statistics (number of files, total space,
...), either for the query as a whole, or perhaps per node (because
that's what matters for work_mem). So I don't think we should mimic this
just because log_temp_files does this.

I don't know how difficult would it be to track/collect this information
for the whole query.

regards

[1]: /messages/by-id/D04977E3-9F54-452C-A4C4-CDA67F392BD1@amazon.com
/messages/by-id/D04977E3-9F54-452C-A4C4-CDA67F392BD1@amazon.com

[2]: /messages/by-id/11e34b80-b0a6-e2e4-1606-1f5077379a34@dalibo.com -- Tomas Vondra EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company
/messages/by-id/11e34b80-b0a6-e2e4-1606-1f5077379a34@dalibo.com
--
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

#14Peter Smith
smithpb2250@gmail.com
In reply to: Tomas Vondra (#13)
Re: Logging parallel worker draught

On Mon, Feb 26, 2024 at 6:13 AM Tomas Vondra
<tomas.vondra@enterprisedb.com> wrote:

1) name of the GUC

I find the "log_parallel_worker_draught" to be rather unclear :-( Maybe
it's just me and everyone else just immediately understands what this
does / what will happen after it's set to "on", but I find it rather
non-intuitive.

Also, I don't understand how the word "draught" (aka "draft") makes
sense here -- I assume the intended word was "drought" (???).

==========
Kind Regards,
Peter Smith.
Fujitsu Australia.

#15Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Tomas Vondra (#13)
Re: Logging parallel worker draught

On 2/25/24 20:13, Tomas Vondra wrote:

1) name of the GUC

...

2) logging just the failures provides an incomplete view
log_parallel_workers = {none | failures | all}>
where "failures" only logs when at least one worker fails to start, and
"all" logs everything.

AFAIK Sami made the same observation/argument in his last message [1].

I like the name and different levels you propose. I was initially
thinking that the overall picture would be better summarized (an easier
to implement) with pg_stat_statements. But with the granularity you
propose, the choice is in the hands of the DBA, which is great and
provides more options when we don't have full control of the installation.

3) node-level or query-level?

...

There's no value in having information about every individual temp file,
because we don't even know which node produced it. It'd be perfectly
sufficient to log some summary statistics (number of files, total space,
...), either for the query as a whole, or perhaps per node (because
that's what matters for work_mem). So I don't think we should mimic this
just because log_temp_files does this.

I must admit that, given my (poor) technical level, I went for the
easiest way.

If we go for the three levels you proposed, "node-level" makes even less
sense (and has great "potential" for spam).

I can see one downside to the "query-level" approach: it might be more
difficult to to give information in cases where the query doesn't end
normally. It's sometimes useful to have hints about what was going wrong
before a query was cancelled or crashed, which log_temp_files kinda does.

I don't know how difficult would it be to track/collect this information
for the whole query.

I am a worried this will be a little too much for me, given the time and
the knowledge gap I have (both in C and PostgreSQL internals). I'll try
to look anyway.

--
Benoit Lobréau
Consultant
http://dalibo.com

#16Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Peter Smith (#14)
Re: Logging parallel worker draught

On 2/25/24 23:32, Peter Smith wrote:

Also, I don't understand how the word "draught" (aka "draft") makes
sense here -- I assume the intended word was "drought" (???).

yes, that was the intent, sorry about that. English is not my native
langage and I was convinced the spelling was correct.

--
Benoit Lobréau
Consultant
http://dalibo.com

#17Tomas Vondra
tomas.vondra@enterprisedb.com
In reply to: Benoit Lobréau (#15)
Re: Logging parallel worker draught

On 2/27/24 10:55, Benoit Lobréau wrote:

On 2/25/24 20:13, Tomas Vondra wrote:

1) name of the GUC

...

2) logging just the failures provides an incomplete view
log_parallel_workers = {none | failures | all}>
where "failures" only logs when at least one worker fails to start, and
"all" logs everything.

AFAIK Sami made the same observation/argument in his last message [1].

I like the name and different levels you propose. I was initially
thinking that the overall picture would be better summarized (an easier
to implement) with pg_stat_statements. But with the granularity you
propose, the choice is in the hands of the DBA, which is great and
provides more options when we don't have full control of the installation.

Good that you like the idea with multiple levels.

I agree pg_stat_statements may be an easier way to get a summary, but it
has limitations too (e.g. no built-in ability to show how the metrics
evolves over time, which is easier to restore from logs). So I think
those approaches are complementary.

3) node-level or query-level?

...

There's no value in having information about every individual temp file,
because we don't even know which node produced it. It'd be perfectly
sufficient to log some summary statistics (number of files, total space,
...), either for the query as a whole, or perhaps per node (because
that's what matters for work_mem). So I don't think we should mimic this
just because log_temp_files does this.

I must admit that, given my (poor) technical level, I went for the
easiest way.

That's understandable, I'd do the same thing.

If we go for the three levels you proposed, "node-level" makes even less
sense (and has great "potential" for spam).

Perhaps.

I can see one downside to the "query-level" approach: it might be more
difficult to to give information in cases where the query doesn't end
normally. It's sometimes useful to have hints about what was going wrong
before a query was cancelled or crashed, which log_temp_files kinda does.

That is certainly true, but it's not a new thing, I believe. IIRC we may
not report statistics until the end of the transaction, so no progress
updates, I'm not sure what happens if the doesn't end correctly (e.g.
backend dies, ...). Similarly for the temporary files, we don't report
those until the temporary file gets closed, so I'm not sure you'd get a
lot of info about the progress either.

I admit I haven't tried and maybe I don't remember the details wrong.
Might be useful to experiment with this first a little bit ...

I don't know how difficult would it be to track/collect this information
for the whole query.

I am a worried this will be a little too much for me, given the time and
the knowledge gap I have (both in C and PostgreSQL internals). I'll try
to look anyway.

I certainly understand that, and I realize it may feel daunting and even
discouraging. What I can promise is that I'm willing to help, either by
suggesting ways to approach the problems, doing reviews, and so on.
Would that be sufficient for you to continue working on this patch?

Some random thoughts/ideas about how to approach this:

- For parallel workers I think this might be as simple as adding some
counters into QueryDesc, and update those during query exec (instead of
just logging stuff directly). I'm not sure if it should be added to
"Instrumentation" or separately.

- I was thinking maybe we could just walk the execution plan and collect
the counts that way. But I'm not sure that'd work if the Gather node
happens to be executed repeatedly (in a loop). Also, not sure we'd want
to walk all plans.

- While log_temp_files is clearly out of scope for this patch, it might
be useful to think about it and how it should behave. We've already used
log_temp_files to illustrate some issues with logging the info right
away, so maybe there's something to learn here ...

- For temporary files I think it'd be more complicated, because we can
create temporary files from many different places, not just in executor,
so we can't simply update QueryDesc etc. Also, the places that log info
about temporary files (using ReportTemporaryFileUsage) only really know
about individual temporary files, so if a Sort or HashJoin creates a
1000 files, we'll get one LOG for each of those temp files. But they're
really a single "combined" file. So maybe we should introduce some sort
of "context" to group those files, and only accumulate/log the size for
the group as a whole? Maybe it'd even allow printing some info about
what the temporary file is for (e.g. tuplestore / tuplesort / ...).

regards

--
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

#18Andrew Dunstan
andrew@dunslane.net
In reply to: Benoit Lobréau (#16)
Re: Logging parallel worker draught

On 2024-02-27 Tu 05:03, Benoit Lobréau wrote:

On 2/25/24 23:32, Peter Smith wrote:

Also, I don't understand how the word "draught" (aka "draft") makes
sense here -- I assume the intended word was "drought" (???).

yes, that was the intent, sorry about that. English is not my native
langage and I was convinced the spelling was correct.

Both are English words spelled correctly, but with very different
meanings. (Drought is definitely the one you want here.) This reminds me
of the Errata section of Sellars and Yeatman's classic "history" work
"1066 And All That":

"For 'pheasant' read 'peasant' throughout."

cheers

andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

#19Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Tomas Vondra (#17)
Re: Logging parallel worker draught

On 2/27/24 15:09, Tomas Vondra wrote> That is certainly true, but it's
not a new thing, I believe. IIRC we may

not report statistics until the end of the transaction, so no progress
updates, I'm not sure what happens if the doesn't end correctly (e.g.
backend dies, ...). Similarly for the temporary files, we don't report
those until the temporary file gets closed, so I'm not sure you'd get a
lot of info about the progress either.

I admit I haven't tried and maybe I don't remember the details wrong.
Might be useful to experiment with this first a little bit ...

Ah, yes, Tempfile usage is reported on tempfile closure or deletion
for shared file sets.

I certainly understand that, and I realize it may feel daunting and even
discouraging. What I can promise is that I'm willing to help, either by
suggesting ways to approach the problems, doing reviews, and so on.
Would that be sufficient for you to continue working on this patch?

Yes, thanks for the proposal, I'll work on it on report here. I am otherwise
booked on company projects so I cannot promise a quick progress.

Some random thoughts/ideas about how to approach this:

- For parallel workers I think this might be as simple as adding some
counters into QueryDesc, and update those during query exec (instead of
just logging stuff directly). I'm not sure if it should be added to
"Instrumentation" or separately.

I will start here to see how it works.

--
Benoit Lobréau
Consultant
http://dalibo.com

#20Andrey M. Borodin
x4mmm@yandex-team.ru
In reply to: Benoit Lobréau (#19)
Re: Logging parallel worker draught

On 29 Feb 2024, at 11:24, Benoit Lobréau <benoit.lobreau@dalibo.com> wrote:

Yes, thanks for the proposal, I'll work on it on report here.

Hi Benoit!

This is kind reminder that this thread is waiting for your response.
CF entry [0]https://commitfest.postgresql.org/47/4291/ is in "Waiting on Author", I'll move it to July CF.

Thanks!

Best regards, Andrey Borodin.

[0]: https://commitfest.postgresql.org/47/4291/

#21Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Andrey M. Borodin (#20)
Re: Logging parallel worker draught

On 4/8/24 10:05, Andrey M. Borodin wrote:

Hi Benoit!

This is kind reminder that this thread is waiting for your response.
CF entry [0] is in "Waiting on Author", I'll move it to July CF.

Hi thanks for the reminder,

The past month as been hectic for me.
It should calm down by next week at wich point I'll have time to go back
to this. sorry for the delay.

--
Benoit Lobréau
Consultant
http://dalibo.com

#22Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Benoit Lobréau (#21)
1 attachment(s)
Re: Logging parallel worker draught

Hi,

Here is a new version of the patch. Sorry for the long delay, I was hit
by a motivation drought and was quite busy otherwise.

The guc is now called `log_parallel_workers` and has three possible values:

* "none": disables logging
* "all": logs parallel worker info for all parallel queries or utilities
* "failure": logs only when the number of parallel workers planned
couldn't be reached.

For this, I added several members to the EState struct.

Each gather node / gather merge node updates the values and the
offending queries are displayed during standard_ExecutorEnd.

For CREATE INDEX / REINDEX on btree and brin, I check the parallel
context struct (pcxt) during _bt_end_parallel() or _brin_end_parallel()
and display a log message when needed.

For vacuum, I do the same in parallel_vacuum_end().

I added some information to the error message for parallel queries as an
experiment. I find it useful, but it can be removed, if you re not
convinced.

2024-08-27 15:59:11.089 CEST [54585] LOG: 1 parallel nodes planned (1
obtained all their workers, 0 obtained none), 2 workers planned (2
workers launched)
2024-08-27 15:59:11.089 CEST [54585] STATEMENT: EXPLAIN (ANALYZE)
SELECT i, avg(j) FROM test_pql GROUP BY i;

2024-08-27 15:59:14.006 CEST [54585] LOG: 2 parallel nodes planned (0
obtained all their workers, 1 obtained none), 4 workers planned (1
workers launched)
2024-08-27 15:59:14.006 CEST [54585] STATEMENT: EXPLAIN (ANALYZE)
SELECT i, avg(j) FROM test_pql GROUP BY i
UNION
SELECT i, avg(j) FROM test_pql GROUP BY i;

For CREATE INDEX / REDINDEX / VACUUMS:

2024-08-27 15:58:59.769 CEST [54521] LOG: 1 workers planned (0 workers
launched)
2024-08-27 15:58:59.769 CEST [54521] STATEMENT: REINDEX TABLE test_pql;

Do you think this is better?

I am not sure if a struct is needed to store the es_nworkers* and if the
modification I did to parallel.h is ok.

Thanks to: Jehan-Guillaume de Rorthais, Guillaume Lelarge and Franck
Boudehen for the help and motivation boost.

(sorry for the spam, I had to resend the mail to the list)

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

0001-Add-logging-for-parallel-worker-usage.patchtext/x-patch; charset=UTF-8; name=0001-Add-logging-for-parallel-worker-usage.patchDownload
From 940e1d1149f777733ea00e7a0a688da67f492f6d Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@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         |  8 ++++++++
 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, 110 insertions(+)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 2937384b00..234552c3fc 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7700,6 +7700,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 6467bed604..0d53d5c575 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..fc40b68903 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -435,6 +435,14 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats)
 {
 	Assert(!IsParallelWorker());
 
+	if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+		 pvs->pcxt->nworkers_to_launch > 0) ||
+		(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+		 pvs->pcxt->nworkers_to_launch > pvs->pcxt->nworkers_launched))
+		elog(LOG, "%i workers planned (%i workers launched)",
+			pvs->pcxt->nworkers_to_launch,
+			pvs->pcxt->nworkers_launched);
+
 	/* Copy the updated statistics */
 	for (int i = 0; i < pvs->nindexes; i++)
 	{
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 29e186fa73..42c4f9fc54 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -480,6 +480,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 af227b1f24..891f71e980 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 af7d8fd1e7..06b48bfe41 100644
--- a/src/include/nodes/execnodes.h
+++ b/src/include/nodes/execnodes.h
@@ -724,6 +724,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

#23Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Benoit Lobréau (#22)
Re: Logging parallel worker draught

I found out in [1]/messages/by-id/783bc7f7-659a-42fa-99dd-ee0565644e25@dalibo.com that I am not correctly tracking the workers for
vacuum commands. I trap workers used by
parallel_vacuum_cleanup_all_indexes but not
parallel_vacuum_bulkdel_all_indexes.

Back to the drawing board.

[1]: /messages/by-id/783bc7f7-659a-42fa-99dd-ee0565644e25@dalibo.com
/messages/by-id/783bc7f7-659a-42fa-99dd-ee0565644e25@dalibo.com

--
Benoit Lobréau
Consultant
http://dalibo.com

#24Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Benoit Lobréau (#23)
1 attachment(s)
Re: Logging parallel worker draught

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]/messages/by-id/783bc7f7-659a-42fa-99dd-ee0565644e25@dalibo.com
[1]: /messages/by-id/783bc7f7-659a-42fa-99dd-ee0565644e25@dalibo.com
/messages/by-id/783bc7f7-659a-42fa-99dd-ee0565644e25@dalibo.com

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

0001-Add-logging-for-parallel-worker-usage.patch_v2text/plain; charset=UTF-8; name=0001-Add-logging-for-parallel-worker-usage.patch_v2Download
From d82cea62d4ab53d3d77054286cddb1536172c8c0 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@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

#25Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Benoit Lobréau (#24)
5 attachment(s)
Re: Logging parallel worker draught

This is a rebased version.

I have split queries, vacuum and index creation in different patches.
I have also split the declartion that are in common with the
pg_stat_database patch.

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

V3_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchtext/x-patch; charset=UTF-8; name=V3_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchDownload
From cfa4263333a080ca2d0c484ac8f5201800bd6434 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:59:15 +0200
Subject: [PATCH 5/5] Implements logging for parallel worker usage in queries

---
 src/backend/executor/execMain.c        | 12 ++++++++++++
 src/backend/executor/execUtils.c       |  3 +++
 src/backend/executor/nodeGather.c      |  5 +++++
 src/backend/executor/nodeGatherMerge.c |  5 +++++
 src/include/nodes/execnodes.h          |  4 ++++
 5 files changed, 29 insertions(+)

diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index cc9a594cba..6663fea7b1 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -483,6 +483,18 @@ standard_ExecutorEnd(QueryDesc *queryDesc)
 
 	Assert(estate != NULL);
 
+	if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+		 estate->es_parallel_workers_to_launch > 0) ||
+		(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+		 estate->es_parallel_workers_to_launch != estate->es_parallel_workers_launched))
+		elog(LOG, "%i parallel nodes planned (%i obtained all their workers, %i obtained none), "
+				  "%i workers planned to be launched (%i workers launched)",
+			estate->es_parallel_nodes,
+			estate->es_parallel_nodes_success,
+			estate->es_parallel_nodes_no_workers,
+			estate->es_parallel_workers_to_launch,
+			estate->es_parallel_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 6712302ec8..fd463f7e4c 100644
--- a/src/backend/executor/execUtils.c
+++ b/src/backend/executor/execUtils.c
@@ -160,6 +160,9 @@ CreateExecutorState(void)
 	estate->es_use_parallel_mode = false;
 	estate->es_parallel_workers_to_launch = 0;
 	estate->es_parallel_workers_launched = 0;
+	estate->es_parallel_nodes = 0;
+	estate->es_parallel_nodes_success = 0;
+	estate->es_parallel_nodes_no_workers = 0;
 
 	estate->es_jit_flags = 0;
 	estate->es_jit = NULL;
diff --git a/src/backend/executor/nodeGather.c b/src/backend/executor/nodeGather.c
index 7f7edc7f9f..49a96f7cbf 100644
--- a/src/backend/executor/nodeGather.c
+++ b/src/backend/executor/nodeGather.c
@@ -188,6 +188,10 @@ ExecGather(PlanState *pstate)
 			 */
 			estate->es_parallel_workers_to_launch += pcxt->nworkers_to_launch;
 			estate->es_parallel_workers_launched += pcxt->nworkers_launched;
+			estate->es_parallel_nodes += 1;
+
+			if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+				estate->es_parallel_nodes_success += 1;
 
 			/* Set up tuple queue readers to read the results. */
 			if (pcxt->nworkers_launched > 0)
@@ -205,6 +209,7 @@ ExecGather(PlanState *pstate)
 				/* No workers?	Then never mind. */
 				node->nreaders = 0;
 				node->reader = NULL;
+				estate->es_parallel_nodes_no_workers += 1;
 			}
 			node->nextreader = 0;
 		}
diff --git a/src/backend/executor/nodeGatherMerge.c b/src/backend/executor/nodeGatherMerge.c
index bc99c0b448..f3aa7ee14f 100644
--- a/src/backend/executor/nodeGatherMerge.c
+++ b/src/backend/executor/nodeGatherMerge.c
@@ -229,6 +229,10 @@ ExecGatherMerge(PlanState *pstate)
 			 */
 			estate->es_parallel_workers_to_launch += pcxt->nworkers_to_launch;
 			estate->es_parallel_workers_launched += pcxt->nworkers_launched;
+			estate->es_parallel_nodes += 1;
+
+			if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+				estate->es_parallel_nodes_success += 1;
 
 			/* Set up tuple queue readers to read the results. */
 			if (pcxt->nworkers_launched > 0)
@@ -246,6 +250,7 @@ ExecGatherMerge(PlanState *pstate)
 				/* No workers?	Then never mind. */
 				node->nreaders = 0;
 				node->reader = NULL;
+				estate->es_parallel_nodes_no_workers += 1;
 			}
 		}
 
diff --git a/src/include/nodes/execnodes.h b/src/include/nodes/execnodes.h
index e4698a28c4..d87af53853 100644
--- a/src/include/nodes/execnodes.h
+++ b/src/include/nodes/execnodes.h
@@ -713,6 +713,10 @@ typedef struct EState
 	int			es_parallel_workers_launched;	/* number of workers actually
 												 * launched. */
 
+	int			es_parallel_nodes;
+	int			es_parallel_nodes_success;
+	int			es_parallel_nodes_no_workers;
+
 	/* The per-query shared memory area to use for parallel execution. */
 	struct dsa_area *es_query_dsa;
 
-- 
2.46.2

V3_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchtext/x-patch; charset=UTF-8; name=V3_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchDownload
From c6dfd6d7751337a9e7a435efe742c4aea9d831e3 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:58:40 +0200
Subject: [PATCH 4/5] Implements logging for parallel worker usage in vacuums

---
 src/backend/commands/vacuumparallel.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 77679e8df6..e207a6b7d9 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -443,6 +443,14 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats)
 {
 	Assert(!IsParallelWorker());
 
+	if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+		 pvs->nworkers_to_launch > 0) ||
+		(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+		 pvs->nworkers_to_launch > pvs->nworkers_launched))
+		elog(LOG, "%i workers planned to be launched for index cleanup and bulkdelete (%i workers launched)",
+			pvs->nworkers_to_launch,
+			pvs->nworkers_launched);
+
 	/* Copy the updated statistics */
 	for (int i = 0; i < pvs->nindexes; i++)
 	{
-- 
2.46.2

V3_0003-Setup-counters-for-parallel-vacuums.patchtext/x-patch; charset=UTF-8; name=V3_0003-Setup-counters-for-parallel-vacuums.patchDownload
From 4cc5b301c9d0cc3f86dd84fe30eac7cfa2abbf25 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:56:23 +0200
Subject: [PATCH 3/5] Setup counters for parallel vacuums

This is used by the logging and  pg_stat_database patches.
---
 src/backend/commands/vacuumparallel.c | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 4fd6574e12..77679e8df6 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;
 
@@ -739,6 +745,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.46.2

V3_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchtext/x-patch; charset=UTF-8; name=V3_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchDownload
From 367b163e135011290125fc4db7586f6603e09270 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:45:03 +0200
Subject: [PATCH 2/5] Implements logging for parallel worker usage in index
 builds

Two types of index are concerned: brin and btree.
---
 src/backend/access/brin/brin.c      | 8 ++++++++
 src/backend/access/nbtree/nbtsort.c | 8 ++++++++
 2 files changed, 16 insertions(+)

diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index c0b978119a..fdfbbc7dc4 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2544,6 +2544,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 5cca0d4f52..e31bd8e223 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1615,6 +1615,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.)
-- 
2.46.2

V3_0001-Add-a-guc-for-parallel-worker-logging.patchtext/x-patch; charset=UTF-8; name=V3_0001-Add-a-guc-for-parallel-worker-logging.patchDownload
From 676fbaf183639b37c382e784c89558a98ff7af9c Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:39:41 +0200
Subject: [PATCH 1/5] 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 `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/utils/misc/guc_tables.c           | 12 ++++++++++++
 src/backend/utils/misc/postgresql.conf.sample |  1 +
 src/include/access/parallel.h                 | 15 +++++++++++++++
 4 files changed, 46 insertions(+)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 9707d5238d..5c04a27eb6 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/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)
 
-- 
2.46.2

#26Alena Rybakina
a.rybakina@postgrespro.ru
In reply to: Benoit Lobréau (#25)
1 attachment(s)
Re: Logging parallel worker draught

On 28.08.2024 15:58, Benoit Lobréau wrote:

Hi,

Here is a new version of the patch. Sorry for the long delay, I was
hit by a motivation drought and was quite busy otherwise.

The guc is now called `log_parallel_workers` and has three possible
values:

* "none": disables logging
* "all": logs parallel worker info for all parallel queries or utilities
* "failure": logs only when the number of parallel workers planned
couldn't be reached.

For this, I added several members to the EState struct.

Each gather node / gather merge node updates the values and the
offending queries are displayed during standard_ExecutorEnd.

For CREATE INDEX / REINDEX on btree and brin, I check the parallel
context struct (pcxt) during _bt_end_parallel() or
_brin_end_parallel() and display a log message when needed.

For vacuum, I do the same in parallel_vacuum_end().

I added some information to the error message for parallel queries as
an experiment. I find it useful, but it can be removed, if you re not
convinced.

2024-08-27 15:59:11.089 CEST [54585] LOG:  1 parallel nodes planned (1
obtained all their workers, 0 obtained none), 2 workers planned (2
workers launched)
2024-08-27 15:59:11.089 CEST [54585] STATEMENT:  EXPLAIN (ANALYZE)
        SELECT i, avg(j) FROM test_pql GROUP BY i;

2024-08-27 15:59:14.006 CEST [54585] LOG:  2 parallel nodes planned (0
obtained all their workers, 1 obtained none), 4 workers planned (1
workers launched)
2024-08-27 15:59:14.006 CEST [54585] STATEMENT:  EXPLAIN (ANALYZE)
        SELECT i, avg(j) FROM test_pql GROUP BY i
        UNION
        SELECT i, avg(j) FROM test_pql GROUP BY i;

For CREATE INDEX / REDINDEX / VACUUMS:

2024-08-27 15:58:59.769 CEST [54521] LOG:  1 workers planned (0
workers launched)
2024-08-27 15:58:59.769 CEST [54521] STATEMENT:  REINDEX TABLE test_pql;

Do you think this is better?

I am not sure if a struct is needed to store the es_nworkers* and if
the modification I did to parallel.h is ok.

Thanks to: Jehan-Guillaume de Rorthais, Guillaume Lelarge and Franck
Boudehen for the help and motivation boost.

Hi!

I think it's a good idea to log this. I suggest some changes that might
improve your patch.

1. I think you should rewrite the first statement of the documentation
about parameter as follows:

Controls a log message about the number of workers produced during an
execution of the parallel query or utility statement.

2. I think you can transfer nworkers_to_launch and nworkers_launched
vacuum parameters in the ParallelContext struct.

3. I think you should write the logging check condition in an
independent function and provide necessary parameters for that. To be
honest if the parameters weren't stored in a different struct for
parallel queries, I would have put it in a macro.

I attached the diff file including my proposals.

--
Regards,
Alena Rybakina
Postgres Professional

Attachments:

parallel_log_workers.no-cfbottext/plain; charset=UTF-8; name=parallel_log_workers.no-cfbotDownload
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 5c04a27eb66..1e2fadffaf1 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7704,8 +7704,8 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
       </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
+        Controls whether a log message about the number of workers produced during an
+        execution of the parallel query or utility statement. 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
diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index fdfbbc7dc42..3ed10c7f8a0 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2544,10 +2544,9 @@ _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))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   brinleader->pvs->pcxt->parallel_workers_to_launch,
+							   brinleader->pvs->pcxt->parallel_workers_launched))
 		elog(LOG, "%i workers planned (%i workers launched)",
 			brinleader->pcxt->nworkers_to_launch,
 			brinleader->pcxt->nworkers_launched);
diff --git a/src/backend/access/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index e31bd8e223e..85fede89d9f 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1615,10 +1615,9 @@ _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))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   btleader->pvs->pcxt->parallel_workers_to_launch,
+							   btleader->pvs->pcxt->parallel_workers_launched))
 		elog(LOG, "%i workers planned (%i workers launched)",
 			btleader->pcxt->nworkers_to_launch,
 			btleader->pcxt->nworkers_launched);
diff --git a/src/backend/access/transam/parallel.c b/src/backend/access/transam/parallel.c
index d4e84aabac7..d3e37915fdf 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -1627,3 +1627,17 @@ LookupParallelWorkerFunction(const char *libraryname, const char *funcname)
 	return (parallel_worker_main_type)
 		load_external_function(libraryname, funcname, true, NULL);
 }
+
+/*
+ * The function determines of logging information
+ * about workers.
+*/
+LoggingParallelWorkers(int log_parallel_workers,
+					   int parallel_workers_to_launch,
+					   int parallel_workers_launched)
+{
+	return ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+		 	parallel_workers_to_launch > 0) ||
+		   (log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+		 	parallel_workers_to_launch != parallel_workers_launched));
+}
\ No newline at end of file
diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index e207a6b7d91..bae64b07e9a 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -208,9 +208,6 @@ 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;
 
@@ -365,8 +362,8 @@ 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;
+	pcxt->nworkers_to_launch = 0;
+	pcxt->nworkers_launched = 0;
 
 	shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_INDEX_STATS, indstats);
 	pvs->indstats = indstats;
@@ -443,13 +440,12 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats)
 {
 	Assert(!IsParallelWorker());
 
-	if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
-		 pvs->nworkers_to_launch > 0) ||
-		(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
-		 pvs->nworkers_to_launch > pvs->nworkers_launched))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   pvs->pcxt->parallel_workers_to_launch,
+							   pvs->pcxt->parallel_workers_launched))
 		elog(LOG, "%i workers planned to be launched for index cleanup and bulkdelete (%i workers launched)",
-			pvs->nworkers_to_launch,
-			pvs->nworkers_launched);
+			pvs->pcxt->nworkers_to_launch,
+			pvs->pcxt->nworkers_launched);
 
 	/* Copy the updated statistics */
 	for (int i = 0; i < pvs->nindexes; i++)
@@ -754,8 +750,8 @@ 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;
+		pvs->pcxt->nworkers_to_launch += pvs->pcxt->nworkers_to_launch;
+		pvs->pcxt->nworkers_launched += pvs->pcxt->nworkers_launched;
 	}
 
 	/*
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 6663fea7b12..b85d679b7fd 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -483,10 +483,9 @@ standard_ExecutorEnd(QueryDesc *queryDesc)
 
 	Assert(estate != NULL);
 
-	if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
-		 estate->es_parallel_workers_to_launch > 0) ||
-		(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
-		 estate->es_parallel_workers_to_launch != estate->es_parallel_workers_launched))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   estate->es_parallel_workers_to_launch,
+							   estate->es_parallel_workers_launched))
 		elog(LOG, "%i parallel nodes planned (%i obtained all their workers, %i obtained none), "
 				  "%i workers planned to be launched (%i workers launched)",
 			estate->es_parallel_nodes,
diff --git a/src/include/access/parallel.h b/src/include/access/parallel.h
index ed33e545d76..00aad1e742a 100644
--- a/src/include/access/parallel.h
+++ b/src/include/access/parallel.h
@@ -93,4 +93,8 @@ extern void ParallelWorkerReportLastRecEnd(XLogRecPtr last_xlog_end);
 
 extern void ParallelWorkerMain(Datum main_arg);
 
+extern bool LoggingParallelWorkers(int log_parallel_workers,
+								   int parallel_workers_to_launch,
+								   int parallel_workers_launched);
+
 #endif							/* PARALLEL_H */
#27Alena Rybakina
a.rybakina@postgrespro.ru
In reply to: Alena Rybakina (#26)
1 attachment(s)
Re: Logging parallel worker draught

Sorry, I was in a hurry and didn't check my patch properly.

On 14.10.2024 23:20, Alena Rybakina wrote:

On 28.08.2024 15:58, Benoit Lobréau wrote:

Hi,

Here is a new version of the patch. Sorry for the long delay, I was
hit by a motivation drought and was quite busy otherwise.

The guc is now called `log_parallel_workers` and has three possible
values:

* "none": disables logging
* "all": logs parallel worker info for all parallel queries or utilities
* "failure": logs only when the number of parallel workers planned
couldn't be reached.

For this, I added several members to the EState struct.

Each gather node / gather merge node updates the values and the
offending queries are displayed during standard_ExecutorEnd.

For CREATE INDEX / REINDEX on btree and brin, I check the parallel
context struct (pcxt) during _bt_end_parallel() or
_brin_end_parallel() and display a log message when needed.

For vacuum, I do the same in parallel_vacuum_end().

I added some information to the error message for parallel queries as
an experiment. I find it useful, but it can be removed, if you re not
convinced.

2024-08-27 15:59:11.089 CEST [54585] LOG:  1 parallel nodes planned
(1 obtained all their workers, 0 obtained none), 2 workers planned (2
workers launched)
2024-08-27 15:59:11.089 CEST [54585] STATEMENT:  EXPLAIN (ANALYZE)
        SELECT i, avg(j) FROM test_pql GROUP BY i;

2024-08-27 15:59:14.006 CEST [54585] LOG:  2 parallel nodes planned
(0 obtained all their workers, 1 obtained none), 4 workers planned (1
workers launched)
2024-08-27 15:59:14.006 CEST [54585] STATEMENT:  EXPLAIN (ANALYZE)
        SELECT i, avg(j) FROM test_pql GROUP BY i
        UNION
        SELECT i, avg(j) FROM test_pql GROUP BY i;

For CREATE INDEX / REDINDEX / VACUUMS:

2024-08-27 15:58:59.769 CEST [54521] LOG:  1 workers planned (0
workers launched)
2024-08-27 15:58:59.769 CEST [54521] STATEMENT:  REINDEX TABLE test_pql;

Do you think this is better?

I am not sure if a struct is needed to store the es_nworkers* and if
the modification I did to parallel.h is ok.

Thanks to: Jehan-Guillaume de Rorthais, Guillaume Lelarge and Franck
Boudehen for the help and motivation boost.

Hi!

I think it's a good idea to log this. I suggest some changes that
might improve your patch.

2. I think you can transfer nworkers_to_launch and nworkers_launched
vacuum parameters in the ParallelContext struct.

Sorry, I didn’t notice right away that the second point is impossible to
fulfill here.

Attached is the correct version of the patch.

--
Regards,
Alena Rybakina
Postgres Professional

Attachments:

parallel_log_workers.no-cfbottext/plain; charset=UTF-8; name=parallel_log_workers.no-cfbotDownload
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 5c04a27eb66..1e2fadffaf1 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7704,8 +7704,8 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
       </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
+        Controls whether a log message about the number of workers produced during an
+        execution of the parallel query or utility statement. 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
diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index fdfbbc7dc42..402be20e27c 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2544,10 +2544,9 @@ _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))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   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);
diff --git a/src/backend/access/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index e31bd8e223e..1ca027d2727 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1615,10 +1615,9 @@ _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))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   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);
diff --git a/src/backend/access/transam/parallel.c b/src/backend/access/transam/parallel.c
index d4e84aabac7..8a0d5028b1c 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -1627,3 +1627,18 @@ LookupParallelWorkerFunction(const char *libraryname, const char *funcname)
 	return (parallel_worker_main_type)
 		load_external_function(libraryname, funcname, true, NULL);
 }
+
+/*
+ * The function determines of logging information
+ * about workers.
+*/
+bool
+LoggingParallelWorkers(int log_parallel_workers,
+					   int parallel_workers_to_launch,
+					   int parallel_workers_launched)
+{
+	return ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+		 	parallel_workers_to_launch > 0) ||
+		   (log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+		 	parallel_workers_to_launch != parallel_workers_launched));
+}
\ No newline at end of file
diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index e207a6b7d91..84b0a90921c 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -443,10 +443,9 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats)
 {
 	Assert(!IsParallelWorker());
 
-	if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
-		 pvs->nworkers_to_launch > 0) ||
-		(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
-		 pvs->nworkers_to_launch > pvs->nworkers_launched))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   pvs->nworkers_to_launch,
+							   pvs->nworkers_launched))
 		elog(LOG, "%i workers planned to be launched for index cleanup and bulkdelete (%i workers launched)",
 			pvs->nworkers_to_launch,
 			pvs->nworkers_launched);
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 6663fea7b12..b85d679b7fd 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -483,10 +483,9 @@ standard_ExecutorEnd(QueryDesc *queryDesc)
 
 	Assert(estate != NULL);
 
-	if ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
-		 estate->es_parallel_workers_to_launch > 0) ||
-		(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
-		 estate->es_parallel_workers_to_launch != estate->es_parallel_workers_launched))
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   estate->es_parallel_workers_to_launch,
+							   estate->es_parallel_workers_launched))
 		elog(LOG, "%i parallel nodes planned (%i obtained all their workers, %i obtained none), "
 				  "%i workers planned to be launched (%i workers launched)",
 			estate->es_parallel_nodes,
diff --git a/src/include/access/parallel.h b/src/include/access/parallel.h
index ed33e545d76..00aad1e742a 100644
--- a/src/include/access/parallel.h
+++ b/src/include/access/parallel.h
@@ -93,4 +93,8 @@ extern void ParallelWorkerReportLastRecEnd(XLogRecPtr last_xlog_end);
 
 extern void ParallelWorkerMain(Datum main_arg);
 
+extern bool LoggingParallelWorkers(int log_parallel_workers,
+								   int parallel_workers_to_launch,
+								   int parallel_workers_launched);
+
 #endif							/* PARALLEL_H */
#28Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Alena Rybakina (#27)
Re: Logging parallel worker draught

On 10/14/24 22:42, Alena Rybakina wrote:

Attached is the correct version of the patch.

Thank you, it's a lot cleaner that way.
I'll add this asap.

--
Benoit Lobréau
Consultant
http://dalibo.com

#29Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Benoit Lobréau (#28)
5 attachment(s)
Re: Logging parallel worker draught

On 10/15/24 09:52, Benoit Lobréau wrote:

Thank you, it's a lot cleaner that way.
I'll add this asap.

This is an updated version with the suggested changes.

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

V4_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchtext/x-patch; charset=UTF-8; name=V4_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchDownload
From b9bf7c0fa967c72972fd77333a768dfe89d91765 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:59:15 +0200
Subject: [PATCH 5/5] Implements logging for parallel worker usage in queries

---
 src/backend/executor/execMain.c        | 11 +++++++++++
 src/backend/executor/execUtils.c       |  3 +++
 src/backend/executor/nodeGather.c      |  5 +++++
 src/backend/executor/nodeGatherMerge.c |  5 +++++
 src/include/nodes/execnodes.h          |  4 ++++
 5 files changed, 28 insertions(+)

diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index cc9a594cba..b85d679b7f 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -483,6 +483,17 @@ standard_ExecutorEnd(QueryDesc *queryDesc)
 
 	Assert(estate != NULL);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   estate->es_parallel_workers_to_launch,
+							   estate->es_parallel_workers_launched))
+		elog(LOG, "%i parallel nodes planned (%i obtained all their workers, %i obtained none), "
+				  "%i workers planned to be launched (%i workers launched)",
+			estate->es_parallel_nodes,
+			estate->es_parallel_nodes_success,
+			estate->es_parallel_nodes_no_workers,
+			estate->es_parallel_workers_to_launch,
+			estate->es_parallel_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 6712302ec8..fd463f7e4c 100644
--- a/src/backend/executor/execUtils.c
+++ b/src/backend/executor/execUtils.c
@@ -160,6 +160,9 @@ CreateExecutorState(void)
 	estate->es_use_parallel_mode = false;
 	estate->es_parallel_workers_to_launch = 0;
 	estate->es_parallel_workers_launched = 0;
+	estate->es_parallel_nodes = 0;
+	estate->es_parallel_nodes_success = 0;
+	estate->es_parallel_nodes_no_workers = 0;
 
 	estate->es_jit_flags = 0;
 	estate->es_jit = NULL;
diff --git a/src/backend/executor/nodeGather.c b/src/backend/executor/nodeGather.c
index 7f7edc7f9f..49a96f7cbf 100644
--- a/src/backend/executor/nodeGather.c
+++ b/src/backend/executor/nodeGather.c
@@ -188,6 +188,10 @@ ExecGather(PlanState *pstate)
 			 */
 			estate->es_parallel_workers_to_launch += pcxt->nworkers_to_launch;
 			estate->es_parallel_workers_launched += pcxt->nworkers_launched;
+			estate->es_parallel_nodes += 1;
+
+			if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+				estate->es_parallel_nodes_success += 1;
 
 			/* Set up tuple queue readers to read the results. */
 			if (pcxt->nworkers_launched > 0)
@@ -205,6 +209,7 @@ ExecGather(PlanState *pstate)
 				/* No workers?	Then never mind. */
 				node->nreaders = 0;
 				node->reader = NULL;
+				estate->es_parallel_nodes_no_workers += 1;
 			}
 			node->nextreader = 0;
 		}
diff --git a/src/backend/executor/nodeGatherMerge.c b/src/backend/executor/nodeGatherMerge.c
index bc99c0b448..f3aa7ee14f 100644
--- a/src/backend/executor/nodeGatherMerge.c
+++ b/src/backend/executor/nodeGatherMerge.c
@@ -229,6 +229,10 @@ ExecGatherMerge(PlanState *pstate)
 			 */
 			estate->es_parallel_workers_to_launch += pcxt->nworkers_to_launch;
 			estate->es_parallel_workers_launched += pcxt->nworkers_launched;
+			estate->es_parallel_nodes += 1;
+
+			if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+				estate->es_parallel_nodes_success += 1;
 
 			/* Set up tuple queue readers to read the results. */
 			if (pcxt->nworkers_launched > 0)
@@ -246,6 +250,7 @@ ExecGatherMerge(PlanState *pstate)
 				/* No workers?	Then never mind. */
 				node->nreaders = 0;
 				node->reader = NULL;
+				estate->es_parallel_nodes_no_workers += 1;
 			}
 		}
 
diff --git a/src/include/nodes/execnodes.h b/src/include/nodes/execnodes.h
index e4698a28c4..d87af53853 100644
--- a/src/include/nodes/execnodes.h
+++ b/src/include/nodes/execnodes.h
@@ -713,6 +713,10 @@ typedef struct EState
 	int			es_parallel_workers_launched;	/* number of workers actually
 												 * launched. */
 
+	int			es_parallel_nodes;
+	int			es_parallel_nodes_success;
+	int			es_parallel_nodes_no_workers;
+
 	/* The per-query shared memory area to use for parallel execution. */
 	struct dsa_area *es_query_dsa;
 
-- 
2.46.2

V4_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchtext/x-patch; charset=UTF-8; name=V4_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchDownload
From f13f1da31e4e45c68c3afae5c71572008caf6e84 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:58:40 +0200
Subject: [PATCH 4/5] Implements logging for parallel worker usage in vacuums

---
 src/backend/commands/vacuumparallel.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 77679e8df6..84b0a90921 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -443,6 +443,13 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats)
 {
 	Assert(!IsParallelWorker());
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   pvs->nworkers_to_launch,
+							   pvs->nworkers_launched))
+		elog(LOG, "%i workers planned to be launched for index cleanup and bulkdelete (%i workers launched)",
+			pvs->nworkers_to_launch,
+			pvs->nworkers_launched);
+
 	/* Copy the updated statistics */
 	for (int i = 0; i < pvs->nindexes; i++)
 	{
-- 
2.46.2

V4_0003-Setup-counters-for-parallel-vacuums.patchtext/x-patch; charset=UTF-8; name=V4_0003-Setup-counters-for-parallel-vacuums.patchDownload
From 9106db2f93d2d4087dcbe6e2da74043edc535ae5 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:56:23 +0200
Subject: [PATCH 3/5] Setup counters for parallel vacuums

Thsi can be used bu other patches such as the one for pg_stat_database.
---
 src/backend/commands/vacuumparallel.c | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 4fd6574e12..77679e8df6 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;
 
@@ -739,6 +745,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.46.2

V4_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchtext/x-patch; charset=UTF-8; name=V4_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchDownload
From e34c1f3634adf1f0fd927c303e90c4ef873884ce Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:45:03 +0200
Subject: [PATCH 2/5] Implements logging for parallel worker usage in index
 builds

Two types of index are concerned: brin and btree.
---
 src/backend/access/brin/brin.c      | 7 +++++++
 src/backend/access/nbtree/nbtsort.c | 7 +++++++
 2 files changed, 14 insertions(+)

diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index c0b978119a..402be20e27 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2544,6 +2544,13 @@ _brin_end_parallel(BrinLeader *brinleader, BrinBuildState *state)
 	/* Shutdown worker processes */
 	WaitForParallelWorkersToFinish(brinleader->pcxt);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   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 5cca0d4f52..1ca027d272 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1615,6 +1615,13 @@ _bt_end_parallel(BTLeader *btleader)
 	/* Shutdown worker processes */
 	WaitForParallelWorkersToFinish(btleader->pcxt);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   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.)
-- 
2.46.2

V4_0001-Add-a-guc-for-parallel-worker-logging.patchtext/x-patch; charset=UTF-8; name=V4_0001-Add-a-guc-for-parallel-worker-logging.patchDownload
From 907f83e81031c8faa839acdef5d07e57f046ade1 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:39:41 +0200
Subject: [PATCH 1/5] 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 `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/transam/parallel.c         | 15 +++++++++++++++
 src/backend/utils/misc/guc_tables.c           | 12 ++++++++++++
 src/backend/utils/misc/postgresql.conf.sample |  1 +
 src/include/access/parallel.h                 | 19 +++++++++++++++++++
 5 files changed, 65 insertions(+)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 934ef5e469..541b1a0f6e 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 about the number of workers is produced during the
+        execution of a parallel query or utility statement. 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/transam/parallel.c b/src/backend/access/transam/parallel.c
index d4e84aabac..cfd73dc64e 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -1627,3 +1627,18 @@ LookupParallelWorkerFunction(const char *libraryname, const char *funcname)
 	return (parallel_worker_main_type)
 		load_external_function(libraryname, funcname, true, NULL);
 }
+
+/*
+ * The function determines if information about workers should
+ * be logged.
+*/
+bool
+LoggingParallelWorkers(int log_parallel_workers,
+					   int parallel_workers_to_launch,
+					   int parallel_workers_launched)
+{
+	return ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+			parallel_workers_to_launch > 0) ||
+			(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+			parallel_workers_to_launch != parallel_workers_launched));
+}
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 2c4cc8cd41..94b6a237b1 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..00aad1e742 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)
 
@@ -78,4 +93,8 @@ extern void ParallelWorkerReportLastRecEnd(XLogRecPtr last_xlog_end);
 
 extern void ParallelWorkerMain(Datum main_arg);
 
+extern bool LoggingParallelWorkers(int log_parallel_workers,
+								   int parallel_workers_to_launch,
+								   int parallel_workers_launched);
+
 #endif							/* PARALLEL_H */
-- 
2.46.2

#30Guillaume Lelarge
guillaume@lelarge.info
In reply to: Benoit Lobréau (#29)
Re: Logging parallel worker draught

Hi,

Le sam. 19 oct. 2024 à 06:46, Benoit Lobréau <benoit.lobreau@dalibo.com> a
écrit :

On 10/15/24 09:52, Benoit Lobréau wrote:

Thank you, it's a lot cleaner that way.
I'll add this asap.

This is an updated version with the suggested changes.

AFAICT, Benoit answered to all questions and requests. Is there anything we
can do to make this move forward?

Thanks.

--
Guillaume.

#31Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Guillaume Lelarge (#30)
5 attachment(s)
Re: Logging parallel worker draught

This is just a rebase.

As stated before, I added some information to the error message for
parallel queries as an experiment. It can be removed, if you re not
convinced.

---
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

V5_0001-Add-a-guc-for-parallel-worker-logging.patchtext/x-patch; charset=UTF-8; name=V5_0001-Add-a-guc-for-parallel-worker-logging.patchDownload
From 7e63f79226357f2fe84acedb950e64383e582b17 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:39:41 +0200
Subject: [PATCH 1/5] 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 `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/transam/parallel.c         | 15 +++++++++++++++
 src/backend/utils/misc/guc_tables.c           | 12 ++++++++++++
 src/backend/utils/misc/postgresql.conf.sample |  1 +
 src/include/access/parallel.h                 | 19 +++++++++++++++++++
 5 files changed, 65 insertions(+)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index fbdd6ce574..3a5f7131b3 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7752,6 +7752,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 produced during the
+        execution of a parallel query or utility statement. 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/transam/parallel.c b/src/backend/access/transam/parallel.c
index 0a1e089ec1..e1d378efa6 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -1653,3 +1653,18 @@ LookupParallelWorkerFunction(const char *libraryname, const char *funcname)
 	return (parallel_worker_main_type)
 		load_external_function(libraryname, funcname, true, NULL);
 }
+
+/*
+ * The function determines if information about workers should
+ * be logged.
+*/
+bool
+LoggingParallelWorkers(int log_parallel_workers,
+					   int parallel_workers_to_launch,
+					   int parallel_workers_launched)
+{
+	return ((log_parallel_workers == LOG_PARALLEL_WORKERS_ALL &&
+			parallel_workers_to_launch > 0) ||
+			(log_parallel_workers == LOG_PARALLEL_WORKERS_FAILURE &&
+			parallel_workers_to_launch != parallel_workers_launched));
+}
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 8cf1afbad2..cc4d70177d 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;
@@ -5226,6 +5228,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 a2ac7575ca..f11bf173ff 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -622,6 +622,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..00aad1e742 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)
 
@@ -78,4 +93,8 @@ extern void ParallelWorkerReportLastRecEnd(XLogRecPtr last_xlog_end);
 
 extern void ParallelWorkerMain(Datum main_arg);
 
+extern bool LoggingParallelWorkers(int log_parallel_workers,
+								   int parallel_workers_to_launch,
+								   int parallel_workers_launched);
+
 #endif							/* PARALLEL_H */
-- 
2.47.0

V5_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchtext/x-patch; charset=UTF-8; name=V5_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchDownload
From 2894c62d8f550d6030d1327b322864805aaa8c5f Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:45:03 +0200
Subject: [PATCH 2/5] Implements logging for parallel worker usage in index
 builds

Two types of index are concerned: brin and btree.
---
 src/backend/access/brin/brin.c      | 7 +++++++
 src/backend/access/nbtree/nbtsort.c | 7 +++++++
 2 files changed, 14 insertions(+)

diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index 9af445cdcd..a19e1eed7f 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2544,6 +2544,13 @@ _brin_end_parallel(BrinLeader *brinleader, BrinBuildState *state)
 	/* Shutdown worker processes */
 	WaitForParallelWorkersToFinish(brinleader->pcxt);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   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 28522c0ac1..6459a01618 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1614,6 +1614,13 @@ _bt_end_parallel(BTLeader *btleader)
 	/* Shutdown worker processes */
 	WaitForParallelWorkersToFinish(btleader->pcxt);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   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.)
-- 
2.47.0

V5_0003-Setup-counters-for-parallel-vacuums.patchtext/x-patch; charset=UTF-8; name=V5_0003-Setup-counters-for-parallel-vacuums.patchDownload
From 477b08125e4131b2199ad7c38560c6ce3a0f63fd Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:56:23 +0200
Subject: [PATCH 3/5] Setup counters for parallel vacuums

Thsi can be used bu other patches such as the one for pg_stat_database.
---
 src/backend/commands/vacuumparallel.c | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 67cba17a56..7094c80dc6 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;
 
@@ -738,6 +744,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.47.0

V5_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchtext/x-patch; charset=UTF-8; name=V5_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchDownload
From a3c12d9991e6063025979c8fb3f90a256f8b42e0 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:58:40 +0200
Subject: [PATCH 4/5] Implements logging for parallel worker usage in vacuums

---
 src/backend/commands/vacuumparallel.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 7094c80dc6..efce9c155f 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -443,6 +443,13 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats)
 {
 	Assert(!IsParallelWorker());
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   pvs->nworkers_to_launch,
+							   pvs->nworkers_launched))
+		elog(LOG, "%i workers planned to be launched for index cleanup and bulkdelete (%i workers launched)",
+			pvs->nworkers_to_launch,
+			pvs->nworkers_launched);
+
 	/* Copy the updated statistics */
 	for (int i = 0; i < pvs->nindexes; i++)
 	{
-- 
2.47.0

V5_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchtext/x-patch; charset=UTF-8; name=V5_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchDownload
From 4886538cb5d2542b36af6793b8827d695a44ab5b Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Fri, 11 Oct 2024 23:59:15 +0200
Subject: [PATCH 5/5] Implements logging for parallel worker usage in queries

---
 src/backend/executor/execMain.c        | 11 +++++++++++
 src/backend/executor/execUtils.c       |  3 +++
 src/backend/executor/nodeGather.c      |  5 +++++
 src/backend/executor/nodeGatherMerge.c |  5 +++++
 src/include/nodes/execnodes.h          |  4 ++++
 5 files changed, 28 insertions(+)

diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 1c12d6ebff..81da8f5e17 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -485,6 +485,17 @@ standard_ExecutorEnd(QueryDesc *queryDesc)
 		pgstat_update_parallel_workers_stats((PgStat_Counter) estate->es_parallel_workers_to_launch,
 											 (PgStat_Counter) estate->es_parallel_workers_launched);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   estate->es_parallel_workers_to_launch,
+							   estate->es_parallel_workers_launched))
+		elog(LOG, "%i parallel nodes planned (%i obtained all their workers, %i obtained none), "
+				  "%i workers planned to be launched (%i workers launched)",
+			estate->es_parallel_nodes,
+			estate->es_parallel_nodes_success,
+			estate->es_parallel_nodes_no_workers,
+			estate->es_parallel_workers_to_launch,
+			estate->es_parallel_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 df0223129c..c38253f5e5 100644
--- a/src/backend/executor/execUtils.c
+++ b/src/backend/executor/execUtils.c
@@ -160,6 +160,9 @@ CreateExecutorState(void)
 	estate->es_use_parallel_mode = false;
 	estate->es_parallel_workers_to_launch = 0;
 	estate->es_parallel_workers_launched = 0;
+	estate->es_parallel_nodes = 0;
+	estate->es_parallel_nodes_success = 0;
+	estate->es_parallel_nodes_no_workers = 0;
 
 	estate->es_jit_flags = 0;
 	estate->es_jit = NULL;
diff --git a/src/backend/executor/nodeGather.c b/src/backend/executor/nodeGather.c
index 7f7edc7f9f..49a96f7cbf 100644
--- a/src/backend/executor/nodeGather.c
+++ b/src/backend/executor/nodeGather.c
@@ -188,6 +188,10 @@ ExecGather(PlanState *pstate)
 			 */
 			estate->es_parallel_workers_to_launch += pcxt->nworkers_to_launch;
 			estate->es_parallel_workers_launched += pcxt->nworkers_launched;
+			estate->es_parallel_nodes += 1;
+
+			if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+				estate->es_parallel_nodes_success += 1;
 
 			/* Set up tuple queue readers to read the results. */
 			if (pcxt->nworkers_launched > 0)
@@ -205,6 +209,7 @@ ExecGather(PlanState *pstate)
 				/* No workers?	Then never mind. */
 				node->nreaders = 0;
 				node->reader = NULL;
+				estate->es_parallel_nodes_no_workers += 1;
 			}
 			node->nextreader = 0;
 		}
diff --git a/src/backend/executor/nodeGatherMerge.c b/src/backend/executor/nodeGatherMerge.c
index bc99c0b448..f3aa7ee14f 100644
--- a/src/backend/executor/nodeGatherMerge.c
+++ b/src/backend/executor/nodeGatherMerge.c
@@ -229,6 +229,10 @@ ExecGatherMerge(PlanState *pstate)
 			 */
 			estate->es_parallel_workers_to_launch += pcxt->nworkers_to_launch;
 			estate->es_parallel_workers_launched += pcxt->nworkers_launched;
+			estate->es_parallel_nodes += 1;
+
+			if (pcxt->nworkers_to_launch == pcxt->nworkers_launched)
+				estate->es_parallel_nodes_success += 1;
 
 			/* Set up tuple queue readers to read the results. */
 			if (pcxt->nworkers_launched > 0)
@@ -246,6 +250,7 @@ ExecGatherMerge(PlanState *pstate)
 				/* No workers?	Then never mind. */
 				node->nreaders = 0;
 				node->reader = NULL;
+				estate->es_parallel_nodes_no_workers += 1;
 			}
 		}
 
diff --git a/src/include/nodes/execnodes.h b/src/include/nodes/execnodes.h
index 1590b64392..dd1fc5a18b 100644
--- a/src/include/nodes/execnodes.h
+++ b/src/include/nodes/execnodes.h
@@ -713,6 +713,10 @@ typedef struct EState
 	int			es_parallel_workers_launched;	/* number of workers actually
 												 * launched. */
 
+	int			es_parallel_nodes;
+	int			es_parallel_nodes_success;
+	int			es_parallel_nodes_no_workers;
+
 	/* The per-query shared memory area to use for parallel execution. */
 	struct dsa_area *es_query_dsa;
 
-- 
2.47.0

#32Sami Imseih
samimseih@gmail.com
In reply to: Benoit Lobréau (#31)
Re: Logging parallel worker draught

Thanks for rebasing.

I took a look and have some high level comments.

1/ The way the patches stand now, different parallel commands
will result in a different formatted log line. This may be
OK for reading the logs manually, but will be hard to
consume via tools that parse logs and if we support other
parallel commands in the future.

Thinking about this further, it seems to me this logging only makes sense
for parallel query and not maintenance commands. This is because
for the latter case, the commands are executed manually and a user can issue
VACUUM VERBOSE ( for the case of vacuum ). For CREATE INDEX, one
can enable DEBUG1. For example:

postgres=# CREATE INDEX tbl_c1 ON tbl(c1);
DEBUG: building index "tbl_c1" on table "tbl" with request for 1
parallel workers
DEBUG: index "tbl_c1" can safely use deduplication
CREATE INDEX

It does appear though the debug1 message is missing the number of workers
actually used, but this could be taken up in a separate discussion.

2/ For logging parallel query workers, the log line could be simpler.

Instead of:

+ elog(LOG, "%i parallel nodes planned (%i obtained all their workers,
%i obtained none), "
+ "%i workers planned to be launched (%i workers launched)",

what about something like:

"launched %d parallel workers (planned: %)"

For example, if I have 2 gather nodes and they each plan and launch
2 workers, the log line should be as simple as

"launched 4 parallel workers (planned: 4)"

This behavior in which workers planned and launched are aggregated in the
log can be described in the documentation.

3/ Also, log_parallel_query_workers as the name of the GUC will make more sense
if we go logging parallel query only.

What do you think?

Regards,

Sami Imseih
Amazon Web Services (AWS)

On Thu, Dec 26, 2024 at 8:25 AM Benoit Lobréau
<benoit.lobreau@dalibo.com> wrote:

Show quoted text

This is just a rebase.

As stated before, I added some information to the error message for
parallel queries as an experiment. It can be removed, if you re not
convinced.

---
Benoit Lobréau
Consultant
http://dalibo.com

#33Sami Imseih
samimseih@gmail.com
In reply to: Sami Imseih (#32)
Re: Logging parallel worker draught

I missed one more point earlier.

I don't think "failure" is a good name for the setting as it's
a bit too harsh. What we really have is a "shortage" of
workers.

Instead of
+ {"failure", LOG_PARALLEL_WORKERS_FAILURE, false},

what about?

{"shortage", LOG_PARALLEL_WORKERS_SHORTAGE, false},

Regards,

Sami

#34Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Sami Imseih (#32)
Re: Logging parallel worker draught

Hi, thank you for the review and sorry for the delayed answer.

On 12/28/24 05:17, Sami Imseih wrote:> Thinking about this further, it
seems to me this logging only makes sense

for parallel query and not maintenance commands. This is because
for the latter case, the commands are executed manually and a user

can issue

VACUUM VERBOSE ( for the case of vacuum ). For CREATE INDEX, one
can enable DEBUG1. For example:

postgres=# CREATE INDEX tbl_c1 ON tbl(c1);
DEBUG: building index "tbl_c1" on table "tbl" with request for 1
parallel workers
DEBUG: index "tbl_c1" can safely use deduplication
CREATE INDEX

In my opinion, it's useful:

* Centralization of logs: The maintenance operation can be planned in
cron jobs. In that context, it could certainly be logged separately via
the script. However, when I am doing an audit on a client database, I
think it's useful to have all the relevant information in PostgreSQL logs.

* Centralization of the configuration: If I am auditing the usage of
parallelism, I would like to have a single GUC to enable the logging
for all relevant information.

* Context: Maintenance workers are part of the global pool of workers.
To know why there is a shortage after the fact, having all the information
on what was using workers could be useful. I tied this argument when we
added the parallel worker info to pg_stat_database and wasn't successful.
It would be nice to have the info somewhere.

The logging for CREATE INDEX and VACUUM is in separate patches. If you
don't mind, I would like to keep it as long as possible.

2/ For logging parallel query workers, the log line could be simpler.

Instead of:

+ elog(LOG, "%i parallel nodes planned (%i obtained all their workers,
%i obtained none), "
+ "%i workers planned to be launched (%i workers launched)",

what about something like:

"launched %d parallel workers (planned: %)"

For example, if I have 2 gather nodes and they each plan and launch
2 workers, the log line should be as simple as

"launched 4 parallel workers (planned: 4)"

This behavior in which workers planned and launched are aggregated in the
log can be described in the documentation.

"%i parallel nodes planned (%i obtained all their workers, %i obtained
none),"

I added this part during my first reorganization. I was trying to extract
as much information as possible and thought that the special case where a
parallel node was planned but no workers were obtained was the worst-case
scenario, which might be interesting to log.

If you think it doesn't bring much value, we can strip it.

3/ Also, log_parallel_query_workers as the name of the GUC will make

more sense

if we go logging parallel query only.

I agree that log_parallel_query_workers would make more sense if we focus
on logging parallel queries only. Since the maintenance-related logging
was added later, I missed this point. Thank you for bringging this up.

If agreeable, I will rename the GUC to log_parallel_workers as long as
the argument regarding maintenance workers is unresolved. If we decide
to strip them, I will revert it to log_parallel_query_workers.

I don't think "failure" is a good name for the setting as it's
a bit too harsh. What we really have is a "shortage" of
workers.

I agree that "failure" is too harsh. The term "shortage" better describes
the situation.

Note: I added Tomas Vondra to the recipients of the email since he advised
me on this topic initially and might have an opinion on this.

--
Benoit Lobréau
Consultant
http://dalibo.com

#35Sami Imseih
samimseih@gmail.com
In reply to: Benoit Lobréau (#34)
Re: Logging parallel worker draught

* Centralization of logs: The maintenance operation can be planned in
cron jobs. In that context, it could certainly be logged separately via
the script. However, when I am doing an audit on a client database, I
think it's useful to have all the relevant information in PostgreSQL logs.

Maintenance work is usually planned, so if queries
issues by the applications are not launching enough workers, it's
easy to point the blame on the maintenance activity.

* Centralization of the configuration: If I am auditing the usage of
parallelism, I would like to have a single GUC to enable the logging
for all relevant information.
* Context: Maintenance workers are part of the global pool of workers.
To know why there is a shortage after the fact, having all the information
on what was using workers could be useful. I tied this argument when we
added the parallel worker info to pg_stat_database and wasn't successful.
It would be nice to have the info somewhere.

The logging for CREATE INDEX and VACUUM is in separate patches. If you
don't mind, I would like to keep it as long as possible.

Maybe it's better to log parallel maintenance workers separately actually
if there is a truly good justification for it. As it stands now, even
pg_stat_database
does not track maintenance workers. Maybe adding logging could also be part
of that discussion?

I think logging maintenance workers will be an odd experience.
For example, if a user runs "VACUUM VERBOSE sometable",
all details are sent to the client ( including the parallel worker )
and not the logs. I doubt putting this infor alone in the log will be useful.

Also, the CREATE INDEX provides this info in DEBUG1. Although,
I think we need a separate discussion to add the # of launched workers
to then output. And maybe some documentation on how to emit
the parallel worker info for CREATE INDEX.

I wonder if we should really just have a CREATE INDEX VERBOSE syntax.

Regards,

Sami

#36Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Sami Imseih (#35)
5 attachment(s)
Re: Logging parallel worker draught

Here is a new set of patches.

The following changed:

* rebase
* simplify the log message to go back to "launched X parallel workers
(planned: Y)"
* rename the "failure" configuration item to "shortage".

On 1/3/25 17:24, Sami Imseih wrote:> Maintenance work is usually
planned, so if queries

issues by the applications are not launching enough workers, it's
easy to point the blame on the maintenance activity.

I often work on systems I have no prior knowledge of. Some of these
systems have external schedulers. Having information in PostgreSQL's
logs is really useful in such cases.

Maybe it's better to log parallel maintenance workers separately actually
if there is a truly good justification for it. As it stands now, even
pg_stat_database
does not track maintenance workers. Maybe adding logging could also be part
of that discussion?

The original patch on pg_stat_database included this information. I
still think that having a centralized way to get the information is
important, whether in the logs and/or pg_stat_database (preferably both).

I feel that observability is important, and I don't understand why we
would want to have the information for only a portion of the
functionality's usage (even if it's the most important).

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

V6_0003-Setup-counters-for-parallel-vacuums.patchtext/x-patch; charset=UTF-8; name=V6_0003-Setup-counters-for-parallel-vacuums.patchDownload
From 3064562b08ca9ed447f19c6ea985d49138e41f79 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Mon, 20 Jan 2025 15:48:32 +0100
Subject: [PATCH 3/5] Setup counters for parallel vacuums

This can be used by other patches such as the one for pg_stat_database.
---
 src/backend/commands/vacuumparallel.c | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 0d92e694d6a..2d91fa2ae69 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;
 
@@ -738,6 +744,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.47.0

V6_0001-Add-a-guc-for-parallel-worker-logging.patchtext/x-patch; charset=UTF-8; name=V6_0001-Add-a-guc-for-parallel-worker-logging.patchDownload
From b99dc5c1c549921ed2ac054db4e8c5398543dfc4 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:39:41 +0200
Subject: [PATCH 1/5] 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         | 15 +++++++++++++++
 src/backend/utils/misc/guc_tables.c           | 12 ++++++++++++
 src/backend/utils/misc/postgresql.conf.sample |  1 +
 src/include/access/parallel.h                 | 19 +++++++++++++++++++
 5 files changed, 65 insertions(+)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index a8866292d46..095bb751183 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7611,6 +7611,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 produced during the
+        execution of a parallel query or utility statement. The default value is
+        <literal>none</literal> which disables logging. <literal>all</literal> displays
+        information for all parallel queries or utilities, whereas <literal>shortage</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/transam/parallel.c b/src/backend/access/transam/parallel.c
index 7817bedc2ef..d5b630e055b 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -1659,3 +1659,18 @@ LookupParallelWorkerFunction(const char *libraryname, const char *funcname)
 	return (parallel_worker_main_type)
 		load_external_function(libraryname, funcname, true, NULL);
 }
+
+/*
+ * The function determines if information about workers should
+ * be logged.
+*/
+bool
+LoggingParallelWorkers(int log_parallel_workers,
+					   int parallel_workers_to_launch,
+					   int parallel_workers_launched)
+{
+	return ((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));
+}
diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c
index 38cb9e970d5..fe38758fd57 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;
@@ -5236,6 +5238,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 079efa1baa7..94da28977cc 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -614,6 +614,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 8811618acb7..46df6e7de65 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_SHORTAGE,
+} 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},
+	{"shortage", LOG_PARALLEL_WORKERS_SHORTAGE, 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)
 
@@ -78,4 +93,8 @@ extern void ParallelWorkerReportLastRecEnd(XLogRecPtr last_xlog_end);
 
 extern void ParallelWorkerMain(Datum main_arg);
 
+extern bool LoggingParallelWorkers(int log_parallel_workers,
+								   int parallel_workers_to_launch,
+								   int parallel_workers_launched);
+
 #endif							/* PARALLEL_H */
-- 
2.47.0

V6_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchtext/x-patch; charset=UTF-8; name=V6_0002-Implements-logging-for-parallel-worker-usage-in-inde.patchDownload
From 2ac1032e64e30c65863b76a4616fc509e7be6fe0 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:45:03 +0200
Subject: [PATCH 2/5] Implements logging for parallel worker usage in index
 builds

Two types of index are concerned: brin and btree.
---
 src/backend/access/brin/brin.c      | 7 +++++++
 src/backend/access/nbtree/nbtsort.c | 7 +++++++
 2 files changed, 14 insertions(+)

diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index 4289142e20b..a081974fe2c 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2544,6 +2544,13 @@ _brin_end_parallel(BrinLeader *brinleader, BrinBuildState *state)
 	/* Shutdown worker processes */
 	WaitForParallelWorkersToFinish(brinleader->pcxt);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   brinleader->pcxt->nworkers_to_launch,
+							   brinleader->pcxt->nworkers_launched))
+		elog(LOG, "launched %i parallel workers (planned: %i)",
+			brinleader->pcxt->nworkers_launched,
+			brinleader->pcxt->nworkers_to_launch);
+
 	/*
 	 * 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 7aba852db90..db3f19bcf50 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1614,6 +1614,13 @@ _bt_end_parallel(BTLeader *btleader)
 	/* Shutdown worker processes */
 	WaitForParallelWorkersToFinish(btleader->pcxt);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   btleader->pcxt->nworkers_to_launch,
+							   btleader->pcxt->nworkers_launched))
+		elog(LOG, "launched %i parallel workers (planned: %i)",
+			btleader->pcxt->nworkers_launched,
+			btleader->pcxt->nworkers_to_launch);
+
 	/*
 	 * Next, accumulate WAL usage.  (This must wait for the workers to finish,
 	 * or we might get incomplete data.)
-- 
2.47.0

V6_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchtext/x-patch; charset=UTF-8; name=V6_0004-Implements-logging-for-parallel-worker-usage-in-vacu.patchDownload
From 6ec49fac6c6dead5affe9953f3fd10af61a7c9ad Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Mon, 20 Jan 2025 15:49:54 +0100
Subject: [PATCH 4/5] Implements logging for parallel worker usage in vacuums

---
 src/backend/commands/vacuumparallel.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 2d91fa2ae69..a34769e0505 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -443,6 +443,13 @@ parallel_vacuum_end(ParallelVacuumState *pvs, IndexBulkDeleteResult **istats)
 {
 	Assert(!IsParallelWorker());
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   pvs->nworkers_to_launch,
+							   pvs->nworkers_launched))
+		elog(LOG, "launched %i parallel workers (planned: %i)",
+			pvs->nworkers_launched,
+			pvs->nworkers_to_launch);
+
 	/* Copy the updated statistics */
 	for (int i = 0; i < pvs->nindexes; i++)
 	{
-- 
2.47.0

V6_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchtext/x-patch; charset=UTF-8; name=V6_0005-Implements-logging-for-parallel-worker-usage-in-quer.patchDownload
From 993e1cca0a78f7c8724b50cb315899de83954658 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Mon, 20 Jan 2025 15:51:16 +0100
Subject: [PATCH 5/5] Implements logging for parallel worker usage in queries

---
 src/backend/executor/execMain.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index fb8dba3ab2c..671722def4b 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -485,6 +485,13 @@ standard_ExecutorEnd(QueryDesc *queryDesc)
 		pgstat_update_parallel_workers_stats((PgStat_Counter) estate->es_parallel_workers_to_launch,
 											 (PgStat_Counter) estate->es_parallel_workers_launched);
 
+	if (LoggingParallelWorkers(log_parallel_workers,
+							   estate->es_parallel_workers_to_launch,
+							   estate->es_parallel_workers_launched))
+		elog(LOG, "launched %i parallel workers (planned: %i)",
+			estate->es_parallel_workers_launched,
+			estate->es_parallel_workers_to_launch);
+
 	/*
 	 * Check that ExecutorFinish was called, unless in EXPLAIN-only mode. This
 	 * Assert is needed because ExecutorFinish is new as of 9.1, and callers
-- 
2.47.0

#37Sami Imseih
samimseih@gmail.com
In reply to: Benoit Lobréau (#36)
Re: Logging parallel worker draught

I feel that observability is important, and I don't understand why we
would want to have the information for only a portion of the
functionality's usage (even if it's the most important).

In my opinion, the requirement for parallel usage in
the utility statement is different. In fact, I think the story
there needs improvement as is being discussed in [1]/messages/by-id/CAA5RZ0trTUL6_vpvW79daGgkp7B-ZtWUc5yrPz5Sjm8Ns4KRgQ@mail.gmail.com
by introducing something like a VERBOSE.

Here is the kind of case I think will be a bit odd if we
introduce the parallel logging for vacuum in V6_0003
and V6_0004.

postgres=# set client_min_messages = LOG;
SET
postgres=# set log_parallel_workers = "all";
SET
postgres=# vacuum (verbose, parallel 4) t ;
INFO: vacuuming "postgres.public.t"
INFO: launched 2 parallel vacuum workers for index vacuuming (planned: 2)
LOG: launched 2 parallel workers (planned: 2)
INFO: table "t": truncated 17242 to 0 pages
INFO: finished vacuuming "postgres.public.t": index scans: 1
pages: 17242 removed, 0 remain, 17242 scanned (100.00% of total)

There will both be an INFO ( existing behavior ) and LOG ( new behavior ).
This seems wrong to me and there should only really be one
mechanism to log parallel workers for utility statements.
Others may have different opinions.

I also have a few comments on V6

1/
For the new comments.

Change:
"workers is produced"
To
"workers is emitted"

"emit" is used mainly to describe logs.

Also, change "displays" to "emits"

2/
Should the function LoggingParallelWorkers do all the work,
including logging? This way the callers just need to
call the function without checking for the return
value? Currently, the patch just repeats the same
logging calls everywhere it's needed.

Maybe use a void returning function called
LogParallelWorkersIfNeeded for this purpose?

Regards,

Sami

[1]: /messages/by-id/CAA5RZ0trTUL6_vpvW79daGgkp7B-ZtWUc5yrPz5Sjm8Ns4KRgQ@mail.gmail.com

#38Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Sami Imseih (#37)
4 attachment(s)
Re: Logging parallel worker draught

On 1/29/25 12:41 AM, Sami Imseih wrote:

There will both be an INFO ( existing behavior ) and LOG ( new behavior ).
This seems wrong to me and there should only really be one
mechanism to log parallel workers for utility statements.
Others may have different opinions.

In the use case you describe, I agree that the VERBOSE option is more
suited for the job. But it's not the use case I had in mind for this
guc.

The "story" I have in mind is: I need to audit an instance I know
nothing about. I ask the client to adapt the logging parameters for
pgbadger (including this one), collect the logs and generate a report
for the said period to have a broad overview of what is happenning.

I attached patches that implemented both your suggestions (I regrouped
all the utilities together).

Thank you !

--
Benoit Lobréau
Consultant
http://dalibo.com

Attachments:

V7_0001-Add-a-guc-for-parallel-worker-logging.patchtext/x-patch; charset=UTF-8; name=V7_0001-Add-a-guc-for-parallel-worker-logging.patchDownload
From 5ae1a4e619c1d7c8e899641e16dda831e792438d Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:39:41 +0200
Subject: [PATCH 1/4] 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         | 18 ++++++++++++++++++
 src/backend/utils/misc/guc_tables.c           | 12 ++++++++++++
 src/backend/utils/misc/postgresql.conf.sample |  1 +
 src/include/access/parallel.h                 | 19 +++++++++++++++++++
 5 files changed, 68 insertions(+)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index a782f109982..f8c879f1c10 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7612,6 +7612,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 7817bedc2ef..d18d203d178 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -1659,3 +1659,21 @@ LookupParallelWorkerFunction(const char *libraryname, const char *funcname)
 	return (parallel_worker_main_type)
 		load_external_function(libraryname, funcname, true, NULL);
 }
+
+/*
+ * This function emits information about workers in the logs depending
+ * on the setting of log_parallel_workers
+ */
+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))
+		elog(LOG, "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 38cb9e970d5..fe38758fd57 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;
@@ -5236,6 +5238,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 079efa1baa7..94da28977cc 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -614,6 +614,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 8811618acb7..a5bc98a3223 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_SHORTAGE,
+} 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},
+	{"shortage", LOG_PARALLEL_WORKERS_SHORTAGE, 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)
 
@@ -78,4 +93,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 */
-- 
2.48.1

V7_0002-Setup-counters-for-parallel-vacuums.patchtext/x-patch; charset=UTF-8; name=V7_0002-Setup-counters-for-parallel-vacuums.patchDownload
From 803d4871677d4b36d4a5fdfc1521c0680cd0c6e0 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Mon, 20 Jan 2025 15:48:32 +0100
Subject: [PATCH 2/4] Setup counters for parallel vacuums

This can be used by other patches such as the one for pg_stat_database.
---
 src/backend/commands/vacuumparallel.c | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 0d92e694d6a..2d91fa2ae69 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;
 
@@ -738,6 +744,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

V7_0003-Implements-logging-for-parallel-worker-usage-in-util.patchtext/x-patch; charset=UTF-8; name=V7_0003-Implements-logging-for-parallel-worker-usage-in-util.patchDownload
From 4a6c618fce16a13c2db8a0ec1a1defdd7a95f157 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Wed, 29 Jan 2025 17:10:57 +0100
Subject: [PATCH 3/4] 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 and brin index builds.
---
 src/backend/access/brin/brin.c        | 4 ++++
 src/backend/access/nbtree/nbtsort.c   | 4 ++++
 src/backend/commands/vacuumparallel.c | 4 ++++
 3 files changed, 12 insertions(+)

diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index 4289142e20b..d15bfcb6e7e 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2544,6 +2544,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/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index 7aba852db90..28574d27c7d 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1614,6 +1614,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 2d91fa2ae69..8d411df2e3a 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -443,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++)
 	{
-- 
2.48.1

V7_0004-Implements-logging-for-parallel-worker-usage-in-quer.patchtext/x-patch; charset=UTF-8; name=V7_0004-Implements-logging-for-parallel-worker-usage-in-quer.patchDownload
From 24674646aeeb4d8d707ee9ef277a4b07bee3b8d5 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Wed, 29 Jan 2025 17:15:25 +0100
Subject: [PATCH 4/4] Implements logging for parallel worker usage in queries

---
 src/backend/executor/execMain.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index fb8dba3ab2c..4d898acce8b 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -485,6 +485,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. This
 	 * Assert is needed because ExecutorFinish is new as of 9.1, and callers
-- 
2.48.1

#39Sami Imseih
samimseih@gmail.com
In reply to: Benoit Lobréau (#38)
4 attachment(s)
Re: Logging parallel worker draught

The "story" I have in mind is: I need to audit an instance I know
nothing about. I ask the client to adapt the logging parameters for
pgbadger (including this one), collect the logs and generate a report
for the said period to have a broad overview of what is happenning.

Let's see if anyone has a different opinion.

As far as the current set of patches, I had some other changes that
I missed earlier; indentation to the calls in LogParallelWorkersIfNeeded
and comment for the LogParallelWorkersIfNeeded function. I also re-worked the
setup of the GUC as it was not setup the same way as other
GUCs with an options list. I ended up just making those changes
in v8.

Besides that, I think this is ready for committer.

Regards,

Sami

Attachments:

v8-0002-Setup-counters-for-parallel-vacuums.patchapplication/octet-stream; name=v8-0002-Setup-counters-for-parallel-vacuums.patchDownload
From 23e98f7c6f6551b64ec42bd17cad1c3bb1252c4f Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Mon, 20 Jan 2025 15:48:32 +0100
Subject: [PATCH v8 2/4] Setup counters for parallel vacuums

This can be used by other patches such as the one for pg_stat_database.
---
 src/backend/commands/vacuumparallel.c | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index dc3322c256..b63a4c0c55 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;
 
@@ -738,6 +744,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.47.1

v8-0001-Add-a-guc-for-parallel-worker-logging.patchapplication/octet-stream; name=v8-0001-Add-a-guc-for-parallel-worker-logging.patchDownload
From 60a9b106a05d0a49cc95a0f53a3c5a6b7c8aa47d Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Tue, 8 Oct 2024 12:39:41 +0200
Subject: [PATCH v8 1/4] 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 a782f10998..f8c879f1c1 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7612,6 +7612,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 7817bedc2e..0a58abdbba 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -1659,3 +1659,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 71448bb4fd..6697f04d11 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -28,6 +28,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"
@@ -423,6 +424,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");
 
@@ -526,6 +534,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;
@@ -5190,6 +5199,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 079efa1baa..94da28977c 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -614,6 +614,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 8811618acb..68a904e294 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 1233e07d7d..01f132d324 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.47.1

v8-0003-Implements-logging-for-parallel-worker-usage-in-u.patchapplication/octet-stream; name=v8-0003-Implements-logging-for-parallel-worker-usage-in-u.patchDownload
From 6819dc47ad96a98dc16cab8237161ccebc580695 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Wed, 29 Jan 2025 17:10:57 +0100
Subject: [PATCH v8 3/4] 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 and brin index builds.
---
 src/backend/access/brin/brin.c        | 4 ++++
 src/backend/access/nbtree/nbtsort.c   | 4 ++++
 src/backend/commands/vacuumparallel.c | 4 ++++
 3 files changed, 12 insertions(+)

diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index ccf824bbdb..0435522dd5 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2546,6 +2546,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/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index 7aba852db9..0877350d9c 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1614,6 +1614,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 b63a4c0c55..182dba0f36 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -443,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++)
 	{
-- 
2.47.1

v8-0004-Implements-logging-for-parallel-worker-usage-in-q.patchapplication/octet-stream; name=v8-0004-Implements-logging-for-parallel-worker-usage-in-q.patchDownload
From 601b2ce6dc442e40fab28cb323b1289fda3aa8d2 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@dalibo.com>
Date: Wed, 29 Jan 2025 17:15:25 +0100
Subject: [PATCH v8 4/4] Implements logging for parallel worker usage in
 queries

---
 src/backend/executor/execMain.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 604cb0625b..7366a18a54 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -486,6 +486,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. This
 	 * Assert is needed because ExecutorFinish is new as of 9.1, and callers
-- 
2.47.1

#40Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Sami Imseih (#39)
Re: Logging parallel worker draught

On 2/3/25 6:36 AM, Sami Imseih wrote:

As far as the current set of patches, I had some other changes that
I missed earlier; indentation to the calls in LogParallelWorkersIfNeeded
and comment for the LogParallelWorkersIfNeeded function. I also re-worked the
setup of the GUC as it was not setup the same way as other
GUCs with an options list. I ended up just making those changes
in v8.

Besides that, I think this is ready for committer.

Thank you for your time and advice on this.

--
Benoit Lobréau
Consultant
http://dalibo.com

#41Melanie Plageman
melanieplageman@gmail.com
In reply to: Sami Imseih (#39)
Re: Logging parallel worker draught

On Mon, Feb 3, 2025 at 12:37 AM Sami Imseih <samimseih@gmail.com> wrote:

Besides that, I think this is ready for committer.

I started looking at this, and I like the idea.

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.

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.

Since your last update, it seems parallel gin index build has been
committed, so perhaps you want to add that.

- Melanie

#42Benoit Lobréau
benoit.lobreau@dalibo.com
In reply to: Melanie Plageman (#41)
3 attachment(s)
Re: Logging parallel worker draught

On 4/7/25 6:41 PM, Melanie Plageman wrote:

On Mon, Feb 3, 2025 at 12:37 AM Sami Imseih <samimseih@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]https://commitfest.postgresql.org/patch/5212/, 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

Attachments:

v9-0001-Add-a-guc-for-parallel-worker-logging.patchtext/x-patch; charset=UTF-8; name=v9-0001-Add-a-guc-for-parallel-worker-logging.patchDownload
From 59cd090e78a5833b901ad662d6ae1ae936c3172d Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@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

v9-0002-Implements-logging-for-parallel-worker-usage-in-util.patchtext/x-patch; charset=UTF-8; name=v9-0002-Implements-logging-for-parallel-worker-usage-in-util.patchDownload
From 7184271007622c7fe2f1e3c09506a38e4e874187 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@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

v9-0003-Implements-logging-for-parallel-worker-usage-in-quer.patchtext/x-patch; charset=UTF-8; name=v9-0003-Implements-logging-for-parallel-worker-usage-in-quer.patchDownload
From 5938cbfcc7b46c9c5e9c87c64ab81d9af58c7d41 Mon Sep 17 00:00:00 2001
From: benoit <benoit.lobreau@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

#43Sami Imseih
samimseih@gmail.com
In reply to: Benoit Lobréau (#42)
Re: Logging parallel worker draught

Hi,

This seems to have flown under the radar. I still think it's a good
feature even if we have parallel logging in pg_stat_database and
pg_stat_statements (e7a9496de and cf54a2c002)

You’ll find the updated patch attached.

[1] https://commitfest.postgresql.org/patch/5212/

The latest patchset needs rebasing.

--
Sami Imseih
Amazon Web Services (AWS)