psql: Update \timing also in case of an error

The changes to show all query results (7844c9918) broke \timing output
in case of an error; it didn't update the timing result and showed
0.000 ms.

Fix by updating the timing result also in the error case.  Also, for
robustness, update the timing result any time a result is obtained,
not only for the last, so a sensible value is always available.

Reported-by: Tom Lane <[email protected]>
Author: Richard Guo <[email protected]>
Author: Fabien COELHO <[email protected]>
Discussion: https://www.postgresql.org/message-id/3813350.1652111765%40sss.pgh.pa.us

diff --git a/src/bin/psql/common.c b/src/bin/psql/common.c
index 9b140badeb9f8380da58d5114355957158615a97..03e6d9ce8f85c7b3d87dea146df29488ca6eb67c 100644 (file)
--- a/src/bin/psql/common.c
+++ b/src/bin/psql/common.c
@@ -1566,6 +1566,16 @@ ExecQueryAndProcessResults(const char *query, double *elapsed_msec, bool *svpt_g
            else
                result = PQgetResult(pset.db);
 
+           /*
+            * Get current timing measure in case an error occurs
+            */
+           if (timing)
+           {
+               INSTR_TIME_SET_CURRENT(after);
+               INSTR_TIME_SUBTRACT(after, before);
+               *elapsed_msec = INSTR_TIME_GET_MILLISEC(after);
+           }
+
            continue;
        }
        else if (svpt_gone_p && !*svpt_gone_p)
@@ -1619,7 +1629,7 @@ ExecQueryAndProcessResults(const char *query, double *elapsed_msec, bool *svpt_g
        last = (next_result == NULL);
 
        /*
-        * Get timing measure before printing the last result.
+        * Update current timing measure.
         *
         * It will include the display of previous results, if any. This
         * cannot be helped because the server goes on processing further
@@ -1630,7 +1640,7 @@ ExecQueryAndProcessResults(const char *query, double *elapsed_msec, bool *svpt_g
         * With combined queries, timing must be understood as an upper bound
         * of the time spent processing them.
         */
-       if (last && timing)
+       if (timing)
        {
            INSTR_TIME_SET_CURRENT(after);
            INSTR_TIME_SUBTRACT(after, before);

diff --git a/src/bin/psql/t/001_basic.pl b/src/bin/psql/t/001_basic.pl
index 90e69d7cdba368fca5a32cfc18bd8828f293c3e0..c3ed18e84da2fab138caa18b391a23e80beb2678 100644 (file)
--- a/src/bin/psql/t/001_basic.pl
+++ b/src/bin/psql/t/001_basic.pl
@@ -85,8 +85,16 @@ psql_like(
    '\timing on
 SELECT 1',
    qr/^1$
-^Time: \d+.\d\d\d ms/m,
-   '\timing');
+^Time: \d+\.\d\d\d ms/m,
+   '\timing with successful query');
+
+# test \timing with query that fails
+{
+   my ($ret, $stdout, $stderr) = $node->psql('postgres', "\\timing on\nSELECT error");
+   isnt($ret, 0, '\timing with query error: query failed');
+   like($stdout, qr/^Time: \d+\.\d\d\d ms/m, '\timing with query error: timing output appears');
+   unlike($stdout, qr/^Time: 0\.000 ms/m, '\timing with query error: timing was updated');
+}
 
 # test that ENCODING variable is set and that it is updated when
 # client encoding is changed