RocksDB 跑着跑着发现延迟上去了、吞吐掉下来了第一反应是加缓存、加机器、调参数。但很多时候问题并不在参数本身而是根本没搞清楚时间到底花在了哪里是在内存里比 key是在等锁是在读盘还是在等 compaction 挤占资源这个时候两个层面的工具缺一不可RocksDB 自己内置的 perf_context 就像武侠小说里的“内功”能直接告诉你内部各路武功的消耗而 systemtap、perf、ftrace 这些系统级工具则是“颜值”从外面帮你看清楚进程的 CPU 火焰图、内核的 IO 路径、锁的争抢情况。这篇文章就聊聊我用这几个工具做 RocksDB 性能分析时积累下来的“小技巧”包括怎么开 perf_context、哪些指标最值得盯、三种系统工具分别适合什么场景以及我最常踩的几个坑。1. 先从“内功”说起perf_context 究竟能告诉我们什么1.1 perf_context 的启用方式和正确使用姿势perf_context 是 RocksDB 在内部热路径上埋的一堆计数器和计时器。你执行一次 Get、Put、Seek、Next它会顺带记录下“这次操作比较了几次 key”“从缓存读了多少 block”“触发了多少次 bloom filter 判断”“写 WAL 花了多久”“在 memtable 上花了多久”之类的细节。这些东西在普通日志里看不到但恰恰是判断 RocksDB 自身行为是否正常的第一手资料。启用方式很直接#include rocksdb/perf_context.h // 设为 kEnableTime 才会记录计时类指标 rocksdb::SetPerfLevel(rocksdb::PerfLevel::kEnableTime); rocksdb::get_perf_context()-Reset(); Status s db-Get(options, key, value); // 直接把当前线程的 context 打出来 std::cerr rocksdb::get_perf_context()-ToString();这里有个很关键的点perf_context 是线程局部的。你在主线程开这个开关它只统计主线程发起的操作后台 compaction、flush 线程有自己的 context得在那个线程里单独设置。很多新手一开 perf_context 发现数据很少以为是没生效其实是统计错对象了。PerfLevel 有五个档位从轻到重分别是kDisable完全不统计。kEnableCount只统计次数类指标不计时。kEnableTimeExceptForMutex统计时间但不包含等待 mutex 的时间。kEnableTime所有计时都开。kOutOfTime一种内部过渡状态表示某个计时器因为超出作用域而提前停止。日常排查用 kEnableTime 最直观但要注意它的额外开销不小。线上环境不建议长期挂着我习惯先跑 kEnableCount 看计数器总量确认问题方向后再开 kEnableTime 做短时间采样。如果不想只盯着当前线程RocksDB 也提供了 DB 级别的聚合视图通过 GetProperty 拿std::string value; if (db-GetProperty(rocksdb.perf_context, value)) { // value 里是聚合后的 perf context 字符串 }但这同样需要先在相关线程里打开 perf level否则采集不到数据。实际操作时我会写一个统一的开关函数在压测脚本的每个线程开头调用 SetPerfLevel跑完一批再统一 Reset 读取。1.2 几个值得盯死的核心指标perf_context 的指标很多但大部分场景下盯住这几个就够用指标含义排查建议user_key_comparison_count查询或迭代过程中比较用户 key 的次数数值很大说明比较器开销高可考虑前缀提取器或优化排序规则block_cache_hit_count / block_cache_miss_count块缓存命中/未命中次数miss 占比高先看容量、再看数据访问局部性block_read_count / block_read_byte从磁盘读取 block 的次数和字节数数值越大 IO 占比越高结合 IO 延迟判断瓶颈get_hit_l0 / get_hit_l1 / get_hit_l2_and_upGet 命中的 SST 层级分布老是在 L2 说明数据下沉太深检查 compaction 策略bloom_filter_usefulbloom filter 拦截掉无效查找的次数长期接近 0说明 bloom 配置可能没生效write_delay_time写入路径上因等待而产生的延迟持续非 0 大概率是 write stall需要看停顿原因write_wal_time / write_memtable_time写 WAL 和写 memtable 的耗时WAL 时间高看重做日志刷盘配置memtable 时间高看内存分配举个实际例子。之前接手过一个线上模块业务反馈 Get 偶尔会跳到十几毫秒平时只有零点几毫秒。我第一反应不是先上火焰图而是先用 perf_context 抓一次慢请求。结果发现 block_read_count 和 block_read_byte 明显偏高block_cache_miss_count 也涨得厉害而 bloom_filter_useful 几乎没变化。这基本就能断定读路径上布隆过滤器没有生效很多本该被拦截的 key 都直接去翻 block 了。后来检查发现代码里只配置了 prefix bloom而业务查询用的全是完整 key没办法利用上前缀过滤。把 bloom filter 的配置改成支持整 key 过滤后block_read_count 直接掉了一个数量级慢请求也消失了。这种定位效率是单纯靠看 CPU 火焰图很难达到的。2. “颜值”选手一perf 定位 CPU 热点和锁竞争2.1 采样怎么采才不白采如果说 perf_context 是让 RocksDB 自己“交代”内部情况那 perf 就是从外面看进程到底在忙什么。它基于内核的 perf_event 子系统做采样不改代码、不需要重新编译就能拿到调用栈和硬件计数器。最常用的三招# 第一招实时看热点 perf top -p pid -g # 第二招采样 30 秒生成调用图数据 perf record -F 99 -g --call-graph dwarf -p pid -- sleep 30 perf report # 第三招看硬件计数器 perf stat -e task-clock,cycles,cache-references,cache-misses,branches,branch-misses -p pid -- sleep 30有几个经验之谈采样频率没必要拉太高。-F 99 是 Brendan Gregg 推荐的经典值每秒 99 次采样一方面避免和内核 ticks 的周期共振一方面不至于造成太大开销。压测机配置高的话跑到 1000 也可以但采样太密会把进程拖慢反而失真。调用栈能不能拿到取决于编译选项。RocksDB 如果是用 CMake 默认选项编的帧指针可能被省略这时候 --call-graph fp 拿到的调用栈很残缺。要么用 --call-graph dwarf 让 perf 通过调试信息解析栈要么重新编译时加上-fno-omit-frame-pointer -g。我一般固定用 dwarf 模式省心。采样时间别太短。至少采 30 秒以上否则热点函数的占比波动很大看不出稳定的模式。遇到高吞吐服务给个 60 秒也不嫌多。perf stat 里 cache-misses 这个数要结合 cache-references 看比例。如果 miss 比例超过 20%说明内存访问模式很散数据在 cache 里根本放不住。RocksDB 里常见的原因是跳表节点指针跳跃、hash 索引的随机访问、block cache 的 LRU 链表扫描这些在火焰图上通常表现为 template 代码堆里的长尾。2.2 从火焰图里读出 RocksDB 的秘密采样完之后我喜欢把数据转成火焰图观感比 perf report 的文本界面好太多。流程是标准的perf script out.perf # 用 Brendan Gregg 的脚本折叠调用栈 stackcollapse-perf.pl out.perf out.folded flamegraph.pl out.folded flamegraph.svg拿到火焰图重点看“平顶”和“宽底”。RocksDB 的热点函数有非常典型的几个比较器相关函数比如 bytewise 比较的 memcmp 系。如果这个占比奇高说明你设置的排序规则在大量比较时效率不高或者前缀设计不合理导致比较次数爆炸。和 perf_context 的 user_key_comparison_count 一对照就能验证。MemTable::Add / SkipListRep::Insert说明写入路径在跳表插入上耗费过多 CPU。常见原因是指针追逐加上随机分配可以考虑并发 memtable、批量写入来摊薄开销。LRUCacheShard::Lookup / LRUCacheShard::Insertblock cache 锁和 hash 查找成了热点。数据量大、分片不够时很容易看到它。适当增加 block cache 分片数量会有帮助。MurmurHash / HashIndexReaderhash 索引相关的查找在热点里占大头说明随机 key 查询占比高。malloc / jemalloc 相关分配压力大。这类热点往往伴随内存碎片的隐性问题单靠火焰图还不够得配合后面说的 systemtap 看分配大小分布。perf 还有一个不太被注意的功能是锁分析。遇到写入路径卡顿、多线程吞吐上不去我会用perf lock record -p pid -- sleep 30 perf lock report它会列出哪些锁争抢最激烈、平均等待时间多少。RocksDB 的全局 DB mutex、block cache 的 shard lock、compaction 相关的锁都可能是瓶颈。有一回我排查一个多 CF 场景下的写入抖动perf lock report 里 DBImpl::mutex 的 wait 时间非常扎眼再配合 perf_context 里的 write_delay_time 一起看确认是 memtable 切换时全局锁导致的停顿。后来把 memtable 调大、减少切换频率问题就缓解了。这就是“内功”和“颜值”配合着用的典型场景。3. “颜值”选手二systemtap 做动态插桩3.1 常用脚本片段systemtap 的特点是“无所不插”。它基于 kprobe/uprobe 机制可以动态指定进程里的某个函数在函数进入和返回时执行一段脚本逻辑。RocksDB 这种用户态程序可以拿它来统计 jemalloc 的内存分配、统计某个成员函数的调用延迟分布、甚至追踪某个 key 的走向。先装环境。以常见发行版为例# RHEL/CentOS 系 yum install systemtap kernel-devel kernel-debuginfo kernel-debuginfo-common # Ubuntu/Debian 系 apt install systemtap linux-image-$(uname -r)-dbgsym装完先跑一个 hello world 验证stap -e probe begin { println(hello); exit() }看用户态函数调用最简单的方式probe process(/opt/app/rocksdb_server).function(rocksdb::DBImpl::Write) { printf(Write called on cpu %d pid %d\n, cpu(), pid()) }注意这里的函数名必须和你编译出的符号完全一致可以用 nm 或 cpuid 确认。如果是 C 类方法符号名会被修饰用 nm 拿到完整名字再写进 probe 最省事。带返回值的探针也能做耗时分布统计global start_us probe process(/opt/app/rocksdb_server).function(rocksdb::DBImpl::FlushMemTable) { start_us[tid()] gettimeofday_us() } probe process(/opt/app/rocksdb_server).function(rocksdb::DBImpl::FlushMemTable).return { t gettimeofday_us() - start_us[tid()] if (t 1000) { printf(FlushMemTable slow: %d us\n, t) } }如果你用的是 jemalloc 作为分配器追踪分配行为会非常有用global alloc_count, alloc_bytes probe process(/opt/app/rocksdb_server).function(je_malloc) { alloc_count alloc_bytes $size } probe end { printf(allocs%d bytes%d avg%d\n, alloc_count, alloc_bytes, alloc_bytes/alloc_count) }这个脚本跑 30 秒就能看到进程内到底以什么尺度在分配内存。如果平均每次分配只有几十字节但次数爆炸说明内存碎片风险和分配器争抢都会很严重这时候可以考虑开 jemalloc 的 thread cache、调大 tcache 上限或者直接换更友好的内存管理模式。3.2 systemtap 的“代价”与注意事项systemtap 比 perf 和 ftrace 都“重”这是我最想强调的一点。每个用户态探针在函数入口和出口分别触发等于给热函数套了两个钩子命中频率高的时候性能损失可能到两位数百分比。所以我的原则是只在问题已经缩小到某个嫌疑函数之后才上 systemtap。一次性脚本跑几十秒就够别当监控常驻。优先用函数计数器做粗筛确认必要后再开耗时探针。另外systemtap 对符号和参数的支持依赖调试信息。如果应用程序是 release 构建且没有 debuginfoprobe 函数名可能绑不上参数引用 $size 这种也就编译不过。解决办法是装对应包的 debuginfo或者干脆给自己留一个带-g -O0的 profiling 版本专用二进制分析时用它替换发布版本。我自己一般在 CI 里额外打一个 profiling 包平时不跑需要做深层次分析时临时部署到压测环境。还有一个常见坑是内核版本和 systemtap 匹配问题。升级内核之后kernel-devel、kernel-debuginfo 必须同步升级否则 stap 编译内核模块时会报错。遇到“Systemtap doesnt support this kernel”这类信息第一件事就是检查这几个包版本是否一致。4. “颜值”选手三ftrace 下探到内核与块设备4.1 用 trace_marker 把业务事件标到内核时间轴上如果问题已经怀疑到 IO 层比如磁盘延迟、fsync 太慢、页缓存抖动ftrace 是最趁手的工具。它直接在内核里记录函数调用和 tracepoint 事件能让我们看到 RocksDB 的某个操作在内核里经历了什么。现在 tracefs 一般挂载在这里mount -t tracefs nodev /sys/kernel/tracing如果没有看下老的 debugfs 路径/sys/kernel/debug/tracing。核心概念就几个文件current_tracer 选跟踪模式tracing_on 开关trace 输出结果。我最常用的两个模式是 function_graph 和 tracepoint 事件。function_graph 可以只跟踪某个内核函数echo function_graph /sys/kernel/tracing/current_tracer echo ext4_file_write_iter /sys/kernel/tracing/set_graph_function echo 1 /sys/kernel/tracing/tracing_on # 跑你的压测 echo 0 /sys/kernel/tracing/tracing_on cat /sys/kernel/tracing/trace但 function_graph 追踪 all function 的开销大输出也噪声多我更推荐直接过滤到目标函数或者干脆用 trace-cmd 包装trace-cmd record -p function_graph -l ext4_* -l xfs_* -- sleep 10 trace-cmd report真正让 ftrace 和 RocksDB 业务场景结合起来的是 trace_marker。它允许你从用户态往内核 trace 缓冲区里写一行自定义标记这样你在看内核事件流时能知道什么地方对应业务里的哪一步。echo flush_begin /sys/kernel/tracing/trace_marker在 C 代码里做一个全局 fd避免每次 open开销很小int trace_fd open(/sys/kernel/tracing/trace_marker, O_WRONLY); void trace_mark(const char* msg) { write(trace_fd, msg, strlen(msg)); }4.2 块设备层的读写延迟拆解磁盘延迟高不高、是不是在排队光看应用侧平均延迟是不够的。把块设备层的 tracepoint 打开能看到每一个 IO 请求的扇区、大小、方向以及 issue 和 complete 的时间。echo 1 /sys/kernel/tracing/events/block/block_rq_issue/enable echo 1 /sys/kernel/tracing/events/block/block_rq_complete/enable echo 1 /sys/kernel/tracing/tracing_on如果只想看某一个进程的 IO用 filter 过滤echo pid12345 /sys/kernel/tracing/events/block/block_rq_issue/filter echo pid12345 /sys/kernel/tracing/events/block/block_rq_complete/filterblock_rq_issue 到 block_rq_complete 之间的时间差就是 IO 在设备层面的实际服务时间包括排队、寻址、传输。如果你发现服务时间里方差很大说明设备或调度出了问题如果 issue 到 complete 很快但业务延迟还是高那问题多半在更上层比如页缓存、锁或文件系统。rq 里的 rwbs 字段格式也要认一下R 是读、W 是写、D 是 discard、S 是同步、A 是 readahead看起来像“WS”就是同步写。有一次做写入性能压测业务端 fsync 平均耗时飙升到 200ms。用 ftrace 打开 block_rq_issue/complete 后发现 fsync 触发的 block 请求在设备层的服务时间其实只有十几毫秒但两个请求之间隔了很久。这意味着瓶颈不在磁盘硬件而在文件系统日志提交或者调度策略上。后来顺着 sys_enter_fsync tracepoint 追下去确认是日志提交频繁且互斥通过批量提交优化解决。这种跨层定位能力是 perf 和 perf_context 都给不了的。需要提醒的是ftrace 的 function tracer 开销在 5% 到 15% 之间tracepoint 相对轻一些但都不建议长期开着。用 trace-cmd 的好处是自动管理 tracing_on 和缓冲区大小采集完还能直接 report我强烈建议装上它。5. 组合拳一条完整的性能分析思路5.1 四类工具怎么选面对不确定的性能问题最忌讳拿着一个工具从头试到尾。我自己的经验是先按一个“从内到外、从粗到细”的顺序走每步都能排除一批可能性。工具观察层面典型定位开销perf_contextRocksDB 内部内部计时、计数、cache 命中、stall 原因低到中kEnableTime 较高perfCPU / 硬件计数器 / 锁CPU 热点、cache miss、锁等待采样开销低ftrace内核、块设备、文件系统IO 路径、内核函数耗时、设备延迟函数级中tracepoint 低systemtap用户态 / 内核动态插桩分配器行为、指定函数耗时、调用频率高只适合短时定点排查选择逻辑其实很简单先开 perf_context判断问题在 CPU 计算、block IO、锁等待还是 write stall。如果指向 CPU 计算上 perf 采火焰图。如果指向 IO上 ftrace 看内核和块设备路径。如果连 perf 都查不出头绪比如怀疑内存分配异常、某个自定义函数非常慢才用 systemtap 做定点插桩。5.2 一个典型的分析流程拿一次典型的读延迟高排查举例。接到反馈说某存储服务读延迟从 1ms 涨到 8ms我没有先看火焰图而是先抓 perf_context。结果 block_cache_miss_count 和 block_read_count 明显升高说明问题集中在数据读取路径。接着看 bloom_filter_useful发现数值很低判断可能是布隆过滤器配置失效。然后上 ftrace 打开块设备 tracepoint发现 miss 的 block IO 服务时间确实有几十毫秒的长尾说明底层设备在重负载下延迟不稳定。最后用 perf 采样发现 CPU 热点集中在布隆过滤判断和 block 读取相关函数。整个流程走完问题定位成“布隆未覆盖 设备长尾”的组合而不是盲目加缓存或换磁盘。如果是写入卡顿流程也类似先 perf_context 看 write_delay_time 是否异常如果是 write stall再结合统计信息和 compaction 现状判断是 memtable 切换太频繁还是 L0 文件堆积如果 WAL 延时高就上 ftrace 看 fsync 路径如果怀疑锁问题用 perf lock report 验证。这套流程的核心思想是先花五分钟用最便宜的 perf_context 缩小范围再选择最合适的“颜值”工具深入验证细节。直接拿大炮打蚊子大概率会把问题搅浑。6. 常见问题与避坑记录6.1 perf_context 的坑坑一编译时被 NPERF_CONTEXT 关掉了。RocksDB 提供宏开关来禁用整个 perf_context 的插桩代码如果二进制在编译时带了-DNPERF_CONTEXT你调 SetPerfLevel 和 get_perf_context 也不会得到任何数据。排查办法在代码里加一段条件编译或者直接看编译命令里有没有这个宏。无良提示很多发布版 RocksDB 为了省那点指令默认不开所以拿到的二进制不一定支持。坑二线程局部导致统计不全。前面说过了背景线程需要单独设置。你以为开启了 perf_context其实只统计了主线程。如果是多线程压测最好每个 worker 线程都设置并独立输出最后汇总。坑三kEnableTime 会影响压测结果本身。计时器本身有开销尤其是 Get 这种高频短操作计时开销占的比例会放大。所以压测对比时要么都用同一档位要么只在采集窗口开启。我一般基准测试全关采集性能画像时才开。坑四GetProperty 只返回累计快照。如果用rocksdb.perf_context拿聚合值注意它只是累计器不会自动清零。两次采样要做差值否则看到的是从打开以来的总量没法反映某个时间窗的变化。6.2 排查工具常见报错与处理方法实际跑工具时有一堆老掉牙的报错这里整理成速查表报错现象常见原因处理办法perf: “You may not have permission to collect stats”perf_event_paranoid 限制临时调低sysctl kernel.perf_event_paranoid1或使用 root 运行perf 采集到的调用栈残缺帧指针被优化掉用 --call-graph dwarf重新编译加 -fno-omit-frame-pointerperf: “no symbols” 或地址无法解析缺符号表装 debuginfo 包或对发布二进制做 addr2linesystemtap: “Missing separate debuginfo”应用程序或内核缺少调试符号安装对应的 -dbg / -debuginfo 包systemtap: “Systemtap doesnt support this kernel”kernel-devel / debuginfo 版本不匹配同步升级内核开发包和调试包ftrace: “trace_marker: No such file or directory”tracefs 未挂载或权限不足确认 mount 路径使用 rootftrace: 跟踪输出太多刷屏function tracer 全量开启用 set_ftrace_filter 或 trace-cmd -l 限定函数ftrace: 采样期间丢事件ring buffer 太小调大 buffer_size_kb先行减少过滤面有一个很容易被忽视的通用问题在容器里跑这些工具权限和挂载路径会被 seccomp 或 namespace 限制。perf_event_open 这类系统调用可能在容器里被拦截tracefs 也可能没在容器里挂载。遇到“明明装了工具却各种 Permission denied”先检查是否容器环境必要时在宿主机上采集或者给容器增加对应 capabilities。另外提一句采样工具叠加用的时候开销是累加的。我见过有人同时开着 perf record、systemtap 脚本和 ftrace结果业务本身被拖慢了 30%得出来的火焰图全是工具自身上下文切换的噪声。正确做法是串行使用每步基于上一步的结论缩小范围而不是一次性全开。结尾这几样工具用熟了之后我对“性能分析”这件事最大的体会是不要急着炫技。一次线上 RocksDB 延迟抖动的排查可能最后用到的方法非常简单——先让 perf_context 开口说话再让 ftrace 带你看一眼磁盘最后用 perf 确认一下 CPU 花在哪。工具再多也只是帮你把“你猜”变成“你确定”的手段。我个人现在的习惯是在压测环境里常驻一个带-g -fno-omit-frame-pointer的 profiling 包线上绝不碰这些重工具每次排查都从 perf_context 的 kEnableCount 开始确定方向后再按需升级到 kEnableTime 和其他系统工具。这套流程不一定是最快的但每次都能把问题画在合理的圈子里不会跑偏。