线上环境 CPU 使用率高排查笔记

景象

生产环境上业务运行容器呈现 cpu 使用率升高、业务交易执行速度慢，平台日志未打印异样信息。

现场数据

1. jvm 线程的 cpu 使用率（top -H）
2. 线程栈
3. 平台配置
4. jdk 版本信息
5. 生产的 jvm 内存堆栈

剖析思路

1. 依据现场的共事形容，呈现问题的是 rpc 服务调用 (abs 通过 tci 调用 afa 的 rpc 服务)，同时该 rpc 服务配置了流控的性能，对于开启了流控的接入服务，在申请进来的时候，会去查看以后流量的大小，这一步会调用到 concurrentLinkedQueue 的 size() 办法。
2. 依据线程 cpu 使用率及以后的线程栈，排查到 cpu 使用率异样时，cpu 次要耗费 concurrentLinkedQueue 的 size()和 remove()办法上，对应的 ConcuureLinkedQueue(jdk 是 8u40)源码行数别离是 450 行和 490 行(见下图)
   

这两个函数均是须要遍历队列中的元素，工夫复杂度为 O(n)，如果队列中的元素达到肯定数量级，会占用比拟高的 cpu。 依据以后现有的数据来看，能够揣测出以后队列的深度可能比拟大。

3. 依据过后生产环境发现 cpu 高时 dump 下来的内存镜像，发现 ConcurrenLinkedQueue 中 item 为 null 的节点数居然高达约 695 万 个，这一步也证实了第 2 点的揣测。

4. 再联合 jdk 官网提供的 bug 清单，发现在 jdk 8u40 版本的存在一个 ConcurrentLinkedQueue 的 bug：在特定的状况下，将对象通过 remove()移除后，队列中仍会残留一个 item 值为 null 的节点。也就是说，将对象存入队列时，它会将对象封装为一个 Node 放入队列中，Node 的 item 指向对象，在特定的状况下，通过 remove()移除对象时，它只将 itme 的值置为 null，但没有将 node 从队列中移除，导致队列的大小并没有变动。而随着对象的增加，队列的大小将越来越大。jdk bug 的详情请看：https://bugs.java.com/bugdata…

5. 从现场的线程栈来看，发现 afa 平台配置的定时工作 (日志清理) 在每天凌晨 1 点调起来，会始终挂住交易线程，造成交易线程始终被占用不开释，可用的业务线程数每日递加，从而造成线程泄露。

   所有日志清理定时工作均是堵在了 readBytes 这个操作，一共发现 23 笔，依据启动工夫以及 dump 线程栈的工夫，剖析下来刚好对应每天启动一笔。

6. 通过剖析 jdk 源码，发现在另一种状况下，ConcurrentLinkedQueue 在通过 remove()移除对象时，也会造成 node 不会真正从队列中移除的问题。首先，ConcurrentLinkedQueue 将 node 从对象中移除只产生在两个地位，一个是调用 remove()办法，另一个是调用 first()办法。

   • 在执行 remove()时，队列移除是通过 cas 操作去执行，在并发较高的状况下，当相邻的两个元素被移除时，可能会有一个 item 为 null 的 node 没有被删除掉，从而造成泄露。

     比方：队列中 A,B,C,D4 个节点，当同时删除 B,C 两个节点，在高并发的状况下，两个并发线程同时走到下图 495 行的地位时，此时线程 1 获取到 A,B,C 三个的援用，线程 2 获取 B,C,D 三个节点的援用，这时候持续往向走，线程 1 删除后，A 的 netxt 指向 C, 线程 2 删除后，B 的 next 指向 D，因为 A 是头节点，B 的节点没有被援用(因为线程 1 的执行)，所以最终队列会变成了 A ->C->D 的状况，这个工夫就造成了 C 的 item 为 null，但没有真正从队列中移除。

     而在执行 first()时，当 head 发现更新时，将会遍历后续 item 不为 Null 的节点作为头结节，这一步可能将 item 为 null 的节点移出队列，如果以后 head 节点没有被更新时，队列后续可能存在的 item 为 Null 的节点将会始终寄存于队列中。

7、联合第 4 点和第 5 点来剖析，发现因为定时清理日志的线程始终没有进行。因为只有交易执行实现并开释线程时，该线程对象才会从 ConcurrentLinkedQueue 队列中移除，其余线程执行工夫较短的线程，都曾经移出队列，从而它会更新成为队列头，但因为它始终挂住不开释，导致 ConcurrentLinkedQueue 的队列头始终不会更新。因而这会导致队列的 item 为 null 的节点数越来越高，所以在执行 size()办法和 remove()办法遍历队列时，造成占用 cpu 重大的状况。

论断

综上所述，因为 jdk 8u40 的 bug 导致 ConcurrentLinkedQueue 的队列存在大量 item 为 null 的节点，再刚好碰巧日志清理交易始终未退出使得 ConcurrentLinkedQueue 的头节点始终不会更新，从而导致 size()以及 remove()在遍历时速度慢，耗费 cpu 高。

复现

提供与生产环境上雷同 afa 配置以及雷同 jdk 版本的测试环境，筹备一个长时间挂住业务线程的交易，以及若干短耗时交易。

平台启动后，先启动挂住线程的交易，而后通过 loadrunner 测试计划继续压测短耗时交易，在压力与工夫足够下，可能重现 cpu 高以及业务交易吞吐量低的状况。

验证

因为 itme 为 null 的节点透露的条件比拟刻薄，在高并发下，可能 1 秒只会有一两笔呈现一个节点泄露，所以须要通过比拟长时间的压测能力齐全重现过后的场景。不过，还有另一种办法，在压测过程中，通过每隔十、二十分钟打印一次内存镜像，将内存镜像拿进去剖析，通过 Eclipse 的 Memory analyze tool 工具的 oql 语言搜寻 itme 为空的 node 数，进行比照，就可能发现 item 为 null 的节点数的增长速率。

下图为压测三天后 dump 下来的内存镜像，发现压测前跟压测后两次镜像中，item 为 null 的节点数减少了约 268 万个。
压测前

压测后

​ 同时，RpcServer-IoWorker-30 线程的 cpu 占用率已稳定上升到 31.8%，察看过后的线程栈发现，线程正在执行 ConcurrentLinkedQueue 的 size()办法，这点与生产环境的状况是统一的。

解决方案

1. 降级 jdk 版本（次要）
2. 优化交易，保障排查定时工作日志清理交易失常进行。（次要）
3. 优化平台，在进行流控校验的逻辑中，弃用 ConcurrentLinkedQueue 的 size()办法，采纳 BlockingQueue 或其余并发队列来实现。(主要问题，只有在交易线程长时间未开释的状况下才会呈现)
4. 将 rpc 接入服务的流控性能下线；（实用于应急状况）

修复后压测验证

降级 jdk 版本到 8u152 后，优化日志清理交易，依照原来的压测计划进行压测。
压测前的内存堆栈如下所示:

压测 5 小时后