upstream/postgresql
1
0
Fork 0
mirror of https://github.com/postgres/postgres.git synced 2026-07-08 01:01:01 -04:00
Code Issues Projects Releases Packages Wiki Activity Actions

Add log_statement_max_length GUC to limit logged statement text

Browse source 
Very large statements can make server logs grow unexpectedly. This is
particularly painful when applications accidentally or intentionally
send huge literal values and statement logging is enabled: the full
statement text may be written to the log even when DBA sees only
its leading part is useful for normal operations.

This commit adds log_statement_max_length GUC that limits the number
of bytes of statement text emitted by statement logging. The setting
applies to statements logged by log_statement, log_min_duration_statement,
log_min_duration_sample, and log_transaction_sample_rate. A positive
value truncates the logged statement body to at most that many bytes,
zero  logs an empty statement body, and the default value -1 preserves
the existing behavior of logging statements in full.

Truncation is byte-based, matching the GUC unit, but it clips only
at multibyte character boundaries so that the log output remains valid.
This setting does not affect statements logged because of
log_min_error_statement; handling error-statement logging can be
considered separately.

Author: Jim Jones <jim.jones@uni-muenster.de>
Author: Kirill Gavrilov <diphantxm@gmail.com>
Reviewed-by: Kirill Reshke <reshkekirill@gmail.com>
Reviewed-by: Álvaro Herrera <alvherre@kurilemu.de>
Reviewed-by: Maxym Kharchenko <maxymkharchenko@gmail.com>
Reviewed-by: Fujii Masao <masao.fujii@gmail.com>
Discussion: https://postgr.es/m/CA+E0NR4S+NC6+QHyY_vUuQZMzLhKqczMx-jJVqtjAxF6+=JwAA@mail.gmail.com
This commit is contained in:
Fujii Masao 2026-07-03 08:47:18 +09:00
parent 53e6f51eef
commit c8bd8387c2
8 changed files with 289 additions and 38 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

25
doc/src/sgml/config.sgml
View file

@ -8512,6 +8512,31 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
</listitem>
</varlistentry>
<varlistentry id="guc-log-statement-max-length" xreflabel="log_statement_max_length">
<term><varname>log_statement_max_length</varname> (<type>integer</type>)
<indexterm>
<primary><varname>log_statement_max_length</varname> configuration parameter</primary>
</indexterm>
</term>
<listitem>
<para>
If greater than zero, each statement logged by
<xref linkend="guc-log-statement"/>,
<xref linkend="guc-log-min-duration-statement"/>,
<xref linkend="guc-log-min-duration-sample"/>, or
<xref linkend="guc-log-transaction-sample-rate"/>
is truncated to at most this many bytes.
A value of zero causes statements to be logged with an empty body.
<literal>-1</literal> (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
<xref linkend="guc-log-min-error-statement"/>.
Only superusers and users with the appropriate <literal>SET</literal>
privilege can change this setting.
</para>
</listitem>
</varlistentry>
<varlistentry id="guc-log-replication-commands" xreflabel="log_replication_commands">
<term><varname>log_replication_commands</varname> (<type>boolean</type>)
<indexterm>

171
src/backend/tcop/postgres.c
View file

@ -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 : "<unnamed>",
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 : "<unnamed>",
(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 : "<unnamed>",
*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 : "<unnamed>",
*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
*

10
src/backend/utils/misc/guc_parameters.dat
View file

@ -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).',

1
src/backend/utils/misc/guc_tables.c
View file

@ -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;

3
src/backend/utils/misc/postgresql.conf.sample
View file

@ -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;

1
src/include/utils/guc.h
View file

@ -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;

1
src/test/modules/test_misc/meson.build
View file

@ -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,

115
src/test/modules/test_misc/t/014_log_statement_max_length.pl Normal file
View file

@ -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 <unnamed>: 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 <unnamed>: 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 <unnamed>: SELECT '123456789ABC$/m, $log_offset),
"parse duration entry truncated");
ok( $node->log_contains(
qr/bind <unnamed>: SELECT '123456789ABC$/m, $log_offset),
"bind duration entry truncated");
ok( $node->log_contains(
qr/execute <unnamed>: SELECT '123456789ABC$/m, $log_offset),
"execute duration entry truncated");
$node->stop;
done_testing();