From a47ccafc334e8b508f117afdfc5ce3266e0ed8fa Mon Sep 17 00:00:00 2001 From: Jim Jones 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 Co-authored-by: Fujii Masao --- 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 ' , , or - is truncated to at most this many bytes. + is truncated to at most this many bytes. When a statement is + truncated, an ellipsis (...) is appended to + indicate that truncation has occurred. 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. 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 : SELECT '123456789ABC$/m, $log_offset), + qr/execute : 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 : SELECT '123456789ABC$/m, $log_offset), + qr/parse : SELECT '123456789ABC...$/m, $log_offset), "parse duration entry truncated"); ok( $node->log_contains( - qr/bind : SELECT '123456789ABC$/m, $log_offset), + qr/bind : SELECT '123456789ABC...$/m, $log_offset), "bind duration entry truncated"); ok( $node->log_contains( - qr/execute : SELECT '123456789ABC$/m, $log_offset), + qr/execute : 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