Subject: Re: explain analyze rows=%.0f

From: Ibrar Ahmed <[email-masked]>
Date: Thu, 8 Jun 2023 22:49:11 +0500

On Mon, Mar 20, 2023 at 7:56 PM Gregory Stark (as CFM) <[email-masked]>
wrote:

> On Wed, 4 Jan 2023 at 10:05, Ibrar Ahmed <[email-masked]> wrote:
> >
> > Thanks, I have modified everything as suggested, except one point
> >
> > > Don't use variable format strings. They're hard to read and they
> > > probably defeat compile-time checks that the arguments match the
> > > format string. You could use a "*" field width instead, ie
> ...
> > > * Another thought is that the non-text formats tend to prize output
> > > consistency over readability, so maybe we should just always use 2
> > > fractional digits there, rather than trying to minimize visible
> changes.
> >
> > In that, we need to adjust a lot of test case outputs.
>
> > > * We need some doc adjustments, surely, to explain what the heck this
> > > means.
>
> That sounds like three points :) But they seem like pretty good
> arguments to me and straightforward if a little tedious to adjust.
>
> This patch was marked Returned with Feedback and then later Waiting on
> Author. And it hasn't had any updates since January. What is the state
> on this feedback? If it's already done we can set the patch to Ready
> for Commit and if not do you disagree with the proposed changes?
>
> If there is a consensus to modify the test cases' output, I am willing to
make the necessary changes and adjust the patch accordingly. However,
if there is a preference to keep the output of certain test cases unchanged,
I can rebase and modify the patch accordingly to accommodate those
preferences.

> It's actually the kind of code cleanup changes I'm reluctant to bump a
> patch for. It's not like a committer can't make these kinds of changes
> when committing. But there are so many patches they're likely to just
> focus on a different patch when there are adjustments like this
> pending.
>
> --
> Gregory Stark
> As Commitfest Manager
>

-- 
Ibrar Ahmed

---

From: Daniel Gustafsson <[email-masked]>
Date: Mon, 3 Jul 2023 18:34:47 +0200

> On 8 Jun 2023, at 19:49, Ibrar Ahmed <[email-masked]> wrote:
> On Mon, Mar 20, 2023 at 7:56 PM Gregory Stark (as CFM) <[email-masked] <mailto:[email-masked]>> wrote:

> I can rebase and modify the patch accordingly to accommodate those preferences.

As there hasn't been any other comments I suggest updating your patch to
address Tom's comments to see if we can make progress here.

--
Daniel Gustafsson

---

From: Daniel Gustafsson <[email-masked]>
Date: Tue, 1 Aug 2023 22:29:05 +0200

> On 3 Jul 2023, at 18:34, Daniel Gustafsson <[email-masked]> wrote:
> 

Since there hasn't been any updates here, and the thread has been stalled, I'm
marking this returned with feedback.  Please feel free to resubmit a version of
the patch addressing comments to a future CF.

--
Daniel Gustafsson

---

From: Ilia Evdokimov <[email-masked]>
Date: Thu, 12 Dec 2024 14:56:47 +0300

> the patch addressing comments to a future CF.

Hi everybody,

When the total number of returned tuples is less than the number of 
loops currently shows 'rows = 0'. This can mislead users into thinking 
that no rows were returned at all, even though some might have appeared 
occasionally. For example, if there is 1 tuple over 100 loops, the 
average is 0.01 rows per loop, but as displayed it simply looks like zero.

To clarify this situation, it has been suggested that display rows with 
two decimal places in scenarios where 'loops > 1 && ntuples < loops'. In 
other words, show something like 'rows = 0.01' instead of 'rows=0'. This 
minor change would make it evident that rows did occur, just very 
infrequently.

For all other cases, the current formatting would remain the same. This 
approach aims to provide a more nuanced understanding of query execution 
behavior without introducing unnecessary complexity or false precision.

I would appreciate any thoughts or feedback on this proposal.

