Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commitba79cb5

Browse files
committed
Emit parameter values during query bind/execute errors
This makes such log entries more useful, since the cause of the errorcan be dependent on the parameter values.Author: Alexey Bashtanov, Álvaro HerreraDiscussion:https://postgr.es/m/0146a67b-a22a-0519-9082-bc29756b93a2@imap.ccReviewed-by: Peter Eisentraut, Andres Freund, Tom Lane
1 parent16114f2 commitba79cb5

File tree

8 files changed

+271
-47
lines changed

8 files changed

+271
-47
lines changed

‎doc/src/sgml/config.sgml

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6595,6 +6595,29 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
65956595
</listitem>
65966596
</varlistentry>
65976597

6598+
<varlistentry id="guc-log-parameters-on-error" xreflabel="log_parameters_on_error">
6599+
<term><varname>log_parameters_on_error</varname> (<type>boolean</type>)
6600+
<indexterm>
6601+
<primary><varname>log_parameters_on_error</varname> configuration parameter</primary>
6602+
</indexterm>
6603+
</term>
6604+
<listitem>
6605+
<para>
6606+
Controls whether bind parameters are logged when a statement is logged
6607+
as a result of <xref linkend="guc-log-min-error-statement"/>.
6608+
It adds some overhead, as postgres will compute and store textual
6609+
representations of parameter values in memory for all statements,
6610+
even if they eventually do not get logged.
6611+
This setting has no effect on statements logged due to
6612+
<xref linkend="guc-log-min-duration-statement"/> or
6613+
<xref linkend="guc-log-statement"/> settings, as they are always logged
6614+
with parameters.
6615+
The default is <literal>off</literal>.
6616+
Only superusers can change this setting.
6617+
</para>
6618+
</listitem>
6619+
</varlistentry>
6620+
65986621
<varlistentry id="guc-log-statement" xreflabel="log_statement">
65996622
<term><varname>log_statement</varname> (<type>enum</type>)
66006623
<indexterm>

‎src/backend/nodes/params.c

Lines changed: 110 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,11 +15,14 @@
1515

1616
#include"postgres.h"
1717

18+
#include"access/xact.h"
19+
#include"mb/stringinfo_mb.h"
1820
#include"nodes/bitmapset.h"
1921
#include"nodes/params.h"
2022
#include"storage/shmem.h"
2123
#include"utils/datum.h"
2224
#include"utils/lsyscache.h"
25+
#include"utils/memutils.h"
2326

2427

2528
/*
@@ -44,6 +47,7 @@ makeParamList(int numParams)
4447
retval->paramCompileArg=NULL;
4548
retval->parserSetup=NULL;
4649
retval->parserSetupArg=NULL;
50+
retval->paramValuesStr=NULL;
4751
retval->numParams=numParams;
4852

4953
returnretval;
@@ -58,6 +62,8 @@ makeParamList(int numParams)
5862
* set of parameter values. If dynamic parameter hooks are present, we
5963
* intentionally do not copy them into the result. Rather, we forcibly
6064
* instantiate all available parameter values and copy the datum values.
65+
*
66+
* paramValuesStr is not copied, either.
6167
*/
6268
ParamListInfo
6369
copyParamList(ParamListInfofrom)
@@ -158,6 +164,8 @@ EstimateParamListSpace(ParamListInfo paramLI)
158164
* RestoreParamList can be used to recreate a ParamListInfo based on the
159165
* serialized representation; this will be a static, self-contained copy
160166
* just as copyParamList would create.
167+
*
168+
* paramValuesStr is not included.
161169
*/
162170
void
163171
SerializeParamList(ParamListInfoparamLI,char**start_address)
@@ -251,3 +259,105 @@ RestoreParamList(char **start_address)
251259

