From: Justin Pryzby <pryzby@telsasoft.com>
To: Alvaro Herrera <alvherre@alvh.no-ip.org>
Cc: Alexey Bashtanov <bashtanov@imap.cc>
Cc: Franck Verrot <franck@verrot.fr>
Cc: pgsql-hackers@postgresql.org
Subject: Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..
Date: Mon, 22 Feb 2021 11:15:25 -0600
Message-ID: <20210222171525.GU14772@telsasoft.com> (raw)
In-Reply-To: <20210222050526.GA11347@telsasoft.com>
References: <20210104170939.GH9712@telsasoft.com>
<20210222050526.GA11347@telsasoft.com>
On Sun, Feb 21, 2021 at 11:05:26PM -0600, Justin Pryzby wrote:
> On Mon, Jan 04, 2021 at 11:09:39AM -0600, Justin Pryzby wrote:
> > For example:
> >
> > $ python3.5 -c "import pg; db=pg.DB(); q = db.query(\"SET log_parameter_max_length_on_error=-1;\"); db.prepare('p', 'SELECT \$1::smallint'); db.query_prepared('p',66666);"
> > 2021-01-03 02:21:04.547 CST [20157] ERROR: value "66666" is out of range for type smallint
> > 2021-01-03 02:21:04.547 CST [20157] CONTEXT: unnamed portal with parameters: $1 = '66666'
> > 2021-01-03 02:21:04.547 CST [20157] STATEMENT: SELECT $1::smallint
> >
> > When there are many bind params, this can be useful to determine which is out
> > of range. Think 900 int/smallint columns, or less-wide tables being inserted
> > multiple rows at a time with VALUES(),(),()...
>
> This fixes a crash when there are zero bind params, and the error context was
> popped after not being pushed.
The previous patch was dysfynctional due to params_data.params = NULL.
This also fixes an issue with string termination.
And added a new test case.
I didn't understand how the existing pgbench test was working; apparently the
first of these queries generates parameter value CONTEXT messages in v13, but
(without my patch) not the 2nd.
| select column1::smallint from (values ($1)) as q;
| select $1::smallint
In the first case, it looks like:
postgres: pryzbyj postgres [local] BIND(int2in+0x11) [0x55a57addd461]
postgres: pryzbyj postgres [local] BIND(evaluate_expr+0x94) [0x55a57acba634]
postgres: pryzbyj postgres [local] BIND(expression_tree_mutator+0x99) [0x55a57ac5a839]
postgres: pryzbyj postgres [local] BIND(expression_tree_mutator+0x31e) [0x55a57ac5aabe]
postgres: pryzbyj postgres [local] BIND(eval_const_expressions+0x53) [0x55a57acbbc73]
postgres: pryzbyj postgres [local] BIND(subquery_planner+0x5a9) [0x55a57aca7159]
postgres: pryzbyj postgres [local] BIND(standard_planner+0x113) [0x55a57aca8a63]
postgres: pryzbyj postgres [local] BIND(pg_plan_query+0x4c) [0x55a57ad7cbfc]
postgres: pryzbyj postgres [local] BIND(pg_plan_queries+0x41) [0x55a57ad7ccf1]
postgres: pryzbyj postgres [local] BIND(GetCachedPlan+0x7d) [0x55a57ae87b9d]
postgres: pryzbyj postgres [local] BIND(PostgresMain+0xe82) [0x55a57ad7e352]
In the 2nd case:
postgres: pryzbyj postgres [local] BIND(int2in+0x11) [0x55a57addd461]
postgres: pryzbyj postgres [local] BIND(InputFunctionCall+0x7f) [0x55a57aea19df]
postgres: pryzbyj postgres [local] BIND(OidInputFunctionCall+0x4d) [0x55a57aea1bad]
postgres: pryzbyj postgres [local] BIND(PostgresMain+0x1754) [0x55a57ad7ec24]
This could be considered a bugfix to v13, since ba79cb5dc says:
"Emit parameter values during query bind/execute errors"
--
Justin
Attachments:0001-report-errors-in-parameter-values-during-BIND.patch (text/x-diff, 9.2K) download
From 0cfc8ad16edea93ac1de223684e22725d1e86988 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryzbyj@telsasoft.com>
Date: Fri, 1 Jan 2021 19:38:57 -0600
Subject: [PATCH] report errors in parameter values during BIND
For example:
$ python3.5 -c "import pg,time; db=pg.DB('dbname=postgres host=/var/run/postgresql port=5432 host=/tmp'); q = db.query(\"SET log_parameter_max_length_on_error=-1;\"); db.prepare('p', 'SELECT \$1::smallint'); db.query_prepared('p',66666);"
2021-01-01 19:40:24.777 CST [5330] ERROR: value "66666" is out of range for type smallint
2021-01-01 19:40:24.777 CST [5330] CONTEXT: unnamed portal with parameters: $1 = '66666'
This can be useful to determine which is out of range when there are many bind
params.
See also:
commit ba79cb5dc
commit 0b34e7d30
https://www.postgresql.org/message-id/flat/CANfkH5k-6nNt-4cSv1vPB80nq2BZCzhFVR5O4VznYbsX0wZmow@mail.gmail.com
Mention column name in error messages
---
src/backend/tcop/postgres.c | 175 ++++++++++++-------
src/bin/pgbench/t/001_pgbench_with_server.pl | 18 ++
2 files changed, 132 insertions(+), 61 deletions(-)
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.cindex bb5ccb4578..553b2e30fe 100644--- a/src/backend/tcop/postgres.c+++ b/src/backend/tcop/postgres.c@@ -1759,14 +1759,121 @@ exec_bind_message(StringInfo input_message)
snapshot_set = true;
}
+ /*+ * Set the error callback so that parameters are logged, as needed.+ * This has no effect until params->paramValuesStr is set+ */+ params_data.portalName = portal->name;+ params_data.params = NULL;+ params_errcxt.previous = error_context_stack;+ params_errcxt.callback = ParamsErrorCallback;+ params_errcxt.arg = (void *) ¶ms_data;+ error_context_stack = ¶ms_errcxt;+
/*
* Fetch parameters, if any, and store in the portal's memory context.
*/
if (numParams > 0)
{
char **knownTextValues = NULL; /* allocate on first use */
+ int32 *plengths;+ char **pstrings;++ plengths = palloc0(numParams * sizeof(*plengths));++ /* Indexed by paramno, but not used for nulls */+ pstrings = palloc0(numParams * sizeof(*pstrings));
params = makeParamList(numParams);
+ params_data.params = params;++ /*+ * Do two loops to allow error reports during BIND;+ * On the first pass, just save the offset and length of each param;+ * On the second pass, convert the params to the required type.+ * If this fails, the params have already been saved for error callack.+ */++ for (int paramno = 0; paramno < numParams; paramno++)+ {+ int32 plength;+ int16 pformat;+ char *pstring;+ MemoryContext oldcxt;++ plength = plengths[paramno] = pq_getmsgint(input_message, 4);++ /* Minimal amount needed for error callback */+ params->params[paramno].ptype = psrc->param_types[paramno];+ params->params[paramno].isnull = (plength == -1);++ if (params->params[paramno].isnull)+ continue;++ pstrings[paramno] = unconstify(char *, pq_getmsgbytes(input_message, plength));++ if (log_parameter_max_length_on_error == 0)+ continue;++ if (numPFormats > 1)+ pformat = pformats[paramno];+ else if (numPFormats > 0)+ pformat = pformats[0];+ else+ pformat = 0; /* default = text */++ if (pformat != 0) /* text mode */+ continue;++ /*+ * If we might need to log parameters later, save a copy of+ * the converted string in MessageContext;+ * XXX: only supported in text mode ??+ */+ pstring = pg_client_to_server(pstrings[paramno], plength);+ oldcxt = MemoryContextSwitchTo(MessageContext);++ if (knownTextValues == NULL)+ knownTextValues =+ palloc0(numParams * sizeof(char *));++ if (log_parameter_max_length_on_error < 0)+ {+ knownTextValues[paramno] = pstrdup(pstring);+ knownTextValues[paramno][plength] = 0;+ }+ else+ {+ /*+ * We can trim the saved string, knowing that we+ * won't print all of it. But we must copy at+ * least two more full characters than+ * BuildParamLogString wants to use; otherwise it+ * might fail to include the trailing ellipsis.+ */+ char csave = pstring[plength];+ pstring[plength] = 0;+ knownTextValues[paramno] =+ pnstrdup(pstring,+ log_parameter_max_length_on_error+ + 2 * MAX_MULTIBYTE_CHAR_LEN);+ pstring[plength] = csave;+ }++ MemoryContextSwitchTo(oldcxt);+ if (pstring != pstrings[paramno])+ pfree(pstring);+ }++ /*+ * Once all parameters have been received, prepare for printing them+ * in errors, if configured to do so. (This is saved in the portal,+ * so that they'll appear when the query is executed later.)+ */+ if (log_parameter_max_length_on_error != 0)+ params->paramValuesStr = BuildParamLogString(params,+ knownTextValues,+ log_parameter_max_length_on_error);
for (int paramno = 0; paramno < numParams; paramno++)
{
@@ -1778,13 +1885,11 @@ exec_bind_message(StringInfo input_message)
char csave;
int16 pformat;
- plength = pq_getmsgint(input_message, 4);+ plength = plengths[paramno];
isNull = (plength == -1);
if (!isNull)
{
- const char *pvalue = pq_getmsgbytes(input_message, plength);-
/*
* Rather than copying data around, we just set up a phony
* StringInfo pointing to the correct portion of the message
@@ -1793,7 +1898,7 @@ exec_bind_message(StringInfo input_message)
* trailing null. This is grotty but is a big win when
* dealing with very large parameter strings.
*/
- pbuf.data = unconstify(char *, pvalue);+ pbuf.data = pstrings[paramno];
pbuf.maxlen = plength + 1;
pbuf.len = plength;
pbuf.cursor = 0;
@@ -1833,45 +1938,9 @@ exec_bind_message(StringInfo input_message)
pval = OidInputFunctionCall(typinput, pstring, typioparam, -1);
- /*- * If we might need to log parameters later, save a copy of- * the converted string in MessageContext; then free the- * result of encoding conversion, if any was done.- */- if (pstring)- {- if (log_parameter_max_length_on_error != 0)- {- MemoryContext oldcxt;-- oldcxt = MemoryContextSwitchTo(MessageContext);-- if (knownTextValues == NULL)- knownTextValues =- palloc0(numParams * sizeof(char *));-- if (log_parameter_max_length_on_error < 0)- knownTextValues[paramno] = pstrdup(pstring);- else- {- /*- * We can trim the saved string, knowing that we- * won't print all of it. But we must copy at- * least two more full characters than- * BuildParamLogString wants to use; otherwise it- * might fail to include the trailing ellipsis.- */- knownTextValues[paramno] =- pnstrdup(pstring,- log_parameter_max_length_on_error- + 2 * MAX_MULTIBYTE_CHAR_LEN);- }-- MemoryContextSwitchTo(oldcxt);- }- if (pstring != pbuf.data)- pfree(pstring);- }+ /* free the result of encoding conversion, if any was done. */+ if (pstring && pstring != pbuf.data)+ pfree(pstring);
}
else if (pformat == 1) /* binary mode */
{
@@ -1922,16 +1991,8 @@ exec_bind_message(StringInfo input_message)
params->params[paramno].ptype = ptype;
}
- /*- * Once all parameters have been received, prepare for printing them- * in errors, if configured to do so. (This is saved in the portal,- * so that they'll appear when the query is executed later.)- */- if (log_parameter_max_length_on_error != 0)- params->paramValuesStr =- BuildParamLogString(params,- knownTextValues,- log_parameter_max_length_on_error);+ pfree(plengths);+ pfree(pstrings);
}
else
params = NULL;
@@ -1939,14 +2000,6 @@ exec_bind_message(StringInfo input_message)
/* Done storing stuff in portal's context */
MemoryContextSwitchTo(oldContext);
- /* Set the error callback so that parameters are logged, as needed */- params_data.portalName = portal->name;- params_data.params = params;- params_errcxt.previous = error_context_stack;- params_errcxt.callback = ParamsErrorCallback;- params_errcxt.arg = (void *) ¶ms_data;- error_context_stack = ¶ms_errcxt;-
/* Get the result format codes */
numRFormats = pq_getmsgint(input_message, 2);
if (numRFormats > 0)
diff --git a/src/bin/pgbench/t/001_pgbench_with_server.pl b/src/bin/pgbench/t/001_pgbench_with_server.plindex daffc18e52..936ae80f91 100644--- a/src/bin/pgbench/t/001_pgbench_with_server.pl+++ b/src/bin/pgbench/t/001_pgbench_with_server.pl@@ -350,6 +350,7 @@ $node->append_conf('postgresql.conf',
. "log_parameter_max_length = 7\n"
. "log_parameter_max_length_on_error = -1");
$node->reload;
+
pgbench(
'-n -t1 -c1 -M prepared',
2,
@@ -389,6 +390,23 @@ like(
"parameter report truncates");
$log = undef;
+# Check that errors happen during BIND phase, too+pgbench(+ '-n -t1 -c1 -M prepared',+ 2,+ [],+ [+ qr{ERROR: invalid input syntax for type smallint: "1a"},+ qr{CONTEXT: unnamed portal with parameters: \$1 = '1a'}+ ],+ 'server parameter logging',+ {+ '001_param_6' => q{select '1a' as value \gset+select :value::smallint;+}+ });++
# Restore default logging config
$node->append_conf('postgresql.conf',
"log_min_duration_statement = -1\n"
--
2.17.0
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, alvherre@alvh.no-ip.org, bashtanov@imap.cc, franck@verrot.fr
Subject: Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..
In-Reply-To: <20210222171525.GU14772@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