--
Best regards,
Ilia Evdokimov,
Tantor Labs LLC.
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index a201ed3082..b3f7fa8743 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -1981,14 +1981,14 @@ ExplainNode(PlanState *planstate, List *ancestors,
 
 		if (es->format == EXPLAIN_FORMAT_TEXT)
 		{
+			appendStringInfo(es->str, " (actual");
 			if (es->timing)
-				appendStringInfo(es->str,
-								 " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)",
-								 startup_ms, total_ms, rows, nloops);
+				appendStringInfo(es->str, " time=%.3f..%.3f", startup_ms, total_ms);
+
+			if (nloops > 1 && planstate->instrument->ntuples < nloops)
+				appendStringInfo(es->str," rows=%.2f loops=%.2f)", rows, nloops);
 			else
-				appendStringInfo(es->str,
-								 " (actual rows=%.0f loops=%.0f)",
-								 rows, nloops);
+				appendStringInfo(es->str," rows=%.0f loops=%.0f)", rows, nloops);
 		}
 		else
 		{
@@ -1999,8 +1999,16 @@ ExplainNode(PlanState *planstate, List *ancestors,
 				ExplainPropertyFloat("Actual Total Time", "ms", total_ms,
 									 3, es);
 			}
-			ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
-			ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+			if (nloops > 1 && planstate->instrument->ntuples < nloops)
+			{
+				ExplainPropertyFloat("Actual Rows", NULL, rows, 2, es);
+				ExplainPropertyFloat("Actual Loops", NULL, nloops, 2, es);
+			}
+			else
+			{
+				ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+				ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+			}
 		}
 	}
 	else if (es->analyze)
