现象
部署到dev机器,调用这个接口,客户端超时。但是自己本地mac启动服务,然后调用,能够正常返回。
然后重启dev机器,然后去测试,点了几轮后,发现其中不是的一台机器是能够正常返回的,重新部署下就不好使了。
排查过程
因为这里有递归,首先怀疑的就是出现了无限递归,所以去看cpu、内存,都很稳定,没有明显的上升,所以不太可能是无穷递归。(猜测如果出现无穷递归、死循环,cpu理论上应该要上涨。因为无穷的的去压调用栈,内存应该也有波动)
增加调试日志,在各个节点出增加调试日志:发现递归是正常返回了,但是提交任务后,任务确实已经提交给线程池了,因为返回了future,日志里把那个future列表的大小打出来了。但是任务却没有执行,因为日志没有打印。
因为我司搞了日志隔离,将日志打印到了各个文件,虽然确实已经指定了appender,但是还是先怀疑了多线程的时候日志打丢了,或者因为混乱的日志配置,被搞到其他的appender去了,于是本机全局搜索,很遗憾,没有发现调试日志,所以肯定不是日志打到其他appender,就是没打出来。
神奇的一幕发生了,在dev机器上,狂点n次后,接口是可以成功执行的(后面分析为什么这台机器可以),任务执行过程中的debug日志也打印出来了。这就不得不怀疑死锁/活锁了。
于是观察了,cpu、内存都没有上涨,任务也提交给了线程池,但是任务就是没有执行,说明肯定不是死循环,很像死锁的现象。于是看了下线程监控:
jstack pid | grep dead
神奇了,没有发现有死锁检测结果(神奇,当时确实没有发现,回头复现的时候,真切的是能够检测出死锁的)
到此就很尴尬了。没办法,只能再次仔细看代码了,因为查询的时候有两层任务嵌套,而且等待结果是用的不待超时的future.get(),不得不怀疑是相互等待导致的问题了。于是开始根据入参树的信息,画了下线程池的状态:
ps:这里其实正常思维不是用笔去在纸上复现线程池状况,应该是看线程池监控的,这样其实很容易发现异常。但是奈何我司没有监控组件能够有线程池的监控数据。
我倒是想过debug,直接去看线程池,但是我本地是好的,我司的远程debug看数据非常慢(这里又傻逼了一回,直接将线程池数据打印出来不久好了么),所以这里就硬刚了一把。
过程入下:
假如前台类目如下:
对于一个叶子节点,会提交一个查控制模型的任务,而叶子节点下的一个产品,会提交一个查询产品详情的任务,且叶子节点任务会等待查询产品任详情任务完结后,才会完结:
任务依次提交后,线程池情况如下:
ps:其实这个图画出来就非常明显了,有循环依赖。就是思索问题。所以问题的原因基本是明确了。
这里还是继续分析完。
问题:看线程池里的等待关系:
1、2、3个查询叶子节点控制模型的任务提交后,因为线程池有三个线程,所以直接会分配到线程驱动执行,后续提交的任务都会进入到工作队列。
但是每个查询控制模型的任务,又会等待对应节点下查询产品详情的任务完成,但是查询产品详情的任务是在队列中等空闲的线程。
这就形成了死锁等待:
、
这种形成的死锁,但是jstack没打印出来,自以为是这种思索jvm没检测不出来,所以在jstack时打出来的线程堆栈里,是找不到死锁的检测结果的,只能看到线程池里线程都线程状态是waiting状态。但是正常情况下,没有任务提交过来,线程阻塞在工作队列上也是这个状态。
ps:再次本地复现的时候,其实是可以检测的,复现的时候,是检测到死锁了(但复现的时候是用的本地环境,再用dev机器复现一下)
为什么本地起没有问题,部署到dev机器上就有问题了呢?
关键点就是线程池的大小不一样。实际的测试数据是5个叶子节点,总共挂了5个产品。我自己本地mac的cpu核心数Runtime.getRuntime().availableProcessors()是12,所以提交的任务都能够获得一个线程来驱动执行,所以完美的完成了任务。但是看了下发布到dev的机器,Runtime.getRuntime().availableProcessors()是2,线程池里就两个线程,所以就出现了上述情况。
本地mac的配置:单个6个物理核的cpu,并且启用了超线程,所以逻辑核可以到12个。
但是将dev的机器Runtime.getRuntime().availableProcessors()的结果打印出来,发现是2.
查看机器上的cpu信息:/etc/proc/cpuinfo,可以发现:不支持超线程技术的,只有一颗cpu,单颗cpu有80+核。
这种cpu配置是贼高的,理论上,可以支持80+个线程并行执行。但实际上java的RunTime#avaliableProcessor()只是返回了2,其原因就是容器,而使用的java版本RunTime#avaliableProcessor()是考虑了容器的,返回的是容器的cpu限制。
所以咨询,得到的回答是线下申请的机器,默认都是2c的,所以基本证实了RunTime#avaliableProcessor()确实是考虑了容器环境的,返回的就是容器 内cpu的最大限制。
java8的releasenote:Consolidated JDK 8 Release Notes
因为这样,其实也就能理解了,为啥jdk对RunTime#avaliableProcessor()的文档描述这个方法返回值是可变的。如果它感知了cgroup,那么随着宿主机的cpu使用率的变化,那么当前容器(cpu 控制组)能够使用的cpu也就会变化了。所以按道理,宿主机cpu不打满的情况下,RunTime#avaliableProcessor()返回的就应该是cpu控制组下的cpu.cfs_quota_us/cpu.cfs_period_us的值,但我们看到的实际情况却不是,因为我们dev机器上docker这两个参数的比值应该是5.8。
看了下jdk版本,发现使用的jdk版本是我司有改动,所以咨询了下,RunTime#avaliableProcessor()会优先读取一个特定环境变量,如果这个环境变量不存在,才会去按照jdk的描述去读取quota、share控制的cpu限制值。
ps:
- cgroup限制一个cpu控制组使用cpu的个数,其实是通过控制调度器控制一组进程使用的cpu时长(tick数)来达到限制的,同样linux中cpu的使用率的统计也是基于tick数的。
- linux统计到cpu使用率包含两部分:用户态占用cpu的tick数+内核态占用的cpu的tick数,但实际上对于业务来说,更多的其实是关注用户态处理业务消耗的cpu。所以我司在k8s的基础上做了定制,会根据k8s的limit.cpu按照一定的规则进行一定的放大后,填写到cpu.cfs_quota_us上,这就是为什么看到k8s的yaml配置问价limit.cpu=3,但是到了cgroup中cpu.cfs_quota_us/cpu.cfs_period_us是大于3的原因。
- 超卖:简单理解什么是超卖。根据上面的宿主机的cpu情况,宿主机是只有一块cpu,总共有4个核心,那么理论上,宿主机能够同时支持4个并行计算,正常情况下,只要宿主机上同时对cpu的需求小于等于4核,那么能够保证同一时间,大家都能够有cpu用。但如果对cpu的需求大于了4核,就超卖了。比如超卖3倍,那就是宿主机上的虚拟机对cpu的诉求已经达到了4*3=12了。也就是说兄弟们需要12袋米,但地主家的余粮就4,又不能让兄弟们饿着,那就一人吃点,但大家都吃不饱,又不至于饿死。所以体现出来的就是发现机器很慢。
但看top,cpu使用率很低,st的cpu也是0,没有超卖。top统计的是当前统计窗口里的情况。一般情况下,只要不是宿主机上的所有容器负载都很大,超卖是没有影响的,即只要没有把物理机cpu打满,超卖就超卖,反正也用不完,但是只要某一时刻兄弟们要求的12个cpu都要用的时候,那就完了,物理机cpu使用率飙高,这个时候进程上下文切换更加频繁,雪上加霜,系统会更慢的。可以使用iostat看下劫富济贫的统计情况。ps:cpu超卖简单可参考谁偷走了我的云主机CPU时间:理解CPU Steal Time - 知乎
为什么部署到某些机器上,测试了几次后好使了?
其实因为线程池的参数设置是线程池的工作队列满了后,任务会让父线程驱动执行,所以如果超时继续重试,那么最终是会成功的,那就是当工作队列也满了,这个时候提交的任务就都会在父线程执行,其效果就相当于单线程执行了。
部署到dev机器后,使用我自己建的测试类目测试了一把后,工作队列满了,执行拒绝策略,因为这里的拒绝策略是在父线程中执行,所以是能够返回的,只是相当于单线程执行了。
这个把线程池的工作队列设置小点,多重试几次就复现出来了。
为啥脑抽使用了不待超时的
麻木了。但还有一点人性没有泯灭,当时这么写的时候,其实有点膈应,但是一个闪念的想法让我就这么写了:任务里的操作其实会很快,因为有两层缓存,即走到了db,也一定走上索引,应该不会慢的,就这样吧,应该问题不大。从未在代码中真的搞出过死锁,所以这里其实当时脑子里没有想到死锁。
其实在任何需要等待的场景,都要使用带超时时间的等待,这是一个好的编程习惯。其目的就是为了防止死锁,导致资源被锁住,不重启就不能缓解。
所以几乎在所有讲死锁的文章中,讲到死锁的4个必要条件去防止死锁的时候,说到破坏循环等待的时候,基本都会提到这个,包括很多编程规范中也是这么要求的。这样即使发生死锁,在一定时间后,也能够自我环节。
ps:比如mysql除了昂贵的主动死锁检测以外,事务超时时间其实也能一定程度上自我从死锁中解放出来。前人用血泪换来的最佳实践,学习学习,且去践行,在没有十足的理由的时候,别自我"创新",当然也千万别不明所以的盲目的照搬很多所谓的编程规范,同样容易踩坑。
举个栗子:阿里的java编程规范里说了,所有和钱相关的,都不要使用double,要使用BigDecimal,因为double有精度问题,但是没有说为什么。于是乎就看到了BigDecimal lat = new BigDecimal(123.1231231)
guava工具Lists#partion(),为什么要重写,不用?
这个工具的本质是用了jdk的List#subList(),而这个接口会返回一个SubList类,它本质是原list的一个视图,其修改是线程不安全的,就可能出现当前SubList和本身ArrayList的modCount不一致,而每次操作都会校验两者是否一致,如果不一致就会报错ConcurrentModificationException。不展开,八股文之jdk的List的modCount,以及subList()函数的实现里就能得到答案。
ps:jdk、甚至是guava、apache里的很多集合工具,返回值有的可能是不支持修改的一个集合子类型、或者就直接是依赖了List#subList()等这类函数,当要对结果进行修改的时候,要千万注意。
所以,这种在很多编程规范中有个建议规范(甚至是强制规则),,大概的意思就是:
- 对于查询接口,不要去直接修改返回值。
- 对于写入(查询接口我感觉也是),处理过程中不要修改其入参。
这其实也就引入了另外一个规范,在定义api的时候,最好不要定义大而全的,然后需要什么去什么、需要什么设置什么,这种,往往很容易在分层调用的时候,在处理逻辑中就直接去修改出入参了。
ps:findbugs这种静态代码扫描工具,默认规则中其实都是扫描出这种情况的,但是结果等级比较低,貌似是建议吧,所以往往被忽视。
修复
明确了问题所在,解决就相对容易了:就是解开这个循环依赖。
- 用两个不同的线程池
- 用同一个线程池,但是要断开任务之间的依赖(采用的就是方式去改的代码)。并且等待结果改成了待超时时间的等待。
总结
- 既然是线程池问题,应该一开始就去看线程池监控,其实从监控里的workqueue,就能看出问题的。只是我们现在没有现成的线程池监控。是分析了代码后,分析出问题后,为了验证分析结论的时候,才去看了线程池的workqueue。所以线程池监控还是很重要的。如果开始就看到了线程池的线程处于阻塞状态、但是工作队列里又不为空,这就绝对是有问题的。
- 永远自定义线程池的ThreadFactory,起一个和业务场景相关的名字。在线程监控的时候会有大作用。
- 线程池使用的的时候,并不是往里丢任务,然后自己等待结果就好了。搞不好也容易踩雷。总之就是提交到一个线程池里的任务,别有任何的依赖关系。
- 永远不要使用不带超时时间的等待。切记。
- 当方法调用时内外两个方法都用了多线程,一定要注意,使用同一个线程池就可能出现死锁
附录--线程池监控
线程池里没有任务,阻塞在工作队列上的线程的状态监控:
上述场景的线程监控:
死锁检测:
ps:当时还专门看了死锁检测的,没有发现,已经搞不懂为啥了。
模拟代码:
public class Main {
public static void main(String[] args) {
TreeProductService treeProductService = new TreeProductService();
TreeNode rootNode = treeProductService.getSubStre("rootId", true);
System.out.println(rootNode);
}
}
public class MockService {
// 模拟查产品详情
public ProductBaseInfo mockGetProductInfo(String productCode) {
switch (productCode) {
case "leaf1pdcode1":
return new ProductBaseInfo("front", "leaf1pdname1");
case "leaf1pdcode2":
return new ProductBaseInfo("front", "leaf1pdname2");
case "leaf2pdcode1":
return new ProductBaseInfo("front", "leaf2pdname1");
case "leaf3pdcode1":
return new ProductBaseInfo("front", "leaf3pdname1");
case "leaf3pdcode2":
return new ProductBaseInfo("backend", "leaf3pdname1");
default:
return null;
}
}
// 模拟查产排序
public Map<String, Integer> mockGetProductSortNum() {
Map<String, Integer> productCode2SortNumMap = new HashMap<>(8);
productCode2SortNumMap.put("leaf1pdcode1", 1);
productCode2SortNumMap.put("leaf1pdcode2", 1);
productCode2SortNumMap.put("leaf2pdcode1", 1);
productCode2SortNumMap.put("leaf3pdcode1", 1);
productCode2SortNumMap.put("leaf3pdcode2", 1);
return productCode2SortNumMap;
}
// 模拟查询出当前节点及子树。
public TreeNode mockSubTree(List<TreeNode> leafNodes) {
TreeNode leafNode1 = new TreeNode();
leafNode1.setNodeType("leaf");
leafNode1.setId("leaf1");
leafNode1.setProductInfos(Lists.newArrayList(new TreeProductInfo("leaf1pdcode1"), new TreeProductInfo("leaf1pdcode2")));
TreeNode leafNode2 = new TreeNode();
leafNode2.setNodeType("leaf");
leafNode2.setId("leaf2");
leafNode2.setProductInfos(Lists.newArrayList(new TreeProductInfo("leaf2pdcode1")));
TreeNode leafNode3 = new TreeNode();
leafNode3.setNodeType("leaf");
leafNode3.setId("leaf3");
leafNode3.setProductInfos(Lists.newArrayList(new TreeProductInfo("leaf3pdcode1"), new TreeProductInfo("leaf3pdcode2")));
TreeNode leafNode4 = new TreeNode();
leafNode4.setNodeType("leaf");
leafNode4.setId("leaf4");
leafNode4.setProductInfos(Lists.newArrayList());
TreeNode curNode = new TreeNode();
curNode.setId("rootId");
curNode.setNodeType("root");
curNode.setChildNoes(Lists.newArrayList(leafNode1, leafNode2, leafNode3));
leafNodes.addAll(Lists.newArrayList(leafNode1, leafNode2, leafNode3, leafNode4));
return curNode;
}
}
public class ProductBaseInfo {
private String type;
private String name;
public ProductBaseInfo(String type, String name) {
this.type = type;
this.name = name;
}
public String getType() {
return type;
}
public void setType(String type) {
this.type = type;
}
public String getName() {
return name;
}
public void setName(String name) {
this.name = name;
}
}
public class TreeNode {
private String id;
private String name;
private String nodeType;//root、middle、leaf
private List<TreeNode> childNoes; // 子树
private List<TreeProductInfo> productInfos;// 叶子节点上上挂ProductInfo
public String getId() {
return id;
}
public void setId(String id) {
this.id = id;
}
public String getName() {
return name;
}
public void setName(String name) {
this.name = name;
}
public String getNodeType() {
return nodeType;
}
public void setNodeType(String nodeType) {
this.nodeType = nodeType;
}
public List<TreeNode> getChildNoes() {
return childNoes;
}
public void setChildNoes(List<TreeNode> childNoes) {
this.childNoes = childNoes;
}
public List<TreeProductInfo> getProductInfos() {
return productInfos;
}
public void setProductInfos(List<TreeProductInfo> productInfos) {
this.productInfos = productInfos;
}
}
public class TreeProductInfo {
private String productCode;
private String productName;
private Integer sortNum;
public TreeProductInfo(String productCode) {
this.productCode = productCode;
}
public String getProductCode() {
return productCode;
}
public void setProductCode(String productCode) {
this.productCode = productCode;
}
public String getProductName() {
return productName;
}
public void setProductName(String productName) {
this.productName = productName;
}
public Integer getSortNum() {
return sortNum;
}
public void setSortNum(Integer sortNum) {
this.sortNum = sortNum;
}
}
public class TreeProductService {
private MockService mockService = new MockService();
private Lock lock = new ReentrantLock();
private ExecutorService scmProdExecutor = new ThreadPoolExecutor(2, 2, 10, TimeUnit.SECONDS,
new ArrayBlockingQueue<>(10),
new ThreadFactoryBuilder().setNameFormat("treeProductQuery-%d").build()
, new RejectedExecutionHandler() {
@Override
public void rejectedExecution(Runnable r, ThreadPoolExecutor executor) {
r.run();
}
});
public TreeNode getSubStre(String treeNodeId, boolean includeProduct) {
List<TreeNode> leafNodes = new ArrayList<>(32);
// 缓存接口有递归拉出所有的节点,以及叶子节点下挂载的产品,所以树的深度以及叶子节点挂载的产品数不宜过大。
TreeNode currentNode = mockService.mockSubTree(leafNodes);
if (currentNode == null) {
throw new RuntimeException("节点不存在");
}
if (includeProduct) {
assembleTreeProductInfo(leafNodes);
}
return currentNode;
}
//
private void assembleTreeProductInfo(List<TreeNode> leafNodes) {
List<Future<?>> leafFutures = new ArrayList<>(100);
for (TreeNode leafNode : leafNodes) {
leafFutures.add(
scmProdExecutor.submit(() -> {
assembleLeafProds(leafNode);
})
);
}
// 等待结果
leafFutures.forEach(future -> {
try {
future.get();
} catch (InterruptedException | ExecutionException e) {
throw new RuntimeException("");
}
});
}
private void assembleLeafProds(TreeNode leafNode) {
if (CollectionUtils.isEmpty(leafNode.getProductInfos())) {
return;
}
// TODO 查询节点关联信息
Map<String, Integer> pdCode2SortNumMap = mockService.mockGetProductSortNum();
List<Future<?>> assembleProdfutures = new ArrayList<>(80);
for (List<TreeProductInfo> productVOS : partition(leafNode.getProductInfos(), 5)) {
assembleProdfutures.add(scmProdExecutor.submit(() -> {
assembleTreeProductInfo(leafNode, productVOS, pdCode2SortNumMap);
}));
}
// 等待结果
assembleProdfutures.forEach(future -> {
try {
future.get();
} catch (InterruptedException | ExecutionException e) {
throw new RuntimeException("失败");
}
});
}
private void assembleTreeProductInfo(TreeNode leafNode, List<TreeProductInfo> productVOS, Map<String, Integer> pdCode2SortNumMap) {
for (int i = 0; i < productVOS.size(); i++) {
TreeProductInfo treeProductInfo = productVOS.get(i);
ProductBaseInfo latestVersionProduct = mockService.mockGetProductInfo(treeProductInfo.getProductCode());
if (latestVersionProduct == null || !"front".equals(latestVersionProduct.getType())) {
// List是不安全的,所以这里加锁删除。正常情况下,不会将非前台产品放到权限集的前台类目,所以正常情况下是走不到这里来的。加锁不影响正常情况效率
try {
lock.lock();
leafNode.getProductInfos().remove(treeProductInfo);
} finally {
lock.unlock();
}
continue;
}
treeProductInfo.setProductName(latestVersionProduct.getName());
treeProductInfo.setSortNum(pdCode2SortNumMap.get(treeProductInfo.getProductCode()));
}
}
// guava的List#partition()工具使用的是List#subList,返回的SubList,其实现的迭代器访问是线程不安全,并发访问会报错。所以这里不能使用List#sublist()
private <T> List<List<T>> partition(List<T> list, int size) {
List<List<T>> listGroup = new ArrayList<>();
int length = list.size();
int subLength = length - 1;
int toIndex = 0;
List<T> newList = new ArrayList<>(size);
for (int i = 0; i < length; i++) {
newList.add(list.get(i));
toIndex++;
if (toIndex == size || i == subLength) {
listGroup.add(newList);
toIndex = 0;
newList = new ArrayList<>(size);
}
}
return listGroup;
}
}