On 8/21/25 14:02, Frédéric Yhuel wrote:
This v6 patch includes the TAP test that I sent in my previous email,
with some enhancements.
The meson test system was overlooked by this patch, and the attached v7
fixes that.From 554e8e62675574cbde0fd35b0a10f6ae56e5f0d6 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Yhuel?= <[email protected]>
Date: Wed, 18 Jun 2025 09:32:13 +0200
Subject: [PATCH v7] Fix reporting of temp files usage
Drop unnamed portals early enough so that we avoid blaming the wrong
query. There will be cases where no query is logged at all, like when
using the extended protocol with unnamed portal. Moreover, when using
SQL cursors, either the CLOSE request or the COMMIT will be logged,
which isn't great, but like before this patch.
Reviewed-by: Sami Imseih <[email protected]>
---
src/backend/tcop/postgres.c | 21 +++-
src/test/modules/test_misc/meson.build | 1 +
.../modules/test_misc/t/008_log_temp_files.pl | 113 ++++++++++++++++++
3 files changed, 129 insertions(+), 6 deletions(-)
create mode 100644 src/test/modules/test_misc/t/008_log_temp_files.pl
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 2f8c3d5f918..f307ed67827 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -1748,13 +1748,10 @@ exec_bind_message(StringInfo input_message)
errdetail_abort()));
/*
- * Create the portal. Allow silent replacement of an existing portal only
- * if the unnamed portal is specified.
+ * Create the portal. Don't allow silent replacement of an existing named portal.
+ * An unnamed portal should have been removed already.
*/
- if (portal_name[0] == '\0')
- portal = CreatePortal(portal_name, true, true);
- else
- portal = CreatePortal(portal_name, false, false);
+ portal = CreatePortal(portal_name, false, false);
/*
* Prepare to copy stuff into the portal's memory context. We do all this
@@ -4745,6 +4742,18 @@ PostgresMain(const char *dbname, const char *username)
if (ignore_till_sync && firstchar != EOF)
continue;
+ /* Drop unnamed portals early enough in order to avoid weird things with
+ * debug_query_string, like blaming the wrong query in the logs, when
+ * we log temporary files. */
+ if (firstchar == PqMsg_Query || firstchar == PqMsg_Bind)
+ {
+ Portal portal;
+
+ portal = GetPortalByName("");
+ if (PortalIsValid(portal))
+ PortalDrop(portal, false);
+ }
+
switch (firstchar)
{
case PqMsg_Query:
diff --git a/src/test/modules/test_misc/meson.build b/src/test/modules/test_misc/meson.build
index 9c50de7efb0..44d44d5344c 100644
--- a/src/test/modules/test_misc/meson.build
+++ b/src/test/modules/test_misc/meson.build
@@ -16,6 +16,7 @@ tests += {
't/005_timeouts.pl',
't/006_signal_autovacuum.pl',
't/007_catcache_inval.pl',
+ 't/008_log_temp_files.pl',
],
},
}
diff --git a/src/test/modules/test_misc/t/008_log_temp_files.pl b/src/test/modules/test_misc/t/008_log_temp_files.pl
new file mode 100644
index 00000000000..ebdd36010ff
--- /dev/null
+++ b/src/test/modules/test_misc/t/008_log_temp_files.pl
@@ -0,0 +1,113 @@
+# Copyright (c) 2025, PostgreSQL Global Development Group
+
+# Verify that temp files are logged with the right statement.
+
+use strict;
+use warnings FATAL => 'all';
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Test::More;
+
+sub check_log
+{
+ my $node = shift;
+ my $offset = shift;
+
+ if ($node->log_contains('STATEMENT: SELECT 1', $offset))
+ {
+ ok(0, "The wrong query has been logged");
+ }
+ elsif ($node->log_contains('STATEMENT: SELECT a FROM foo ORDER BY a', $offset))
+ {
+ ok(1, "The right query has been logged");
+ }
+ elsif ($node->log_contains('STATEMENT: CLOSE', $offset))
+ {
+ ok(1, "Cursor CLOSE has been logged, OK");
+ }
+ else
+ {
+ ok(1, "No query has been logged");
+ }
+}
+
+my $offset = 0;
+my $node = PostgreSQL::Test::Cluster->new('primary');
+$node->init();
+$node->append_conf(
+ 'postgresql.conf', qq(
+work_mem = 64kB
+log_temp_files = 0
+log_statement = none
+));
+$node->start;
+
+$node->safe_psql("postgres", qq{
+CREATE UNLOGGED TABLE foo(a int);
+INSERT INTO foo(a) SELECT * FROM generate_series(1, 5000);
+VACUUM ANALYZE foo;
+});
+
+$offset = -s $node->logfile;
+# The following sequence used to logged the second query instead of the first one
+# Now it should log no query at all
+$node->safe_psql("postgres", qq{
+BEGIN;
+SELECT a FROM foo ORDER BY a OFFSET \$1 \\bind 4999 \\g
+SELECT 1;
+COMMIT;
+});
+check_log($node, $offset);
+
+$offset = -s $node->logfile;
+# The following sequence should log no query at all
+$node->safe_psql("postgres", qq{
+SELECT a FROM foo ORDER BY a OFFSET \$1 \\bind 4999 \\g
+SELECT 1;
+});
+check_log($node, $offset);
+
+$offset = -s $node->logfile;
+# The following pipelined sequence used to logged the second query instead of the first one
+# Now it should log no query at all
+$node->safe_psql("postgres", qq{
+\\startpipeline
+SELECT a FROM foo ORDER BY a OFFSET \$1 \\bind 4999 \\sendpipeline
+SELECT 1;
+\\endpipeline
+});
+check_log($node, $offset);
+
+$offset = -s $node->logfile;
+# The following sequence should log the right query
+$node->safe_psql("postgres", qq{
+SELECT a FROM foo ORDER BY a OFFSET 4999;
+});
+check_log($node, $offset);
+
+$offset = -s $node->logfile;
+# The following sequence should log no query at all (named statement, unnamed portal)
+$node->safe_psql("postgres", qq{
+BEGIN;
+SELECT a FROM foo ORDER BY a OFFSET \$1 \\parse stmt
+\\bind_named stmt 4999 \\g
+SELECT 1;
+COMMIT;
+});
+check_log($node, $offset);
+
+$offset = -s $node->logfile;
+# The following sequence should log the CLOSE query
+$node->safe_psql("postgres", qq{
+BEGIN;
+DECLARE mycur CURSOR FOR SELECT a FROM foo ORDER BY a OFFSET 4999;
+FETCH 10 FROM mycur;
+SELECT 1;
+CLOSE mycur;
+COMMIT;
+});
+check_log($node, $offset);
+
+
+$node->stop('fast');
+done_testing();
--
2.47.2