@@ -2052,14 +2060,14 @@ ExplainNode(PlanState *planstate, List *ancestors,
 			if (es->format == EXPLAIN_FORMAT_TEXT)
 			{
 				ExplainIndentText(es);
+				appendStringInfo(es->str, "actual");
 				if (es->timing)
-					appendStringInfo(es->str,
-									 "actual time=%.3f..%.3f rows=%.0f loops=%.0f\n",
-									 startup_ms, total_ms, rows, nloops);
+					appendStringInfo(es->str, " time=%.3f..%.3f", startup_ms, total_ms);
+
+				if (nloops > 1 && planstate->instrument->ntuples < nloops)
+					appendStringInfo(es->str," rows=%.2f loops=%.2f)", rows, nloops);
 				else
-					appendStringInfo(es->str,
-									 "actual rows=%.0f loops=%.0f\n",
-									 rows, nloops);
+					appendStringInfo(es->str," rows=%.0f loops=%.0f)", rows, nloops);
 			}
 			else
 			{
@@ -2070,8 +2078,17 @@ ExplainNode(PlanState *planstate, List *ancestors,
 					ExplainPropertyFloat("Actual Total Time", "ms",
 										 total_ms, 3, es);
 				}
-				ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
-				ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+
+				if (nloops > 1 && planstate->instrument->ntuples < nloops)
+				{
+					ExplainPropertyFloat("Actual Rows", NULL, rows, 2, es);
+					ExplainPropertyFloat("Actual Loops", NULL, nloops, 2, es);
+				}
+				else
+				{
+					ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+					ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+				}
 			}
 
 			ExplainCloseWorker(n, es);
diff --git a/src/test/regress/expected/partition_prune.out b/src/test/regress/expected/partition_prune.out
index c52bc40e81..cf50776ef7 100644
--- a/src/test/regress/expected/partition_prune.out
+++ b/src/test/regress/expected/partition_prune.out
@@ -3041,16 +3041,16 @@ select * from tbl1 inner join tprt on tbl1.col1 > tprt.col1;
 
 explain (analyze, costs off, summary off, timing off, buffers off)
 select * from tbl1 inner join tprt on tbl1.col1 = tprt.col1;
-                                QUERY PLAN                                
---------------------------------------------------------------------------
+                                   QUERY PLAN                                   
+--------------------------------------------------------------------------------
  Nested Loop (actual rows=3 loops=1)
    ->  Seq Scan on tbl1 (actual rows=5 loops=1)
-   ->  Append (actual rows=1 loops=5)
+   ->  Append (actual rows=0.60 loops=5.00)
          ->  Index Scan using tprt1_idx on tprt_1 (never executed)
                Index Cond: (col1 = tbl1.col1)
          ->  Index Scan using tprt2_idx on tprt_2 (actual rows=1 loops=2)
                Index Cond: (col1 = tbl1.col1)
-         ->  Index Scan using tprt3_idx on tprt_3 (actual rows=0 loops=3)
+         ->  Index Scan using tprt3_idx on tprt_3 (actual rows=0.33 loops=3.00)
                Index Cond: (col1 = tbl1.col1)
          ->  Index Scan using tprt4_idx on tprt_4 (never executed)
                Index Cond: (col1 = tbl1.col1)

---

From: Guillaume Lelarge <[email-masked]>
Date: Sat, 11 Jan 2025 10:15:06 +0100

Hello,

Le jeu. 12 déc. 2024 à 12:57, Ilia Evdokimov <[email-masked]>
a écrit :

> >>> On Mon, Mar 20, 2023 at 7:56 PM Gregory Stark (as CFM) <
> [email-masked] <mailto:[email-masked]>> wrote:
Thanks for your patch, this looks like a very interesting feature that I'd
like to see in a future release.

It did a quick run: patch OK, make OK, make install OK, but make check
fails quite a lot on partition_prune.sql.

I guess it would need some work on partition_prune.sql tests and perhaps
also on the docs.

Thanks again.

-- 
Guillaume.

---

From: Ilia Evdokimov <[email-masked]>
Date: Sat, 11 Jan 2025 14:10:47 +0300

On 11.01.2025 12:15, Guillaume Lelarge wrote:
>
>
> Thanks for your patch, this looks like a very interesting feature that 
> I'd like to see in a future release.
>
> I guess it would need some work on partition_prune.sql tests and 
> perhaps also on the docs.
>
> Thanks again.
>
>
> -- 
> Guillaume.

Yes, certainly. I have fixed partition_prune.sql. In the documentation 
example for EXPLAIN ANALYZE where loops is greater than one, I updated 
how 'rows' and 'loops' values are displayed so they appear as decimal 
fractions with two digits after the decimal point.

I attached fixed patch.

Any suggestions?

--
Best regards,
Ilia Evdokimov,
Tantor Labs LLC.
From a934fbd278350edf7a3a3e7fe620a0027ceb2580 Mon Sep 17 00:00:00 2001
From: Ilia Evdokimov <[email-masked]>
Date: Sat, 11 Jan 2025 13:59:34 +0300
Subject: [PATCH] Clarify display of rows and loops as decimal fractions

When the average number of rows is small compared to the number of loops,
both rows and loops are displayed as decimal fractions with two digits
after the decimal point in EXPLAIN ANALYZE.
---
 doc/src/sgml/perform.sgml                     |  2 +-
 src/backend/commands/explain.c                | 49 +++++++++++++------
 src/test/regress/expected/partition_prune.out | 10 ++--
 src/test/regress/sql/partition_prune.sql      |  2 +-
 4 files changed, 40 insertions(+), 23 deletions(-)

diff --git a/doc/src/sgml/perform.sgml b/doc/src/sgml/perform.sgml
index a502a2aaba..da7a19f4b8 100644
--- a/doc/src/sgml/perform.sgml
+++ b/doc/src/sgml/perform.sgml
@@ -730,7 +730,7 @@ WHERE t1.unique1 &lt; 10 AND t1.unique2 = t2.unique2;
          -&gt;  Bitmap Index Scan on tenk1_unique1  (cost=0.00..4.36 rows=10 width=0) (actual time=0.004..0.004 rows=10 loops=1)
                Index Cond: (unique1 &lt; 10)
                Buffers: shared hit=2
-   -&gt;  Index Scan using tenk2_unique2 on tenk2 t2  (cost=0.29..7.90 rows=1 width=244) (actual time=0.003..0.003 rows=1 loops=10)
+   -&gt;  Index Scan using tenk2_unique2 on tenk2 t2  (cost=0.29..7.90 rows=1 width=244) (actual time=0.003..0.003 rows=1.00 loops=10.00)
          Index Cond: (unique2 = t1.unique2)
          Buffers: shared hit=24 read=6
  Planning:
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index c24e66f82e..200294b756 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -1981,14 +1981,14 @@ ExplainNode(PlanState *planstate, List *ancestors,

 			ExplainCloseWorker(n, es);
diff --git a/src/test/regress/expected/partition_prune.out b/src/test/regress/expected/partition_prune.out
index c52bc40e81..dc6a3cb54a 100644
--- a/src/test/regress/expected/partition_prune.out
+++ b/src/test/regress/expected/partition_prune.out
@@ -2338,7 +2338,7 @@ begin
             $1)
     loop
         ln := regexp_replace(ln, 'Workers Launched: \d+', 'Workers Launched: N');
-        ln := regexp_replace(ln, 'actual rows=\d+ loops=\d+', 'actual rows=N loops=N');
+        ln := regexp_replace(ln, 'actual rows=\d+(?:\.\d+)? loops=\d+(?:\.\d+)?', 'actual rows=N loops=N');
         ln := regexp_replace(ln, 'Rows Removed by Filter: \d+', 'Rows Removed by Filter: N');
         return next ln;
     end loop;
@@ -3041,16 +3041,16 @@ select * from tbl1 inner join tprt on tbl1.col1 > tprt.col1;
 
 explain (analyze, costs off, summary off, timing off, buffers off)
 select * from tbl1 inner join tprt on tbl1.col1 = tprt.col1;
-                                QUERY PLAN                                
---------------------------------------------------------------------------
+                                   QUERY PLAN                                   
+--------------------------------------------------------------------------------
  Nested Loop (actual rows=3 loops=1)
    ->  Seq Scan on tbl1 (actual rows=5 loops=1)
-   ->  Append (actual rows=1 loops=5)
+   ->  Append (actual rows=0.60 loops=5.00)
          ->  Index Scan using tprt1_idx on tprt_1 (never executed)
                Index Cond: (col1 = tbl1.col1)
          ->  Index Scan using tprt2_idx on tprt_2 (actual rows=1 loops=2)
                Index Cond: (col1 = tbl1.col1)
-         ->  Index Scan using tprt3_idx on tprt_3 (actual rows=0 loops=3)
+         ->  Index Scan using tprt3_idx on tprt_3 (actual rows=0.33 loops=3.00)
                Index Cond: (col1 = tbl1.col1)
          ->  Index Scan using tprt4_idx on tprt_4 (never executed)
                Index Cond: (col1 = tbl1.col1)
diff --git a/src/test/regress/sql/partition_prune.sql b/src/test/regress/sql/partition_prune.sql
index d67598d5c7..bb1e09a536 100644
--- a/src/test/regress/sql/partition_prune.sql
+++ b/src/test/regress/sql/partition_prune.sql
@@ -571,7 +571,7 @@ begin
             $1)
     loop
         ln := regexp_replace(ln, 'Workers Launched: \d+', 'Workers Launched: N');
