5. lcnt - The Lock Profiler

5 lcnt - 锁定分析器

在Erlang运行时系统内部,锁被用来保护资源不被多线程以致命的方式更新。锁是确保运行时系统正常工作所必需的,但它也引入了一些限制。锁定争用和锁定开销。

对于锁争用,我们指的是一个线程锁定资源,另一个线程或线程尝试同时获取相同的资源。该锁将拒绝其他线程访问资源,并且该线程将被阻止继续执行。第二个线程必须等到第一个线程完成对资源的访问并解除锁定。该lcnt工具测量这些锁冲突。

锁具有执行时间和内存空间的固有成本。需要时间来初始化,销毁,获取或释放锁。为了减少锁争用,有时需要使用更精细的锁定策略。这通常也会增加锁定开销,因此在锁争用和开销之间进行权衡。通常,锁争用会随着并发运行的线程数的增加而增加。该lcnt工具不会测量锁定开销。

5.1启用锁定计数

为了调查仿真器中的锁,我们使用一个称为lcnt(锁定计数的简写)的内部工具。虚拟机需要在启用该选项的情况下编译。要编译锁定计数虚拟机以及常规VM,请使用:

cd $ERL_TOP ./configure --enable-lock-counter

像这样启动锁计数VM:

$ERL_TOP/bin/erl -emu_type lcnt

要验证是否启用了锁定计数,请检查[lock-counting]虚拟机启动时显示在状态文本中的内容。

Erlang/OTP 20 [erts-9.0] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:10] [hipe] [kernel-poll:false] [lock-counting]

5.2开始

一旦启用了锁定计数功能,lcnt可以使用该模块。该模块旨在从当前正在运行的节点外壳中使用。要访问远程节点,请使用lcnt:clear(Node)lcnt:collect(Node)

所有的锁都会不断进行监控并更新统计数据。用于lcnt:clear/0在运行任何特定测试之前初始清除所有计数器。该命令还会在内部重置持续时间计时器。

要检索锁定统计信息,请使用lcnt:collect/0,1。收集操作将启动lcnt服务器(如果尚未启动)。所有收集的数据将被构建成Erlang术语并上传到服务器,同时还会上传持续时间。该持续时间之间的时间lcnt:clear/0,1lcnt:collect/0,1

一旦数据被收集到服务器,它可以被过滤,分类和打印许多不同的方式。

请参阅reference manual每个功能的说明。

5.3使用例

从Erlang shell:

Erlang R13B03 (erts-5.7.4) [source] [smp:8:8] [rq:8] [async-threads:0] [hipe] [kernel-poll:false] [lock-counting] 1> lcnt:rt_opt{copy_save, true}). false 2> lcnt:clear(), big:bang(1000), lcnt:collect(). ok 3> lcnt:conflicts(). lock id #tries #collisions collisions [%] time [us] duration [%] ----- --- ------- ------------ --------------- ---------- ------------- alcu_allocator 50 4113692 158921 3.8632 215464 4.4962 pix_lock 256 4007140 4882 0.1218 12221 0.2550 run_queue 8 2287246 6949 0.3038 9825 0.2050 proc_main 1029 3115778 25755 0.8266 1199 0.0250 proc_msgq 1029 2467022 1910 0.0774 1048 0.0219 proc_status 1029 5708439 2435 0.0427 706 0.0147 message_pre_alloc_lock 8 2008569 134 0.0067 90 0.0019 timeofday 1 54065 8 0.0148 22 0.0005 gc_info 1 7071 7 0.0990 5 0.0001 ok

对简档的特定功能的另一种方法是使用lcnt:apply/3lcnt:apply/1哪个做lcnt:clear/0的函数之前和lcnt:collect/0它的调用之后。此方法只能用于微基准测试,因为它在函数调用期间设置copy_savetrue,如果尝试在加载情况下尝试,可能会导致模拟器运行内存不足。

