public inbox for [email protected]  
help / color / mirror / Atom feed
From: Benoit Lobréau <[email protected]>
To: pgsql-hackers <[email protected]>
Cc: Melanie Plageman <[email protected]>
Subject: Logging parallel worker draught
Date: Fri, 21 Apr 2023 15:04:01 +0200
Message-ID: <[email protected]> (raw)

Hi hackers,

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. 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] 
https://www.postgresql.org/message-id/[email protected]

-- 
Benoit Lobréau
Consultant
http://dalibo.com
From f7d3dae918df2dbbe7fd18cf48f7ca39d5716c73 Mon Sep 17 00:00:00 2001
From: benoit <[email protected]>
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



Attachments:

  [text/plain] 0001-Add-logging-for-exceeded-parallel-worker-slot-limits.patch_v1 (4.8K, ../[email protected]/2-0001-Add-logging-for-exceeded-parallel-worker-slot-limits.patch_v1)
  download | inline diff:
From f7d3dae918df2dbbe7fd18cf48f7ca39d5716c73 Mon Sep 17 00:00:00 2001
From: benoit <[email protected]>
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



view thread (2+ messages)

reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: [email protected]
  Cc: [email protected], [email protected]
  Subject: Re: Logging parallel worker draught
  In-Reply-To: <[email protected]>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox