v9-0001-Drop-unnamed-portal-before-setting-debug_query_st.patch

text/plain

Filename: v9-0001-Drop-unnamed-portal-before-setting-debug_query_st.patch
Type: text/plain
Part: 0
Message: Re: [BUG] temporary file usage report with extended protocol and unnamed portals
From b2bc429dd0fb4f01920a3bf70a9756cf912f0c56 Mon Sep 17 00:00:00 2001
From: "Sami Imseih (AWS)"
 <simseih@dev-dsk-simseih-1e-c76a1a95.us-east-1.amazon.com>
Date: Fri, 29 Aug 2025 17:19:34 +0000
Subject: [PATCH v9] Drop unnamed portal before setting debug_query_string

Discussion: https://www.postgresql.org/message-id/flat/3d07ee43-8855-42db-97e0-bad5db82d972@dalibo.com
---
 src/backend/tcop/postgres.c                   |  48 +++++++-
 src/backend/utils/mmgr/portalmem.c            |  62 ++++++----
 src/include/utils/portal.h                    |   1 +
 src/test/modules/test_misc/meson.build        |   1 +
 .../modules/test_misc/t/009_log_temp_files.pl | 115 ++++++++++++++++++
 5 files changed, 199 insertions(+), 28 deletions(-)
 create mode 100644 src/test/modules/test_misc/t/009_log_temp_files.pl

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 0cecd46490..bbfee7c0ce 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -148,6 +148,7 @@ static bool ignore_till_sync = false;
  * in order to reduce overhead for short-lived queries.
  */
 static CachedPlanSource *unnamed_stmt_psrc = NULL;
+static bool unnamed_portal = false;
 
 /* assorted command-line switches */
 static const char *userDoption = NULL;	/* -D switch */
@@ -182,6 +183,7 @@ static bool IsTransactionExitStmt(Node *parsetree);
 static bool IsTransactionExitStmtList(List *pstmts);
 static bool IsTransactionStmtList(List *pstmts);
 static void drop_unnamed_stmt(void);
+static void drop_unnamed_portal(void);
 static void log_disconnections(int code, Datum arg);
 static void enable_statement_timeout(void);
 static void disable_statement_timeout(void);
@@ -1020,6 +1022,12 @@ exec_simple_query(const char *query_string)
 	bool		use_implicit_block;
 	char		msec_str[32];
 
+	/*
+	 * Drop the unnamed portal before setting debug_query_string, to avoid
+	 * attributing messages from the drop (e.g., temp usage) to the new query.
+	 */
+	drop_unnamed_portal();
+
 	/*
 	 * Report query to various monitoring facilities.
 	 */
@@ -1213,7 +1221,13 @@ exec_simple_query(const char *query_string)
 		 * Create unnamed portal to run the query or queries in. If there
 		 * already is one, silently drop it.
 		 */
-		portal = CreatePortal("", true, true);
+		if (!unnamed_portal)
+			portal = CreatePortalOnly("");
+		else
+			portal = CreatePortal("", true, true);
+
+		unnamed_portal = true;
+
 		/* Don't display the portal in pg_cursors */
 		portal->visible = false;
 
@@ -1672,6 +1686,12 @@ exec_bind_message(StringInfo input_message)
 					 errmsg("unnamed prepared statement does not exist")));
 	}
 
+	/*
+	 * Same as exec_simple_query, drop the unnamed portal before setting
+	 * debug_query_string.
+	 */
+	drop_unnamed_portal();
+
 	/*
 	 * Report query to various monitoring facilities.
 	 */
@@ -1753,7 +1773,14 @@ exec_bind_message(StringInfo input_message)
 	 * if the unnamed portal is specified.
 	 */
 	if (portal_name[0] == '\0')
-		portal = CreatePortal(portal_name, true, true);
+	{
+		if (!unnamed_portal)
+			portal = CreatePortalOnly(portal_name);
+		else
+			portal = CreatePortal(portal_name, true, true);
+
+		unnamed_portal = true;
+	}
 	else
 		portal = CreatePortal(portal_name, false, false);
 
@@ -5229,3 +5256,20 @@ disable_statement_timeout(void)
 	if (get_timeout_active(STATEMENT_TIMEOUT))
 		disable_timeout(STATEMENT_TIMEOUT, false);
 }
+
+/* Drop the unnamed portal if one exists */
+static void
+drop_unnamed_portal(void)
+{
+	Portal		portal;
+
+	if (!unnamed_portal)
+		return;
+
+	/* Get the portal and drop it */
+	portal = GetPortalByName("");
+	if (PortalIsValid(portal))
+		PortalDrop(portal, false);
+
+	unnamed_portal = false;
+}
diff --git a/src/backend/utils/mmgr/portalmem.c b/src/backend/utils/mmgr/portalmem.c
index 0be1c2b0ff..facb475fd9 100644
--- a/src/backend/utils/mmgr/portalmem.c
+++ b/src/backend/utils/mmgr/portalmem.c
@@ -162,37 +162,13 @@ PortalGetPrimaryStmt(Portal portal)
 	return NULL;
 }
 
