记录测试环境hertzbeat压测cpu高,oom问题排查。jvm,mat,visulavm
记录测试环境hertzbeat压测cpu高,oom问题排查。jvm,mat,visulavm
一,问题背景
运维平台,采用hertzbeat开源代码进行采集。对单个设备连接,采集9个指标。目前hertzbeat对1个设备连接,下发9次单独采集并获取采集结果,存放到tsdb数据库。测试环境进行压测,造500个设备,hertzbeat共计500个采集任务,运行一天后,hertzbeat web页面采集任务宕机约300+,且正常状态的采集任务,查看采集详情,只有实时数据,没有历史数据。(将查询时间扩大到1天,则发现历史数据只在20多分钟的时间段内才有)。
问题整理:
1.hertzbeat任务运行一天后存在宕机
2.hertzbeat任务历史采集数据无法查看
3.hertzbeat服务cpu在200+
4.运维服务oom
本文讨论1,2,3问题。第4问题不做讨论。
其中问题,1,3是同一种。2单独。
涉及的核心服务:
运维服务,hertzbeat服务,kafka,模拟设备,emqx,tsdb时序数据库(存放采集数据的历史记录)
服务部署信息和版本信息
k8s部署
hertzbeat 分支: 1.6.1
emqx版本 5.7.1
mqtt协议:5.0
核心服务配置:
hertzbeat服务,最大堆15g
采集流程:
hertzbeat 通过mqtt协议下发采集任务,模拟设备收到消息后,返回采集数据(mqtt协议消息都通过emqx broker转发),hertzbeat收到采集结果后,通过kafka发送采集结果消息,然后hertzbeat和运维服务消费这个消息。
流程图如下:
二,使用工具
k8s:部署服务的部署平台
VisulaVm:堆,线程分析工具
MAT:内存泄漏分析工具
豆包:工具人
MAT下载地址:
https://blog.csdn.net/wutrg1502/article/details/132315468
三,排查问题2,hertzbeat采集历史数据无法查看。
排查思路:
hertzbeat采集数据收到后由kafka发送后,hertzbeat消费,然后写入tsdb数据库。
已知模拟器不停在上报。
检查点:
kafaka消息是否有积压情况。
tsdb是否有历史数据。
kafka看是否消息积压:
进入k8s的kafka容器,cd bin
然后执行:
查看消费组:./kafka-consumer-groups.sh --list --bootstrap-server localhost:9092
看 hertzbeat消费./kafka-consumer-groups.sh --describe --group xxt-consumer --bootstrap-server localhost:9092 | grep xxtopic
数字分别为:已消费,总数,待消费(这个图是修复后,修复前有大量消息积压。也就解释了为什么tsdb数据库没有历史数据写入。)
如何找到写入tsdb数据库代码:
直接停止tsdb数据库服务,看hertzbeat报错日志,根据调用栈找到代码。
原因是,hertzbeat将指标拆成多个小的循环进行调用并存储到tsdb数据库。将单条处理为批量调用:
List<CollectRep.Field> fields = metricsData.getFieldsList();Long[] timestamp = new Long[]{metricsData.getTime()};Map<String, Double> fieldsValue = new HashMap<>(fields.size());Map<String, String> labels = new HashMap<>(fields.size());StringBuilder batchPayload = new StringBuilder();int qty = 0;for (CollectRep.ValueRow valueRow : metricsData.getValuesList()) {fieldsValue.clear();labels.clear();for (int index = 0; index < fields.size(); index++) {CollectRep.Field field = fields.get(index);String value = valueRow.getColumns(index);if (field.getType() == CommonConstants.TYPE_NUMBER && !field.getLabel()) {// number metrics dataif (!CommonConstants.NULL_VALUE.equals(value)) {fieldsValue.put(field.getName(), CommonUtil.parseStrDouble(value));}}// labelif (field.getLabel() && !CommonConstants.NULL_VALUE.equals(value)) {labels.put(field.getName(), value);}}for (Map.Entry<String, Double> entry : fieldsValue.entrySet()) {if (entry.getKey() != null && entry.getValue() != null) {try {labels.putAll(defaultLabels);String labelName = isPrometheusAuto ? metricsData.getMetrics() : metricsData.getMetrics() + SPILT + entry.getKey();labels.put(LABEL_KEY_NAME, labelName);labels.put(MONITOR_METRIC_KEY, entry.getKey());VictoriaMetricsContent content = VictoriaMetricsContent.builder().metric(labels).values(new Double[]{entry.getValue()}).timestamps(timestamp).build();batchPayload.append(JsonUtil.toJson(content)).append("\n");qty = qty + 1;} catch (Exception e) {log.error("flush metrics data to victoria-metrics error: {}.", e.getMessage(), e);}}}}if (qty > 0){sendBatchData(batchPayload);}}
三,排查问题1,3,hertzbeat采集任务宕机和cpu高问题
生成堆,线程dump文件
进入hertzbeat容器,生成堆,线程的dump文件
命令:
1 和22 是容器中java的进程id
如何查看:
jps -v
生成线程堆栈
jstack 1 > /home/app/logs/thread_dump_$(date +%Y%m%d%H%M%S).txtjstack 1 > /home/app/logs/thread_dump_$(date +%Y%m%d%H%M%S).tdump生成堆栈
jmap -dump:format=b,file=/home/app/logs/heap_dump_$(date +%Y%m%d%H%M%S).hprof 1jstack 22 > /home/app/logs/hert_thread_dump_$(date +%Y%m%d%H%M%S).tdump
jmap -dump:format=b,file=/home/app/logs/hert_heap_dump_$(date +%Y%m%d%H%M%S).hprof 21
注意,要重启pod前先将转储的文件拷贝到本地电脑。
快速试错
重启hertzbeat服务。重启后发现原本宕机的采集任务,恢复上线。
推测是hertzbeat服务性能问题导致采集任务宕机。
信息可视化
连接visulaVm
因为是测试环境,可以使用visulaVm对hertzbeat服务做一个堆,线程监控。本地windows安装visulaVm后连接远程服务。
具体连接操作为:(待完善,k8s管理的服务,开通jconsle连接端口)
连接好后如图:
本次处理中关注的关键信息:
Uptime: jvm运行时长
Heap/metaspace:堆信息/元空间
Threads:线程创建和销毁信息
图中反馈的问题:
1.堆占用巨大,快10G并且在频繁gc (首先应该限制这么大的堆)
2.线程创建总数 5w+,存活 300+,守护线程300+。反映出有非常多的线程创建后就销毁。(频繁创建线程会消耗cpu)
问题处理:
注意,如果有k8s可视化页面,在页面操作就行。比如rancher,以下以rancher为例(直接用命令修改k8s配置文件也是相同的)
1.针对大堆,检查容器启动命令,发现k8s没有配置pod资源限制,和java -jar启动没有设置堆信息。
查看k8s资源限制:
修改k8s配置文件
kubectl edit deployment hertzbeat-serv(服务名称) -n devops(命名空间)
没有resources limit字样。
设置资源限制路径:
deployment -> edit config -> resources -> memoryLimit (设置的是pod的资源,java启动比这个小)
配置为3Gi
设置java启动参数。找到hertzbeat启动命令添加 -Xmx2048m -Xms2048m
2.针对线程创建问题。
选择live thread和 finished thread进行查看。
观察到有大量live thread是与mqtt有关,这个是自定义拓展的代码线程。
如果在上面就能判断创建后销毁的线程大部分都是mqtt相关的话,可以直接搜索代码。关键字 mqtt之类。
我之前使用豆包生成的java代码解析jstack生成的 线程dump.txt文件(并发截图时的线程dump),结论为:
===== MQTT线程统计结果 =====
当前存活的MQTT线程总数:219
估算的MQTT线程总创建数:36963
估算的MQTT线程销毁数:36744
找到代码:
CommonDispatcher 类中处理任务下发的线程池,发现创建的线程池为:
int coreSize = Math.max(2, Runtime.getRuntime().availableProcessors());int maxSize = Runtime.getRuntime().availableProcessors() * 16;workerExecutor = new ThreadPoolExecutor(coreSize,maxSize,10,TimeUnit.SECONDS,new SynchronousQueue<>(),threadFactory,new ThreadPoolExecutor.AbortPolicy());
SynchronousQueue队列的意思时,核心线程用完后,任务到达队列,则直接按照最大线程数进行创建。
参考visulavm线程存活信息,重新设置新的线程池进行替换,原hertzbeat线程池不动。
新线程设置为:
int coreSize = 500;int maxSize = 1500;collectExecutor = new ThreadPoolExecutor(coreSize,maxSize,10,TimeUnit.MINUTES,new SynchronousQueue<>(),threadFactory,new ThreadPoolExecutor.AbortPolicy());
修改jvm堆为2g,和线程池500后运行观察结果
结果图:
问题:
1.hertzbeat堆最大2g,运行近40分钟后pod被重启,看着是oom kill,查看rancher,发现这个pod的确被oom kill,且存在restart次数。
解决问题:
1.线程创建多,且没有线程复用的问题。
继续排查:
通过上面的图可以看出,heap图,不停在gc,但每gc一次,堆的使用则比之前大一点,直到达到最大堆触发 oom被k8s kill重拉。
怀疑是gc后对象没有被及时清理,或者堆内存泄漏。
visulaVm分析堆内存占用
将堆dump文件导入visulaVm。
在summary页面。
发现mqtt相关的占到了77.8%
右键这行,点击open in new tab
看到类 MqttSubscribedPublishFlowTree 这个是mqtt发布订阅的代码。
于是想到业务上是用mqtt的同步响应模式进行数据采集。找到这个代码
大概为:
每次hertzbeat执行采集,都会触发到这个代码。
代码先订阅,在发布采集消息。
在高频的采集任务下,会出现高频订阅,而订阅本质是长期关联的,因此优化为单个设备采集topic就订阅一次。
优化这个后,运行2小时,查看堆dump文件:
使用mat分析堆内存泄漏
获取java堆的dump文件,存放到本地,用mat打开。
注意mat如果打不开卡死了,则需要配置他内存大小,路径:
mat安装文件夹,MemoryAnalyzer.ini文件,设置-Xmx和-Xms,默认1g。我给的3g
使用mat加载dump文件。
点file -> open xx
导入后总览为:
推荐查看:
Leak Suspects
这里会列出嫌疑比较大的。
上面已经有类名了,直接搜这个类名:
MemoryDataStorage
发现是hertzbeat存储实时数据的核心类。有2中实现。内存,redis。
查看hertzbeat nacos配置:
real-time:memory:enabled: trueinit-size: 16redis:enabled: false# redis mode: single, sentinel, cluster. Default is singlemode: single# separate each address with comma when using cluster mode, eg: 127.0.0.1:6379,127.0.0.1:6380address: 127.0.0.1:6379# enter master name when using sentinel modemasterName: mymasterpassword: 123456# redis db index, default: DB0db: 0
的确,这里也使用的是内存。
切换到redis 后重启服务。
排查内存泄漏后继续观察
visulaVm截图:
已运行2小时多。
此时继续查看mat信息:
这个problem 1在上面mat图的第二个problerm。
暂不处理这个,继续观察hertzbeat再看看。
更新运行结果:
结果上看优化有效果。7小时,没有崩溃。
看服务器上top信息,hertzbeat cpu在30~80%之间,多数在60%以下。
看hertzbeat 采集任务,没有宕机。
看web采集结果正常。
到此优化完成。
到此,优化的点为:
修改前:visulaVm监控8h内总计创建7w线程,活跃线程400+,守护线程100+,且堆占用到了15G,且hertzbeat页面,存在约一半采集任务宕机情况。
1.修改了执行采集任务的线程池,配置核心500 最大1500
修改点:CommonDispatcher中分发采集任务的线程池改造
修改后:观察2H,线程创建总数1100左右,存活640,守护线程100+
2.分析堆dump文件,查看主要占用内存数据,找到,MqttSubscribedPublishFlowTree,发现采集的mqtt同步响应模式下存在重复订阅问题。
优化订阅次数,完成1个模拟器,1个topic订阅1次。
3.给pod增加容量限制3G,堆增加限制最大,最小2G
修改点:配置堆最大,最小为2G,给pod增加资源限制3G
修改后:观察40Min,存在重启pod现象,因为oom,观察到频繁gc且,gc后,内值在不断变大。怀疑内存泄漏
用mat分析发现,MemoryDataStorage占用内存高。(这个是存放采集的实时数据核心类)
4.将检测采集的实时数据,修改到redis
修改点:将hertzbeat实时数据采集nacos配置,从内存,改动到redis
修改后:观察20min后,堆占用在220m到890m之间波动,
排查建议
建议将堆信息,比如作为提问内容,且带上怀疑代码,直接问ai这有什么可以优化的,或者是否有问题。