查看源代码 lcnt - 锁分析器
在 Erlang 运行时系统中,内部使用锁来保护资源,防止多个线程以致命的方式更新资源。锁对于确保运行时系统正常工作是必要的,但也引入了限制,即锁争用和锁开销。
锁争用是指当一个线程锁定一个资源时,另一个(或多个)线程同时尝试获取同一资源。锁会拒绝其他线程访问该资源,并且该线程将被阻止继续执行。第二个线程必须等到第一个线程完成对资源的访问并解锁后才能继续。 lcnt
工具测量这些锁冲突。
锁在执行时间和内存空间方面具有固有的成本。初始化、销毁、获取或释放锁都需要时间。为了减少锁争用,有时需要使用更细粒度的锁定策略。但这通常也会增加锁定开销。因此,锁争用和开销之间存在权衡。一般来说,锁争用会随着并发运行的线程数量增加而增加。
lcnt
工具不测量锁定开销。
启用锁计数
为了调查仿真器中的锁,我们使用一个名为 lcnt
(锁计数简称)的内部工具。虚拟机需要启用此选项进行编译。要编译一个启用锁计数的虚拟机以及一个普通的虚拟机,请使用
cd $ERL_TOP
./configure --enable-lock-counter
make
像这样启动启用锁计数的虚拟机
$ERL_TOP/bin/erl -emu_type lcnt
要验证是否启用了锁计数,请检查虚拟机启动时状态文本中是否出现 [lock-counting]
。
Erlang/OTP 27 [erts-15.0] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [jit] [lock-counting]
入门
一旦您拥有启用了锁计数的虚拟机,就可以使用模块 lcnt
。该模块旨在从当前正在运行的节点的 shell 中使用。要访问远程节点,请使用 lcnt:clear(Node)
和 lcnt:collect(Node)
。
所有锁都会被持续监控,其统计信息也会更新。在运行任何特定测试之前,请使用 lcnt:clear/0
初始化清除所有计数器。此命令还会重置内部持续时间计时器。
要检索锁统计信息,请使用 lcnt:collect/0,1
。如果 lcnt
服务器尚未启动,则 collect 操作将启动该服务器。所有收集的数据将存储在 Erlang 术语中,并与持续时间一起上传到服务器。持续时间是 lcnt:clear/0,1
和 lcnt:collect/0,1
之间的时间。
一旦数据被收集到服务器,就可以以多种方式对其进行过滤、排序和打印。
用法示例
以下是运行 Big Bang 基准测试 的示例
Erlang/OTP 27 [erts-15.0] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [jit] [lock-counting]
Eshell V15.0 (press Ctrl+G to abort, type help(). for help)
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 [%]
----- --- ------- ------------ --------------- ---------- -------------
run_queue 10 590799 8875 1.5022 37906 2.2167
proc_msgq 1048 2515180 4667 0.1856 20962 1.2258
proc_main 1048 2195317 23775 1.0830 1664 0.0973
ok
另一种分析特定函数的方法是使用 lcnt:apply/3
或 lcnt:apply/1
,它们会在调用函数之前调用 lcnt:clear/0
,并在调用函数之后调用 lcnt:collect/0
。此方法仅应在微基准测试中使用,因为它会将 copy_save
设置为 true
,持续时间为函数调用期间,如果尝试在负载下执行,可能会导致仿真器耗尽内存。
1> lcnt:apply(fun() -> big:bang(1000) end).
1845411
2> lcnt:conflicts().
lock id #tries #collisions collisions [%] time [us] duration [%]
----- --- ------- ------------ --------------- ---------- -------------
run_queue 10 582789 9237 1.5850 41929 2.2633
proc_msgq 1047 2494483 4731 0.1897 11173 0.6031
proc_main 1047 2192806 23283 1.0618 1500 0.0810
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]
----- ------- --------------- ----------
run_queue 582789 1.5850 41929
<[email protected]> 5692 0.5095 484
<[email protected]> 4989 0.4410 393
<[email protected]> 6319 2.1839 284
<[email protected]> 6077 1.9747 198
<[email protected]> 5071 1.3015 192
<[email protected]> 5846 1.7106 186
<[email protected]> 6305 1.2054 179
<[email protected]> 5820 1.2715 176
<[email protected]> 6329 1.4852 168
<[email protected]> 5172 0.8701 167
<[email protected]> 5306 0.4146 166
<[email protected]> 5838 1.9870 160
<[email protected]> 6346 1.5443 143
<[email protected]> 5542 0.4331 141
<[email protected]> 5260 0.2662 137
<[email protected]> 5610 0.9447 127
<[email protected]> 5354 0.5230 118
<[email protected]> 5845 0.9239 115
<[email protected]> 5140 0.7782 108
ok
Mnesia 事务基准测试示例
从 Erlang shell 中
Erlang/OTP 27 [erts-15.0] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [jit] [lock-counting]
Eshell V15.0 (press Ctrl+G to abort, type help(). for help)
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}], ok.
ok
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).
.
.
.
50204.666666666664
基准测试运行 60 秒(然后进行验证和分析),然后返回每秒的事务数。
4> lcnt:swap_pid_keys().
ok
5> lcnt:conflicts().
lock id #tries #collisions collisions [%] time [us] duration [%]
----- --- ------- ------------ --------------- ---------- -------------
run_queue 10 89329288 3227515 3.6131 5018119 8.3606
mnesia_locker 5 64793236 8231226 12.7038 98654 0.1644
db_tab 3012324 416847817 140631 0.0337 75308 0.1255
<[email protected]> 5 14499900 36934 0.2547 4878 0.0081
<[email protected]> 5 14157504 35797 0.2528 4727 0.0079
<[email protected]> 5 14194934 34510 0.2431 4403 0.0073
<[email protected]> 5 14149447 35326 0.2497 4150 0.0069
<[email protected]> 5 14316525 35675 0.2492 4116 0.0069
<[email protected]> 5 14241146 35358 0.2483 4101 0.0068
<[email protected]> 5 14224491 35182 0.2473 4094 0.0068
<[email protected]> 5 14190075 35328 0.2490 4075 0.0068
<[email protected]> 5 14308906 35031 0.2448 3896 0.0065
<[email protected]> 5 14457330 36182 0.2503 3856 0.0064
mnesia_tm 5 28149333 179294 0.6369 1057 0.0018
pix_lock 1024 132 1 0.7576 549 0.0009
<[email protected]> 5 17 2 11.7647 87 0.0001
<[email protected]> 5 1335 6 0.4494 1 0.0000
ok
当使用选项 {combine, true}
(默认启用)时,id
标头表示类下唯一标识符的数量。否则,它将显示特定的标识符。 db_tab
列表显示了 3,012,324 个唯一锁,即为每个创建的 ETS 表提供一个锁。 Mnesia 为每个事务创建一个 ETS 表。
该列表还显示 mnesia_locker
进程具有高度争用的锁。 使用 lcnt:inspect/1
可以显示有关该进程的更多信息
6> lcnt:inspect(mnesia_locker).
lock id #tries #collisions collisions [%] time [us] duration [%] histogram [log2(us)]
----- --- ------- ------------ --------------- ---------- ------------- ---------------------
mnesia_locker proc_main 19853372 7591248 38.2366 80550 0.1342 |. ...X........ |
mnesia_locker proc_msgq 30917225 639627 2.0688 17126 0.0285 |. .X......... |
mnesia_locker proc_status 9348426 351 0.0038 978 0.0016 | .xxX. . |
mnesia_locker proc_btm 0 0 0.0000 0 0.0000 | |
mnesia_locker proc_trace 4674213 0 0.0000 0 0.0000 | |
ok
列出没有类组合器的冲突
7> lcnt:conflicts([{combine, false}, {print, [name, id, tries, ratio, time]}]).
lock id #tries collisions [%] time [us]
----- --- ------- --------------- ----------
run_queue 2 31075249 3.5676 1728233
run_queue 1 29738521 3.6348 1683219
run_queue 3 27912150 3.6429 1573593
mnesia_locker proc_main 19853372 38.2366 80550
db_tab mnesia_transient_decision 3012281 2.5675 55104
run_queue 4 512077 3.7041 29486
mnesia_locker proc_msgq 30917225 2.0688 17126
db_tab account 6044562 0.3599 7909
db_tab branch 6026659 0.3132 5654
db_tab teller 6044659 0.2684 4727
<[email protected]> proc_main 3207155 0.7178 3726
<[email protected]> proc_main 3138532 0.7485 3593
<[email protected]> proc_main 3133180 0.7156 3547
<[email protected]> proc_main 3165128 0.7609 3517
<[email protected]> proc_main 3128838 0.7525 3477
<[email protected]> proc_main 3137627 0.7559 3433
<[email protected]> proc_main 3144886 0.7509 3425
<[email protected]> proc_main 3149315 0.7487 3372
<[email protected]> proc_main 3196546 0.7591 3310
<[email protected]> proc_main 3164333 0.7483 3309
ok
在这种情况下,调度程序的运行队列锁占用了等待锁的时间。ETS 表最受争用的锁是 mnesia_transient_decision
ETS 表的锁。
以下是如何显示 ETS 表的信息。
8> lcnt:inspect(db_tab, [{print, [name, id, tries, colls, ratio, duration]}]).
lock id #tries #collisions collisions [%] duration [%]
----- --- ------- ------------ --------------- -------------
db_tab mnesia_transient_decision 3012281 77341 2.5675 0.0918
db_tab account 6044562 21753 0.3599 0.0132
db_tab branch 6026659 18873 0.3132 0.0094
db_tab teller 6044659 16221 0.2684 0.0079
db_tab history 3012281 4005 0.1330 0.0022
db_tab mnesia_stats 3071064 2437 0.0794 0.0010
db_tab mnesia_trans_store 15 0 0.0000 0.0000
db_tab mnesia_decision 3012281 0 0.0000 0.0000
db_tab schema 0 0 0.0000 0.0000
db_tab dets 0 0 0.0000 0.0000
db_tab dets_owners 0 0 0.0000 0.0000
db_tab dets_registry 0 0 0.0000 0.0000
db_tab mnesia_lock_queue 36154974 0 0.0000 0.0000
db_tab mnesia_sticky_locks 12108098 0 0.0000 0.0000
db_tab mnesia_tid_locks 27176721 0 0.0000 0.0000
db_tab mnesia_held_locks 48321870 0 0.0000 0.0000
db_tab mnesia_subscr 0 0 0.0000 0.0000
db_tab mnesia_gvar 102680683 1 0.0000 0.0000
db_tab user_functions 0 0 0.0000 0.0000
db_tab shell_records 0 0 0.0000 0.0000
ok
解读输出
通常,较高的 time
值是不好的,这通常是需要注意的事情。但是,还应注意较高的锁获取频率 (#tries
),因为锁会产生开销,并且即使在特定测试中没有显示冲突,高频率也可能会在开始发生冲突时变得有问题。
Big Bang 基准测试
-module(big).
-export([bang/1]).
pinger([], [], true) ->
receive
{procs, Procs, ReportTo} ->
pinger(Procs, [], ReportTo)
end;
pinger([], [], false) ->
receive {ping, From} -> From ! {pong, self()} end,
pinger([],[],false);
pinger([], [], ReportTo) ->
ReportTo ! {done, self()},
pinger([],[],false);
pinger([], [Po|Pos] = Pongers, ReportTo) ->
receive
{ping, From} ->
From ! {pong, self()},
pinger([], Pongers, ReportTo);
{pong, Po} ->
pinger([], Pos, ReportTo)
end;
pinger([Pi|Pis], Pongers, ReportTo) ->
receive {ping, From} -> From ! {pong, self()}
after 0 -> ok
end,
Pi ! {ping, self()},
pinger(Pis, [Pi|Pongers], ReportTo).
spawn_procs(N) when N =< 0 ->
[];
spawn_procs(N) ->
[spawn_link(fun () -> pinger([],[],true) end) | spawn_procs(N-1)].
send_procs([], Msg) ->
Msg;
send_procs([P|Ps], Msg) ->
P ! Msg,
send_procs(Ps, Msg).
receive_msgs([]) ->
ok;
receive_msgs([M|Ms]) ->
receive
M ->
receive_msgs(Ms)
end.
bang(N) when integer(N) ->
Procs = spawn_procs(N),
RMsgs = lists:map(fun (P) -> {done, P} end, Procs),
Start = now(),
send_procs(Procs, {procs, Procs, self()}),
receive_msgs(RMsgs),
Stop = now(),
lists:foreach(fun (P) -> exit(P, normal) end, Procs),
timer:now_diff(Stop, Start).