-        ln := regexp_replace(ln, 'actual rows=\d+ loops=\d+', 'actual rows=N loops=N');
+        ln := regexp_replace(ln, 'actual rows=\d+(?:\.\d+)? loops=\d+(?:\.\d+)?', 'actual rows=N loops=N');
         ln := regexp_replace(ln, 'Rows Removed by Filter: \d+', 'Rows Removed by Filter: N');
         return next ln;
     end loop;
-- 
2.34.1

---

From: Guillaume Lelarge <[email-masked]>
Date: Sat, 11 Jan 2025 15:02:15 +0100

Le sam. 11 janv. 2025 à 12:10, Ilia Evdokimov <[email-masked]>
a écrit :

> example for EXPLAIN ANALYZE where loops is greater than one, I updated how
> 'rows' and 'loops' values are displayed so they appear as decimal fractions
> with two digits after the decimal point.
>
> I attached fixed patch.
>
> Any suggestions?
>

Thanks for the updated patch.

"make check" is happy, so no more suggestions, except you should register
it in the next commitfest.

-- 
Guillaume.

---

From: Ilia Evdokimov <[email-masked]>
Date: Sat, 11 Jan 2025 21:21:16 +0300

On 11.01.2025 17:02, Guillaume Lelarge wrote:
> Le sam. 11 janv. 2025 à 12:10, Ilia Evdokimov 
> <[email-masked]> a écrit :
>
>
>>     Thanks for your patch, this looks like a very interesting feature
>>     that I'd like to see in a future release.
>>
>>     It did a quick run: patch OK, make OK, make install OK, but make
>>     check fails quite a lot on partition_prune.sql.
>>
>     Yes, certainly. I have fixed partition_prune.sql. In the
>     documentation example for EXPLAIN ANALYZE where loops is greater
>     than one, I updated how 'rows' and 'loops' values are displayed so
>     they appear as decimal fractions with two digits after the decimal
>     point.
>
>     I attached fixed patch.
>
>     Any suggestions?
>
>
> "make check" is happy, so no more suggestions, except you should 
> register it in the next commitfest.
>
>
> -- 
> Guillaume.

Done!

https://commitfest.postgresql.org/52/5501/

--
Best regards,
Ilia Evdokimov,
Tantor Labs LLC.