PostgreSQL La base de donnees la plus sophistiquee au monde.

Forums PostgreSQL.fr

Le forum officiel de la communauté francophone de PostgreSQL

Vous n'êtes pas identifié(e).

#1 18/06/2009 18:01:55

F.Chanson
Membre

Besoin d'infos sur le resultat issu d'un explain

Bonjour , je suis nouveau sur le forum , mais j'aurais besoin d'une explication sur le resultat de cet explain qui est relatif à la requete sql suivante sur une base de données postgres 8.2.7  sous linux redhat 64 bits

le pb est le suivant  pourquoi les index sur les primary key (crées de base par postgres) ne sont pas utilisés lors des jointures sur les join  (la fin de la commande explain liste les seq scan )

Cette Requette rameme 
===============
select mdmetadata0_.id as col_0_0_ from   public.md_metadata mdmetadata0_
inner join public.mf_metadata mdmetadata0_1_ on mdmetadata0_.id=mdmetadata0_1_.id
left outer join public.content_info contentinf1_ on mdmetadata0_.id=contentinf1_.fk_metadata
left outer join public.mi_imagedesc contentinf1_1_ on contentinf1_.id=contentinf1_1_.id
left outer join public.mi_radarimagedesc contentinf1_2_ on contentinf1_.id=contentinf1_2_.id
left outer join public.mi_opticalimagedesc contentinf1_3_ on contentinf1_.id=contentinf1_3_.id
left outer join public.md_identification identifica2_ on mdmetadata0_.id=identifica2_.fk_md_metadata
left outer join public.md_dataidentification identifica2_1_ on identifica2_.id=identifica2_1_.id
left outer join public.catalog_id catalogid3_ on identifica2_1_.fk_catalog_id=catalogid3_.id
left outer join public.ex_temporalextent temporalex4_ on identifica2_.id=temporalex4_.fk_dataident
where contentinf1_1_.attribute_desc='DATASTRIP_SCENE' and catalogid3_.profile='LEVEL0' and (temporalex4_.begin_ between '2007-08-01' and '2007-08-30')
"
Durée totale d'exécution de la requête :2624 ms.
161 lignes récupérées.


