数据库CPU升高导致系统变卡的问题排查

一、问题描述
客户信息化平台系统卡顿,作业票无法使用,测试之后发现不仅仅是作业票无法使用,系统菜单点击后也不能快速跳转。

二、问题排查
第一步、查看系统日志
查看系统日志,一切正常。
第二步、查看进程信息
使用top命令查看进程的内存,cpu使用情况,发现mysql cpu一直在100%以上。

第三步、查看mysql process
使用show processlist 查看mysql正在运行的process执行情况。
由于在远程操作,看数据不方便,info的数据非常多,在远程看比较耗时间,个人一般使用 select * from information_schema.processlist;查询所有process的执行情况,导出excel到自己本地,也可以根据process执行的时间做排序。

从mysql运行的process list 可以看出两点问题:
1:执行时间最长的线程,锁了全部的数据库表

2:执行时间长的线程,几乎都是流程引擎相关的操作

第四步、查看线程快照
由于机器上面只部署了信息化平台一个服务,此时排查的方向转到了信息化平台
找到信息化平台的进程id 15211,使用jstack多次生成服务的线程快照。

从下图的线程快照及计数中可以看到,此时有7个线程在执行流程引擎的任务提交,这点也和mysql中process list中长时间执行的数据符合,有兴趣的伙伴可以到上一步导出的mysql processlist中数下时间较长的process数量也是7个。

从上面线程快照中,还能看到一个重要的信息,就是locked,说明由于数据库锁全表导致作业票提交失败。

从这一步结论可以间接的推断,导致问题的原因不是作业票引起,而是引起数据库锁表的这个行为影响了作业票的提交。
为了确保细节不被遗漏,逐个看了一遍线程快照中包含wwyt(信息化平台包名)代码方法的线程,并通过几次线程快照的对比,发现并没有其它阻塞的线程。

第五步、查看mysql 事务列表
到这里问题的源头又来到了数据库。为什么又要去看数据库,去看数据库哪里,因为我看到这么多submit task 想到了Innodb的事务列表,看看数据库现在有那些事务在处理中,通过事务的列表看看能不能发现一些有价值的信息。

mysql Innodb的运行事务列表在information_schema下面的 INNODB_TRX中,使用客户端工具打开表后,问题显现出来。
线程id是57的更新监测点数据语句的权重达到了2500多万(被锁定的行数,数量不一定准确,见下图),我们线上使用的mysql版本是5.7,从官方文档看到权重的解释如下:
information-schema-innodb-trx

我们再通过show processlist查看线程id 57 对应的连接信息及用户,到此问题已经找到。

这里有个小问题需要注意:我们再看下这个process 的Time字段值是0,因为这个peocess的时间没有没mysql记录到,我们在排查过程中也要引起重视。排查过程当然也可以使用其它的工具,对工具不做要求。

三、解决问题及后续跟踪
和同事沟通之后得知,这个监测点的数据是客户自己的程序写入的,我们提供数据表。在沟通之后。可以kill掉这个process,用户急着用系统,当kill掉process后,页面弹出用户使用的程序信息。

项目开始逐渐恢复正常,这个事务也在回滚数据,这是一段时间之后的截图,被锁的数据由2500多万变为600多万,直至为0。这个问题后续还需要继续跟进,在客户处理好之前,可能会反复出现,需要尽快沟通。

创建人:张光良

转载请注明作者和出处,并添加本页链接。
原文链接: //svn.seekcy.com:33382/461