252260
returnparamLI;
253261
}
262+
263+
/*
264+
* BuildParamLogString
265+
*Return a string that represent the parameter list, for logging.
266+
*
267+
* If caller already knows textual representations for some parameters, it can
268+
* pass an array of exactly params->numParams values as knownTextValues, which
269+
* can contain NULLs for any unknown individual values. NULL can be given if
270+
* no parameters are known.
271+
*
272+
* If maxlen is not zero, that's the maximum number of characters of the
273+
* input string printed; an ellipsis is added if more characters exist.
274+
* (Added quotes are not considered.)
275+
*/
276+
char*
277+
BuildParamLogString(ParamListInfoparams,char**knownTextValues,intmaxlen)
278+
{
279+
MemoryContexttmpCxt,
280+
oldCxt;
281+
StringInfoDatabuf;
282+
283+
/*
284+
* NB: think not of returning params->paramValuesStr! It may have been
285+
* generated with a different maxlen, and so unsuitable.
286+
*/
287+
288+
/*
289+
* No work if the param fetch hook is in use. Also, it's not possible to
290+
* do this in an aborted transaction. (It might be possible to improve on
291+
* this last point when some knownTextValues exist, but it seems tricky.)
292+
*/
293+
if (params->paramFetch!=NULL||
294+
IsAbortedTransactionBlockState())
295+
returnNULL;
296+
297+
/* Initialize the output stringinfo, in caller's memory context */
298+
initStringInfo(&buf);
299+
300+
/* Use a temporary context to call output functions, just in case */
301+
tmpCxt=AllocSetContextCreate(CurrentMemoryContext,
302+
"BuildParamLogString",
303+
ALLOCSET_DEFAULT_SIZES);
304+
oldCxt=MemoryContextSwitchTo(tmpCxt);
305+
306+
for (intparamno=0;paramno<params->numParams;paramno++)
307+
{
308+
ParamExternData*param=&params->params[paramno];
309+
310+
appendStringInfo(&buf,
311+
"%s$%d = ",
312+
paramno>0 ?", " :"",
313+
paramno+1);
314+
315+
if (param->isnull|| !OidIsValid(param->ptype))
316+
appendStringInfoString(&buf,"NULL");
317+
else
318+
{
319+
if (knownTextValues!=NULL&&knownTextValues[paramno]!=NULL)
320+
appendStringInfoStringQuoted(&buf,knownTextValues[paramno],
321+
maxlen);
322+
else
323+
{
324+
Oidtypoutput;
325+
booltypisvarlena;
326+
char*pstring;
327+
328+
getTypeOutputInfo(param->ptype,&typoutput,&typisvarlena);
329+
pstring=OidOutputFunctionCall(typoutput,param->value);
330+
appendStringInfoStringQuoted(&buf,pstring,maxlen);
331+
}
332+
}
333+
}
334+
335+
MemoryContextSwitchTo(oldCxt);
336+
MemoryContextDelete(tmpCxt);
337+
338+
returnbuf.data;
339+
}
340+
341+
/*
342+
* ParamsErrorCallback - callback for printing parameters in error context
343+
*
344+
* Note that this is a no-op unless BuildParamLogString has been called
345+
* beforehand.
346+
*/
347+
void
348+
ParamsErrorCallback(void*arg)
349+
{
350+
ParamsErrorCbData*data= (ParamsErrorCbData*)arg;
351+
352+
if (data==NULL||
353+
data->params==NULL||
354+
data->params->paramValuesStr==NULL)
355+
return;
356+
357+
if (data->portalName&&data->portalName[0]!='\0')
358+
errcontext("extended query \"%s\" with parameters: %s",
359+
data->portalName,data->params->paramValuesStr);
360+
else
361+
errcontext("extended query with parameters: %s",
362+
data->params->paramValuesStr);
363+
}

‎src/backend/tcop/postgres.c

Lines changed: 72 additions & 47 deletions
Original file line numberDiff line numberDiff line change
@@ -1614,6 +1614,8 @@ exec_bind_message(StringInfo input_message)
16141614
boolsave_log_statement_stats=log_statement_stats;
16151615
boolsnapshot_set= false;
16161616
charmsec_str[32];
1617+
ParamsErrorCbDataparams_data;
1618+
ErrorContextCallbackparams_errcxt;
16171619

