IdentifiantMot de passe
Mot de passe oublié ?Je m'inscris ! (gratuit)
Navigation

Inscrivez-vous gratuitement
pour pouvoir participer, suivre les réponses en temps réel, voter pour les messages, poser vos propres questions et recevoir la newsletter

Requêtes PostgreSQL Discussion :

Explain analyse : temps fantome !


Sujet :

Requêtes PostgreSQL

Vue hybride

Message précédent Message précédent   Message suivant Message suivant
  1. 24/06/2013, 17h30 #1
    Sidart
    Sidart est déconnecté
    Membre habitué
    Profil pro
    Inscrit en
    Mai 2010
    Messages
    7
    Détails du profil
    Informations personnelles :
    Localisation : France

    Informations forums :
    Inscription : Mai 2010
    Messages : 7
    Par défaut Explain analyse : temps fantome !
    Bonjour,

    je suis au devant d'une requête qui est très longue et l'explain plan ne m'aide pas du tout ( en mode ANALYSE).

    Voici le plan pour les amateurs : ( le problème peut surement être résolu sans le lire, a supposer qu'il existe une solution : ) )

    Code : Sélectionner tout - Visualiser dans une fenêtre à part
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    22
    23
    24
    25
    26
    27
    28
    29
    30
    31
    32
    33
    34
    35
    36
    37
    38
    39
    40
    41
    42
    43
    44
    45
    46
    47
    48
    49
    50
    51
    52
    53
    54
    55
    56
    57
    58
    59
    60
    61
    62
    63
    64
    65
    66
    67
    68
    69
    70
    71
    72
    73
    74
    75
    76
    77
    78
    79
    80
    81
    82
    83
    84
    85
    86
    87
    88
     
"        Hash Cond: (cte_dwh.rfoperdtd = dwhinv.dwhinvdtd)"
"        ->  Group  (cost=20000003814.32..20000004408.92 rows=19820 width=99) (actual time=2.720..3.408 rows=731 loops=1)"
"              ->  Sort  (cost=20000003814.32..20000003863.87 rows=19820 width=99) (actual time=2.715..2.765 rows=731 loops=1)"
"                    Sort Key: cte_periode1.rfoper___rforefide, cte_periode4.rfoperlic, cte_dwh.rfoperdtd, cte_periode1.rfoperlic, (to_char(cte_periode1.rfoperdtd, 'MM'::text)), (to_char(cte_dwh.rfoperdtd, 'DD'::text)), cte_dwh.rfoper___rfotpeide, cte_dwh.rfoperdtf"
"                    Sort Method: quicksort  Memory: 127kB"
"                    ->  Nested Loop  (cost=20000000000.00..20000002399.70 rows=19820 width=99) (actual time=0.279..2.396 rows=731 loops=1)"
"                          ->  Nested Loop  (cost=10000000000.00..10000000020.75 rows=231 width=106) (actual time=0.030..0.232 rows=460 loops=1)"
"                                ->  Index Scan using rfoper_cte_idx on rfoper cte_periode4  (cost=0.00..4.80 rows=1 width=53) (actual time=0.019..0.021 rows=2 loops=1)"
"                                      Index Cond: ((rfoper___rfocteide)::text = 'ANNEE'::text)"
"                                      Filter: (((rfoperlic)::text = ANY ('{2011,2012}'::text[])) AND ((rfoper___rforefide)::text = 'REF'::text))"
"                                ->  Index Scan using rfoper_cte_idx on rfoper cte_periode1  (cost=0.00..13.63 rows=231 width=53) (actual time=0.006..0.073 rows=230 loops=2)"
"                                      Index Cond: ((rfoper___rfocteide)::text = 'MOIS'::text)"
"                                      Filter: ((rfoper___rforefide)::text = 'REF'::text)"
"                          ->  Index Scan using rfoper_pk on rfoper cte_dwh  (cost=0.00..8.15 rows=86 width=27) (actual time=0.003..0.003 rows=2 loops=460)"
"                                Index Cond: (((rfoper___rforefide)::text = 'REF'::text) AND ((rfoper___rfocteide)::text = 'JOUR'::text) AND (rfoperdtd >= cte_periode1.rfoperdtd) AND (rfoperdtd <= cte_periode1.rfoperdtf) AND (rfoperdtd >= cte_periode4.rfoperdtd) AND (rfoperdtd <= cte_periode4.rfoperdtf))"
"        ->  Hash  (cost=58956.34..58956.34 rows=1 width=66) (actual time=1263.463..1263.463 rows=1275612 loops=1)"
"              Buckets: 1024  Batches: 4 (originally 1)  Memory Usage: 49153kB"
"              ->  Hash Join  (cost=15992.56..58956.34 rows=1 width=66) (actual time=103.705..829.034 rows=1275612 loops=1)"
"                    Hash Cond: ((dwhinv.dwhinv_d2rfodstide)::text = (ade2.rfoade_i_rfodstide)::text)"
"                    ->  Hash Join  (cost=8566.99..51530.67 rows=18 width=64) (actual time=71.614..523.049 rows=1275612 loops=1)"
"                          Hash Cond: ((dwhinv.dwhinv___rsaedtide)::text = (aed2.rsaaed_i_rsaedtide)::text)"
"                          ->  Hash Join  (cost=8551.88..51514.47 rows=251 width=62) (actual time=71.492..297.644 rows=637806 loops=1)"
"                                Hash Cond: ((dwhinv.dwhinv_p2rfodstide)::text = (ade2.rfoade_i_rfodstide)::text)"
"                                ->  Bitmap Heap Scan on dwhinv  (cost=1090.11..43970.64 rows=21214 width=60) (actual time=34.946..78.786 rows=225354 loops=1)"
"                                      Recheck Cond: ((((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '17'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '18'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '15'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '16'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '20'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '17'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '18'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '15'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '19'::text)) OR (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '16'::text)))"
"                                      Filter: ((dwhinv___rforefide)::text = 'REF'::text)"
"                                      ->  BitmapOr  (cost=1090.11..1090.11 rows=21229 width=0) (actual time=33.963..33.963 rows=0 loops=1)"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..168.78 rows=4497 width=0) (actual time=6.936..6.936 rows=46619 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '17'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..109.07 rows=2280 width=0) (actual time=4.336..4.336 rows=28849 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '18'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..180.03 rows=4917 width=0) (actual time=7.050..7.050 rows=46619 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '15'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..222.61 rows=6403 width=0) (actual time=4.302..4.302 rows=28849 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'LABO'::text) AND ((dwhinv___rfoindide)::text = '16'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..47.88 rows=105 width=0) (actual time=2.671..2.671 rows=17723 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '20'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..65.63 rows=725 width=0) (actual time=0.042..0.042 rows=227 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '17'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..55.16 rows=367 width=0) (actual time=2.921..2.921 rows=19259 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '18'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..66.47 rows=792 width=0) (actual time=0.042..0.042 rows=227 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '15'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..47.97 rows=112 width=0) (actual time=2.778..2.778 rows=17723 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '19'::text))"
"                                            ->  Bitmap Index Scan on dwhinv_vin_idx  (cost=0.00..73.47 rows=1032 width=0) (actual time=2.882..2.882 rows=19259 loops=1)"
"                                                  Index Cond: (((dwhinv___rfovsnide)::text = '201210_reel'::text) AND ((dwhinv___rfodomide)::text = 'ANAPATH'::text) AND ((dwhinv___rfoindide)::text = '16'::text))"
"                                ->  Hash  (cost=7459.12..7459.12 rows=212 width=16) (actual time=36.530..36.530 rows=1806 loops=1)"
"                                      Buckets: 1024  Batches: 1  Memory Usage: 77kB"
"                                      ->  Hash Join  (cost=40.51..7459.12 rows=212 width=16) (actual time=8.389..36.248 rows=1806 loops=1)"
"                                            Hash Cond: (((ade2.rfoade___rforefide)::text = (ade1.rfoade___rforefide)::text) AND ((ade2.rfoade___rfovdeide)::text = (ade1.rfoade___rfovdeide)::text))"
"                                            Join Filter: (((ade2.rfoadegch)::text >= (ade1.rfoadegch)::text) AND ((ade2.rfoadedrt)::text <= (ade1.rfoadedrt)::text))"
"                                            ->  Seq Scan on rfoade ade2  (cost=0.00..6584.59 rows=107380 width=224) (actual time=0.004..20.757 rows=107751 loops=1)"
"                                                  Filter: (rfoadervs = 1)"
"                                            ->  Hash  (cost=40.49..40.49 rows=1 width=224) (actual time=0.075..0.075 rows=17 loops=1)"
"                                                  Buckets: 1024  Batches: 1  Memory Usage: 4kB"
"                                                  ->  Bitmap Heap Scan on rfoade ade1  (cost=38.45..40.49 rows=1 width=224) (actual time=0.051..0.066 rows=17 loops=1)"
"                                                        Recheck Cond: (((rfoade___rfovdeide)::text = 'STRC_REF'::text) AND ((rfoade_i_rfodstide)::text = ANY ('{01,04,05,06,07,99,REF,CR2107,CR2108,CR2109,CR2110,CR2111,CR2114,CR2116,CR2126,CR4101,CR4201}'::text[])))"
"                                                        Filter: (((rfoade___rforefide)::text = 'REF'::text) AND (rfoadervs = 1))"
"                                                        ->  Bitmap Index Scan on rfoade_adv  (cost=0.00..38.45 rows=1 width=0) (actual time=0.046..0.046 rows=17 loops=1)"
"                                                              Index Cond: (((rfoade___rfovdeide)::text = 'STRC_REF'::text) AND ((rfoade_i_rfodstide)::text = ANY ('{01,04,05,06,07,99,REF,CR2107,CR2108,CR2109,CR2110,CR2111,CR2114,CR2116,CR2126,CR4101,CR4201}'::text[])))"
"                          ->  Hash  (cost=15.08..15.08 rows=2 width=14) (actual time=0.107..0.107 rows=43 loops=1)"
"                                Buckets: 1024  Batches: 1  Memory Usage: 3kB"
"                                ->  Hash Join  (cost=6.83..15.08 rows=2 width=14) (actual time=0.040..0.095 rows=43 loops=1)"
"                                      Hash Cond: (((aed2.rsaaed___rforefide)::text = (aed1.rsaaed___rforefide)::text) AND ((aed2.rsaaed___rsavedide)::text = (aed1.rsaaed___rsavedide)::text))"
"                                      Join Filter: (((aed2.rsaaedgch)::text >= (aed1.rsaaedgch)::text) AND ((aed2.rsaaeddrt)::text <= (aed1.rsaaeddrt)::text))"
"                                      ->  Seq Scan on rsaaed aed2  (cost=0.00..6.83 rows=146 width=182) (actual time=0.005..0.028 rows=146 loops=1)"
"                                            Filter: (rsaaedrvs = 1)"
"                                      ->  Hash  (cost=6.82..6.82 rows=1 width=182) (actual time=0.028..0.028 rows=3 loops=1)"
"                                            Buckets: 1024  Batches: 1  Memory Usage: 1kB"
"                                            ->  Bitmap Heap Scan on rsaaed aed1  (cost=4.80..6.82 rows=1 width=182) (actual time=0.022..0.022 rows=3 loops=1)"
"                                                  Recheck Cond: (((rsaaed___rforefide)::text = 'REF'::text) AND ((rsaaed___rsavedide)::text = 'PRESTA_ACTE'::text) AND ((rsaaed_i_rsaedtide)::text = ANY ('{PRISE_EN_CHARGE,REG_EXT,REG_HOSPI_SEANCE}'::text[])) AND (rsaaedrvs = 1))"
"                                                  ->  Bitmap Index Scan on rsaaed_pk  (cost=0.00..4.80 rows=1 width=0) (actual time=0.020..0.020 rows=3 loops=1)"
"                                                        Index Cond: (((rsaaed___rforefide)::text = 'REF'::text) AND ((rsaaed___rsavedide)::text = 'PRESTA_ACTE'::text) AND ((rsaaed_i_rsaedtide)::text = ANY ('{PRISE_EN_CHARGE,REG_EXT,REG_HOSPI_SEANCE}'::text[])) AND (rsaaedrvs = 1))"
"                    ->  Hash  (cost=7422.92..7422.92 rows=212 width=16) (actual time=32.089..32.089 rows=1242 loops=1)"
"                          Buckets: 1024  Batches: 1  Memory Usage: 54kB"
"                          ->  Hash Join  (cost=4.30..7422.92 rows=212 width=16) (actual time=8.424..31.889 rows=1242 loops=1)"
"                                Hash Cond: (((ade2.rfoade___rforefide)::text = (ade1.rfoade___rforefide)::text) AND ((ade2.rfoade___rfovdeide)::text = (ade1.rfoade___rfovdeide)::text))"
"                                Join Filter: (((ade2.rfoadegch)::text >= (ade1.rfoadegch)::text) AND ((ade2.rfoadedrt)::text <= (ade1.rfoadedrt)::text))"
"                                ->  Seq Scan on rfoade ade2  (cost=0.00..6584.59 rows=107380 width=224) (actual time=0.005..20.907 rows=107751 loops=1)"
"                                      Filter: (rfoadervs = 1)"
"                                ->  Hash  (cost=4.29..4.29 rows=1 width=224) (actual time=0.014..0.014 rows=1 loops=1)"
"                                      Buckets: 1024  Batches: 1  Memory Usage: 1kB"
"                                      ->  Index Scan using rfoade_adv on rfoade ade1  (cost=0.00..4.29 rows=1 width=224) (actual time=0.011..0.012 rows=1 loops=1)"
"                                            Index Cond: (((rfoade___rfovdeide)::text = 'STRC'::text) AND ((rfoade_i_rfodstide)::text = 'REF'::text))"
"                                            Filter: (((rfoade___rforefide)::text = 'REF'::text) AND (rfoadervs = 1))"
"Total runtime: 5647.677 ms"

    Entre les deux derniers composants : un HashJoin et un HashAggregate, plusieurs secondes semblent n'avoir été utilisée par aucun composant.

    Le hashjoin ayant tourné de 1200 a 1600 ms, et le hashaggregate de 5645 ms a 5645 ms.

    Quelqu’un aurait déjà rencontré ce problème ?
    Répondre avec citation Répondre avec citation   0  0
  2. 25/06/2013, 18h16 #2
    SQLpro
    SQLpro est déconnecté
    Rédacteur

    Avatar de SQLpro
    Homme Profil pro
    Expert bases de données / SQL / MS SQL Server / Postgresql
    Inscrit en
    Mai 2002
    Messages
    22 002
    Détails du profil
    Informations personnelles :
    Sexe : Homme
    Localisation : France, Var (Provence Alpes Côte d'Azur)

    Informations professionnelles :
    Activité : Expert bases de données / SQL / MS SQL Server / Postgresql
    Secteur : Conseil

    Informations forums :
    Inscription : Mai 2002
    Messages : 22 002
    Billets dans le blog
    6
    Par défaut
    Sans la requête difficile de t'aider... mais visiblement tu à plus de 12 jointures. Or l'optimiseur de PG est paramétré pour être plus ou moins optimal jusqu'à 12 jointures. Au delà, afin de ne pas explorer trop de combinaisons, il utilise un algo génétique (GEQO) qui est assez imbitable et rend assez souvent des plans foireux.

    Solutions possible :
    1) augmenter le seuil de déclenchement de GEQO et la taille des stats (200 entrées me paraissent un bon paramétrage)
    2) diminuer le nombre des jointures
    3) passer à un autre SGBDR qui supporte sans broncher plusieurs dizaines de jointures (MS SQL Server ou Oracle...) !

    A +
    Frédéric Brouard - SQLpro - ARCHITECTE DE DONNÉES - expert SGBDR et langage SQL
    Le site sur les SGBD relationnels et le langage SQL: http://sqlpro.developpez.com/
    Blog SQL, SQL Server, SGBDR : http://blog.developpez.com/sqlpro
    Expert Microsoft SQL Server - M.V.P. (Most valuable Professional) MS Corp.
    Entreprise SQL SPOT : modélisation, conseils, audit, optimisation, formation...
    * * * * * Expertise SQL Server : http://mssqlserver.fr/ * * * * *
    Répondre avec citation Répondre avec citation   1  0
  3. 26/06/2013, 14h53 #3
    estofilo
    estofilo est déconnecté
    Membre Expert
    Profil pro
    Inscrit en
    Octobre 2008
    Messages
    1 874
    Détails du profil
    Informations personnelles :
    Localisation : France, Paris (Île de France)

    Informations forums :
    Inscription : Octobre 2008
    Messages : 1 874
    Par défaut
    Ce plan comporte beaucoup de conditions mais pas spécialement beaucoup de jointures.
    Le problème est surtout que le HashJoin et HashAggregate sur lesquels portent la question ne sont pas montrés.
    Apparemment l' EXPLAIN ANALYZE est incomplètement recopié.
    Répondre avec citation Répondre avec citation   1  0