-/*
- * CreatePortal
- *		Returns a new portal given a name.
- *
- * allowDup: if true, automatically drop any pre-existing portal of the
- * same name (if false, an error is raised).
- *
- * dupSilent: if true, don't even emit a WARNING.
- */
 Portal
-CreatePortal(const char *name, bool allowDup, bool dupSilent)
+CreatePortalOnly(const char *name)
 {
-	Portal		portal;
+	Portal portal;
 
 	Assert(PointerIsValid(name));
 
-	portal = GetPortalByName(name);
-	if (PortalIsValid(portal))
-	{
-		if (!allowDup)
-			ereport(ERROR,
-					(errcode(ERRCODE_DUPLICATE_CURSOR),
-					 errmsg("cursor \"%s\" already exists", name)));
-		if (!dupSilent)
-			ereport(WARNING,
-					(errcode(ERRCODE_DUPLICATE_CURSOR),
-					 errmsg("closing existing cursor \"%s\"",
-							name)));
-		PortalDrop(portal, false);
-	}
-
 	/* make new portal structure */
 	portal = (Portal) MemoryContextAllocZero(TopPortalContext, sizeof *portal);
 
@@ -227,6 +203,40 @@ CreatePortal(const char *name, bool allowDup, bool dupSilent)
 	return portal;
 }
 
+/*
+ * CreatePortal
+ *		Returns a new portal given a name.
+ *
+ * allowDup: if true, automatically drop any pre-existing portal of the
+ * same name (if false, an error is raised).
+ *
+ * dupSilent: if true, don't even emit a WARNING.
+ */
+Portal
+CreatePortal(const char *name, bool allowDup, bool dupSilent)
+{
+	Portal		portal;
+
+	Assert(PointerIsValid(name));
+
+	portal = GetPortalByName(name);
+	if (PortalIsValid(portal))
+	{
+		if (!allowDup)
+			ereport(ERROR,
+					(errcode(ERRCODE_DUPLICATE_CURSOR),
+					 errmsg("cursor \"%s\" already exists", name)));
+		if (!dupSilent)
+			ereport(WARNING,
+					(errcode(ERRCODE_DUPLICATE_CURSOR),
+					 errmsg("closing existing cursor \"%s\"",
+							name)));
+		PortalDrop(portal, false);
+	}
+
+	return CreatePortalOnly(name);
+}
+
 /*
  * CreateNewPortal
  *		Create a new portal, assigning it a random nonconflicting name.
diff --git a/src/include/utils/portal.h b/src/include/utils/portal.h
index 0b62143af8..fb80bf3945 100644
--- a/src/include/utils/portal.h
+++ b/src/include/utils/portal.h
@@ -226,6 +226,7 @@ extern void AtSubAbort_Portals(SubTransactionId mySubid,
 							   ResourceOwner myXactOwner,
 							   ResourceOwner parentXactOwner);
 extern void AtSubCleanup_Portals(SubTransactionId mySubid);
+extern Portal CreatePortalOnly(const char *name);
 extern Portal CreatePortal(const char *name, bool allowDup, bool dupSilent);
 extern Portal CreateNewPortal(void);
 extern void PinPortal(Portal portal);
diff --git a/src/test/modules/test_misc/meson.build b/src/test/modules/test_misc/meson.build
index 6b1e730bf4..f258bf1ccd 100644
--- a/src/test/modules/test_misc/meson.build
+++ b/src/test/modules/test_misc/meson.build
@@ -17,6 +17,7 @@ tests += {
       't/006_signal_autovacuum.pl',
       't/007_catcache_inval.pl',
       't/008_replslot_single_user.pl',
+      't/009_log_temp_files.pl',
     ],
   },
 }
diff --git a/src/test/modules/test_misc/t/009_log_temp_files.pl b/src/test/modules/test_misc/t/009_log_temp_files.pl
new file mode 100644
index 0000000000..d16eb82a54
--- /dev/null
+++ b/src/test/modules/test_misc/t/009_log_temp_files.pl
@@ -0,0 +1,115 @@
+# 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 = all
+log_line_prefix='%t [%p]: [%l-1] user=%u,db=%d,host=%h,app=%a,cilent=%h'
+log_min_duration_statement = 0
+));
+$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 log 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 log 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();

base-commit: 09119238a18191dea3deed635a2b2a6ffe904932
-- 
2.39.5 (Apple Git-154)