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,1
和lcnt: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/3
或lcnt:apply/1
哪个做lcnt:clear/0
的函数之前和lcnt:collect/0
它的调用之后。此方法只能用于微基准测试,因为它在函数调用期间设置copy_save
为true
,如果尝试在加载情况下尝试,可能会导致模拟器运行内存不足。
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