search

mosn / holmes

self-aware Golang profile dumper
Apache License 2.0
1.08k stars 135 forks source link

cpu 突然飙高的一下触发了dump操作，但是dump下来的文件使用 go tool pprof 分析文件，好像什么都分析不出来 #123

Open sk872529557 opened 2 years ago

sk872529557 commented 2 years ago

代码： h, err := holmes.New( holmes.WithProfileReporter(r), holmes.WithCollectInterval("30s"), holmes.WithDumpPath(pprofDumpPath), holmes.WithLogger(holmes.NewFileLog(holmesLogFilePath, mlog.INFO)), holmes.WithCPUDump(30, 50,60, time.Minute), holmes.WithCPUMax(90), holmes.WithCGroup(true), ) h.EnableCPUDump()

// start the metrics collect and dump loop
h.Start()

holmes log image

pprof_file

wecom-temp-151278-ae93f62a8cb7ddf44a471a9863a220a7

看起来感觉cpu突然飙高了一下，然后又正常了，是采集周期或者参数设置的问题吗

Jun10ng commented 2 years ago

可以用文本格式的输出看一下

holmes.WithTextDump(),

ps: 输出的holmes log 里的参数配置 似乎和你代码里声明参数配置 不一致， log里是 min:20, diff:25 abs 80 代码里是 30, 50, 60

sk872529557 commented 2 years ago

image 但是这里说WithTextDump() 在cpu场景下会失效？

Jun10ng commented 2 years ago

image 但是这里说WithTextDump() 在cpu场景下会失效？

哦，是的。cpu不支持文本格式。

你能给出一个能复现的demo吗，我尝试debug一下

sk872529557 commented 2 years ago

这个是线上容器正在跑的程序，不太好给出demo 也是偶发现象。。。。 也不太好判断这个突然上涨的cpu是采集程序的问题，还是我们容器中程序或者其他问题，从我们自己的监控看cpu并没有出现向log中的尖刺

Jun10ng commented 2 years ago

明白了。 请问这个pprof事件发生的时间点离服务启动的时间近吗？

sk872529557 commented 2 years ago

服务启动一段时间后报出来的，而且是不太稳定的偶发现象，我们看下先调整参数处理。

nejisama commented 2 years ago

这就是标准的pprof文件，dump的是cpu高那一会的快照。可以看下cpu占用情况，然后和正常的pprof对比一下 来看是哪里增高了

Jun10ng commented 2 years ago

这就是标准的pprof文件，dump的是cpu高那一会的快照。可以看下cpu占用情况，然后和正常的pprof对比一下 来看是哪里增高了

是标准的 profile文件，但是profile里没有sample。是不是不太正常。

cch123 commented 2 years ago

感觉不太正常，profile文件能分享么

sk872529557 commented 2 years ago

文件链接 https://github.com/sk872529557/simpleGo/blob/main/cpu.20220922134326.843.log

doujiang24 commented 2 years ago

这个 profile 文件里，完全没有采样的数据，难道是飙升之后， CPU 跌到几乎为 0 了？

holmes 的逻辑是，飙升之后，会触发采样，采样时长为 5s 如果这 5s 期间，异常消失了，那也是没有办法捕获异常的了

只是你这个文件里，一点数据都没有，比较怀疑是，CPU 跌到几乎为 0 了 你那边有秒级的 CPU 监控不呢？

Jun10ng commented 2 years ago

如果这 5s 期间，异常消失了，那也是没有办法捕获异常的了

就算异常消失了，应该还有在运行的函数，除非这些函数运行很快，无法以默认的频率(100hz)捕获到它们。

sk872529557 commented 2 years ago

我们的容器cpu监控并没有异常，所以现在不太清楚是holmes采集的问题，还是我们监控的问题。 目前看也有能正常dump的cpu pprof 这个问题还没再复现过。

doujiang24 commented 2 years ago

如果这 5s 期间，异常消失了，那也是没有办法捕获异常的了

就算异常消失了，应该还有在运行的函数，除非这些函数运行很快，无法以默认的频率(100hz)捕获到它们。

所以，这里说的是两个问题：

  1. 异常消失，cpu 恢复正常，没法捕获异常，是符合 holmes 机制预期的
  2. profile 完全没数据，只能怀疑 cpu 几乎跌到为 0 了
doujiang24 commented 2 years ago

我们的容器cpu监控并没有异常，所以现在不太清楚是holmes采集的问题，还是我们监控的问题。 目前看也有能正常dump的cpu pprof 这个问题还没再复现过。

你们的监控，有秒级的数据么？如果是分钟级的平均数据，通常是看不出来异常的 holmes 采集的秒级的瞬间值，这个细节需要注意下的

Darrenzzy commented 1 year ago

https://github.com/mosn/holmes/issues/123#issuecomment-1260300293 是的，大家要知道监控是秒级的，这样才能第一时间捕获到信息， 至于上报和后面消耗io的事情可以时间拉久一点。 设置5分钟告警一次即可。