Postgres 解释分析在 pgAdmin 中花费的负时间

Postgres explain analyze negative time spent in pgAdmin

我 运行 使用 pgAdmin 对我的 postgres 数据库进行解释分析查询。

它创建了一个独占时间为负的可视化:

我认为“Gather Merge”的总时间低于其子“Group”,但如果我正确阅读了原始 postgres 输出,则事实并非如此。

[
  {
    "Plan": {
      "Node Type": "Result",
      "Parallel Aware": false,
      "Startup Cost": 5259558.14,
      "Total Cost": 5259558.24,
      "Plan Rows": 1,
      "Plan Width": 2,
      "Actual Startup Time": 2891.076,
      "Actual Total Time": 2925.989,
      "Actual Rows": 1,
      "Actual Loops": 1,
      "Output": [
        "(SubPlan 2)",
        "(SubPlan 3)"
      ],
      "Shared Hit Blocks": 16,
      "Shared Read Blocks": 605065,
      "Shared Dirtied Blocks": 0,
      "Shared Written Blocks": 0,
      "Local Hit Blocks": 0,
      "Local Read Blocks": 0,
      "Local Dirtied Blocks": 0,
      "Local Written Blocks": 0,
      "Temp Read Blocks": 0,
      "Temp Written Blocks": 0,
      "I/O Read Time": 1329.432,
      "I/O Write Time": 0,
      "Plans": [
        {
          "Node Type": "Group",
          "Parent Relationship": "InitPlan",
          "Subplan Name": "CTE foo",
          "Parallel Aware": false,
          "Startup Cost": 5255772.15,
          "Total Cost": 5259558.14,
          "Plan Rows": 4,
          "Plan Width": 2,
          "Actual Startup Time": 2851.957,
          "Actual Total Time": 2925.973,
          "Actual Rows": 3,
          "Actual Loops": 1,
          "Output": [
            "\"DailyRatePricingTable\".\"HasFlatPrices\"",
            "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
          ],
          "Group Key": [
            "\"DailyRatePricingTable\".\"HasFlatPrices\"",
            "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
          ],
          "Shared Hit Blocks": 16,
          "Shared Read Blocks": 605065,
          "Shared Dirtied Blocks": 0,
          "Shared Written Blocks": 0,
          "Local Hit Blocks": 0,
          "Local Read Blocks": 0,
          "Local Dirtied Blocks": 0,
          "Local Written Blocks": 0,
          "Temp Read Blocks": 0,
          "Temp Written Blocks": 0,
          "I/O Read Time": 1329.432,
          "I/O Write Time": 0,
          "Plans": [
            {
              "Node Type": "Gather Merge",
              "Parent Relationship": "Outer",
              "Parallel Aware": false,
              "Startup Cost": 5255772.15,
              "Total Cost": 5259558.1,
              "Plan Rows": 8,
              "Plan Width": 2,
              "Actual Startup Time": 2851.955,
              "Actual Total Time": 2925.966,
              "Actual Rows": 5,
              "Actual Loops": 1,
              "Output": [
                "\"DailyRatePricingTable\".\"HasFlatPrices\"",
                "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
              ],
              "Workers Planned": 2,
              "Workers Launched": 2,
              "Shared Hit Blocks": 16,
              "Shared Read Blocks": 605065,
              "Shared Dirtied Blocks": 0,
              "Shared Written Blocks": 0,
              "Local Hit Blocks": 0,
              "Local Read Blocks": 0,
              "Local Dirtied Blocks": 0,
              "Local Written Blocks": 0,
              "Temp Read Blocks": 0,
              "Temp Written Blocks": 0,
              "I/O Read Time": 1329.432,
              "I/O Write Time": 0,
              "Plans": [
                {
                  "Node Type": "Group",
                  "Parent Relationship": "Outer",
                  "Parallel Aware": false,
                  "Startup Cost": 5254772.12,
                  "Total Cost": 5258557.15,
                  "Plan Rows": 4,
                  "Plan Width": 2,
                  "Actual Startup Time": 2849.038,
                  "Actual Total Time": 2898.808,
                  "Actual Rows": 3,
                  "Actual Loops": 3,
                  "Output": [
                    "\"DailyRatePricingTable\".\"HasFlatPrices\"",
                    "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
                  ],
                  "Group Key": [
                    "\"DailyRatePricingTable\".\"HasFlatPrices\"",
                    "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
                  ],
                  "Shared Hit Blocks": 16,
                  "Shared Read Blocks": 605065,
                  "Shared Dirtied Blocks": 0,
                  "Shared Written Blocks": 0,
                  "Local Hit Blocks": 0,
                  "Local Read Blocks": 0,
                  "Local Dirtied Blocks": 0,
                  "Local Written Blocks": 0,
                  "Temp Read Blocks": 0,
                  "Temp Written Blocks": 0,
                  "I/O Read Time": 1329.432,
                  "I/O Write Time": 0,
                  "Workers": [
                    {
                      "Worker Number": 0,
                      "Actual Startup Time": 2848.861,
                      "Actual Total Time": 2913.74,
                      "Actual Rows": 4,
                      "Actual Loops": 1,
                      "Shared Hit Blocks": 8,
                      "Shared Read Blocks": 40501,
                      "Shared Dirtied Blocks": 0,
                      "Shared Written Blocks": 0,
                      "Local Hit Blocks": 0,
                      "Local Read Blocks": 0,
                      "Local Dirtied Blocks": 0,
                      "Local Written Blocks": 0,
                      "Temp Read Blocks": 0,
                      "Temp Written Blocks": 0,
                      "I/O Read Time": 92.497,
                      "I/O Write Time": 0
                    },
                    {
                      "Worker Number": 1,
                      "Actual Startup Time": 2847.78,
                      "Actual Total Time": 2912.523,
                      "Actual Rows": 3,
                      "Actual Loops": 1,
                      "Shared Hit Blocks": 8,
                      "Shared Read Blocks": 40588,
                      "Shared Dirtied Blocks": 0,
                      "Shared Written Blocks": 0,
                      "Local Hit Blocks": 0,
                      "Local Read Blocks": 0,
                      "Local Dirtied Blocks": 0,
                      "Local Written Blocks": 0,
                      "Temp Read Blocks": 0,
                      "Temp Written Blocks": 0,
                      "I/O Read Time": 92.609,
                      "I/O Write Time": 0
                    }
                  ],
                  "Plans": [
                    {
                      "Node Type": "Sort",
                      "Parent Relationship": "Outer",
                      "Parallel Aware": false,
                      "Startup Cost": 5254772.12,
                      "Total Cost": 5256033.8,
                      "Plan Rows": 504670,
                      "Plan Width": 2,
                      "Actual Startup Time": 2849.035,
                      "Actual Total Time": 2868.677,
                      "Actual Rows": 310993,
                      "Actual Loops": 3,
                      "Output": [
                        "\"DailyRatePricingTable\".\"HasFlatPrices\"",
                        "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
                      ],
                      "Sort Key": [
                        "\"DailyRatePricingTable\".\"HasFlatPrices\"",
                        "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
                      ],
                      "Sort Method": "quicksort",
                      "Sort Space Used": 31099,
                      "Sort Space Type": "Memory",
                      "Shared Hit Blocks": 16,
                      "Shared Read Blocks": 605065,
                      "Shared Dirtied Blocks": 0,
                      "Shared Written Blocks": 0,
                      "Local Hit Blocks": 0,
                      "Local Read Blocks": 0,
                      "Local Dirtied Blocks": 0,
                      "Local Written Blocks": 0,
                      "Temp Read Blocks": 0,
                      "Temp Written Blocks": 0,
                      "I/O Read Time": 1329.432,
                      "I/O Write Time": 0,
                      "Workers": [
                        {
                          "Worker Number": 0,
                          "Actual Startup Time": 2848.858,
                          "Actual Total Time": 2874.257,
                          "Actual Rows": 403788,
                          "Actual Loops": 1,
                          "Sort Method": "quicksort",
                          "Sort Space Used": 31232,
                          "Sort Space Type": "Memory",
                          "Shared Hit Blocks": 8,
                          "Shared Read Blocks": 40501,
                          "Shared Dirtied Blocks": 0,
                          "Shared Written Blocks": 0,
                          "Local Hit Blocks": 0,
                          "Local Read Blocks": 0,
                          "Local Dirtied Blocks": 0,
                          "Local Written Blocks": 0,
                          "Temp Read Blocks": 0,
                          "Temp Written Blocks": 0,
                          "I/O Read Time": 92.497,
                          "I/O Write Time": 0
                        },
                        {
                          "Worker Number": 1,
                          "Actual Startup Time": 2847.777,
                          "Actual Total Time": 2873.428,
                          "Actual Rows": 406553,
                          "Actual Loops": 1,
                          "Sort Method": "quicksort",
                          "Sort Space Used": 31361,
                          "Sort Space Type": "Memory",
                          "Shared Hit Blocks": 8,
                          "Shared Read Blocks": 40588,
                          "Shared Dirtied Blocks": 0,
                          "Shared Written Blocks": 0,
                          "Local Hit Blocks": 0,
                          "Local Read Blocks": 0,
                          "Local Dirtied Blocks": 0,
                          "Local Written Blocks": 0,
                          "Temp Read Blocks": 0,
                          "Temp Written Blocks": 0,
                          "I/O Read Time": 92.609,
                          "I/O Write Time": 0
                        }
                      ],
                      "Plans": [
                        {
                          "Node Type": "Bitmap Heap Scan",
                          "Parent Relationship": "Outer",
                          "Parallel Aware": true,
                          "Relation Name": "DailyRatePricingTable",
                          "Schema": "RateManager",
                          "Alias": "DailyRatePricingTable",
                          "Startup Cost": 2209995.05,
                          "Total Cost": 5206967.31,
                          "Plan Rows": 504670,
                          "Plan Width": 2,
                          "Actual Startup Time": 2486.18,
                          "Actual Total Time": 2779.302,
                          "Actual Rows": 404097,
                          "Actual Loops": 3,
                          "Output": [
                            "\"DailyRatePricingTable\".\"HasFlatPrices\"",
                            "\"DailyRatePricingTable\".\"HasOccupancyPrices\""
                          ],
                          "Recheck Cond": "(\"DailyRatePricingTable\".\"TenantId\" = '3eb2f28c-67aa-405d-9821-c9fc59de1501'::uuid)",
                          "Rows Removed by Index Recheck": 0,
                          "Exact Heap Blocks": 40808,
                          "Lossy Heap Blocks": 0,
                          "Shared Hit Blocks": 0,
                          "Shared Read Blocks": 605065,
                          "Shared Dirtied Blocks": 0,
                          "Shared Written Blocks": 0,
                          "Local Hit Blocks": 0,
                          "Local Read Blocks": 0,
                          "Local Dirtied Blocks": 0,
                          "Local Written Blocks": 0,
                          "Temp Read Blocks": 0,
                          "Temp Written Blocks": 0,
                          "I/O Read Time": 1329.432,
                          "I/O Write Time": 0,
                          "Workers": [
                            {
                              "Worker Number": 0,
                              "Actual Startup Time": 2485.217,
                              "Actual Total Time": 2779.164,
                              "Actual Rows": 404130,
                              "Actual Loops": 1,
                              "Shared Hit Blocks": 0,
                              "Shared Read Blocks": 40501,
                              "Shared Dirtied Blocks": 0,
                              "Shared Written Blocks": 0,
                              "Local Hit Blocks": 0,
                              "Local Read Blocks": 0,
                              "Local Dirtied Blocks": 0,
                              "Local Written Blocks": 0,
                              "Temp Read Blocks": 0,
                              "Temp Written Blocks": 0,
                              "I/O Read Time": 92.497,
                              "I/O Write Time": 0
                            },
                            {
                              "Worker Number": 1,
                              "Actual Startup Time": 2485.342,
                              "Actual Total Time": 2779.53,
                              "Actual Rows": 406879,
                              "Actual Loops": 1,
                              "Shared Hit Blocks": 0,
                              "Shared Read Blocks": 40588,
                              "Shared Dirtied Blocks": 0,
                              "Shared Written Blocks": 0,
                              "Local Hit Blocks": 0,
                              "Local Read Blocks": 0,
                              "Local Dirtied Blocks": 0,
                              "Local Written Blocks": 0,
                              "Temp Read Blocks": 0,
                              "Temp Written Blocks": 0,
                              "I/O Read Time": 92.609,
                              "I/O Write Time": 0
                            }
                          ],
                          "Plans": [
                            {
                              "Node Type": "Bitmap Index Scan",
                              "Parent Relationship": "Outer",
                              "Parallel Aware": false,
                              "Index Name": "PK_DailyRatePricingTable",
                              "Startup Cost": 0,
                              "Total Cost": 2209692.25,
                              "Plan Rows": 1211208,
                              "Plan Width": 0,
                              "Actual Startup Time": 2459.404,
                              "Actual Total Time": 2459.404,
                              "Actual Rows": 1213885,
                              "Actual Loops": 1,
                              "Index Cond": "(\"DailyRatePricingTable\".\"TenantId\" = '3eb2f28c-67aa-405d-9821-c9fc59de1501'::uuid)",
                              "Shared Hit Blocks": 0,
                              "Shared Read Blocks": 483154,
                              "Shared Dirtied Blocks": 0,
                              "Shared Written Blocks": 0,
                              "Local Hit Blocks": 0,
                              "Local Read Blocks": 0,
                              "Local Dirtied Blocks": 0,
                              "Local Written Blocks": 0,
                              "Temp Read Blocks": 0,
                              "Temp Written Blocks": 0,
                              "I/O Read Time": 1048.699,
                              "I/O Write Time": 0,
                              "Workers": []
                            }
                          ]
                        }
                      ]
                    }
                  ]
                }
              ]
            }
          ]
        },
        {
          "Node Type": "CTE Scan",
          "Parent Relationship": "SubPlan",
          "Subplan Name": "SubPlan 2",
          "Parallel Aware": false,
          "CTE Name": "foo",
          "Alias": "foo",
          "Startup Cost": 0,
          "Total Cost": 0.08,
          "Plan Rows": 4,
          "Plan Width": 1,
          "Actual Startup Time": 2851.959,
          "Actual Total Time": 2891.068,
          "Actual Rows": 3,
          "Actual Loops": 1,
          "Output": [
            "foo.\"HasFlatPrices\""
          ],
          "Shared Hit Blocks": 0,
          "Shared Read Blocks": 523976,
          "Shared Dirtied Blocks": 0,
          "Shared Written Blocks": 0,
          "Local Hit Blocks": 0,
          "Local Read Blocks": 0,
          "Local Dirtied Blocks": 0,
          "Local Written Blocks": 0,
          "Temp Read Blocks": 0,
          "Temp Written Blocks": 0,
          "I/O Read Time": 1144.327,
          "I/O Write Time": 0
        },
        {
          "Node Type": "CTE Scan",
          "Parent Relationship": "SubPlan",
          "Subplan Name": "SubPlan 3",
          "Parallel Aware": false,
          "CTE Name": "foo",
          "Alias": "foo_1",
          "Startup Cost": 0,
          "Total Cost": 0.08,
          "Plan Rows": 4,
          "Plan Width": 1,
          "Actual Startup Time": 0.001,
          "Actual Total Time": 0.001,
          "Actual Rows": 2,
          "Actual Loops": 1,
          "Output": [
            "foo_1.\"HasOccupancyPrices\""
          ],
          "Shared Hit Blocks": 0,
          "Shared Read Blocks": 0,
          "Shared Dirtied Blocks": 0,
          "Shared Written Blocks": 0,
          "Local Hit Blocks": 0,
          "Local Read Blocks": 0,
          "Local Dirtied Blocks": 0,
          "Local Written Blocks": 0,
          "Temp Read Blocks": 0,
          "Temp Written Blocks": 0,
          "I/O Read Time": 0,
          "I/O Write Time": 0
        }
      ]
    },
    "Planning": {
      "Shared Hit Blocks": 3,
      "Shared Read Blocks": 0,
      "Shared Dirtied Blocks": 0,
      "Shared Written Blocks": 0,
      "Local Hit Blocks": 0,
      "Local Read Blocks": 0,
      "Local Dirtied Blocks": 0,
      "Local Written Blocks": 0,
      "Temp Read Blocks": 0,
      "Temp Written Blocks": 0,
      "I/O Read Time": 0,
      "I/O Write Time": 0
    },
    "Triggers": []
  }
]

这有什么合理的解释吗? pgAdmin 可视化可以信任吗?

有一个类似的问题,但我没有看到那里解释了负值。

PostgreSQL 13.3 on aarch64-unknown-linux-gnu,由 gcc (GCC) 7.3.1 20180712 (Red Hat 7.3.1-6) 编译,64 位

PgAdmin 4.16

这是一个 pgAdmin 错误

pgAdmin 盲目地将执行时间与循环计数相乘,这对于嵌套循环来说没问题,但对于并行操作来说是错误的。所以“聚集”下面的数字高了三倍。