From 7d348771607551f57c7806ef6f32bfda27050bdc Mon Sep 17 00:00:00 2001 From: Jim Jones Date: Fri, 15 May 2026 12:44:45 +0200 Subject: [PATCH v14] Add log_statement_max_length GUC to limit logged statement size Queries logged by log_statement or log_min_duration_statement can be arbitrarily long and may consume significant disk space in server logs. This patch introduces a new GUC, log_statement_max_length, which limits the maximum byte length of those logged statements. A value greater than zero truncates each logged statement to the given number of bytes, respecting multibyte character boundaries to avoid producing invalid output. The default is -1, which logs statements in full. If specified without units, the value is interpreted as bytes. --- doc/src/sgml/config.sgml | 25 +++ src/backend/tcop/postgres.c | 171 ++++++++++++++---- src/backend/utils/misc/guc_parameters.dat | 10 + src/backend/utils/misc/guc_tables.c | 1 + src/backend/utils/misc/postgresql.conf.sample | 3 + src/include/utils/guc.h | 1 + src/test/modules/test_misc/meson.build | 1 + .../t/014_log_statement_max_length.pl | 115 ++++++++++++ 8 files changed, 289 insertions(+), 38 deletions(-) create mode 100644 src/test/modules/test_misc/t/014_log_statement_max_length.pl diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 6e9626fcf38..9172a4c5c95 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -8512,6 +8512,31 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' + + log_statement_max_length (integer) + + log_statement_max_length configuration parameter + + + + + If greater than zero, each statement logged by + , + , + , or + + is truncated to at most this many bytes. + A value of zero causes statements to be logged with an empty body. + -1 (the default) logs statements in full. + If this value is specified without units, it is taken as bytes. + This setting does not affect statements logged because of + . + Only superusers and users with the appropriate SET + privilege can change this setting. + + + + log_replication_commands (boolean) diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index dbef734a93f..ce18df820cd 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -183,6 +183,7 @@ static int SocketBackend(StringInfo inBuf); static int ReadCommand(StringInfo inBuf); static void forbidden_in_wal_sender(char firstchar); static bool check_log_statement(List *stmt_list); +static char *truncate_query_log(const char *query); static int errdetail_execute(List *raw_parsetree_list); static int errdetail_params(ParamListInfo params); static void bind_param_error_callback(void *arg); @@ -1084,11 +1085,20 @@ exec_simple_query(const char *query_string) /* Log immediately if dictated by log_statement */ if (check_log_statement(parsetree_list)) { + char *truncated_stmt = NULL; + + if (log_statement_max_length >= 0) + truncated_stmt = truncate_query_log(query_string); + ereport(LOG, - (errmsg("statement: %s", query_string), + (errmsg("statement: %s", + (truncated_stmt != NULL) ? truncated_stmt : query_string), errhidestmt(true), errdetail_execute(parsetree_list))); was_logged = true; + + if (truncated_stmt != NULL) + pfree(truncated_stmt); } /* @@ -1381,12 +1391,23 @@ exec_simple_query(const char *query_string) errhidestmt(true))); break; case 2: - ereport(LOG, - (errmsg("duration: %s ms statement: %s", - msec_str, query_string), - errhidestmt(true), - errdetail_execute(parsetree_list))); - break; + { + char *truncated_stmt = NULL; + + if (log_statement_max_length >= 0) + truncated_stmt = truncate_query_log(query_string); + + ereport(LOG, + (errmsg("duration: %s ms statement: %s", + msec_str, + (truncated_stmt != NULL) ? truncated_stmt : query_string), + errhidestmt(true), + errdetail_execute(parsetree_list))); + + if (truncated_stmt != NULL) + pfree(truncated_stmt); + break; + } } if (save_log_statement_stats) @@ -1616,13 +1637,23 @@ exec_parse_message(const char *query_string, /* string to execute */ errhidestmt(true))); break; case 2: - ereport(LOG, - (errmsg("duration: %s ms parse %s: %s", - msec_str, - *stmt_name ? stmt_name : "", - query_string), - errhidestmt(true))); - break; + { + char *truncated_stmt = NULL; + + if (log_statement_max_length >= 0) + truncated_stmt = truncate_query_log(query_string); + + ereport(LOG, + (errmsg("duration: %s ms parse %s: %s", + msec_str, + *stmt_name ? stmt_name : "", + (truncated_stmt != NULL) ? truncated_stmt : query_string), + errhidestmt(true))); + + if (truncated_stmt != NULL) + pfree(truncated_stmt); + break; + } } if (save_log_statement_stats) @@ -2093,16 +2124,26 @@ exec_bind_message(StringInfo input_message) errhidestmt(true))); break; case 2: - ereport(LOG, - (errmsg("duration: %s ms bind %s%s%s: %s", - msec_str, - *stmt_name ? stmt_name : "", - *portal_name ? "/" : "", - *portal_name ? portal_name : "", - psrc->query_string), - errhidestmt(true), - errdetail_params(params))); - break; + { + char *truncated_stmt = NULL; + + if (log_statement_max_length >= 0) + truncated_stmt = truncate_query_log(psrc->query_string); + + ereport(LOG, + (errmsg("duration: %s ms bind %s%s%s: %s", + msec_str, + *stmt_name ? stmt_name : "", + *portal_name ? "/" : "", + *portal_name ? portal_name : "", + (truncated_stmt != NULL) ? truncated_stmt : psrc->query_string), + errhidestmt(true), + errdetail_params(params))); + + if (truncated_stmt != NULL) + pfree(truncated_stmt); + break; + } } if (save_log_statement_stats) @@ -2241,6 +2282,11 @@ exec_execute_message(const char *portal_name, long max_rows) /* Log immediately if dictated by log_statement */ if (check_log_statement(portal->stmts)) { + char *truncated_source = NULL; + + if (log_statement_max_length >= 0) + truncated_source = truncate_query_log(sourceText); + ereport(LOG, (errmsg("%s %s%s%s: %s", execute_is_fetch ? @@ -2249,10 +2295,13 @@ exec_execute_message(const char *portal_name, long max_rows) prepStmtName, *portal_name ? "/" : "", *portal_name ? portal_name : "", - sourceText), + (truncated_source != NULL) ? truncated_source : sourceText), errhidestmt(true), errdetail_params(portalParams))); was_logged = true; + + if (truncated_source != NULL) + pfree(truncated_source); } /* @@ -2364,19 +2413,29 @@ exec_execute_message(const char *portal_name, long max_rows) errhidestmt(true))); break; case 2: - ereport(LOG, - (errmsg("duration: %s ms %s %s%s%s: %s", - msec_str, - execute_is_fetch ? - _("execute fetch from") : - _("execute"), - prepStmtName, - *portal_name ? "/" : "", - *portal_name ? portal_name : "", - sourceText), - errhidestmt(true), - errdetail_params(portalParams))); - break; + { + char *truncated_source = NULL; + + if (log_statement_max_length >= 0) + truncated_source = truncate_query_log(sourceText); + + ereport(LOG, + (errmsg("duration: %s ms %s %s%s%s: %s", + msec_str, + execute_is_fetch ? + _("execute fetch from") : + _("execute"), + prepStmtName, + *portal_name ? "/" : "", + *portal_name ? portal_name : "", + (truncated_source != NULL) ? truncated_source : sourceText), + errhidestmt(true), + errdetail_params(portalParams))); + + if (truncated_source != NULL) + pfree(truncated_source); + break; + } } if (save_log_statement_stats) @@ -2490,6 +2549,42 @@ check_log_duration(char *msec_str, bool was_logged) return 0; } +/* + * truncate_query_log + * Truncate query string if needed for logging + * + * Returns a palloc'd truncated copy if truncation is needed, + * or NULL if no truncation is required. + */ +static char * +truncate_query_log(const char *query) +{ + size_t query_len; + size_t truncated_len; + char *truncated_query; + + /* Truncation is disabled when the limit is negative */ + if (!query || log_statement_max_length < 0) + return NULL; + + query_len = strlen(query); + + /* + * No need to allocate a truncated copy if the query is shorter than + * log_statement_max_length. + */ + if (query_len <= (size_t) log_statement_max_length) + return NULL; + + /* Truncate at a multibyte character boundary */ + truncated_len = pg_mbcliplen(query, query_len, log_statement_max_length); + truncated_query = (char *) palloc(truncated_len + 1); + memcpy(truncated_query, query, truncated_len); + truncated_query[truncated_len] = '\0'; + + return truncated_query; +} + /* * errdetail_execute * diff --git a/src/backend/utils/misc/guc_parameters.dat b/src/backend/utils/misc/guc_parameters.dat index 3c1e6b31bf8..c9118e71988 100644 --- a/src/backend/utils/misc/guc_parameters.dat +++ b/src/backend/utils/misc/guc_parameters.dat @@ -1868,6 +1868,16 @@ options => 'log_statement_options', }, +{ name => 'log_statement_max_length', type => 'int', context => 'PGC_SUSET', group => 'LOGGING_WHAT', + short_desc => 'Sets the maximum length in bytes of logged statements.', + long_desc => '-1 means log statement in full; 0 means log an empty statement body.', + flags => 'GUC_UNIT_BYTE', + variable => 'log_statement_max_length', + boot_val => '-1', + min => '-1', + max => 'INT_MAX / 2', +}, + { name => 'log_statement_sample_rate', type => 'real', context => 'PGC_SUSET', group => 'LOGGING_WHEN', short_desc => 'Fraction of statements exceeding "log_min_duration_sample" to be logged.', long_desc => 'Use a value between 0.0 (never log) and 1.0 (always log).', diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index 290ccbc543e..90aa374b3ec 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -571,6 +571,7 @@ int log_min_duration_statement = -1; int log_parameter_max_length = -1; int log_parameter_max_length_on_error = 0; int log_temp_files = -1; +int log_statement_max_length = -1; double log_statement_sample_rate = 1.0; double log_xact_sample_rate = 0; char *backtrace_functions; diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 86f2e16eba0..d7942f50a70 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -675,6 +675,9 @@ # bind-parameter values to N bytes; # -1 means print in full, 0 disables #log_statement = 'none' # none, ddl, mod, all +#log_statement_max_length = -1 # max bytes of logged statements; + # -1 means log statement in full, + # 0 means log an empty body #log_replication_commands = off #log_temp_files = -1 # log temporary files equal or larger # than the specified size in kilobytes; diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index dc406d6651a..8057d7870ad 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -300,6 +300,7 @@ extern PGDLLIMPORT int client_min_messages; extern PGDLLIMPORT int log_min_duration_sample; extern PGDLLIMPORT int log_min_duration_statement; extern PGDLLIMPORT int log_temp_files; +extern PGDLLIMPORT int log_statement_max_length; extern PGDLLIMPORT double log_statement_sample_rate; extern PGDLLIMPORT double log_xact_sample_rate; extern PGDLLIMPORT char *backtrace_functions; diff --git a/src/test/modules/test_misc/meson.build b/src/test/modules/test_misc/meson.build index 969e90b396d..ee290698b31 100644 --- a/src/test/modules/test_misc/meson.build +++ b/src/test/modules/test_misc/meson.build @@ -22,6 +22,7 @@ tests += { 't/011_lock_stats.pl', 't/012_ddlutils.pl', 't/013_temp_obj_multisession.pl', + 't/014_log_statement_max_length.pl', ], # The injection points are cluster-wide, so disable installcheck 'runningcheck': false, diff --git a/src/test/modules/test_misc/t/014_log_statement_max_length.pl b/src/test/modules/test_misc/t/014_log_statement_max_length.pl new file mode 100644 index 00000000000..6cd45f2ee83 --- /dev/null +++ b/src/test/modules/test_misc/t/014_log_statement_max_length.pl @@ -0,0 +1,115 @@ +# Copyright (c) 2026, PostgreSQL Global Development Group + +# Test log_statement_max_length GUC: verifies that logged statement text is +# truncated at the specified byte limit, respecting multibyte boundaries, for +# both log_statement and log_min_duration_statement logging. + +use strict; +use warnings FATAL => 'all'; +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; + +my $node = PostgreSQL::Test::Cluster->new('primary'); +$node->init(); +$node->start; + +# Verify ASCII truncation. With log_statement_max_length = 20, +# a 24-byte query should end at the 20th byte ('C'). +note "ASCII truncation via log_statement"; +my $log_offset = -s $node->logfile; +$node->psql( + 'postgres', " + SET log_statement_max_length TO 20; + SELECT '123456789ABCDEF';"); +ok($node->log_contains(qr/statement: SELECT '123456789ABC$/m, $log_offset), + "ASCII query truncated at 20 bytes"); + +# Verify -1 logs statement in full (closing quote must be present). +note "-1 logs statement in full"; +$log_offset = -s $node->logfile; +$node->psql( + 'postgres', " + SET log_statement_max_length TO -1; + SELECT '123456789ABCDEF';"); +ok( $node->log_contains(qr/statement: SELECT '123456789ABCDEF'/, $log_offset), + "-1 logs full query"); + +# Verify multibyte character handling: truncation must not split a multibyte +# character when the byte limit falls in the middle of it. +SKIP: +{ + skip "UTF8 database encoding required for multibyte truncation test", 1 + unless $node->safe_psql('postgres', 'SHOW server_encoding') eq 'UTF8'; + + note "Multibyte truncation respects character boundaries"; + my $mbchar = pack("C*", 0xC4, 0x80); # U+0100 in UTF-8 + my $mbquery = "SELECT 'AA${mbchar}Z';"; + $log_offset = -s $node->logfile; + $node->psql( + 'postgres', " + SET client_encoding TO 'UTF8'; + SET log_statement_max_length TO 11; + $mbquery"); + ok($node->log_contains(qr/statement: SELECT 'AA$/m, $log_offset), + "multibyte truncation at character boundary"); +} + +# Verify 0 logs an empty statement body. +note "Zero length truncation"; +$log_offset = -s $node->logfile; +$node->psql( + 'postgres', " + SET log_statement_max_length TO 0; + SELECT '123456789ABCDEF';"); +ok($node->log_contains(qr/LOG:\s+statement:\s*$/m, $log_offset), + "0 logs an empty statement body"); + +# Verify truncation via the extended query protocol (execute message). +# With log_statement_max_length = 20, a 24-byte query should end +# at the 20th byte ('C'). +note "Extended query protocol (execute) truncation"; +$log_offset = -s $node->logfile; +$node->psql( + 'postgres', " + SET log_statement_max_length TO 20; + SELECT '123456789ABCDEF' \\bind \\g"); +ok( $node->log_contains( + qr/execute : SELECT '123456789ABC$/m, $log_offset), + "extended protocol execute truncated at 20 bytes"); + +# Verify extended protocol also respects -1 (no truncation; closing quote +# present). +note "Extended query protocol with -1 (no truncation)"; +$log_offset = -s $node->logfile; +$node->psql( + 'postgres', " + SET log_statement_max_length TO -1; + SELECT '123456789ABCDEF' \\bind \\g"); +ok( $node->log_contains( + qr/execute : SELECT '123456789ABCDEF'/, $log_offset), + "extended protocol -1 logs full query"); + +# Verify truncation applies to the parse/bind/execute duration log entries +# emitted by log_min_duration_statement. log_statement must be 'none' to +# ensure the duration entries include the statement text. +note "Duration logging via log_min_duration_statement"; +$log_offset = -s $node->logfile; +$node->psql( + 'postgres', " + SET log_statement TO 'none'; + SET log_min_duration_statement TO 0; + SET log_statement_max_length TO 20; + SELECT '123456789ABCDEF' \\bind \\g"); +ok( $node->log_contains( + qr/parse : SELECT '123456789ABC$/m, $log_offset), + "parse duration entry truncated"); +ok( $node->log_contains( + qr/bind : SELECT '123456789ABC$/m, $log_offset), + "bind duration entry truncated"); +ok( $node->log_contains( + qr/execute : SELECT '123456789ABC$/m, $log_offset), + "execute duration entry truncated"); + +$node->stop; +done_testing(); -- 2.53.0