On 12.02.2025 22:56, Robert Haas wrote:
On Wed, Feb 12, 2025 at 2:55 PM Andrei Lepikhov<lepi...@gmail.com> wrote:
On 13/2/2025 01:40, Tom Lane wrote:
I was idly speculating yesterday about letting the Ryu code print
the division result, so that we get a variable number of digits.
Realistically, that'd probably result in many cases in more digits
than anybody wants, so it's not a serious proposal. I'm cool with
the fixed-two-digits approach to start with.
Okay, since no one else voted for the meaningful-numbers approach, I
would say that fixed size is better than nothing. It may cover some of
my practical cases, but unfortunately, not the most problematic ones.
I don't love it either, but I do think it is significantly better than nothing.
I'm in favor of having some improvement rather than nothing at
all—otherwise, we might never reach a consensus.
1. Documentation
(v9-0001-Clarify-display-of-rows-as-decimal-fractions-DOC.patch)
One thing that bothers me is that the documentation explains how to
compute total time, but it does not clarify how to compute total rows.
Maybe this was obvious to others before, but now that we are displaying
|rows| as a fraction, we should explicitly document how to interpret it
alongside total time.
I believe it would be helpful to show a non-integer rows value in an
example query. However, to achieve this, we need the index scan results
to vary across iterations. One way to accomplish this is by using the
condition t1.unique2 > t2.unique2. Additionally, I suggest making loops
a round number (e.g., 100) for better readability, which can be achieved
using t1.thousand < 10. The final query would look like this:
EXPLAIN ANALYZE SELECT *
FROM tenk1 t1, tenk2 t2
WHERE t1.thousand < 10 AND t1.unique2 > t2.unique2;
I believe this is an ideal example for the documentation because it not
only demonstrates fractional rows, but also keeps the execution plan
nearly unchanged. While the estimated and actual average row counts
become slightly rounded, I don't see another way to ensure different
results for each index scan.
I'm open to any feedback or suggestions for a better example to use in
the documentation or additional explaining fractional rows in the text.
2. Code and tests
(v9-0002-Clarify-display-of-rows-as-decimal-fractions.patch)
I left the code and tests unchanged since we agreed on a fixed format of
two decimal places.
--
Best regards,
Ilia Evdokimov,
Tantor Labs LLC.
From 789d98383988ef6d3b0bc2c6b9b5c73a83ffd6d4 Mon Sep 17 00:00:00 2001
From: Ilia Evdokimov <ilya.evdoki...@tantorlabs.ru>
Date: Thu, 13 Feb 2025 11:19:03 +0300
Subject: [PATCH v9] Clarify display of rows as decimal fractions
When loops > 1, the average rows value is now displayed as a decimal fraction
with two digits after the decimal point in EXPLAIN ANALYZE.
Previously, the average rows value was always rounded to an integer,
which could lead to misleading results when estimating total rows
by multiplying rows by loop. This change ensures that users
get a more accurate representation of the data flow through execution nodes.
---
doc/src/sgml/perform.sgml | 41 ++++++++++++++++++++-------------------
1 file changed, 21 insertions(+), 20 deletions(-)
diff --git a/doc/src/sgml/perform.sgml b/doc/src/sgml/perform.sgml
index a502a2aaba..dd61ae4507 100644
--- a/doc/src/sgml/perform.sgml
+++ b/doc/src/sgml/perform.sgml
@@ -717,26 +717,26 @@ FROM tenk1 t1 WHERE t1.ten = (SELECT (random() * 10)::integer);
<screen>
EXPLAIN ANALYZE SELECT *
FROM tenk1 t1, tenk2 t2
-WHERE t1.unique1 < 10 AND t1.unique2 = t2.unique2;
-
- QUERY PLAN
--------------------------------------------------------------------&zwsp;--------------------------------------------------------------
- Nested Loop (cost=4.65..118.50 rows=10 width=488) (actual time=0.017..0.051 rows=10 loops=1)
- Buffers: shared hit=36 read=6
- -> Bitmap Heap Scan on tenk1 t1 (cost=4.36..39.38 rows=10 width=244) (actual time=0.009..0.017 rows=10 loops=1)
- Recheck Cond: (unique1 < 10)
- Heap Blocks: exact=10
- Buffers: shared hit=3 read=5 written=4
- -> 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 < 10)
+WHERE t1.thousand < 10 AND t1.unique2 > t2.unique2;
+
+ QUERY PLAN
+-------------------------------------------------------------------&zwsp;-------------------------------------------------------------------------
+ Nested Loop (cost=5.40..11571.44 rows=356667 width=488) (actual time=0.042..117.205 rows=513832 loops=1)
+ Buffers: shared hit=19377 read=29
+ -> Bitmap Heap Scan on tenk1 t1 (cost=5.11..233.60 rows=107 width=244) (actual time=0.021..0.103 rows=100 loops=1)
+ Recheck Cond: (thousand < 10)
+ Heap Blocks: exact=90
+ Buffers: shared hit=92
+ -> Bitmap Index Scan on tenk1_thous_tenthous (cost=0.00..5.09 rows=107 width=0) (actual time=0.010..0.010 rows=100 loops=1)
+ Index Cond: (thousand < 10)
Buffers: shared hit=2
- -> 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)
- Index Cond: (unique2 = t1.unique2)
- Buffers: shared hit=24 read=6
+ -> Index Scan using tenk2_unique2 on tenk2 t2 (cost=0.29..72.63 rows=3333 width=244) (actual time=0.006..0.410 rows=5138.32 loops=100)
+ Index Cond: (unique2 < t1.unique2)
+ Buffers: shared hit=19285 read=29
Planning:
- Buffers: shared hit=15 dirtied=9
- Planning Time: 0.485 ms
- Execution Time: 0.073 ms
+ Buffers: shared hit=258 read=9 dirtied=2
+ Planning Time: 0.519 ms
+ Execution Time: 131.378 ms
</screen>
Note that the <quote>actual time</quote> values are in milliseconds of
@@ -756,8 +756,9 @@ WHERE t1.unique1 < 10 AND t1.unique2 = t2.unique2;
values shown are averages per-execution. This is done to make the numbers
comparable with the way that the cost estimates are shown. Multiply by
the <literal>loops</literal> value to get the total time actually spent in
- the node. In the above example, we spent a total of 0.030 milliseconds
- executing the index scans on <literal>tenk2</literal>.
+ the node, and to get the total rows processed in the node. In the above example,
+ we spent a total of 41 milliseconds executing the index scans,
+ and the node processed a total of 513832 rows on <literal>tenk2</literal>.
</para>
<para>
--
2.34.1
From a30ee71240d731c386f9dd4eb37b2817e3238807 Mon Sep 17 00:00:00 2001
From: Ilia Evdokimov <ilya.evdoki...@tantorlabs.ru>
Date: Thu, 13 Feb 2025 11:24:03 +0300
Subject: [PATCH v9] Clarify display of rows as decimal fractions
When loops > 1, the average rows value is now displayed as a decimal fraction
with two digits after the decimal point in EXPLAIN ANALYZE.
Previously, the average rows value was always rounded to an integer,
which could lead to misleading results when estimating total rows
by multiplying rows by loop. This change ensures that users
get a more accurate representation of the data flow through execution nodes.
---
src/backend/commands/explain.c | 55 +++++++++++++------
src/test/regress/expected/partition_prune.out | 18 +++---
src/test/regress/sql/partition_prune.sql | 2 +-
3 files changed, 49 insertions(+), 26 deletions(-)
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index c24e66f82e..ae81aeea13 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -13,6 +13,8 @@
*/
#include "postgres.h"
+#include <math.h>
+
#include "access/xact.h"
#include "catalog/pg_type.h"
#include "commands/createas.h"
@@ -69,6 +71,9 @@ typedef struct SerializeMetrics
*/
#define BYTES_TO_KILOBYTES(b) (((b) + 1023) / 1024)
+/* Check if float/double has any decimal number */
+#define HAS_DECIMAL(x) (floor(x) != x)
+
static void ExplainOneQuery(Query *query, int cursorOptions,
IntoClause *into, ExplainState *es,
ParseState *pstate, ParamListInfo params);
@@ -1981,14 +1986,15 @@ 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 && HAS_DECIMAL(rows))
+ appendStringInfo(es->str, "rows=%.2f loops=%.0f)", 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 +2005,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 && HAS_DECIMAL(rows))
+ {
+ ExplainPropertyFloat("Actual Rows", NULL, rows, 2, es);
+ ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+ }
+ else
+ {
+ ExplainPropertyFloat("Actual Rows", NULL, rows, 0, es);
+ ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, es);
+ }
}
}
else if (es->analyze)
@@ -2052,14 +2066,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 && HAS_DECIMAL(rows))
+ appendStringInfo(es->str, "rows=%.2f loops=%.0f\n", rows, nloops);
else
- appendStringInfo(es->str,
- "actual rows=%.0f loops=%.0f\n",
- rows, nloops);
+ appendStringInfo(es->str, "rows=%.0f loops=%.0f\n", rows, nloops);
}
else
{
@@ -2070,8 +2084,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 && HAS_DECIMAL(rows))
+ {
+ ExplainPropertyFloat("Actual Rows", NULL, rows, 2, es);
+ ExplainPropertyFloat("Actual Loops", NULL, nloops, 0, 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 e667503c96..fde44db1a0 100644
--- a/src/test/regress/expected/partition_prune.out
+++ b/src/test/regress/expected/partition_prune.out
@@ -2367,7 +2367,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+', 'actual rows=N loops=N');
ln := regexp_replace(ln, 'Rows Removed by Filter: \d+', 'Rows Removed by Filter: N');
return next ln;
end loop;
@@ -3049,14 +3049,14 @@ order by tbl1.col1, tprt.col1;
insert into tbl1 values (1001), (1010), (1011);
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=23 loops=1)
-> Seq Scan on tbl1 (actual rows=5 loops=1)
- -> Append (actual rows=5 loops=5)
+ -> Append (actual rows=4.60 loops=5)
-> Index Scan using tprt1_idx on tprt_1 (actual rows=2 loops=5)
Index Cond: (col1 < tbl1.col1)
- -> Index Scan using tprt2_idx on tprt_2 (actual rows=3 loops=4)
+ -> Index Scan using tprt2_idx on tprt_2 (actual rows=2.75 loops=4)
Index Cond: (col1 < tbl1.col1)
-> Index Scan using tprt3_idx on tprt_3 (actual rows=1 loops=2)
Index Cond: (col1 < tbl1.col1)
@@ -3070,16 +3070,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)
-> 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)
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 730545e86a..58756e0b18 100644
--- a/src/test/regress/sql/partition_prune.sql
+++ b/src/test/regress/sql/partition_prune.sql
@@ -586,7 +586,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+', '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
