服务CPU异常飙高问题分析和解决

2023-10-20 17:15

本文主要是介绍服务CPU异常飙高问题分析和解决,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!

📢📢📢📣📣📣
哈喽!大家好,我是「奇点」,江湖人称 singularity。刚工作几年,想和大家一同进步🤝🤝
一位上进心十足的【Java ToB端大厂领域博主】!😜😜😜
喜欢java和python,平时比较懒,能用程序解决的坚决不手动解决😜😜😜

✨ 如果有对【java】感兴趣的【小可爱】,欢迎关注我

❤️❤️❤️感谢各位大可爱小可爱!❤️❤️❤️

如果觉得本文对你有帮助,欢迎点赞,欢迎关注我,如果有补充欢迎评论交流,我将努力创作更多更好的文章。

 现象

线上有一个非常繁忙的服务的 JVM 进程 CPU 经常跑到 100% 以上,下面写了一下排查的过程。

通过阅读这篇文章你会了解到下面这些知识。

  • Java 程序 CPU 占用高的排查思路
  • 可能造成线上服务大量异常的 log4j 假异步
  • Kafka 异步发送的优化
  • On-CPU 火焰图的原理和解读

开始尝试

JVM CPU 占用高,第一反应是找出 CPU 占用最高的线程,看这个线程在执行什么,使用 top 命令可以查看进程中所有线程占用的 CPU 情况,命令如下所示。

top -Hp pid信息

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND48 root      20   0 30.367g 2.636g  12940 S  12.7  2.9  36:15.18 java2365 root      20   0 30.367g 2.636g  12940 R  1.3  2.9   2:33.64 java2380 root      20   0 30.367g 2.636g  12940 S  1.3  2.9   2:33.10 java2381 root      20   0 30.367g 2.636g  12940 S  1.3  2.9   2:33.41 java
10079 root      20   0 30.367g 2.636g  12940 S  1.3  2.9   0:30.73 java10 root      20   0 30.367g 2.636g  12940 S  1.0  2.9   4:08.54 java11 root      20   0 30.367g 2.636g  12940 S  1.0  2.9   4:08.55 java92 root      20   0 30.367g 2.636g  12940 S  1.0  2.9   2:53.71 java681 root      20   0 30.367g 2.636g  12940 S  1.0  2.9   2:52.56 java683 root      20   0 30.367g 2.636g  12940 S  1.0  2.9   2:56.81 java690 root      20   0 30.367g 2.636g  12940 S  1.0  2.9   3:34.24 java

 

可以看到占用 CPU 最高的线程 PID 为 48(0x30),使用 jstack 输出当前线程堆栈,然后 grep 一下 0x30,如下所示。

jstack 1 | grep -A 10 "0x30 "

输出结果

