ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

Prometheus误报MySQL重启?问题出在process_start_time_seconds

Prometheus误报MySQL重启?问题出在process_start_time_seconds 凌晨2点14分手机连续震了三下。告警标题写得很直接MysqlRestart严重级别critical内容提示“order-db疑似重启”。打开Grafana运行时长曲线确实是一条标准断崖——几分钟前还在三千九百秒的位置下一个点直接归零然后重新爬坡。按一般经验这是典型的“进程重启”图形。可当我切到mysqld_exporter的指标看到mysql_global_status_uptime还在老老实实地递增连接数没有断过进程号也没变才发现数据库根本没动。这一篇我就把这类“数据库没动、Prometheus却说重启”的假告警拆开讲核心不在于Prometheus不靠谱而在于我们让监控读了一个不该读的指标。它叫process_start_time_seconds跟数据库之间只差了一个进程的“毫厘”却足以让整个告警说谎。1. 告警现场还原一场Prometheus发来的“重启”风波1.1 凌晨两点那条刺眼的告警先看当时收到的告警规则长什么样。因为这类规则太常见了几乎每个从模板复制监控面板的人都会踩一次- alert: MysqlRestart expr: changes(process_start_time_seconds{jobnode}[2m]) 0 for: 1m labels: severity: critical component: mysql annotations: summary: MySQL实例疑似重启规则的本意很朴素process_start_time_seconds一旦发生变化就说明进程的启动时间戳变了也就是“重启了”。这个逻辑本身没有错错的是它监控的“进程”。jobnode指的是node_exporter的采集任务所以这个规则真正监控的是node_exporter这个进程有没有重启而不是MySQL。我当时打开Grafana看到的面板更是经典time() - process_start_time_seconds{instance10.0.8.15:9100, jobnode}这条PromQL把当前时间减去node_exporter进程的启动时间算出“运行时长”。正常情况下它会是一条平稳递增的线可一旦node_exporter重启启动时间戳会从几个月前的值变成一个刚刚生成的秒级时间戳time() - process_start_time_seconds会瞬间从几十万秒跌到几秒。在图表上这就是一道标准的悬崖式断崖。这个“断崖”形态太有迷惑性了它和数据库真重启的图形长得一模一样。人眼看到曲线归零第一反应都是“服务崩了”。1.2 数据库死不承认但监控曲线确实断崖了我当时的排查顺序是这样的先看mysql_global_status_uptime这个指标来自mysqld_exporter对应MySQL内部的SHOW GLOBAL STATUS里的Uptime是MySQL自己统计的存活秒数。查到的值是359912还在持续递增。再用mysqladmin ping连上去返回mysqld is alive。查看数据库进程PID没有变化。翻数据库error log没有启动、关闭、崩溃的痕迹。SHOW SLAVE STATUS复制线程也正常。全套验证下来MySQL确实没重启。但Prometheus一侧process_start_time_seconds{instance10.0.8.15:9100, jobnode}这个值确实变了。再看告警时间点和grafana面板的断崖时间严丝合缝。这时候基本可以确定不是数据库重启了而是node_exporter重启了。一个常见的反驳是数据库没动node_exporter也没人碰它怎么会自己重启答案就藏在node_exporter自己的运行状态里。当天晚上那台机器上有systemd配置了Restarton-failurenode_exporter因为内存紧张触发了OOM killer内核把它杀掉之后systemd自动拉起了新进程。整个过程不过一两秒但对Prometheus来说下一次scrape拿到的process_start_time_seconds就是另一个值了。这件事的“毫厘”藏在哪就藏在监控对象和真实对象之间差了那么一个进程。规则写的时候少看了一眼job标签面板复用的时候没改instance端口都会掉进这个坑。2. 毫厘之间的真相process_start_time_seconds到底在说谁2.1 从源码看这个指标到底怎么算出来的process_start_time_seconds这个指标几乎由所有基于client_golang的Prometheus exporter暴露包括prometheus自身、node_exporter、mysqld_exporter、postgres_exporter等。它表示的是当前这个exporter进程的启动Unix时间戳单位是秒。这个值的来源在github.com/prometheus/client_golang/prometheus/process_collector.go里写得很清楚process_start_time_seconds btime starttime / USER_HZ其中btime来自/proc/stat表示系统的启动Unix时间戳。starttime来自/proc/pid/stat的第22个字段表示当前进程自系统启动以来经过的clock ticks数。USER_HZ通常是100也就是说一个tick等于10毫秒。因为starttime除以USER_HZ通常不是整数所以这个指标的值经常是带小数的比如1692000000.37。这也是“毫厘”两个字在字面上最直观的体现一个看起来精确到秒的指标小数点后其实带着tick余数精度是毫秒级的。问题在于node_exporter暴露的process_start_time_seconds说的是node_exporter自己的启动时间mysqld_exporter暴露的process_start_time_seconds说的是mysqld_exporter的启动时间。它们都不是数据库进程的启动时间。很多人会觉得“既然exporter和数据库跑在同一台机器上exporter不重启数据库应该也没事吧”。这种想法在物理机裸部署时代勉强成立但一旦exporter被systemd自动拉起、被容器编排系统重建、被OOM杀掉再恢复它跟数据库的进程生命周期就彻底分道扬镳了。exporter可以一分钟重启五次数据库连一根连接都不掉。2.2 为什么exporter的“自我时间”会被当成数据库的重启信号我复盘过很多次这类误配置通常会从下面三个路径溜进来路径一模板复用。网上很多现成的Grafana Dashboard都带一个“运行时长”面板里面的PromQL直接写time() - process_start_time_seconds{jobnode}。用户导入模板后只改了instance的IP没注意这个指标代表的是node_exporter进程本身。路径二同名不同身。Prometheus自身有process_start_time_secondsnode_exporter有mysqld_exporter也有。指标名一模一样如果在PromQL里不限定job和instance查询会把所有target的这个指标全部抓出来。只要任何一个exporter重启整个面板都会出现一条断崖。更夸张的是如果Prometheus服务器自己重启过所有历史面板的“运行时长”都会同步跳变一次。路径三告警规则不带业务标签。像前面那条规则changes(process_start_time_seconds[2m]) 0后面既没有jobmysql也没有和mysql_up做联合判断。它监控的是一个通用进程指标而不是数据库状态指标。这个规则的准确率取决于exporter和数据库的进程生命周期绑定得有多紧。这里我特别想强调指标名相同不代表监控对象相同。这是监控系统里最容易栽跟头的语义陷阱。同样是process_start_time_seconds放在node_exporter的target下就是node_exporter的生命周期放在mysqld_exporter的target下就是mysqld_exporter的生命周期。一个MySQL实例压根不会直接暴露这个指标除非你用的监控agent把数据库进程信息也采集进来了。2.3 当晚node_exporter为何会重启要实锤“node_exporter重启”这个根因不能靠猜。我是这样查的journalctl -u node_exporter --since 02:10:00 --until 02:16:00日志里能看到两段关键内容Feb 22 02:13:41 db1 systemd[1]: node_exporter.service: Main process exited, codekilled, status9/KILL Feb 22 02:13:41 db1 systemd[1]: node_exporter.service: Failed with result signal Feb 22 02:13:41 db1 systemd[1]: node_exporter.service: Scheduled restart job, restart counter is at 3. Feb 22 02:13:41 db1 systemd[1]: Stopped Prometheus Node Exporter. Feb 22 02:13:41 db1 systemd[1]: Started Prometheus Node Exporter.再加上一句dmesg | grep -i -E oom|killed process --since 02:10:00能看到内核OOM的记录。node_exporter本身内存占用不高但机器上如果还有别的服务在高峰期抢内存内核会在内存严重不足的时候优先杀进程。这就是为什么“没人碰它它自己重启了”。在容器化环境里原因更五花八门。常见的有Pod滚动更新时node_exporter容器被重建。Docker daemon重启导致容器被调度到另一台节点。资源limit设置不当容器被OOM Kill后由重启策略拉起。node_exporter自身在解析某些异常文件系统时panic。发布运维脚本顺手systemctl restart node_exporter。不管哪种原因只要exporter的PID变了process_start_time_seconds就会变这条曲线的断崖就会出现。而真正的数据库可能全程稳如老狗。3. 用三分钟实验把“谎报”钉死3.1 手动重启node_exporter复现假重启如果你也遇到“数据库没动监控说重启”的诡异情况建议别急着改规则先做个可控实验把因果链钉死。方法很简单三步第一步在Prometheus里查一下当前的基线值process_start_time_seconds{instance你机器IP:9100, jobnode}记下这个值。假设是1692000000.37。第二步手动重启node_exportersudo systemctl restart node_exporter第三步等一个scrape周期Prometheus默认15秒左右再查同一个查询。此时你会看到值变成了一个全新的时间戳比如1692100000.52。同时再查一下数据库的真实状态指标mysql_global_status_uptime{instance你机器IP:9104}这个值会保持连续递增不会因为node_exporter的重启而跳变。对照结果非常直观指标监控对象重启前重启后是否变化process_start_time_secondsnode_exporter进程1692000000.371692100000.52变化mysql_global_status_uptimeMySQL实例359912359927未变连续递增mysql_upmysqld_exporter连接MySQL状态11未变这个实验能一锤定音地证明告警所依赖的指标重启的是node_exporter不是数据库。3.2 从instance端口和job标签识破“同名指标”还有一个更快的判断方法看告警里的instance端口。Prometheus生态里的exporter端口号基本是约定俗成的node_exporter默认9100mysqld_exporter默认9104postgres_exporter默认9187redis_exporter默认9121如果一条标着“MySQL重启”的告警instance是10.0.8.15:9100那它盯的其实是node_exporter。真正的MySQL实例相关指标应该来自10.0.8.15:9104。同样的道理Grafana面板的PromQL里如果出现jobnode配上process_start_time_seconds它画的永远是node_exporter的进程运行时长。想画MySQL实例的运行时长应该用jobmysql下的mysql_global_status_uptime或者直接用time() - pg_postmaster_start_time_seconds这类数据库侧指标。端口和job标签就是监控世界的“身份ID”。毫厘之差指的就是这里同样叫process_start_time_secondsjobnode和jobmysql是两个完全不同的生命体。4. 把“数据库是否重启”的规则写成不会说谎的样子4.1 别用changes()判断这种每秒都在变的gauge先说一个常见的反向误区。有人发现process_start_time_seconds不靠谱之后决定改用mysql_global_status_uptime来判断重启然后写了一条规则changes(mysql_global_status_uptime[5m]) 0这条规则是错的而且会一直告警。原因很简单mysql_global_status_uptime是一个每秒都在涨的gauge每抓取一次样本它的值都会变化。changes()统计的是“样本值有没有发生改变”而不是“有没有归零”。所以对uptime这类单调递增的指标来说changes()几乎永远大于0。正确的判断方向是看它有没有下降。正常运行的MySQLmysql_global_status_uptime只增不减。一旦它出现明显下降比如5分钟前还是60000秒现在只有10秒那就是实例重启了。所以规则应该写成delta(mysql_global_status_uptime[5m]) 0这条表达式计算5分钟内mysql_global_status_uptime的变化量。正常运行时会得到一个正数大约是5m窗口内的真实运行秒数如果数据库重启了最新值会远小于窗口起始时的值delta就会变成负数告警被触发。4.2 MySQL、PostgreSQL、Redis重启告警的正确指标不同数据库正确指标各不相同。我用过的组合里比较靠谱的有下面这些数据库指标说明MySQLmysql_global_status_uptime来自mysqld_exporter对应SHOW GLOBAL STATUS的UptimePostgreSQLpg_postmaster_start_time_seconds来自postgres_exporter反映postmaster主进程启动时间Redisredis_uptime_in_seconds来自redis_exporter对应INFO里的uptime_in_secondsMongoDBmongodb_uptime_seconds来自mongodb_exporter来自serverStatus的uptime拿PostgreSQL举例重启判断可以直接看pg_postmaster_start_time_seconds有没有变化。因为postmaster就是PostgreSQL的主进程它的启动时间就是数据库实例的启动时间。MySQL没有这么直接的指标所以要用mysql_global_status_uptime的下降来推断。Redis的redis_uptime_in_seconds和MySQL的uptime类似正常只增不减用delta() 0判断同样有效。4.3 更稳的多指标互证写法任何单指标告警都有盲区。比如Prometheus在某一轮scrape里网络抖动mysql_global_status_uptime可能暂时没有新样本delta()窗口边缘对不齐容易产生边界噪声。我现在的做法是加一层互证条件(delta(mysql_global_status_uptime[5m]) 0) and (mysql_up 1)mysql_up 1表示mysqld_exporter当前成功连上了MySQL。这个条件排除了一部分因为抓取失败导致的“数据缺失假下降”。当然它不能完全消除前面说的边界噪声但能显著降低误报率。再配合for: 1m让告警持续一分钟才触发。这个for参数很关键它让“毫厘之内的瞬时抖动”有时间归于平静。关掉for会让告警对任何边界状态都过度敏感。另外delta(mysql_global_status_uptime[5m])窗口不建议设得太短。窗口小于scrape interval的两倍时样本数量太少反而容易产生不可预期的结果。我习惯把scrape interval设为15秒窗口至少设2分钟。还有一个技巧在看板里同时展示mysql_up和mysql_global_status_uptime两条线叠在一个图上。当某次告警来临先看mysql_up那条线有没有瞬时掉线。如果只是exporter与数据库之间的连接断了一拍mysql_up会有短暂为0的点如果是真重启mysql_global_status_uptime的曲线会先断崖再重新爬坡而mysql_up在重启完成后会恢复为1。图形上的差别比告警文字更容易识别。5. 假告警排查方法论从告警文字走到指标语义5.1 五步定位流程那次踩坑之后我把整个排查过程固化成了一套流程。遇到任何“数据库疑似重启”的告警按这个顺序走十分钟内基本能定位真相。第一步查告警的instance端口。9100就是node_exporter9104才是mysqld_exporter。端口对不上先怀疑规则引用了错误target的指标。第二步查数据库真实状态指标。MySQL看mysql_global_status_uptimePostgreSQL看pg_postmaster_start_time_secondsRedis看redis_uptime_in_seconds。这个指标如果纹丝不动数据库大概率没重启。第三步查exporter的进程生命周期。用up{jobnode}看target当前是否在线再用process_start_time_seconds{jobnode}对比告警时间点前后的变化。第四步回溯exporter的日志和系统事件。journalctl -u node_exporter、dmesg、容器事件找到它重启的直接原因。第五步把告警时间、exporter重启时间、数据库error log时间的三条时间线对齐。如果exporter重启时间和告警触发时间完全重合而数据库日志一片安静那这起“重启”就是假的重启。5.2 现场时间线复盘表格我不习惯看完就下结论而是把时间线拉出来做个表格对照。那次事件的真实时间线长这样时间Prometheus侧数据库侧02:13:41node_exporter进程被OOM killsystemd自动拉起新进程error log无任何记录02:13:56Prometheus下一次scrape采集到新的process_start_time_seconds无影响02:14:01changes()判断指标变化告警进入pending状态无影响02:15:01告警for条件满足触发critical告警无影响02:15:03收到手机推送mysql_global_status_uptime从359912递增到359927表格一拉出来真相就藏不住了Prometheus侧的所有异常都发生在02:13:41到02:15:01之间数据库侧全程无变化。所谓“数据库重启”只是监控规则内部的一次“乌龙事件”。5.3 建立指标语义登记表杜绝下次同名误会这次经历之后我给团队立了一个规矩每个exporter接入时必须维护一张“指标语义登记表”。表里面写清楚每个核心指标代表哪个进程、哪个对象以及它的误判风险。指标名暴露者真实语义常见误判process_start_time_secondsnode_exporternode_exporter进程启动时间误认为主机或数据库启动时间process_start_time_secondsmysqld_exportermysqld_exporter进程启动时间误认为MySQL实例启动时间mysql_global_status_uptimemysqld_exporterMySQL实例存活秒数无pg_postmaster_start_time_secondspostgres_exporterPostgreSQL主进程启动时间无redis_uptime_in_secondsredis_exporterRedis实例存活秒数无node_boot_time_secondsnode_exporter操作系统启动时间误认为数据库启动时间这张表还有个额外作用新人刚接手监控体系时不用从零啃代码。看一眼表就明白哪些指标能用于告警哪些指标只能用来观察exporter自身的健康状况。6. 常见误报组合与防御习惯6.1 常见“假重启”现象速查表我把实际工作中遇到过的几类误报组合整理了一下你自己排查时可以对照着看现象可能根因排查方向解决方案process_start_time_seconds断崖但mysql_uptime正常规则用了node_exporter的进程指标查看告警instance端口和job标签改用mysql_global_status_uptime判断重启process_start_time_seconds和mysql_uptime同时异常数据库真重启或主机崩溃重启查看数据库日志、主机重启记录按真实故障处理并检查主备切换逻辑mysql_up短暂为0后恢复uptime无变化mysqld_exporter和MySQL之间的连接断拍查看exporter日志、网络情况调大scrape_timeout检查连接池配置多个target的process_start_time_seconds同时跳变Prometheus自身重启或Prometheus所在主机重启查看Prometheus日志和node_boot_time_seconds区分监控对象与被监控对象Grafana运行时长曲线呈锯齿状小幅波动time()与被监控主机存在时钟偏差检查NTP同步状态保证监控和被监控主机时间同步避免毫秒级阈值6.2 三个最容易踩的“毫厘坑”第一个坑叫“对象毫厘”。指标名一样前面的job和instance不同指向的就是完全不同的对象。我的经验是写告警规则时一定要显式带job或instance不要省。不带限定条件看起来“覆盖全面”实际上把所有exporter的进程生命周期全卷进来了。第二个坑叫“时间毫厘”。process_start_time_seconds本身是秒级时间戳但不是整数它带tick余数。用time()去和它做差值绕不开两边主机的时钟偏差。哪怕偏差只有几十毫秒在Grafana那种精确到秒甚至毫秒的图表上都能画出微小锯齿。所以和“运行时长”相关的计算别用毫秒阈值卡死。第三个坑叫“阈值毫厘”。for: 0m的告警规则对瞬时抖动零容忍。Prometheus的抓取间隔、规则评估间隔、网络偶发超时这些因素叠加起来本来就会产生毫秒级误差。给告警加一个合理的for本质是让系统容忍“正常范围内的微小扰动”。6.3 每月做一次告警演练的习惯最后一个建议可能有点反直觉想减少假告警反而要主动制造告警。我现在每个月都会挑一个低峰期手动重启一次node_exporter、mysqld_exporter甚至停掉Prometheus的抓取任务一小会儿。目的就是观察告警系统会不会误报。如果重启exporter之后MysqlRestart告警风控正确没有触发说明规则已经改对了。如果还在误报那就继续修。这种演练成本很低却能持续校验监控规则的有效性。很多团队只关心“监控能发现真故障”却忽略了“监控不能总报假故障”同样重要。一次假告警会消耗值班人员半小时还会让人对后续真实告警失去敏感度。等到真正出事时反而没人信了。我个人在实际操作中的体会是Prometheus监控本身没有错它只是忠实地反映了你让它采集的那个指标。数据库没动监控却“谎报”重启问题永远出在指标语义和告警规则的错配上。现在每次有人拿着类似截图来找我我通常只回一句你先看一眼告警里的instance端口是9100还是数据库的真实端口。很多时候真相就在这毫厘之间。
返回列表