07 深入专题:监控诊断与故障排查

07 深入专题:监控诊断与故障排查

这一篇聚焦 MySQL 监控与故障排查:performance_schema/sys 库运用、常见故障案例(OOM、连接暴涨、IO 打满、字符集/时区坑)的系统化定位方法。内容整理自爱可生开源社区《大智小技》系列(2019/2020 两册)技术文章精选。

MySQL 在拥有大量表的实例上执行 create table 为什么会崩溃?根因与规避方法是什么?

这是 MySQL Bug #89126。现象是:用满 InnoDB 表定义缓存后继续 create table,有一定概率让 MySQL 崩溃。根因在代码逻辑:create table 向表定义缓存插入新定义并持有引用,但同时又把该表定义释放了;恰在此时 InnoDB 定时器回收(free)了这块已被释放的内存,后续 create table 继续使用悬空引用,访问已回收地址导致崩溃。临时规避方法是不释放表定义(官方尚未接受该修复)。配置层面建议 table_definition_cache 略大于表总数,使缓存能容纳全部表定义,避免频繁回收触发竞争。

table_definition_cache 参数默认值如何计算?最小/上限怎么设?

InnoDB 会对表定义进行缓存以减少反复读取 frm 的 IO 压力,内部用 Hash 结构做查找、LRU 结构做回收,并区分忙时/闲时两种回收策略。容量可临时超过上限(与定时回收机制相关)。参数 table_definition_cache 最小值为 400;默认值由公式 min(400 + table_open_cache/2, 2000) 得出。除非实例有上万张表,一般建议把它设为略大于实际表数量,让缓存容纳所有表定义,避免回收竞争引发 Bug #89126 类崩溃。

InnoDB 报 Semaphore wait has lasted > 600 seconds 并主动 crash,触发机制是什么?

后台线程 srv_error_monitor_thread 检测到存在阻塞超过 600 秒的 latch 锁时,若连续 10 次检测该锁仍未释放,MySQL 会主动 panic 以避免服务持续 hang。日志中可见 ‘InnoDB: Semaphore wait has lasted > 600 seconds. We intentionally crash the server because it appears to be hung.’ 这类崩溃通常不是单一原因,需结合持有锁线程的事务信息、等待的 RW-latch 位置(如 dict0dict.c / btr0sea.c)逐层追因。

MySQL Bug #92108 与 binlog_transaction_dependency_tracking 参数有什么关系?哪个版本修复?

5.7.22 引入了 binlog_transaction_dependency_tracking 和 binlog_transaction_dependency_history_size 两个参数,在 5.7.23 版本中读取它们需要 LOCK_log,从而引发包括本文在内的多种死锁。5.7.25 之后这两个参数的读取改用影响更低的锁,避免了该死锁。因此遇到 exporter/监控采集导致 hang 时,可升级到 5.7.25+,或临时规避(如不在从库侧用会触发该锁的采集方式)。排查时用 pstack $(pgrep -xn mysqld) 抓取调用栈是定位此类死锁的关键手段。

Percona MySQL 5.7.23 半同步主从上部署 exporter 采集状态,为何整库 hang 死?死锁链路是什么?

exporter 周期性执行 show global variables/status、show master/slave status。这三个语句在 5.7.23 形成环形死锁:SHOW GLOBAL VARIABLES 持有 LOCK_global_system_variables 等待 LOCK_log;SLAVE SQL THREAD 持有 LOCK_log 等待 LOCK_status;SHOW GLOBAL STATUS 持有 LOCK_status 等待 LOCK_global_system_variables。而新连接初始化(THD::init)与查询(Item_func_get_system_var)都需要 LOCK_global_system_variables,于是连接建不了、查询全阻塞,表现为整库 hang。

delete 任务导致大量 SQL 被 kill,根因是脏页比例过高,原理是什么?

环境每分钟超 200 条 delete 被 kill(类似 pt-killer 的 sql-killer 工具)。排查发现被 kill 的 SQL 分散在各表且无长事务,但 innodb buffer pool 脏页比例接近 90%。原理:当脏页比例超过 innodb_max_dirty_pages_pct(默认 75)时 InnoDB 会剧烈刷脏;而 delete 持续产生脏页、刷脏速度跟不上,为防脏页进一步扩大,更新会被堵塞直至超时被 kill。脏页产生快+Buffer Pool 偏小是根因,与机器/IO 无关(换机器依旧)。

innodb_max_dirty_pages_pct 与 innodb_max_dirty_pages_pct_lwm 有何区别?lwm 设太低为何反而加剧抖动?

