GaussDB(DWS)性能场景之存储过程慢怎么办

1. 前言

用户在使用GaussDB(DWS)进行存储过程的开发和调度时，可能会出现存储过程执行偶发慢的情况。对于一些开发比较规范的业务，存储过程中的每一个关键步骤都会对时间戳进行日志表保存，可以很方便的定位到存储过程中哪一条语句执行慢。但是对于一些没有时间戳记录的业务，存储过程中可能包含很多复杂语句，当出现存储过程执行慢，尤其是偶发慢的情况下，如何快速定位到慢的子语句是什么呢？本文根据TopSql的子语句记录功能，教大家根据TopSql定位此类问题。

使用历史topsql功能定位存储过程慢问题需要设置如下参数（8.1.3版本建议按照下列推荐值设置，8.1.3之前的版本根据实际情况设置）：

enable_resource_track: on（表示开启topsql功能）

enable_resource_record: on（表示开启topsql的转储功能，可以查到历史topsql）

enable_track_record_subsql: on（本场景的关键参数，表示可以记录存储过程中的内部语句）

resource_track_cost: 0（执行代价大于resource_track_cost的作业会被记录，设置为0表示除特殊数据定义语句外（SET、SHOW、ALTER、DROP等），可以记录所有DML/SELECT等语句）

resource_track_duration: 0（执行时间大于resource_track_duration的作业会被记录，设置为0表示除特殊数据定义语句外（SET、SHOW、ALTER、DROP等），可以记录所有DML/SELECT等语句）

2. 使用历史TOPSQL定位存储过程慢场景的使用示例

现有存储过程定义如下，现在发现执行select slow_test('2022-01-01')场景偶发慢，平常执行时间在1s内完成，12号晚上执行时间将近20s，定位思路如下：

第一步：根据慢的存储过程名字和时间范围在topsql中获取queryid

select * from pgxc_wlm_session_info where start_time > 'xxxx-xx-xx' and start_time < 'xxxx-xx-xx' and query like '%存储过程名%';

从上述信息可以看到，topsql中block_time为0，duration为18.968s，说明没有发生排队耗时，可以确定是存储过程本身慢。记录该存储过程的queryid信息。

第二步：根据queryid找到存储过程中每个子语句的执行时间

select * from pgxc_wlm_session_info where queryid = xxx order by duration desc;

从上图可以看到，在本例中，子语句里最耗时的sql是存储过程中第三条insert语句，耗时18.925ms，将近占了存储过程中所有语句的总耗时。

第三步：根据子语句执行时间，定位到慢的子语句的执行计划

找到存储过程中耗时最长的子语句后，可以找到该语句的内存、CPU时间、下盘、执行计划等信息。本例中未发生下盘和CPU时间倾斜，执行计划如下：

第四步：根据该执行计划，对子语句进行优化

获取执行计划的信息后，就可以根据执行计划对sql进行优化。本例中可以看到，基表t1和t2的行数估算都为1行，两表join走了nestloop计划，因此怀疑是统计信息不准导致的作业慢。对t2和t1表analyze后，该作业执行时间恢复到毫秒级，问题解决。

3. 总结

通过开启enable_track_record_subsql，可以很方便的根据topsql快速定位到存储过程中最耗时的子语句，从而将存储过程慢的问题转化为单sql调优问题。单sql调优问题可参考：https://bbs.huaweicloud.com/blogs/163514