欢迎光临
我们一直在努力

SkyWalking 日志又积压 1900 万:Kafka 分区明明均匀了,凶手却藏在 ES 段合并里

📝 摘要:SkyWalking 日志积压逼近 1900 万,但 Kafka 分区已均匀,瓶颈下移到 ES。顺着「生产→消费→落库」逐段排查,用 hot_threads、_cat/shards、thread_pool 三连定位真凶:大头日志被 SkyWalking 归为 super dataset(36 分片/0 副本/DAY_STEP=5),单分片 20GB 让段合并轮流打满磁盘 IO、反压积压。DAY_STEP 从 5 改成 1、单分片降到 4.6GB 后几分钟清空。两坑:分片配置是烟雾弹、热点轮动≠数据倾斜。

上一集,我们把 SkyWalking 的 Kafka 分区倾斜治好了——把 Agent 里固定的 key 改成 null,数据从此均匀落到 12 个分区。我以为这事儿就此翻篇了。

结果没过多久,监控大盘又红了:消费积压逼近 1900 万,而且这次 Kafka 分区是均匀的。

生产均匀、消费均匀、却照样堆积——这就好比 12 个食堂窗口排队人数一样多,可饭菜还是出不来。那问题一定不在窗口,而在更后面的厨房。

这一篇,就是从「分区都均匀了为什么还积压」一路追到 ES 段合并热点、最后靠一个参数收工的完整复盘。

📖 前置阅读:第一阶段「Kafka 分区倾斜 → key 改 null」的完整故事见上一篇 《SkyWalking 消费积压 6 亿条:一次 Kafka 分区倾斜的深度复盘》。本篇假设你已经知道「key=null 让数据均匀分区」这个背景,不再展开。


一、问题现象:分区均匀,却又积压了

距离上次治理过去没多久,SkyWalking 的 Kafka 消费组又开始积压,峰值逼近 1900 万条。

研发同学的体感和上次一样难受:

  • 日志查询又开始延迟,“查不到最新日志”
  • 链路追踪页面数据滞后
  • 积压量持续往上爬,不收敛

但有一个地方和上次完全不同——上次是分区严重倾斜(少数分区在 996、其他在摸鱼),这次打开分区维度的监控:

近 7 天 Kafka 各分区积压、消费情况

生产均匀、消费也均匀,12 个分区齐头并进,可整体还是在积压。

上次的"病根"已经治好了,分区不歪了。这说明瓶颈不在 Kafka 这一层,而是被它下游卡住了——消息消费出来,写不进去。


二、排查现场:顺着「生产 → 消费 → 落库」往下找

SkyWalking 的数据链路很清晰:

Agent → Kafka → OAP(消费) → Elasticsearch(落库)

Kafka 那层已经确认均匀了,OAP 消费也跟得上,那就只剩最后一环——ES 写入。

1. 先看大头在哪个 topic

在 Kafka UI 上扫一眼各 topic 的数据量:

SkyWalking 各 topic 数据量

skywalking-logs 一骑绝尘——500 GB 量级、7 亿多条,其余 topic 加起来都不够它一个零头。所以这次的主战场是日志,落库目标是 ES 的日志索引。

2. ES 机器:一个节点被打满,而且读 IO 高得离谱

集群是 3 台机器(sw2 / sw3 / sw4)装 ES,另有一台 sw1 完全空闲、没装 ES。拉一眼资源总览:

主机健康值CPUIOutil磁盘读磁盘写
sw4 70(最差) 78% 82% 247 MiB/s 10 MiB/s
sw3 84 54% 54% 262 MiB/s 21 MiB/s
sw2 93 26% 28% 184 MiB/s 7 MiB/s
sw1(无 ES) 99 8% 0% 0

ES 机器消费不均

