pg.ddx.io  pgsql-hackers@postgresql.org mailing list archive  
help / color / mirror / Atom feed
From: Justin Pryzby <pryzby@telsasoft.com>
To: pgsql-hackers@postgresql.org
Subject: Re: query logging of prepared statements
Date: Wed, 27 Feb 2019 12:06:53 -0600
Message-ID: <20190227180653.GF28750@telsasoft.com> (raw)
In-Reply-To: <20190215145704.GW30291@telsasoft.com>
References: <20190208132953.GF29720@telsasoft.com>
	<20190215145704.GW30291@telsasoft.com>

On Fri, Feb 15, 2019 at 08:57:04AM -0600, Justin Pryzby wrote:
> I propose that the prepared statement associated with an EXECUTE should be
> included in log "DETAIL" only when log_error_verbosity=VERBOSE, for both SQL
> EXECUTE and PQexecPrepared (if at all).  I'd like to be able to continue
> logging DETAIL (including bind parameters), so want like to avoid setting
> "TERSE" just to avoid redundant messages.  (It occurs to me that the GUC should
> probably stick to its existing documented behavior rather than be extended,
> which suggests that the duplicitive portions of the logs should simply be
> removed, rather than conditionalized.  Let me know what you think).

I'm attaching a v2 patch which avoids repeated logging of PREPARE, rather than
making such logs conditional on log_error_verbosity=VERBOSE, since
log_error_verbosity is documented to control whether these are output:
DETAIL/HINT/QUERY/CONTEXT/SQLSTATE.

For SQL EXECUTE, excluding "detail" seems reasonable (perhaps for
log_error_verbosity<VERBOSE).  But for PQexecPrepared, the
v1 patch made log_error_verbosity also control the "message" output, which is
outside the scope of its documented behavior.

|message                | execute qq: PREPARE qq AS SELECT $1
|detail                 | parameters: $1 = '3'

https://www.postgresql.org/docs/current/runtime-config-logging.html
|Controls the amount of detail written in the server log for each message that
|is logged. Valid values are TERSE, DEFAULT, and VERBOSE, each adding more
|fields to displayed messages. TERSE excludes the logging of DETAIL, HINT,
|QUERY, and CONTEXT error information. VERBOSE output includes the SQLSTATE
|error code (see also Appendix A) and the source code file name, function name,
|and line number that generated the error. Only superusers can change this
|setting.

As I mentioned in my original message, it seems odd that for SQL EXECUTE, the
PREPARE is shown in "detail", but for the library call, it's shown in
"message".  This patch resolves that inconsistency by showing it in neither.

Attachments:

v2-0001-Avoid-repetitive-log-of-PREPARE-during-EXECUTE-of.patch (text/x-diff, 1.8K) download From d60957d9cd1108f389dde0125fadee71a96b4229 Mon Sep 17 00:00:00 2001 From: Justin Pryzby <justin@telsasoft.com> Date: Sat, 9 Feb 2019 19:20:43 -0500 Subject: [PATCH v2] Avoid repetitive log of PREPARE during EXECUTE of prepared statements --- src/backend/tcop/postgres.c | 13 +++++-------- 1 file changed, 5 insertions(+), 8 deletions(-) diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 8b4d94c9a1..dac5362c81 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -1041,8 +1041,7 @@ exec_simple_query(const char *query_string) { ereport(LOG, (errmsg("statement: %s", query_string), - errhidestmt(true), - errdetail_execute(parsetree_list))); + errhidestmt(true))); was_logged = true; } @@ -2062,14 +2061,13 @@ exec_execute_message(const char *portal_name, long max_rows) if (check_log_statement(portal->stmts)) { ereport(LOG, - (errmsg("%s %s%s%s: %s", + (errmsg("%s %s%s%s", execute_is_fetch ? _("execute fetch from") : _("execute"), prepStmtName, *portal_name ? "/" : "", - *portal_name ? portal_name : "", - sourceText), + *portal_name ? portal_name : ""), errhidestmt(true), errdetail_params(portalParams))); was_logged = true; @@ -2150,15 +2148,14 @@ exec_execute_message(const char *portal_name, long max_rows) break; case 2: ereport(LOG, - (errmsg("duration: %s ms %s %s%s%s: %s", + (errmsg("duration: %s ms %s %s%s%s", msec_str, execute_is_fetch ? _("execute fetch from") : _("execute"), prepStmtName, *portal_name ? "/" : "", - *portal_name ? portal_name : "", - sourceText), + *portal_name ? portal_name : ""), errhidestmt(true), errdetail_params(portalParams))); break; -- 2.12.2

view thread (16+ messages)  latest in thread

Message-ID: <20190227180653.GF28750@telsasoft.com>
Permalink:  ../20190227180653.GF28750@telsasoft.com/
Also on:    postgresql.org/message-id/20190227180653.GF28750@telsasoft.com

 ·  · 

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: pgsql-hackers@postgresql.org
  Cc: pryzby@telsasoft.com
  Subject: Re: query logging of prepared statements
  In-Reply-To: <20190227180653.GF28750@telsasoft.com>

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

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