Prise en compte d'un index par le planificateur

pitpoule · 22/08/2019 09:26:22

Bonjour,

La question peut paraître étrange mais à quel moment la création d'un index est prise en compte par le planificateur ? J'ai constaté ce phénomène plusieurs fois sur notre BDD de prod (v 9.6) . Je créé un index, le planificateur (en tout cas l'explain analyze) continue à faire des seq scan.. j'ai tenté de passer un vacuum analyze, le plan ne change pas.
Au final, j'ai lancé un vacuum full sur la table et là , l'index est utilisé. Et cet index est vraiment utile, on gagne un facteur 100 sur le temps d'exécution.

Merci

gleu · 22/08/2019 23:18:15

Il est pris en compte immédiatement. Sans plan d'exécution, il sera impossible de dire quoi que ce soit de plus.

pitpoule · 23/08/2019 09:15:06

La requête est vraiment basique

Au départ, je créé l'index, le plan ne change pas

toto=> EXPLAIN ANALYZE SELECT col1, col_id
FROM la_table WHERE col_id IN (13);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
Gather (cost=1000.00..6956.66 rows=1 width=16) (actual time=77.157..91.363 rows=0 loops=1)
Workers Planned: 3
Workers Launched: 3
-> Parallel Seq Scan on la_table (cost=0.00..5956.56 rows=1 width=16) (actual time=62.873..62.874 rows=0 loops=4)
Filter: (col_id = 13)
Rows Removed by Filter: 250006
Planning time: 0.063 ms
Execution time: 91.389 ms
(8 rows)

Je lance le vacuum full et là, il est pris en compte

toto=> vacuum FULL ANALYZE verbose la_table;
INFO: vacuuming "la_table"
INFO: "la_table": found 0 removable, 1001757 nonremovable row versions in 19242 pages
DETAIL: 1729 dead row versions cannot be removed yet.
CPU 0.14s/0.59u sec elapsed 1.13 sec.
INFO: analyzing "la_table"
INFO: "la_table": scanned 12584 of 12584 pages, containing 1000028 live rows and 1729 dead rows; 30000 rows in sample, 1000028 estimated total rows
VACUUM

toto=> EXPLAIN ANALYZE SELECT col1, col_id
FROM la_table WHERE col_id IN (13);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------
Index Scan using la_table_col_id_idx on la_table (cost=0.42..0.64 rows=1 width=16) (actual time=0.080..0.080 rows=0 loops=1)
Index Cond: (col_id = 13)
Planning time: 0.160 ms
Execution time: 0.098 ms
(4 rows)

Est ce qu'il y a un cache des plans ?

dverite · 23/08/2019 13:32:27

Lors de la première requête, le planificateur n'a visiblement pas de statistiques sur le contenu de la table, c'est pourquoi il choisit un Seq Scan.
Le processus autovacuum met à jour en tâche de fond les statistiques, mais s'il n'a pas eu le temps de passer et que la table est requêtée immédiatement après avoir été chargée, ça donne ce genre de plan.

Dans ce cas de figure, il faut faire un ANALYZE table après le chargement. Un VACUUM FULL ANALYZE calcule aussi ces stats mais il réécrit aussi toute la table, ce qui est beaucoup plus coûteux et inutile si on veut juste les stats.

pitpoule · 23/08/2019 14:16:07

J'avais déjà lancé un analyze avant, même un vacuum analyze, sans succès

Daniel, à quoi voyez vous que le planificateur n'avait pas de statistique ?

Merci

gleu · 23/08/2019 16:36:27

Il n'y aurait pas de statistiques sur la table, on aurait une valeur de lignes estimées bien plus importantes. Le comportement de non utilisation de l'index est-il reproductible ? autrement dit, si vous supprimez l'index, il fera un seqscan. Si vous créez ensuite l'index sans vacuum, utilise-t-il toujours un seqscan ? si oui, pouvez-vous désactiver la parallélisation dans un premier temps (set max_parallel_workers_per_gather to 0) ? et si ça ne suffit pas à avoir un parcours d'index, pouvez-vous désactiver les seqscan ? (set enable_seqscan to off)

Merci de fournir le "EXPLAIN (ANALYZE,BUFFERS)" pour chaque test.

pitpoule · 23/08/2019 17:04:23

ok, je ferai le test

J'ai déjà constaté ce problème de non prise en compte immédiate d'un index pour d'autres tables. Au final, en attendant un peu, le plan de la requête change et l'index est bien utilisé.... mais ce n'est pas immédiat et ça, je ne comprends pas pourquoi.
Je me suis demandé si le problème ne venait pas du paramétrage des coûts du planificateur dans le postgresql.conf, ils sont assez spécifiques sur notre base, notamment:

seq_page_cost = 0.1 # measured on an arbitrary scale
random_page_cost = 0.1 # same scale as above

gleu · 23/08/2019 17:11:12

Ce paramétrage aurait plutôt tendance à imposer des parcours d'index alors que des parcours de tables seraient plus intéressants. Donc a priori, ça ne serait pas la raison du problème :-)

pitpoule · 23/08/2019 17:18:02

ok

pitpoule · 26/08/2019 09:15:17

Voici le résultat des différents tests

Sans l'index

toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (8438);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
Gather (cost=1000.00..6200.20 rows=1 width=74) (actual time=0.253..419.457 rows=1 loops=1)
Workers Planned: 3
Workers Launched: 0
Buffers: shared hit=12875
-> Parallel Seq Scan on ma_table (cost=0.00..5200.10 rows=1 width=74) (actual time=0.010..419.084 rows=1 loops=1)
Filter: (col_id = 8438)
Rows Removed by Filter: 1009620
Buffers: shared hit=12875
Planning time: 0.045 ms
Execution time: 419.475 ms
(10 rows)

Je crée l'index, pas de prise en compte

toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (8438);
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------
Gather (cost=1000.00..6358.91 rows=1 width=74) (actual time=0.335..167.624 rows=1 loops=1)
Workers Planned: 3
Workers Launched: 3
Buffers: shared hit=12944
-> Parallel Seq Scan on ma_table (cost=0.00..5358.81 rows=1 width=74) (actual time=70.830..107.629 rows=0 loops=4)
Filter: (col_id = 8438)
Rows Removed by Filter: 252406
Buffers: shared hit=12944
Planning time: 0.138 ms
Execution time: 167.644 ms

Je lance un analyze sur la table, idem

toto=> analyze verbose ma_table;
INFO: analyzing "ma_table"
INFO: "ma_table": scanned 12875 of 12875 pages, containing 1009623 live rows and 2125 dead rows; 30000 rows in sample, 1009623 estimated total rows
ANALYZE
toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (8438);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
Gather (cost=1000.00..6358.66 rows=1 width=74) (actual time=0.229..99.608 rows=1 loops=1)
Workers Planned: 3
Workers Launched: 3
Buffers: shared hit=12944
-> Parallel Seq Scan on ma_table (cost=0.00..5358.56 rows=1 width=74) (actual time=42.118..63.982 rows=0 loops=4)
Filter: (col_id = 8438)
Rows Removed by Filter: 252406
Buffers: shared hit=12944
Planning time: 0.173 ms
Execution time: 99.628 ms
(10 rows)

Je lance un vacuum analyze sur la table, pas mieux

toto=> vacuum analyze ma_table;
VACUUM
toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (8438);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
Gather (cost=1000.00..6358.66 rows=1 width=74) (actual time=0.228..80.305 rows=1 loops=1)
Workers Planned: 3
Workers Launched: 3
Buffers: shared hit=12944
-> Parallel Seq Scan on ma_table (cost=0.00..5358.56 rows=1 width=74) (actual time=37.382..55.064 rows=0 loops=4)
Filter: (col_id = 8438)
Rows Removed by Filter: 252405
Buffers: shared hit=12944
Planning time: 0.133 ms
Execution time: 80.325 ms
(10 rows)

vacuum full et là l'index est pris en compte

toto=> vacuum full analyze verbose ma_table;
INFO: vacuuming "ma_table"
INFO: "ma_table": found 0 removable, 1009808 nonremovable row versions in 12875 pages
DETAIL: 186 dead row versions cannot be removed yet.
CPU 0.14s/1.02u sec elapsed 1.91 sec.
INFO: analyzing "ma_table"
INFO: "ma_table": scanned 12686 of 12686 pages, containing 1009622 live rows and 186 dead rows; 30000 rows in sample, 1009622 estimated total rows
VACUUM
toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (8438);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------
Index Scan using ma_table_col_id_idx on ma_table (cost=0.42..0.64 rows=1 width=74) (actual time=0.045..0.045 rows=1 loops=1)
Index Cond: (col_id = 8438)
Buffers: shared hit=5 read=2
Planning time: 0.182 ms
Execution time: 0.062 ms
(5 rows)

gleu · 26/08/2019 13:38:41

Manque les tests demandés, à savoir désactivation de la parallélisation, puis désactivation des parcours séquentiels.

Avec juste ce que vous indiquez là, la seule raison que je vois est que l'index est créé invalide, et que le VACUUM FULL le recrée en valide. Le seul moyen de créer un index invalide est de faire un CREATE INDEX CONCURRENTLY. Est-ce que vous faites ?

dverite · 26/08/2019 15:13:20

Daniel, à quoi voyez vous que le planificateur n'avait pas de statistique ?

Il n'y a pas de preuve formelle de ça dans l'explain analyze, mais pas non plus de preuve du contraire. Mais c'est une des raisons principales de non-prise en compte d'un index (avec les tables trop petites) parce que c'est un scénario typique: création de table vide, chargement, select.

Sinon, une autre piste: ces CREATE INDEX seraient faits dans une session non committée.

Il se trouve que dans ce qu'on voit ci-dessus, les CREATE INDEX ne sont pas montrés contrairement aux autres commandes. Pour quelle raison? Si vous les faites dans une autre session, avec un autre outil, ça pourrait avoir un rapport avec le problème.

pitpoule · 27/08/2019 09:02:13

Désolé gleu, voici les tests manquants

EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (305683);

toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (305683);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
Gather (cost=1000.00..6313.63 rows=1 width=74) (actual time=0.488..274.712 rows=1 loops=1)
Workers Planned: 3
Workers Launched: 0
Buffers: shared hit=13040
-> Parallel Seq Scan on ma_table (cost=0.00..5313.53 rows=1 width=74) (actual time=0.319..274.474 rows=1 loops=1)
Filter: (col_id = 305683)
Rows Removed by Filter: 1012963
Buffers: shared hit=13040
Planning time: 0.030 ms
Execution time: 274.724 ms
(10 rows)

toto=> create index on ma_table(col_id);
CREATE INDEX
toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (305683);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
Gather (cost=1000.00..6391.82 rows=1 width=74) (actual time=0.626..113.348 rows=1 loops=1)
Workers Planned: 3
Workers Launched: 3
Buffers: shared hit=13109
-> Parallel Seq Scan on ma_table (cost=0.00..5391.72 rows=1 width=74) (actual time=45.652..70.369 rows=0 loops=4)
Filter: (col_id = 305683)
Rows Removed by Filter: 253241
Buffers: shared hit=13109
Planning time: 0.295 ms
Execution time: 113.373 ms
(10 rows)

toto=> set max_parallel_workers_per_gather to 0;
SET
toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (305683);
QUERY PLAN
---------------------------------------------------------------------------------------------------------------
Seq Scan on ma_table (cost=0.00..13975.94 rows=1 width=74) (actual time=0.355..248.830 rows=1 loops=1)
Filter: (col_id = 305683)
Rows Removed by Filter: 1012966
Buffers: shared hit=13040
Planning time: 0.036 ms
Execution time: 248.845 ms
(6 rows)

toto=> set enable_seqscan to off;
SET
toto=> EXPLAIN (ANALYZE,BUFFERS) SELECT col1 FROM ma_table WHERE col_id IN (305683);
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
Seq Scan on ma_table (cost=10000000000.00..10000013975.94 rows=1 width=74) (actual time=0.391..265.597 rows=1 loops=1)
Filter: (col_id = 305683)
Rows Removed by Filter: 1012967
Buffers: shared hit=13040
Planning time: 0.044 ms
Execution time: 265.616 ms
(6 rows)

pitpoule · 27/08/2019 09:03:15

dverite a écrit :

Il n'y a pas de preuve formelle de ça dans l'explain analyze, mais pas non plus de preuve du contraire. Mais c'est une des raisons principales de non-prise en compte d'un index (avec les tables trop petites) parce que c'est un scénario typique: création de table vide, chargement, select.

Sinon, une autre piste: ces CREATE INDEX seraient faits dans une session non committée.
Il se trouve que dans ce qu'on voit ci-dessus, les CREATE INDEX ne sont pas montrés contrairement aux autres commandes. Pour quelle raison? Si vous les faites dans une autre session, avec un autre outil, ça pourrait avoir un rapport avec le problème.

L'index est bien "commité" et valide

gleu · 27/08/2019 09:55:50

Quelque chose l'empêche de l'utiliser vu que, même en désactivant les parcours séquentiels, il préfère toujours un parcours séquentiel. Que donne un "\d ma_table" après création de l'index ?

Si vous sauvegardez la table, et que vous la restaurez sur un autre serveur, le problème est reproductible ? si oui, est-il possible d'avoir ce fichier de sauvegarde pour tenter de reproduire le problème ?

pitpoule · 27/08/2019 10:25:26

gleu a écrit :

Quelque chose l'empêche de l'utiliser vu que, même en désactivant les parcours séquentiels, il préfère toujours un parcours séquentiel. Que donne un "\d ma_table" après création de l'index ?
Si vous sauvegardez la table, et que vous la restaurez sur un autre serveur, le problème est reproductible ? si oui, est-il possible d'avoir ce fichier de sauvegarde pour tenter de reproduire le problème ?

le \d ne donne rien de particulier, l'index est valide

Le truc, c'est que ce n'est pas la première fois que je rencontre ce problème...d'où mon post. Le planificateur finit toujours par utiliser l'index mais pas immédiatement. Sur les autres environnements (dev,recette, préprod), je n'ai jamais eu ce souci. Ce n'est pas lié à la table en particulier, c'est global à l'instance de mon point de vue.

Pour vous fournir un fichier de sauvegarde, c'est compliqué, ce sont des données de paiements.

gleu · 27/08/2019 10:53:36

Difficile de vous dire autre chose dans ce cas. PostgreSQL n'a besoin de rien (normalement) pour utiliser un index, comme le montre d'ailleurs, si je comprend bien, le fonctionnement des autres plateformes. Il doit y avoir une différence entre cette plateforme et les autres pour qu'elle se comporte autrement. Difficile de savoir quoi si on ne peut pas reproduire le problème ou si on n'a pas les mains sur le serveur.

pitpoule · 27/08/2019 11:24:30

gleu a écrit :

Difficile de vous dire autre chose dans ce cas. PostgreSQL n'a besoin de rien (normalement) pour utiliser un index, comme le montre d'ailleurs, si je comprend bien, le fonctionnement des autres plateformes. Il doit y avoir une différence entre cette plateforme et les autres pour qu'elle se comporte autrement. Difficile de savoir quoi si on ne peut pas reproduire le problème ou si on n'a pas les mains sur le serveur.

Je me doute que c'est difficile de trouver au travers de posts d'un forum

Sinon à votre connaissance, est ce que ce comportement pourrait être expliqué par: une très forte activité sur la table ? un paramétrage du moteur particulier ? une corruption d'une table système quelconque ? un paramétrage particulier de l'OS ?

gleu · 27/08/2019 11:48:37

Je n'explique pas ce comportement. Du coup, tout est possible

#1 22/08/2019 09:26:22

Prise en compte d'un index par le planificateur

#2 22/08/2019 23:18:15

Re : Prise en compte d'un index par le planificateur

#3 23/08/2019 09:15:06

Re : Prise en compte d'un index par le planificateur

#4 23/08/2019 13:32:27

Re : Prise en compte d'un index par le planificateur

#5 23/08/2019 14:16:07

Re : Prise en compte d'un index par le planificateur

#6 23/08/2019 16:36:27

Re : Prise en compte d'un index par le planificateur

#7 23/08/2019 17:04:23

Re : Prise en compte d'un index par le planificateur

#8 23/08/2019 17:11:12

Re : Prise en compte d'un index par le planificateur

#9 23/08/2019 17:18:02

Re : Prise en compte d'un index par le planificateur

#10 26/08/2019 09:15:17

Re : Prise en compte d'un index par le planificateur

#11 26/08/2019 13:38:41

Re : Prise en compte d'un index par le planificateur

#12 26/08/2019 15:13:20

Re : Prise en compte d'un index par le planificateur

#13 27/08/2019 09:02:13

Re : Prise en compte d'un index par le planificateur

#14 27/08/2019 09:03:15

Re : Prise en compte d'un index par le planificateur

#15 27/08/2019 09:55:50

Re : Prise en compte d'un index par le planificateur

#16 27/08/2019 10:25:26

Re : Prise en compte d'un index par le planificateur

#17 27/08/2019 10:53:36

Re : Prise en compte d'un index par le planificateur

#18 27/08/2019 11:24:30

Re : Prise en compte d'un index par le planificateur

#19 27/08/2019 11:48:37

Re : Prise en compte d'un index par le planificateur

Pied de page des forums

À propos

Nous contacter

Groupes Locaux

Réseaux Sociaux