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 <pryz...@telsasoft.com> 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': { @@ -2469,10 +2440,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata) pg_strftime(strfbuf, sizeof(strfbuf), "%Y-%m-%d %H:%M:%S %Z", pg_localtime(&stamp_time, log_timezone)); - if (padding != 0) - appendStringInfo(buf, "%*s", padding, strfbuf); - else - appendStringInfoString(buf, strfbuf); + appendStringInfo(buf, "%*s", padding, strfbuf); } break; case 'n': @@ -2489,19 +2457,13 @@ log_line_prefix(StringInfo buf, ErrorData *edata) (long) saved_timeval.tv_sec, (int) (saved_timeval.tv_usec / 1000)); - if (padding != 0) - appendStringInfo(buf, "%*s", padding, strfbuf); - else - appendStringInfoString(buf, strfbuf); + appendStringInfo(buf, "%*s", padding, strfbuf); } break; case 's': if (formatted_start_time[0] == '\0') setup_formatted_start_time(); - if (padding != 0) - appendStringInfo(buf, "%*s", padding, formatted_start_time); - else - appendStringInfoString(buf, formatted_start_time); + appendStringInfo(buf, "%*s", padding, formatted_start_time); break; case 'i': if (MyProcPort) @@ -2510,10 +2472,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata) int displen; psdisp = get_ps_display(&displen); - if (padding != 0) - appendStringInfo(buf, "%*s", padding, psdisp); - else - appendBinaryStringInfo(buf, psdisp, displen); + appendStringInfo(buf, "%*s", padding, psdisp); } else if (padding != 0) @@ -2523,37 +2482,24 @@ log_line_prefix(StringInfo buf, ErrorData *edata) case 'r': if (MyProcPort && MyProcPort->remote_host) { - if (padding != 0) + if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0') { - if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0') - { - /* - * This option is slightly special as the port - * number may be appended onto the end. Here we - * need to build 1 string which contains the - * remote_host and optionally the remote_port (if - * set) so we can properly align the string. - */ - - char *hostport; - - hostport = psprintf("%s(%s)", MyProcPort->remote_host, MyProcPort->remote_port); - appendStringInfo(buf, "%*s", padding, hostport); - pfree(hostport); - } - else - appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host); + /* + * This option is slightly special as the port + * number may be appended onto the end. Here we + * need to build 1 string which contains the + * remote_host and optionally the remote_port (if + * set) so we can properly align the string. + */ + + char *hostport; + + hostport = psprintf("%s(%s)", MyProcPort->remote_host, MyProcPort->remote_port); + appendStringInfo(buf, "%*s", padding, hostport); + pfree(hostport); } else - { - /* padding is 0, so we don't need a temp buffer */ - appendStringInfoString(buf, MyProcPort->remote_host); - if (MyProcPort->remote_port && - MyProcPort->remote_port[0] != '\0') - appendStringInfo(buf, "(%s)", - MyProcPort->remote_port); - } - + appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host); } else if (padding != 0) appendStringInfoSpaces(buf, @@ -2561,12 +2507,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata) break; case 'h': if (MyProcPort && MyProcPort->remote_host) - { - if (padding != 0) - appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host); - else - appendStringInfoString(buf, MyProcPort->remote_host); - } + appendStringInfo(buf, "%*s", padding, MyProcPort->remote_host); else if (padding != 0) appendStringInfoSpaces(buf, padding > 0 ? padding : -padding); @@ -2581,32 +2522,21 @@ log_line_prefix(StringInfo buf, ErrorData *edata) /* keep VXID format in sync with lockfuncs.c */ if (MyProc != NULL && MyProc->backendId != InvalidBackendId) { - if (padding != 0) - { - char strfbuf[128]; + char strfbuf[128]; - snprintf(strfbuf, sizeof(strfbuf) - 1, "%d/%u", - MyProc->backendId, MyProc->lxid); + snprintf(strfbuf, sizeof(strfbuf) - 1, "%d/%u", + MyProc->backendId, MyProc->lxid); appendStringInfo(buf, "%*s", padding, strfbuf); - } - else - appendStringInfo(buf, "%d/%u", MyProc->backendId, MyProc->lxid); } else if (padding != 0) appendStringInfoSpaces(buf, padding > 0 ? padding : -padding); break; case 'x': - if (padding != 0) - appendStringInfo(buf, "%*u", padding, GetTopTransactionIdIfAny()); - else - appendStringInfo(buf, "%u", GetTopTransactionIdIfAny()); + appendStringInfo(buf, "%*u", padding, GetTopTransactionIdIfAny()); break; case 'e': - if (padding != 0) - appendStringInfo(buf, "%*s", padding, unpack_sql_state(edata->sqlerrcode)); - else - appendStringInfoString(buf, unpack_sql_state(edata->sqlerrcode)); + appendStringInfo(buf, "%*s", padding, unpack_sql_state(edata->sqlerrcode)); break; default: /* format error - ignore it */ -- 2.17.0
>From 5c91aea3562fb4d2dd082cfa8d6a3b75c551303a Mon Sep 17 00:00:00 2001 From: Justin Pryzby <pryz...@telsasoft.com> Date: Fri, 13 Mar 2020 22:03:06 -0500 Subject: [PATCH v5 2/2] 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 | 29 +++++++++++++++++++ src/backend/utils/misc/postgresql.conf.sample | 1 + 3 files changed, 39 insertions(+), 1 deletion(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 994155ca00..e1da2e12e8 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6694,6 +6694,13 @@ local0.* /var/log/postgresql <entry>Process ID</entry> <entry>no</entry> </row> + <row> + <entry><literal>%P</literal></entry> + <entry>Process ID of the parallel group leader, if this process is + a parallel query worker. + </entry> + <entry>no</entry> + </row> <row> <entry><literal>%t</literal></entry> <entry>Time stamp without milliseconds</entry> @@ -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 <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> @@ -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) ); </programlisting> diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index b0b1a09ab1..60e2f524a7 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" @@ -2425,6 +2426,23 @@ log_line_prefix(StringInfo buf, ErrorData *edata) case 'p': appendStringInfo(buf, "%*d", padding, MyProcPid); break; + + case 'P': + if (MyProc) + { + PGPROC *leader = MyProc->lockGroupLeader; + if (leader != NULL && leader->pid != MyProcPid) + /* leader_pid is blank for the leader itself */ + appendStringInfo(buf, "%*d", padding, leader->pid); + else + appendStringInfoSpaces(buf, + padding > 0 ? padding : -padding); + } + else if (padding != 0) + appendStringInfoSpaces(buf, + padding > 0 ? padding : -padding); + break; + case 'l': appendStringInfo(buf, "%*ld", padding, log_line_number); break; @@ -2766,6 +2784,17 @@ write_csvlog(ErrorData *edata) else appendCSVLiteral(&buf, GetBackendTypeDesc(MyBackendType)); + appendStringInfoChar(&buf, ','); + + /* leader PID */ + if (MyProc) + { + PGPROC *leader = MyProc->lockGroupLeader; + /* leader_pid is blank for leader itself */ + if (leader && leader->pid != MyProcPid) + 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 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