HDUO Lab

分类： 故障排查实战

  • 深入 Apache Pulsar 写入雪崩排查：Journal/Ledger 磁盘混用引发的 IO 饱和与 Bookie 假死实战

    某次接手一个号称“完全按照官方最佳实践”部署的 Pulsar 集群，业务方反馈高并发场景下大量 Producer 频繁抛出 PulsarClientException$TimeoutException，P99 写入延迟从常态的 5ms 瞬间飙升至 8000ms+，集群吞吐呈断崖式下跌。直接抛出排查结论：这是典型的底层存储架构无知导致的惨案。部署人员将 BookKeeper 的 journalDirectories（写前日志）和 ledgerDirectories（数据与索引）挂载到了同一块物理磁盘（甚至是同一块云盘）。当 Ledger 触发后台垃圾回收（Garbage Collection）或 RocksDB 刷盘时，海量随机 IO 直接榨干了磁盘 IOPS，导致 Journal 的顺序 fsync 严重阻塞。Bookie 内部线程池大面积挂起，最终因 ZK 心跳超时被踢出集群，引发 NotEnoughBookiesException 全局写入雪崩。

    Pulsar 最大的卖点就是“计算与存储分离”（Broker 与 Bookie 分离），但很多人只停留在节点级别的隔离，完全无视了 BookKeeper 内部极其苛刻的 IO 路径分离要求。

    BookKeeper 的写入模型极其严谨且保守：一条消息到达 Bookie 后，必须强制 fsync 落盘到 Journal（类似 MySQL 的 Redo Log），才会向 Broker 返回 ACK。同时，消息会被写入内存（MemTable），随后异步批量刷入 Ledger 磁盘，并更新 RocksDB 中的索引。 这套设计的初衷非常明确：用 Journal 的极速顺序写保证低延迟和数据可靠性，用 Ledger 的大容量存储应对历史数据读取和高吞吐。

    把 Journal 和 Ledger 混在一块盘上，无异于在高速公路上摆地摊。

    排查期间，登陆故障 Bookie 节点，一条极其普通的 iostat 命令就让问题原形毕露：

    # iostat -dx 1
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
nvme1n1           0.00     0.00  850.00 1200.00 10240.00 45000.00    53.89   145.20   70.83   90.50   56.90   0.49 100.00

    磁盘 %util 死死钉在 100%，avgqu-sz（请求队列长度）高达 145，await 飙到 70ms 以上（对于 NVMe 来说，超过 5ms 就已经是不及格了）。

    去翻看 Bookie 的 Prometheus 监控，核心指标 bookkeeper_journal_JOURNAL_SYNC_99_per（Journal 落盘 99 线）与磁盘 IO 延迟高度吻合，出现了巨幅毛刺。此时，Broker 的日志里已经尸横遍野：

    org.apache.bookkeeper.client.BKException$BKNotEnoughBookiesException: Not enough non-faulty bookies available
    at org.apache.bookkeeper.client.LedgerCreateOp.initiate(LedgerCreateOp.java:142)
    ...

    为什么会突然爆发？因为 BookKeeper 并非只有简单的追加写。当 Ledger 中的 EntryLog 文件里被删除（或过期）的数据达到一定比例时，Bookie 会触发后台 GC 线程（Minor/Major Compaction）。GC 的动作是读取旧文件、过滤有效数据、重写到新文件。这是一个极其暴力的重度随机读 + 顺序写过程。 如果 Journal 和 Ledger 共享物理 IO 设备，GC 产生的海量 IO 请求会瞬间塞满 OS 的 Block Layer 队列，Journal 线程哪怕只是想追加写入几 KB 数据并调用一次 fsync，也只能在队列里绝望地排队。

    不仅如此，由于 Journal 同步阻塞，Bookie 的 Netty Worker 线程被耗尽，导致 Bookie 连发往 ZooKeeper 的心跳都无法及时响应。ZK 判定 Bookie 宕机，Broker 发现 Ensemble 可用节点不足（例如配置了 3 副本，只剩下 2 个健康节点），直接拒绝写入。由于集群是均衡负载的，随着 GC 在各个节点轮番上演，整个 Pulsar 集群如同多米诺骨牌般倒塌。

    解决这种问题，不要去迷信什么神奇的 JVM 调优参数，核心就是尊重物理拓扑。

    修复手段与防御性配置：

    1. 物理级别的 IO 隔离（最关键） 修改 bookkeeper.conf，强制分离 Journal 和 Ledger 目录到不同的物理磁盘。Journal 给一块极小但极快的高性能 NVMe SSD（几十G即可，写满会自动清理），Ledger 给大容量的普通 SSD 甚至 HDD。

    # 高速 NVMe 挂载点
