Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-03-16 Thread Tom Lane
Justin Pryzby  writes:
> I think it's somewhat confusing that there's two callbacks.
> The first one applies only during typinput/typreceive.
> I guess the 2nd one should say that they're printed "in *future errors".

I adjusted the comments to make this a bit clearer, and pushed it.

regards, tom lane




Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-03-15 Thread Justin Pryzby
On Mon, Mar 15, 2021 at 08:30:18PM -0400, Tom Lane wrote:
> +   /* Pop the error callback */
> +   error_context_stack = error_context_stack->previous;
> +
> /*
>  * 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,
...

I think it's somewhat confusing that there's two callbacks.
The first one applies only during typinput/typreceive.
I guess the 2nd one should say that they're printed "in *future errors".

> +# Check that errors are reported during BIND phase, too

Actually, the v13 log_parameter_max_length_on_error feature works during BIND
too, but only after typinput of *all* params.

For example, this shows params when failing in GetCachedPlan().

| python3.5 -c "import pg,time; db=pg.DB('dbname=postgres 
host=/var/run/postgresql port=5432 host=/tmp'); q = db.query(\"SET 
backtrace_functions=pg_strtoint16; SET 
log_parameter_max_length_on_error=-1;\"); db.prepare('p', 'SELECT a::smallint 
from (select \$1 a)a'); db.query_prepared('p',6);"

So my own description of the patch evolved from "show errors during BIND" to
"show errors during typinput of text params".

Thanks,
-- 
Justin




Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-03-15 Thread Tom Lane
Justin Pryzby  writes:
> On Mon, Mar 15, 2021 at 06:45:49PM -0400, Tom Lane wrote:
>> I started to look at this, and immediately began to wonder where is the
>> previous discussion you're evidently referring to.  Can you dig up an
>> archives link?

> I think I was referring to this (from the commit message).
> https://www.postgresql.org/message-id/flat/canfkh5k-6nnt-4csv1vpb80nq2bzczhfvr5o4vznybsx0wz...@mail.gmail.com

Got it, thanks.

After studying the patch it seems like there's a better way to do it:
we should just log the single parameter that's at fault.  That saves
the user from having to dig through a bunch of parameters to figure
out which one we're complaining about, plus we can usefully identify
the parameter (by number) even if it was sent in binary.

This is a little bit more net code addition than what you had,
but only by ten lines or so.  On the plus side, it doesn't
require rearranging any existing code.

regards, tom lane

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 8a0332dde9..b9ac6b8f76 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -102,7 +102,18 @@ int			max_stack_depth = 100;
 /* wait N seconds to allow attach from a debugger */
 int			PostAuthDelay = 0;
 
+/* 
+ *		private typedefs etc
+ * 
+ */
 
+/* type of argument for bind_param_error_callback */
+typedef struct BindParamCbData
+{
+	const char *portalName;
+	int			paramno;		/* zero-based param number, or -1 initially */
+	const char *paramval;		/* textual input string, if available */
+} BindParamCbData;
 
 /* 
  *		private variables
@@ -183,6 +194,7 @@ static int	errdetail_execute(List *raw_parsetree_list);
 static int	errdetail_params(ParamListInfo params);
 static int	errdetail_abort(void);
 static int	errdetail_recovery_conflict(void);
+static void bind_param_error_callback(void *arg);
 static void start_xact_command(void);
 static void finish_xact_command(void);
 static bool IsTransactionExitStmt(Node *parsetree);
@@ -1698,6 +1710,16 @@ exec_bind_message(StringInfo input_message)
 	if (numParams > 0)
 	{
 		char	  **knownTextValues = NULL; /* allocate on first use */
+		BindParamCbData one_param_data;
+
+		/* Set the error callback so that parameters are logged for errors */
+		one_param_data.portalName = portal->name;
+		one_param_data.paramno = -1;
+		one_param_data.paramval = NULL;
+		params_errcxt.previous = error_context_stack;
+		params_errcxt.callback = bind_param_error_callback;
+		params_errcxt.arg = (void *) _param_data;
+		error_context_stack = _errcxt;
 
 		params = makeParamList(numParams);
 
