Skip to content

Commit d4bfe41

Browse files
michaelpqmichaelpq
committed
autho_explain: Add GUC to log query parameters
auto_explain.log_parameter_max_length is a new GUC part of the extension, similar to the corresponding core setting, that controls the inclusion of query parameters in the logged explain output. More tests are added to check the behavior of this new parameter: when parameters logged in full (the default of -1), when disabled (value of 0) and when partially truncated (value different than the two others). Author: Dagfinn Ilmari Mannsåker Discussion: https://postgr.es/m/[email protected]
1 parent 08385ed commit d4bfe41

File tree

5 files changed

+105
-0
lines changed

5 files changed

+105
-0
lines changed

‎contrib/auto_explain/auto_explain.c

+15
Original file line numberDiff line numberDiff line change
@@ -19,12 +19,14 @@
1919
#include "common/pg_prng.h"
2020
#include "executor/instrument.h"
2121
#include "jit/jit.h"
22+
#include "nodes/params.h"
2223
#include "utils/guc.h"
2324

2425
PG_MODULE_MAGIC;
2526

2627
/* GUC variables */
2728
static int auto_explain_log_min_duration = -1; /* msec or -1 */
29+
static int auto_explain_log_parameter_max_length = -1; /* bytes or -1 */
2830
static bool auto_explain_log_analyze = false;
2931
static bool auto_explain_log_verbose = false;
3032
static bool auto_explain_log_buffers = false;
@@ -105,6 +107,18 @@ _PG_init(void)
105107
NULL,
106108
NULL);
107109

110+
DefineCustomIntVariable("auto_explain.log_parameter_max_length",
111+
"Sets the maximum length of query parameters to log.",
112+
"Zero logs no query parameters, -1 logs them in full.",
113+
&auto_explain_log_parameter_max_length,
114+
-1,
115+
-1, INT_MAX,
116+
PGC_SUSET,
117+
GUC_UNIT_BYTE,
118+
NULL,
119+
NULL,
120+
NULL);
121+
108122
DefineCustomBoolVariable("auto_explain.log_analyze",
109123
"Use EXPLAIN ANALYZE for plan logging.",
110124
NULL,
@@ -389,6 +403,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
389403

390404
ExplainBeginOutput(es);
391405
ExplainQueryText(es, queryDesc);
406+
ExplainQueryParameters(es, queryDesc->params, auto_explain_log_parameter_max_length);
392407
ExplainPrintPlan(es, queryDesc);
393408
if (es->analyze && auto_explain_log_triggers)
394409
ExplainPrintTriggers(es, queryDesc);

‎contrib/auto_explain/t/001_auto_explain.pl

+48
Original file line numberDiff line numberDiff line change
@@ -60,6 +60,11 @@ sub query_log
6060
qr/Query Text: SELECT \* FROM pg_class;/,
6161
"query text logged, text mode");
6262

63+
unlike(
64+
$log_contents,
65+
qr/Query Parameters:/,
66+
"no query parameters logged when none, text mode");
67+
6368
like(
6469
$log_contents,
6570
qr/Seq Scan on pg_class/,
@@ -75,11 +80,49 @@ sub query_log
7580
qr/Query Text: PREPARE get_proc\(name\) AS SELECT \* FROM pg_proc WHERE proname = \$1;/,
7681
"prepared query text logged, text mode");
7782

83+
like(
84+
$log_contents,
85+
qr/Query Parameters: \$1 = 'int4pl'/,
86+
"query parameters logged, text mode");
87+
7888
like(
7989
$log_contents,
8090
qr/Index Scan using pg_proc_proname_args_nsp_index on pg_proc/,
8191
"index scan logged, text mode");
8292