journalDirectories=/mnt/nvme_journal/bookkeeper/journal
# 大容量 SSD/HDD 挂载点
ledgerDirectories=/mnt/ssd_ledger/bookkeeper/ledgers

    2. 对后台 GC 进行冷酷的资源限流 不要让 GC 跑起来像脱缰的野马。在 bookkeeper.conf 中开启 GC 限速，严格控制其对磁盘带宽的占用：

    # 开启按字节限流
isThrottleByBytes=true
# 限制 Compaction 最大速率为 50MB/s (根据底层磁盘能力调整)
compactionRateByBytes=52428800
# 避免在高峰期触发 Major Compaction
minorCompactionThreshold=0.2
majorCompactionThreshold=0.8

    3. RocksDB 索引刷盘的平滑处理 Ledger 中的索引默认由 RocksDB 管理，RocksDB 的 MemTable Flush 同样会带来 IO 尖峰。确保配置了合理的 Write Buffer 和并发度：

    dbStorage_rockdb_writeBufferSizeMB=64
dbStorage_rockdb_numLevels=6

    架构设计不是画几个方块就完事了。Pulsar 这种分布式中间件的性能底座，其实都建立在底层 Linux IO 调度和文件系统特性的基础之上。不理解数据的生命周期流转，不看磁盘的 IOPS 和延迟分布，一键部署出来的集群，最终都会在晚高峰教你做人。

    排查清单：BookKeeper IO 阻塞与假死速查

    1. 磁盘物理拓扑核对：执行 df -h 和 lsblk，严格对照 bookkeeper.conf 中的 journalDirectories 和 ledgerDirectories，确认两者绝未落在同一块物理盘、同一个 LVM 卷或同一个共享云盘组上。

    2. Journal Sync 延迟监控：紧盯 bookkeeper_journal_JOURNAL_SYNC 的 P99 和 P999 指标，一旦常态超过 10ms，立刻排查底层的 IO 争抢或硬件寿命衰减问题。

    3. ZooKeeper 会话抖动排查：排查 Bookie 侧日志是否有 Expired session，以及 ZK 侧是否有 Closed socket connection for client。如果是 IO 夯死导致的 CPU 调度迟滞，考虑适当调大 zkTimeout（默认通常为 10s-30s），但治本仍在 IO 治理。

    4. GC 日志与速率审查：搜索 Bookie 日志中的 GarbageCollectorThread 关键字，观察 Compaction 触发频率和耗时。确认 isThrottleByBytes 是否开启并配置了合理的阈值，防止后台合并打挂前台写入。

    5. Direct Memory 泄漏挤压 OS Cache：检查 dbStorage_directIO_entryLogger 是否未正确分配，导致 Bookie OOM 或严重依赖 PageCache。确保为 Bookie 预留充足的 Direct Memory 给 RocksDB Block Cache 和 ReadAhead Cache。

  • 深入 Zabbix 队列雪崩排查：Housekeeper 锁表引发的 MySQL IO 饱和与 History Syncer 堵塞实战

    排查某次监控系统大面积告警延迟事故，Zabbix Dashboard 显示待处理队列（Queue）堆积突破 20 万，告警通知 P99 延迟达到夸张的 2 小时。最终定位：业务团队滥用自定义模板，通过 log[] 键值将大段 Java 报错栈直接写入 Zabbix，导致 history_str 和 history_text 表数据暴增；同时 Zabbix 原生 Housekeeper 清理过期数据时触发海量 DELETE 操作，彻底打爆 MySQL InnoDB 的 IOPS，引发 History Syncer 进程全部夯死。解决方案极其粗暴且有效：彻底关闭 Zabbix 原生 Housekeeper，将所有历史与趋势表改造成 MySQL 按天/按月分区表（Table Partitioning），用 DROP PARTITION 替代 DELETE。

    故障现场极具讽刺意味：监控系统本身成了最需要被监控的系统。登录 Zabbix Server 节点，系统负载（Load Average）出奇的低，但查看 zabbix_server.log，满屏的红色告警：

    Zabbix server history syncer processes more than 75% busy
Zabbix server trapper processes more than 75% busy
[Z3005] query failed: [1205] Lock wait timeout exceeded; try restarting transaction [delete from history_text where itemid=19283 and clock<1698710400]

    History Syncer 是 Zabbix 将内存缓存数据刷入数据库的核心进程，它被堵死，意味着前端 Poller 和 Trapper 收集到的数据全憋在 Server 的 Shared Memory 里，最终导致采集停滞、队列爆炸。

    切到 MySQL 数据库节点，罪魁祸首立刻浮出水面。执行 iostat -dx 2 观察磁盘，数据盘的 %util 死死钉在 100%，w/s （每秒写 IO）达到磁盘物理极限，await 延迟飙升到 800ms 以上。 进入 MySQL 终端敲下 SHOW FULL PROCESSLIST;，看到几十个处于 updating 或 Locked 状态的 SQL 线程，全部是类似这样的语句：

    DELETE FROM history_str WHERE itemid=40281 AND clock < 1698710400 LIMIT 5000;