@@ -1711,6 +1733,9 @@ exec_bind_message(StringInfo input_message)
 			char		csave;
 			int16		pformat;
 
+			one_param_data.paramno = paramno;
+			one_param_data.paramval = NULL;
+
 			plength = pq_getmsgint(input_message, 4);
 			isNull = (plength == -1);
 
@@ -1764,8 +1789,13 @@ exec_bind_message(StringInfo input_message)
 else
 	pstring = pg_client_to_server(pbuf.data, plength);
 
+/* Now we can log the input string in case of error */
+one_param_data.paramval = pstring;
+
 pval = OidInputFunctionCall(typinput, pstring, typioparam, -1);
 
+one_param_data.paramval = NULL;
+
 /*
  * If we might need to log parameters later, save a copy of
  * the converted string in MessageContext; then free the
@@ -1855,6 +1885,9 @@ exec_bind_message(StringInfo input_message)
 			params->params[paramno].ptype = ptype;
 		}
 
+		/* Pop the error callback */
+		error_context_stack = error_context_stack->previous;
+
 		/*
 		 * Once all parameters have been received, prepare for printing them
 		 * in errors, if configured to do so.  (This is saved in the portal,
@@ -2413,6 +2446,55 @@ errdetail_recovery_conflict(void)
 	return 0;
 }
 
+/*
+ * bind_param_error_callback
+ *
+ * Error context callback used while parsing parameters in a Bind message
+ */
+static void
+bind_param_error_callback(void *arg)
+{
+	BindParamCbData *data = (BindParamCbData *) arg;
+	StringInfoData buf;
+	char	   *quotedval;
+
+	if (data->paramno < 0)
+		return;
+
+	/* If we have a textual value, quote it, and trim if necessary */
+	if (data->paramval)
+	{
+		initStringInfo();
+		appendStringInfoStringQuoted(, data->paramval,
+	 log_parameter_max_length_on_error);
+		quotedval = buf.data;
+	}
+	else
+		quotedval = NULL;
+
+	if (data->portalName && data->portalName[0] != '\0')
+	{
+		if (quotedval)
+			errcontext("portal \"%s\" parameter $%d = %s",
+	   data->portalName, data->paramno + 1, quotedval);
+		else
+			errcontext("portal \"%s\" parameter $%d",
+	   data->portalName, data->paramno + 1);
+	}
+	else
+	{
+		if (quotedval)
+			errcontext("unnamed portal parameter $%d = %s",
+	   data->paramno + 1, quotedval);
+		else
+			errcontext("unnamed portal parameter $%d",
+	   data->paramno + 1);
+	}
+
+	if (quotedval)
+		pfree(quotedval);
+}
+
 /*
  * 

Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-03-15 Thread Justin Pryzby
On Mon, Mar 15, 2021 at 06:45:49PM -0400, Tom Lane wrote:
> Justin Pryzby  writes:
> > 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',6);"
> > 2021-01-03 02:21:04.547 CST [20157] ERROR:  value "6" is out of range 
> > for type smallint
> > 2021-01-03 02:21:04.547 CST [20157] CONTEXT:  unnamed portal with 
> > parameters: $1 = '6'
> > 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(),(),()...
> 
> > Of course, this isn't as good as showing the column name, so I might pursue
> > Tom's suggestion for that at some point.
> 
> I started to look at this, and immediately began to wonder where is the
> previous discussion you're evidently referring to.  Can you dig up an
> archives link?

I think I was referring to this (from the commit message).
https://www.postgresql.org/message-id/flat/canfkh5k-6nnt-4csv1vpb80nq2bzczhfvr5o4vznybsx0wz...@mail.gmail.com

Also, I looked through the original thread, and found this was discussed at the
time:

https://www.postgresql.org/message-id/b1b68453-9756-bd92-306e-a29fc5ad7cd7%402ndquadrant.com
> >> ERROR:  value "62812" is out of range for type smallint
> >> STATEMENT:  SELECT abalance FROM pgbench_accounts WHERE aid = $1;
> >>
> >> (In this case the error message contains the parameter value, so it's
> >> not a very practical case, but it should work, it seems.)
> > I guess this error occurred /while/ binding, so the parameters probably
> > weren't yet all bound by the time of error reporting.
> > That's why the error message came without parameters.
> 
> I see.  But I think that could be fixed.  Change exec_bind_message() to
> loop over the parameters twice: once to save them away, once to actually
> process them.  I think the case of a faulty input value is probably very
> common, so it would be confusing if that didn't work.

https://www.postgresql.org/message-id/resend/20191205231550.GA28677%40alvherre.pgsql
> One problem I noticed is that we don't log parameters when
> exec_bind_message fetches the parameter values.  So the very first
> example problem in testlibpq5 fails to print the values of any
> parameters previously seen.  I don't think this is a real problem in
> practice.  You still get the unparseable value in the error message from
> the input function, so not having the errdetail() does not seem very
> important.

I see that as a deficiency (as Peter did), so I'm requesting to improve that
now.  It's not a bugfix, though.

-- 
Justin




Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-03-15 Thread Tom Lane
Justin Pryzby  writes:
> 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',6);"
> 2021-01-03 02:21:04.547 CST [20157] ERROR:  value "6" is out of range for 
> type smallint
> 2021-01-03 02:21:04.547 CST [20157] CONTEXT:  unnamed portal with parameters: 
> $1 = '6'
> 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(),(),()...

> Of course, this isn't as good as showing the column name, so I might pursue
> Tom's suggestion for that at some point.

I started to look at this, and immediately began to wonder where is the
previous discussion you're evidently referring to.  Can you dig up an
archives link?

regards, tom lane




Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-02-23 Thread Justin Pryzby
On Mon, Feb 22, 2021 at 11:15:25AM -0600, Justin Pryzby wrote:
> 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',6);"
> > > 2021-01-03 02:21:04.547 CST [20157] ERROR:  value "6" is out of range 
> > > for type smallint
> > > 2021-01-03 02:21:04.547 CST [20157] CONTEXT:  unnamed portal with 
> > > parameters: $1 = '6'
> > > 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 noticed that this would crash with binary mode parameter input from
PQexecParams, if typinput failed.

So this patch allows reporting of bind params on errors in typinput if all the
params are sent in text mode (which is typical).

But if they're sent in binary mode, we can't provide error output before
they're processed by the typinput function.

I added ecpg tests to exercize the binary mode cases.

-- 
Justin
>From feddd203edc7175ed7463f39078cd5f573fae308 Mon Sep 17 00:00:00 2001
From: Justin Pryzby 
Date: Fri, 1 Jan 2021 19:38:57 -0600
Subject: [PATCH 1/3] Report text parameters during errors in typinput

Since v13, bind parameters have been logged during errors in BIND/EXECUTE, but
the BIND errors didn't happen during type conversion, which misses cases
involving simple VALUES() lists.

This patch also includes the bind parameters in errors which happen during the
typinput function, for text mode bind parameters.

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',6);"
2021-01-01 19:40:24.777 CST [5330] ERROR:  value "6" is out of range for type smallint
2021-01-01 19:40:24.777 CST [5330] CONTEXT:  unnamed portal with parameters: $1 = '6'

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-4csv1vpb80nq2bzczhfvr5o4vznybsx0wz...@mail.gmail.com
  Mention column name in error messages
---
 src/backend/tcop/postgres.c  | 185 +--
 src/bin/pgbench/t/001_pgbench_with_server.pl |  18 ++
 2 files changed, 146 insertions(+), 57 deletions(-)

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index bb5ccb4578..95be9ba460 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -1759,14 +1759,130 @@ 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 *) _data;
+	error_context_stack = _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;
+		bool		textonly = true;
+
+		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 parameters to be displayed in error
+		 * reports during typinput.
+		 * 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 that fails, text params have already been saved and can
+		 * be displayed by the 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;
+
+	

Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-02-22 Thread Justin Pryzby
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',6);"
> > 2021-01-03 02:21:04.547 CST [20157] ERROR:  value "6" is out of range 
> > for type smallint
> > 2021-01-03 02:21:04.547 CST [20157] CONTEXT:  unnamed portal with 
> > parameters: $1 = '6'
> > 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
>From 0cfc8ad16edea93ac1de223684e22725d1e86988 Mon Sep 17 00:00:00 2001
From: Justin Pryzby 
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',6);"
2021-01-01 19:40:24.777 CST [5330] ERROR:  value "6" is out of range for type smallint
2021-01-01 19:40:24.777 CST [5330] CONTEXT:  unnamed portal with parameters: $1 = '6'

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-4csv1vpb80nq2bzczhfvr5o4vznybsx0wz...@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.c
index 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 *) _data;
+	error_context_stack = _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 * 

Re: [PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-02-21 Thread Justin Pryzby
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',6);"
> 2021-01-03 02:21:04.547 CST [20157] ERROR:  value "6" is out of range for 
> type smallint
> 2021-01-03 02:21:04.547 CST [20157] CONTEXT:  unnamed portal with parameters: 
> $1 = '6'
> 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.

-- 
Justin
>From 1796775733edec40ad5515270e3b002c202ca23f Mon Sep 17 00:00:00 2001
From: Justin Pryzby 
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',6);"
2021-01-01 19:40:24.777 CST [5330] ERROR:  value "6" is out of range for type smallint
2021-01-01 19:40:24.777 CST [5330] CONTEXT:  unnamed portal with parameters: $1 = '6'

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-4csv1vpb80nq2bzczhfvr5o4vznybsx0wz...@mail.gmail.com
  Mention column name in error messages
---
 src/backend/tcop/postgres.c | 170 +++-
 1 file changed, 108 insertions(+), 62 deletions(-)

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index bb5ccb4578..3965f37e85 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -1618,7 +1618,7 @@ exec_bind_message(StringInfo input_message)
 	Portal		portal;
 	char	   *query_string;
 	char	   *saved_stmt_name;
-	ParamListInfo params;
+	ParamListInfo params = NULL;
 	MemoryContext oldContext;
 	bool		save_log_statement_stats = log_statement_stats;
 	bool		snapshot_set = false;
@@ -1759,15 +1759,115 @@ 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 = params;
+	params_errcxt.previous = error_context_stack;
+	params_errcxt.callback = ParamsErrorCallback;
+	params_errcxt.arg = (void *) _data;
+	error_context_stack = _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);
 
+		/*
+		 * 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);
+			else
+			{
+/*
+ * We can trim the saved string, knowing that we
+ * won't print all of it.  But we must copy at

[PATCH]: Allow errors in parameter values to be reported during the BIND phase itself..

2021-01-04 Thread Justin Pryzby
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',6);"
2021-01-03 02:21:04.547 CST [20157] ERROR:  value "6" is out of range for 
type smallint
2021-01-03 02:21:04.547 CST [20157] CONTEXT:  unnamed portal with parameters: 
$1 = '6'
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(),(),()...

Of course, this isn't as good as showing the column name, so I might pursue
Tom's suggestion for that at some point.

-- 
Justin
>From 40dd798d8518b4d113dbf70c37687c87bf734659 Mon Sep 17 00:00:00 2001
From: Justin Pryzby 
Date: Fri, 1 Jan 2021 19:38:57 -0600
Subject: [PATCH] Allow errors in parameter values to be reported during the
 BIND phase itself..

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',6);"
2021-01-01 19:40:24.777 CST [5330] ERROR:  value "6" is out of range for type smallint
2021-01-01 19:40:24.777 CST [5330] CONTEXT:  unnamed portal with parameters: $1 = '6'

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-4csv1vpb80nq2bzczhfvr5o4vznybsx0wz...@mail.gmail.com
  Mention column name in error messages
---
 src/backend/tcop/postgres.c | 166 +++-
 1 file changed, 106 insertions(+), 60 deletions(-)

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 317d1aa573..30fb86d97f 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -1765,9 +1765,109 @@ exec_bind_message(StringInfo input_message)
 	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);
 
+		/*
+		 * 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 require 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);
+			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 != 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);
+		}
+
+		/* Set the error