16181620
/* Get the fixed part of the message */
16191621
portal_name=pq_getmsgstring(input_message);
@@ -1753,6 +1755,8 @@ exec_bind_message(StringInfo input_message)
17531755
*/
17541756
if (numParams>0)
17551757
{
1758+
char**knownTextValues=NULL;/* allocate on first use */
1759+
17561760
params=makeParamList(numParams);
17571761

17581762
for (intparamno=0;paramno<numParams;paramno++)
@@ -1820,9 +1824,32 @@ exec_bind_message(StringInfo input_message)
18201824

18211825
pval=OidInputFunctionCall(typinput,pstring,typioparam,-1);
18221826

1823-
/* Free result of encoding conversion, if any */
1824-
if (pstring&&pstring!=pbuf.data)
1825-
pfree(pstring);
1827+
/*
1828+
* Free result of encoding conversion, if any, and save a copy
1829+
* for later when logging parameters.
1830+
*/
1831+
if (pstring)
1832+
{
1833+
if (log_parameters_on_error)
1834+
{
1835+
MemoryContextoldcxt;
1836+
1837+
oldcxt=MemoryContextSwitchTo(MessageContext);
1838+
if (knownTextValues==NULL)
1839+
knownTextValues=
1840+
palloc0(numParams*sizeof(char*));
1841+
/*
1842+
* Note: must copy at least two more full characters
1843+
* than BuildParamLogString wants to see; otherwise it
1844+
* might fail to include the ellipsis.
1845+
*/
1846+
knownTextValues[paramno]=
1847+
pnstrdup(pstring,64+2*MAX_MULTIBYTE_CHAR_LEN);
1848+
MemoryContextSwitchTo(oldcxt);
1849+
}
1850+
if (pstring!=pbuf.data)
1851+
pfree(pstring);
1852+
}
18261853
}
18271854
elseif (pformat==1)/* binary mode */
18281855
{
@@ -1872,13 +1899,30 @@ exec_bind_message(StringInfo input_message)
18721899
params->params[paramno].pflags=PARAM_FLAG_CONST;
18731900
params->params[paramno].ptype=ptype;
18741901
}
1902+
1903+
/*
1904+
* Once all parameters have been received, prepare for printing them in
1905+
* errors, if configured to do so. (This is saved in the portal, so
1906+
* that they'll appear when the query is executed later.)
1907+
*/
1908+
if (log_parameters_on_error)
1909+
params->paramValuesStr=
1910+
BuildParamLogString(params,knownTextValues,64);
18751911
}
18761912
else
18771913
params=NULL;
18781914

18791915
/* Done storing stuff in portal's context */
18801916
MemoryContextSwitchTo(oldContext);
18811917

1918+
/* Set the error callback so that parameters are logged, as needed */
1919+
params_data.portalName=portal->name;
1920+
params_data.params=params;
1921+
params_errcxt.previous=error_context_stack;
1922+
params_errcxt.callback=ParamsErrorCallback;
1923+
params_errcxt.arg= (void*)&params_data;
1924+
error_context_stack=&params_errcxt;
1925+
18821926
/* Get the result format codes */
18831927
numRFormats=pq_getmsgint(input_message,2);
18841928
if (numRFormats>0)
@@ -1924,6 +1968,12 @@ exec_bind_message(StringInfo input_message)
19241968
*/
19251969
PortalSetResultFormat(portal,numRFormats,rformats);
19261970

1971+
/*
1972+
* Done binding; remove the parameters error callback. Entries emitted
1973+
* later determine independently whether to log the parameters or not.
1974+
*/
1975+
error_context_stack=error_context_stack->previous;
1976+
19271977
/*
19281978
* Send BindComplete.
19291979
*/
@@ -1980,6 +2030,8 @@ exec_execute_message(const char *portal_name, long max_rows)
19802030
boolexecute_is_fetch;
19812031
boolwas_logged= false;
19822032
charmsec_str[32];
2033+
ParamsErrorCbDataparams_data;
2034+
ErrorContextCallbackparams_errcxt;
19832035

19842036
/* Adjust destination to tell printtup.c what to do */
19852037
dest=whereToSendOutput;
@@ -2104,8 +2156,16 @@ exec_execute_message(const char *portal_name, long max_rows)
21042156
CHECK_FOR_INTERRUPTS();
21052157