Erlang R13B03 (erts-5.7.4) [source] [smp:8:8] [rq:8] [async-threads:0] [hipe] [kernel-poll:false] [lock-counting] 1> lcnt:apply(fun() -> big:bang(1000) end). 4384.338 2> lcnt:conflicts(). lock id #tries #collisions collisions [%] time [us] duration [%] ----- --- ------- ------------ --------------- ---------- ------------- alcu_allocator 50 4117913 183091 4.4462 234232 5.1490 run_queue 8 2050398 3801 0.1854 6700 0.1473 pix_lock 256 4007080 4943 0.1234 2847 0.0626 proc_main 1028 3000178 28247 0.9415 1022 0.0225 proc_msgq 1028 2293677 1352 0.0589 545 0.0120 proc_status 1028 5258029 1744 0.0332 442 0.0097 message_pre_alloc_lock 8 2009322 147 0.0073 82 0.0018 timeofday 1 48616 9 0.0185 13 0.0003 gc_info 1 7455 12 0.1610 9 0.0002 ok

进程锁像其他所有锁一样在其类之后进行排序。将特定进程和端口视为类是很方便的。我们可以通过交换类和类标识符来做到这一点lcnt:swap_pid_keys/0

3> lcnt:swap_pid_keys(). ok 4> lcnt:conflicts([{print, [name, tries, ratio, time]}]). lock #tries collisions [%] time [us] ----- ------- --------------- ---------- alcu_allocator 4117913 4.4462 234232 run_queue 2050398 0.1854 6700 pix_lock 4007080 0.1234 2847 message_pre_alloc_lock 2009322 0.0073 82 <nonode@nohost.660.0> 13493 1.4452 41 <nonode@nohost.724.0> 13504 1.1404 36 <nonode@nohost.803.0> 13181 1.6235 35 <nonode@nohost.791.0> 13534 0.8202 22 <nonode@nohost.37.0> 8744 5.8326 22 <nonode@nohost.876.0> 13335 1.1174 19 <nonode@nohost.637.0> 13452 1.3678 19 <nonode@nohost.799.0> 13497 1.8745 18 <nonode@nohost.469.0> 11009 2.5343 18 <nonode@nohost.862.0> 13131 1.2566 16 <nonode@nohost.642.0> 13216 1.7327 15 <nonode@nohost.582.0> 13156 1.1098 15 <nonode@nohost.622.0> 13420 0.7303 14 <nonode@nohost.596.0> 13141 1.6437 14 <nonode@nohost.592.0> 13346 1.2064 13 <nonode@nohost.526.0> 13076 1.1701 13 ok

5.4 Mnesia交易基准的例子

从Erlang shell:

Erlang R13B03 (erts-5.7.4) [source] [smp:8:8] [rq:8] [async-threads:0] [hipe] [kernel-poll:false] [lock-counting] Eshell V5.7.4 (abort with ^G) 1> Conf=[{db_nodes, [node()]}, {driver_nodes, [node()]}, {replica_nodes, [node()]}, {n_drivers_per_node, 10}, {n_branches, 1000}, {n_accounts_per_branch, 10}, {replica_type, ram_copies}, {stop_after, 60000}, {reuse_history_id, true}]. [{db_nodes,[nonode@nohost]}, {driver_nodes,[nonode@nohost]}, {replica_nodes,[nonode@nohost]}, {n_drivers_per_node,10}, {n_branches,1000}, {n_accounts_per_branch,10}, {replica_type,ram_copies}, {stop_after,60000}, {reuse_history_id,true}] 2> mnesia_tpcb:init([{use_running_mnesia, false}|Conf]). ignore

基准的初始配置已完成。现在是介绍实际基准和Mnesia的时候了

3> lcnt:apply(fun() -> {ok,{time, Tps,_,_,_,_}} = mnesia_tpcb:run([{use_running_mnesia, true}|Conf]), Tps/60 end). 12037.483333333334 ok 4> lcnt:swap_pid_keys(). ok

id报头表示当选项的唯一标识符的一类下的数量{combine, true}被使用(这是在默认情况下)。否则它将显示特定的标识符。该db_tab清单显示了722287个独特的锁,它是一个用于创建的每个ETS-表的Mnesia创建一个为每个事务。

