一次线上内存报警的排查

Posted on | In

最近线上遇到个内存溢出问题，排查过程虽然很快但是觉得其中思考过程和一些点还是比较有意思，所以有了这篇博客。

背景

某个平淡无奇的周末，运维突然告诉我说线上我负责的系统内存告警，由于线上有完备的监控日志，所以让运维保存了下堆栈信息就直接重启了，先
恢复业务以免出现其他问题。

现场情况

接下来登录运维平台看了下，之前内存占用在百分之90左右，重启过后暂时正常。查看线上接口的失败率、响应时间都没啥大问题。然后查看系统资源
占用情况，悲剧的发现堆内存没有监控：
jvm监控
上图可以看到，堆内存情况不详，而非堆内存和直接缓冲区都很正常。线程数不正常。

分析

由于线上环境不是突然性的就内存超限了，所以怀疑是内存泄露(memory leak)，而导致内存泄露的根本原因是分配了资源却没有回收，在频繁的发生过后
在某个节点就会触发后台的监控报警。一般情况下，会泄露的包含:

  • 代码中加载的数据过多，比如数据库或缓存了读了过多数据
  • 死循环
  • 未释放的资源，包括对象、线程等等

在JVM监控中看到线程数异常，随着应用的使用线程数剧烈增加并且没有减少，峰值达到2.5k个线程且都处于WAITING状态，所以这里肯定是有问题的。于是
jstack看看：
jstack监控
大概统计了下线程的数量：

线程数量

发现现象非常直接：

  • 有很多个线程池，并且名字是默认的（pool-NUMBER-thread-NUMBER）
  • 几乎每个线程池都只有1个线程

我们知道，除非说手动制定了固定大小的线程池或者设置了allowCoreThreadTimeOut，不然一般线程次的线程数量通常在核心线程数，而这里的情况是只有
1个任务，那么基本可以推断出是在某种请求里频繁的创建任务，并且这种任务每次都是不同的线程，进一步的，很可能就对应着一次http请求。

原因排查

上面提到，由于线程池没有调用ThreadFactory设置名称，所以无法根据这个找到泄露位置。但是线程池可以确定是某个地方的使用方式不对，并且是没有设置ThreadFactory，所以全局查找下Executors和ThreadPoolExecutor变量，发现还挺多的，暂时不想全局REVEVIEW,所以想想其他思路。

1周之前项目有上线，但是由于某个产品最近这两天才有上量，用户数相对于以前有较大的增加，所以才被关注到了这个问题（之前一直没有关注到这里），于是查看当时这次提交和前一次提交的代码差异，找出所有与Executors和ThreadPoolExecutor相关的代码。发现下面这段代码：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
public class ThreadPoolGroupComponent{
    private final ConcurrentHashMap<String,ExecutorService> group = new ConcurrentHashMap(50);

    private static final int CORE_POOL_SIZE = 3;
    private static final int MAX_POOL_SIZE = 30;
    private static final int KEEP_ALIVE_TIME = 6000;
    private static final int QUEUE_SIZE = 100;

    public ExecutorService getExecutor(String key){
        //TODO 负载均衡
        if (group.contains(key)){
            return group.get(key);
        }
        ExecutorService executor = new ThreadPoolExecutor(CORE_POOL_SIZE,MAX_POOL_SIZE,KEEP_ALIVE_TIME,TimeUnit.MILLISECONDS,
                new ArrayBlockingQueue<>(QUEUE_SIZE),new ThreadPoolExecutor.CallerRunsPolicy());
        group.put(key,executor);
        return executor;
    }
}

这里明显看出有两个问题：

  1. 检查-设置 不是原子性性的，存在重复创建的风险
  2. Map的检查key是否存在的方法调用错，contains方法的注解是：

    Legacy method testing if some key maps into the specified value
    in this table. This method is identical in functionality to
    {@link #containsValue(Object)}, and exists solely to ensure
    full compatibility with class {@link java.util.Hashtable},
    which supported this method prior to introduction of the
    Java Collections framework.

这个方法校验的指定的value是否存在，明显与这里的线程池组的设计不符，所以这里肯定是有问题。

ThreadPoolGroupComponent这个类是在最近（1周内）上业务时才被使用到的方法，但是在这之前，线程池也存在泄露问题，所以可能还存在其他的问题， 没办法，只好全局review下。
又看到这个：

1
2
3
4
5
6
7
8
9
10
11
12
@Component("userThreadPool")
@Scope("prototype")
public class UserThreadPool {

    private final ExecutorService executorService = Executors.newFixedThreadPool(1);


    public ExecutorService getExecutor(){
        return executorService;
    }

}

简直是虎躯一震，Spring的prototype生命期注解放在线程池上。那么这就意味着对这个类的每次Bean获取都会新生成一个线程池，ALT+F7查找引用一看–果然，某个量不大但一直有的业务使用着，也就是一直慢慢创建新的线程池。但是由于这里对应的是客户的某个操作-也就是一次http请求，所以也就是只会处理一个任务就被搁置，自然也是只有一个线程存活。

反思

这次问题排查速度还是比较快，但是我觉得一些关键的排查问题的点还是挺重要的：

  1. 完备的线上监控、预警
    不然出了问题几乎是瞎的，在分布式系统或者C这种语言里很难还原现场
  2. 优先保障线上业务的正常使用，同时记得保留现场
    要熟练使用jstack,jmap甚至一些profiling工具
  3. 如何正确的缩小问题排查范围是解决问题速度的关键
    这个有多种维度，比如项目模块、使用库、时间线、主机/Runtime等

而还有一些项目管控上的东西则需要引以为戒：

  1. 线程池应该作为一个基础组件来使用，各个子系统最好不要”自定义“各种花式使用方式
  2. 设计的时候如果考虑要多线程使用，就一定要特别注意相关的api是否线程安全。这个远远不止是使用线程安全的容器那么简单，需要特别注意一些常见的坑

PS: 本文所描述的问题其实本质上来说也不是线程导致的内存溢出，线上环境给整个应用的堆只有2G，其实还是非常小的。空闲线程对内存的占用还是比较有限，但是由于Hotspot JVM是直接把Java线程映射到操作系统上的，所以线程过多就必然会影响正常业务的线程申请和使用，这个可能是更加重要的点。