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

有时候需要进行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