innodb_max_dirty_pages_pct(默认 75)是上限,超过则 InnoDB 激烈刷脏,但不直接改变刷脏速度。innodb_max_dirty_pages_pct_lwm(低水位,默认 0 即关闭)表示脏页比例达到该值时启动预刷脏(preflushing)来控制比例,刷脏最大 IO 能力受 innodb_io_capacity / innodb_io_capacity_max 约束。本案例把 lwm 设为 5,导致脏页稍高就频繁预刷,刷脏线程与 delete 持续产生的脏页拉锯,引发刷脏量抖动和 SQL 变慢。多实例主机 IO 已高时不宜靠调大 io_capacity 解决。

innodb_thread_concurrency 与 innodb_concurrency_tickets 的工作原理与官方设置建议?

innodb_thread_concurrency 控制同时进入 InnoDB 层的线程数,超过则睡眠(时长由 innodb_thread_sleep_delay、innodb_adaptive_max_sleep_delay 自适应调整)。innodb_concurrency_tickets 是线程与 InnoDB 层交互的’票’,每进一次减 1,耗尽即让出 CPU,避免长查询饿死短查询(如 insert select 一行消耗 2 张票)。官方建议:并发用户<64 设 0;负载重则先设 128 再逐步下调到 96/80/64 找最优;过高反而因内部竞争导致回退。trx_operation_state 显示 ‘sleeping before entering InnoDB’ 即被挡在层外。

大量 insert/update/select 都卡在 updating / sending data,但 CPU、IO 都不高,是什么原因?

这是 innodb_thread_concurrency 与 innodb_concurrency_tickets 配置不当导致。pstack 显示所有线程都阻塞在 innobase_srv_conc_enter_innodb —— 即被挡在 InnoDB 层之外。innodb_thread_concurrency 限制同一时刻能进入 InnoDB 层的线程数,超出后新线程进入短暂睡眠(os_thread_sleep/nanosleep),状态显示为 ‘sleeping before entering InnoDB’。当事务 tickets 耗尽(trx_concurrency_tickets=0)又会重新排队。取消/调大这两个参数(官方建议并发<64 时设 0)后故障解除。

如何快速从海量错误日志中梳理 semaphore crash 的锁/线程/事务关系?

在动辄几 MB 的日志里手工定位关系很低效。可用 ‘mysqldba doctor -f /path/mysqld_safe.log’ 程序自动梳理:统计 crash 次数与启动次数(判断是正常启动还是 crash)、各线程主要等待哪些 RW-latch 及出现次数、哪些写线程持有 X 锁、以及写线程对应的事务信息。还支持 ‘mysqldba -uxxx -pxxx doctor -w’ 事中采集——监视错误日志一旦出现 ‘a writer (thread id …) has reserved it in mode’ 就查询 performance_schema 中的事务信息并保存,弥补事后日志未输出事务信息的缺陷。

如何用 pstack/gdb 采集 MySQL 调用栈来定位 hang 死问题?

日志无法判断原因时,迅速采集调用栈:pstack $(pgrep -xn mysqld)(或用 gdb -p 然后 bt)。本案例中三个语句各持有一把 mutex 并等待另一把,从栈帧可看到 SHOW GLOBAL VARIABLES 停在 PolyLock_lock_log::rdlock(等 LOCK_log)、SLAVE SQL 停在 publish_coordinates_for_global_status(持 LOCK_log 等 LOCK_status)、SHOW GLOBAL STATUS 停在 fill_status(持 LOCK_status 等 LOCK_global_system_variables)。结合源码确认锁依赖方向,即可还原环形死锁。新连接栈停在 THD::init 也印证了 LOCK_global_system_variables 被占。

如何通过 information_schema.innodb_trx 与 show engine innodb status 诊断并发进入 InnoDB 被阻塞?

被 innodb_thread_concurrency 挡住的事务,其 trx_operation_state 会标记为 ‘sleeping before entering InnoDB’,且 trx_concurrency_tickets 逐渐降到 0(只读事务在 show engine innodb status 中可能看不到,但 innodb_trx 可见)。show engine innodb status 的 ROW OPERATIONS 段会显示 ‘N queries inside InnoDB, M queries in queue’,本案例即显示 ‘1 queries inside InnoDB, 2 queries in queue’,说明有 2 个会话堵在 InnoDB 层外。配合 show processlist 的 State 列(updating/sending data)可确认阻塞范围。

开启 innodb_stats_on_metadata 与 AHI 如何引发 semaphore crash?

