starrocks 3.1.17 插入数据锁库，查询超时

💬 StarRocks 用户问答 日常运维
#1

【详述】
starrocks 3.17
starrocks 3fe 3be
从kafka里消费数据数据入库，每隔一段时间，就会有消费延迟，然后锁库，
随后过几分钟，就会报 starrocks_fe_query_latency_ms 超5分钟。
fe be日志如下，能否帮忙分析下问题？

看了下promethues，cpu 内存 都正常，资源都没有报警，占了40%左右

报警时间：2025.11.18 06:40:40
恢复时间：2025.11.18 06:43:25

To平台與運維[1.主题]:10.176.44.75-9308 恢復[2.恢复时间]:2025.11.18 06:43:25[3.恢复详情]:Port 9308:1[4.恢复集群]:kafka_gl_75[5.恢复內容]:【环境】xx.xx.xx.xx-9308 【消费组】sr2-dwd_phm_cnc_realtime_param_latest_20250321 【topic】hzdata-phm-dwd.cnc-param【积压】：83830.00[6.告警開始時間]:2025.11.18 06:40:40

To平台與運維[1.主题]:10.176.44.75-9308 恢復[2.恢复时间]:2025.11.18 06:43:25[3.恢复详情]:Port 9308:1[4.恢复集群]:kafka_gl_75[5.恢复內容]:【环境】xx.xx.xx.xx-9308 【消费组】sr2-dwd_phm_cnc_realtime_param_20250417 【topic】hzdata-phm-dwd.cnc-param【积压】：107492.00[6.告警開始時間]:2025.11.18 06:40:25

To平台與運維[1.主题]:10.176.46.212-8030 異常[2.告警时间]:[3.问题详情]:Port 8030:0[4.告警集群]:gl-starrocks2[5.告警內容]:starrocks_fe_query_latency_ms 超5分钟

【业务影响】慢查询
【是否存算分离】存算一体
【StarRocks版本】3.1.17
【集群规模】3fe（1 follower+2observer）+ 3be
【机器信息】
【联系方式】StarRocks社区群20-生鱼片
【附件】
fe.tmp.warn.log (455.6 KB) be.tmp.INFO (10.7 MB) fe.tmp.log (10.3 MB)

#2

可能需要提供 06:40 左右的 FE GC 日志，这是判断 FE 是否是“受害者”还是“元凶”的关键证据。

#3

感谢，这是今天gc的日志，您帮忙看一下 fe.gc.tmp.log (227.3 KB)

#4

GC 日志分析结果

通过分析 06:40:40 到 06:43:25 这一关键时间窗口的 GC 记录，我们可以得出以下结论：

  1. 没有发生长时间的 GC 暂停 (Stop-The-World, STW)。
  • 在整个日志片段中，所有的 Young GC (G1 Evacuation Pause) 暂停时间都非常短，通常在 10ms 到 71ms 之间。
  • 在报警时间窗口内（06:43:18 和 06:43:23），GC 暂停时间分别为 13.119ms 和 13.477ms 。
  • 结论： FE 节点并没有因为长时间的 Full GC 暂停而导致线程阻塞，因此 FE 延迟超 5 分钟（300,000ms） 的原因 不是 JVM GC 引起的 。
  1. Old 区内存持续增长。
  • 在 06:00 时，Old 区内存占用约为 1.6GB (1607M)。
  • 到 06:43 时，Old 区内存占用约为 1.66GB (1664M)。
  • 到 07:00 时，Old 区内存占用约为 1.79GB (1794M)。
  • 结论： Old 区内存确实在缓慢增长，这与您之前发现的 RecycleBin 内存泄漏 的分析一致。但是，这种缓慢的增长不足以在几分钟内导致 FE 彻底阻塞 5 分钟。
  1. FE 内存使用情况：
  • FE 堆内存总量为 16344M (约 16GB)。
  • 在 06:43 报警时，FE 的 Old 区占用仅约 1.6GB，总内存占用（Young + Old + Humongous）在 GC 暂停后约为 1.6GB - 2GB 左右。
  • 结论： FE 内存使用率非常低，远未达到内存瓶颈。

