事故描述
1、上午9.55发布了一个Apollo动态配置参数;
2、片刻后,服务器接口开始出现大量的超时告警,似乎是某资源被耗尽不足分配;
3、正值业务请求高峰的上午十点(平台上午10点会有一些活动会拉一波用户流量);
4、考虑是否是机器资源不足导致无法承载用户并发量,其实不是,还是跟Apollo发布配置有关;
5、进行服务器资源观测,发现14台机器只有1台机器线程数急剧飙升,并且出现了死锁线程(平台分析工具或jstack),超时告警也都集中出现在这一台机器上;
6、赶紧进行对应机器重启,先解除故障;
7、随后进行dubbo支持的离线jstack-log分析;
从dubbo源码可以看到AbortPolicyWithReport继承自AbortPolicy,AbortPolicy的默认行为是如果任务超过线程池的最大处理能力则直接拒绝任务并抛出异常。而AbortPolicyWithReport除了抛出异常外,还打印了一条非常详细的日志,该日志包含了线程池的详细配置,并且在用户的家目录下面导出了一个Dubbo_JStack.log文件。
原因分析
jasypt-spring-boot-starter是干嘛的?
Jasypt(Java Simplified Encryption)是一个用于Java应用程序的简单加密库,它提供了各种加密算法和解密工具。
jasypt-spring-boot-starter
是一个Spring Boot Starter,用于在Spring Boot应用程序中方便地集成Jasypt,以实现配置文件的加密和解密。在 Apollo 中添加配置项,将数据库密码进行加密保存。确保配置项的值以ENC()
开头,表示它是一个加密过的值。例如,假设你的数据库密码是password
,加密后的值为ENC(加密后的密码)
为什么会出现死锁现象?
CachingDelegateEncryptablePropertySource中getProperty方法中存在加锁操作(多把锁),且加锁的顺序不是一致的!
图1:
图2:
上图2中的source就是图1中的delegate
如上图,最终会在for循环中重新访问到:
com.ulisesbocchio.jasyptspringboot.caching.CachingDelegateEncryptablePropertySource#getProperty
简化后的加锁分析图如上图,因为加锁的目标是this:即CachingDelegateEncryptablePropertySource的实例对象,而这种实例对象又存在多个,就是代表有多把锁的存在。那么就会存在如上图所示的场景,如果apollo触发了更新,而此刻又有大量的线程在访问property资源,那么在极端情况下就会触发这个死锁现象!这也是14台机器只有一台出现死锁问题的原因。后面找了github,也确实是存在这个问题。
官方解释及如何解决
Issues · ulisesbocchio/jasypt-spring-boot · GitHub
加锁目标改用属性名称的字符串常量值,这样多线程并发访问某个name时,加锁的目标是固定的,锁也是同一把,不存在多把锁,这样就避免了死锁;