"kafka-producer-network-thread | producer-1" #35 daemon prio=5 os_prio=0 tid=0x00007f9ac4fc7000 nid=0x30 runnable [0x00007f9ac9b88000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x0000000094ef70c8> (a sun.nio.ch.Util$3)
        - locked <0x0000000094ef70e0> (a java.util.Collections$UnmodifiableSet)
        - locked <0x000000009642bbb8> (a sun.nio.ch.EPollSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at org.apache.kafka.common.network.Selector.select(Selector.java:686) 

可以看到这是一个 kafka 的发送线程。我们的日志打印是使用 log4j2 的 kafka 插件将日志文件写入到 kafka,日志写入量非常大。接下来先来优化这个 kafka 发送线程的 CPU 占用。

Log4j2 下 KafkaAppender 优化

KafkaAppender 中封装了 KafkaProducer,经过测试与 KafkaProducer 发送频率有很大关系的有这几个参数 batch.size、linger.ms。接下来看看这里几个参数有什么实际的作用。

linger.ms

KafkaProducer 在 batch 缓冲区满或者 linger.ms 时间到达时,会将消息发送出去。linger.ms 用来指定发送端在 batch 缓冲池被填满之前最多等待多长时间,相当于 TCP 协议的 Nagle 算法。
这个值默认为 0,只要有数据 Sender 线程就会一直发,不会等待,就算 batch 缓冲区只有一条数据也会立即发送。这样消息发送的延迟确实很低,但是吞吐量会变得很差。
设置一个大于 0 的值,可以让发送端在缓冲区没有满的情况下等待一段时间,累积 linger.ms 时间的数据一起发送。这样可以减少请求的数量,避免频繁发送太多小包,不会立即发送数据。这样增加了消息的时延(latency),但是提高了吞吐量(throughput)。

batch.size

KafkaProducer 在发送多条消息时,会把发往同一个 partition 的的消息当做一个 batch 批量发送。
batch.size 用于指定批量发送缓存内存区域的大小,注意这里不是条数,默认值是 16384(16KB)
当 batch 缓冲区满,缓冲区中所有的消息会被发送出去。这并不意味着 KafkaProducer 会等到 batch 满才会发,不然只有一条消息时,消息就一直发不出去了。linger.ms 和 batch.size 都会影响 KafkaProducer 的发送行为。
batch.size 值设置太小会降低吞吐量,太大会浪费内存。
我们线上的配置这两个值都没配置,会按 linger.ms=0,batch.size 为 16KB 的配置运行,因为日志产生的非常频繁,Sender 线程几乎不会闲下来,一直在处理发送数据包。

og4j2 的异步 Appender 潜在的坑

在做 Kafka 发送端的参数调整之前有一个风险点,log4j2 的异步 Appender 潜在的坑需要提前避免,否则会造成线上业务接口的大量超时。
log4j2 的异步 Appender 原理上是在本地利用了本地的一个 ArrayBlockingQueue 存储应用层发过来的消息,这个 queue 的大小默认值在 2.7 版本的 log4j2 中是 128,在高版本中,这个值已经被调为了 1024。如果 KafkaAppender 处理的比较慢,很快这个队列就填满,如下图所示。

 

填满以后就涉及到是 blocking 等待,还是丢弃后面加入的日志的问题,比较坑的是 log4j2 的默认配置是 DefaultAsyncQueueFullPolicy,这个策略是同步阻塞等待当前线程。我们可以选择将这个值设置为丢弃,以保证不管底层的日志写入慢不慢,都不能影响上层的业务接口,大不了就丢弃部分日志。log4j 提供了配置项,将系统属性 log4j2.AsyncQueueFullPolicy 设置为 Discard 即可。
这还没完,设置了队列满的策略为 Discard 后,log4j 默认只会舍弃 INFO 及以下级别的日志。如果系统大量产生 WARN、ERROR 级别的日志,就算策略是 Discard 还是会造成阻塞上游线程,需要将 log4j2.DiscardThreshold 设置为 ERROR 或者 FATAL。
修改了 KafkaProducer 和 log4j 的参数以后,kafka 发送线程的 CPU 占用降低到了 5% 以下,整体的 CPU 负载依旧是比较高的,接下来继续排查。

火焰图

一开始本来想用 perf、dtrace、systemtap 等工具来生成火焰图,无奈在 Docker 容器中没有 privileged 权限,我一一尝试了都无法运行上面的所有命令,好在是 Arthas 提供了火焰图生成的命令 profiler,它的原理是利用 async-profiler 对应用采样,生成火焰图。
使用 arthas Attach 上 JVM 进程以后,使用 profiler start 开始进行采样,运行一段时间后执行 profiler stop 就可以生成火焰图 svg 了,部分如下图所示。

火焰图有几个特征:

  • 每个框代表栈里的一个函数;
  • Y 轴表示函数调用栈的深度,下层函数是上层函数的父调用。调用栈越深,火焰越高;
  • X 轴不是表示时间的流逝,而是表示抽样数,一个函数在 X 轴的宽度越宽,表示它在采样中被抽到的次数越多,执行时间越长。

从上面的图可以看到 kafka 和 Spring 函数执行的 CPU 占用最多,kafka 的问题上面的内容可以优化,接下来我们来看 Spring 函数相关调用栈。

log4j 行号计算的代价

把 svg 放大,可以看到有一个顶一直都平很高,函数是 Log4jLogEvent.calcLocation,也就是 log4j 生成日志打印行数的计算的地方,如下图所示。

 

计算行号的原理实际上是通过获取当前调用堆栈来实现的,这个计算性能很差,具体有多慢,网上有很多 benchmark 的例子可以实测一下。

我们把 log4j 的行号输出关掉,CPU 占用又小了一点点,这个平顶的调用也不见了。

 

这篇关于服务CPU异常飙高问题分析和解决的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!



http://www.chinasem.cn/article/248512

相关文章

判断PyTorch是GPU版还是CPU版的方法小结

《判断PyTorch是GPU版还是CPU版的方法小结》PyTorch作为当前最流行的深度学习框架之一,支持在CPU和GPU(NVIDIACUDA)上运行,所以对于深度学习开发者来说,正确识别PyTor... 目录前言为什么需要区分GPU和CPU版本?性能差异硬件要求如何检查PyTorch版本?方法1:使用命

Redis 热 key 和大 key 问题小结

《Redis热key和大key问题小结》:本文主要介绍Redis热key和大key问题小结,本文给大家介绍的非常详细,对大家的学习或工作具有一定的参考借鉴价值,需要的朋友参考下吧... 目录一、什么是 Redis 热 key?热 key(Hot Key)定义: 热 key 常见表现:热 key 的风险:二、

IntelliJ IDEA 中配置 Spring MVC 环境的详细步骤及问题解决

《IntelliJIDEA中配置SpringMVC环境的详细步骤及问题解决》:本文主要介绍IntelliJIDEA中配置SpringMVC环境的详细步骤及问题解决,本文分步骤结合实例给大... 目录步骤 1:创建 Maven Web 项目步骤 2:添加 Spring MVC 依赖1、保存后执行2、将新的依赖

Spring 中的循环引用问题解决方法

《Spring中的循环引用问题解决方法》:本文主要介绍Spring中的循环引用问题解决方法,本文给大家介绍的非常详细,对大家的学习或工作具有一定的参考借鉴价值,需要的朋友参考下吧... 目录什么是循环引用?循环依赖三级缓存解决循环依赖二级缓存三级缓存本章来聊聊Spring 中的循环引用问题该如何解决。这里聊

Spring Boot中JSON数值溢出问题从报错到优雅解决办法

《SpringBoot中JSON数值溢出问题从报错到优雅解决办法》:本文主要介绍SpringBoot中JSON数值溢出问题从报错到优雅的解决办法,通过修改字段类型为Long、添加全局异常处理和... 目录一、问题背景:为什么我的接口突然报错了?二、为什么会发生这个错误?1. Java 数据类型的“容量”限制

SpringBoot基于配置实现短信服务策略的动态切换

《SpringBoot基于配置实现短信服务策略的动态切换》这篇文章主要为大家详细介绍了SpringBoot在接入多个短信服务商(如阿里云、腾讯云、华为云)后,如何根据配置或环境切换使用不同的服务商,需... 目录目标功能示例配置(application.yml)配置类绑定短信发送策略接口示例:阿里云 & 腾

关于MongoDB图片URL存储异常问题以及解决

《关于MongoDB图片URL存储异常问题以及解决》:本文主要介绍关于MongoDB图片URL存储异常问题以及解决方案,具有很好的参考价值,希望对大家有所帮助,如有错误或未考虑完全的地方,望不吝赐... 目录MongoDB图片URL存储异常问题项目场景问题描述原因分析解决方案预防措施js总结MongoDB图

SpringBoot项目中报错The field screenShot exceeds its maximum permitted size of 1048576 bytes.的问题及解决

《SpringBoot项目中报错ThefieldscreenShotexceedsitsmaximumpermittedsizeof1048576bytes.的问题及解决》这篇文章... 目录项目场景问题描述原因分析解决方案总结项目场景javascript提示:项目相关背景:项目场景:基于Spring

解决Maven项目idea找不到本地仓库jar包问题以及使用mvn install:install-file

《解决Maven项目idea找不到本地仓库jar包问题以及使用mvninstall:install-file》:本文主要介绍解决Maven项目idea找不到本地仓库jar包问题以及使用mvnin... 目录Maven项目idea找不到本地仓库jar包以及使用mvn install:install-file基

一文详解Java异常处理你都了解哪些知识

《一文详解Java异常处理你都了解哪些知识》:本文主要介绍Java异常处理的相关资料,包括异常的分类、捕获和处理异常的语法、常见的异常类型以及自定义异常的实现,文中通过代码介绍的非常详细,需要的朋... 目录前言一、什么是异常二、异常的分类2.1 受检异常2.2 非受检异常三、异常处理的语法3.1 try-