DELETE FROM history_text WHERE itemid=40282 AND clock < 1698710400 LIMIT 5000;

    技术逻辑其实非常清晰。把关系型数据库当做时序数据库（TSDB）来用，本身就是一种架构妥协。在 InnoDB 引擎中，执行 DELETE 语句删除几百万行历史数据，简直是运维自杀。DELETE 并不是简单地抹掉磁盘空间，而是会产生海量的 Undo Log（用于回滚）和 Redo Log（用于崩溃恢复），同时需要更新 B+ 树索引，引发大量的数据页分裂与 Buffer Pool 内存淘汰（Churn）。 当这种重度 IO 操作遇上业务团队滥用 Zabbix 收集文本日志（把 Zabbix 当 ELK 用），history_text 表的一行数据可能高达几 KB。Housekeeper 一启动，瞬间的随机写 IO 洪峰直接把底层存储击穿。

    为什么说这种配置不可原谅？因为在超过万级 NVPS（每秒处理新值数）的中大型 Zabbix 架构中，依赖原生 Housekeeper 清理数据是标准的新手雷区。Zabbix 官方手册虽然提过分区表的替代方案，但默认安装依然开启 Housekeeper，这坑了无数没有经历过数据量毒打的运维。

    止血与根治方案：

    第一步，紧急止损。立刻修改 zabbix_server.conf，将 Housekeeping 的频率设置为 0，切断 IO 洪峰的源头，并重启 Zabbix Server，等待队列慢慢消化。

    # zabbix_server.conf
HousekeepingFrequency=0

    第二步，架构重构，实施 MySQL 表分区（Table Partitioning）。 原理很简单：将时间序列数据按时间（clock 字段）分散到不同的物理文件中。当需要删除过期数据时，直接 ALTER TABLE ... DROP PARTITION。在文件系统层面，这等同于直接 rm -f 一个物理文件，时间复杂度为 O(1)，瞬间释放空间，彻底零 IO 负担，不会产生任何 Undo Log。

    针对 Zabbix 历史表的改造核心 SQL 如下（以 history_uint 为例）：

    -- 确保表结构没有外键，且时钟字段是主键/唯一键的一部分
ALTER TABLE history_uint PARTITION BY RANGE (clock) (
    PARTITION p20231101 VALUES LESS THAN (UNIX_TIMESTAMP('2023-11-02 00:00:00')),
    PARTITION p20231102 VALUES LESS THAN (UNIX_TIMESTAMP('2023-11-03 00:00:00')),
    -- 预先建好未来的分区
    PARTITION p_future VALUES LESS THAN MAXVALUE
);

    配合一个定时执行的 Shell 或 Python 脚本（业内常用 zabbix-mysql-partitioning.pl 脚本），每天零点自动检查并 DROP 掉过期的历史分区，同时 ADD 未来的新分区。

    最后，强烈建议剥离 Zabbix 的文本日志收集职能。Zabbix 核心是数值型时序监控（float/uint），日志型（str/text）数据一律丢给 Filebeat + Elasticsearch 或 Promtail + Loki 去处理。在监控架构里，强行让一个工具做所有事，最后通常是什么都做不好。

    同类问题排查清单（Zabbix 性能雪崩速查）

    1. Zabbix 内部队列指标：在 Zabbix Frontend 检查 Administration -> Queue。如果延迟集中在 10 分钟以上，且大部分是 Zabbix agent (active) 或 Trapper，大概率是 Server 性能瓶颈而非网络问题。

    2. 底层数据库 IOPS 饱和度：通过 iostat -dx 1 或 Node Exporter 的 node_disk_io_time_seconds_total 指标，排查底层数据盘 %util 是否长期处于 90%+。如果是，立即停止 Zabbix Server 进程以保护 DB。

    3. Housekeeper 配置确认：检查 Zabbix Server 配置中的 HousekeepingFrequency、MaxHousekeeperDelete。大规模场景下必须置 0 关闭，改用 DB 原生表分区或直接使用 TimescaleDB/ClickHouse 作为后端。

    4. 滥用监控项审查：在 MySQL 执行 SELECT itemid, COUNT(*) FROM history_text GROUP BY itemid ORDER BY COUNT(*) DESC LIMIT 10;，揪出产生大量文本型历史数据的 Top 10 监控项（Items），并在 Zabbix 页面中直接 Disable，切断污染源。

    5. 缓存击穿指标：查看 Dashboard 中的 Zabbix cache usage, % free。如果 History index cache 或 Value cache 经常跌破 5%，说明 CacheSize 和 HistoryCacheSize 配置过小，或者存在大量低频的长周期聚合查询在刷缓存。