记录测试环境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之间波动，