ActualitésF.A.Q POSTGRESQLDOC POSTGRESQLTUTORIELS POSTGRESQLUDF POSTGRESQLLIVRES POSTGRESQL
« Discussion précédente | Discussion suivante »

Discussions similaires

  1. Daq toolbox : Analyse temps réel avec recouvrement.
    Par OReLo dans le forum Signal
    Réponses: 16
    Dernier message: 15/11/2010, 17h17
  2. Analyse Temps Frequence dB
    Par pamath dans le forum Signal
    Réponses: 1
    Dernier message: 20/06/2010, 20h39
  3. Outil automatique d'analyse d'EXPLAIN
    Par battistuta dans le forum DB2
    Réponses: 4
    Dernier message: 04/09/2008, 17h28
  4. [Recherche]Outil d'analyse de temps de code
    Par Spout dans le forum C++
    Réponses: 12
    Dernier message: 26/08/2008, 14h13
  5. Aide pour l'analyse d'un problème de gestion de temps
    Par PAINCO dans le forum Décisions SGBD
    Réponses: 8
    Dernier message: 03/06/2005, 15h49

Partager

Partager
  • Envoyer la discussion sur Viadeo
  • Envoyer la discussion sur Twitter
  • Envoyer la discussion sur Google
  • Envoyer la discussion sur Facebook
  • Envoyer la discussion sur Digg
  • Envoyer la discussion sur Delicious
  • Envoyer la discussion sur MySpace
  • Envoyer la discussion sur Yahoo