一、重点参数说明
·auto_explain.log_min_duration
该参数主要用于决定执行耗时超过多长时间的 SQL 语句会被记录执行计划。默认为-1,代表不记录。自定义范围500-60000 ,单位为毫秒。
·auto_explain.log_analyze
加此参数可以打印执行计划的实际执行时间。默认 off ,关闭状态。
·auto_explain.log_timing
加此参数可以打印语句执行时间。默认 off ,关闭状态。
·auto_explain.log_verbose
加此参数可以增加 explain 中 verbose 信息输出,获得更详细的执行计划信息。默认 off ,关闭状态。
二、示例说明
假如实例中有 database a_all,该 database 的 public 模式下有10张表格,分别为:student_info_b0、student_info_b1、student_info_b2、student_info_b3、student_info_b4、student_info_b5、student_info_b6、student_info_b7、student_info_b8、student_info_b9
当前云数据库 PostgreSQL 实例已经开启了 auto_explain 插件。其参数值如下:
a_all=> show auto_explain.log_min_duration; auto_explain.log_min_duration ——————————- 800ms(1 row)a_all=> show auto_explain.log_analyze; auto_explain.log_analyze ————————– on(1 row)a_all=> show auto_explain.log_verbose; auto_explain.log_verbose ————————– on(1 row)a_all=> show auto_explain.log_timing; auto_explain.log_timing ————————- on(1 row)
执行如下语句:
SELECT user_id, COUNT(*) OVER (PARTITION BY user_id) as count FROM ( SELECT user_id FROM student_info_b0 UNION ALL SELECT user_id FROM student_info_b1 UNION ALL SELECT user_id FROM student_info_b2 UNION ALL SELECT user_id FROM student_info_b3 UNION ALL SELECT user_id FROM student_info_b4 UNION ALL SELECT user_id FROM student_info_b5 UNION ALL SELECT user_id FROM student_info_b6 UNION ALL SELECT user_id FROM student_info_b7 UNION ALL SELECT user_id FROM student_info_b8 UNION ALL SELECT user_id FROM student_info_b9) AS all_students;
在 云数据库 PostgreSQL 的控制台 看到的慢日志记录如下:
下载的 auto_explain 日志中执行计划如下:
duration: 147.603 ms plan:Query Text: SELECT user_id, COUNT(*) OVER (PARTITION BY user_id) as countFROM ( SELECT user_id FROM student_info_b0 UNION ALL SELECT user_id FROM student_info_b1 UNION ALL SELECT user_id FROM student_info_b2 UNION ALL SELECT user_id FROM student_info_b3 UNION ALL SELECT user_id FROM student_info_b4 UNION ALL SELECT user_id FROM student_info_b5 UNION ALL SELECT user_id FROM student_info_b6 UNION ALL SELECT user_id FROM student_info_b7 UNION ALL SELECT user_id FROM student_info_b8 UNION ALL SELECT user_id FROM student_info_b9) AS all_students;WindowAgg (cost=19181.71..21924.66 rows=156740 width=14) (actual time=56.009..116.522 rows=157000 loops=1) Output: student_info_b0.user_id, count(*) OVER (?) -> Sort (cost=19181.71..19573.56 rows=156740 width=6) (actual time=55.956..72.756 rows=157000 loops=1) Output: student_info_b0.user_id Sort Key: student_info_b0.user_id Sort Method: external merge Disk: 2448kB -> Append (cost=0.00..3511.10 rows=156740 width=6) (actual time=0.010..20.861 rows=157000 loops=1) -> Seq Scan on public.student_info_b0 (cost=0.00..272.74 rows=15674 width=4) (actual time=0.009..1.367 rows=15700 loops=1) Output: student_info_b0.user_id -> Seq Scan on public.student_info_b1 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.005..1.302 rows=15700 loops=1) Output: student_info_b1.user_id -> Seq Scan on public.student_info_b2 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.004..1.316 rows=15700 loops=1) Output: student_info_b2.user_id -> Seq Scan on public.student_info_b3 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.005..1.318 rows=15700 loops=1) Output: student_info_b3.user_id -> Seq Scan on public.student_info_b4 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.006..1.320 rows=15700 loops=1) Output: student_info_b4.user_id -> Seq Scan on public.student_info_b5 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.005..1.294 rows=15700 loops=1) Output: student_info_b5.user_id -> Seq Scan on public.student_info_b6 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.004..1.377 rows=15700 loops=1) Output: student_info_b6.user_id -> Seq Scan on public.student_info_b7 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.005..1.327 rows=15700 loops=1) Output: student_info_b7.user_id -> Seq Scan on public.student_info_b8 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.006..1.285 rows=15700 loops=1) Output: student_info_b8.user_id -> Seq Scan on public.student_info_b9 (cost=0.00..272.74 rows=15674 width=6) (actual time=0.004..1.293 rows=15700 loops=1) Output: student_info_b9.user_id
如此,我们能清晰的查看该慢 SQL 的详细执行计划,并进行后续的业务分析。