93+
94+
# Prepared query with truncated parameters.
95+
$log_contents = query_log(
96+
$node,
97+
q{PREPARE get_type(name) AS SELECT * FROM pg_type WHERE typname = $1; EXECUTE get_type('float8');},
98+
{ "auto_explain.log_parameter_max_length" => 3 });
99+
100+
like(
101+
$log_contents,
102+
qr/Query Text: PREPARE get_type\(name\) AS SELECT \* FROM pg_type WHERE typname = \$1;/,
103+
"prepared query text logged, text mode");
104+
105+
like(
106+
$log_contents,
107+
qr/Query Parameters: \$1 = 'flo\.\.\.'/,
108+
"query parameters truncated, text mode");
109+
110+
# Prepared query with parameter logging disabled.
111+
$log_contents = query_log(
112+
$node,
113+
q{PREPARE get_type(name) AS SELECT * FROM pg_type WHERE typname = $1; EXECUTE get_type('float8');},
114+
{ "auto_explain.log_parameter_max_length" => 0 });
115+
116+
like(
117+
$log_contents,
118+
qr/Query Text: PREPARE get_type\(name\) AS SELECT \* FROM pg_type WHERE typname = \$1;/,
119+
"prepared query text logged, text mode");
120+
121+
unlike(
122+
$log_contents,
123+
qr/Query Parameters:/,
124+
"query parameters not logged when disabled, text mode");
125+
83126
# JSON format.
84127
$log_contents = query_log(
85128
$node,
@@ -91,6 +134,11 @@ sub query_log
91134
qr/"Query Text": "SELECT \* FROM pg_proc;"/,
92135
"query text logged, json mode");
93136

137+
unlike(
138+
$log_contents,
139+
qr/"Query Parameters":/,
140+
"query parameters not logged when none, json mode");
141+
94142
like(
95143
$log_contents,
96144
qr/"Node Type": "Seq Scan"[^}]*"Relation Name": "pg_proc"/s,

‎doc/src/sgml/auto-explain.sgml

+19
Original file line numberDiff line numberDiff line change
@@ -63,6 +63,25 @@ LOAD 'auto_explain';
6363
</listitem>
6464
</varlistentry>
6565

66+
<varlistentry>
67+
<term>
68+
<varname>auto_explain.log_parameter_max_length</varname> (<type>integer</type>)
69+
<indexterm>
70+
<primary><varname>auto_explain.log_parameter_max_length</varname> configuration parameter</primary>
71+
</indexterm>
72+
</term>
73+
<listitem>
74+
<para>
75+
<varname>auto_explain.log_parameter_max_length</varname> controls the
76+
logging of query parameter values. A value of<literal>-1</literal> (the
77+
default) logs the parameter values in full. <literal>0</literal> disables
78+
logging of parameter values. A value greater than zero truncates each
79+
parameter value to that many bytes. Only superusers can change this
80+
setting.
81+
</para>
82+
</listitem>
83+
</varlistentry>
84+
6685
<varlistentry>
6786
<term>
6887
<varname>auto_explain.log_analyze</varname> (<type>boolean</type>)

‎src/backend/commands/explain.c

+22
Original file line numberDiff line numberDiff line change
@@ -972,6 +972,28 @@ ExplainQueryText(ExplainState *es, QueryDesc *queryDesc)
972972
ExplainPropertyText("Query Text", queryDesc->sourceText, es);
973973
}
974974

975+
/*
976+
* ExplainQueryParameters -
977+
* add a "Query Parameters" node that describes the parameters of the query
978+
*
979+
* The caller should have set up the options fields of *es, as well as
980+
* initializing the output buffer es->str.
981+
*
982+
*/
983+
void
984+
ExplainQueryParameters(ExplainState *es, ParamListInfo params, int maxlen)
985+
{
986+
char *str;
987+
988+
/* This check is consistent with errdetail_params() */
989+
if (params == NULL || params->numParams <= 0 || maxlen == 0)
990+
return;
991+
992+
str = BuildParamLogString(params, NULL, maxlen);
993+
if (str && str[0] != '\0')
994+
ExplainPropertyText("Query Parameters", str, es);
995+
}
996+
975997
/*
976998
* report_triggers -
977999
* report execution stats for a single relation's triggers

‎src/include/commands/explain.h

+1
Original file line numberDiff line numberDiff line change
@@ -99,6 +99,7 @@ extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc);
9999
extern void ExplainPrintJITSummary(ExplainState *es, QueryDesc *queryDesc);
100100

101101
extern void ExplainQueryText(ExplainState *es, QueryDesc *queryDesc);
102+
extern void ExplainQueryParameters(ExplainState *es, ParamListInfo params, int maxlen);
102103

103104
extern void ExplainBeginOutput(ExplainState *es);
104105
extern void ExplainEndOutput(ExplainState *es);

0 commit comments

Comments
 (0)