On 15.02.2025 11:46, Andrei Lepikhov wrote:
On 13/2/2025 21:42, Robert Haas wrote:
On Thu, Feb 13, 2025 at 4:05 AM Ilia Evdokimov
<ilya.evdoki...@tantorlabs.com> wrote:
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.
Anyone else have an opinion on this? I see Ilia's point, but a
non-equality join is probably an atypical case.
For me, it is ok: it demonstrates the feature and may legally happen.
But this patch should be the second one, isn't it?
I didn't want to introduce a new table instead of tenk1 and tenk2, as
the entire page already uses them. Moreover, if we use = in the join
condition, the number of rows will always be the same. So, I couldn't
find a better option than t1.unique > t2.unique.
Regarding the order of the patches, I made this one first because, as
Tom mentioned earlier, we need to finalize the documentation first.
However, in order to check tests in CirrusCI, it should be really the
second.
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.
This still has the HAS_DECIMAL() thing to which I objected.
I don't understand why using math.h and the floor() routine is
necessary. I personally prefer x%y!=0 expression.
You're right—floor shouldn't be used since it behaves differently across
platforms, as Tom also pointed out earlier. I like the idea of using %,
but since the compiler doesn't allow this operation with double, we need
to cast it to int64. I checked how nloops and ntuples are modified -
they are only incremented by 1. So that the casting might be safe. If I
missed anything or if there's a reason why this casting wouldn't be
safe, please let me know.
--
Best regards,
Ilia Evdokimov,
Tantor Labs LLC.
From c1494f8815b0e69479d19e74e10970a54c8e6de6 Mon Sep 17 00:00:00 2001
From: Ilia Evdokimov <ilya.evdoki...@tantorlabs.ru>
Date: Mon, 17 Feb 2025 11:02:33 +0300
Subject: [PATCH v10 2/2] 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 | 39 ++++++++++++++++++++-------------------
1 file changed, 20 insertions(+), 19 deletions(-)
diff --git a/doc/src/sgml/perform.sgml b/doc/src/sgml/perform.sgml
index a502a2aaba..588ee6d5aa 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;
+WHERE t1.thousand < 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)
+ 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 0ba7069534afcf54cd39fc4bc21aa44d5bf3e343 Mon Sep 17 00:00:00 2001
From: Ilia Evdokimov <ilya.evdoki...@tantorlabs.ru>
Date: Mon, 17 Feb 2025 10:59:50 +0300
Subject: [PATCH v10 1/2] 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 | 54 +++++++++++++------
src/test/regress/expected/partition_prune.out | 18 +++----
src/test/regress/sql/partition_prune.sql | 2 +-
3 files changed, 48 insertions(+), 26 deletions(-)
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index dc4bef9ab8..50b3b224c2 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -1978,17 +1978,20 @@ ExplainNode(PlanState *planstate, List *ancestors,
double startup_ms = 1000.0 * planstate->instrument->startup / nloops;
double total_ms = 1000.0 * planstate->instrument->total / nloops;
double rows = planstate->instrument->ntuples / nloops;
+ bool rows_is_fractonal = (int64)planstate->instrument->ntuples %
+ (int64)nloops;
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 && rows_is_fractonal)
+ 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 +2002,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 && rows_is_fractonal)
+ {
+ 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)
@@ -2040,26 +2051,28 @@ ExplainNode(PlanState *planstate, List *ancestors,
double startup_ms;
double total_ms;
double rows;
+ bool rows_is_fractonal;
if (nloops <= 0)
continue;
startup_ms = 1000.0 * instrument->startup / nloops;
total_ms = 1000.0 * instrument->total / nloops;
rows = instrument->ntuples / nloops;
+ rows_is_fractonal = (int64)instrument->ntuples % (int64)nloops;
ExplainOpenWorker(n, es);
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 && rows_is_fractonal)
+ 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 +2083,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 && rows_is_fractonal)
+ {
+ 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 6f80b62a3b..1e9ceee593 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 86621dcec0..6aad02156c 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