某 5.5.40 环境崩溃链路:开启 innodb_stats_on_metadata 后,查询 information_schema 表会触发统计信息更新,调用 dict_table_stats_lock 上 X 锁(数据字典锁);同时 buffer pool 空闲页为 0,驱逐旧页需调用 btr_search_drop_page_hash_index 清理 AHI,而 AHI 在 5.5 由全局锁 btr_search_latch 保护。两条路径相互等待形成锁竞争,最终信号量超时 crash。5.7 后对 AHI 锁做了多实例拆分有所缓解。结论:统计信息更新与 AHI 全局锁竞争是该类 crash 主因,应避免在热点实例上开启 innodb_stats_on_metadata。

脏页比例接近 90% 导致 delete 被 kill,生产上如何快速止血?

三种思路:①调大 innodb_io_capacity(但本例多实例主机 IO 已高,放弃);②降低 delete 速度(数据产生快,删跟不上,放弃);③调大 Buffer Pool 容纳更多脏页。得益于 MySQL 5.7 支持在线调整 Buffer Pool,直接将 innodb_buffer_pool_size 扩一倍立即生效,脏页比例回落、被 kill 的 SQL 大幅下降、平均 rt 明显改善。这是线上最稳妥的临时止血方案,之后再复盘 delete 任务节奏与 buffer pool 容量规划。

THD::set_time 的三种重载如何影响 show processlist 的 Time 计算?

THD::set_time 有三种重载:重载1(无参)设 start_time 为当前时间,命令发起时调用;重载2(带 timeval*)和重载3(带 QUERY_START_TIME_INFO*)会同时设置 start_utime 与 start_time,之后即便再调重载1 也不会改 start_time。关键点:从库应用 Event 用重载3(start_time=主库时间)、手动 set timestamp= 用重载2,都会让后续 Time = now - 设定时间,可能出现很大或为负(Percona 显示 0)。空闲会话 now 增大而 start_time 不变,Time 持续增大直到下条命令。理解重载差异才能解释 Time 异常。

show processlist 中 MTS Worker 线程的 Time 出现负数,原因是什么?

Time 计算为 now - thd_info->start_time。主库命令发起走 THD::set_time 重载1,start_time 取当前时间;而从库 SQL/Worker 线程执行 Event 时走重载3(set_time(&common_header->when)),start_time 取 Event header 中的 timestamp,该时间实际来自主库命令发起时间。因此 Time = 从库当前时间 - 主库命令时间。若从库服务器时间小于主库时间,结果即为负数(Percona 版做了优化负数显示 0,官方版可能为负)。这就是 MTS Worker 出现负 Time 的根因——主从系统时钟不一致。

DBLE 与 Mycat 在分片规则完全一致时,跨节点 join 结果却不一致,谁对谁错?

测试用 mod 分片(t_bl_detail、t_bl_super_detail 按 unit_num 取模分布到 db1-db4),执行跨节点 join:DBLE 结果符合预期,Mycat 结果缺失跨节点部分。根因在中间件实现:Mycat 对跨节点 join 直接把 SQL 透传到各分片、汇总结果,跨节点的关联数据无法 join,故缺失;DBLE 则先在中间件获取关联所需数据、提取到中间层做融合(merge)后再返回,结果与直连 MySQL 一致。结论:跨节点关联查询应优先用 DBLE,Mycat 在此类场景会静默丢数据。

DBLE 与 Mycat 的分片算法配置(mod)有哪些关键差异?

两者均用取模算法但配置项不同:DBLE 的 rule.xml 中 function 用 class=“Hash”,属性 partitionCount(如 4)与 partitionLength(如 1),rule 指定 columns=unit_num;Mycat 用 class=“io.mycat.route.function.PartitionByMod”,属性为 count=4,rule 指定 columns=id。注意 columns 指定的分片键必须一致(本例都用 unit_num 才能保证数据分布相同)。分片键、算法参数、节点数三者对齐才能复现相同的数据分布,否则即使中间件不同也会因路由不一致产生结果差异。配置前务必核对 columns 与 partitionCount/count。

拿到 MySQL 崩溃堆栈里的 ‘函数名+0x偏移’(如 generate_new_name+0x71),如何定位代码行?

