From: Tom Lane <tgl@sss.pgh.pa.us>
To: Justin Pryzby <pryzby@telsasoft.com>
cc: Alvaro Herrera <alvherre@alvh.no-ip.org>,
        Alexey Bashtanov <bashtanov@imap.cc>,
 Franck Verrot <franck@verrot.fr>,
        pgsql-hackers@postgresql.org
Subject: Re: [PATCH]: Allow errors in parameter values to be reported during
 the BIND phase itself..
In-reply-to: <20210315224945.GB29463@telsasoft.com>
References: <20210104170939.GH9712@telsasoft.com>
 <3087634.1615848349@sss.pgh.pa.us> <20210315224945.GB29463@telsasoft.com>
Comments: In-reply-to Justin Pryzby <pryzby@telsasoft.com>
	message dated "Mon, 15 Mar 2021 17:49:45 -0500"
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="----- =_aaaaaaaaaa0"
Content-ID: <3140502.1615854606.0@sss.pgh.pa.us>
Date: Mon, 15 Mar 2021 20:30:18 -0400
Message-ID: <3140512.1615854618@sss.pgh.pa.us>
Archived-At: 
 <https://www.postgresql.org/message-id/3140512.1615854618%40sss.pgh.pa.us>
Precedence: bulk

------- =_aaaaaaaaaa0
Content-Type: text/plain; charset="us-ascii"
Content-ID: <3140502.1615854606.1@sss.pgh.pa.us>
Content-Transfer-Encoding: quoted-printable

Justin Pryzby <pryzby@telsasoft.com> 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-4cSv1vPB80nq2BZ=
CzhFVR5O4VznYbsX0wZmow@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


------- =_aaaaaaaaaa0
Content-Type: text/x-diff; name="0001-identify-bad-bind-parameters.patch";
	charset="us-ascii"
Content-ID: <3140502.1615854606.2@sss.pgh.pa.us>
Content-Description: 0001-identify-bad-bind-parameters.patch
Content-Transfer-Encoding: quoted-printable

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 =3D 100;
 /* wait N seconds to allow attach from a debugger */
 int			PostAuthDelay =3D 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 =3D NULL; /* allocate on first use */
+		BindParamCbData one_param_data;
+
+		/* Set the error callback so that parameters are logged for errors */
+		one_param_data.portalName =3D portal->name;
+		one_param_data.paramno =3D -1;
+		one_param_data.paramval =3D NULL;
+		params_errcxt.previous =3D error_context_stack;
+		params_errcxt.callback =3D bind_param_error_callback;
+		params_errcxt.arg =3D (void *) &one_param_data;
+		error_context_stack =3D &params_errcxt;
 =

 		params =3D makeParamList(numParams);
 =

@@ -1711,6 +1733,9 @@ exec_bind_message(StringInfo input_message)
 			char		csave;
 			int16		pformat;
 =

+			one_param_data.paramno =3D paramno;
+			one_param_data.paramval =3D NULL;
+
 			plength =3D pq_getmsgint(input_message, 4);
 			isNull =3D (plength =3D=3D -1);
 =

@@ -1764,8 +1789,13 @@ exec_bind_message(StringInfo input_message)
 				else
 					pstring =3D pg_client_to_server(pbuf.data, plength);
 =

+				/* Now we can log the input string in case of error */
+				one_param_data.paramval =3D pstring;
+
 				pval =3D OidInputFunctionCall(typinput, pstring, typioparam, -1);
 =

+				one_param_data.paramval =3D 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 =3D ptype;
 		}
 =

+		/* Pop the error callback */
+		error_context_stack =3D 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 =3D (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(&buf);
+		appendStringInfoStringQuoted(&buf, data->paramval,
+									 log_parameter_max_length_on_error);
+		quotedval =3D buf.data;
+	}
+	else
+		quotedval =3D NULL;
+
+	if (data->portalName && data->portalName[0] !=3D '\0')
+	{
+		if (quotedval)
+			errcontext("portal \"%s\" parameter $%d =3D %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 =3D %s",
+					   data->paramno + 1, quotedval);
+		else
+			errcontext("unnamed portal parameter $%d",
+					   data->paramno + 1);
+	}
+
+	if (quotedval)
+		pfree(quotedval);
+}
+
 /*
  * exec_describe_statement_message
  *
diff --git a/src/bin/pgbench/t/001_pgbench_with_server.pl b/src/bin/pgbenc=
h/t/001_pgbench_with_server.pl
index d11c4e8c24..b66e564802 100644
--- a/src/bin/pgbench/t/001_pgbench_with_server.pl
+++ b/src/bin/pgbench/t/001_pgbench_with_server.pl
@@ -389,6 +389,22 @@ like(
 	"parameter report truncates");
 $log =3D undef;
 =

+# Check that errors are reported during BIND phase, too
+pgbench(
+	'-n -t1 -c1 -M prepared',
+	2,
+	[],
+	[
+		qr{ERROR:  invalid input syntax for type smallint: "1a"},
+		qr{CONTEXT:  unnamed portal parameter \$2 =3D '1a'}
+	],
+	'server parameter logging',
+	{
+		'001_param_6' =3D> q{select 42 as value1, '1a' as value2 \gset
+select :value1::smallint, :value2::smallint;
+}
+	});
+
 # Restore default logging config
 $node->append_conf('postgresql.conf',
 	    "log_min_duration_statement =3D -1\n"

------- =_aaaaaaaaaa0--