diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 2de21903a1..3d7db57d74 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6690,29 +6690,48 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' - - log_parameters_on_error (boolean) + + log_parameter_max_length (integer) - log_parameters_on_error configuration parameter + log_parameter_max_length configuration parameter - Controls whether bind parameters are logged when a statement is logged - as a result of . - It adds some overhead, as PostgreSQL will - compute and store textual representations of parameter values in - memory for all statements, even if they eventually do not get logged. - This setting has no effect on statements logged due to - or - settings, as they are always logged - with parameters. - The default is off. + If greater than zero, bind parameter values reported in non-error + statement-logging messages are trimmed to no more than this many bytes. + If this value is specified without units, it is taken as bytes. + Zero disables logging parameters with statements. + -1 (the default) makes parameters logged in full. Only superusers can change this setting. + + log_parameter_max_length_on_error (integer) + + log_parameter_max_length_on_error configuration parameter + + + + + If greater than zero, bind parameter values reported in error messages + are trimmed to no more than this many bytes. + If this value is specified without units, it is taken as bytes. + Zero (the default) disables logging parameters on error. + -1 makes parameters logged in full. + + This setting only affects statements logged as a result of + . + Non-zero values add some overhead, as + PostgreSQL will compute and store textual + representations of parameter values in memory for all statements, + even if they eventually do not get logged. + + + + log_statement (enum) diff --git a/src/backend/nodes/params.c b/src/backend/nodes/params.c index a57f9eea76..77328e17ff 100644 --- a/src/backend/nodes/params.c +++ b/src/backend/nodes/params.c @@ -269,7 +269,7 @@ RestoreParamList(char **start_address) * can contain NULLs for any unknown individual values. NULL can be given if * no parameters are known. * - * If maxlen is not zero, that's the maximum number of bytes of any one + * If maxlen is not -1, that's the maximum number of bytes of any one * parameter value to be printed; an ellipsis is added if the string is * longer. (Added quotes are not considered in this calculation.) */ @@ -280,6 +280,7 @@ BuildParamLogString(ParamListInfo params, char **knownTextValues, int maxlen) oldCxt; StringInfoData buf; + Assert(maxlen == -1 || maxlen > 0); /* * NB: think not of returning params->paramValuesStr! It may have been * generated with a different maxlen, and so be unsuitable. Besides that, diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 5b677863b9..cbe4907e61 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -1838,7 +1838,7 @@ exec_bind_message(StringInfo input_message) */ if (pstring) { - if (log_parameters_on_error) + if (log_parameter_max_length_on_error != 0) { MemoryContext oldcxt; @@ -1846,13 +1846,24 @@ exec_bind_message(StringInfo input_message) if (knownTextValues == NULL) knownTextValues = palloc0(numParams * sizeof(char *)); - /* - * Note: must copy at least two more full characters - * than BuildParamLogString wants to see; otherwise it - * might fail to include the ellipsis. - */ - knownTextValues[paramno] = - pnstrdup(pstring, 64 + 2 * MAX_MULTIBYTE_CHAR_LEN); + + if (log_parameter_max_length_on_error > 0) + { + /* + * 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); + } + else + knownTextValues[paramno] = pstrdup(pstring); + MemoryContextSwitchTo(oldcxt); } if (pstring != pbuf.data) @@ -1913,9 +1924,11 @@ exec_bind_message(StringInfo input_message) * 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_parameters_on_error) + if (log_parameter_max_length_on_error != 0) params->paramValuesStr = - BuildParamLogString(params, knownTextValues, 64); + BuildParamLogString(params, + knownTextValues, + log_parameter_max_length_on_error); } else params = NULL; @@ -2400,11 +2413,11 @@ errdetail_execute(List *raw_parsetree_list) static int errdetail_params(ParamListInfo params) { - if (params && params->numParams > 0) + if (log_parameter_max_length != 0 && params && params->numParams > 0) { char *str; - str = BuildParamLogString(params, NULL, 0); + str = BuildParamLogString(params, NULL, log_parameter_max_length); if (str && str[0] != '\0') errdetail("parameters: %s", str); } diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index 79bc7ac8ca..538d940895 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -515,7 +515,6 @@ extern const struct config_enum_entry dynamic_shared_memory_options[]; * GUC option variables that are exported from this module */ bool log_duration = false; -bool log_parameters_on_error = false; bool Debug_print_plan = false; bool Debug_print_parse = false; bool Debug_print_rewritten = false; @@ -544,6 +543,8 @@ int log_min_messages = WARNING; int client_min_messages = NOTICE; int log_min_duration_sample = -1; int log_min_duration_statement = -1; +int log_parameter_max_length = 0; +int log_parameter_max_length_on_error = 0; int log_temp_files = -1; double log_statement_sample_rate = 1.0; double log_xact_sample_rate = 0; @@ -1381,15 +1382,6 @@ static struct config_bool ConfigureNamesBool[] = false, NULL, NULL, NULL }, - { - {"log_parameters_on_error", PGC_SUSET, LOGGING_WHAT, - gettext_noop("Logs bind parameters of the logged statements where possible."), - NULL - }, - &log_parameters_on_error, - false, - NULL, NULL, NULL - }, { {"debug_print_parse", PGC_USERSET, LOGGING_WHAT, gettext_noop("Logs each query's parse tree."), @@ -2855,6 +2847,28 @@ static struct config_int ConfigureNamesInt[] = NULL, NULL, NULL }, + { + {"log_parameter_max_length", PGC_SUSET, LOGGING_WHAT, + gettext_noop("When logging statements, limit logged parameter values to first N bytes."), + gettext_noop("Zero to print values in full."), + GUC_UNIT_BYTE + }, + &log_parameter_max_length, + -1, -1, INT_MAX / 2, + NULL, NULL, NULL + }, + + { + {"log_parameter_max_length_on_error", PGC_USERSET, LOGGING_WHAT, + gettext_noop("When reporting an error, limit logged parameter values to first N bytes."), + gettext_noop("Zero to print values in full."), + GUC_UNIT_BYTE + }, + &log_parameter_max_length_on_error, + 0, -1, INT_MAX / 2, + NULL, NULL, NULL + }, + { {"bgwriter_delay", PGC_SIGHUP, RESOURCES_BGWRITER, gettext_noop("Background writer sleep time between rounds."), diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index e9f8ca775d..8c26ac90d1 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -545,7 +545,12 @@ # e.g. '<%u%%%d> ' #log_lock_waits = off # log lock waits >= deadlock_timeout #log_statement = 'none' # none, ddl, mod, all -#log_parameters_on_error = off # on error log statements with bind parameters +#log_parameter_max_length = -1 # when logging statements, limit logged + # parameter values to N bytes; + # -1 means print in full, 0 to disable +#log_parameter_max_length_on_error = 0 # when logging an error, limit logged + # parameter values to N bytes; + # -1 means print in full, 0 to disable #log_replication_commands = off #log_temp_files = -1 # log temporary files equal or larger # than the specified size in kilobytes; diff --git a/src/bin/pgbench/t/001_pgbench_with_server.pl b/src/bin/pgbench/t/001_pgbench_with_server.pl index 25ea17f7d1..b7eb37d65d 100644 --- a/src/bin/pgbench/t/001_pgbench_with_server.pl +++ b/src/bin/pgbench/t/001_pgbench_with_server.pl @@ -271,7 +271,35 @@ COMMIT; }); # Verify server logging of parameters. -$node->append_conf('postgresql.conf', "log_parameters_on_error = true"); +# 1. Logging neither with errors nor with statements +$node->append_conf('postgresql.conf', + "log_min_duration_statement = 0\n" . + "log_parameter_max_length = 0\n" . + "log_parameter_max_length_on_error = 0"); +$node->reload; +pgbench( + '-n -t1 -c1 -M prepared', + 2, + [], + [ + qr{ERROR: invalid input syntax for type json}, + qr{(?!extended query with parameters)} + ], + 'server parameter logging', + { + '001_param_1' => q[select '{ invalid ' as value \gset +select $$'Valame Dios!' dijo Sancho; 'no le dije yo a vuestra merced que mirase bien lo que hacia?'$$ as long \gset +select column1::jsonb from (values (:value), (:long)) as q; +] + }); +my $log = TestLib::slurp_file($node->logfile); +unlike($log, qr[DETAIL: parameters: \$1 = '\{ invalid ',], "no parameters logged"); +$log = undef; + +# 2. Logging truncated parameters on error, full with statements +$node->append_conf('postgresql.conf', + "log_parameter_max_length = -1\n" . + "log_parameter_max_length_on_error = 64"); $node->reload; pgbench( '-n -t1 -c1 -M prepared', @@ -283,11 +311,10 @@ pgbench( ], 'server parameter logging', { - '001_param_1' => q{select '1' as one \gset + '001_param_2' => q{select '1' as one \gset SELECT 1 / (random() / 2)::int, :one::int, :two::int; } }); - $node->append_conf('postgresql.conf', "log_min_duration_statement = 0"); $node->reload; pgbench( @@ -300,17 +327,64 @@ pgbench( ], 'server parameter logging', { - '001_param_2' => q[select '{ invalid ' as value \gset + '001_param_3' => q[select '{ invalid ' as value \gset select $$'Valame Dios!' dijo Sancho; 'no le dije yo a vuestra merced que mirase bien lo que hacia?'$$ as long \gset select column1::jsonb from (values (:value), (:long)) as q; ] }); -my $log = TestLib::slurp_file($node->logfile); +$log = TestLib::slurp_file($node->logfile); like($log, qr[DETAIL: parameters: \$1 = '\{ invalid ', \$2 = '''Valame Dios!'' dijo Sancho; ''no le dije yo a vuestra merced que mirase bien lo que hacia\?'''], "parameter report does not truncate"); $log = undef; -$node->append_conf('postgresql.conf', "log_min_duration_statement = -1"); +# 3. Logging full parameters on error, truncated with statements +$node->append_conf('postgresql.conf', + "log_min_duration_statement = -1\n" . + "log_parameter_max_length = 7\n" . + "log_parameter_max_length_on_error = -1"); +$node->reload; +pgbench( + '-n -t1 -c1 -M prepared', + 2, + [], + [ + qr{ERROR: division by zero}, + qr{CONTEXT: extended query with parameters: \$1 = '1', \$2 = NULL} + ], + 'server parameter logging', + { + '001_param_4' => q{select '1' as one \gset +SELECT 1 / (random() / 2)::int, :one::int, :two::int; +} + }); + +$node->append_conf('postgresql.conf', "log_min_duration_statement = 0"); +$node->reload; +pgbench( + '-n -t1 -c1 -M prepared', + 2, + [], + [ + qr{ERROR: invalid input syntax for type json}, + qr[CONTEXT: JSON data, line 1: \{ invalid\.\.\.[\r\n]+extended query with parameters: \$1 = '\{ invalid ', \$2 = '''Valame Dios!'' dijo Sancho; ''no le dije yo a vuestra merced que mirase bien lo que hacia\?']m + ], + 'server parameter logging', + { + '001_param_5' => q[select '{ invalid ' as value \gset +select $$'Valame Dios!' dijo Sancho; 'no le dije yo a vuestra merced que mirase bien lo que hacia?'$$ as long \gset +select column1::jsonb from (values (:value), (:long)) as q; +] + }); +$log = TestLib::slurp_file($node->logfile); +like($log, qr[DETAIL: parameters: \$1 = '\{ inval\.\.\.', \$2 = '''Valame\.\.\.'], + "parameter report truncates"); +$log = undef; + +# 3. Restore config +$node->append_conf('postgresql.conf', + "log_min_duration_statement = -1\n" . + "log_parameter_max_length_on_error = 0\n" . + "log_parameter_max_length = -1"); $node->reload; # test expressions diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index ce93ace76c..a375914440 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -234,7 +234,8 @@ typedef enum /* GUC vars that are actually declared in guc.c, rather than elsewhere */ extern bool log_duration; -extern bool log_parameters_on_error; +extern int log_parameter_max_length; +extern int log_parameter_max_length_on_error; extern bool Debug_print_plan; extern bool Debug_print_parse; extern bool Debug_print_rewritten;