用 GDB 打开对应版本的 mysqld,在崩溃地址打断点即可打印文件名与行号;也可用 c++filt 还原被编码的函数签名。‘函数起始位置+偏移量’是一种内存位置表示法:工具找到就近函数(如 generate_new_name)的起始地址,加上 0x71 偏移写成 generate_new_name+0x71。注意该位置大概率但不一定在该函数内部——只是离它最近。本例据此猜到缺陷发生在为 binlog 生成新文件名时。交付开发时给出 ‘文件:行号’ 与函数签名即可精准定位。

使用 bcc/eBPF 观测 MySQL 对内核版本有什么要求?

bcc 基于 eBPF 开发,要求 Linux 3.15 及以上;其大部分功能(包括 dbstat/dbslower 用到的高级特性)需要 Linux 4.1 及以上。此外 dbslower/dbstat 依赖 MySQL 编译时开启的 USDT/DTrace tracepoint,否则启用 probe 会报错:‘bcc.usdt.USDTException: failed to enable probe query__start; a possible cause can be that the probe requires a pid to enable’,需指定 -p PID 或换带 tracepoint 的 MySQL 版本。安装:Ubuntu 加 iovisor 源装 bcc-tools;CentOS 用 yum install bcc-tools,并把 /usr/share/bcc/tools 加入 PATH。

如何用 bcc 的 dbstat / dbslower 观测 MySQL 查询延迟?

bcc 是基于 eBPF 的工具集,提供两个 MySQL 观测命令:①dbstat mysql -p pidof mysqld -u 把查询延迟汇总为直方图(默认毫秒,-u 微秒,-m 只统计高于阈值的),直观看延迟分布;②dbslower mysql -p pidof mysqld -m 2 跟踪并列出延迟高于 2ms 的每条 SQL(含 TIME/PID/MS/QUERY)。两者都不依赖慢查询日志,适合实时定位延迟毛刺。注意需 MySQL 具备 USDT/DTrace tracepoint,否则报 ‘failed to enable probe query__start’。

Percona Toolkit 还有哪些实用工具(pt-variable-advisor/pt-archiver/pt-pmp)?

①pt-variable-advisor:参数优化建议器,pt-variable-advisor h=… 会给出 WARN/NOTE(如 delay_key_write、innodb_log_buffer_size 不应>16M、expire_logs_days 未开自动清理等)。②pt-archiver:数据归档回收,pt-archiver –source … –dest … –where ‘id<=1000’ 归档并删原行,加 –no-delete 只归档不删,也可 –file 归档到文件再用 load data infile 导入。③pt-pmp:用 gdb 打印 mysqld 线程栈并按调用链合并相同栈(第一列是线程数),在日志/状态命令找不到原因、需深入程序级或想保留故障现场时极有用。

pt-config-diff 如何快速对比多套 MySQL 实例或配置文件的参数差异?

pt-config-diff 是 Percona Toolkit 中做参数对比的工具。对比运行时参数:pt-config-diff h=172.20.134.1,P=5722,u=repl,p=repl h=172.20.134.3,P=5722,u=dba,p=dba –report-width 200,会列出两实例所有不同项(如 gtid_executed、server_uuid 等)。对比配置文件:pt-config-diff /data/mysql/etc/5.7.22.cnf /tmp/5.7.22.cnf –report-width 200,可发现 max_allowed_packet、relay_log_recovery 等差异。–report-width 防止长参数被截断。适合多环境排障时控制变量、定位配置漂移。

pt-heartbeat 相比 Seconds_Behind_Master 为什么能更准确测量复制延迟?

原生 Seconds_Behind_Master 只能观测’应用延迟’(从库已收到 binlog 但未应用完),在异步/降级半同步下误差大,且无法反映’日志延迟’(主库已生成但未发给从库)。pt-heartbeat 原理:在 Master 循环执行 insert into database.heartbeat(master_now) values(NOW());该变更随复制流向从库;从库测延迟 = 系统当前时间 - heartbeat 表时间。启动:pt-heartbeat -D delay_checker –create-table –interval=5 –update -h 主库;检查:pt-heartbeat -D delay_checker –check 从库。注意从库系统时间须与主库一致,否则计算偏差。

MySQL 5.7.25 中派生表未物化时,SELECT sub.rnd FROM (SELECT FLOOR(RAND()*10) rnd …) sub WHERE sub.rnd<3 为何结果错误?

这是 Bug #86624。内层用 RAND() 生成随机数,外层 WHERE 过滤 sub.rnd<3,期望拿到 <3 的结果。但当派生表未被物化时,外层每取一行都会重新计算一次 RAND(),导致过滤条件用的随机数与内层显示的不一致,结果错乱。验证:去掉 test 表(SELECT sub.rnd FROM (SELECT FLOOR(RAND(100)*10) rnd) sub WHERE sub.rnd<3)正常;加 LIMIT 10000 强制物化后也正常;拉平用 HAVING 同样异常。规避:5.7 加 LIMIT 大数强制物化;8.0 用 no_merge Hint 阻止派生表合并。官方确认但不修。

