Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 31, 2020 at 10:31:13PM -0500, Justin Pryzby wrote: > Also, I was reminded by Tom's c410af098 about this comment: > > * Further note: At least on some platforms, passing %*s > rather than > * %s to appendStringInfo() is substantially slower, so many > of the > * cases below avoid doing that unless non-zero padding is in > fact > * specified. > > It seems we can remove that hack and avoid its spiriling conditionals. > It's cleaner to make that 0001. Not sure what 0001 is doing on this thread, so I would suggest to create a new thread for that to attract the correct audience. It is true that we should not need that anymore as we use our own implementation of sprintf now. For now, I have taken 0002 as a base, fixed a couple of things (doc tweaks, removed unnecessary header inclusion, etc.), and committed it, meaning that we are done here. -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 31, 2020 at 03:04:48PM -0500, Justin Pryzby wrote:
> On Tue, Jul 28, 2020 at 10:10:33AM +0900, Michael Paquier wrote:
> > Except for those nits, I have tested the patch and things behave as we
> > want (including padding and docs), so this looks good to me.
>
> Revised with your suggestions.
Uh, wrong patch. 2nd attempt.
Also, I was reminded by Tom's c410af098 about this comment:
* Further note: At least on some platforms, passing %*s rather
than
* %s to appendStringInfo() is substantially slower, so many of
the
* cases below avoid doing that unless non-zero padding is in
fact
* specified.
It seems we can remove that hack and avoid its spiriling conditionals.
It's cleaner to make that 0001.
--
Justin
>From 2b27a52ff93f1352fc9550837422374eab08813b Mon Sep 17 00:00:00 2001
From: Justin Pryzby
Date: Fri, 31 Jul 2020 21:53:01 -0500
Subject: [PATCH v5 1/2] Remove performance hack for %*s format strings..
..which should no longer be needed since it was a performance hack for specific
platform snprintf, which are no longer used.
See also:
4334639f4 Allow printf-style padding specifications in log_line_prefix.
96bf88d52 Always use our own versions of *printf().
abd9ca377 Make assorted performance improvements in snprintf.c.
---
src/backend/utils/error/elog.c | 134 -
1 file changed, 32 insertions(+), 102 deletions(-)
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index e4b717c79a..b0b1a09ab1 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -2350,11 +2350,6 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
* Note: Since only '-', '0' to '9' are valid formatting characters we
* can do a quick check here to pre-check for formatting. If the char
* is not formatting then we can skip a useless function call.
- *
- * Further note: At least on some platforms, passing %*s rather than
- * %s to appendStringInfo() is substantially slower, so many of the
- * cases below avoid doing that unless non-zero padding is in fact
- * specified.
*/
if (*p > '9')
padding = 0;
@@ -2371,10 +2366,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
if (appname == NULL || *appname == '\0')
appname = _("[unknown]");
- if (padding != 0)
- appendStringInfo(buf, "%*s", padding, appname);
- else
- appendStringInfoString(buf, appname);
+ appendStringInfo(buf, "%*s", padding, appname);
}
else if (padding != 0)
appendStringInfoSpaces(buf,
@@ -2392,10 +2384,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
else
backend_type_str = GetBackendTypeDesc(MyBackendType);
- if (padding != 0)
- appendStringInfo(buf, "%*s", padding, backend_type_str);
- else
- appendStringInfoString(buf, backend_type_str);
+ appendStringInfo(buf, "%*s", padding, backend_type_str);
break;
}
case 'u':
@@ -2405,10 +2394,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
if (username == NULL || *username == '\0')
username = _("[unknown]");
- if (padding != 0)
- appendStringInfo(buf, "%*s", padding, username);
- else
- appendStringInfoString(buf, username);
+ appendStringInfo(buf, "%*s", padding, username);
}
else if (padding != 0)
appendStringInfoSpaces(buf,
@@ -2421,17 +2407,13 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
if (dbname == NULL || *dbname == '\0')
dbname = _("[unknown]");
- if (padding != 0)
- appendStringInfo(buf, "%*s", padding, dbname);
- else
- appendStringInfoString(buf, dbname);
+ appendStringInfo(buf, "%*s", padding, dbname);
}
else if (padding != 0)
appendStringInfoSpaces(buf,
padding > 0 ? padding : -padding);
break;
case 'c':
-if (padding != 0)
{
char strfbuf[128];
@@ -2439,27 +2421,16 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
(long) (MyStartTime), MyProcPid);
appendStringInfo(buf, "%*s", padding, strfbuf);
}
-else
- appendStringInfo(buf, "%lx.%x", (long) (MyStartTime), MyProcPid);
break;
case 'p':
-if (padding != 0)
- appendStringInfo(buf, "%*d", padding, MyProcPid);
-else
- appendStringInfo(buf, "%d", MyProcPid);
+appendStringInfo(buf, "%*d", padding, MyProcPid);
break;
case 'l':
-if (padding != 0)
- appendStringInfo(buf, "%*ld", padding, log_line_number);
-else
- appendStringInfo(buf, "%ld", log_line_number);
+appendStringInfo(buf, "%*ld", padding, log_line_number);
break;
case 'm':
setup_formatted_log_time();
-if (padding != 0)
- appendStringInfo(buf, "%*s", padding, formatted_log_time);
-else
- appendStringInfoString(buf, formatted_log_time);
+appendStringInfo(buf, "%*s", padding, formatted_log_time);
break;
case 't':
Re: expose parallel leader in CSV and log_line_prefix
On Tue, Jul 28, 2020 at 10:10:33AM +0900, Michael Paquier wrote:
> Except for those nits, I have tested the patch and things behave as we
> want (including padding and docs), so this looks good to me.
Revised with your suggestions.
--
Justin
>From 72184bdb83eba6e477a12b743bb8d6bf938c5f41 Mon Sep 17 00:00:00 2001
From: Justin Pryzby
Date: Fri, 13 Mar 2020 22:03:06 -0500
Subject: [PATCH v4] Include the leader PID in logfile
See also: b025f32e0b, which added the leader PID to pg_stat_activity
---
doc/src/sgml/config.sgml | 10 ++-
src/backend/utils/error/elog.c| 30 +++
src/backend/utils/misc/postgresql.conf.sample | 1 +
3 files changed, 40 insertions(+), 1 deletion(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 994155ca00..89dd19035c 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -6694,6 +6694,13 @@ local0.*/var/log/postgresql
Process ID
no
+
+ %P
+ For a parallel worker, this is the Process ID of its leader
+ process.
+
+ no
+
%t
Time stamp without milliseconds
@@ -7026,7 +7033,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
character count of the error position therein,
location of the error in the PostgreSQL source code
(if log_error_verbosity is set to verbose),
-application name, and backend type.
+application name, backend type, and leader PID.
Here is a sample table definition for storing CSV-format log output:
@@ -7056,6 +7063,7 @@ CREATE TABLE postgres_log
location text,
application_name text,
backend_type text,
+ leader_pid integer,
PRIMARY KEY (session_id, session_line_num)
);
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index e4b717c79a..3055b72c01 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -77,6 +77,7 @@
#include "postmaster/syslogger.h"
#include "storage/ipc.h"
#include "storage/proc.h"
+#include "storage/procarray.h"
#include "tcop/tcopprot.h"
#include "utils/guc.h"
#include "utils/memutils.h"
@@ -2448,6 +2449,25 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
else
appendStringInfo(buf, "%d", MyProcPid);
break;
+
+ case 'P':
+if (MyProc)
+{
+ PGPROC *leader = MyProc->lockGroupLeader;
+ if (leader == NULL || leader->pid == MyProcPid)
+ /* padding only */
+ appendStringInfoSpaces(buf,
+padding > 0 ? padding : -padding);
+ else if (padding != 0)
+ appendStringInfo(buf, "%*d", padding, leader->pid);
+ else
+ appendStringInfo(buf, "%d", leader->pid);
+}
+else if (padding != 0)
+ appendStringInfoSpaces(buf,
+ padding > 0 ? padding : -padding);
+break;
+
case 'l':
if (padding != 0)
appendStringInfo(buf, "%*ld", padding, log_line_number);
@@ -2836,6 +2856,16 @@ write_csvlog(ErrorData *edata)
else
appendCSVLiteral(, GetBackendTypeDesc(MyBackendType));
+ appendStringInfoChar(, ',');
+
+ /* leader PID */
+ if (MyProc)
+ {
+ PGPROC *leader = MyProc->lockGroupLeader;
+ if (leader && leader->pid != MyProcPid)
+ appendStringInfo(, "%d", leader->pid);
+ }
+
appendStringInfoChar(, '\n');
/* If in the syslogger process, try to write messages direct to file */
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index b0715ae188..1ecdfc51a6 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -537,6 +537,7 @@
# %h = remote host
# %b = backend type
# %p = process ID
+ # %P = leader PID
# %t = timestamp without milliseconds
# %m = timestamp with milliseconds
# %n = timestamp with milliseconds (as a Unix epoch)
--
2.17.0
Re: expose parallel leader in CSV and log_line_prefix
On Sun, Jul 26, 2020 at 01:54:27PM -0500, Justin Pryzby wrote:
> +
> + %P
> + For a parallel worker, this is the Process ID of its
> leader
> + process.
> +
> + no
> +
Let's be a maximum simple and consistent with surrounding descriptions
here and what we have for pg_stat_activity, say:
"Process ID of the parallel group leader, if this process is a
parallel query worker."
> +case 'P':
> +if (MyProc)
> +{
> +PGPROC *leader = MyProc->lockGroupLeader;
> +if (leader == NULL || leader->pid == MyProcPid)
> +/* padding only */
> +appendStringInfoSpaces(buf,
> +padding > 0 ? padding : -padding);
> +else if (padding != 0)
> +appendStringInfo(buf, "%*d", padding, leader->pid);
> +else
> +appendStringInfo(buf, "%d", leader->pid);
It seems to me we should document here that the check on MyProcPid
ensures that this only prints the leader PID only for parallel workers
and discards the leader.
> +appendStringInfoChar(, ',');
> +
> +/* leader PID */
> +if (MyProc)
> +{
> +PGPROC *leader = MyProc->lockGroupLeader;
> +if (leader && leader->pid != MyProcPid)
> +appendStringInfo(, "%d", leader->pid);
> +}
> +
Same here.
Except for those nits, I have tested the patch and things behave as we
want (including padding and docs), so this looks good to me.
--
Michael
signature.asc
Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On Sun, Jul 26, 2020 at 04:42:06PM +0900, Michael Paquier wrote:
> On Thu, Jul 23, 2020 at 09:52:14AM +0900, Michael Paquier wrote:
> > Sounds fine to me. Thanks.
> >
> > Do others have any objections with this wording?
>
> I have used the wording suggested by Alvaro, and applied the patch
> down to 13. Now let's see about the original item of this thread..
Updated with updated wording to avoid "null", per Tom.
--
Justin
>From 665c9ea8827d4ad94ea0100c5ba93dbf05db5943 Mon Sep 17 00:00:00 2001
From: Justin Pryzby
Date: Fri, 13 Mar 2020 22:03:06 -0500
Subject: [PATCH v3] Include the leader PID in logfile
See also: b025f32e0b, which adds the leader PID to pg_stat_activity
---
doc/src/sgml/config.sgml | 10 ++-
src/backend/utils/error/elog.c| 30 +++
src/backend/utils/misc/postgresql.conf.sample | 1 +
3 files changed, 40 insertions(+), 1 deletion(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index e806b13754..c525a0fd15 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -6687,6 +6687,13 @@ local0.*/var/log/postgresql
Process ID
no
+
+ %P
+ For a parallel worker, this is the Process ID of its leader
+ process.
+
+ no
+
%t
Time stamp without milliseconds
@@ -7019,7 +7026,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
character count of the error position therein,
location of the error in the PostgreSQL source code
(if log_error_verbosity is set to verbose),
-application name, and backend type.
+application name, backend type, and leader PID.
Here is a sample table definition for storing CSV-format log output:
@@ -7049,6 +7056,7 @@ CREATE TABLE postgres_log
location text,
application_name text,
backend_type text,
+ leader_pid integer,
PRIMARY KEY (session_id, session_line_num)
);
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index e4b717c79a..3055b72c01 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -77,6 +77,7 @@
#include "postmaster/syslogger.h"
#include "storage/ipc.h"
#include "storage/proc.h"
+#include "storage/procarray.h"
#include "tcop/tcopprot.h"
#include "utils/guc.h"
#include "utils/memutils.h"
@@ -2448,6 +2449,25 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
else
appendStringInfo(buf, "%d", MyProcPid);
break;
+
+ case 'P':
+if (MyProc)
+{
+ PGPROC *leader = MyProc->lockGroupLeader;
+ if (leader == NULL || leader->pid == MyProcPid)
+ /* padding only */
+ appendStringInfoSpaces(buf,
+padding > 0 ? padding : -padding);
+ else if (padding != 0)
+ appendStringInfo(buf, "%*d", padding, leader->pid);
+ else
+ appendStringInfo(buf, "%d", leader->pid);
+}
+else if (padding != 0)
+ appendStringInfoSpaces(buf,
+ padding > 0 ? padding : -padding);
+break;
+
case 'l':
if (padding != 0)
appendStringInfo(buf, "%*ld", padding, log_line_number);
@@ -2836,6 +2856,16 @@ write_csvlog(ErrorData *edata)
else
appendCSVLiteral(, GetBackendTypeDesc(MyBackendType));
+ appendStringInfoChar(, ',');
+
+ /* leader PID */
+ if (MyProc)
+ {
+ PGPROC *leader = MyProc->lockGroupLeader;
+ if (leader && leader->pid != MyProcPid)
+ appendStringInfo(, "%d", leader->pid);
+ }
+
appendStringInfoChar(, '\n');
/* If in the syslogger process, try to write messages direct to file */
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index aa30291ea3..55c2e23c47 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -536,6 +536,7 @@
# %h = remote host
# %b = backend type
# %p = process ID
+ # %P = leader PID
# %t = timestamp without milliseconds
# %m = timestamp with milliseconds
# %n = timestamp with milliseconds (as a Unix epoch)
--
2.17.0
Re: expose parallel leader in CSV and log_line_prefix
On Thu, Jul 23, 2020 at 09:52:14AM +0900, Michael Paquier wrote: > Sounds fine to me. Thanks. > > Do others have any objections with this wording? I have used the wording suggested by Alvaro, and applied the patch down to 13. Now let's see about the original item of this thread.. -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On Wed, Jul 22, 2020 at 08:59:04PM -0400, Tom Lane wrote: > Is "NULL" really le mot juste here? If we're talking about text strings, > as the thread title implies (I've not read the patch), then I think you > should say "empty string", because the SQL concept of null doesn't apply. Sorry for the confusion. This part of the thread applies to the open item for v13 related to pg_stat_activity's leader_pid. A different thread should have been spawned for this specific topic, but things are as they are.. -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
Michael Paquier writes: > On Wed, Jul 22, 2020 at 11:36:05AM -0400, Alvaro Herrera wrote: >> How about we combine both. "Process ID of the parallel group leader, if >> this process is a parallel query worker. NULL if this process is a >> parallel group leader or does not participate in parallel query". > Sounds fine to me. Thanks. > Do others have any objections with this wording? Is "NULL" really le mot juste here? If we're talking about text strings, as the thread title implies (I've not read the patch), then I think you should say "empty string", because the SQL concept of null doesn't apply. regards, tom lane
Re: expose parallel leader in CSV and log_line_prefix
On Wed, Jul 22, 2020 at 11:36:05AM -0400, Alvaro Herrera wrote: > How about we combine both. "Process ID of the parallel group leader, if > this process is a parallel query worker. NULL if this process is a > parallel group leader or does not participate in parallel query". Sounds fine to me. Thanks. Do others have any objections with this wording? -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On 2020-Jul-21, Michael Paquier wrote: > On Mon, Jul 20, 2020 at 11:12:31PM -0500, Justin Pryzby wrote: > >> + Process ID of the parallel group leader if this process is involved > >> + in parallel query, or null. For a parallel group leader, this > >> field > >> + is NULL. > >> > > | For a parallel worker, this is the Process ID of its leader process. Null > > | for processes which are not parallel workers. How about we combine both. "Process ID of the parallel group leader, if this process is a parallel query worker. NULL if this process is a parallel group leader or does not participate in parallel query". -- Álvaro Herrerahttps://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Re: expose parallel leader in CSV and log_line_prefix
On Tue, Jul 21, 2020 at 6:33 AM Michael Paquier wrote: > > On Mon, Jul 20, 2020 at 11:12:31PM -0500, Justin Pryzby wrote: > > On Tue, Jul 21, 2020 at 12:51:45PM +0900, Michael Paquier wrote: > > The documentation could talk about either: > > > > 1) "lock group leader" - low-level, raw view of the internal data structure > > (with a secondary mention that "for a parallel process, this is its parallel > > leader). > > 2) "parallel leaders" high-level, user-facing, "cooked" view; > > > > Right now it doesn't matter, but it seems that if we document the high-level > > "parallel leader", then we don't need to accomodate future uses (at least > > until > > the future happens). > > Hmm. Not sure. This sounds like material for a separate and larger > patch. > > >> > >> - Process ID of the parallel group leader if this process is or > >> - has been involved in parallel query, or null. This field is set > >> - when a process wants to cooperate with parallel workers, and > >> - remains set as long as the process exists. For a parallel group > >> leader, > >> - this field is set to its own process ID. For a parallel worker, > >> - this field is set to the process ID of the parallel group leader. > >> + Process ID of the parallel group leader if this process is involved > >> + in parallel query, or null. For a parallel group leader, this > >> field > >> + is NULL. > >> > > > > FWIW , I prefer something like my earlier phrase: > > > > | For a parallel worker, this is the Process ID of its leader process. Null > > | for processes which are not parallel workers. > > I preferred mine, and it seems to me that the first sentence of the > previous patch covers already both things mentioned in your sentence. > It also seems to me that it is an important thing to directly outline > that this field remains NULL for group leaders. I agree that Michael's version seems less error prone and makes everything crystal clear, so +1 for it.
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 17, 2020 at 07:34:54AM +0200, Julien Rouhaud wrote: > I had the same concern and was thinking about this approach too. > Another argument is that IIUC any log emitted due to > log_min_duration_statement wouldn't see the backend as executing a > parallel query, since the workers would already have been shut down. Not sure that it is worth bothering about this case. You could also have a backend killed by log_min_duration_statement on a query that did not involve parallel query, where you would still report the PID if it got involved at least once in parallel query for a query before that. -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On Mon, Jul 20, 2020 at 11:12:31PM -0500, Justin Pryzby wrote: > On Tue, Jul 21, 2020 at 12:51:45PM +0900, Michael Paquier wrote: > The documentation could talk about either: > > 1) "lock group leader" - low-level, raw view of the internal data structure > (with a secondary mention that "for a parallel process, this is its parallel > leader). > 2) "parallel leaders" high-level, user-facing, "cooked" view; > > Right now it doesn't matter, but it seems that if we document the high-level > "parallel leader", then we don't need to accomodate future uses (at least > until > the future happens). Hmm. Not sure. This sounds like material for a separate and larger patch. >> >> - Process ID of the parallel group leader if this process is or >> - has been involved in parallel query, or null. This field is set >> - when a process wants to cooperate with parallel workers, and >> - remains set as long as the process exists. For a parallel group >> leader, >> - this field is set to its own process ID. For a parallel worker, >> - this field is set to the process ID of the parallel group leader. >> + Process ID of the parallel group leader if this process is involved >> + in parallel query, or null. For a parallel group leader, this field >> + is NULL. >> > > FWIW , I prefer something like my earlier phrase: > > | For a parallel worker, this is the Process ID of its leader process. Null > | for processes which are not parallel workers. I preferred mine, and it seems to me that the first sentence of the previous patch covers already both things mentioned in your sentence. It also seems to me that it is an important thing to directly outline that this field remains NULL for group leaders. -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On Tue, Jul 21, 2020 at 12:51:45PM +0900, Michael Paquier wrote: > And I'd rather keep the simple suggestion of upthread to leave the > field as NULL for the parallel group leader with a PID match but not a > backend type check so as this could be useful for other types of > processes. The documentation could talk about either: 1) "lock group leader" - low-level, raw view of the internal data structure (with a secondary mention that "for a parallel process, this is its parallel leader). 2) "parallel leaders" high-level, user-facing, "cooked" view; Right now it doesn't matter, but it seems that if we document the high-level "parallel leader", then we don't need to accomodate future uses (at least until the future happens). > diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml > index dc49177c78..15c598b2a5 100644 > --- a/doc/src/sgml/monitoring.sgml > +++ b/doc/src/sgml/monitoring.sgml > @@ -687,12 +687,9 @@ postgres 27093 0.0 0.0 30096 2752 ?Ss > 11:34 0:00 postgres: ser > leader_pid integer > > > - Process ID of the parallel group leader if this process is or > - has been involved in parallel query, or null. This field is set > - when a process wants to cooperate with parallel workers, and > - remains set as long as the process exists. For a parallel group > leader, > - this field is set to its own process ID. For a parallel worker, > - this field is set to the process ID of the parallel group leader. > + Process ID of the parallel group leader if this process is involved > + in parallel query, or null. For a parallel group leader, this field > + is NULL. > > FWIW , I prefer something like my earlier phrase: | For a parallel worker, this is the Process ID of its leader process. Null | for processes which are not parallel workers. -- Justin
Re: expose parallel leader in CSV and log_line_prefix
On Mon, Jul 20, 2020 at 06:30:48PM -0500, Justin Pryzby wrote:
> This thread is about a new feature that I proposed which isn't yet committed
> (logging leader_pid). But it raises a question which is immediately relevant
> to pg_stat_activity.leader_pid, which is committed for v13. So feel free to
> move to a new thread or to the thread for commit b025f3.
For a change of this size, with everybody involved in the past
discussion already on this thread, and knowing that you already
created an open item pointing to this part of the thread, I am not
sure that I would bother spawning a new thread now :)
> I see a couple options:
>
> - Update the documentation only, saying something like "leader_pid: the lock
> group leader. For a process involved in parallel query, this is the
> parallel
> leader. In particular, for the leader process itself, leader_pid = pid, and
> it is not reset until the leader terminates (it does not change when
> parallel
> workers exit). This leaves in place the "raw" view of the data structure,
> which can be desirable, but can be perceived as exposing unfriendly
> implementation details.
>
> - Functional change to show leader_pid = NULL for the leader itself. Maybe
> the columns should only be not-NULL when st_backendType == B_BG_WORKER &&
> bgw_type='parallel worker'. Update documentation to say: "leader_pid: for
> parallel workers, the PID of their leader process". (not a raw view of the
> "lock group leader").
Yeah, I don't mind revisiting that per the connection pooler argument.
And I'd rather keep the simple suggestion of upthread to leave the
field as NULL for the parallel group leader with a PID match but not a
backend type check so as this could be useful for other types of
processes. This leads me to the attached with the docs updated
(tested with read-only pgbench spawning parallel workers with
pg_stat_activity queried in parallel), to be applied down to 13.
Thoughts are welcome.
--
Michael
diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c
index 2aff739466..95738a4e34 100644
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -735,7 +735,13 @@ pg_stat_get_activity(PG_FUNCTION_ARGS)
wait_event = pgstat_get_wait_event(raw_wait_event);
leader = proc->lockGroupLeader;
-if (leader)
+
+/*
+ * Show the leader only for active parallel workers. This
+ * leaves the field as NULL for the leader of a parallel
+ * group.
+ */
+if (leader && leader->pid != beentry->st_procpid)
{
values[29] = Int32GetDatum(leader->pid);
nulls[29] = false;
diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml
index dc49177c78..15c598b2a5 100644
--- a/doc/src/sgml/monitoring.sgml
+++ b/doc/src/sgml/monitoring.sgml
@@ -687,12 +687,9 @@ postgres 27093 0.0 0.0 30096 2752 ?Ss 11:34 0:00 postgres: ser
leader_pid integer
- Process ID of the parallel group leader if this process is or
- has been involved in parallel query, or null. This field is set
- when a process wants to cooperate with parallel workers, and
- remains set as long as the process exists. For a parallel group leader,
- this field is set to its own process ID. For a parallel worker,
- this field is set to the process ID of the parallel group leader.
+ Process ID of the parallel group leader if this process is involved
+ in parallel query, or null. For a parallel group leader, this field
+ is NULL.
signature.asc
Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 17, 2020 at 05:32:36PM -0500, Justin Pryzby wrote:
> On Fri, Jul 17, 2020 at 05:27:21PM -0400, Alvaro Herrera wrote:
> > On 2020-Jul-17, Justin Pryzby wrote:
> > > Ok, but should we then consider changing pg_stat_activity for consistency
> > > ?
> > > Probably in v13 to avoid changing it a year later.
> > > https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=b025f32e0b5d7668daec9bfa957edf3599f4baa8
> > >
> > > I think the story is that we're exposing to the user a "leader pid" what's
> > > internally called (and used as) the "lock group leader", which for the
> > > leader
> > > process is set to its own PID. But I think what we're exposing as
> > > leader_pid
> > > will seem like an implementation artifact to users.
> >
> > IMO it *is* an implementation artifact if, as you say, the leader PID
> > remains set after the parallel query is done. I mentioned the pgbouncer
> > case before: if you run a single parallel query, then the process
> > remains a "parallel leader" for days or weeks afterwards even if it
> > hasn't run a parallel query ever since. That doesn't sound great to me.
> >
> > I think it's understandable and OK if there's a small race condition
> > that means you report a process as a leader shortly before or shortly
> > after a parallel query is actually executed. But doing so until backend
> > termination seems confusing as well as useless.
>
> I'm not sure that connection pooling is the strongest argument against the
> current behavior, but we could change it as suggested to show as NULL the
> leader_pid for the leader's own process. I think that's the intuitive
> behavior
> a user expects. Parallel processes are those with leader_pid IS NOT NULL. If
> we ever used lockGroupLeader for something else, you'd also have to say AND
> backend_type='parallel worker'.
>
> We should talk about doing that for PSA and for v13 as well. Here or on the
> other thread or a new thread ? It's a simple enough change, but the question
> is if we want to provide a more "cooked" view whcih hides the internals, and
> if
> so, is this really enough.
>
> --- a/src/backend/utils/adt/pgstatfuncs.c
> +++ b/src/backend/utils/adt/pgstatfuncs.c
> @@ -737,3 +737,4 @@ pg_stat_get_activity(PG_FUNCTION_ARGS)
> leader = proc->lockGroupLeader;
> - if (leader)
> + if (leader && leader->pid !=
> beentry->st_procpid)
> {
> values[29] =
> Int32GetDatum(leader->pid);
This thread is about a new feature that I proposed which isn't yet committed
(logging leader_pid). But it raises a question which is immediately relevant
to pg_stat_activity.leader_pid, which is committed for v13. So feel free to
move to a new thread or to the thread for commit b025f3.
I added this to the Opened Items list so it's not lost.
I see a couple options:
- Update the documentation only, saying something like "leader_pid: the lock
group leader. For a process involved in parallel query, this is the parallel
leader. In particular, for the leader process itself, leader_pid = pid, and
it is not reset until the leader terminates (it does not change when parallel
workers exit). This leaves in place the "raw" view of the data structure,
which can be desirable, but can be perceived as exposing unfriendly
implementation details.
- Functional change to show leader_pid = NULL for the leader itself. Maybe
the columns should only be not-NULL when st_backendType == B_BG_WORKER &&
bgw_type='parallel worker'. Update documentation to say: "leader_pid: for
parallel workers, the PID of their leader process". (not a raw view of the
"lock group leader").
- ??
--
Justin
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 17, 2020 at 05:27:21PM -0400, Alvaro Herrera wrote:
> On 2020-Jul-17, Justin Pryzby wrote:
> > Ok, but should we then consider changing pg_stat_activity for consistency ?
> > Probably in v13 to avoid changing it a year later.
> > https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=b025f32e0b5d7668daec9bfa957edf3599f4baa8
> >
> > I think the story is that we're exposing to the user a "leader pid" what's
> > internally called (and used as) the "lock group leader", which for the
> > leader
> > process is set to its own PID. But I think what we're exposing as
> > leader_pid
> > will seem like an implementation artifact to users.
>
> IMO it *is* an implementation artifact if, as you say, the leader PID
> remains set after the parallel query is done. I mentioned the pgbouncer
> case before: if you run a single parallel query, then the process
> remains a "parallel leader" for days or weeks afterwards even if it
> hasn't run a parallel query ever since. That doesn't sound great to me.
>
> I think it's understandable and OK if there's a small race condition
> that means you report a process as a leader shortly before or shortly
> after a parallel query is actually executed. But doing so until backend
> termination seems confusing as well as useless.
I'm not sure that connection pooling is the strongest argument against the
current behavior, but we could change it as suggested to show as NULL the
leader_pid for the leader's own process. I think that's the intuitive behavior
a user expects. Parallel processes are those with leader_pid IS NOT NULL. If
we ever used lockGroupLeader for something else, you'd also have to say AND
backend_type='parallel worker'.
We should talk about doing that for PSA and for v13 as well. Here or on the
other thread or a new thread ? It's a simple enough change, but the question
is if we want to provide a more "cooked" view whcih hides the internals, and if
so, is this really enough.
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -737,3 +737,4 @@ pg_stat_get_activity(PG_FUNCTION_ARGS)
leader = proc->lockGroupLeader;
- if (leader)
+ if (leader && leader->pid !=
beentry->st_procpid)
{
values[29] = Int32GetDatum(leader->pid);
--
Justin
Re: expose parallel leader in CSV and log_line_prefix
On 2020-Jul-17, Justin Pryzby wrote: > Ok, but should we then consider changing pg_stat_activity for consistency ? > Probably in v13 to avoid changing it a year later. > https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=b025f32e0b5d7668daec9bfa957edf3599f4baa8 > > I think the story is that we're exposing to the user a "leader pid" what's > internally called (and used as) the "lock group leader", which for the leader > process is set to its own PID. But I think what we're exposing as leader_pid > will seem like an implementation artifact to users. IMO it *is* an implementation artifact if, as you say, the leader PID remains set after the parallel query is done. I mentioned the pgbouncer case before: if you run a single parallel query, then the process remains a "parallel leader" for days or weeks afterwards even if it hasn't run a parallel query ever since. That doesn't sound great to me. I think it's understandable and OK if there's a small race condition that means you report a process as a leader shortly before or shortly after a parallel query is actually executed. But doing so until backend termination seems confusing as well as useless. -- Álvaro Herrerahttps://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 17, 2020 at 11:35:40AM -0400, Alvaro Herrera wrote: > > On Fri, Jul 17, 2020 at 7:01 AM Michael Paquier wrote: > > > > > Hmm. Knowing if a leader is actually running parallel query or not > > > requires a lookup at lockGroupMembers, that itself requires a LWLock. > > > I think that it would be better to not require that. So what if > > > instead we logged %P only if Myproc has lockGroupLeader set and it > > > does *not* match MyProcPid? > > That's what I said first, so +1 for that approach. Ok, but should we then consider changing pg_stat_activity for consistency ? Probably in v13 to avoid changing it a year later. https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=b025f32e0b5d7668daec9bfa957edf3599f4baa8 I think the story is that we're exposing to the user a "leader pid" what's internally called (and used as) the "lock group leader", which for the leader process is set to its own PID. But I think what we're exposing as leader_pid will seem like an implementation artifact to users. It's unnatural to define a leader PID for the leader itself, and I'm guessing that at least 30% of people who use pg_stat_activity.leader_pid will be surprised by rows with | backend_type='client backend' AND leader_pid IS NOT NULL And maybe additionally confused if PSA doesn't match CSV or other log. Right now, PSA will include processes "were leader" queries like: | SELECT pid FROM pg_stat_activity WHERE pid=leader_pid If we change it, I think you can get the same thing for a *current* leader like: | SELECT pid FROM pg_stat_activity a WHERE EXISTS (SELECT 1 FROM pg_stat_activity b WHERE b.leader_pid=a.pid); But once the children die, you can't get that anymore. Is that a problem ? I didn't think of it until now, but it would be useful to query logs for processes which were involved in parallel process. (It would be more useful if it indicated the query, and not just the process) I agree that showing the PID as the leader PID while using a connection pooler is "noisy". But I think that's maybe just a consequence of connection pooling. As an analogy, I would normally use a query like: | SELECT session_line, message, query FROM postgres_log WHERE session_id='..' ORDER BY 1 But that already doesn't work usefully with connection pooling (and I'm not sure how to resolve that other than by not using pooling when logs are useful) I'm not sure what the answer. Probably we should either make both expose lockGroupLeader exactly (and not filtered) or make both show lockGroupLeader only if lockGroupLeader!=getpid(). -- Justin
Re: expose parallel leader in CSV and log_line_prefix
> On Fri, Jul 17, 2020 at 7:01 AM Michael Paquier wrote: > > > Hmm. Knowing if a leader is actually running parallel query or not > > requires a lookup at lockGroupMembers, that itself requires a LWLock. > > I think that it would be better to not require that. So what if > > instead we logged %P only if Myproc has lockGroupLeader set and it > > does *not* match MyProcPid? That's what I said first, so +1 for that approach. -- Álvaro Herrerahttps://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Re: expose parallel leader in CSV and log_line_prefix
Hi, On Fri, Jul 17, 2020 at 7:01 AM Michael Paquier wrote: > > On Thu, Jul 16, 2020 at 10:55:45PM -0400, Alvaro Herrera wrote: > > Oh, ugh, I don't like that part much. If you run connections through a > > connection pooler, it's going to be everywhere. Let's put it there only > > if the connection *is* running a parallel query, without being too > > stressed about the startup and teardown sequence. > > Hmm. Knowing if a leader is actually running parallel query or not > requires a lookup at lockGroupMembers, that itself requires a LWLock. > I think that it would be better to not require that. So what if > instead we logged %P only if Myproc has lockGroupLeader set and it > does *not* match MyProcPid? In short, it means that we would get the > information of a leader for each worker currently running parallel > query, but that we would not know from the leader if it is running a > parallel query or not at the moment of the log. One can then easily > guess what was happening on the leader by looking at the logs of the > backend matching with the PID the workers are logging with %P. I had the same concern and was thinking about this approach too. Another argument is that IIUC any log emitted due to log_min_duration_statement wouldn't see the backend as executing a parallel query, since the workers would already have been shut down.
Re: expose parallel leader in CSV and log_line_prefix
On Thu, Jul 16, 2020 at 10:55:45PM -0400, Alvaro Herrera wrote: > Oh, ugh, I don't like that part much. If you run connections through a > connection pooler, it's going to be everywhere. Let's put it there only > if the connection *is* running a parallel query, without being too > stressed about the startup and teardown sequence. Hmm. Knowing if a leader is actually running parallel query or not requires a lookup at lockGroupMembers, that itself requires a LWLock. I think that it would be better to not require that. So what if instead we logged %P only if Myproc has lockGroupLeader set and it does *not* match MyProcPid? In short, it means that we would get the information of a leader for each worker currently running parallel query, but that we would not know from the leader if it is running a parallel query or not at the moment of the log. One can then easily guess what was happening on the leader by looking at the logs of the backend matching with the PID the workers are logging with %P. -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On 2020-Jul-17, Michael Paquier wrote: > Please note that this choice comes from BecomeLockGroupLeader(), where > a leader registers itself in lockGroupLeader, and remains set as such > as long as the process is alive so we would always get a value for a > process once it got involved in parallel query. This patch is just Oh, ugh, I don't like that part much. If you run connections through a connection pooler, it's going to be everywhere. Let's put it there only if the connection *is* running a parallel query, without being too stressed about the startup and teardown sequence. -- Álvaro Herrerahttps://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 10, 2020 at 01:16:40PM -0400, Alvaro Herrera wrote: > On 2020-Jul-10, Justin Pryzby wrote: >> That's what's done. >> >> + Process ID of the parallel group leader if this process >> was >> + at some point involved in parallel query, otherwise null. For >> a >> + parallel group leader itself, this field is set to its own >> process >> + ID. > > Oh, okay by me then. Please note that this choice comes from BecomeLockGroupLeader(), where a leader registers itself in lockGroupLeader, and remains set as such as long as the process is alive so we would always get a value for a process once it got involved in parallel query. This patch is just doing what we do in pg_stat_get_activity(), with the padding handling. It is true that this may cause log_line_prefix to be overly verbose in the case where you keep a lot of sessions alive for long time when they got all involved at least once in parallel query as most of them would just refer to their own PID, but I think that it is better to be consistent with what we do already with pg_stat_activity, as that's the data present in the PGPROC entries. -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On 2020-Jul-10, Justin Pryzby wrote: > On Fri, Jul 10, 2020 at 12:45:29PM -0400, Alvaro Herrera wrote: > > I think it's overly verbose; all non-parallel backends are going to get > > their own PID twice, and I'm not sure this is going to be great to > > parse. I think it would be more sensible that if the process does not > > have a parent (leader), %P expands to empty. > > That's what's done. > > + Process ID of the parallel group leader if this process > was > + at some point involved in parallel query, otherwise null. For a > + parallel group leader itself, this field is set to its own > process > + ID. Oh, okay by me then. -- Álvaro Herrerahttps://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 10, 2020 at 12:45:29PM -0400, Alvaro Herrera wrote: > On 2020-Mar-18, Justin Pryzby wrote: > > > On Sun, Mar 15, 2020 at 12:49:33PM +0100, Julien Rouhaud wrote: > > > template1=# SET log_temp_files=0; explain analyze SELECT a,COUNT(1) FROM t > > a JOIN t b USING(a) GROUP BY 1; > > 2020-03-15 21:20:47.288 CDT [55375537]LOG: statement: SET > > log_temp_files=0; > > SET > > 2020-03-15 21:20:47.289 CDT [55375537]LOG: statement: explain > > analyze SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; > > 2020-03-15 21:20:51.253 CDT [56275537]LOG: temporary file: path > > "base/pgsql_tmp/pgsql_tmp5627.0", size 6094848 > > 2020-03-15 21:20:51.253 CDT [56275537]STATEMENT: explain analyze > > SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; > > 2020-03-15 21:20:51.254 CDT [56265537]LOG: temporary file: path > > "base/pgsql_tmp/pgsql_tmp5626.0", size 6103040 > > 2020-03-15 21:20:51.254 CDT [56265537]STATEMENT: explain analyze > > SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; > > 2020-03-15 21:20:51.263 CDT [55375537]LOG: temporary file: path > > "base/pgsql_tmp/pgsql_tmp5537.1.sharedfileset/o15of16.p0.0", size 557056 > > I think it's overly verbose; all non-parallel backends are going to get > their own PID twice, and I'm not sure this is going to be great to > parse. I think it would be more sensible that if the process does not > have a parent (leader), %P expands to empty. That's what's done. + Process ID of the parallel group leader if this process was + at some point involved in parallel query, otherwise null. For a + parallel group leader itself, this field is set to its own process + ID. 2020-07-10 11:53:32.304 CDT [16699 ]LOG: statement: SELECT 1; 2020-07-10 11:53:32.304 CDT,"pryzbyj","postgres",16699,"[local]",5f089d0b.413b,1,"idle",2020-07-10 11:53:31 CDT,3/4,0,LOG,0,"statement: SELECT 1;","psql","client backend", -- Justin
Re: expose parallel leader in CSV and log_line_prefix
On 2020-Mar-18, Justin Pryzby wrote: > On Sun, Mar 15, 2020 at 12:49:33PM +0100, Julien Rouhaud wrote: > template1=# SET log_temp_files=0; explain analyze SELECT a,COUNT(1) FROM t a > JOIN t b USING(a) GROUP BY 1; > 2020-03-15 21:20:47.288 CDT [55375537]LOG: statement: SET > log_temp_files=0; > SET > 2020-03-15 21:20:47.289 CDT [55375537]LOG: statement: explain > analyze SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; > 2020-03-15 21:20:51.253 CDT [56275537]LOG: temporary file: path > "base/pgsql_tmp/pgsql_tmp5627.0", size 6094848 > 2020-03-15 21:20:51.253 CDT [56275537]STATEMENT: explain analyze > SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; > 2020-03-15 21:20:51.254 CDT [56265537]LOG: temporary file: path > "base/pgsql_tmp/pgsql_tmp5626.0", size 6103040 > 2020-03-15 21:20:51.254 CDT [56265537]STATEMENT: explain analyze > SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; > 2020-03-15 21:20:51.263 CDT [55375537]LOG: temporary file: path > "base/pgsql_tmp/pgsql_tmp5537.1.sharedfileset/o15of16.p0.0", size 557056 I think it's overly verbose; all non-parallel backends are going to get their own PID twice, and I'm not sure this is going to be great to parse. I think it would be more sensible that if the process does not have a parent (leader), %P expands to empty. -- Álvaro Herrerahttps://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 10, 2020 at 11:11:15AM -0500, Justin Pryzby wrote: > On Fri, Jul 10, 2020 at 05:13:26PM +0200, Julien Rouhaud wrote: > > There's a thinko in the padding handling. It should be dones whether MyProc > > and/or lockGroupLeader is NULL or not, and only if padding was asked, like > > it's > > done for case 'd' for instance. > > > > Also, the '%k' escape sounds a bit random. Is there any reason why we don't > > use any uppercase character for log_line_prefix? %P could be a better > > alternative, otherwise maybe %g, as GroupLeader/Gather? > > Thanks for looking. %P is a good idea - it's consistent with ps and pkill and > probably other %commands. I also amended the docs. Thanks! So for the leader == NULL case, the AppendStringInfoSpace is a no-op if no padding was asked, so it's probably not worth adding extra code to make it any more obvious. It all looks good to me, I'm marking the patch a ready for committer!
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 10, 2020 at 05:13:26PM +0200, Julien Rouhaud wrote:
> There's a thinko in the padding handling. It should be dones whether MyProc
> and/or lockGroupLeader is NULL or not, and only if padding was asked, like
> it's
> done for case 'd' for instance.
>
> Also, the '%k' escape sounds a bit random. Is there any reason why we don't
> use any uppercase character for log_line_prefix? %P could be a better
> alternative, otherwise maybe %g, as GroupLeader/Gather?
Thanks for looking. %P is a good idea - it's consistent with ps and pkill and
probably other %commands. I also amended the docs.
--
Justin
>From 68a892d0023e915cc48aea1bb77eae5deabcecec Mon Sep 17 00:00:00 2001
From: Justin Pryzby
Date: Fri, 13 Mar 2020 22:03:06 -0500
Subject: [PATCH v2] Include the leader PID in logfile
See also: b025f32e0b, which adds the leader PID to pg_stat_activity
---
doc/src/sgml/config.sgml | 11 ++-
src/backend/utils/error/elog.c| 30 +++
src/backend/utils/misc/postgresql.conf.sample | 1 +
3 files changed, 41 insertions(+), 1 deletion(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index b353c61683..e60403d6a5 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -6611,6 +6611,14 @@ local0.*/var/log/postgresql
Process ID
no
+
+ %P
+ Process ID of the parallel group leader if this process was
+ at some point involved in parallel query, otherwise null. For a
+ parallel group leader itself, this field is set to its own process
+ ID.
+ no
+
%t
Time stamp without milliseconds
@@ -6943,7 +6951,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
character count of the error position therein,
location of the error in the PostgreSQL source code
(if log_error_verbosity is set to verbose),
-application name, and backend type.
+application name, backend type, and leader PID.
Here is a sample table definition for storing CSV-format log output:
@@ -6973,6 +6981,7 @@ CREATE TABLE postgres_log
location text,
application_name text,
backend_type text,
+ leader_pid integer,
PRIMARY KEY (session_id, session_line_num)
);
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index e4b717c79a..dea098faf1 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -77,6 +77,7 @@
#include "postmaster/syslogger.h"
#include "storage/ipc.h"
#include "storage/proc.h"
+#include "storage/procarray.h"
#include "tcop/tcopprot.h"
#include "utils/guc.h"
#include "utils/memutils.h"
@@ -2448,6 +2449,25 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
else
appendStringInfo(buf, "%d", MyProcPid);
break;
+
+ case 'P':
+if (MyProc)
+{
+ PGPROC *leader = MyProc->lockGroupLeader;
+ if (leader == NULL)
+ /* padding only */
+ appendStringInfoSpaces(buf,
+padding > 0 ? padding : -padding);
+ else if (padding != 0)
+ appendStringInfo(buf, "%*d", padding, leader->pid);
+ else
+ appendStringInfo(buf, "%d", leader->pid);
+}
+else if (padding != 0)
+ appendStringInfoSpaces(buf,
+ padding > 0 ? padding : -padding);
+break;
+
case 'l':
if (padding != 0)
appendStringInfo(buf, "%*ld", padding, log_line_number);
@@ -2836,6 +2856,16 @@ write_csvlog(ErrorData *edata)
else
appendCSVLiteral(, GetBackendTypeDesc(MyBackendType));
+ appendStringInfoChar(, ',');
+
+ /* leader PID */
+ if (MyProc)
+ {
+ PGPROC *leader = MyProc->lockGroupLeader;
+ if (leader)
+ appendStringInfo(, "%d", leader->pid);
+ }
+
appendStringInfoChar(, '\n');
/* If in the syslogger process, try to write messages direct to file */
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index e430e33c7b..48a50fb394 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -533,6 +533,7 @@
# %h = remote host
# %b = backend type
# %p = process ID
+ # %P = leader PID
# %t = timestamp without milliseconds
# %m = timestamp with milliseconds
# %n = timestamp with milliseconds (as a Unix epoch)
--
2.17.0
Re: expose parallel leader in CSV and log_line_prefix
On Thu, Jul 09, 2020 at 09:20:23PM -0500, Justin Pryzby wrote:
> On Fri, Jul 10, 2020 at 11:09:40AM +0900, Michael Paquier wrote:
> > On Thu, Jul 09, 2020 at 01:53:39PM +0200, Julien Rouhaud wrote:
> > > Sure! I've been quite busy with internal work duties recently but
> > > I'll review this patch shortly. Thanks for the reminder!
> >
> > Hmm. In which cases would it be useful to have this information in
> > the logs knowing that pg_stat_activity lets us know the link between
> > both the leader and its workers?
>
> PSA is an instantaneous view whereas the logs are a record. That's important
> for shortlived processes (like background workers) or in the case of an ERROR
> or later crash.
>
> Right now, the logs fail to include that information, which is deficient.
> Half
> the utility is in showing *that* the log is for a parallel worker, which is
> otherwise not apparent.
Yes, I agree that this is a nice thing to have and another smell step toward
parallel query monitoring.
About the patch:
+ case 'k':
+ if (MyProc)
+ {
+ PGPROC *leader = MyProc->lockGroupLeader;
+ if (leader == NULL)
+ /* padding only */
+ appendStringInfoSpaces(buf,
+ padding > 0 ? padding : -padding);
+ else if (padding != 0)
+ appendStringInfo(buf, "%*d", padding, leader->pid);
+ else
+ appendStringInfo(buf, "%d", leader->pid);
+ }
+ break;
There's a thinko in the padding handling. It should be dones whether MyProc
and/or lockGroupLeader is NULL or not, and only if padding was asked, like it's
done for case 'd' for instance.
Also, the '%k' escape sounds a bit random. Is there any reason why we don't
use any uppercase character for log_line_prefix? %P could be a better
alternative, otherwise maybe %g, as GroupLeader/Gather?
Re: expose parallel leader in CSV and log_line_prefix
On Fri, Jul 10, 2020 at 11:09:40AM +0900, Michael Paquier wrote: > On Thu, Jul 09, 2020 at 01:53:39PM +0200, Julien Rouhaud wrote: > > Sure! I've been quite busy with internal work duties recently but > > I'll review this patch shortly. Thanks for the reminder! > > Hmm. In which cases would it be useful to have this information in > the logs knowing that pg_stat_activity lets us know the link between > both the leader and its workers? PSA is an instantaneous view whereas the logs are a record. That's important for shortlived processes (like background workers) or in the case of an ERROR or later crash. Right now, the logs fail to include that information, which is deficient. Half the utility is in showing *that* the log is for a parallel worker, which is otherwise not apparent. -- Justin
Re: expose parallel leader in CSV and log_line_prefix
On Thu, Jul 09, 2020 at 01:53:39PM +0200, Julien Rouhaud wrote: > Sure! I've been quite busy with internal work duties recently but > I'll review this patch shortly. Thanks for the reminder! Hmm. In which cases would it be useful to have this information in the logs knowing that pg_stat_activity lets us know the link between both the leader and its workers? -- Michael signature.asc Description: PGP signature
Re: expose parallel leader in CSV and log_line_prefix
On Thu, Jul 9, 2020 at 1:48 PM Daniel Gustafsson wrote: > > > On 18 Mar 2020, at 22:25, Justin Pryzby wrote: > > > This also fixes unsafe access to lockGroupLeader->pid, same issue as in the > > original v1 patch for b025f32e0b. > > Julian, having been involved in the other threads around this topic, do you > have time to review this latest version during the commitfest? Sure! I've been quite busy with internal work duties recently but I'll review this patch shortly. Thanks for the reminder!
Re: expose parallel leader in CSV and log_line_prefix
> On 18 Mar 2020, at 22:25, Justin Pryzby wrote: > This also fixes unsafe access to lockGroupLeader->pid, same issue as in the > original v1 patch for b025f32e0b. Julian, having been involved in the other threads around this topic, do you have time to review this latest version during the commitfest? cheers ./daniel
Re: expose parallel leader in CSV and log_line_prefix
On Sun, Mar 15, 2020 at 12:49:33PM +0100, Julien Rouhaud wrote: > On Sun, Mar 15, 2020 at 06:18:31AM -0500, Justin Pryzby wrote: > > See also: > > https://commitfest.postgresql.org/27/2390/ > > https://www.postgresql.org/message-id/flat/caobau_yy5bt0vtpz2_lum6cucgeqmynoj8-rgto+c2+w3de...@mail.gmail.com > > b025f32e0b Add leader_pid to pg_stat_activity > > FTR this is a followup of > https://www.postgresql.org/message-id/20200315095728.GA26184%40telsasoft.com Yes - but I wasn't going to draw attention to the first patch, in which I did something needlessly complicated and indirect. :) > + case 'k': > + if (MyBackendType != B_BG_WORKER) > + ; /* Do nothing */ > > > Isn't the test inverted? Also a bgworker could run parallel queries through > SPI I think, should we really ignore bgworkers? I don't think it's reversed, but I think I see your point: the patch is supposed to be showing the leader's own PID for the leader itself. So I think that can just be removed. > + else if (!MyProc->lockGroupLeader) > + ; /* Do nothing */ > > There should be a test that MyProc isn't NULL. Yes, done. > + else if (padding != 0) > + appendStringInfo(buf, "%*d", padding, > MyProc->lockGroupLeader->pid); > + else > + appendStringInfo(buf, "%d", MyProc->lockGroupLeader->pid); > + break; > > I think that if padding was asked we should append spaces rather than doing > nothing. Done It logs like: template1=# SET log_temp_files=0; explain analyze SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; 2020-03-15 21:20:47.288 CDT [55375537]LOG: statement: SET log_temp_files=0; SET 2020-03-15 21:20:47.289 CDT [55375537]LOG: statement: explain analyze SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; 2020-03-15 21:20:51.253 CDT [56275537]LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp5627.0", size 6094848 2020-03-15 21:20:51.253 CDT [56275537]STATEMENT: explain analyze SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; 2020-03-15 21:20:51.254 CDT [56265537]LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp5626.0", size 6103040 2020-03-15 21:20:51.254 CDT [56265537]STATEMENT: explain analyze SELECT a,COUNT(1) FROM t a JOIN t b USING(a) GROUP BY 1; 2020-03-15 21:20:51.263 CDT [55375537]LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp5537.1.sharedfileset/o15of16.p0.0", size 557056 Now, with the leader showing its own PID. This also fixes unsafe access to lockGroupLeader->pid, same issue as in the original v1 patch for b025f32e0b. -- Justin >From 53d766e88537ca018d46efc671d5b586862fb30b Mon Sep 17 00:00:00 2001 From: Justin Pryzby Date: Fri, 13 Mar 2020 22:03:06 -0500 Subject: [PATCH v3] Include the leader PID in logfile See also: b025f32e0b, which adds the leader PID to pg_stat_activity --- doc/src/sgml/config.sgml | 11 +++- src/backend/utils/error/elog.c| 27 +++ src/backend/utils/misc/postgresql.conf.sample | 1 + 3 files changed, 38 insertions(+), 1 deletion(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 672bf6f1ee..b9a1bd9a31 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6511,6 +6511,14 @@ local0.*/var/log/postgresql Process ID no + + %k + Process ID of the parallel group leader if this + process is or was involved in parallel query, null + otherwise. For a parallel group leader, this field is + set to its own process ID. + no + %t Time stamp without milliseconds @@ -6809,7 +6817,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' character count of the error position therein, location of the error in the PostgreSQL source code (if log_error_verbosity is set to verbose), -application name, and backend type. +application name, backend type, and leader PID. Here is a sample table definition for storing CSV-format log output: @@ -6839,6 +6847,7 @@ CREATE TABLE postgres_log location text, application_name text, backend_type text, + leader_pid integer, PRIMARY KEY (session_id, session_line_num) ); diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index 62eef7b71f..5328664f4d 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -77,6 +77,7 @@ #include "postmaster/syslogger.h" #include "storage/ipc.h" #include "storage/proc.h" +#include "storage/procarray.h" #include "tcop/tcopprot.h" #include "utils/guc.h" #include "utils/memutils.h" @@ -2560,6 +2561,22 @@ log_line_prefix(StringInfo buf, ErrorData *edata) else appendStringInfo(buf, "%d",
Re: expose parallel leader in CSV and log_line_prefix
On Sun, Mar 15, 2020 at 06:18:31AM -0500, Justin Pryzby wrote: > See also: > https://commitfest.postgresql.org/27/2390/ > https://www.postgresql.org/message-id/flat/caobau_yy5bt0vtpz2_lum6cucgeqmynoj8-rgto+c2+w3de...@mail.gmail.com > b025f32e0b Add leader_pid to pg_stat_activity FTR this is a followup of https://www.postgresql.org/message-id/20200315095728.GA26184%40telsasoft.com +1 for the feature. Regarding the patch: + case 'k': + if (MyBackendType != B_BG_WORKER) + ; /* Do nothing */ Isn't the test inverted? Also a bgworker could run parallel queries through SPI I think, should we really ignore bgworkers? + else if (!MyProc->lockGroupLeader) + ; /* Do nothing */ There should be a test that MyProc isn't NULL. + else if (padding != 0) + appendStringInfo(buf, "%*d", padding, MyProc->lockGroupLeader->pid); + else + appendStringInfo(buf, "%d", MyProc->lockGroupLeader->pid); + break; I think that if padding was asked we should append spaces rather than doing nothing.
expose parallel leader in CSV and log_line_prefix
See also: https://commitfest.postgresql.org/27/2390/ https://www.postgresql.org/message-id/flat/caobau_yy5bt0vtpz2_lum6cucgeqmynoj8-rgto+c2+w3de...@mail.gmail.com b025f32e0b Add leader_pid to pg_stat_activity -- Justin >From 5268e89fb32fbb639cb39796729dfe0dfcf14705 Mon Sep 17 00:00:00 2001 From: Justin Pryzby Date: Fri, 13 Mar 2020 22:03:06 -0500 Subject: [PATCH v2] Include the leader PID in logfile See also: b025f32e0b, which adds the leader PID to pg_stat_activity --- doc/src/sgml/config.sgml | 11 +- src/backend/utils/error/elog.c| 20 +++ src/backend/utils/misc/postgresql.conf.sample | 1 + 3 files changed, 31 insertions(+), 1 deletion(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 3cac340f32..f6ded2bc45 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6491,6 +6491,14 @@ local0.*/var/log/postgresql Process ID no + + %k + Process ID of the parallel group leader if this + process is or was involved in parallel query, null + otherwise. For a parallel group leader, this field is + set to its own process ID. + no + %t Time stamp without milliseconds @@ -6789,7 +6797,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' character count of the error position therein, location of the error in the PostgreSQL source code (if log_error_verbosity is set to verbose), -application name, and backend type. +application name, backend type, and leader PID. Here is a sample table definition for storing CSV-format log output: @@ -6819,6 +6827,7 @@ CREATE TABLE postgres_log location text, application_name text, backend_type text, + leader_pid integer, PRIMARY KEY (session_id, session_line_num) ); diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index 62eef7b71f..0f5881355d 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -77,6 +77,7 @@ #include "postmaster/syslogger.h" #include "storage/ipc.h" #include "storage/proc.h" +#include "storage/procarray.h" #include "tcop/tcopprot.h" #include "utils/guc.h" #include "utils/memutils.h" @@ -2560,6 +2561,18 @@ log_line_prefix(StringInfo buf, ErrorData *edata) else appendStringInfo(buf, "%d", MyProcPid); break; + + case 'k': +if (MyBackendType != B_BG_WORKER) + ; /* Do nothing */ +else if (!MyProc->lockGroupLeader) + ; /* Do nothing */ +else if (padding != 0) + appendStringInfo(buf, "%*d", padding, MyProc->lockGroupLeader->pid); +else + appendStringInfo(buf, "%d", MyProc->lockGroupLeader->pid); +break; + case 'l': if (padding != 0) appendStringInfo(buf, "%*ld", padding, log_line_number); @@ -2948,6 +2961,13 @@ write_csvlog(ErrorData *edata) else appendCSVLiteral(, GetBackendTypeDesc(MyBackendType)); + appendStringInfoChar(, ','); + + /* leader PID */ + if (MyBackendType == B_BG_WORKER && + MyProc->lockGroupLeader) + appendStringInfo(, "%d", MyProc->lockGroupLeader->pid); + appendStringInfoChar(, '\n'); /* If in the syslogger process, try to write messages direct to file */ diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index aa44f0c9bf..6874792a15 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -530,6 +530,7 @@ # %h = remote host # %b = backend type # %p = process ID + # %k = leader PID # %t = timestamp without milliseconds # %m = timestamp with milliseconds # %n = timestamp with milliseconds (as a Unix epoch) -- 2.17.0
