Postgresql：查看执行一条SQL语句所用的时间及过程摘要

红太狼 2022-12-25 12:52 163阅读 0赞

有时候需要进行SQL语句的优化，这时就需要先分析一下语句的执行情况：

### 我们得知道语句执行花了多少时间，以及语句执行的过程。 ###

主要是使用`EXPLAIN`命令，

现在我有一个存放用户登录记录的表`login_records`，其中有100万条数据：

SELECT COUNT(1) FROM "user"."login_records" WHERE "user_id" = 1000;

查询一下表的行数，结果：

count
    ---------
     1000000
    (1 row)

那么，我执行上面这条SQL语句花费了多长时间呢？

### 在Postgresql中想要查看一条SQL语句的执行时间，可以使用`EXPLAIN ANALYZE`，就像这样： ###

EXPLAIN ANALYZE
    SELECT COUNT(1) FROM "user"."login_records" WHERE "user_id" = 1000;

执行结果：

QUERY PLAN
    ------------------------------------------------------------
     Finalize Aggregate  (cost=24938.42..24938.43 rows=1 width=8) (actual time=180.381..183.104 rows=1 loops=1)
       ->  Gather  (cost=24938.21..24938.42 rows=2 width=8) (actual time=117.553..183.099 rows=3 loops=1)
             Workers Planned: 2
             Workers Launched: 2
             ->  Partial Aggregate  (cost=23938.21..23938.22 rows=1 width=8) (actual time=65.535..65.535 rows=1 loops=3)
                   ->  Parallel Seq Scan on login_records  (cost=0.00..22955.51 rows=393080 width=0) (actual time=0.021..53.224 rows=333333 loops=3)
                         Filter: (user_id = 1000)
     Planning Time: 0.052 ms
     Execution Time: 183.125 ms
    (9 rows)
    
    EXPLAIN

可以看到，Postgresql为我们输出了一个**查询计划树**。包括最上面一行，以及 `->` 箭头所指的就是每个查询节点了。

上面输出结果中的`Execution Time`正是我们SQL语句的**执行时间**，可以看到是 `183.125 ms`。  
而`Planning time`则是SQL语句生成**查询计划**所花费的时间，为 `0.052 ms`。

值得注意的是，我们的SQL语句是按照查询计划树**从底部至顶部执行**的，你仔细看就能发现，位于下面的查询节点的`actual time`（执行时间段）总是比上面的要小。

各个查询节点从下至上运行的时间段（ms）：

节点4：actual time=180.381..183.104
    节点3：actual time=117.553..183.099
    节点2：actual time=65.535..65.535
    节点1：actual time=0.021..53.224

现在我们以节点1为例：

->  Parallel Seq Scan on login_records  (cost=0.00..22955.51 rows=393080 width=0) (actual time=0.021..53.224 rows=333333 loops=3)
          Filter: (user_id = 1000)

`Seq Scan` 表示对数据表的**顺序扫描**，这是无索引情况下的整表扫描。

`cost` 表示节点的**预估代价**，rows是预估行数，width是预估结果的宽度（字节）。

`actual time` 表示节点的**执行时间**，格式是`开始`…`结束`（毫秒），可以看出，这个节点花费了约53毫秒执行。

`Filter` 表示**过滤条件**，这里是 `user_id = 1000`

--------------------

简单介绍就到这里了！  
Postgresql `EXPLAIN` 命令官方英文文档：[https://www.postgresql.org/docs/11/using-explain.html][https_www.postgresql.org_docs_11_using-explain.html]

[https_www.postgresql.org_docs_11_using-explain.html]: https://www.postgresql.org/docs/11/using-explain.html