Percona QAN(PMM 的慢查询分析)架构由哪几部分组成?slow-log 如何流转?

QAN 是 PMM 中分析慢查询日志的组件,由三部分组成:QAN-Agent(client,采集 slow-log 上报)、QAN-API(server,存储数据并提供查询接口)、QAN-APP(专门展示慢查询的 Grafana 第三方插件)。数据流:slow-log → QAN-Agent → QAN-API ↔ QAN-APP(Grafana)。它是免费开源方案,摆脱直接看 slow-log 的困扰,也是爱可生数据库管理平台问题诊断全家桶的一部分。PMM 有 pmm1/pmm2 两个架构版本,但 QAN 组成基本相同。

QAN 页面中 Load/Count/Latency 指标代表什么?slow-log 关键字段有哪些?

QAN 默认展示 top 10 慢 SQL,三列指标:Load = 选定时间段内该 query 执行时间占比,公式 query_time/(end_time-start_time);Count = 请求总数;Latency = 平均/最大/最小/95%(去掉前 5% 尖峰后求平均)执行时间。slow-log 字段:Query_time(执行秒数)、Lock_time(持锁秒数)、Rows_sent(发往客户端行数)、Rows_examined(检查行数)、SET timestamp(语句完成后的时间戳)。点开某 query 还能看 EXPLAIN、SHOW CREATE TABLE、SHOW INDEX 辅助定位。

pt-stalk 的触发式监控原理是什么?关键参数有哪些?

pt-stalk(Percona Toolkit 中的 Shell 脚本)后台监控,满足条件时收集 OS 与 MySQL 诊断数据。核心参数:function(默认 status 监控 SHOW GLOBAL STATUS,或 processlist 监控 show processlist)、variable(监控项,默认 Threads_running)、threshold(阈值,默认 25)、cycles(连续几次满足才触发,默认 5)、interval(检查频率,默认 1s)、run-time(收集时长,默认 30s)、sleep(触发后休眠,默认 300s)、dest(存放路径默认 /var/lib/pt-stalk)、retention-time(保留 30 天)、daemonize(后台)。伪代码即:variable>threshold 连续 cycles 次 → 收集 run-time 秒 → 休眠。

pt-stalk 采集的数据如何分析?lock-waits 与 transactions 有什么用?

pt-stalk 输出大量以命令命名的文件,关键有 lock-waits 与 transactions:lock-waits 记录行锁等待详情(阻塞者/被阻塞者),transactions 记录所有活动事务详细信息,利于分析行锁等待。若怀疑事务挂起,仍需借助 general_log 分析整个事务。PT 工具包还提供 pt-sift,可对 pt-stalk 历史采集数据做汇总性展示,快速概览。整体适合未部署监控系统、需临时排查 MySQL 问题的环境。

如何用 pt-stalk 在 Threads_running 超阈值时自动采集,以及临时一次性采集现场?

后台监控活跃线程:pt-stalk –function status –variable Threads_running –threshold 500 –daemonize –user=root –password=xxx,连续 5 次 >500 即触发收集主机与 MySQL 状态。同理可监控 Threads_connected。临时保留问题场景用非后台模式:pt-stalk –no-stalk –run-time=60 –iterations=1,立即收集 60 秒后退出,无需触发条件,适合事后分析。还可加 collect-gdb/collect-strace/collect-tcpdump 收集更深信息(需对应工具)。注意 pt-stalk 适合在 MySQL 本机运行,远程无法收主机信息;触发条件单一不可多选是短板。

在 DBLE 上执行 DDL 卡住(hang)时,如何一步步排查根因?

排查三步走:①看 DBLE 日志有无报错/告警,less dble.log|grep DDL;②看日志上下文理解处理机制——DBLE 执行 DDL 分两步(先测试连接可用性,再真正下发),本例步骤一连接验证成功,但某节点状态一直 start。根据提示的 connection 号(如 23)定位到问题 dataNode(dn2),并找到对应 MySQL 线程号(如 29);③连到该 MySQL 节点执行 show processlist,发现该 DDL 在等待一把锁。结论:DDL hang 通常是后端某个分片节点持锁未释放,从 DBLE 日志定位 dataNode 再到后端排查锁即可。