TiDB node_exporter采集缓慢超时

【 TiDB 使用环境】生产环境
【 TiDB 版本】5.3.0
【复现路径】混部环境
【遇到的问题:问题现象及影响】
问题现象:curl node1:9100/metrics 耗时10-20s才能采集到,甚至有时候需要更长的时间。
影响:grafana监控线条断断续续
原因排查:
默认情况下,启动参数为:bin/node_exporter/node_exporter --web.listen-address=:9100 --collector.tcpstat --collector.systemd --collector.mountstats --collector.meminfo_numa --collector.interrupts --collector.buddyinfo --collector.vmstat.fields=^.* --log.level=info
从现象看,是采集慢。因此尝试调整collector列表进行排除法定位。测试发现:启用 --collector.systemd后,采集瞬间变慢。因此,慢的原因定位到了!就是collector.systemd这里慢
想知道的是:
1、collector.systemd到底采集了哪些数据?禁用采集后,对于监控影响面在哪?
2、如何进一步定位为什么采集systemd会变慢呢?尝试过 strace -f -T -tt 启动node_exporter,并不能很明确给出哪儿慢了,看起来每次调用都挺快…

【资源配置】32C 256G *3台
【附件:截图/日志/监控】存在企业水印,或许涉密,因此截图就不发了…附件是我strace的日志
strace.log (41.3 MB)

time=“2024-01-24T19:07:43+08:00” level=error msg=“error encoding and sending metric family: write tcp IP1:9100->IP2:53648: write: broken pipe\n” source=“log.go:172”

补充一下,机器的dbus-daemon CPU利用率50%,其余节点1-2%

https://github.com/prometheus/node_exporter/issues/2585

我看到node_exporter项目下有人建议systemd的采集需要一个超时时间。
但是目前还没有改。这个issue还是open的。

大佬说得对,这个链接排查的时候搜到过,但是没啥响应,难道其他人没遇到过?

@h5n1 @Billmay表妹 诚邀两位大佬协助分析下。

是不是跟日志的采集级别有关

说不通吧。其他服务器一样的配置,也没这个问题。
响应20s的metrics接口,其中:
mount信息 4286
ssh信息 76514
其他:
1810 node_systemd_unit_state
800 node_interrupts_total
362 node_systemd_unit_start_time_seconds

https://github.com/prometheus/node_exporter/blob/c914f0052629e3c99449bdfb4fa7189ce09e77b5/collector/systemd_linux.go#L201

level.Debug(c.logger).Log(“msg”, “getAllUnits took”, “duration_seconds”, time.Since(begin).Seconds())

代码里面有一些逻辑会输出执行的了多少秒。但是日志级别是debug。

实在不行,就只能调低日志级别,看看到底是在那个地方耗时长了。

感觉和日志级别有关

今天我抽空调整日志级别看看!迟些回复

1 个赞

各位大佬新年好。年后我来补充报错。
调整node_export日志等级后,日志提示如下:
大量的如下信息:
time=“2024-02-19T15:27:49+08:00” level=debug msg=“couldn’t get unit ‘sshd@30434801-IP地址1:22-IP地址2:49440.service’ NRestarts: Unknown property or interface.” source=“systemd_linux.go:256”
time=“2024-02-19T15:28:04+08:00” level=debug msg=“Adding unit: sshd@30448417-IP地址1:22-IP地址2:49440.service” source=“systemd_linux.go:325”

最终输出耗时:
DEBU[0099] OK: systemd collector succeeded after 79.567751s. source=“collector.go:135”

现在现在的核心问题是,
1、为什么有如此多的sshd@.service信息
2、连接从哪儿来。
3、即使有,也不应该阻塞采集才对。

[root@node1 ~]# systemctl status
● node1
State: degraded
Jobs: 0 queued
Failed: 12742 units
Since: Fri 2023-04-28 10:19:12 CST; 9 months 23 days ago

https://github.com/prometheus/node_exporter/issues/2500

你可以参考一下这个,是否是内核问题。

The 5.4.0-135 kernel seems to have fixed this issue for me. More than 24 hours now without issue.

感谢!
我看看这个issue

我们当前还是
Linux node1 3.10.0-1160.el7.x86_64 #1 SMP Mon Oct 19 16:18:59 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

https://github.com/prometheus/node_exporter/issues/2387

这个是检测到网络原因。可以检测一下网络和这个机器的负载情况如何,混合部署在这台上都是什么服务?

dbus-monitor --system 这个也截图看下。

现在基本确定是有过多的sshd@ID-IP1-IP2:端口.service信息。 collect 去收集systemd的这个信息时,有1W多条失败,导致采集变慢

已经解决掉了。最终执行命令:
systemctl reset-failed来清理failed服务。这样systemd就不再记录这些信息,采集也就变快了。

1 个赞

根源是,我们有一台机器,会频繁的ssh到这台节点来执行shell命令获取某些监控信息,导致systemd里存在了大量的sshd相关的failed状态,采集时就变慢了。
监控节点年前就停掉了,后来一直处理巡检,就没跟进这个问题。
至此,这个问题算是告一段落。感谢各位大佬的支持!