21062158
/*
2107-
* Okay to run the portal.
2159+
* Okay to run the portal. Set the error callback so that parameters are
2160+
* logged. The parameters must have been saved during the bind phase.
21082161
*/
2162+
params_data.portalName=portal->name;
2163+
params_data.params=portalParams;
2164+
params_errcxt.previous=error_context_stack;
2165+
params_errcxt.callback=ParamsErrorCallback;
2166+
params_errcxt.arg= (void*)&params_data;
2167+
error_context_stack=&params_errcxt;
2168+
21092169
if (max_rows <=0)
21102170
max_rows=FETCH_ALL;
21112171

@@ -2119,6 +2179,9 @@ exec_execute_message(const char *portal_name, long max_rows)
21192179

21202180
receiver->rDestroy(receiver);
21212181

2182+
/* Done executing; remove the params error callback */
2183+
error_context_stack=error_context_stack->previous;
2184+
21222185
if (completed)
21232186
{
21242187
if (is_xact_command)
@@ -2329,51 +2392,13 @@ errdetail_execute(List *raw_parsetree_list)
23292392
staticint
23302393
errdetail_params(ParamListInfoparams)
23312394
{
2332-
/* We mustn't call user-defined I/O functions when in an aborted xact */
2333-
if (params&&params->numParams>0&& !IsAbortedTransactionBlockState())
2395+
if (params&&params->numParams>0)
23342396
{
2335-
StringInfoDataparam_str;
2336-
MemoryContextoldcontext;
2397+
char*str;
23372398

2338-
/* This code doesn't support dynamic param lists */
2339-
Assert(params->paramFetch==NULL);
2340-
2341-
/* Make sure any trash is generated in MessageContext */
2342-
oldcontext=MemoryContextSwitchTo(MessageContext);
2343-
2344-
initStringInfo(&param_str);
2345-
2346-
for (intparamno=0;paramno<params->numParams;paramno++)
2347-
{
2348-
ParamExternData*prm=&params->params[paramno];
2349-
Oidtypoutput;
2350-
booltypisvarlena;
2351-
char*pstring;
2352-
2353-
appendStringInfo(&param_str,"%s$%d = ",
2354-
paramno>0 ?", " :"",
2355-
paramno+1);
2356-
2357-
if (prm->isnull|| !OidIsValid(prm->ptype))
2358-
{
2359-
appendStringInfoString(&param_str,"NULL");
2360-
continue;
2361-
}
2362-
2363-
getTypeOutputInfo(prm->ptype,&typoutput,&typisvarlena);
2364-
2365-
pstring=OidOutputFunctionCall(typoutput,prm->value);
2366-
2367-
appendStringInfoStringQuoted(&param_str,pstring,0);
2368-
2369-
pfree(pstring);
2370-
}
2371-
2372-
errdetail("parameters: %s",param_str.data);
2373-
2374-
pfree(param_str.data);
2375-
2376-
MemoryContextSwitchTo(oldcontext);
2399+
str=BuildParamLogString(params,NULL,0);
2400+
if (str&&str[0]!='\0')
2401+
errdetail("parameters: %s",str);
23772402
}
23782403

23792404
return0;

‎src/backend/utils/misc/guc.c

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -486,6 +486,7 @@ extern const struct config_enum_entry dynamic_shared_memory_options[];
486486
* GUC option variables that are exported from this module
487487
*/
488488
boollog_duration= false;
489+
boollog_parameters_on_error= false;
489490
boolDebug_print_plan= false;
490491
boolDebug_print_parse= false;
491492
boolDebug_print_rewritten= false;
@@ -1300,6 +1301,15 @@ static struct config_bool ConfigureNamesBool[] =
13001301
false,
13011302
NULL,NULL,NULL
13021303
},
1304+
{
1305+
{"log_parameters_on_error",PGC_SUSET,LOGGING_WHAT,
1306+
gettext_noop("Logs bind parameters of the logged statements where possible."),
1307+
NULL
1308+
},
1309+
&log_parameters_on_error,
1310+
false,
1311+
NULL,NULL,NULL
1312+
},
13031313
{
13041314
{"debug_print_parse",PGC_USERSET,LOGGING_WHAT,
13051315
gettext_noop("Logs each query's parse tree."),

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp