29毫秒迟到引发的MySQL监控误报：Prometheus连接池与超时排查实录

凌晨三点手机连着震了八次屏幕上全是同一个内容[FIRING] MySQLExporterDownPrometheus 告警说 MySQL 监控目标已经不可达。我第一反应是数据库挂了但当我连上数据库执行SHOW GLOBAL STATUS LIKE Uptime看到结果那一刻人直接愣了。Uptime 稳定在 124 天进程没重启会话正常慢查询没有磁盘 IO 没有异常。数据库完全没动监控却在煞有介事地喊“重启”。这种事经历过一次就会刻进 DNA。排查到最后真相藏在一段毫秒级的时间差里——准确说是迟到了 29 毫秒的 HTTP 响应。这篇文章我不讲虚的直接把这次“监控谎报数据库重启”的事故现场、排查链路、根因分析和修复方案完整复盘出来。对于正在用 Prometheus mysqld_exporter或者任何数据库 exporter监控业务库的同学尤其是监控告警偶发、但查来查去数据库都没问题的场景这篇值得你从头看到尾。里面涉及的抓包时间线、连接池空闲连接回收、scrape_timeout 与 scrape_interval 的匹配关系都是平时文档里很少写透的东西。1. 凌晨三点被一个“重启”告警吵醒1.1 告警内容MySQL exporter 消失了 48 秒先说清楚这次告警长什么样因为“假重启”这个结论很大程度上是告警文案误导出来的。我们的监控体系是 Prometheus mysqld_exporter Grafana/Alertmanager数据库是云上的 MySQL 实例。告警规则大概是这样的groups: - name: mysql_alerts rules: - alert: MySQLExporterDown expr: up{jobmysql} 0 for: 2m labels: severity: critical annotations: summary: MySQL exporter 不可达 description: Prometheus 抓取 {{ $labels.instance }} 失败持续时间超过 2 分钟请立即排查数据库是否重启。凌晨那会儿Alertmanager 收到的告警信息里明确写着up{jobmysql}为 0已经持续了 2 分钟。按照监控告警的默认理解up 0意味着这个 exporter 挂了而 exporter 和数据库共生自然就联想到“数据库重启了”。但注意这条告警里有个非常容易忽略的陷阱up指标是 Prometheus 自己生成的它只代表“这一次 HTTP 抓取是否成功”和 MySQL 实例本身的生命周期是两码事。我当时也犯了同样的错误——看到告警后第一反应不是查 Prometheus而是直接冲去数据库。告警从触发到恢复前后一共 48 秒左右期间 Alertmanager 还在做分组聚合等真正收到通知的时候监控其实已经恢复了。这种“来也匆匆去也匆匆”的告警比持续不可达更让人头疼因为你去现场看的时候所有表象都是正常的唯一留下的线索就是 Prometheus 里那段断点时间序列。1.2 第一波操作以为数据库挂了结果数据库一脸无辜接到告警后我的操作顺序按惯例来先确认数据库状态再查 Prometheus 目标状态最后看 exporter 日志。第一步就碰壁了。连上数据库以后我执行了这几条命令SHOW GLOBAL STATUS LIKE Uptime; SHOW GLOBAL STATUS LIKE Threads_connected; SHOW FULL PROCESSLIST;结果分别是Uptime10713600 秒约 124 天远超这次事故的时间跨度Threads_connected23平稳SHOW FULL PROCESSLIST没有任何异常长事务、没有锁等待、没有堆积的查询。我又跑到数据库主机上用ps -eo pid,etime,cmd | grep mysqld看了一眼进程运行时间进程启动时间同样是 124 天前。也就是说从数据库实例、操作系统进程、连接数、会话状态四个维度看MySQL 都“没动过”。问题显然不在数据库这一层。但 Prometheus 界面上up 0又是铁板钉钉的事实。这时候我怀疑过 exporter 是不是被容器调度器杀了重启甚至一度想直接systemctl restart mysqld_exporter草草了事。还好没这么干——如果光把 exporter 重启症状会消失但根因会继续潜伏后面大概率还会再犯。这个“没这么干”是我整场排查里做过的最正确的决定。2. 为什么数据库没动监控会判定它“重启”2.1 监控链路的三个跳点任何一个断了都会报错要搞懂“谎报重启”必须把这条监控链路拆开看。Prometheus 抓 MySQL 指标不是直连数据库的 3306 端口而是有一条完整链路Prometheus --HTTP-- mysqld_exporter(:9104) --MySQL协议-- MySQL(:3306)这条链路上有三个跳点Prometheus 到 exporter 的 HTTP 链路Prometheus 按照scrape_interval定时发起 HTTP GET 请求到 exporter 的/metrics端点并受scrape_timeout约束。只要请求超时、连接被拒、返回非 200Prometheus 就会把up标记为 0。exporter 到 MySQL 的连接链路mysqld_exporter 本身是用 Go 写的底层通过database/sql连接池管理到 MySQL 的连接。每次抓取任务进来exporter 从连接池拿连接执行一系列查询SHOW STATUS、SHOW VARIABLES、SHOW PROCESSLIST、查询performance_schema等收集完指标后序列化为 Prometheus 格式。TCP/IP 链路上的中间设备这是最容易被忽略的一环。exporter 和数据库之间可能经过云负载均衡、防火墙、交换机甚至容器网络里的 NAT 网关。这些中间设备普遍有“空闲连接回收”策略一个 TCP 连接如果空闲时间超过阈值会被设备默默断掉。任何一个跳点出现问题最终表现都可能是up 0。但很多人都默认“exporter 和数据库在一台机器上中间链路不会有问题”尤其当我们用的是云数据库时exporter 实际上是通过内网 IP 访问数据库的中间必然经过一层虚拟网络设备。恰恰是这个“想当然”把排查方向带偏了。2.2 告警规则看着是up 0背后是整整 10 秒的超时关键要理解 Prometheus 的抓取超时机制。我们当时的抓取配置如下scrape_configs: - job_name: mysql static_configs: - targets: [10.0.8.11:9104] scrape_interval: 60s scrape_timeout: 10sscrape_interval: 60s表示每 60 秒抓一次scrape_timeout: 10s表示单次抓取的硬性超时上限。超时判定的起点不是请求到达 exporter 的时刻而是Prometheus 决定发起该次抓取的时刻。为什么单独拎出这个机制说因为它直接决定了“毫厘之间”的谎言是否成立。举个例子某次抓取在03:12:20.107开始那么 Prometheus 内部设置的 deadline 就是03:12:30.107。如果请求实际在03:12:30.136才完成哪怕整个过程只多了 29 毫秒Prometheus 也会无情地把这一次抓取标记为失败up从 1 翻转为 0。而且还有一层叠加效应当 Prometheus 对一个 target 判定抓取失败后它不会立刻在下一个周期重试而是会按照指数退避策略延后下一次抓取比如本次失败后下一次调度可能被推迟到 60 秒甚至更久之后。这个推迟窗口加上告警规则的for: 2m就会让“瞬间超时”被放大成“持续 2 分钟的不可达”最终触发告警。所以当我们看到up 0并持续 2 分钟时真相可能只是某个毫秒级的超时而不是什么灾难性的进程重启。2.3 毫厘之间的计算29 毫秒怎么来的我在确认数据库没重启之后做的第一件事就是去 Prometheus 的 target 页面找到了那个“失败”的抓取周期并把它的时间戳精确记下来。同时我在 exporter 所在机器上用tcpdump抓了下一阶段的包最后把 Prometheus 调度时间、TCP 建连时间、MySQL 查询时间、HTTP 响应时间四条线合并得到了一张完整的时间线时间事件03:12:20.104上一次抓取结束连接空闲下来03:12:20.107Prometheus 发起本次 HTTP GET /metrics03:12:20.110exporter 从连接池取到空闲连接发送 MySQL 查询请求03:12:20.112连接被中间设备标记为失效TCP 层收到 RST03:12:20.114Go 的 database/sql 检测到坏连接自动尝试重连03:12:20.410TCP 三次握手完成03:12:20.412exporter 发送 MySQL 握手认证包03:12:20.515认证完成开始查询指标03:12:29.904指标查询完成准备序列化输出03:12:30.107Prometheus 端的 deadline 到期判定抓取失败03:12:30.136HTTP 响应最后一个字节到达 Prometheus迟了 29ms这 29 毫秒是怎么来的两部分累加坏连接重连开销从 RST 到 TCP 建连完成约 300 毫秒MySQL 查询耗时正常情况下SHOW STATUS这类查询是毫秒级但那一刻恰好赶上数据库侧一个凌晨批处理任务processlist相关查询被拖慢整体接近 9.4 秒。如果只是重连总耗时在 1 秒以内不会超时如果只是查询慢热连接直接可用也可能在 10 秒内完成。但两者叠加总耗时刚好越过 10 秒阈值——只多了 29 毫秒。这就是“真相藏在毫厘之间”的完整含义。排查此类问题如果不把时间线拆到这种精度永远只能得到“数据库没问题啊”的结论。3. 排查实录三步锁定“假重启”3.1 先用 SQL 和 ps 证伪数据库重启承认数据库“没动”的过程要比想象中费力因为告警文案太有误导性了。我建议所有遇到同类问题的人在动手查链路之前先做一件事把“数据库重启”和“exporter 不可达”两个结论彻底剥离开。具体操作就是两条命令SHOW GLOBAL STATUS LIKE Uptime;ps -eo pid,etime,cmd | grep mysqld这两个输出的时间如果都在百天级别那么数据库进程层面绝对没有重启。再补一条SHOW FULL PROCESSLIST确认当前没有异常会话就可以把排查重心转向监控链路本身。当时我做完这一步后心里反而更确定了问题出在 Prometheus 到 exporter 这一段而不是数据库。这里有个小建议生产环境的数据库监控最好把告警触发条件从“直接依赖up”调整成“依赖数据库实测指标”。比如用mysql_global_status_uptime的变化量来判断实例有没有重启或者用mysql_global_status_threads_connected突降来判断连接异常。直连数据库实测的指标远比 Prometheus 的抓取状态可靠得多。3.2 target 页面和 exporter 日志给的第二个线索证伪数据库重启后我进入 Prometheus 自带的 Targets 页面找到mysql这个 job点开它。页面上会显示最近一次抓取的耗时、时间戳和错误信息。我当时看到的 error 大概长这样Get http://10.0.8.11:9104/metrics: context deadline exceeded (Client.Timeout exceeded while awaiting headers)注意最后半句context deadline exceeded。这直接说明是超时而不是拒绝连接也不是 DNS 解析失败。同一个错误我翻看历史记录发现它并不是首次出现——过去一周里这个 job 每天都有那么一两次超时错落分布毫无规律。因为每次都能自动恢复没有触发过告警就一直被忽略了。这次之所以报警是因为连续几次抓取恰好都卡在同一类问题上累计时长超过了告警规则里的for: 2m。接下来我去看 mysqld_exporter 的日志。注意 exporter 默认输出到 stdout如果它是容器部署日志在 Docker stdout如果是 systemd 部署日志在 journald。我执行的命令是journalctl -u mysqld_exporter --since 03:10 --until 03:15 -f日志里没有任何panic或者进程重启动的记录只有一条 SQL 执行时间的警告大意是某个查询执行了较长时间。这就把范围进一步缩小了exporter 进程本身没挂只是它在抓取周期内花了太多时间去执行数据库查询最终拖垮了整个 HTTP 响应。3.3 tcpdump 抓包时间线终于开口说话到这一步常规手段已经用尽剩下的问题就是“到底哪里慢了”。我决定上tcpdump抓包分别抓 exporter 到 Prometheus 的 9104 端口以及 exporter 到数据库的 3306 端口。第一条命令tcpdump -i eth0 -nn -tttt -s 0 host 10.0.8.11 and port 9104 -w /tmp/prom_9104.pcap第二条命令tcpdump -i eth0 -nn -tttt -s 0 host 数据库内网IP and port 3306 -w /tmp/mysql_3306.pcap抓了一个小时等下一次告警复现。抓到之后用 Wireshark 打开按时间排序重点观察三类包RST 包如果某个 TCP 连接上出现 RST说明连接已经被对端或中间设备强制断开SYN 包出现新的 SYN说明连接池在建立新连接HTTP 请求与响应的相对时间定位 Prometheus 发起请求和收到完整响应的精确时刻。结果很清晰。exporter 和数据库之间存在一条长连接这条连接已经空闲了很长时间在某次抓取请求到来时exporter 尝试通过这条连接发送查询命令立刻收到 RST。随后 300 毫秒内exporter 重新发起 TCP 连接完成握手、认证再执行那些指标查询。而 Prometheus 的 10 秒 deadline 已经在这期间被大量消耗最终只差了 29 毫秒。顺便说一句抓包文件不要删这东西在复盘和写报告时价值极高。我后来把那个 RST 包的 TCP 时间戳、HTTP 请求的时间戳截了个图贴到事故文档里整个锅甩得明明白白。3.4 为什么连接池里的空闲连接会“消失”到这里核心问题只剩最后一个那条被断掉的连接中间设备为什么要断它答案是空闲连接回收。我们的 exporter 和数据库中间隔着一个云负载均衡SLB/CLB这类四层负载均衡普遍有“空闲超时”机制TCP 连接上长时间没有数据传输就会被判定为“死连接”并主动断开。断开方式通常就是 RST 或者 FIN。而 mysqld_exporter 使用的 Godatabase/sql连接池默认会保留空闲连接。池里的连接如果长时间不被使用池本身并不知道连接在中间设备上已经失效直到下一次真的去写数据时收到 RST才反应过来“哦坏了”。于是它触发重连机制重新走一遍 TCP 握手 MySQL 认证 指标查询。这个“重新走一遍”里的每一步都是额外时间成本。讲个通俗的类比连接池就像你手机里保存的“常用联系人”你以为对方一直在等你电话但你并不知道对方早就换了号码。你有一天真正拨过去听到的是“您拨打的号码是空号”这个时候你才手忙脚乱地去翻新通讯录。如果你赶时间这通电话就会“超时”。还有一个隐藏细节Go 的database/sql对坏连接有自动重试机制默认最多重试一次。我们这次碰到的场景里重试是成功的——新连接建起来了查询也完成了但完成时间已经越过 Prometheus 的 deadline。如果没有这个重试报错会更直接up也会从 1 直接变 0反而更好查。真正难查的就是这种“重试恰好在超时边缘擦过”的偶发情况。4. 修复与配置改造把这些隐患一次清干净4.1 调整 Prometheus 抓取参数别让超时成为常态找到根因后第一件事当然是让 Prometheus 别再“掐秒表”。但调整scrape_timeout不是简单把 10s 改成 20s 就完事有两个硬性约束scrape_timeout必须小于scrape_interval。如果 timeout 大于或等于 interval两次抓取可能重叠会给 exporter 带来并发压力也可能造成数据序列错乱。我们把 interval 从 60s 改成 90stimeout 从 10s 改成 15s留出了足够的缓冲区间。单次抓取耗时不应该无限放宽。如果 exporter 查询一次要 15 秒说明它的采集 SQL 已经很有问题那不是调整 timeout 能解决的而是要优化查询本身或者拆分成多个 collector 并行采集。最终配置我改成了这样scrape_configs: - job_name: mysql static_configs: - targets: [10.0.8.11:9104] scrape_interval: 90s scrape_timeout: 15s改完配置 reload 之后连续观察了三天没有再出现context deadline exceeded。但这只是治标真正治本的是接下来这一步。4.2 让 exporter、数据库、中间链路“活”起来既然问题出在“连接被中间设备静默回收后exporter 后知后觉”那就要让连接在回收之前持续活跃或者让 exporter 能提前感知失效。我做了三件事第一开启 TCP keepalive。在 exporter 所在主机和数据库两端检查并调低 TCP keepalive 探测周期。默认情况下 Linux 的/proc/sys/net/ipv4/tcp_keepalive_time是 7200 秒2 小时这个值对于云环境太漫长了。我调成了 300 秒这样连接空闲 5 分钟就会有一次探测报文负载均衡的空闲回收阈值通常在几秒到几分钟探测报文足以让连接“保鲜”。sysctl -w net.ipv4.tcp_keepalive_time300 sysctl -w net.ipv4.tcp_keepalive_intvl30 sysctl -w net.ipv4.tcp_keepalive_probes3第二给 exporter 的连接池做“预热”。与其让连接在池子里睡着然后被断开不如直接缩短连接空闲寿命。Go 的database/sql可以通过SetConnMaxIdleTime主动控制连接最大空闲时间但 mysqld_exporter 没有直接暴露这个参数。所以我换了一种思路在 exporter 前增加一条独立于抓取周期的健康检查也就是用 Blackbox exporter 或者一个简单的定时脚本每 30 秒主动访问一次/metrics。这样连接池里始终有活跃连接中间设备永远不会触发空闲回收。这个方案便宜且有效。第三和云厂商确认负载均衡的连接空闲超时时间。不同云产品的默认值不一样有的是 500 秒有的是 900 秒。我们把 SLB 的空闲超时调到与 TCP keepalive 参数匹配保证是“先有 keepalive 报文、后有连接回收”从协议层面掐死了这个隐患。4.3 告警规则增加噪声抑制别让值班兄弟白折腾配置层面的修复完成后我还顺手把告警规则改得更“抗抖动”了。原规则是up{jobmysql} 0单点判断只要有瞬时抓取失败就可能会误报。我改成两个方向方向一引入持续窗口判断。用min_over_time把窗口拉长要求一段时间内抓取状态持续为 0 才告警。比如- alert: MySQLExporterDown expr: min_over_time(up{jobmysql}[5m]) 0 for: 2m这样单次抓取超时造成的瞬时抖动不会直接触发告警。方向二交叉验证。增加一个依赖数据库实测指标的告警比如mysql_global_status_threads_connected突降或mysql_global_status_uptime出现明显跳变用这个来确认“数据库是否真的出了问题”。两个告警单独触发时只是 P3 提示同时触发才升级为 P1。这样即便监控链路再抽风也不会再把“exporter 超时”误报成“数据库重启”。说实话告警设计的目标不是“一个都不漏”而是“该响的时候响不该响的时候别响”。一个凌晨三点让 DBA 白跑一趟的告警对系统的伤害不比一次真实故障小——因为狼来了喊多了真出事的时候没人当回事。5. 复盘和避坑建议5.1 监控告警要有交叉验证别信单点指标这次事故给我最大的教训就是任何单点的监控指标都不可信尤其在跨链路场景下。up这个指标是 Prometheus 对“抓取过程”的感知不是对“数据库健康状态”的感知。把up和“数据库重启”划等号本质上是用错了指标。以后我设计的数据库告警体系至少包含三层第一层Prometheus 抓取状态up负责发现 exporter 链路问题第二层数据库实测状态mysql_global_status_uptime、mysql_global_status_threads_connected负责发现数据库实例问题第三层业务可观测性查询失败率、接口耗时负责发现“用户到底受没受影响”。只有第一层告警触发时先不要拉高 Severity而是去看第二层和第三层指标。如果后两层都是平的那大概率是监控链路的问题不是数据库的问题。5.2 超时参数要成体系别只调一个地方scrape_timeout不是孤立存在的它只是整条链路上的一个环节。与之相关的参数包括参数位置作用scrape_timeoutPrometheus 配置限制单次 HTTP 抓取的硬性超时scrape_intervalPrometheus 配置决定抓取频率必须大于 timeoutTCP keepalive 参数操作系统防止连接被中间设备回收负载均衡空闲超时云厂商控制台/配置文件决定连接空闲多久会被断开MySQLwait_timeout数据库参数决定服务端何时断开空闲连接连接池 MaxIdleConnsexporter 底层库决定保留多少空闲连接这六个参数必须放到一起看单独调任何一个都容易埋雷。比如你把scrape_timeout调大了但 TCP keepalive 没调连接照样会被回收你调了 keepalive但负载均衡的空闲超时比 keepalive 间隔还短keepalive 也救不了。最高效的做法是画一条从“Prometheus 发起请求”到“数据库返回结果”的全链路超时基线每个环节留出明确余量。5.3 这类偶发问题日常巡检怎么提前发现偶发故障最恶心的地方在于它不是每次都发生你很难在事后复现更别说在故障前预警。我的经验是把“偶发”转变为“可观测”才能提前发现。具体做法有三条给 Prometheus 增加抓取耗时的历史指标。Prometheus 在抓取过程中会自动记录scrape_duration_seconds把它做成趋势图。如果某个 exporter 的抓取耗时开始缓慢上升、逐步接近scrape_timeout阈值这就是明确的“预兆”。这次事故之前我们的scrape_duration_seconds就已经开始出现尖刺了只是没人看。对告警规则做“吸血测试”。故意把scrape_timeout调小到极限观察告警什么时候会误报摸清监控系统的“真实容错边界”而不是凭感觉设置参数。建立故障时间线采集习惯。每次遇到偶发问题第一时间在 exporter 和数据库两端同时抓包保留现场而不是先重启。这次如果没有 tcpdump 抓包数据单靠日志和现象很难在几小时内锁定那 29 毫秒。5.4 速查命令与配置模板最后把这些排查中用到的命令和配置整理成一个速查清单下次遇到可以直接抄作业。排查命令速查# 1. 证伪数据库重启 mysql -h DB_HOST -e SHOW GLOBAL STATUS LIKE Uptime; ps -eo pid,etime,cmd | grep mysqld # 2. 查看 Prometheus 目标状态页面 # http://prometheus:9090/targets # 3. 查看 exporter 日志systemd 部署 journalctl -u mysqld_exporter --since 10分钟前 -f # 4. 抓包定位毫秒级时间线 tcpdump -i eth0 -nn -tttt -s 0 host exporter_ip and port 9104 -w /tmp/prom.pcap tcpdump -i eth0 -nn -tttt -s 0 host db_ip and port 3306 -w /tmp/mysql.pcap # 5. 查看 TCP keepalive 参数 sysctl net.ipv4.tcp_keepalive_time net.ipv4.tcp_keepalive_intvl net.ipv4.tcp_keepalive_probesPrometheus job 配置模板scrape_configs: - job_name: mysql static_configs: - targets: [10.0.8.11:9104] scrape_interval: 90s scrape_timeout: 15s告警规则模板交叉验证版groups: - name: mysql_alerts rules: - alert: MySQLExporterDown expr: min_over_time(up{jobmysql}[5m]) 0 for: 2m labels: severity: warning annotations: summary: MySQL exporter 疑似不可达 description: Prometheus 连续多次无法抓取 mysql 目标请检查 exporter 和监控链路。 - alert: MySQLInstanceDown expr: changes(mysql_global_status_uptime[5m]) 1 for: 2m labels: severity: critical annotations: summary: MySQL 实例疑似重启 description: 检测到 MySQL 运行时长发生跳变请立即确认数据库进程状态。最后再分享一个我自己的体会监控系统报错时先别急着把锅甩给“数据库”。监控是代理数据库才是真身。代理偶尔会说谎真身沉默寡言。遇到这种“数据库没动监控却在喊”的情况用抓包工具把时间线拆到毫秒很多看似诡异的偶发故障其实都是几个参数在边缘状态下互相踩踏的结果。这次是 29 毫秒的迟到下次可能就只差 2 毫秒——一旦踩线告警照样会响根因照样藏在毫厘之间。