brpc/docs/cn/contention_profiler.md
2022-12-14 20:13:26 +08:00

3.6 KiB
Raw Permalink Blame History

brpc可以分析花在等待锁上的时间及发生等待的函数。

开启方法

按需开启。无需配置不依赖tcmalloc不需要链接frame pointer或libunwind。如果只是brpc client或没有使用brpc这里

图示

当很多线程争抢同一把锁时,一些线程无法立刻获得锁,而必须睡眠直到某个线程退出临界区。这个争抢过程我们称之为contention。在多核机器上当多个线程需要操作同一个资源却被一把锁挡住时便无法充分发挥多个核心的并发能力。现代OS通过提供比锁更底层的同步原语使得无竞争锁完全不需要系统调用只是一两条wait-free耗时10-20ns的原子操作非常快。而锁一旦发生竞争一些线程就要陷入睡眠再次醒来触发了OS的调度代码代价至少为3-5us。所以让锁尽量无竞争让所有线程“一起飞”是需要高性能的server的永恒话题。

r31906后brpc支持contention profiler可以分析在等待锁上花费了多少时间。等待过程中线程是睡着的不会占用CPU所以contention profiler中的时间并不是cpu时间也不会出现在cpu profiler中。cpu profiler可以抓到特别频繁的锁以至于花费了很多cpu但耗时真正巨大的临界区往往不是那么频繁而无法被cpu profiler发现。**contention profiler和cpu profiler好似互补关系前者分析等待时间被动后者分析忙碌时间。**还有一类由用户基于condition或sleep发起的主动等待时间无需分析。

目前contention profiler支持pthread_mutex_t非递归和bthread_mutex_t开启后每秒最多采集1000个竞争锁这个数字由参数-bvar_collector_expected_per_second控制同时影响rpc_dump

Name Value Description Defined At
bvar_collector_expected_per_second 1000 Expected number of samples to be collected per second bvar/collector.cpp

如果一秒内竞争锁的次数超过了1000那么每把锁会有1000/N的概率被采集。在我们的各类测试场景中qps在10万-60万不等没有观察到被采集程序的性能有明显变化。

我们通过实际例子来看下如何使用contention profiler点击“contention”按钮more左侧后就会开启默认10秒的分析过程。下图是libraft中的一个示例程序的锁状况这个程序是3个节点复制组的leaderqps在10-12万左右。左上角的Total seconds: 2.449是采集时间内10秒在锁上花费的所有等待时间。注意是“等待”无竞争的锁不会被采集也不会出现在下图中。顺着箭头往下走能看到每份时间来自哪些函数。

img

上图有点大让我们放大一个局部看看。下图红框中的0.768是这个局部中最大的数字它代表raft::LogManager::get_entry在等待涉及到bvar::detail::UniqueLockBase的函数上共等待了0.768秒10秒内。我们如果觉得这个时间不符合预期就可以去排查代码。

img

点击上方的count选择框可以查看锁的竞争次数。选择后左上角变为了Total samples: 439026,代表采集时间内总共的锁竞争次数(估算)。图中箭头上的数字也相应地变为了次数,而不是时间。对比同一份结果的时间和次数,可以更深入地理解竞争状况。

img