Drop unnamed portal immediately after execution to completion

Previously, unnamed portals were kept until the next Bind message or the
end of the transaction.  This could cause temporary files to persist
longer than expected and make logging not reflect the actual SQL
responsible for the temporary file.

This patch changes exec_execute_message() to drop unnamed portals
immediately after execution to completion at the end of an Execute
message, making their removal more aggressive.  This forces temporary
file cleanups to happen at the same time as the completion of the portal
execution, with statement logging correctly reflecting to which
statements these temporary files were attached to (see the diffs in the
TAP test updated by this commit for an idea).

The documentation is updated to describe the lifetime of unnamed
portals, and test cases are updated to verify temporary file removal and
proper statement logging after unnamed portal execution.  This changes
how unnamed portals are handled in the protocol, hence no backpatch is
done.

Author: Frédéric Yhuel <frederic.yhuel@dalibo.com>
Co-Authored-by: Sami Imseih <samimseih@gmail.com>
Co-Authored-by: Mircea Cadariu <cadariu.mircea@gmail.com>
Discussion: https://postgr.es/m/CAA5RZ0tTrTUoEr3kDXCuKsvqYGq8OOHiBwoD-dyJocq95uEOTQ%40mail.gmail.com

diff --git a/doc/src/sgml/protocol.sgml b/doc/src/sgml/protocol.sgml
index 9d7552328736153879570f0b124a5139799cc306..d1b9af11b079940ab59e508c0ebbff19adf666ce 100644 (file)
--- a/doc/src/sgml/protocol.sgml
+++ b/doc/src/sgml/protocol.sgml
@@ -1006,8 +1006,8 @@ SELCT 1/0;<!-- this typo is intentional -->
    <para>
     If successfully created, a named portal object lasts till the end of the
     current transaction, unless explicitly destroyed.  An unnamed portal is
-    destroyed at the end of the transaction, or as soon as the next Bind
-    statement specifying the unnamed portal as destination is issued.  (Note
+    destroyed at the end of the transaction, or as soon as the statement
+    specifying the unnamed portal as destination is processed to completion.  (Note
     that a simple Query message also destroys the unnamed portal.)  Named
     portals must be explicitly closed before they can be redefined by another
     Bind message, but this is not required for the unnamed portal.

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 7dd75a490aab54e6066864bc4f0edec9e02563ae..2bd89102686e254d28bbc2dcc33c3b285c35b506 100644 (file)
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -2327,6 +2327,16 @@ exec_execute_message(const char *portal_name, long max_rows)
                         * message.  The next protocol message will start a fresh timeout.
                         */
                        disable_statement_timeout();
+
+                       /*
+                        * We completed fetching from an unnamed portal.  There is no need
+                        * for it beyond this point, so drop it now rather than wait for
+                        * the next Bind message to do this cleanup.  This ensures that
+                        * the correct statement is logged when cleaning up temporary file
+                        * usage.
+                        */
+                       if (portal->name[0] == '\0')
+                               PortalDrop(portal, false);
                }
 
                /* Send appropriate CommandComplete to client */

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
index 462a949e41141507834c4b4a9c1c979856dd7c88..7ecd301ae29ee3c272be434d27eef69e29b8e3fc 100644 (file)
--- a/src/test/modules/test_misc/t/009_log_temp_files.pl
+++ b/src/test/modules/test_misc/t/009_log_temp_files.pl
@@ -29,7 +29,7 @@ CREATE UNLOGGED TABLE foo(a int);
 INSERT INTO foo(a) SELECT * FROM generate_series(1, 5000);
 });
 
-note "unnamed portal: temporary file dropped under second SELECT query";
+note "unnamed portal: temporary file dropped under first SELECT query";
 my $log_offset = -s $node->logfile;
 $node->safe_psql(
        "postgres", qq{
@@ -39,22 +39,23 @@ SELECT 'unnamed portal';
 END;
 });
 ok( $node->log_contains(
-               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT 'unnamed portal'/s,
+               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT a FROM foo ORDER BY a OFFSET \$1/s,
                $log_offset),
        "unnamed portal");
 
-note "bind and implicit transaction: temporary file dropped without query";
+note
+  "bind and implicit transaction: temporary file dropped under single query";
 $log_offset = -s $node->logfile;
 $node->safe_psql(
        "postgres", qq{
 SELECT a FROM foo ORDER BY a OFFSET \$1 \\bind 4991 \\g
 });
-ok( $node->log_contains(qr/LOG:\s+temporary file:/s, $log_offset),
-       "bind and implicit transaction, temporary file removed");
-ok( !$node->log_contains(qr/STATEMENT:/s, $log_offset),
-       "bind and implicit transaction, no statement logged");
+ok( $node->log_contains(
+               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT a FROM foo ORDER BY a OFFSET \$1/s,
+               $log_offset),
+       "bind and implicit transaction");
 
-note "named portal: temporary file dropped under second SELECT query";
+note "named portal: temporary file dropped under first SELECT query";
 $node->safe_psql(
        "postgres", qq{
 BEGIN;
@@ -64,11 +65,11 @@ SELECT 'named portal';
 END;
 });
 ok( $node->log_contains(
-               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT 'named portal'/s,
+               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT a FROM foo ORDER BY a OFFSET \$1/s,
                $log_offset),
        "named portal");
 
-note "pipelined query: temporary file dropped under second SELECT query";
+note "pipelined query: temporary file dropped under first SELECT query";
 $log_offset = -s $node->logfile;
 $node->safe_psql(
        "postgres", qq{
@@ -78,21 +79,21 @@ SELECT 'pipelined query';
 \\endpipeline
 });
 ok( $node->log_contains(
-               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT 'pipelined query'/s,
+               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT a FROM foo ORDER BY a OFFSET \$1/s,
                $log_offset),
        "pipelined query");
 
-note "parse and bind: temporary file dropped without query";
+note "parse and bind: temporary file dropped under SELECT query";
 $log_offset = -s $node->logfile;
 $node->safe_psql(
        "postgres", qq{
 SELECT a, a, a FROM foo ORDER BY a OFFSET \$1 \\parse p1
 \\bind_named p1 4993 \\g
 });
-ok($node->log_contains(qr/LOG:\s+temporary file:/s, $log_offset),
-       "parse and bind, temporary file removed");
-ok(!$node->log_contains(qr/STATEMENT:/s, $log_offset),
-       "bind and bind, no statement logged");
+ok( $node->log_contains(
+               qr/LOG:\s+temporary file: path.*\n.*\ STATEMENT:\s+SELECT a, a, a FROM foo ORDER BY a OFFSET \$1/s,
+               $log_offset),
+       "parse and bind");
 
 note "simple query: temporary file dropped under SELECT query";
 $log_offset = -s $node->logfile;