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 07/06/2021 20:17:50

jolafrite
Membre

Interprétation explain analyze

Bonjour. Assez régulièrement j'ai un execution time inférieur au slowest node

Ici par exemple temps d'exécution 1,02 seconde alors que le plus lent node prend 1.07 seconde. Je n'ai plus le plan sous la main mais j'ai déjà eu une différence encore plus grande genre 1 seconde de différence.

[
  {
    "Plan": {
      "Node Type": "Aggregate",
      "Strategy": "Sorted",
      "Partial Mode": "Finalize",
      "Parallel Aware": false,
      "Async Capable": false,
      "Startup Cost": 19615.22,
      "Total Cost": 19739.9,
      "Plan Rows": 981,
      "Plan Width": 45,
      "Actual Startup Time": 779.342,
      "Actual Total Time": 1009.576,
      "Actual Rows": 169016,
      "Actual Loops": 1,
      "Group Key": [
        "a.translation",
        "b.translation",
        "c.translation",
        "document.establishing_date"
      ],
      "Plans": [
        {
          "Node Type": "Gather Merge",
          "Parent Relationship": "Outer",
          "Parallel Aware": false,
          "Async Capable": false,
          "Startup Cost": 19615.22,
          "Total Cost": 19719.86,
          "Plan Rows": 818,
          "Plan Width": 45,
          "Actual Startup Time": 779.339,
          "Actual Total Time": 936.264,
          "Actual Rows": 242644,
          "Actual Loops": 1,
          "Workers Planned": 2,
          "Workers Launched": 2,
          "Plans": [
            {
              "Node Type": "Aggregate",
              "Strategy": "Sorted",
              "Partial Mode": "Partial",
              "Parent Relationship": "Outer",
              "Parallel Aware": false,
              "Async Capable": false,
              "Startup Cost": 18615.2,
              "Total Cost": 18625.42,
              "Plan Rows": 409,
              "Plan Width": 45,
              "Actual Startup Time": 699.582,
              "Actual Total Time": 766.359,
              "Actual Rows": 80881,
              "Actual Loops": 3,
              "Group Key": [
                "a.translation",
                "b.translation",
                "c.translation",
                "document.establishing_date"
              ],
              "Workers": [],
              "Plans": [
                {
                  "Node Type": "Sort",
                  "Parent Relationship": "Outer",
                  "Parallel Aware": false,
                  "Async Capable": false,
                  "Startup Cost": 18615.2,
                  "Total Cost": 18616.22,
                  "Plan Rows": 409,
                  "Plan Width": 41,
                  "Actual Startup Time": 699.572,
                  "Actual Total Time": 716.065,
                  "Actual Rows": 134557,
                  "Actual Loops": 3,
                  "Sort Key": [
                    "a.translation COLLATE \"C\"",
                    "b.translation COLLATE \"C\"",
                    "c.translation COLLATE \"C\"",
                    "document.establishing_date"
                  ],
                  "Sort Method": "quicksort",
                  "Sort Space Used": 20263,
                  "Sort Space Type": "Memory",
                  "Workers": [
                    {
                      "Worker Number": 0,
                      "Sort Method": "quicksort",
                      "Sort Space Used": 13859,
                      "Sort Space Type": "Memory"
                    },
                    {
                      "Worker Number": 1,
                      "Sort Method": "quicksort",
                      "Sort Space Used": 13903,
                      "Sort Space Type": "Memory"
                    }
                  ],
                  "Plans": [
                    {
                      "Node Type": "Hash Join",
                      "Parent Relationship": "Outer",
                      "Parallel Aware": false,
                      "Async Capable": false,
                      "Join Type": "Inner",
                      "Startup Cost": 369.37,
                      "Total Cost": 18597.45,
                      "Plan Rows": 409,
                      "Plan Width": 41,
                      "Actual Startup Time": 5.025,
                      "Actual Total Time": 358.178,
                      "Actual Rows": 134557,
                      "Actual Loops": 3,
                      "Inner Unique": false,
                      "Hash Cond": "(document.redaction_place_code = (b.val)::integer)",
                      "Workers": [],
                      "Plans": [
                        {
                          "Node Type": "Hash Join",
                          "Parent Relationship": "Outer",
                          "Parallel Aware": false,
                          "Async Capable": false,
                          "Join Type": "Inner",
                          "Startup Cost": 221.84,
                          "Total Cost": 18337.94,
                          "Plan Rows": 97,
                          "Plan Width": 34,
                          "Actual Startup Time": 1.526,
                          "Actual Total Time": 260.962,
                          "Actual Rows": 134557,
                          "Actual Loops": 3,
                          "Inner Unique": false,
                          "Hash Cond": "(\"left\"(document.basis, 1) = c.val)",
                          "Workers": [],
                          "Plans": [
                            {
                              "Node Type": "Hash Join",
                              "Parent Relationship": "Outer",
                              "Parallel Aware": false,
                              "Async Capable": false,
                              "Join Type": "Inner",
                              "Startup Cost": 111.08,
                              "Total Cost": 17409.83,
                              "Plan Rows": 13062,
                              "Plan Width": 25,
                              "Actual Startup Time": 0.754,
                              "Actual Total Time": 199.868,
                              "Actual Rows": 134557,
                              "Actual Loops": 3,
                              "Inner Unique": false,
                              "Hash Cond": "(document.doc_type = (a.val)::smallint)",
                              "Workers": [],
                              "Plans": [
                                {
                                  "Node Type": "Index Scan",
                                  "Parent Relationship": "Outer",
                                  "Parallel Aware": true,
                                  "Async Capable": false,
                                  "Scan Direction": "Forward",
                                  "Index Name": "idx_doc_docst",
                                  "Relation Name": "document",
                                  "Alias": "document",
                                  "Startup Cost": 0.42,
                                  "Total Cost": 15535.84,
                                  "Plan Rows": 163271,
                                  "Plan Width": 16,
                                  "Actual Startup Time": 0.033,
                                  "Actual Total Time": 129.7,
                                  "Actual Rows": 134557,
                                  "Actual Loops": 3,
                                  "Filter": "((establishing_date <= '2021-01-01'::date) AND (establishing_date >= '2020-01-01'::date))",
                                  "Rows Removed by Filter": 154106,
                                  "Workers": []
                                },
                                {
                                  "Node Type": "Hash",
                                  "Parent Relationship": "Inner",
                                  "Parallel Aware": false,
                                  "Async Capable": false,
                                  "Startup Cost": 110.46,
                                  "Total Cost": 110.46,
                                  "Plan Rows": 16,
                                  "Plan Width": 16,
                                  "Actual Startup Time": 0.685,
                                  "Actual Total Time": 0.686,
                                  "Actual Rows": 16,
                                  "Actual Loops": 3,
                                  "Hash Buckets": 1024,
                                  "Original Hash Buckets": 1024,
                                  "Hash Batches": 1,
                                  "Original Hash Batches": 1,
                                  "Peak Memory Usage": 9,
                                  "Workers": [],
                                  "Plans": [
                                    {
                                      "Node Type": "Seq Scan",
                                      "Parent Relationship": "Outer",
                                      "Parallel Aware": false,
                                      "Async Capable": false,
                                      "Relation Name": "label2",
                                      "Alias": "a",
                                      "Startup Cost": 0,
                                      "Total Cost": 110.46,
                                      "Plan Rows": 16,
                                      "Plan Width": 16,
                                      "Actual Startup Time": 0.659,
                                      "Actual Total Time": 0.664,
                                      "Actual Rows": 16,
                                      "Actual Loops": 3,
                                      "Filter": "((lang = 1) AND (type = 23))",
                                      "Rows Removed by Filter": 6748,
                                      "Workers": []
                                    }
                                  ]
                                }
                              ]
                            },
                            {
                              "Node Type": "Hash",
                              "Parent Relationship": "Inner",
                              "Parallel Aware": false,
                              "Async Capable": false,
                              "Startup Cost": 110.46,
                              "Total Cost": 110.46,
                              "Plan Rows": 24,
                              "Plan Width": 16,
                              "Actual Startup Time": 0.716,
                              "Actual Total Time": 0.717,
                              "Actual Rows": 24,
                              "Actual Loops": 3,
                              "Hash Buckets": 1024,
                              "Original Hash Buckets": 1024,
                              "Hash Batches": 1,
                              "Original Hash Batches": 1,
                              "Peak Memory Usage": 10,
                              "Workers": [],
                              "Plans": [
                                {
                                  "Node Type": "Seq Scan",
                                  "Parent Relationship": "Outer",
                                  "Parallel Aware": false,
                                  "Async Capable": false,
                                  "Relation Name": "label2",
                                  "Alias": "c",
                                  "Startup Cost": 0,
                                  "Total Cost": 110.46,
                                  "Plan Rows": 24,
                                  "Plan Width": 16,
                                  "Actual Startup Time": 0.017,
                                  "Actual Total Time": 0.703,
                                  "Actual Rows": 24,
                                  "Actual Loops": 3,
                                  "Filter": "((lang = 1) AND (type = 4))",
                                  "Rows Removed by Filter": 6740,
                                  "Workers": []
                                }
                              ]
                            }
                          ]
                        },
                        {
                          "Node Type": "Hash",
                          "Parent Relationship": "Inner",
                          "Parallel Aware": false,
                          "Async Capable": false,
                          "Startup Cost": 110.46,
                          "Total Cost": 110.46,
                          "Plan Rows": 2965,
                          "Plan Width": 16,
                          "Actual Startup Time": 3.45,
                          "Actual Total Time": 3.45,
                          "Actual Rows": 2965,
                          "Actual Loops": 3,
                          "Hash Buckets": 4096,
                          "Original Hash Buckets": 4096,
                          "Hash Batches": 1,
                          "Original Hash Batches": 1,
                          "Peak Memory Usage": 173,
                          "Workers": [],
                          "Plans": [
                            {
                              "Node Type": "Seq Scan",
                              "Parent Relationship": "Outer",
                              "Parallel Aware": false,
                              "Async Capable": false,
                              "Relation Name": "label2",
                              "Alias": "b",
                              "Startup Cost": 0,
                              "Total Cost": 110.46,
                              "Plan Rows": 2965,
                              "Plan Width": 16,
                              "Actual Startup Time": 0.35,
                              "Actual Total Time": 1.567,
                              "Actual Rows": 2965,
                              "Actual Loops": 3,
                              "Filter": "((lang = 1) AND (type = 16))",
                              "Rows Removed by Filter": 3799,
                              "Workers": []
                            }
                          ]
                        }
                      ]
                    }
                  ]
                }
              ]
            }
          ]
        }
      ]
    },
    "Planning Time": 1.011,
    "Triggers": [],
    "Execution Time": 1015.308
  }
]