explain analyse
==========
"Nested Loop  (cost=52157.93..85267.26 rows=1 width=22) (actual time=1872.823..4964.971 rows=161 loops=1)"
"  ->  Hash Join  (cost=52157.93..85266.60 rows=1 width=62) (actual time=1872.756..4961.346 rows=161 loops=1)"
"        Hash Cond: ((identifica2_.id)::text = (temporalex4_.fk_dataident)::text)"
"        ->  Hash Join  (cost=52141.56..84472.30 rows=207445 width=142) (actual time=1849.891..4842.327 rows=206718 loops=1)"
"              Hash Cond: ((mdmetadata0_1_.id)::text = (mdmetadata0_.id)::text)"
"              ->  Hash Left Join  (cost=42890.11..71257.93 rows=192868 width=186) (actual time=1547.823..4117.267 rows=206718 loops=1)"
"                    Hash Cond: ((contentinf1_.id)::text = (contentinf1_2_.id)::text)"
"                    ->  Hash Left Join  (cost=42877.41..70520.95 rows=192868 width=226) (actual time=1547.796..3901.386 rows=206718 loops=1)"
"                          Hash Cond: ((contentinf1_.id)::text = (contentinf1_3_.id)::text)"
"                          ->  Hash Join  (cost=35243.96..58789.05 rows=192868 width=226) (actual time=1254.870..3189.344 rows=206718 loops=1)"
"                                Hash Cond: ((identifica2_.id)::text = (identifica2_1_.id)::text)"
"                                ->  Hash Join  (cost=25911.51..45358.16 rows=192868 width=146) (actual time=922.453..2421.758 rows=206718 loops=1)"
"                                      Hash Cond: ((contentinf1_.id)::text = (contentinf1_1_.id)::text)"
"                                      ->  Hash Join  (cost=15000.19..30439.11 rows=207906 width=146) (actual time=603.148..1667.861 rows=223620 loops=1)"
"                                            Hash Cond: ((mdmetadata0_1_.id)::text = (contentinf1_.fk_metadata)::text)"
"                                            ->  Hash Join  (cost=7337.74..18181.87 rows=223620 width=84) (actual time=299.561..909.856 rows=223620 loops=1)"
"                                                  Hash Cond: ((identifica2_.fk_md_metadata)::text = (mdmetadata0_1_.id)::text)"
"                                                  ->  Seq Scan on md_identification identifica2_  (cost=0.00..6092.20 rows=223620 width=62) (actual time=0.024..135.173 rows=223620 loops=1)"
"                                                  ->  Hash  (cost=4331.22..4331.22 rows=240522 width=22) (actual time=299.419..299.419 rows=240522 loops=1)"
"                                                        ->  Seq Scan on mf_metadata mdmetadata0_1_  (cost=0.00..4331.22 rows=240522 width=22) (actual time=0.017..141.733 rows=240522 loops=1)"
"                                            ->  Hash  (cost=4867.20..4867.20 rows=223620 width=62) (actual time=303.476..303.476 rows=223620 loops=1)"
"                                                  ->  Seq Scan on content_info contentinf1_  (cost=0.00..4867.20 rows=223620 width=62) (actual time=0.030..140.080 rows=223620 loops=1)"
"                                      ->  Hash  (cost=8318.25..8318.25 rows=207445 width=40) (actual time=319.188..319.188 rows=206718 loops=1)"
"                                            ->  Seq Scan on mi_imagedesc contentinf1_1_  (cost=0.00..8318.25 rows=207445 width=40) (actual time=0.035..176.583 rows=206718 loops=1)"
"                                                  Filter: ((attribute_desc)::text = 'DATASTRIP_SCENE'::text)"
"                                ->  Hash  (cost=6537.20..6537.20 rows=223620 width=80) (actual time=332.364..332.364 rows=223620 loops=1)"
"                                      ->  Seq Scan on md_dataidentification identifica2_1_  (cost=0.00..6537.20 rows=223620 width=80) (actual time=0.031..158.848 rows=223620 loops=1)"
"                          ->  Hash  (cost=4838.20..4838.20 rows=223620 width=40) (actual time=292.814..292.814 rows=223620 loops=1)"
"                                ->  Seq Scan on mi_opticalimagedesc contentinf1_3_  (cost=0.00..4838.20 rows=223620 width=40) (actual time=0.026..139.493 rows=223620 loops=1)"
"                    ->  Hash  (cost=11.20..11.20 rows=120 width=90) (actual time=0.002..0.002 rows=0 loops=1)"
"                          ->  Seq Scan on mi_radarimagedesc contentinf1_2_  (cost=0.00..11.20 rows=120 width=90) (actual time=0.001..0.001 rows=0 loops=1)"
"              ->  Hash  (cost=6456.20..6456.20 rows=223620 width=22) (actual time=302.031..302.031 rows=223620 loops=1)"
"                    ->  Seq Scan on md_metadata mdmetadata0_  (cost=0.00..6456.20 rows=223620 width=22) (actual time=0.017..152.591 rows=223620 loops=1)"
"        ->  Hash  (cost=16.36..16.36 rows=1 width=40) (actual time=0.507..0.507 rows=181 loops=1)"
"              ->  Index Scan using ind_ex_temporalextent_begin_ on ex_temporalextent temporalex4_  (cost=0.00..16.36 rows=1 width=40) (actual time=0.088..0.320 rows=181 loops=1)"
"                    Index Cond: ((begin_ >= '2007-08-01 00:00:00'::timestamp without time zone) AND (begin_ <= '2007-08-30 00:00:00'::timestamp without time zone))"
"  ->  Index Scan using catalog_id_pkey on catalog_id catalogid3_  (cost=0.00..0.65 rows=1 width=40) (actual time=0.020..0.020 rows=1 loops=161)"
"        Index Cond: ((identifica2_1_.fk_catalog_id)::text = (catalogid3_.id)::text)"
"        Filter: ((profile)::text = 'LEVEL0'::text)"
"Total runtime: 4972.689 ms"

Merci d'avance

Hors ligne

#2 18/06/2009 19:19:37

Marc Cousin
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Bonjour,

La raison pour laquelle PostgreSQL n'utilise pas les index, c'est qu'il estime que c'est moins rentable que tous les full scans qu'il fait :
Les clauses de filtrage sont sur des tables très 'à droite' dans les left join, la clause sur DATASTRIP_SCENE est très peu restrictive, et je présume que celle sur LEVEL0 ne n'est pas beaucoup non plus. Sur ce genre de plans 'assez compliqués' les versions plus récentes arrivent souvent à de meilleurs plans (sur ma 8.4, sur une requête du même type, j'ai un plan utilisant des index et un merge join).
Vous pouvez essayer :
- De remplacer les left join par des join pour au moins les tables sur lesquelles vous avez des clauses where, puisque de toutes facons, les null disparaitront du fait de la clause where ...
- Une version plus récente (si c'est possible, je n'en sais rien). Si c'est une appli en cours de développement, vous pouvez peut être regarder ce que donne la 8.4 (la sortie est imminente)


Marc.

Hors ligne

#3 19/06/2009 10:27:13

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Merci, pour votre réponse, cette requête est  générée par Hibernate et nous avons peu de latitude sur l'écriture des joins entre les tables (via les primary key)

Il est vrai que les  clauses de filtrage sont sur le tables très 'à droite' dans les left join,ne sont pas très restrictives.