5> lcnt:conflicts(). lock id #tries #collisions collisions [%] time [us] duration [%] ----- --- ------- ------------ --------------- ---------- ------------- alcu_allocator 50 56355118 732662 1.3001 2934747 4.8862 db_tab 722287 94513441 63203 0.0669 1958797 3.2613 timeofday 1 2701048 175854 6.5106 1746079 2.9071 pix_lock 256 24306168 163214 0.6715 918309 1.5289 run_queue 8 11813811 152637 1.2920 357040 0.5945 message_pre_alloc_lock 8 17671449 57203 0.3237 263043 0.4380 mnesia_locker 4 17477633 1618548 9.2607 97092 0.1617 mnesia_tm 4 9891408 463788 4.6888 86353 0.1438 gc_info 1 823460 628 0.0763 24826 0.0413 meta_main_tab_slot 16 41393400 7193 0.0174 11393 0.0190 <nonode@nohost.1108.0> 4 4331412 333 0.0077 7148 0.0119 timer_wheel 1 203185 30 0.0148 3108 0.0052 <nonode@nohost.1110.0> 4 4291098 210 0.0049 885 0.0015 <nonode@nohost.1114.0> 4 4294702 288 0.0067 442 0.0007 <nonode@nohost.1113.0> 4 4346066 235 0.0054 390 0.0006 <nonode@nohost.1106.0> 4 4348159 287 0.0066 379 0.0006 <nonode@nohost.1111.0> 4 4279309 290 0.0068 325 0.0005 <nonode@nohost.1107.0> 4 4292190 302 0.0070 315 0.0005 <nonode@nohost.1112.0> 4 4208858 265 0.0063 276 0.0005 <nonode@nohost.1109.0> 4 4377502 267 0.0061 276 0.0005 ok

清单显示mnesia_locker,一个进程具有高度竞争的锁。

6> lcnt:inspect(mnesia_locker). lock id #tries #collisions collisions [%] time [us] duration [%] ----- --- ------- ------------ --------------- ---------- ------------- mnesia_locker proc_msgq 5449930 59374 1.0894 69781 0.1162 mnesia_locker proc_main 4462782 1487374 33.3284 14398 0.0240 mnesia_locker proc_status 7564921 71800 0.9491 12913 0.0215 mnesia_locker proc_link 0 0 0.0000 0 0.0000 ok

没有类组合器的列表。

7> lcnt:conflicts([{combine, false}, {print, [name, id, tries, ratio, time]}]). lock id #tries collisions [%] time [us] ----- --- ------- --------------- ---------- db_tab mnesia_transient_decision 722250 3.9463 1856852 timeofday undefined 2701048 6.5106 1746079 alcu_allocator ets_alloc 7490696 2.2737 692655 alcu_allocator ets_alloc 7081771 2.3294 664522 alcu_allocator ets_alloc 7047750 2.2520 658495 alcu_allocator ets_alloc 5883537 2.3177 610869 pix_lock 58 11011355 1.1924 564808 pix_lock 60 4426484 0.7120 262490 alcu_allocator ets_alloc 1897004 2.4248 219543 message_pre_alloc_lock undefined 4211267 0.3242 128299 run_queue 3 2801555 1.3003 116792 run_queue 2 2799988 1.2700 100091 run_queue 1 2966183 1.2712 78834 mnesia_locker proc_msgq 5449930 1.0894 69781 message_pre_alloc_lock undefined 3495672 0.3262 65773 message_pre_alloc_lock undefined 4189752 0.3174 58607 mnesia_tm proc_msgq 2094144 1.7184 56361 run_queue 4 2343585 1.3115 44300 db_tab branch 1446529 0.5229 38244 gc_info undefined 823460 0.0763 24826 ok

在这种情况下,保护ets-table的锁mnesia_transient_decision大部分时间都在等待。在运行60秒的测试中,这是1.8秒。时间也分布在八个不同的调度程序线程中。

8> lcnt:inspect(db_tab, [{print, [name, id, tries, colls, ratio, duration]}]). lock id #tries #collisions collisions [%] duration [%] ----- --- ------- ------------ --------------- ------------- db_tab mnesia_transient_decision 722250 28502 3.9463 3.0916 db_tab branch 1446529 7564 0.5229 0.0637 db_tab account 1464500 8203 0.5601 0.0357 db_tab teller 1464529 8110 0.5538 0.0291 db_tab history 722250 3767 0.5216 0.0232 db_tab mnesia_stats 750332 7057 0.9405 0.0180 db_tab mnesia_trans_store 61 0 0.0000 0.0000 db_tab mnesia_trans_store 61 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 db_tab mnesia_trans_store 53 0 0.0000 0.0000 ok

5.5解码输出

通常情况下,高time价值是不好的,这往往是要寻找的东西。但是,还应该寻找高锁定采集频率(#条),因为锁会产生开销,并且如果即使在特定测试中未显示冲突,它们也会发生冲突,因此高频率可能会出现问题。

5.6 另请参阅

LCNT Reference Manual