On 2019-Dec-05, Tom Lane wrote:
> Possibly a workable compromise is to emit the info as an error
> context line, appending it to whatever context exists today.
> The result might look like, say,
>
> ERROR: whatever
> CONTEXT: SQL function "foo"
> extended query with parameters x, y, ...
This is easy to accomodate -- just change the errdetail() to errcontext.
That makes the params be reported different than in the non-error case
(for duration).
> For extra credit maybe we could include the query's statement or
> portal name?
>
> errcontext("extended query \"%s\" with parameters %s", ...);
Sure. Done in the attached.
> An independent point: it seems like just wishful thinking to imagine that
> src/test/examples/ can serve as a regression test for this. Nor is the
> proposed program very useful as an example. I'd drop that and find a
> way to have an actual, routinely-exercised-by-check-world regression
> test. If memory serves, pgbench can be cajoled into executing stuff
> in extended query mode --- maybe we could create a test case using
> that?
I tried
pgbench -c1 -t1 -n -M prepared -f errparameters.bnch
with this file
select '{ invalid ' as value \gset
select column1::jsonb from (values (:value)) as q;
and got these lines:
2019-12-06 13:49:36.388 -03 [31028] ERROR: invalid input syntax for type json
2019-12-06 13:49:36.388 -03 [31028] DETAIL: Token "invalid" is invalid.
2019-12-06 13:49:36.388 -03 [31028] CONTEXT: JSON data, line 1: { invalid...
extended query with parameters: $1 = '{ invalid '
2019-12-06 13:49:36.388 -03 [31028] STATEMENT: select column1::jsonb from
(values ($1)) as q;
With this file,
select '1' as one \gset
SELECT 1 / (random() / 2)::int, :one::int, :two::int;
using the same pgbench invocation as above, I get this in the log:
2019-12-06 14:50:59.181 -03 [6187] ERROR: division by zero
2019-12-06 14:50:59.181 -03 [6187] CONTEXT: extended query with parameters: $1
= '1', $2 = NULL
2019-12-06 14:50:59.181 -03 [6187] STATEMENT: SELECT 1 / (random() / 2)::int,
$1::int, $2::int;
(While testing this I noticed that failing to strdup the text repr of
the datum when it's given as a text-format parameter results in bogus
output. So I added a pstrdup there.)
(It seems a bit weird that if I assign NULL to :two pgbench stores the
empty string, instead of the NULL that I get as in the above which is
what happens when the variable is not defined at all. That's probably a
bug in \gset ...)
--
Álvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
diff --git a/src/backend/nodes/params.c b/src/backend/nodes/params.c
index 13d90f6551..a881df578e 100644
--- a/src/backend/nodes/params.c
+++ b/src/backend/nodes/params.c
@@ -23,6 +23,7 @@
#include "utils/datum.h"
#include "utils/lsyscache.h"
#include "utils/memutils.h"
+#include "utils/portal.h"
/*
@@ -361,14 +362,17 @@ BuildParamLogString(ParamListInfo params, char **knownTextValues)
void
ParamsErrorCallback(void *arg)
{
- ParamListInfo params = (ParamListInfo) arg;
+ ParamsErrorCbData *data = (ParamsErrorCbData *) arg;
- if (params == NULL || params->paramValuesStr == NULL)
+ if (data == NULL ||
+ data->params == NULL ||
+ data->params->paramValuesStr == NULL)
return;
- /*
- * XXX this clobbers any other DETAIL line that the error callsite could
- * have had. Do we care?
- */
- errdetail("parameters: %s", params->paramValuesStr);
+ if (data->portalName && data->portalName[0] != '\0')
+ errcontext("extended query \"%s\" with parameters: %s",
+ data->portalName, data->params->paramValuesStr);
+ else
+ errcontext("extended query with parameters: %s",
+ data->params->paramValuesStr);
}
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 9a009a5a9b..05a03ae924 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -1753,7 +1753,7 @@ exec_bind_message(StringInfo input_message)
*/
if (numParams > 0)
{
- char **knownTextValues = NULL;
+ char **knownTextValues = NULL; /* allocate on first use */
params = makeParamList(numParams);
@@ -1822,22 +1822,19 @@ exec_bind_message(StringInfo input_message)
pval = OidInputFunctionCall(typinput, pstring, typioparam, -1);
- /*
- * Save the parameter string if we need it; otherwise free it.
- */
+ /* When logging params, save a copy for later. */
if (pstring)
{
if (log_parameters_on_error)
{
- /*
- * Allocate this on first use, making sure to put it
- * in a short-lived context.
- */
if (knownTextValues == NULL)
knownTextValues =
MemoryContextAllocZero(MessageContext,
numParams * sizeof(char *));
- knownTextValues[paramno] = pstring;
+ knownTextValues[paramno] =
+ pstring == pbuf.data ?
+ MemoryContextStrdup(MessageContext, pstring) :
+ pstring;
}
else if (pstring != pbuf.data)
pfree(pstring);
@@ -1905,7 +1902,8 @@ exec_bind_message(StringInfo input_message)
/* Set the error callback so that parameters are logged, as needed */
params_errcxt.previous = error_context_stack;
params_errcxt.callback = ParamsErrorCallback;
- params_errcxt.arg = (void *) params;
+ params_errcxt.arg = (void *) &((ParamsErrorCbData)
+ { portal->name, params });
error_context_stack = ¶ms_errcxt;
/* Get the result format codes */
@@ -2145,7 +2143,8 @@ exec_execute_message(const char *portal_name, long max_rows)
*/
params_errcxt.previous = error_context_stack;
params_errcxt.callback = ParamsErrorCallback;
- params_errcxt.arg = (void *) portalParams;
+ params_errcxt.arg = (void *) &((ParamsErrorCbData)
+ { portal->name, portalParams });
error_context_stack = ¶ms_errcxt;
if (max_rows <= 0)
diff --git a/src/include/nodes/params.h b/src/include/nodes/params.h
index ba51dfe5e0..1e557ca7fd 100644
--- a/src/include/nodes/params.h
+++ b/src/include/nodes/params.h
@@ -150,6 +150,12 @@ typedef struct ParamExecData
bool isnull;
} ParamExecData;
+/* type of argument for ParamsErrorCallback */
+typedef struct ParamsErrorCbData
+{
+ const char *portalName;
+ ParamListInfo params;
+} ParamsErrorCbData;
/* Functions found in src/backend/nodes/params.c */
extern ParamListInfo makeParamList(int numParams);
