前言
这两天处理了一起SQL问题,结果很坑人,但是过程还是值得分享,经验+99
问题现象
每天凌晨,业务会触发定时任务,跑一批SQL,但每次跑到一组参数时,便会跑很久,跑8个小时左右,导致业务超时报错,并且可以稳定复现,只要传入参数的是上述组合,便会超时报错。
分析过程
业务传入的参数中每次固定3个参数,总共60条,出问题的参数会固定在第19条。所以很容易想到的第一个原因便是绑定变量了,也就是prepareStatement,通常一条SQL在执行时分为语义解析、查询重写、生成所有可选执行路径、选择最优路径等多个步骤。对于同一类SQL,只是更换SQL中的一些变量时,语义解析、查询重写、生成执行计划等这些步骤其实都是可共享的,这也正是prepareStatement的目的,避免SQL反复解析,但是可能导致后面的SQL延用了之前的执行计划,出现错误的执行计划。所以,询问开发是否关闭了prepareStatement,也即prepareThreshold=0,默认是5,这样每次都会硬解析。但是开发反馈很早就配置了该参数,所以不是绑定变量的问题。甚至不死心,还尝试在服务端使用预备语句,也未能复现。
排除了绑定变量的问题之后,再看一下是否是执行计划的问题。将SQL拿到之后,去server端执行,很不幸,7s就出来了。于是将出问题时的执行计划和我在server端跑的执行计划拿出来对比,但更不幸的是,这条SQL由于需要跑8个小时,在我们的环境里有个限制,架构如下:
PostgreSQL server <——> load balance <——> 业务
由于这条SQL要跑8小时才能返回结果集,而业务端超过2小时处于idle的状态,于是load balance将连接都给你干掉了,由于server端并没有cancel掉相应任务,最终执行完成之后,要将结果返回时,报错"could not send data to client: Broken pipe",并且auto_explain插件由于报错,就没有将执行计划打印出来。。这就十分尴尬了,拿不到执行计划,所以最后决策,只能上pg_show_plans了,该插件通过HOOK可以抓取正在跑的SQL的执行计划,通过一番折腾之后,顺利安装上了,然后就又是一个晚上(要重启,只能申请窗口在夜里操作)。
第二天,不出所料,同样卡住了,通过pg_show_plans终于抓到了执行计划,通过对比,可以发现跑不出来的执行计划采用了nest loop,而手动在服务端跑的时候,采用的是Hash left join,但是为什么JDBC的执行计划和服务端的执行计划不一样呢?莫非是JDBC端设置了什么参数?检查了JDBC的配置之后,发现很简单
jdbc:postgresql://xxx/connectTimeout=5&prepareThreshold=0&targetServerType=master
然后又去JDBC的官网找了一遍,https://jdbc.postgresql.org/documentation/head/connect.html#connection-parameters,也没有发现什么参数有价值。
然后就是各种调参,设想,莫非是work_mem太小了?或者是JDBC的bug?但都未能复现,正当我难受之际,想起了之前的一例生产问题(权限导致),参照之前的《不同用户的执行计划居然不一样?》,关键的点在于是不同的用户!隐隐感觉有点不妙,我一直是用的postgres的超级用户在那里折腾!所以切换成了业务用户,再次查看执行计划,果然,也走了nest loop,跑不出来。
于是查看了一下pg_users视图
postgres=# select * from pg_user;
usename | usesysid | usecreatedb | usesuper | userepl | usebypassrls | passwd | valuntil | useconfig
----------+----------+-------------+----------+---------+--------------+----------+----------+----------------
postgres | 10 | t | t | t | t | ******** | |
mydbdata | 16487 | f | f | f | f | ******** | |
myuser | 24991 | f | f | f | f | ******** | | {work_mem=4MB}
(3 rows)
惊呆了,业务用户居然被限制了work_mem = 4MB,优化器当然认为走nest loop比hash join快了,不然hash join要频繁溢出到磁盘,多个batch,肯定不如nest loop快了。
通过reset之后,执行计划一样了,使用了hash join,瞬间通透了。
postgres=# alter user myuser reset all;
ALTER ROLE
postgres=# select * from pg_user;
usename | usesysid | usecreatedb | usesuper | userepl | usebypassrls | passwd | valuntil | useconfig
----------+----------+-------------+----------+---------+--------------+----------+----------+-----------
postgres | 10 | t | t | t | t | ******** | |
mydbdata | 16487 | f | f | f | f | ******** | |
myuser | 24991 | f | f | f | f | ******** | |
(3 rows)
小结
其实这起SQL问题,查明最终的原因之后,也就那样,最开始甚至想使用pg_hint_plan或者sr_plan来固化执行计划,最后却是这么坑人的结果。不过,还是学习到了不少经验。要进行复现,一定要保证各项条件、基准等严格一致,最开始的分析就是因为一直使用postgres用户在操作,而业务用的用户是xxxopr,这个也是测试标准化的基本准则:所有接受测量的个人必须在相同的施测条件下接受测验。