性能文章>Mysql服务器CPU利用率过高分析>

Mysql服务器CPU利用率过高分析原创

2年前
389347

问题反馈

测试小伙伴反应在压测的时候,响应时间很长。监听服务器资源的时候发现Mysql的cpu利用率非常高,物理核差不多快打满了,找不到原因,很着急
image.png
性能测试知识库

问题分析

Mysql线程的R队列很长,基本可以判断是处于一个线程阻塞的状态,具体在等待什么资源,暂时未知。
image.png
性能测试知识库
Mysql的CPU利用率过高,可以从Mysql的线程入手。
show GLOBAL STATUS like “%thread%”;查看当前已经启动和正在运行的线程。
下图看到连接了33个线程,但是只运行了15个,近一半线程没有运行,考虑线程阻塞。

接下来需要查看一下当前运行的线程,看看线程在执行什么事物
SHOW PROCESSLIST;
image.png

可以看到线程在执行Drop操作,同时大量线程处于Waiting for schema metadata lock【等待metadata锁释放】状态
性能测试知识库
接着查看一下当前被锁定的事物
查看当前的事务 SELECT * FROM INFORMATION_SCHEMA.INNODB_TRX;

查看锁定的事务SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCKS;
查看等锁的事务SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCK_WAITS;

什么都没查到!

不要放弃,再通过下面的sql查看当前是否有事物在等待Metadata lock

select * from information_schema.processlist where state = ‘Waiting for table metadata lock’;
居然还是查不到!
image.png
那么接下来就要考虑Metadata Lock的三种场景了

1:事物1对表a进行DML操作(包括query),这个时候事物2执行DDL,需要获取metadata锁,因此等待事物1。
这个时候通过show processlist可以找到这个事物

2:事物1对表a进行DML(包括query)事务操作后,没有commit/rollback,这个时候show processlist是看到的事物处于sleep状态,执行的SQL显示为空。而这个时候如果事物2执行DDL操作,同样获取不到metadata锁,就会等待。
性能测试知识库
3:在information_schema.innodb_trx中查不到任何进行中的事务。这很可能是因为在事物中对表进行了一个失败的操作(比如查询了一个不存在的字段或一张不存在的表)。这时事务没有开始,但是失败语句获取到的锁依然有效,没有释放。阻塞后续事物

个人觉得应该是第三种,接下来需要验证一下
select * from performance_schema.events_statements_current; 查询执行失败的语句
image.png

果然看到有三个select语句的lock时间非常的长,把sql捞出来执行一下看看有没有异常
image.png
执行结果,提示表不存在,至此真相大白。

问题总结

Mysql的binlog操作记录是基于事务的提交顺序进行的,如果有一个事务未执行完成,而这个时候drop表,执行顺序就会出现大问题
因此MySQL在5.5.3版本后引入了Metadata lock锁,事务完成后才会释放Metadata lock,这样在事务完成期间,不允许进行任何DDL操作,会停在Waiting for table metadata lock状态
性能测试知识库
一旦操作停在Waiting for table metadata lock的状态,后续对表的任何操作(包括读)都无法进行。如果项目的核心表出现了这样的锁等待队列,会造成灾难性的后果。并且metadata lock锁等待不同于普通的行级锁,等待超时时间默认为365天,而普通的行级锁超时是120s
因此,如果metadata lock锁的源头不释放掉,就会一直阻塞,必须需要人为干预。
从本次分析结果来看,事物在DROP之前先做了一次查询操作,但是因为表不存在,所以执行失败了。虽然失败了,但是依然拿到了锁,并且释放不掉。最终大量的线程处于等待状态
,对cpu的影响就是大量线程处于R队列,占用了cpu,导致利用率很高

点赞收藏
飞天小子

13软件测试,10年性能测试,5年性能培训,10万字性能博主,项目经理,微信uhz2008

请先登录,查看4条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步

为你推荐

日常Bug排查-偶发性读数据不一致

日常Bug排查-偶发性读数据不一致

7
4