最终诊断：元数据锁竞争是 FE 延迟的直接原因

既然 GC 暂停被排除，那么 FE 延迟超 5 分钟的直接原因就是 FE 线程被长时间阻塞在等待某个锁上 ，即 元数据锁竞争 。

问题链条确认：

  1. BE 写入瓶颈（根源）： 某个或某几个 Routine Load 任务在 BE 侧写入数据时，由于 Compaction 压力或 I/O 延迟，被阻塞了很长时间（如您之前发现的 15 秒 write cost ）。
  2. FE 事务提交阻塞（直接原因）： 当这些慢任务终于完成 BE 写入后，它们会向 Leader FE 发起事务提交（Commit Transaction）请求。
  3. 元数据锁竞争：
  • FE 在处理事务提交时，需要获取并持有元数据锁（例如，数据库锁或表锁）。[ 重试 错误原因](javascript:void(0))
  • 如果此时有大量积压的导入任务同时到达 FE，或者 FE 正在处理一个耗时长的内部任务（如 Materialized View 刷新、Schema Change、或 Leader FE 内部的元数据操作），并且这个操作长时间持有锁。
  • 结果： 所有后续的查询请求（ SELECT ）和导入请求（Routine Load 的下一个批次）在等待这个锁时被阻塞，直到超时（5 分钟），从而触发 starrocks_fe_query_latency_ms 报警，表现为“锁库”。

建议的下一步行动

现在我们已经排除了 GC 问题，需要将排查重点转向 BE 侧的写入瓶颈 和 FE 侧的锁竞争 。

  1. 排查 BE 写入瓶颈（根源）：
  • I/O 延迟： 检查 06:40 附近的 BE 节点磁盘 I/O 延迟监控图。如果 I/O 延迟有尖峰，说明磁盘是瓶颈。
  • Compaction 积压： 检查 BE 节点的 Compaction 任务积压指标。如果积压严重，需要调整 Compaction 线程数或策略。
  • 表结构： 确认导入的表是否为 Primary Key 或 Unique Key 模型，这些模型会产生更高的 Compaction 压力。
  1. 排查 FE 锁竞争（直接原因）：
  • FE 日志： 检查 06:40 附近的 fe.log ，查找是否有以下关键字：
    • acquire lock 或 lock contention 相关的警告。
    • 长时间运行的内部任务（如 Materialized View refresh 或 Schema Change ）的开始和结束时间，看是否与报警时间重叠。
    • Routine Load 任务的 commit transaction 耗时，看是否有其他任务也像 Txn 61734966 一样耗时异常长。
  1. 升级版本（长期建议）：
  • StarRocks 3.2 及更高版本对 FE 的元数据锁机制进行了大量优化，可以显著减少这种高并发导入导致的锁竞争问题。强烈建议升级。
#5

还有一次，昨天的11点29的gc，能看出有什么问题嘛？现在关键是锁库，影响查询，有什么好的建议吗？

[2025-11-17T12:12:17.493+0800] GC(273407) Pre Evacuate Collection Set: 0.1ms

[2025-11-17T12:12:17.493+0800] GC(273407) Evacuate Collection Set: 10.3ms

[2025-11-17T12:12:17.493+0800] GC(273407) Post Evacuate Collection Set: 1.7ms

[2025-11-17T12:12:17.493+0800] GC(273407) Other: 0.7ms

[2025-11-17T12:12:17.493+0800] GC(273407) Eden regions: 2443->0(2442)

[2025-11-17T12:12:17.493+0800] GC(273407) Survivor regions: 8->9(307)

[2025-11-17T12:12:17.493+0800] GC(273407) Old regions: 415->415

[2025-11-17T12:12:17.493+0800] GC(273407) Humongous regions: 81->39

[2025-11-17T12:12:17.493+0800] GC(273407) Metaspace: 147171K->147171K(1185792K)

