On Fri, Mar 13, 2020 at 10:22:52PM +0100, Peter Eisentraut wrote:
> >Can I suggest:
> >
> >- appendCSVLiteral(&buf, MyBgworkerEntry->bgw_type);
> >+ appendCSVLiteral(&buf, MyBgworkerEntry->bgw_name);
>
> The difference is intentional. bgw_type is so that you can filter and group
> by type. The bgw_name could be totally different for each instance.
I found 5373bc2a0867048bb78f93aede54ac1309b5e227
Your patch adds bgw_type, which is also in pg_stat_activity, so I agree it's
good to allow include it log_line_prefix and CSV.
I suggest the CSV/log should also have the leader_pid, corresponding to
| b025f32e0b Add leader_pid to pg_stat_activity
With the attached on top of your patch, CSV logs like:
2020-03-14 22:09:39.395
CDT,"pryzbyj","template1",17030,"[local]",5e6d9c69.4286,2,"idle",2020-03-14
22:09:29 CDT,3/23,0,LOG,00000,"statement: explain analyze SELECT COUNT(1), a.a
FROM t a JOIN t b ON a.a=b.a GROUP BY 2;",,,,,,,,,"psql","client backend",
2020-03-14 22:09:43.094 CDT,,,17042,,5e6d9c73.4292,1,,2020-03-14 22:09:39
CDT,4/3,0,LOG,00000,"temporary file: path ""base/pgsql_tmp/pgsql_tmp17042.0"",
size 4694016",,,,,,"explain analyze SELECT COUNT(1), a.a FROM t a JOIN t b ON
a.a=b.a GROUP BY 2;",,,"psql","parallel worker",17030
2020-03-14 22:09:43.094 CDT,,,17043,,5e6d9c73.4293,1,,2020-03-14 22:09:39
CDT,5/3,0,LOG,00000,"temporary file: path ""base/pgsql_tmp/pgsql_tmp17043.0"",
size 4694016",,,,,,"explain analyze SELECT COUNT(1), a.a FROM t a JOIN t b ON
a.a=b.a GROUP BY 2;",,,"psql","parallel worker",17030
As for my question "what's using/trying/failing to use parallel workers", I was
able to look into that by parsing "Workers Planned/Launched" from autoexplain.
It's not a *good* way to do it, but I don't see how to do better and I don't
see any way this patch can improve that.
--
Justin
>From 5b111a3a6cd5282dbdf1e504ef648994b1918302 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Sat, 14 Mar 2020 19:09:54 -0500
Subject: [PATCH v1 1/2] Fix previous commit..
---
doc/src/sgml/config.sgml | 2 +-
src/backend/utils/error/elog.c | 5 ++---
2 files changed, 3 insertions(+), 4 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 53d0c480aa..fc0e2c00c3 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -6460,7 +6460,7 @@ local0.* /var/log/postgresql
<row>
<entry><literal>%b</literal></entry>
<entry>Backend process type</entry>
- <entry>yes</entry>
+ <entry>no</entry>
</row>
<row>
<entry><literal>%u</literal></entry>
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 3a6f7f9456..62eef7b71f 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -72,7 +72,6 @@
#include "libpq/pqformat.h"
#include "mb/pg_wchar.h"
#include "miscadmin.h"
-#include "pgstat.h"
#include "postmaster/bgworker.h"
#include "postmaster/postmaster.h"
#include "postmaster/syslogger.h"
@@ -2503,7 +2502,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
else if (MyBackendType == B_BG_WORKER)
backend_type_str = MyBgworkerEntry->bgw_type;
else
- backend_type_str = pgstat_get_backend_desc(MyBackendType);
+ backend_type_str = GetBackendTypeDesc(MyBackendType);
if (padding != 0)
appendStringInfo(buf, "%*s", padding, backend_type_str);
@@ -2947,7 +2946,7 @@ write_csvlog(ErrorData *edata)
else if (MyBackendType == B_BG_WORKER)
appendCSVLiteral(&buf, MyBgworkerEntry->bgw_type);
else
- appendCSVLiteral(&buf, pgstat_get_backend_desc(MyBackendType));
+ appendCSVLiteral(&buf, GetBackendTypeDesc(MyBackendType));
appendStringInfoChar(&buf, '\n');
--
2.17.0
>From 30172a4771360fd6ed4f4646651efffa3785dfb7 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Fri, 13 Mar 2020 22:03:06 -0500
Subject: [PATCH v1 2/2] Include the leader PID in logfile
See also: b025f32e0b, which adds the leader PID to pg_stat_activity
---
doc/src/sgml/config.sgml | 8 +++-
src/backend/utils/error/elog.c | 47 +++++++++++++++++++
src/backend/utils/misc/postgresql.conf.sample | 1 +
3 files changed, 55 insertions(+), 1 deletion(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index fc0e2c00c3..d53b62e2df 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -6487,6 +6487,11 @@ local0.* /var/log/postgresql
<entry>Process ID</entry>
<entry>no</entry>
</row>
+ <row>
+ <entry><literal>%k</literal></entry>
+ <entry>Leader PID for a parallel process, NULL otherwise</entry>
+ <entry>yes</entry>
+ </row>
<row>
<entry><literal>%t</literal></entry>
<entry>Time stamp without milliseconds</entry>
@@ -6777,7 +6782,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 <varname>log_error_verbosity</varname> is set to <literal>verbose</literal>),
- application name, and backend type.
+ application name, backend type, and leader PID.
Here is a sample table definition for storing CSV-format log output:
<programlisting>
@@ -6807,6 +6812,7 @@ CREATE TABLE postgres_log
location text,
application_name text,
backend_type text,
+ leader_pid integer,
PRIMARY KEY (session_id, session_line_num)
);
</programlisting>
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 62eef7b71f..e6b3caf414 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"
@@ -177,6 +178,7 @@ static void write_console(const char *line, int len);
static void setup_formatted_log_time(void);
static void setup_formatted_start_time(void);
static const char *process_log_prefix_padding(const char *p, int *padding);
+static pid_t get_leader_pid();
static void log_line_prefix(StringInfo buf, ErrorData *edata);
static void write_csvlog(ErrorData *edata);
static void send_message_to_server_log(ErrorData *edata);
@@ -2402,6 +2404,24 @@ process_log_prefix_padding(const char *p, int *ppadding)
return p;
}
+/* Return PID of leader, or InvalidPid if not a parallel worker */
+static pid_t
+get_leader_pid()
+{
+ PGPROC *proc;
+ pid_t leader_pid = InvalidPid;
+
+ if (MyBackendType != B_BG_WORKER)
+ return InvalidPid;
+
+ LWLockAcquire(ProcArrayLock, LW_SHARED);
+ proc = BackendPidGetProcWithLock(MyProcPid);
+ if (proc && proc->lockGroupLeader)
+ leader_pid = proc->lockGroupLeader->pid;
+ LWLockRelease(ProcArrayLock);
+ return leader_pid;
+}
+
/*
* Format tag info for log lines; append to the provided buffer.
*/
@@ -2413,6 +2433,10 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
/* has counter been reset in current process? */
static int log_my_pid = 0;
+
+ /* Leader PID is retrieved only once per process after forking from postmaster */
+ static pid_t leader_pid = InvalidPid;
+
int padding;
const char *p;
@@ -2427,6 +2451,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
log_line_number = 0;
log_my_pid = MyProcPid;
formatted_start_time[0] = '\0';
+ leader_pid = get_leader_pid();
}
log_line_number++;
@@ -2560,6 +2585,18 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
else
appendStringInfo(buf, "%d", MyProcPid);
break;
+
+ case 'k':
+ if (!MyProcPort)
+ ; /* Do nothing */
+ else if (leader_pid == InvalidPid)
+ ; /* Do nothing */
+ else if (padding != 0)
+ appendStringInfo(buf, "%*d", padding, leader_pid);
+ else
+ appendStringInfo(buf, "%d", leader_pid);
+ break;
+
case 'l':
if (padding != 0)
appendStringInfo(buf, "%*ld", padding, log_line_number);
@@ -2768,6 +2805,9 @@ write_csvlog(ErrorData *edata)
/* has counter been reset in current process? */
static int log_my_pid = 0;
+ /* Leader PID is retrieved only once per process after forking from postmaster */
+ static pid_t leader_pid = InvalidPid;
+
/*
* This is one of the few places where we'd rather not inherit a static
* variable's value from the postmaster. But since we will, reset it when
@@ -2778,6 +2818,7 @@ write_csvlog(ErrorData *edata)
log_line_number = 0;
log_my_pid = MyProcPid;
formatted_start_time[0] = '\0';
+ leader_pid = get_leader_pid();
}
log_line_number++;
@@ -2948,6 +2989,12 @@ write_csvlog(ErrorData *edata)
else
appendCSVLiteral(&buf, GetBackendTypeDesc(MyBackendType));
+ appendStringInfoChar(&buf, ',');
+
+ /* leader PID */
+ if (MyProcPort && leader_pid != InvalidPid)
+ appendStringInfo(&buf, "%d", leader_pid);
+
appendStringInfoChar(&buf, '\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 c0e9531f9c..32fc4b18e6 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -530,6 +530,7 @@
# %r = remote host and port
# %h = remote host
# %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
