一次线上死循环的排查过程

场景

• A写了一个服务，给B调用

• A的这个服务针对一个key，在一次调用完成以前不能调用第二次，若是连续调用，第二次不会执行业务，而是直接返回系统繁忙，使用ConcurrentHashMap + Atomic的cas控制。（不要吐槽咱们小公司小用户量暂时没有使用水平扩展的分布式服务哦，这里就考虑了单机线程安全）

  // {key -> 是否正在运算}
  Map<Long, AtomicBoolean> map = new ConcurrentHashMap<>();
  
  public * *(@RequestBody ..)  {
      //..省略校验和获取主键
      // 可以保证单机线程安全
      AtomicBoolean atomicBoolean = map.computeIfAbsent(key, (key)->new AtomicBoolean(false));
      // 若是正在执行，直接返回一下子再来
      if(!atomicBoolean.compareAndSet(false, true)){
          return "系统繁忙";
      }
      try {
          //..业务操做并返回
      }finally {
          atomicBoolean.set(false);
      }
  }
  复制代码

某日，调用方B看了日志，有一个key调用这个服务后一直返回系统繁忙，且没再成功过，因而，开始了排查过程。

过程

调用方日志

首先，先看调用方B的日志，找到了使用这个key第一次失败调用的位置：

20-06-06 12:09:12 INFO  ** - 开始调用某key
20-06-06 12:09:22 ERROR ** - 调用 fail :
java.net.http.HttpTimeoutException: request timed out
复制代码

能够看出使用了Http调用，从开始调用到失败日志，有10s时间，正是请求超时时间。

请求没返回，以后调用过程一直返回系统繁忙，说明一直没有执行到上面的释放cas锁的块：

try {
    //..业务操做并返回
}finally {
    // 没有执行到
    atomicBoolean.set(false);
}
复制代码

基本猜到了问题，业务操做代码中一直没有执行完毕；

服务方日志

再去看了服务方A的日志：

20-06-06 12:09:13.476 INFO  ** - 结束
// 关键，有一个只有开始没有结束
20-06-06 12:09:13.476 INFO  ** - 开始
// 这个开始是其它key的
20-06-06 12:09:23.267 INFO  ** - 开始
复制代码

果真，在12:09:13的一次调用只有开始，没有结束。

进程

再去看了服务A的服务器进程线程运行情况：

top
top -Hp <pid>
复制代码

发现有一个线程已经占用了将近43分钟的CPU时间，而距离最后一次调用大约过去了一个小时时间，可见极可能是A的业务代码里面有死循环致使这个线程一直处于运行状态。

由于这个线上只是用了jre，没有jdk，没有jstack命令能够查看详细的线程信息，至于为何没有，得问A。

// 假想一下咱们执行了jstack 线程id查看到了确实这个线程一直处于运行状态
jstack <pid>
复制代码

问题

看了看业务代码，定位到了下面一个循环，A为了分批保存大量数据，使用了一个while循环，线下测试时没有达到须要分批保存的阈值，而最后到了线上，须要分批保存，flg没有像预想的那样退出循环，致使一直插入数据。

while (flg){
    flg = false;
    if(..){
        testService.save(..);
        if(..)
	        flg = true;
    }
}


复制代码

看到这里，我猜测既然while循环中插入数据，那么数据库中这个表估计这一个小时已经被插入了许多重复数据了，可是取数据库里一刷新，居然没有明显新增：

猜测了一下，是由于事务一直在这里循环，未提交，因此我去其它mysql链接会话中固然不可见未提交事务中的记录，可是为了更加确认，决定去查如下数据库表文件，发现这个只有八百多条记录的表居然已经以下占用了700M左右的数据，因此，虽然事务未提交，可是它的表文件是在不停增长的。

并且，刷新以后发现，这个表文件的更改时间一直变化，至此证实了死循环问题代码的存在性。

解决

其实A的分批插入想法能够比较可靠的使用reactor中流的一个buffer方法实现：

Flux.fromIterable(list)
    .buffer(savePerNum)
    .subscribe(testService::save);
复制代码

避免了使用死循环，且可读性更加的高。

发布以后，问题解决。

总结

• 单机状况下，对须要控制线程安全的资源能够使用ConcurrentHashMap + Atomic~ + cas控制
• 出现问题要分析日志，找到问题出现的关键位置，观察猜测问题的可能缘由
• 查看java进程和线程信息证实猜测
• 若是事务没有提交，表文件仍是会不停改变增大的，虽然其它会话看不到未提交的数据
• 流式的分批插入能够使用reactor的buffer优雅完成

小伙伴们有什么建议和想法，欢迎讨论啊~