[2025-11-17T12:12:17.493+0800] GC(273407) Pause Young (Normal) (G1 Evacuation Pause) 11786M->1849M(16344M) 12.819ms

[2025-11-17T12:12:17.493+0800] GC(273407) User=0.13s Sys=0.00s Real=0.02s

[2025-11-17T12:12:19.078+0800] GC(273408) Pause Young (Concurrent Start) (G1 Humongous Allocation)

[2025-11-17T12:12:19.078+0800] GC(273408) Using 13 workers of 13 for evacuation

[2025-11-17T12:12:19.096+0800] GC(273408) Pre Evacuate Collection Set: 0.5ms

[2025-11-17T12:12:19.096+0800] GC(273408) Evacuate Collection Set: 15.6ms

[2025-11-17T12:12:19.096+0800] GC(273408) Post Evacuate Collection Set: 0.8ms

[2025-11-17T12:12:19.096+0800] GC(273408) Other: 0.8ms

[2025-11-17T12:12:19.096+0800] GC(273408) Eden regions: 43->0(2439)

[2025-11-17T12:12:19.096+0800] GC(273408) Survivor regions: 9->12(307)

[2025-11-17T12:12:19.096+0800] GC(273408) Old regions: 415->415

[2025-11-17T12:12:19.096+0800] GC(273408) Humongous regions: 39->39

[2025-11-17T12:12:19.096+0800] GC(273408) Metaspace: 147171K->147171K(1185792K)

[2025-11-17T12:12:19.096+0800] GC(273408) Pause Young (Concurrent Start) (G1 Humongous Allocation) 2019M->1862M(16344M) 17.667ms

[2025-11-17T12:12:19.096+0800] GC(273408) User=0.09s Sys=0.00s Real=0.02s

[2025-11-17T12:12:19.096+0800] GC(273409) Concurrent Cycle

[2025-11-17T12:12:19.096+0800] GC(273409) Concurrent Clear Claimed Marks

[2025-11-17T12:12:19.096+0800] GC(273409) Concurrent Clear Claimed Marks 0.192ms

[2025-11-17T12:12:19.096+0800] GC(273409) Concurrent Scan Root Regions

[2025-11-17T12:12:19.101+0800] GC(273409) Concurrent Scan Root Regions 5.057ms

[2025-11-17T12:12:19.101+0800] GC(273409) Concurrent Mark (16341721.159s)

[2025-11-17T12:12:19.101+0800] GC(273409) Concurrent Mark From Roots

[2025-11-17T12:12:19.101+0800] GC(273409) Using 3 workers of 3 for marking

[2025-11-17T12:12:19.406+0800] GC(273409) Concurrent Mark From Roots 304.399ms

[2025-11-17T12:12:19.406+0800] GC(273409) Concurrent Preclean

[2025-11-17T12:12:19.406+0800] GC(273409) Concurrent Preclean 0.493ms

[2025-11-17T12:12:19.406+0800] GC(273409) Concurrent Mark (16341721.159s, 16341721.464s) 304.962ms

[2025-11-17T12:12:19.407+0800] GC(273409) Pause Remark

[2025-11-17T12:12:19.415+0800] GC(273409) Cleaned string and symbol table, strings: 61147 processed, 730 removed, symbols: 310219 processed, 1 removed

[2025-11-17T12:12:19.416+0800] GC(273409) Pause Remark 1903M->1903M(16344M) 8.627ms

[2025-11-17T12:12:19.416+0800] GC(273409) User=0.09s Sys=0.00s Real=0.01s

[2025-11-17T12:12:19.416+0800] GC(273409) Concurrent Rebuild Remembered Sets

[2025-11-17T12:12:19.722+0800] GC(273409) Concurrent Rebuild Remembered Sets 306.675ms

[2025-11-17T12:12:19.723+0800] GC(273409) Pause Cleanup

[2025-11-17T12:12:19.724+0800] GC(273409) Pause Cleanup 1904M->1904M(16344M) 0.614ms

[2025-11-17T12:12:19.724+0800] GC(273409) User=0.00s Sys=0.00s Real=0.00s

[2025-11-17T12:12:19.724+0800] GC(273409) Concurrent Cleanup for Next Mark

[2025-11-17T12:12:19.733+0800] GC(273409) Concurrent Cleanup for Next Mark 9.026ms

[2025-11-17T12:12:19.733+0800] GC(273409) Concurrent Cycle 636.740ms

[2025-11-17T12:18:11.518+0800] GC(273410) Pause Young (Prepare Mixed) (G1 Evacuation Pause)

[2025-11-17T12:18:11.518+0800] GC(273410) Using 13 workers of 13 for evacuation

[2025-11-17T12:18:11.533+0800] GC(273410) Pre Evacuate Collection Set: 0.1ms

[2025-11-17T12:18:11.533+0800] GC(273410) Evacuate Collection Set: 11.4ms

[2025-11-17T12:18:11.533+0800] GC(273410) Post Evacuate Collection Set: 2.1ms

[2025-11-17T12:18:11.533+0800] GC(273410) Other: 0.9ms

[2025-11-17T12:18:11.533+0800] GC(273410) Eden regions: 2439->0(191)

[2025-11-17T12:18:11.533+0800] GC(273410) Survivor regions: 12->13(307)

[2025-11-17T12:18:11.533+0800] GC(273410) Old regions: 415->415

[2025-11-17T12:18:11.533+0800] GC(273410) Humongous regions: 146->38

[2025-11-17T12:18:11.533+0800] GC(273410) Metaspace: 147171K->147171K(1185792K)

[2025-11-17T12:18:11.533+0800] GC(273410) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 12046M->1861M(16344M) 14.457ms

[2025-11-17T12:18:11.533+0800] GC(273410) User=0.15s Sys=0.00s Real=0.02s

[2025-11-17T12:18:47.137+0800] GC(273411) Pause Young (Mixed) (G1 Evacuation Pause)

[2025-11-17T12:18:47.137+0800] GC(273411) Using 13 workers of 13 for evacuation

[2025-11-17T12:18:47.156+0800] GC(273411) Pre Evacuate Collection Set: 0.1ms

[2025-11-17T12:18:47.156+0800] GC(273411) Evacuate Collection Set: 16.7ms

[2025-11-17T12:18:47.156+0800] GC(273411) Post Evacuate Collection Set: 1.0ms

[2025-11-17T12:18:47.156+0800] GC(273411) Other: 1.1ms

[2025-11-17T12:18:47.156+0800] GC(273411) Eden regions: 191->0(2437)

[2025-11-17T12:18:47.156+0800] GC(273411) Survivor regions: 13->14(26)

[2025-11-17T12:18:47.156+0800] GC(273411) Old regions: 415->413

[2025-11-17T12:18:47.156+0800] GC(273411) Humongous regions: 38->38

[2025-11-17T12:18:47.156+0800] GC(273411) Metaspace: 147171K->147171K(1185792K)

[2025-11-17T12:18:47.156+0800] GC(273411) Pause Young (Mixed) (G1 Evacuation Pause) 2625M->1855M(16344M) 18.881ms

[2025-11-17T12:18:47.156+0800] GC(273411) User=0.12s Sys=0.00s Real=0.02s

[2025-11-17T12:32:30.318+0800] GC(273412) Pause Young (Normal) (G1 Evacuation Pause)

[2025-11-17T12:32:30.318+0800] GC(273412) Using 13 workers of 13 for evacuation

[2025-11-17T12:32:30.337+0800] GC(273412) Pre Evacuate Collection Set: 0.2ms

[2025-11-17T12:32:30.337+0800] GC(273412) Evacuate Collection Set: 16.3ms

[2025-11-17T12:32:30.337+0800] GC(273412) Post Evacuate Collection Set: 1.8ms

[2025-11-17T12:32:30.337+0800] GC(273412) Other: 0.9ms

[2025-11-17T12:32:30.337+0800] GC(273412) Eden regions: 2437->0(2428)