两个细节非常刺眼:

  • 单节点被打满:sw4 的 IOutil 飙到 82%,其他两台轻松。
  • 瓶颈是"读"不是"写":热点节点磁盘读 200+ MiB/s,写才 10 MiB/s。一个日志写入场景,凭什么读这么猛?
  • 3. 反直觉的一幕:热点机器会"漂移"

    过了几天再看,热点居然换了一台机:

    主机6/76/11
    sw4 IOutil 82%(热点) IOutil 31%(恢复了)
    sw3 IOutil 54% IOutil 82%(变热点了)
    sw2 IOutil 28% IOutil 55%

    ES 机器消费不均

    热点不固定在某一台,而是在节点之间轮流坐庄。 到这里,一个特别容易让人跳进去的坑出现了——

    “热点会轮动,肯定是数据倾斜!某些大分片今天落 sw4、明天落 sw3……”

    我一开始也是这么猜的。但这个直觉是错的,下一节用证据打脸(打的是我自己的脸)。


    三、原因分析:一个烟雾弹,两个被推翻的假设

    🗺️ 先给张对照表:上文资源监控用的是主机名 sw*,下文 ES 命令输出用的是节点名 es0*,两套名字指的是同一批机器——sw4 = es01、sw2 = es02、sw3 = es03(sw1 空闲、没装 ES)。所以下面 hot_threads 里 78% 那台 es01,正是上一节 IOutil 82% 的热点 sw4——对着这张表看,就不会把它俩当成两台机。

    1. 烟雾弹:SHARDS_NUMBER=12 看着完全没问题

    第一反应是去翻 ES 分片配置,结果看到:

    SW_STORAGE_ES_INDEX_SHARDS_NUMBER=12

    12 个分片摊到 3 个节点,每节点 4 个,理论上完美均衡。看到这行配置,很容易得出"配置没问题,是 SkyWalking OAP 存储逻辑有 bug"的结论。

    但这行配置是个烟雾弹——先按下不表,我们用三条命令把现场钉死,再回头看它为什么是烟雾弹。

    2. hot_threads:凶手是 Lucene 段合并

    直接问 ES:“你的 CPU 到底在忙什么?”

    GET _nodes/hot_threads

    78.1% cpu by thread 'elasticsearch[es01][[sw_log-20260608][15]: Lucene Merge Thread]'
    …ConcurrentMergeScheduler$MergeThread.run
    21.7% cpu by thread 'elasticsearch[es03][[sw_log-20260608][4]: Lucene Merge Thread]'
    …SegmentMerger.merge

    清一色的 Lucene Merge Thread——是**段合并(segment merge)**在吃 CPU 和磁盘读。而且 search 线程池三节点全是 0:

    这解释了"读 IO 为什么这么高"——不是查询,是合并在读老段、写新段。段合并要把多个小 segment 读出来归并成大 segment,是个典型的读密集操作。

    凶手锁定:段合并热点。

    3. _cat/shards:数据其实完全均匀,"倾斜"假设当场被推翻

    那是不是大分片扎堆某台机?查分片分布:

    GET _cat/shards/*log*?v&s=store:desc

    按节点汇总后,画面让我有点意外:

    ES 节点分片数数据量
    es01 48 ~515 GB
    es02 48 ~515 GB
    es03 48 ~517 GB

    三节点分片数一样、数据量几乎一样,均匀得不能再均匀。 我猜的"数据倾斜"被自己的命令打脸了。

    那"热点轮动"到底怎么回事?答案在分片的大小上:

    • sw_log-20260603:约 800 GB / 36 分片 = 单片约 22 GB
    • sw_log-20260608:约 720 GB / 36 分片 = 单片约 20 GB

    日志索引各分片分布

    等等——配置里明明写的 12 分片,这里怎么变成 36 分片了?而且单片 20 GB 是什么概念?烟雾弹要现形了,先记住这两个数。

    4. recovery + thread_pool:排除搬迁,顺手找到反压出口

    再补两刀,把其他可能性排干净:

    GET _cat/recovery?active_only=true
    # 返回 [] → 没有任何分片在搬迁/重平衡,排除 rebalance

    GET _cat/thread_pool/write,search?v&h=node_name,name,active,queue,rejected

    ES 节点线程池activequeuerejected
    es03(此刻正在 merge) write 8 232 0
    es01 write 0 0 0
    es02 write 0 0 0
    三节点 search 0 0 0

    正在做段合并的 es03,write 队列堆到了 232(它也正是上面 hot_threads 里那个在合并 [sw_log-20260608][4] 的节点)。反压链路一下就通了:

    合并把节点的 IO/CPU 吃满 → 该节点写入队列堆积 → OAP 的 bulk 写入变慢甚至被拒 → OAP 放慢从 Kafka 拉取的速度 → Kafka 积压。

    而 search 全 0,再次确认这台机不是被查询拖垮的,纯粹是合并。

    5. 真相:大头日志根本没走那个 12,而是 super dataset 的另一套参数

    现在回收烟雾弹。翻 SkyWalking 文档才反应过来:SW_STORAGE_ES_INDEX_SHARDS_NUMBER=12 只管 metrics 这类普通索引。而日志、链路这种海量数据,SkyWalking 专门归到一类叫 super dataset,走的是另一套参数:

    SW_STORAGE_ES_SUPER_DATASET_INDEX_SHARDS_FACTOR=3 # 分片 = 12 × 3 = 36
    SW_STORAGE_ES_SUPER_DATASET_INDEX_REPLICAS_NUMBER=0 # 日志 0 副本
    SW_STORAGE_ES_SUPER_DATASET_DAY_STEP=5 # 5 天才滚一个索引

    三个参数凑出了一条完整的因果链:

    参数值后果
    SHARDS_FACTOR=3 36 分片 分片数其实够多,不是分片数的锅
    DAY_STEP=5 5 天一个索引 5 天的日志(约 165 GB/天)全塞进同一批 36 分片 → 单片撑到 20 GB+
    REPLICAS=0 0 副本 无读冗余,且任一节点宕机即丢日志(埋了个雷,见后文)

    症结是 DAY_STEP=5 把单分片养成了 20 GB 的巨无霸。 合并一个 20 GB 的大分片,是一次巨型的读 + CPU 操作;而段合并是突发的、按分片各自触发的——哪几个大分片碰巧在同一时刻、同一台机上一起合并,那台机的 IO 就瞬间被打满。合并完了转到别的分片、别的机器,于是看起来像"热点在轮动"。

    所以「热点轮动」不等于「数据倾斜」。底层数据是均匀的,轮动只是段合并的突发性在不同节点上轮流引爆的假象。我一开始那个"肯定是倾斜"的直觉,正是被这个假象带偏的。

    一句话总结根因:

    大头日志走的是 super dataset,DAY_STEP=5 让单分片高达 20 GB,巨型段合并轮流打满各个 ES 节点的磁盘 IO,反压回 Kafka 形成积压。和 SHARDS_NUMBER=12、和"数据倾斜"都没关系。

    SkyWalking 二次积压根因因果链:DAY_STEP=5 让单分片 20GB,段合并反压回 Kafka 积压 1900 万

    把前面三节的排查证据串成一条因果链:根因 DAY_STEP=5(红)→ 单分片 20GB → 巨型段合并(在均匀节点间轮流引爆,制造"热点轮动"假象)→ 节点 IO 打满、write 队列堆 232 → OAP 放慢拉取 → Kafka 积压 1900 万(红)。解法只需回到链条源头把 DAY_STEP 改成 1。


    四、解决方案:把单分片"喂瘦"

    根因清楚了,思路就一句话——让单个分片别那么大,段合并自然就轻了。 最直接的杠杆就是改 DAY_STEP。

    方案一(治本):DAY_STEP 5 → 1,索引按天滚

    SW_STORAGE_ES_SUPER_DATASET_DAY_STEP=1

    同样 36 分片,但一个索引只装 1 天的数据,单片从 20 GB 直接降到约 4.6 GB(落进 ES 推荐的健康区间)。段合并的规模和耗时随之降到约 1/5,单台机器再也不会被一次大合并打满。

    ⚠️ 改之前必须知道的两个坑(DAY_STEP 是"对存量不友好"的参数):

  • 只对新建索引生效。SkyWalking 是按"时间戳 + 当前 DAY_STEP"反推索引名去查的。改成 1 之后,老的 5 天大索引里,除了"窗口首日"之外的日志会查不到(数据还在盘上,只是索引名对不上了),直到老索引被 TTL 清掉。
  • 老大索引可能不被 TTL 自动清理。同样因为反推索引名对不上,那两个 20 GB+ 的老索引可能赖着不走,需要手动 DELETE 确认回收。
  • 实操建议:改完 DAY_STEP=1,等新索引正常产出、确认不再需要历史日志后,手动删掉老的 super dataset 大索引——一举三得:消除查询空洞、回收上 TB 空间、存量大索引的合并压力当场归零。

    方案二(配套,从源头减量)

    DAY_STEP 治的是"切分",数据总量本身也偏大(约 165 GB/天),可以再做减法:

    • 缩短日志保留天数(SW_CORE_RECORD_DATA_TTL),少留几天,分片更小、合并更轻;
    • 评估日志按错误 / 慢请求采样上报,从采集端减少 skywalking-logs 的量(思路同上一篇给链路降采样)。

    方案三(兜底 & 隐患处理)

    • 临时止血:合并其实已经在限速(hot_threads 里能看到 MergeRateLimiter.maybePause),实在急可再调小 index.merge.scheduler.max_thread_count 给写入让路,但治标。
    • 白捡一台:那台空闲的 sw1 加进 ES 集群,3 节点扩 4 节点,每节点分片从 48 降到 36,合并并发头寸更宽。
    • 0 副本的雷:super dataset 是 0 副本,任一 ES 节点宕机 = 该节点的日志分片直接丢失且不可查。这是稳定性隐患,治理时一并评估要不要给它配 1 副本(代价是写入和存储翻倍,需权衡)。

    五、解决验证:7 分钟从 1900 万降到 10 万以下

    把 DAY_STEP 改成 1 后重建 SkyWalking OAP,效果立竿见影:

    时间状态
    00:05:45 开始重建 OAP 此刻 Kafka 积压约 1893 万
    00:12 积压从 1893 万 降到正常的 10 万以下

    消费积压过程中,三台 ES 的 CPU 终于均衡了(不再有某台被打满):

    改成 1 天 1 索引,消费积压过程中 CPU 均衡

    积压消费完毕后,CPU 整体回落:

    积压消费完毕,CPU 下降

    整体积压曲线断崖式下跌:

    整体积压情况及积压快速降低

    一个参数,7 分钟,积压清零。


    六、举一反三:三条能带走的经验

    这次复盘最值钱的不是"改 DAY_STEP"这个动作,而是过程里踩过的三个认知坑:

    1. 积压排查要顺着「生产 → 消费 → 落库」逐段走,别停在第一层

    第一阶段我们停在 Kafka,治好了分区倾斜。但积压的根可能在更下游——这次 Kafka 完全正常,瓶颈在最末端的 ES 写入。看到"积压"别只盯着消息队列,沿着数据最终要去的地方一段段往下查。

    2. “配置看着对” ≠ “配置在起作用”

    SHARDS_NUMBER=12 是个教科书级的烟雾弹——它语法正确、值也合理,却根本不管大头日志。很多组件都有"普通配置"和"特殊数据集旁路配置"之分(SkyWalking 的 super dataset 就是典型)。当一个配置"看着没问题但现象还在",先确认它到底管不管你这条数据路径,而不是急着甩锅给"框架有 bug"。

    3. “热点轮动” ≠ “数据倾斜”

    热点在机器间漂移,最容易让人脑补成"数据偏了"。但突发型后台任务(段合并、GC、compaction……)在多个均匀节点上轮流引爆,同样会制造"轮动热点"的假象。别靠直觉下结论,用 hot_threads(在忙什么)+ _cat/shards(数据均不均)+ recovery(有没有在搬)三件套把现场钉死,证据比直觉可靠得多。

    三条命令、一个参数,把一次"分区都均匀了为什么还积压"的悬案破了。如果你也在用 SkyWalking + ES 存日志,不妨现在就去看一眼自己的 SUPER_DATASET_DAY_STEP 和单分片大小——别等积压 1900 万了才想起它。


    觉得有用的话,点个赞收藏一下,下次半夜被 SkyWalking 积压告警叫醒时,方便快速翻出来抄作业。👍

    上一集在这儿:《SkyWalking 消费积压 6 亿条:一次 Kafka 分区倾斜的深度复盘》。


    延伸阅读

    • SkyWalking 消费积压 6 亿条:一次 Kafka 分区倾斜的深度复盘 —— 本系列上一集,先把 Kafka 分区倾斜(key 固定)治好,本篇承接其后
    • 从 MQ 积压追到事件总线:诊断 4K 线程吃光 7G 内存的实战 —— 同为消费积压逐层排查,从积压现象追到根因
    • 【待发布后补充引用关系:《一台机磁盘读 180MB/s、另两台几乎为 0:SkyWalking 又积压,凶手是抢走 page cache 的同机 OAP》】 —— 本系列第三集(待发布,上线后换 CSDN 链接)

    🏷️ 标签:SkyWalking Elasticsearch 消息积压 Kafka 线上排障 性能优化

    赞(0)
    未经允许不得转载:171主机测评 » SkyWalking 日志又积压 1900 万:Kafka 分区明明均匀了,凶手却藏在 ES 段合并里
    分享到: 更多 (0)

    评论 抢沙发

    • 昵称 (必填)
    • 邮箱 (必填)
    • 网址