public inbox for [email protected]
help / color / mirror / Atom feedFrom: Jim Jones <[email protected]>
To: Fujii Masao <[email protected]>
Cc: Maxym Kharchenko <[email protected]>
Cc: Kirill Reshke <[email protected]>
Cc: Álvaro Herrera <[email protected]>
Cc: Fujii Masao <[email protected]>
Cc: Kirill Gavrilov <[email protected]>
Cc: Andrey M. Borodin <[email protected]>
Cc: Euler Taveira <[email protected]>
Cc: [email protected]
Subject: Re: Truncate logs by max_log_size
Date: Wed, 8 Jul 2026 19:02:40 +0200
Message-ID: <[email protected]> (raw)
In-Reply-To: <CAHGQGwHhtcMH2YY9bo=qkZWLDkN7DBiHJ0g2Xja8eb6OfVkVUA@mail.gmail.com>
References: <[email protected]>
<CAHGQGwGEd=PpVWDd05bYM8F6mnxcSNmWL2Ei8JCf5azZSJnYJA@mail.gmail.com>
<[email protected]>
<CAHGQGwEc5Dn5KFU04sDp0Kyai2Te5yTuni3QW7pc2a3=343tJQ@mail.gmail.com>
<[email protected]>
<CAHGQGwGVxV1YbtLCT+q1yHejBKjLz7L+8r3WJMW=72SDJFW27g@mail.gmail.com>
<CACsxBjB5+HLw6jJ17qR5vSg+kBb2G5ACSbd_ytZ0HvvD22JqkQ@mail.gmail.com>
<CAHGQGwFYxCVmL4Bvm61bUW+WUi+YXFHzXo9hFEoSgYT1=fU-+w@mail.gmail.com>
<[email protected]>
<[email protected]>
<[email protected]>
<CAHGQGwHJHCi=4zEyMc4GJWPC9-oQZHj+9kncxS2442V9PXGgoQ@mail.gmail.com>
<[email protected]>
<CAHGQGwFOV+7nOdfoO=kfVH=-fRA9aQE1YcHHLYty3nfQ9rQ4RA@mail.gmail.com>
<[email protected]>
<CAHGQGwHhtcMH2YY9bo=qkZWLDkN7DBiHJ0g2Xja8eb6OfVkVUA@mail.gmail.com>
Hi Fujii
On 03.07.26 17:46, Fujii Masao wrote:
> On Fri, Jul 3, 2026 at 4:34 PM Jim Jones <[email protected]> wrote:
>> +1
>> Nice additions -- the feature gap is obvious, IMHO.
>>
>> Are you planning to work on it? I'm drowning in work right now and can
>> only jump on it next week.
>
> I don't have plans to work on those at the moment, so please feel free
> to take them on if you have time!
>
>
>> I'm not so sure about this one. At this point, isn't "query" already \0
>> terminated? I'm also wondering if it could affect pg_mbcliplen() down
>> the road, since strnlen() can return a different value
>> (log_statement_max_length + MAX_MULTIBYTE_CHAR_LEN) on large queries --
>> not tested yet.
>
> Yes, "query" should already be NUL-terminated here. The reason for
> using strnlen() is not to handle an unterminated string, but to avoid
> scanning the entire query when it's very large and we only need to
> know whether it exceeds log_statement_max_length.
>
> I think it's fine to pass the bounded length to pg_mbcliplen().
> It only needs enough input to find a multibyte-safe clipping point at
> or before log_statement_max_length, i.e., it doesn't need the full
> query length. The extra MAX_MULTIBYTE_CHAR_LEN bytes provide enough
> lookahead to handle a multibyte character boundary correctly.
>
> - query_len = strlen(query);
> + query_len = strnlen(query,
> + (size_t) log_statement_max_length + MAX_MULTIBYTE_CHAR_LEN);
Attached 0001 addressing the points you made:
* appending ellipsis to the query to indicate truncation (docs and tests
also updated accordingly). A side effect of this change is that setting
the parameter to 0 logs an ellipsis, which is not zero in length, but is
arguably correct, as it indicates that the whole query has been
truncated - just noting.
* use of strnlen to avoid scanning the whole query.
* truncation of prepared statements in DETAIL.
While working on this I noticed some redundant checks to call
truncate_query_log(), e.g. in exec_execute_message():
if (log_statement_max_length >= 0)
truncated_source = truncate_query_log(sourceText);
truncate_query_log() already returns NULL when query logging is disabled
or when no truncation is needed:
/* Truncation is disabled when the limit is negative */
if (!query || log_statement_max_length < 0)
return NULL;
So I'd argue that we don't need any checks in the caller.
- char *truncated_source = NULL;
-
- if (log_statement_max_length >= 0)
- truncated_source = truncate_query_log(sourceText);
+ char *truncated_source = truncate_query_log(sourceText);
0002 attached does this.
Thoughts?
BTW, should I open a new CF entry for this?
Best, Jim
Attachments:
[text/x-patch] v1-0001-Improve-log_statement_max_length-truncation.patch (7.0K, ../[email protected]/2-v1-0001-Improve-log_statement_max_length-truncation.patch)
download | inline diff:
From a47ccafc334e8b508f117afdfc5ce3266e0ed8fa Mon Sep 17 00:00:00 2001
From: Jim Jones <[email protected]>
Date: Wed, 8 Jul 2026 18:29:09 +0200
Subject: [PATCH v1 1/2] Improve log_statement_max_length truncation
Apply log_statement_max_length consistently when logging prepared
statements. Previously, the prepared query emitted in the DETAIL
message for EXECUTE was not truncated, even though the corresponding
statement logged by log_statement was.
Also append an ellipsis to truncated statements, so it is immediately
apparent when a statement has been truncated.
This also avoid scanning the entire query string when determining
if truncation is needed by using strnlen() instead of strlen() in
truncate_query_log().
Author: Jim Jones <[email protected]>
Co-authored-by: Fujii Masao <[email protected]>
---
doc/src/sgml/config.sgml | 4 +-
src/backend/tcop/postgres.c | 16 +++++---
.../t/014_log_statement_max_length.pl | 37 +++++++++++++++----
3 files changed, 42 insertions(+), 15 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 9172a4c5c95..f4782261e17 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -8525,7 +8525,9 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
<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.
+ is truncated to at most this many bytes. When a statement is
+ truncated, an ellipsis (<literal>...</literal>) is appended to
+ indicate that truncation has occurred.
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.
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index ce18df820cd..b0947fd7298 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -2553,8 +2553,9 @@ check_log_duration(char *msec_str, bool was_logged)
* 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.
+ * Returns a palloc'd copy of the query truncated for logging, with an
+ * ellipsis appended if truncation occurs, or NULL if no truncation is
+ * required.
*/
static char *
truncate_query_log(const char *query)
@@ -2567,7 +2568,7 @@ truncate_query_log(const char *query)
if (!query || log_statement_max_length < 0)
return NULL;
- query_len = strlen(query);
+ query_len = strnlen(query, (size_t) log_statement_max_length + MAX_MULTIBYTE_CHAR_LEN);
/*
* No need to allocate a truncated copy if the query is shorter than
@@ -2578,9 +2579,10 @@ truncate_query_log(const char *query)
/* Truncate at a multibyte character boundary */
truncated_len = pg_mbcliplen(query, query_len, log_statement_max_length);
- truncated_query = (char *) palloc(truncated_len + 1);
+ truncated_query = (char *) palloc(truncated_len + 4);
memcpy(truncated_query, query, truncated_len);
- truncated_query[truncated_len] = '\0';
+ memcpy(truncated_query + truncated_len, "...", 3);
+ truncated_query[truncated_len + 3] = '\0';
return truncated_query;
}
@@ -2608,7 +2610,9 @@ errdetail_execute(List *raw_parsetree_list)
pstmt = FetchPreparedStatement(stmt->name, false);
if (pstmt)
{
- errdetail("prepare: %s", pstmt->plansource->query_string);
+ char *truncated_stmt = truncate_query_log(pstmt->plansource->query_string);
+
+ errdetail("prepare: %s", truncated_stmt ? truncated_stmt : pstmt->plansource->query_string);
return 0;
}
}
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
index b1ce6068f5d..1239eff4a93 100644
--- 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
@@ -22,7 +22,7 @@ $node->psql(
'postgres', "
SET log_statement_max_length TO 20;
SELECT '123456789ABCDEF';");
-ok($node->log_contains(qr/statement: SELECT '123456789ABC$/m, $log_offset),
+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).
@@ -51,7 +51,7 @@ SKIP:
SET client_encoding TO 'UTF8';
SET log_statement_max_length TO 11;
$mbquery");
- ok($node->log_contains(qr/statement: SELECT 'AA$/m, $log_offset),
+ ok($node->log_contains(qr/statement: SELECT 'AA...$/m, $log_offset),
"multibyte truncation at character boundary");
}
@@ -62,8 +62,8 @@ $node->psql(
'postgres', "
SET log_statement_max_length TO 0;
SELECT '123456789ABCDEF';");
-ok($node->log_contains(qr/statement:\s*$/m, $log_offset),
- "0 logs an empty statement body");
+ok($node->log_contains(qr/statement: ...\s*$/m, $log_offset),
+ "0 logs statement body with ellipsis");
# Verify truncation via the extended query protocol (execute message).
# With log_statement_max_length = 20, a 24-byte query should end
@@ -75,7 +75,7 @@ $node->psql(
SET log_statement_max_length TO 20;
SELECT '123456789ABCDEF' \\bind \\g");
ok( $node->log_contains(
- qr/execute <unnamed>: SELECT '123456789ABC$/m, $log_offset),
+ 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
@@ -102,14 +102,35 @@ $node->psql(
SET log_statement_max_length TO 20;
SELECT '123456789ABCDEF' \\bind \\g");
ok( $node->log_contains(
- qr/parse <unnamed>: SELECT '123456789ABC$/m, $log_offset),
+ qr/parse <unnamed>: SELECT '123456789ABC...$/m, $log_offset),
"parse duration entry truncated");
ok( $node->log_contains(
- qr/bind <unnamed>: SELECT '123456789ABC$/m, $log_offset),
+ qr/bind <unnamed>: SELECT '123456789ABC...$/m, $log_offset),
"bind duration entry truncated");
ok( $node->log_contains(
- qr/execute <unnamed>: SELECT '123456789ABC$/m, $log_offset),
+ qr/execute <unnamed>: SELECT '123456789ABC...$/m, $log_offset),
"execute duration entry truncated");
+note "Truncate prepared statement query in DETAIL";
+$log_offset = -s $node->logfile;
+$node->psql(
+ 'postgres', "
+ SET log_statement_max_length TO 12;
+ PREPARE stmt AS SELECT * FROM pg_hba_file_rules WHERE address = \$1;
+ EXECUTE stmt('127.0.0.1');");
+ok( $node->log_contains(
+ qr/prepare: PREPARE stmt...$/m, $log_offset),
+ "Truncate prepared statement query in DETAIL");
+
+note "Truncate prepared statement query in DETAIL (0 length)";
+$log_offset = -s $node->logfile;
+$node->psql(
+ 'postgres', "
+ SET log_statement_max_length TO 0;
+ PREPARE stmt AS SELECT * FROM pg_hba_file_rules WHERE address = \$1;
+ EXECUTE stmt('127.0.0.1');");
+ok( $node->log_contains(
+ qr/prepare: ...$/m, $log_offset),
+ "Truncate prepared statement query in DETAIL (0 length)");
$node->stop;
done_testing();
--
2.25.1
[text/x-patch] v1-0002-Simplify-callers-of-truncate_query_log.patch (3.2K, ../[email protected]/3-v1-0002-Simplify-callers-of-truncate_query_log.patch)
download | inline diff:
From 7110f93844d22f92ee664c2e5ba2d959ce7180bf Mon Sep 17 00:00:00 2001
From: Jim Jones <[email protected]>
Date: Wed, 8 Jul 2026 18:31:27 +0200
Subject: [PATCH v1 2/2] Simplify callers of truncate_query_log()
truncate_query_log() already returns NULL when query logging is disabled
or when no truncation is needed. Callers therefore do not need to check
log_statement_max_length before invoking it.
Remove the redundant checks and rely on truncate_query_log() to decide
whether a truncated copy should be returned. This is purely a code
cleanup with no behavioral change.
Author: Jim Jones <[email protected]>
---
src/backend/tcop/postgres.c | 30 ++++++------------------------
1 file changed, 6 insertions(+), 24 deletions(-)
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index b0947fd7298..61d28728ce1 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -1085,10 +1085,7 @@ 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);
+ char *truncated_stmt = truncate_query_log(query_string);
ereport(LOG,
(errmsg("statement: %s",
@@ -1392,10 +1389,7 @@ exec_simple_query(const char *query_string)
break;
case 2:
{
- char *truncated_stmt = NULL;
-
- if (log_statement_max_length >= 0)
- truncated_stmt = truncate_query_log(query_string);
+ char *truncated_stmt = truncate_query_log(query_string);
ereport(LOG,
(errmsg("duration: %s ms statement: %s",
@@ -1638,10 +1632,7 @@ exec_parse_message(const char *query_string, /* string to execute */
break;
case 2:
{
- char *truncated_stmt = NULL;
-
- if (log_statement_max_length >= 0)
- truncated_stmt = truncate_query_log(query_string);
+ char *truncated_stmt = truncate_query_log(query_string);
ereport(LOG,
(errmsg("duration: %s ms parse %s: %s",
@@ -2125,10 +2116,7 @@ exec_bind_message(StringInfo input_message)
break;
case 2:
{
- char *truncated_stmt = NULL;
-
- if (log_statement_max_length >= 0)
- truncated_stmt = truncate_query_log(psrc->query_string);
+ char *truncated_stmt = truncate_query_log(psrc->query_string);
ereport(LOG,
(errmsg("duration: %s ms bind %s%s%s: %s",
@@ -2282,10 +2270,7 @@ 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);
+ char *truncated_source = truncate_query_log(sourceText);
ereport(LOG,
(errmsg("%s %s%s%s: %s",
@@ -2414,10 +2399,7 @@ exec_execute_message(const char *portal_name, long max_rows)
break;
case 2:
{
- char *truncated_source = NULL;
-
- if (log_statement_max_length >= 0)
- truncated_source = truncate_query_log(sourceText);
+ char *truncated_source = truncate_query_log(sourceText);
ereport(LOG,
(errmsg("duration: %s ms %s %s%s%s: %s",
--
2.25.1
view thread (15+ messages) latest in thread
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: [email protected]
Cc: [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected]
Subject: Re: Truncate logs by max_log_size
In-Reply-To: <[email protected]>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox