tikv 频繁报 async write too slow

tikv的日子几乎每分钟都在报这个日志
async write too slow, write_kv: 0s, write_raft: 0.001082086s, send: 0.00001171s, callback: 0.0000029s thread: store-writer-0"] [takes=1] [thread_id=235]
但是看了下,好像没有write stall的现象,怀疑是写rocksdb 慢

看下 grafana 关于磁盘 IO 的指标

IO有没有限流了

如果不是stall只能认为是IO慢

优先查 TiKV-Details → Storage → Async Write DurationRaft → Append Log Duration 监控

检查下,是不是磁盘压力大

建议排查磁盘I/O瓶颈:IOPS/吞吐打满、await高、%util高

可能是刷盘延迟了,还是要看操作系统的io指标

maybe disk error

IO性能指标有异常吗

典型的排队等待耗时,不是执行耗时。
可能是磁盘瓶颈,内存瓶颈,cpu瓶颈,

  1. 优先检查磁盘 I/O :这是最可能的瓶颈点。
  2. 查看 CPU 使用率:确认是否是计算资源不足。
  3. 分析 Region 分布 :是否存在热点。

看下硬盘是否io慢

日志是 TiDB 最典型的底层 RocksDB 写入延迟高,和业务报错、write stall 无关,100% 是 RocksDB 压不住、磁盘 / IO 瓶颈。

这方面有没有什么办法优化呢

该告警多为RocksDB 后台压实 / 刷盘阻塞,无写 stall 多是 IO 吞吐、后台压缩线程争抢导致,优先排查磁盘 IO 与 RocksDB 参数。

存储引擎层的写入性能瓶颈。这个告警意味着 TiKV 将数据异步写入底层 RocksDB 的耗时超过了预期,通常会直接导致业务写入延迟(Write Latency)升高。

1 个赞

有可能是超过iops限制了

这个日志的意思是:每次 Raftstore 的 store-writer 线程将一批写入刷新到引擎时,都会记录耗时明细。并不是真的有性能问题。

这个日志由 slow_log! 宏发出(tag 为 “slow_log”),虽然它叫"慢日志",但实际上这个调用点用的是无条件变体,意思是每次都打,不检查是否真的"慢"。不过系统中有一个 SlowLogFilter(在 tikv_util/src/logger/mod.rs:449),它会检查 takes 值是否超过 slow_log_threshold 配置。你的 takes=1(1ms)说明你的阈值设得很低或为 0。

各阶段含义

write_kv: 0s → 把 KV 数据写入 RocksDB 的时间(0s,几乎没有数据)
write_raft: 0.001s → 把 Raft 日志写入 Raft Engine 的时间(约 1ms)
send: 0.00001s → 向其他 peer 发送 Raft 消息的时间
callback: 0.000002s → 回调通知的时间
takes=1 → 总耗时(单位:毫秒)

为什么每分钟一次?

这说明你的集群写流量很小,大约每分钟才有一个写批次被刷新。store-writer-0 线程是 raftstore 的异步写入线程,它攒一批写请求,然后批量写入引擎。如果写请求很少,它每隔一段时间才 flush 一次。

是问题吗?

不是问题。整个操作只用了 ~1ms 就完成了,非常快。这只是一个信息日志,让你了解写入路径上每个环节的耗时分布。

如果想减少日志频率

可以调大 slow-log-threshold(默认是 100ms):

[log]
slow-log-threshold = “100ms” # 只记录超过 100ms 的慢操作

slow-log-file = “/path/to/slow.log” # 如果配置了独立文件,会分流到该文件

这样 takes=1ms 的日志就不会再输出了。

磁盘IO和网络