Les questions que je me pose   
- est normal  de passer 2s pour ramener 116 données sur 200.000  via cette requête. cette base doit a terme contenir 1 000.000 d'entrées, la stratégie devrait donc s'adapter en fonction des statistiques, en espérant que  .ce temps vas rester stable avec l'augmentation du volume de la base
- les index sur les primary key sont des btree, je me sert  de ces  "primary key" pour effectuer des jointures entre les tables (via les joins) pourrais-je supprimer les index btree crées par postgres et les remplacer par des index Hash ... , y-a-t-il un intérêt ???

La passage en 8.4 est envisageable car cette BD part en prod a à fin de l'année., la passage de 8.3 à 8.4 necessite -t-il une migration de base ou le remplacement des exe suffit  ??, 


Autre demande d'explication si on lit  l'explain

            Hash Cond: ((mdmetadata0_1_.id)::text = (mdmetadata0_.id)::text)"
"              ->  Hash Left Join  (cost=42890.11..71257.93 rows=192868 width=186) (actual time=1547.823..4117.267 rows=206718 loops=1)"


"              ->  Hash  (cost=6456.20..6456.20 rows=223620 width=22)"
"                    ->  Seq Scan on md_metadata mdmetadata0_  (cost=0.00..6456.20 rows=223620 width=22)"

cela signifie que
1) postgres fait un seq scan sur la table  md_metadata mdmetadata0_
2) puis un Hash sur  chaque identifiant trouvé  ?? avec la table mdmetadata0_1_ sur l'ID

exact ???


merci encore pour votre réactivité

Dernière modification par F.Chanson (19/06/2009 10:29:40)

Hors ligne

#4 19/06/2009 10:37:37

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

est normal  de passer 2s pour ramener 116 données sur 200.000  via cette requête

Si on ne prend en compte que le résultat, non. Si par contre on prend en compte tout le travail nécessaire (ie, des lectures de 200000 pour pratiquement chacune des tables), oui, ça paraît normal.

pourrais-je supprimer les index btree crées par postgres et les remplacer par des index Hash

Supprimer les index revient à faire sauter les contraintes liées, donc non. Concernant les index hash, je n'ai pas encore trouvé de cas où ils pourraient être utilisé, et même les développeurs de PostgreSQL déconseillent leur utilisation actuellement.

la passage de 8.3 à 8.4 necessite -t-il une migration de base ou le remplacement des exe suffit  ?

C'est un changement de version majeur, donc pg_dump / initdb /pg_restore. Cela étant dit, un projet a pour but de faciliter cela (pg_migrator), mais je vous conseille de le tester avant.

cela signifie que
1) postgres fait un seq scan sur la table  md_metadata mdmetadata0_
2) puis un Hash sur  chaque identifiant trouvé  ?? avec la table mdmetadata0_1_ sur l'ID

exact ???

Oui. Notez que le hachage peut demander d'écrire des fichiers temporaires sur disque. log_temp_files peut vous permettre de déctecter ce problème. Et work_mem peut vous permettre de l'atténuer.


Guillaume.

Hors ligne

#5 19/06/2009 11:44:39

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Merci pour ces infos,

si je résume si  je souhaite améliorer le temps de réponse de cette requête; il faut que 

1) je positionne le paramètre  log_temp_files = 0 et je vérifie si des fichiers temp sont crées et si oui j'augmente le work_mem qui est positionné à 512M actuellement

2) j'essaye la version 8.4 

3) je dé-normalise le schéma conceptuel pour limiter les joins !!!


????

Hors ligne

#6 19/06/2009 11:49:32

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

512 Mo est une valeur déjà énorme pour work_mem. Oubliez donc cette proposition. Par contre, vous avez combien de max_connections et combien de mémoire ? parce que le work_mem est par utilisateur, et même par opération de tru et de hachage dans une requête.

Oui pour 2 et 3.


Guillaume.

Hors ligne

#7 19/06/2009 11:55:47

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Je gère  le pool de connexion via hibernate donc au max j'aurais 10 connexions permanentes entre hibernate et postgres

Mon serveur est un Quadri pro  à 10  gigas de Ram dédié à Postgres  donc au max j'occuperais 512 *10 + le shared buffer qui est positioné à 1 Gigas

Hors ligne

#8 19/06/2009 12:21:03

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

Je ne suis pas vraiment d'accord sur le calcul de la mémoire utilisée. Je compte huit HashJoin sur la requête indiquée ci-dessus, donc huit opérations de hachage, donc potentiellement 8 opérations de hachage * 10 connexions (supposées) * 512 Mo, ce qui indique au minimum 40 Go. Alors, j'ai bien dit « potentiellement ». Je ne crois pas que vous aurez des requêtes qui demanderont 512 Mo à chaque opération de tri ou de hachage, mais il y a un risque. C'est tout ce que je voulais souligner.

