Jeu de tests pour les évolutions autour de la commande `EXPLAIN` : ```sqlpostgresql DROP TABLE IF EXISTS t1,t2; CREATE TABLE t1 (c1 integer); INSERT INTO t1 SELECT generate_series(1, 1000); CREATE TABLE t2 (c1 integer); INSERT INTO t2 SELECT random(1,g) FROM generate_series(1, 1000) g; CREATE INDEX ON t2 (c1); VACUUM ANALYZE; ``` **Affichage amélioré des nœuds désactivés** : Lors de la désactivation d'un nœud avec l'un des paramètres `enable_*`,les coûts ne sont plus augmentés arbitrairement de 10 milliards comme auparavant. Cependant, si le nœud désactivé reste la seule solution possible, le nœud apparaît dans le plan avec une ligne `Disabled`. Par exemple : ``` SET enable_seqscan TO off; EXPLAIN SELECT * FROM t1; QUERY PLAN ------------------------------------------------------------ Seq Scan on t1 (cost=0.00..30467.92 rows=2112192 width=4) Disabled: true (2 rows) ``` **Option BUFFERS** : Les informations sur les blocs lus ou écrits sont maintenant affichées par défaut avec `EXPLAIN (ANALYZE)` : ```sqlpostgresql EXPLAIN (ANALYZE, COSTS OFF, TIMING OFF) SELECT * FROM t1; ``` En voici le résultat : ``` QUERY PLAN ---------------------------------------------- Seq Scan on t1 (actual rows=1000.00 loops=1) Buffers: shared hit=5 Planning Time: 0.046 ms Execution Time: 0.162 ms (4 rows) ``` L'effet de cache sera donc beaucoup plus évident lors de la comparaisons de plans à priori identiques mais de durées différentes. Il est toujours possible de désactiver l'option `BUFFERS` grâce à la valeur `OFF` : ```sqlpostgresql EXPLAIN (ANALYZE, COSTS OFF, TIMING OFF, BUFFERS OFF) SELECT * FROM t1; ``` **Option WAL** : Cette option existe depuis la version 13. En version 18, une information supplémentaire est disponible : le nombre de fois où le cache disque des journaux de transactions était rempli (et qu'il a donc fallu le vider sur disque). Par exemple : ```sqlpostgresql EXPLAIN (ANALYZE, COSTS OFF, TIMING OFF, WAL) INSERT INTO t1 SELECT generate_series(1, 1000000); ``` En voici le résultat : ``` QUERY PLAN --------------------------------------------------------------- Insert on t1 (actual rows=0.00 loops=1) Buffers: shared hit=1008860 dirtied=4430 written=4426 WAL: records=1000003 fpi=4 bytes=59028234 buffers full=7007 -> ProjectSet (actual rows=1000000.00 loops=1) -> Result (actual rows=1.00 loops=1) Planning Time: 0.123 ms Execution Time: 1150.033 ms (7 rows) ``` La ligne `WAL` indique 1 million d'enregistrements, 4 _full page writes_, environ 56 Mio de journaux, et 7007 événements _buffer full_. Le nombre de ces derniers est lié au paramètre `wal_buffers` et peut permettre de détecter qu'il est trop petit, ce qui peut ralentir les écritures lourdes. **Ajout du nombre de recherches dans l'index** : Il était difficile auparavant de savoir si l'index était parcouru une seule fois ou plusieurs fois. À partir de la version 18, la ligne `Index Searches` indique le nombre de parcours dans l'index. Par exemple : ``` SET jit TO off ; SET enable_hashjoin TO off; EXPLAIN (ANALYZE) SELECT * FROM t1 JOIN t2 ON t1.c1 Seq Scan on t1 (cost=0.00..13290.00 rows=886000 width=4) (actual time=0.018..34.857 rows=1001000.00 loops=1) Buffers: shared hit=4430 -> Index Only Scan using t2_c1_idx on t2 (cost=0.28..6.10 rows=333 width=4) (actual time=0.000..0.000 rows=0.51 loops=1001000) Index Cond: (c1 > t1.c1) Heap Fetches: 0 Index Searches: 1001000 Buffers: shared hit=2003937 Planning Time: 0.185 ms Execution Time: 532.369 ms ``` Il devient donc beaucoup plus visible que PostgreSQL a fait plus d'un million d'accès à l'index, et non un seul. La mention `loops=1001000` était déjà visible dans les versions précédentes pour pointer ce phénomène. À l'inverse, ce plan n'utilise que deux appels d'index pour récupérer 5 lignes d'une part, et 48 d'autre part : ``` RESET ALL ; EXPLAIN (ANALYZE,BUFFERS OFF, COSTS OFF,SETTINGS) SELECT * FROM t2 WHERE c1 > 900 OR c1 <10 ; ``` ```text QUERY PLAN -------------------------------------------------------------------------------- Bitmap Heap Scan on t2 (actual time=0.032..0.045 rows=53.00 loops=1) Recheck Cond: ((c1 > 900) OR (c1 < 10)) Heap Blocks: exact=5 -> BitmapOr (actual time=0.012..0.013 rows=0.00 loops=1) -> Bitmap Index Scan on t2_c1_idx (actual time=0.005..0.005 rows=5.00 loops=1) Index Cond: (c1 > 900) Index Searches: 1 -> Bitmap Index Scan on t2_c1_idx (actual time=0.006..0.006 rows=48.00 loops=1) Index Cond: (c1 < 10) Index Searches: 1 Planning Time: 0.258 ms Execution Time: 0.075 ms ``` **Affichage du nombre de lignes** : L'affichage du nombre de lignes a un peu changé. Il n'est plus affiché sous la forme d'un entier, mais sous la forme d'un nombre décimal. Ceci a pour but d'éviter d'arrondir à 0 quand il y a quelques lignes renvoyées et que le nombre de boucles est supérieur au nombre de lignes renvoyées. Dans un exemple avec la jointure ci-dessus, on voit : ```text Index Only Scan using t2_c1_idx on t2 (cost=0.28..6.10 rows=333 width=4) (actual time=0.000..0.000 rows=0.51 loops=1001000) ``` Ce parcours d'index a été réalisé 1 million de fois et n'a pas souvent ramené une ligne (total final à 333 seulement). Avant la version 18, nous aurions vu 0 ligne par passage (`rows=0`), donc 0 ligne après les deux millions de passages. Là, nous comprenons que 0,51 × 1001000 lignes sont récupérées (donc environ 0,5 million), ce qui correspond bien au nombre de lignes indiqué au niveau du nœud `Nested Loop`. **Ajout des informations d'utilisation mémoire et disque** Sur les nœuds `CTE Scan`, `Materialize` et `Window Aggregate`, la quantité de mémoire ou d'espace disque est affichée. Par exemple : ``` EXPLAIN (ANALYZE) SET enable_hashjoin TO 'off' ; SET max_parallel_workers_per_gather TO '0' ; SET jit TO 'off'; SET work_mem TO '4MB'; WITH cte1 AS MATERIALIZED (SELECT * FROM t1 WHERE c1 >0) SELECT * FROM cte1 INNER JOIN t2 ON cte1.c1=t2.c1; ``` ```text QUERY PLAN -------------------------------------------------------------------------------- Merge Join (cost=150403.89..150454.92 rows=1007 width=8) (actual time=195.970..196.545 rows=2000.00 loops=1) Merge Cond: (t2.c1 = cte1.c1) Buffers: shared hit=4435, temp read=510 written=3187 CTE cte1 -> Seq Scan on t1 (cost=0.00..16942.50 rows=1000900 width=4) (actual time=0.017..47.152 rows=1001000.00 loops=1) Filter: (c1 > 0) Buffers: shared hit=4430 -> Index Only Scan using t2_c1_idx on t2 (cost=0.28..35.27 rows=1000 width=4) (actual time=0.021..0.074 rows=1000.00 loops=1) Heap Fetches: 0 Index Searches: 1 Buffers: shared hit=5 -> Materialize (cost=133457.03..138461.53 rows=1000900 width=4) (actual time=195.943..196.224 rows=2895.00 loops=1) Storage: Memory Maximum Storage: 17kB Buffers: shared hit=4430, temp read=510 written=3187 -> Sort (cost=133457.03..135959.28 rows=1000900 width=4) (actual time=195.939..196.032 rows=1901.00 loops=1) Sort Key: cte1.c1 Sort Method: external merge Disk: 11776kB Buffers: shared hit=4430, temp read=510 written=3187 -> CTE Scan on cte1 (cost=0.00..20018.00 rows=1000900 width=4) (actual time=0.020..139.627 rows=1001000.00 loops=1) Storage: Disk Maximum Storage: 13680kB Buffers: shared hit=4430, temp written=1710 Planning: Buffers: shared hit=3 Planning Time: 0.276 ms Execution Time: 198.743 ms ``` Ce plan montre deux clauses `Storage` : la première, tout en bas, indique que la CTE matérialisée a pris environ 13 Mo sur le disque ; la deuxième, au milieu, indique que le résultat du nœud `Sort` a été matérialisé en mémoire, dans seulement 17 ko.