[2025-11-17T12:32:30.337+0800] GC(273412) Survivor regions: 14->23(307)

[2025-11-17T12:32:30.337+0800] GC(273412) Old regions: 413->413

[2025-11-17T12:32:30.337+0800] GC(273412) Humongous regions: 81->38

[2025-11-17T12:32:30.337+0800] GC(273412) Metaspace: 147171K->147171K(1185792K)

[2025-11-17T12:32:30.337+0800] GC(273412) Pause Young (Normal) (G1 Evacuation Pause) 11775M->1889M(16344M) 19.079ms

[2025-11-17T12:32:30.337+0800] GC(273412) User=0.15s Sys=0.01s Real=0.02s

[2025-11-17T12:32:36.823+0800] GC(273413) Pause Young (Concurrent Start) (G1 Humongous Allocation)

[2025-11-17T12:32:36.823+0800] GC(273413) Using 13 workers of 13 for evacuation

[2025-11-17T12:32:36.859+0800] GC(273413) Pre Evacuate Collection Set: 0.5ms

[2025-11-17T12:32:36.859+0800] GC(273413) Evacuate Collection Set: 32.7ms

[2025-11-17T12:32:36.859+0800] GC(273413) Post Evacuate Collection Set: 2.6ms

[2025-11-17T12:32:36.859+0800] GC(273413) Other: 1.0ms

[2025-11-17T12:32:36.859+0800] GC(273413) Eden regions: 176->0(2423)

[2025-11-17T12:32:36.859+0800] GC(273413) Survivor regions: 23->28(307)

[2025-11-17T12:32:36.859+0800] GC(273413) Old regions: 413->413

[2025-11-17T12:32:36.859+0800] GC(273413) Humongous regions: 38->38

[2025-11-17T12:32:36.859+0800] GC(273413) Metaspace: 147171K->147171K(1185792K)

[2025-11-17T12:32:36.859+0800] GC(273413) Pause Young (Concurrent Start) (G1 Humongous Allocation) 2592M->1909M(16344M) 36.738ms

[2025-11-17T12:32:36.859+0800] GC(273413) User=0.16s Sys=0.00s Real=0.03s

[2025-11-17T12:32:36.859+0800] GC(273414) Concurrent Cycle

[2025-11-17T12:32:36.859+0800] GC(273414) Concurrent Clear Claimed Marks

[2025-11-17T12:32:36.860+0800] GC(273414) Concurrent Clear Claimed Marks 0.166ms

[2025-11-17T12:32:36.860+0800] GC(273414) Concurrent Scan Root Regions

[2025-11-17T12:32:36.870+0800] GC(273414) Concurrent Scan Root Regions 10.012ms

[2025-11-17T12:32:36.870+0800] GC(273414) Concurrent Mark (16342938.928s)

[2025-11-17T12:32:36.870+0800] GC(273414) Concurrent Mark From Roots

#6

提供的 11 月 17 日 12:12 左右的 GC 日志片段，与 11 月 18 日 06:40 的日志片段得出了 相同的结论 ：

1. GC 日志分析结果

  • GC 类型： 都是 G1 Evacuation Pause (Young GC 或 Mixed GC)。
    GC 类型：都是 G1 Evacuation Pause（年轻 GC 或混合 GC）。
  • 暂停时间： 所有的 GC 暂停时间都非常短，最长的一次是 36.738ms。
  • 结论： FE 节点在 11 月 17 日 12:12 左右 没有发生长时间的 GC 暂停 。

这进一步确认了 FE 延迟超 5 分钟（锁库）的直接原因不是 JVM 垃圾回收，而是 StarRocks 内部的锁竞争或线程阻塞。

2. 解决“锁库”问题的建议（聚焦锁竞争和 BE 瓶颈）

既然 GC 已经被排除，解决“锁库”问题的关键在于打破 “BE 慢写入 -> FE 事务堆积 -> 元数据锁竞争” 这个恶性循环。