Y-a-t'il une raison pour avoir sélectionné 512 Mo pour le work_mem ? surtout avec un shared_buffers à seulement 1 Go. Quelle est la taille de la base au fait ?


Guillaume.

Hors ligne

#9 19/06/2009 13:12:36

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

L'estimation de la bd est  50  Gigas pour 1M d'enreg pour 90 tables jointes , donc "potentiellement" je pourrais avoir des joins sur 90 tables, au max je table sur des jointures en moyenne entre 10 et 30 tables en fonction des clauses where positionnées.

Il y a aura toujours au minimum  8 tables jointées avant de commencer à ajouter les tables associées à la clause "where"

je n'ai pas de requête avec des clauses "d'order by " ces tris sont à posteriori  en java

Le principe retenu pour les recherches dans cette BD est le suivant
1) recherche uniquement des ID en effectuant les clauses de jointure correspondant à la clause Where uniquement ....
2) puis à partir des IDs trouvés récupérer les attributs associés en parcourant les tables .....

Le choix de 512  pour le work_mem  proviennent d'une série de tests afin d'éviter l'écriture de fichiers tempo sur disque. 
Le choix du shared_buffers à seulement 1 Go provient d'un ratio par rapport à la RAM dispo sur ce serveur.
j'ai pris comme ratio 250Mb pour 2G Ram, 500Mb pour 4G Ram donc 1Go pour 8G Ram, en laissant de la place aux  work_mem(s) des différents process connectés

Mais je peux  les changer a des fins de tests

Hors ligne

#10 19/06/2009 14:31:56

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

Avoir au minimum 8 jointures pour la moindre requête me laisse supposer qu'il y a un défaut de normalisation des tables.

Quant au shared_buffers, on l'estime habituellement 1/4 de la RAM pour un serveur dédié. Mais c'est peut-être pas le cas pour vous.


Guillaume.

Hors ligne

#11 19/06/2009 14:58:57

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

"Avoir au minimum 8 jointures pour la moindre requête me laisse supposer qu'il y a un défaut de normalisation des tables."

