SpringBoot Seata 死锁问题排查
现象描述:Spring Boot项目,启动的时候卡住了,一直卡在那里不动,没有报错,也没有日志输出https://img2023.cnblogs.com/blog/874963/202312/874963-20231205182324511-393082103.png
但是,奇怪的是,本地可以正常启动
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205182353702-1785386421.png
好吧,姑且先不深究为什么本地可以启动而部署到服务器上就无法启动的问题,这个不是重点,重点是怎么让它启动起来。(PS:我猜测可能是环境不同造成的,包括操作系统不同和JDK版本不同)
遇到这种情况,我先用jstack查看堆栈情况,果然发现了死锁
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205184215022-1885916211.png
拿到jstack的完整信息,然后仔细排查,看不懂的话也可以借助工具
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205184718945-1338703717.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205184729874-1057870215.png
分析了每个被阻塞的线程之后,发现main线程和timeoutChecker_1_1互相等待对方持有的锁,从而形成了死锁
可以通过 jconsole 和 jvisualvm 查看
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205185243861-1469936655.png
需要注意,如果是查看远程进程,则需要加一些启动参数
[*]-Dcom.sun.management.jmxremote:启用JMX
[*]-Dcom.sun.management.jmxremote.port=:指定JMX远程连接的端口号
[*]-Dcom.sun.management.jmxremote.authenticate=false:禁用JMX远程连接的认证
[*]-Dcom.sun.management.jmxremote.ssl=false:禁用JMX远程连接的SSL加密
于是,我又重启启动
java -jar -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9099 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false app.jar通过jps或者ps命令查找应用的pid
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205185952639-884690021.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205190017229-1839856414.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205190024847-603433668.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205190037792-64419222.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205190044879-974823108.png
用jvisualvm查看也可以,不再赘述,结果都是一样的
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205190159317-837925631.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205190207642-325180987.png
好了,工具介绍到此为止,下面重点看代码
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205190857950-988751580.png
main线程持有这个对象的锁,同时它还需要对象的锁,而timeoutChecker_1_1线程正好相反,于是死锁了
main线程很好理解,就是我们这个SpringBoot应用的主线程,但是timeoutChecker_1_1线程是哪儿来的呢,通过分析发现它来自Seata
对了,该项目中Spring Boot版本是2.6.6,Seata版本是1.4.2
找到timeoutChecker的出处了
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205191622886-1321919197.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205191645421-1380891485.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205192203975-967897795.png
延迟60秒启动定时任务,每隔10秒执行一次,调用io.seata.core.rpc.netty.NettyClientChannelManager#reconnect()
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205192747027-1834785811.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205192753544-1189891486.png
记住这一行,首先调用RegistryFactory.getInstance()获取一个RegistryService,然后调用RegistryService对象的lookup()方法
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205200339779-747362945.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205200118341-518282885.png
接着看1.4.2
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205194202679-1082856293.png
最重要的是 EnhancedServiceLoader.load(ExtConfigurationProvider.class).provide(configuration);
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205194747364-1549432598.png
所以,ExtConfigurationProvider 是 SpringBootConfigurationProvider
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205200801610-2001226290.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205201429392-1748522672.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205201436676-607588901.png
回到seata-1.4.2,可以看到这里调用了applicationContext.getBean(),于是DefaultListableBeanFactory.getBean()
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205201828572-190756356.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205202148820-1008010554.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205202240574-982172291.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205202247088-62286221.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205202425134-1592816464.png
可以看到,getSingletonFactoryBeanForTypeCheck()方法里,对singletonObjects加了同步锁
凡是通过DefaultSingletonBeanRegistry#getSingleton()获取单例Bean的都会先对singletonObjects加锁
接下来看lookup
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205224014127-2074017349.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205224022704-1507827507.png
可以看到,NacosRegistryServiceImpl的lookup()这里也加了锁。另外,getNamingProperties()的时候由于再次用到了ConfigurationFactory.CURRENT_FILE_INSTANCE,所以又到了SpringBootConfigurationProvider#provide()
至此,Seata整个定时任务启动的主要逻辑我们都梳理完了,几处加锁的也都找到了
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205224536715-1692893636.png
这些加锁的地方也就是容易出现死锁的地方
死锁是由于加锁顺序不一致造成的
下面看main线程启动
由于SeataDataSourceBeanPostProcessor实现了BeanPostProcessor接口,所以在创建容器之后会回调其postProcessAfterInitialization()方法
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205214737280-1536877655.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205211442755-977845167.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205211452572-1095131415.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205211502020-1467057567.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205211509320-764018541.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205211631919-245871231.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205212322281-1072167823.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205212259799-243859839.png
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205212346764-1751083961.png
所以,最终还是调NettyClientChannelManager#reconnect()
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205215116805-103640647.png
Spring启动的时候去创建Spring容器,后面就是Spring那一套
ConfigurableApplicationContext#refresh()
ServletWebServerApplicationContext#refresh()
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205215823461-1306427159.png
不再赘述
由于需要注入依赖,所以,这个过程中肯定会多次调用 AbstractBeanFactory.getBean()
前面我们讲过,DefaultSingletonBeanRegistry.getSingleton() 时是加了锁的。因此,main线程很有可能会先持有该锁,当初始化到Seata的时候,又要获取该锁,于是出现了锁争用。
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205225451714-1683051265.png
由于两个线程对同一资源的加锁顺序不一致,导致死锁。
由于timeoutChecker是定时任务每隔10秒启一次,所以第二次加锁顺序变成231
好了,关于main线程和timeoutChecker线程死锁的分析就先到这里了
现在,回到项目中来,由于我们的项目中有一个比较耗时的操作,超时时间固定是60秒,这个方法本来应该在Seata代理数据源之后做,不知道为什么服务器上先执行了,导致main线程等待了60秒,之后才执行SeataDataSourceBeanPostProcessor#postProcessAfterInitialization()
https://img2023.cnblogs.com/blog/874963/202312/874963-20231205231135405-2143330859.png
最终解决方法时将@PostConstruct注解去掉,不在容器初始化的时候取做这么耗时的操作
如果采用Seata-1.5.2版本的话,可能也不会出现死锁问题
参考
jconsole远程连接失败如何解决 - 问答 - 亿速云 (yisu.com)
https://www.zhihuclub.com/179001.shtml
https://zhuanlan.zhihu.com/p/619203844
免责声明:如果侵犯了您的权益,请联系站长,我们会及时删除侵权内容,谢谢合作!
页:
[1]