以下是针对 StarRocks 3.1.7 版本，解决高并发导入导致锁库问题的具体建议：

建议一：优化 BE 写入性能（治本）

这是问题的根源。如果 BE 写入速度慢，FE 就会被动等待。

  1. 检查并优化 Compaction 资源：
  • 监控 Compaction 积压： 重点关注 BE 监控指标中 Compaction 任务的数量和耗时。
  • 调整 Compaction 线程： 如果 Compaction 积压严重，适当增加 BE 配置中的 Compaction 线程数，例如：
    • cumulative_compaction_num_threads
    • base_compaction_num_threads
  • 调整 Compaction 策略： 确保 Compaction 能够及时进行，避免版本过多导致写入变慢。
  1. 检查磁盘 I/O 性能：
  • 监控 I/O 延迟： 检查 BE 节点在 06:40 报警时间点的磁盘 I/O 延迟（Latency）。如果延迟超过几十毫秒，说明磁盘是瓶颈，需要考虑升级到高性能 SSD。
  1. 优化导入任务参数：
  • 增大 Routine Load 批次大小： 适当增大 Routine Load 的 max_batch_interval 和 max_batch_rows 。这可以减少 FE 事务提交的频率，从而减轻 FE 的锁竞争压力。
    • 注意： 批次过大可能导致单个事务失败代价高，需要找到平衡点。如果当前批次很小（例如几百行），可以尝试增大到几千或几万行。

建议二：缓解 FE 锁竞争（治标/治关键）

  1. 检查并优化 Materialized View (MV) 刷新：
  • MV 刷新（特别是全量刷新）需要长时间持有元数据锁。如果 MV 刷新与导入高峰重叠，很容易导致锁竞争。
  • 操作： 检查是否有 MV 刷新任务在 06:40 左右运行。如果是，尝试错开 MV 刷新时间，或将刷新策略改为增量刷新。
  1. 检查 FE 线程池状态：
  • 在问题发生时，如果能通过 FE Web UI 或 JMX 监控 FE 的线程状态，查看是否有大量线程处于 WAITING 状态，等待同一个锁（通常是 Database.readLock 或 GlobalTransactionMgr 相关的锁）。
  1. 升级 StarRocks 版本（最重要）：
  • StarRocks 3.2 及更高版本 对 FE 的元数据锁进行了重构和优化，显著减少了高并发导入和查询之间的锁竞争。
  • 强烈建议将集群升级到 3.2.x 或 3.3.x 的最新稳定版本。 解决这种锁竞争问题，升级通常是最有效的手段。

总结

您的 FE GC 日志显示 FE 本身运行健康， 问题核心在于 BE 写入慢导致的 FE 事务提交堆积和锁竞争 。请重点排查 BE 侧的 Compaction 和 I/O 性能，并考虑通过升级版本来获得更健壮的 FE 锁管理机制。

#7

为啥我改完这几个参数，直接积压报错：
cumulative_compaction_num_threads_per_disk = 3

base_compaction_num_threads_per_disk = 2

cumulative_compaction_check_interval_seconds = 2

update_compaction_num_threads_per_disk = 3

update_compaction_per_tablet_min_interval_seconds = 100

报错信息：
To平台與運維[1.主题]:xx.xx.xx.xxbe.tmp [2].INFO (22.0 MB) -9308 異常[2.告警时间]:2025.11.18 16:37:55[3.问题详情]:Port 9308:0[4.告警集群]:kafka_gl_75[5.告警內容]:【环境】10.176.44.75-9308 【消费组】sr2-dwd_phm_cnc_realtime_param_latest_20250321 【topic】hzdata-phm-dwd.cnc-param【积压】：117967.00

2025-11-18 16:48:08

To平台與運維[1.主题]:xx.xx.xx.xx-8030 異常[2.告警时间]:2025.11.18 16:47:38[3.问题详情]:Port 8030:0[4.告警集群]:starrocks2[5.告警內容]:starrocks_fe_query_latency_ms 超5分钟

京ICP备2022026421号-1