<svg xmlns="http://www.w3.org/2000/svg" style="display: none;"> <path stroke-linecap="round" d="M5,0 0,2.5 5,5z" id="raphael-marker-block" style="-webkit-tap-highlight-color: rgba(0, 0, 0, 0);"></path> </svg> <p></p>
讯享网
某天晚上,突然收到运维同事反馈说系统告警,A系统调用B系统出现大量超时,通过日志分析,B系统中出现了大量的mysql连接报错信息,但是却没有收到任何http请求,怀疑是线程阻塞,运维人员进行了线上的重启操作,系统恢复,开始了问题的追溯。
查看日志中的数据库报错,首先确定问题的源头是出在数据库上面,相关报错日志如下(已屏蔽敏感信息):
讯享网
数据库查询是通过mybatis实现,而数据库连接使用的是druid,默认开启10个连接,最大连接数为50,该系统连接了3个数据源,出问题的是其中的一个,按理来说,应该不至于导致整个系统不可用。
日志中没有任何的请求信息,而且由于系统已经进行了重启,且环境部署在kubernets容器环境,无法获取到现场的一些线程栈信息了,这给问题排查增加了一定的难度。
不过我们还有一个排查利器:链路监控pinpoint。于是进一步查看pinpoint,看看在出故障的时间段是不是有资源异常,首先是发现了一个有意思的现象,在请求的热力分布图上,该系统存在一段空白的区域:

讯享网
这意味着什么?
开发的同学很自然的就会说,你看,这段时间我的系统都没有收到请求,一定是请求方问题,要么是系统A的问题,没有将数据发出来,要么是网络问题导致数据丢失。
然而,事情的真相真是这样吗?
带着这样的疑问,我进一步排查系统的各项指标:堆内存正常、堆外内存正常、CPU正常、事务正常、响应时间正常、活跃线程……
等等,活跃线程怎么出现了一大片黄**域,仔细查看活跃线程,发现从某个时间点开始呈现陡峭的上升趋势,一直到200的时候变成了一条横线,说明此时线程池已经撑爆,和运维确认了故障时间段,与图形吻合。

由于系统使用的springboot+内嵌tomcat的框架,在springboot的源码中:org.springframework.boot.autoconfigure.web包下的ServerProperties中默认主线程的上限就是200,如下:
到此时,已经基本确定问题就出在服务端系统,也就是B系统,虽然从日志和热力图的现象都表明B系统没有收到任何请求,但是从线程池的表现来看,这是进入了排队等待的状态,当活跃线程数量达到上限时,系统就停止响应了。
虽然问题已经查到,是B系统由于线程池占满导致系统停止响应,但是问题的根源到底在哪里呢,我们需要进一步的排查得到深层次的结论。
我们需要得到一些线程栈信息的现场信息才能进一步确定线程到底是阻塞在什么地方,主线程阻塞,一定是在等待什么条件,我们需要获取这个重要的信息,于是想到通过在测试环境模拟故障的方式进行验证
我使用的方式是:本机启动一个nginx,nginx通过配置tcp的4层转发将数据转发到数据库地址,当nginx启动时,则为数据库正常,相反nginx停止时则说明数据库故障。
先简单试验了一下说明该方法有效,将系统的jdbc连接串修改为本地nginx监听的地址和端口,添加tcp代理转发到远程,具体的nginx配置如下(nginx.conf的http后面添加内容):
讯享网
然后使用jemeter模拟客户端向系统不停的发送请求,jemeter中的线程数量不需要设置太大,20以内足够。
刚开始的时候数据库连接正常,启动系统正常,本地我是通过jconsole连接系统进程来实现线程监测,线程数量保持在比较低的水平,日志中能够显示正常的请求日志、响应日志。
然后将数据库连接断开(关闭本地nginx),则开始出现线程堆积,系统响应缓慢,当活跃线程数量达到上限时,系统停止响应,日志中只有不停刷新的数据库连接失败,没有输出任何的请求日志。
通过jstack将线程栈输出到文件中,发现了关键的信息。
通过堆栈信息可以发现,当执行到数据库查询时,通过mybatis的selectOne方法会最终调用druid的getConnection方法,该方法就是从连接池中获取可用连接,此时主线程一直在等待(await),说明连接池中已经没有可用的连接了,于是发生了线程阻塞:

讯享网
进一步分析代码,发现当maxWait为初始值是会执行takeLast方法,该方法会调用线程的await方法获取可用连接,而数据库可用连接为0则会导致该操作一直lock住,从而使得线程挂起。
讯享网
看到此处,是不是已经豁然开朗,那么我们解决问题的思路也就有了。
只要问题分析清楚了,解决问题有时候其实是一件很容易的事情,通过上面的分析我们得知,druid在获取不到可用连接时,会有一个超时时间,这个超时时间就是maxWait,也就是说,只需要将maxWait设置为一个值,那么我们就可以在数据库出现故障时,快速的失败返回,由于使用的springboot的starter方式引入,我们可以直接在springboot的yml配置(笔者所在公司使用的携程apollo配置中心,且统一框架内嵌druid默认配置)中添加如下参数即可:
注意:该超时时间单位为毫秒,并且druid第一次获取连接超时后,会默认进行一次重试,对外表现的超时时间是maxWait*2,,如笔者的配置总体超时时间则为15秒。
需要根据具体的业务场景来进行设置,最好不要超系统间调用超时时间,否则没有意义。
加上了该参数后,通过进一步的测试验证,发现在数据库断开连接的情况下也不会导致主线程阻塞,问题解决。
1、数据库故障导致druid连接池中没有可用的连接;
2、没有设置maxWait参数导致druid使用默认参数-1,无可用连接时无限等待;
3、tomcat主线程同步调用mybatis的数据库查询语句(其他语句也一样),通过druid获取可用连接,陷入等待,导致主线程阻塞;
4、主线程达到线程池最大上限,系统停止响应;
5、调优druid连接池参数,增加maxWait,问题圆满解决。
感谢社区的文章提供的一些思路:
1、线程卡死在druiddatasource上#1160
https://github.com/alibaba/druid/issues/1160
2、数据库连接池Druid配置调优:
https://blog.csdn.net/java/article/details/
版权声明:本文内容由互联网用户自发贡献,该文观点仅代表作者本人。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容,请联系我们,一经查实,本站将立刻删除。
如需转载请保留出处:https://51itzy.com/kjqy/175219.html