Savez-vous ce qui se passe ? Ma query dure combien de temps alors en réalité ?

Hors ligne

#2 07/06/2021 20:18:50

jolafrite
Membre

Re : Interprétation explain analyze

J'utilise http://tatiyants.com/pev/#/plans/new

C'ets le site qui est bugué peut-être ?

Hors ligne

#3 07/06/2021 20:39:09

rjuju
Administrateur

Re : Interprétation explain analyze

"Execution Time": 1015.308

Ma query dure combien de temps alors en réalité ?

1015.308 ms.

Hors ligne

#4 08/06/2021 08:11:26

ruizsebastien
Membre

Re : Interprétation explain analyze

Bonjour,

De mémoire PEV n'est plus maintenu et/ou est obsolete.
A la place vous pouvez utiliser PEV2 :
https://github.com/dalibo/pev2 (en local)
https://explain.dalibo.com/  (en ligne)


Cordialement,

Sébastien.

Hors ligne

#5 08/06/2021 08:40:15

rjuju
Administrateur

Hors ligne

#6 08/06/2021 09:21:10

gleu
Administrateur

Re : Interprétation explain analyze

Le nœud que PEV indique à 1.07s est le nœud Sort. Or ce nœud, d'après le JSON fourni, est en fait à 716ms. Donc, j'ai bien peur que ce soit un bug de PEV. Il est à noter que cet outil n'est plus maintenu. Pierre, qui maintient PEV2, a essayé de contacter l'auteur mais sans succès, ce qui l'a amené à développer PEV2. Mon conseil est d'abandonner PEV, et de passer soit à explain.depesz.com soit à explain.dalibo.com (qui utilise PEV2, même auteur). Si vous appréciez PEV, autant passer à PEV2. Mais les deux sont possibles.


Guillaume.

Hors ligne

Pied de page des forums