1. bug现场情况
部署的是Java应用,容器中间件使用的是IBM WebSphere,数据库使用的是IBM DB2,数据源使用的是容器中间件提供的JNDI数据源服务。
程序在上班前的一段时间点击报错mybatis查询失败(sqlcode=-774 sqlstate=2D522),上班之后就恢复正常了。生产环境的日志没有有效的信息,全是-774的报错,而把报错的sql拿出来在数据库执行没有问题,并且同样的sql在客户上班后系统中执行没有问题。
粗略在网上查一下,DB2数据库sqlcode=-774的含义是:Explanation: Statement cannot be executed within a compound SQL statement.,意思是语句不能在复合sql中执行;sqlstate=2D522的含义是: ATOMIC 复合语句中不允许 COMMIT 和 ROLLBACK。初步的判断可能和数据库的事务相关。
2. 尝试破案
日志中没有有效的报错信息,只能先观察程序表象。发现,报错的现象在中午13:00之后是能够稳定复现的,在14:30之后就稳定消失。问题出现的时候,随意刷新页面就会报错,具体后台就是-774,也就是mybatis执行sql不成功。而14:30之后,随便刷新页面都不会出现问题,即使客户端并发多个请求造成响应慢但是也不会出现报错-774。如果在报错这段时间重启了应用程序,则报错就会消失。
从以上信息,大概估计,问题应该是出现在了数据库连接池上。在某个时刻,程序用数据库连接池中的连接执行了某些操作,该数据库连接就处于了异常状态,其他任何功能用到该异常数据库连接执行sql时,就会报错,不是数据库有什么问题,而是连接数据库的数据库连接有问题。这样设想也解释了两点,第一:为什么同样的sql、同一时刻在程序中执行就会报错,而拿出来到数据库客户端中执行就没有问题;第二:程序报错的时候重启,重启后为什么就正常了。原因都是报错来自于用到了数据库连接池中异常的数据库连接。
那具体是什么样的操作造成了数据库连接池连接的异常呢?正常在日志中应该有所体现才对,生产环境IBM Websphere的日志太不方便看了,并且也没法设置参数重启进行监控。研究决定将生产环境迁移出来一份作为测试环境。原来容器中间件为IBM WebSphere迁移到Tomcat上。
迁移完成后程序运行一段时间后查看日志,发现最先开始报错的日志有如下内容:Processing was cancelled ... SQLSTATE=57014,日志显示在执行一个存储过程的时候,由于某种原因(可能是时间过长)客户端主动取消了。后来在网上查到了IBM官方的一个帖子:www.ibm.com/support/pag…。心里一下子豁然开朗了,这不就是DB2的一个bug吗?
IBM官方帖子说:在DB2版本9上有一个bug,如果你在一个数据库连接中执行一个存储过程,因为某种原因客户端取消了,这时候在这个连接上执行的任何sql都会报错-774。官方还提供了bug的补丁包。果然,找到报错的存储过程,处理之后,后续程序就没有出现过问题了。
这下找到了是什么样的操作导致数据库连接池中的连接异常了,就是DB2数据库的一个bug(存储过程被客户端取消后,使用同一连接执行sql都会报错-774),DB2在后续高版本上解决了这个bug。
3. 破案绊脚石
3.1 Tomcat JNDI容器数据源的配置
1). 配置server.xml中Resource。在GlobalNamingResources节点下增加节点Resource:
特别声明:文章来源用户上传并发布,本站只提供信息存储服务,不拥有所有权,内容仅供参考。