Ce schéma est un schéma générique (avec de l'héritage) , qui est issue de la modélisation d'un schéma XSD très  complexe, une  dé-normalisation de ce schéma sera la dernière amélioration qui sera faite.

Je peux passer le shared_buffers à 2Go par contre c'est votre calcul sur le work-mem qui m'interpelle (8 opérations de hachage * 10 connexions  * 512 Mo, ce qui indique au minimum 40 Go.) Je pensais que le work-mem  etait alloué par process et non par opérations de hachage/tri/jointure  pour un  process !!! , si c'est le cas je dois réduire cette taille à 50Mo => 50 * 8 opérations  (mini) * 10connexions   => 4 gigas

est-ce correct  ???

Hors ligne

#12 19/06/2009 15:27:52

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

De la mémoire est allouée par chaque processus pour ses propres opérations de tri et de hachage. Chaque opération peut utiliser jusqu'à work_mem octets. Donc, ce n'est pas parce que vous avez un tri ou un hachage que vous utiliserez les 512 Mo actuellement configuré mais, suivant les besoins, le processus serveur lié au client qui demande l'exécution de la requête pourra allouer jusqu'à 512 Mo si nécessaire. Donc, il a fort peu de chances que cela arrive à ce point, mais c'est un risque. Avec un shared_buffers à 50 Mo, vous diminuez les risques par 10. Néanmoins, faites bien attention à ce que les perfs ne s'en ressentent pas trop. 2 Go pour shared_buffers me paraît une meilleure valeur. Vérifiez aussi que votre effective_cache_size soit bien proportionnée (2/3 de la RAM pour un serveur dédié).


Guillaume.

Hors ligne

#13 19/06/2009 15:52:11

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Qu'appelez-vous processus , d'après ma compréhension il y a un processus serveur par connexion client , dans mon cas j'ai donc aux max 10 processus serveur qui peuvent consommer au max jusqu'à'  512M  chacun. Mon client hibernate n'effectue des opérations synchones  sur postgres, donc je ne devrais pas arriver à 40 Gigas !!!, mais au max à 5 gigas ?

mon effective_cache_size est positionné 699050  sur mon serveur de 10 gigas

Francis

Hors ligne

#14 19/06/2009 16:16:24

Marc Cousin
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Par processus, on entend processus serveur postgresql, ceux qui sont démarrés pour chaque session. Mais chaque opération de tri dans une requête peut allouer jusqu'à work_mem. Donc dans le cas (extrême) ou chacune des 10 sessions fait en même temps une requête impliquand par exemple 8 hash joins, on peut, si chacun de ces hashages consomme 512Mo de mémoire, se retrouver à
10 x 8 x 512 Mo de mémoire. Evidemment il est statistiquement très peu probable que cela arrive. Mais il est bon de le savoir malgré tout.


Marc.

Hors ligne

#15 19/06/2009 16:24:31

Marc Cousin
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Pour revenir au problème de jointure, il est possible que vous ayez besoin d'autant de tables. Sans connaissance de l'application et du schéma il est bien sûr impossible de dire qu'il y a erreur de conception. Malgré tout, il est déconseillé, sur tous les SGBD, de dépasser un certain nombre de tables jointes, puisque le calcul du plan est un problème de type voyageur de commerce, dont la complexité croit très vite avec le nombre de tables impliquées...

Ce qui me fait penser à ce qui est peut être la cause de votre problème : le paramêtre from_collapse_limit :
par défaut, postgresql ne va pas essayer de réordonner les jointures dans une requête qui contiendra plus de tables que cette valeur.

Pouvez vous essayer de l'augmenter (15 par exemple pour le moment) et constater si le plan est meilleur ?
A mon avis, le problème vient de là (mon cas n'avait pas autant de table).

Attention : le temps de planification de la requête augmentera. Il faudra donc voir si le gain en exécution compense la perte en planification.

Cette page de la doc explique assez bien les bases de ce mécanisme (et parle du GEQO) :
http://docs.postgresql.fr/8.4/explicit-joins.html

Dernière modification par Marc Cousin (19/06/2009 16:27:26)


Marc.

Hors ligne

#16 19/06/2009 16:27:32

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Ok , c'est plus clair ,

maintenant cette question ; comment évaluer précisément le work-men pour un client ?? en analysant (explain) l'ensemble des requêtes passées par mon client via les log Postgres et pggfouine

Sur quelles métriques dois-je me baser pour déterminer la valeur du work-men

Hors ligne

#17 19/06/2009 16:34:02

Marc Cousin
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

L'évaluation précise n'est pas simple je pense.
A mon avis, il vaut mieux l'avoir légèrement sous dimensionnée que sur dimensionnée : avoir quelques tris qui se terminent sur disque, c'est moins grave que de croire les faire en mémoire et qu'ils aient lieu dans le swap. L'effet est du même type que sous Oracle : passé un certain seuil (quelques mégas à quelques dizaines de mégas) on ne gagne plus énormément : les petits tris devant avoir lieu en mémoire s'y font.
L'explain ne donnera pas grand chose (encore que dans les nouvelles versions, à partir de 8.3, l'explain analyze vous donnera la consommation mémoire de chaque étape du plan). Je pense qu'il vaut mieux partir sur une valeur raisonnable de l'ordre de 64 Mo et tracer les tris disques avec log_temp_files, afin de repérer les quelques requêtes qui abusent.

Mais commencez par tester la modification des collapse_limit, je pense que c'est la principale cause de vos problèmes.


Marc.

Hors ligne

#18 19/06/2009 16:38:18

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Mon application ne fait pas de tri explicite sur la base , mais uniquement des joins , le log_temp_files sera-il utilisé dans ce cas ???

Hors ligne

#19 19/06/2009 16:39:04

Marc Cousin
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Oui, c'est pour l'ensemble des opérations de 'tri' (cela inclut les hashages et les tris principalement).


Marc.

Hors ligne

#20 19/06/2009 16:41:13

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

Il n'y a pas vraiment de moyens. On se rend compte que le work_mem n'est pas suffisant quand il y a des écritures sur disque à cause des tris et des hachages (d'où le gros intérêt du paramètre log_temp_files, nouveau en 8.3).


Guillaume.

Hors ligne

#21 19/06/2009 16:43:57

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

Ok je modifie les paramètres  from_collapse_limit et join_collapse_limit  à la valeur de 15 ,
faut-il un restart de postgres ??? et je vérifie le plan de l'optimiseur

Hors ligne

#22 19/06/2009 16:47:06

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

Non, vous n'avez pas besoin de faire un restart. Vous pouvez même le faire sur votre session (SET from_collapse_limit TO 15; puis vous exécutez votre requête).


Guillaume.

Hors ligne

#23 19/06/2009 16:54:14

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

voici le plan obtenu à partir de cette requête

SET from_collapse_limit TO 15;
explain analyse select mdmetadata0_.id as col_0_0_ from   public.md_metadata mdmetadata0_
inner join public.mf_metadata mdmetadata0_1_ on mdmetadata0_.id=mdmetadata0_1_.id
left outer join public.content_info contentinf1_ on mdmetadata0_.id=contentinf1_.fk_metadata
left outer join public.mi_imagedesc contentinf1_1_ on contentinf1_.id=contentinf1_1_.id
left outer join public.mi_radarimagedesc contentinf1_2_ on contentinf1_.id=contentinf1_2_.id
left outer join public.mi_opticalimagedesc contentinf1_3_ on contentinf1_.id=contentinf1_3_.id
left outer join public.md_identification identifica2_ on mdmetadata0_.id=identifica2_.fk_md_metadata
left outer join public.md_dataidentification identifica2_1_ on identifica2_.id=identifica2_1_.id
left outer join public.catalog_id catalogid3_ on identifica2_1_.fk_catalog_id=catalogid3_.id
left outer join public.ex_temporalextent temporalex4_ on identifica2_.id=temporalex4_.fk_dataident
where contentinf1_1_.attribute_desc='DATASTRIP_SCENE' and catalogid3_.profile='LEVEL0' and (temporalex4_.begin_ between '2007-08-01' and '2007-08-30')


"Nested Loop  (cost=52157.93..85267.26 rows=1 width=22) (actual time=1870.443..4967.570 rows=161 loops=1)"
"  ->  Hash Join  (cost=52157.93..85266.60 rows=1 width=62) (actual time=1870.377..4963.943 rows=161 loops=1)"
"        Hash Cond: ((identifica2_.id)::text = (temporalex4_.fk_dataident)::text)"
"        ->  Hash Join  (cost=52141.56..84472.30 rows=207445 width=142) (actual time=1847.458..4843.893 rows=206718 loops=1)"
"              Hash Cond: ((mdmetadata0_1_.id)::text = (mdmetadata0_.id)::text)"
"              ->  Hash Left Join  (cost=42890.11..71257.93 rows=192868 width=186) (actual time=1546.351..4118.596 rows=206718 loops=1)"
"                    Hash Cond: ((contentinf1_.id)::text = (contentinf1_2_.id)::text)"
"                    ->  Hash Left Join  (cost=42877.41..70520.95 rows=192868 width=226) (actual time=1546.325..3900.222 rows=206718 loops=1)"
"                          Hash Cond: ((contentinf1_.id)::text = (contentinf1_3_.id)::text)"
"                          ->  Hash Join  (cost=35243.96..58789.05 rows=192868 width=226) (actual time=1254.140..3188.293 rows=206718 loops=1)"
"                                Hash Cond: ((identifica2_.id)::text = (identifica2_1_.id)::text)"
"                                ->  Hash Join  (cost=25911.51..45358.16 rows=192868 width=146) (actual time=923.143..2424.479 rows=206718 loops=1)"
"                                      Hash Cond: ((contentinf1_.id)::text = (contentinf1_1_.id)::text)"
"                                      ->  Hash Join  (cost=15000.19..30439.11 rows=207906 width=146) (actual time=601.607..1670.034 rows=223620 loops=1)"
"                                            Hash Cond: ((mdmetadata0_1_.id)::text = (contentinf1_.fk_metadata)::text)"
"                                            ->  Hash Join  (cost=7337.74..18181.87 rows=223620 width=84) (actual time=299.616..912.999 rows=223620 loops=1)"
"                                                  Hash Cond: ((identifica2_.fk_md_metadata)::text = (mdmetadata0_1_.id)::text)"
"                                                  ->  Seq Scan on md_identification identifica2_  (cost=0.00..6092.20 rows=223620 width=62) (actual time=0.023..138.506 rows=223620 loops=1)"
"                                                  ->  Hash  (cost=4331.22..4331.22 rows=240522 width=22) (actual time=299.474..299.474 rows=240522 loops=1)"
"                                                        ->  Seq Scan on mf_metadata mdmetadata0_1_  (cost=0.00..4331.22 rows=240522 width=22) (actual time=0.015..142.287 rows=240522 loops=1)"
"                                            ->  Hash  (cost=4867.20..4867.20 rows=223620 width=62) (actual time=301.880..301.880 rows=223620 loops=1)"
"                                                  ->  Seq Scan on content_info contentinf1_  (cost=0.00..4867.20 rows=223620 width=62) (actual time=0.029..140.764 rows=223620 loops=1)"
"                                      ->  Hash  (cost=8318.25..8318.25 rows=207445 width=40) (actual time=321.418..321.418 rows=206718 loops=1)"
"                                            ->  Seq Scan on mi_imagedesc contentinf1_1_  (cost=0.00..8318.25 rows=207445 width=40) (actual time=0.034..176.820 rows=206718 loops=1)"
"                                                  Filter: ((attribute_desc)::text = 'DATASTRIP_SCENE'::text)"
"                                ->  Hash  (cost=6537.20..6537.20 rows=223620 width=80) (actual time=330.886..330.886 rows=223620 loops=1)"
"                                      ->  Seq Scan on md_dataidentification identifica2_1_  (cost=0.00..6537.20 rows=223620 width=80) (actual time=0.029..158.008 rows=223620 loops=1)"
"                          ->  Hash  (cost=4838.20..4838.20 rows=223620 width=40) (actual time=292.073..292.073 rows=223620 loops=1)"
"                                ->  Seq Scan on mi_opticalimagedesc contentinf1_3_  (cost=0.00..4838.20 rows=223620 width=40) (actual time=0.024..137.913 rows=223620 loops=1)"
"                    ->  Hash  (cost=11.20..11.20 rows=120 width=90) (actual time=0.002..0.002 rows=0 loops=1)"
"                          ->  Seq Scan on mi_radarimagedesc contentinf1_2_  (cost=0.00..11.20 rows=120 width=90) (actual time=0.001..0.001 rows=0 loops=1)"
"              ->  Hash  (cost=6456.20..6456.20 rows=223620 width=22) (actual time=300.994..300.994 rows=223620 loops=1)"
"                    ->  Seq Scan on md_metadata mdmetadata0_  (cost=0.00..6456.20 rows=223620 width=22) (actual time=0.017..151.848 rows=223620 loops=1)"
"        ->  Hash  (cost=16.36..16.36 rows=1 width=40) (actual time=0.516..0.516 rows=181 loops=1)"
"              ->  Index Scan using ind_ex_temporalextent_begin_ on ex_temporalextent temporalex4_  (cost=0.00..16.36 rows=1 width=40) (actual time=0.086..0.324 rows=181 loops=1)"
"                    Index Cond: ((begin_ >= '2007-08-01 00:00:00'::timestamp without time zone) AND (begin_ <= '2007-08-30 00:00:00'::timestamp without time zone))"
"  ->  Index Scan using catalog_id_pkey on catalog_id catalogid3_  (cost=0.00..0.65 rows=1 width=40) (actual time=0.020..0.020 rows=1 loops=161)"
"        Index Cond: ((identifica2_1_.fk_catalog_id)::text = (catalogid3_.id)::text)"
"        Filter: ((profile)::text = 'LEVEL0'::text)"
"Total runtime: 4976.187 ms"

---------------------------------------------------------
Durée totale d'exécution de la requête :2656 ms.
161 lignes récupérées.

Hors ligne

#24 19/06/2009 17:13:49

gleu
Administrateur

Re : Besoin d'infos sur le resultat issu d'un explain

À priori, tout se fait à partir de la colonne id de contentinf1_. Pré-ordonner cette table en prenant en compte cette colonne pourrait améliorer les choses. J'ai fait ça chez un client, et ça avait permis d'améliorer les temps de réponses. Pour cela, il faut utiliser la commande CLUSTER (http://docs.postgresqlfr.org/8.2/sql-cluster.html).


Guillaume.

Hors ligne

#25 19/06/2009 18:01:32

F.Chanson
Membre

Re : Besoin d'infos sur le resultat issu d'un explain

après un passage des commandes  suivantes

CLUSTER content_info_pkey ON public.content_info

puis un restart postgres

la requête s'effectue
SET join_collapse_limit TO 15;
select mdmetadata0_.id as col_0_0_ from   public.md_metadata mdmetadata0_
inner join public.mf_metadata mdmetadata0_1_ on mdmetadata0_.id=mdmetadata0_1_.id
left outer join public.content_info contentinf1_ on mdmetadata0_.id=contentinf1_.fk_metadata
left outer join public.mi_imagedesc contentinf1_1_ on contentinf1_.id=contentinf1_1_.id
left outer join public.mi_radarimagedesc contentinf1_2_ on contentinf1_.id=contentinf1_2_.id
left outer join public.mi_opticalimagedesc contentinf1_3_ on contentinf1_.id=contentinf1_3_.id
left outer join public.md_identification identifica2_ on mdmetadata0_.id=identifica2_.fk_md_metadata
left outer join public.md_dataidentification identifica2_1_ on identifica2_.id=identifica2_1_.id
left outer join public.catalog_id catalogid3_ on identifica2_1_.fk_catalog_id=catalogid3_.id
left outer join public.ex_temporalextent temporalex4_ on identifica2_.id=temporalex4_.fk_dataident
where contentinf1_1_.attribute_desc='DATASTRIP_SCENE' and catalogid3_.profile='LEVEL0' and (temporalex4_.begin_ between '2007-08-01' and '2007-08-30')


Durée totale d'exécution de la requête :93 ms.
161 lignes récupérées.

le plan d'adressage est bien meilleur car il passe systématiquement par les index  vs un  seq scan !!!!

Ma question :  dois-je positionner le  from_collapse_limit  ??? qui a prioi n'est pas  utile ???  , quand je supprime le join_collapse_limit , je retombe sur des  seq scan , donc  le bon paramete semble être  join_collapse_limit

"Nested Loop  (cost=0.00..53.24 rows=1 width=22) (actual time=0.299..21.167 rows=161 loops=1)"
"  ->  Nested Loop  (cost=0.00..52.63 rows=1 width=66) (actual time=0.282..18.888 rows=161 loops=1)"
"        ->  Nested Loop Left Join  (cost=0.00..51.96 rows=1 width=106) (actual time=0.151..16.286 rows=181 loops=1)"
"              ->  Nested Loop Left Join  (cost=0.00..51.68 rows=1 width=106) (actual time=0.149..15.851 rows=181 loops=1)"
"                    ->  Nested Loop  (cost=0.00..51.08 rows=1 width=106) (actual time=0.131..13.248 rows=181 loops=1)"
"                          ->  Nested Loop  (cost=0.00..50.43 rows=1 width=146) (actual time=0.113..10.622 rows=181 loops=1)"
"                                ->  Nested Loop  (cost=0.00..33.98 rows=1 width=186) (actual time=0.094..7.973 rows=181 loops=1)"
"                                      ->  Nested Loop  (cost=0.00..33.48 rows=1 width=124) (actual time=0.076..5.383 rows=181 loops=1)"
"                                            ->  Nested Loop  (cost=0.00..32.81 rows=1 width=102) (actual time=0.058..2.845 rows=181 loops=1)"
"                                                  ->  Index Scan using ind_ex_temporalextent_begin_ on ex_temporalextent temporalex4_  (cost=0.00..16.36 rows=1 width=40) (actual time=0.027..0.164 rows=181 loops=1)"
"                                                        Index Cond: ((begin_ >= '2007-08-01 00:00:00'::timestamp without time zone) AND (begin_ <= '2007-08-30 00:00:00'::timestamp without time zone))"
"                                                  ->  Index Scan using md_identification_pkey on md_identification identifica2_  (cost=0.00..16.43 rows=1 width=62) (actual time=0.012..0.013 rows=1 loops=181)"
"                                                        Index Cond: ((identifica2_.id)::text = (temporalex4_.fk_dataident)::text)"
"                                            ->  Index Scan using md_metadata_pkey on md_metadata mdmetadata0_  (cost=0.00..0.66 rows=1 width=22) (actual time=0.011..0.012 rows=1 loops=181)"
"                                                  Index Cond: ((mdmetadata0_.id)::text = (identifica2_.fk_md_metadata)::text)"
"                                      ->  Index Scan using ind_content_info_fk_metadata on content_info contentinf1_  (cost=0.00..0.49 rows=1 width=62) (actual time=0.012..0.012 rows=1 loops=181)"
"                                            Index Cond: ((mdmetadata0_.id)::text = (contentinf1_.fk_metadata)::text)"
"                                ->  Index Scan using md_dataidentification_pkey on md_dataidentification identifica2_1_  (cost=0.00..16.43 rows=1 width=80) (actual time=0.012..0.013 rows=1 loops=181)"
"                                      Index Cond: ((identifica2_.id)::text = (identifica2_1_.id)::text)"
"                          ->  Index Scan using catalog_id_pkey on catalog_id catalogid3_  (cost=0.00..0.63 rows=1 width=40) (actual time=0.012..0.013 rows=1 loops=181)"
"                                Index Cond: ((identifica2_1_.fk_catalog_id)::text = (catalogid3_.id)::text)"
"                                Filter: ((profile)::text = 'LEVEL0'::text)"
"                    ->  Index Scan using ind_mi_opticalimagedesc_multicol on mi_opticalimagedesc contentinf1_3_  (cost=0.00..0.59 rows=1 width=40) (actual time=0.012..0.012 rows=1 loops=181)"
"                          Index Cond: ((contentinf1_.id)::text = (contentinf1_3_.id)::text)"
"              ->  Index Scan using mi_radarimagedesc_pkey on mi_radarimagedesc contentinf1_2_  (cost=0.00..0.27 rows=1 width=90) (actual time=0.001..0.001 rows=0 loops=181)"
"                    Index Cond: ((contentinf1_.id)::text = (contentinf1_2_.id)::text)"
"        ->  Index Scan using ind_mi_imagedesc_id on mi_imagedesc contentinf1_1_  (cost=0.00..0.65 rows=1 width=40) (actual time=0.012..0.013 rows=1 loops=181)"
"              Index Cond: ((contentinf1_.id)::text = (contentinf1_1_.id)::text)"
"              Filter: ((attribute_desc)::text = 'DATASTRIP_SCENE'::text)"
"  ->  Index Scan using mf_metadata_pkey on mf_metadata mdmetadata0_1_  (cost=0.00..0.60 rows=1 width=22) (actual time=0.012..0.012 rows=1 loops=161)"
"        Index Cond: ((mdmetadata0_.id)::text = (mdmetadata0_1_.id)::text)"
"Total runtime: 21.411 ms"

Hors ligne

Pied de page des forums