From 317b9988e4243e354e6330bbebb6a554bb802d4e Mon Sep 17 00:00:00 2001 From: Peter Geoghegan Date: Wed, 24 Jun 2026 13:25:40 -0400 Subject: [PATCH v29 09/12] Add EXPLAIN (IO) support for plain index scans. Extends the EXPLAIN (IO) instrumentation added for ReadStream-backed scans (bitmap scans in 681daed9, then sequential scans in 3b1117d6) to the heap page prefetching now performed during index scans (and Index-only scans). Their Prefetch and I/O lines describe read-ahead of table (heap) blocks only: the blocks the scan prefetches as it follows index entries back to the table. Index pages are never prefetched this way, and so are neither relevant to nor counted in these numbers. For an index-only scan the only heap blocks prefetched are the occasional pages that are not yet all-visible (the same ones counted by "Heap Fetches"), so a scan that never falls back to the table shows no such lines at all. Unlike the other scan nodes that display this kind of instrumentation, the SO_SCAN_INSTRUMENT table AM scan flag isn't passed down to the scan. SeqScan, BitmapHeapScan and TidRangeScan set that flag (and only under INSTRUMENT_IO), so that the table AM allocates the IOStats and enables ReadStream statistics in beginscan only when it is present. An index scan is rescanned far more often than those nodes, so we avoid passing down the flag. Instead we reuse the IndexScanInstrumentation struct that the executor already allocates for every index scan during EXPLAIN ANALYZE. We always capture I/O instrumentation when running under EXPLAIN ANALYZE -- though we only show it to the user when they asked for it. Author: Tomas Vondra Author: Peter Geoghegan --- src/include/executor/instrument_node.h | 3 + src/backend/access/heap/heapam_indexscan.c | 4 + src/backend/commands/explain.c | 62 ++++++++++++++ src/backend/executor/nodeIndexonlyscan.c | 3 + src/backend/executor/nodeIndexscan.c | 3 + doc/src/sgml/perform.sgml | 96 ++++++++++++++++++++++ doc/src/sgml/ref/explain.sgml | 2 + 7 files changed, 173 insertions(+) diff --git a/src/include/executor/instrument_node.h b/src/include/executor/instrument_node.h index 41a7d33f1..bfb2cbc3d 100644 --- a/src/include/executor/instrument_node.h +++ b/src/include/executor/instrument_node.h @@ -108,6 +108,9 @@ typedef struct IndexScanInstrumentation /* Table tuples fetched count (incremented during index-only scans) */ uint64 ntabletuplefetches; + + /* Table AM index scan I/O prefetching instrumentation */ + IOStats io; } IndexScanInstrumentation; /* diff --git a/src/backend/access/heap/heapam_indexscan.c b/src/backend/access/heap/heapam_indexscan.c index c16a29066..58a9655fa 100644 --- a/src/backend/access/heap/heapam_indexscan.c +++ b/src/backend/access/heap/heapam_indexscan.c @@ -1386,6 +1386,10 @@ heapam_index_start_prefetching(IndexScanDesc scan, IndexScanHeapData *hscan) read_stream_begin_relation(READ_STREAM_DEFAULT, NULL, scan->heapRelation, MAIN_FORKNUM, heapam_index_prefetch_next_block, scan, 0); + + if (scan->instrument) + read_stream_enable_stats(hscan->xs_read_stream, + &scan->instrument->io); } /* diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 41c928456..e605a89de 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -1979,6 +1979,7 @@ ExplainNode(PlanState *planstate, List *ancestors, show_instrumentation_count("Rows Removed by Filter", 1, planstate, es); show_indexscan_info(planstate, es); + show_scan_io_usage((ScanState *) planstate, es); break; case T_IndexOnlyScan: show_scan_qual(((IndexOnlyScan *) plan)->indexqual, @@ -1993,6 +1994,7 @@ ExplainNode(PlanState *planstate, List *ancestors, show_instrumentation_count("Rows Removed by Filter", 1, planstate, es); show_indexscan_info(planstate, es); + show_scan_io_usage((ScanState *) planstate, es); break; case T_BitmapIndexScan: show_scan_qual(((BitmapIndexScan *) plan)->indexqualorig, @@ -4079,6 +4081,18 @@ show_scan_io_usage(ScanState *planstate, ExplainState *es) { stats = planstate->ss_currentScanDesc->rs_instrument->io; } + else if (IsA(planstate, IndexScanState)) + { + IndexScanState *indexstate = ((IndexScanState *) planstate); + + stats = indexstate->iss_Instrument->io; + } + else if (IsA(planstate, IndexOnlyScanState)) + { + IndexOnlyScanState *indexstate = ((IndexOnlyScanState *) planstate); + + stats = indexstate->ioss_Instrument->io; + } /* * Accumulate data from parallel workers (if any). @@ -4155,6 +4169,54 @@ show_scan_io_usage(ScanState *planstate, ExplainState *es) } } + break; + } + case T_IndexScan: + { + SharedIndexScanInstrumentation *sinstrument + = ((IndexScanState *) planstate)->iss_SharedInfo; + + if (sinstrument) + { + for (int i = 0; i < sinstrument->num_workers; ++i) + { + IndexScanInstrumentation *winstrument = &sinstrument->winstrument[i]; + + AccumulateIOStats(&stats, &winstrument->io); + + if (!es->workers_state) + continue; + + ExplainOpenWorker(i, es); + print_io_usage(es, &winstrument->io); + ExplainCloseWorker(i, es); + } + } + + break; + } + case T_IndexOnlyScan: + { + SharedIndexScanInstrumentation *sinstrument + = ((IndexOnlyScanState *) planstate)->ioss_SharedInfo; + + if (sinstrument) + { + for (int i = 0; i < sinstrument->num_workers; ++i) + { + IndexScanInstrumentation *winstrument = &sinstrument->winstrument[i]; + + AccumulateIOStats(&stats, &winstrument->io); + + if (!es->workers_state) + continue; + + ExplainOpenWorker(i, es); + print_io_usage(es, &winstrument->io); + ExplainCloseWorker(i, es); + } + } + break; } default: diff --git a/src/backend/executor/nodeIndexonlyscan.c b/src/backend/executor/nodeIndexonlyscan.c index 3c8877528..779417c84 100644 --- a/src/backend/executor/nodeIndexonlyscan.c +++ b/src/backend/executor/nodeIndexonlyscan.c @@ -254,6 +254,9 @@ ExecEndIndexOnlyScan(IndexOnlyScanState *node) */ winstrument->nsearches += node->ioss_Instrument->nsearches; winstrument->ntabletuplefetches += node->ioss_Instrument->ntabletuplefetches; + + /* Collect IO stats for this process into shared instrumentation */ + AccumulateIOStats(&winstrument->io, &node->ioss_Instrument->io); } /* diff --git a/src/backend/executor/nodeIndexscan.c b/src/backend/executor/nodeIndexscan.c index 1410b1ee7..c114040b2 100644 --- a/src/backend/executor/nodeIndexscan.c +++ b/src/backend/executor/nodeIndexscan.c @@ -821,6 +821,9 @@ ExecEndIndexScan(IndexScanState *node) */ winstrument->nsearches += node->iss_Instrument->nsearches; Assert(node->iss_Instrument->ntabletuplefetches == 0); + + /* Collect IO stats for this process into shared instrumentation */ + AccumulateIOStats(&winstrument->io, &node->iss_Instrument->io); } /* diff --git a/doc/src/sgml/perform.sgml b/doc/src/sgml/perform.sgml index 604e8578a..37807ce64 100644 --- a/doc/src/sgml/perform.sgml +++ b/doc/src/sgml/perform.sgml @@ -1047,6 +1047,102 @@ EXPLAIN (ANALYZE, BUFFERS OFF) SELECT * FROM tenk1 WHERE unique1 < 100 AND un + + EXPLAIN also has an IO option, which + reports statistics about the read-ahead, or prefetching, + of table data that takes place during execution. Many scan nodes — such as + Seq Scan, Bitmap Heap Scan, and + Index Scan — prefetch the blocks of a table ahead + of the point the scan has reached, so that the blocks needed next are + already on their way in from storage (or already present in shared + buffers) by the time the scan asks for them; see + . The IO + option exposes how effective this prefetching was. It can only be used + together with ANALYZE, since it reports on work done + while actually running the query, and unlike BUFFERS it + is not enabled by default. The tables in the regression test database are + too small for read-ahead to matter, so the example below instead uses a + table of one million rows (of roughly two hundred bytes each), indexed on + its id column and not in cache to begin with: + + +EXPLAIN (ANALYZE, IO, BUFFERS OFF) SELECT * FROM tbl WHERE id < 100000 AND id % 7 = 0; + + QUERY PLAN +---------------------------------------------------------------------&zwsp;---------------------------------------------------------- + Index Scan using tbl_id_idx on tbl (cost=0.42..6497.39 rows=516 width=208) (actual time=0.335..24.695 rows=14285.00 loops=1) + Index Cond: (id < 100000) + Filter: ((id % 7) = 0) + Rows Removed by Filter: 85714 + Index Searches: 1 + Prefetch: avg=82.24 max=92 capacity=94 + I/O: count=187 waits=139 size=15.72 in-progress=4.81 + Planning Time: 2.411 ms + Execution Time: 24.995 ms + + + + + The Prefetch line describes how far ahead of the scan the + read-ahead ran, measured in blocks: avg is the average + look-ahead distance maintained over the course of the scan, + max is the greatest distance reached, and + capacity is the maximum distance the scan was permitted to + use (which depends on and + , and is also capped by the number of + buffers the scan is allowed to keep pinned at once). + The I/O line describes the read I/O that the prefetching + performed: count is the number of read I/O operations issued + (a single operation can cover several consecutive blocks), + waits is the number of times the scan had to stop and wait + for an I/O to finish (because the needed block was not ready yet), + size is the average number of blocks read per I/O operation + (consecutive blocks are merged into a single larger I/O, up to + ), and in-progress + is the average number of I/O operations outstanding at once, a measure of the + I/O concurrency that was achieved. A small waits count + relative to count indicates that prefetching was + successful in hiding read latency behind useful work. A large one is not + necessarily a problem: a scan that does little work per row, as in the + example above, repeatedly catches up with its own read-ahead and briefly + waits for the oldest I/O to complete; keeping many I/Os in flight is still + far faster than issuing them one at a time. The + I/O line is shown only when the prefetching performed at + least one read I/O operation. A scan that never started any read-ahead in + the first place, as happens when an index scan finds every table block it + needs already in shared buffers, shows neither line. + + + + These statistics only ever describe I/O against the table itself (its heap), + never against indexes. In particular, for an Index Scan + the Prefetch and I/O lines report on the + table blocks that the scan prefetches as it follows index entries back to the + table; the index's own pages are not prefetched in this way, and so index page + hits and reads are neither relevant to nor counted in these numbers. (Index + page accesses are included under the BUFFERS option, though + there they are combined with table page accesses rather than reported + separately.) For the same reason a Bitmap Heap Scan reports + these statistics on the heap scan node itself, rather than on its child + Bitmap Index Scan node. + + + + An Index Only Scan can show these statistics too, which may + be unexpected: the whole point of an index-only scan is to answer the + query from the index alone, without reading the table at all (see + ). It can usually do so, but not + always. When a table page has been modified recently enough that it is not + yet marked all-visible in the table's visibility map, an index-only scan must + read that one page from the table anyway, in order to confirm that the rows it + references are visible to the current transaction. These occasional table + reads (the page reads behind the index-only scan's + Heap Fetches count) are prefetched as well, and they are the + only thing the Prefetch and I/O lines + describe for an index-only scan. An index-only scan that never has to fall + back to the table will not show these lines at all. + + Keep in mind that because EXPLAIN ANALYZE actually runs the query, any side-effects will happen as usual, even though diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml index f38d31e10..3c72b0839 100644 --- a/doc/src/sgml/ref/explain.sgml +++ b/doc/src/sgml/ref/explain.sgml @@ -313,6 +313,8 @@ ROLLBACK; In text format, only non-zero values are printed. This parameter may only be used when ANALYZE is also enabled. It defaults to FALSE. + describes the information + provided. -- 2.53.0