檢視原始碼 lcnt - 鎖定分析器
在 Erlang 執行時系統內部,會使用鎖定來保護資源,避免在多個執行緒同時更新時發生錯誤。鎖定對於確保執行時系統正常運作是必要的,但也引入了限制,即鎖定競爭和鎖定開銷。
鎖定競爭指的是當一個執行緒鎖定資源時,另一個執行緒(或多個執行緒)同時嘗試取得相同的資源。鎖定會拒絕其他執行緒訪問資源,並且該執行緒會被阻止繼續執行。第二個執行緒必須等待第一個執行緒完成對資源的存取並解除鎖定。 lcnt
工具會測量這些鎖定衝突。
鎖定在執行時間和記憶體空間方面都有固有的成本。初始化、銷毀、取得或釋放鎖定都需要時間。為了減少鎖定競爭,有時需要使用更細粒度的鎖定策略。這通常也會增加鎖定開銷。因此,鎖定競爭和開銷之間存在權衡。一般來說,鎖定競爭會隨著同時運行的執行緒數量而增加。
lcnt
工具不測量鎖定開銷。
啟用鎖定計數
為了調查模擬器中的鎖定,我們使用一個名為 lcnt
(鎖定計數的縮寫)的內部工具。虛擬機器 (VM) 需要在啟用此選項的情況下編譯。若要編譯一個具有鎖定計數功能的 VM 以及一個正常的 VM,請使用
cd $ERL_TOP
./configure --enable-lock-counter
make
像這樣啟動鎖定計數 VM
$ERL_TOP/bin/erl -emu_type lcnt
要驗證是否已啟用鎖定計數,請檢查當 VM 啟動時,狀態文字中是否出現 [lock-counting]
。
Erlang/OTP 27 [erts-15.0] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [jit] [lock-counting]
開始使用
一旦您擁有啟用了鎖定計數的 VM,就可以使用 lcnt
模組。此模組旨在從目前執行節點的 shell 中使用。若要存取遠端節點,請使用 lcnt:clear(Node)
和 lcnt:collect(Node)
。
所有鎖定都會持續監控,並更新其統計資訊。在運行任何特定測試之前,請使用 lcnt:clear/0
來初始化清除所有計數器。此命令也會重置內部持續時間計時器。
若要檢索鎖定統計資訊,請使用 lcnt:collect/0,1
。如果尚未啟動,收集操作將會啟動一個 lcnt
伺服器。所有收集的資料都將儲存在 Erlang 術語中,並連同持續時間時間一起上傳到伺服器。持續時間時間是介於 lcnt:clear/0,1
和 lcnt:collect/0,1
之間的時間。
一旦資料收集到伺服器,就可以以多種方式進行篩選、排序和列印。
使用範例
這是一個運行 Big Bang Benchmark 的範例
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
<nonode@nohost.1042.0> 5692 0.5095 484
<nonode@nohost.465.0> 4989 0.4410 393
<nonode@nohost.347.0> 6319 2.1839 284
<nonode@nohost.436.0> 6077 1.9747 198
<nonode@nohost.307.0> 5071 1.3015 192
<nonode@nohost.455.0> 5846 1.7106 186
<nonode@nohost.565.0> 6305 1.2054 179
<nonode@nohost.461.0> 5820 1.2715 176
<nonode@nohost.173.0> 6329 1.4852 168
<nonode@nohost.453.0> 5172 0.8701 167
<nonode@nohost.741.0> 5306 0.4146 166
<nonode@nohost.403.0> 5838 1.9870 160
<nonode@nohost.463.0> 6346 1.5443 143
<nonode@nohost.184.0> 5542 0.4331 141
<nonode@nohost.289.0> 5260 0.2662 137
<nonode@nohost.166.0> 5610 0.9447 127
<nonode@nohost.189.0> 5354 0.5230 118
<nonode@nohost.121.0> 5845 0.9239 115
<nonode@nohost.104.0> 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
<nonode@nohost.1158.0> 5 14499900 36934 0.2547 4878 0.0081
<nonode@nohost.1157.0> 5 14157504 35797 0.2528 4727 0.0079
<nonode@nohost.1163.0> 5 14194934 34510 0.2431 4403 0.0073
<nonode@nohost.1164.0> 5 14149447 35326 0.2497 4150 0.0069
<nonode@nohost.1166.0> 5 14316525 35675 0.2492 4116 0.0069
<nonode@nohost.1159.0> 5 14241146 35358 0.2483 4101 0.0068
<nonode@nohost.1162.0> 5 14224491 35182 0.2473 4094 0.0068
<nonode@nohost.1160.0> 5 14190075 35328 0.2490 4075 0.0068
<nonode@nohost.1165.0> 5 14308906 35031 0.2448 3896 0.0065
<nonode@nohost.1161.0> 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
<nonode@nohost.85.0> 5 17 2 11.7647 87 0.0001
<nonode@nohost.1156.0> 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
<nonode@nohost.1158.0> proc_main 3207155 0.7178 3726
<nonode@nohost.1163.0> proc_main 3138532 0.7485 3593
<nonode@nohost.1157.0> proc_main 3133180 0.7156 3547
<nonode@nohost.1166.0> proc_main 3165128 0.7609 3517
<nonode@nohost.1164.0> proc_main 3128838 0.7525 3477
<nonode@nohost.1160.0> proc_main 3137627 0.7559 3433
<nonode@nohost.1162.0> proc_main 3144886 0.7509 3425
<nonode@nohost.1159.0> proc_main 3149315 0.7487 3372
<nonode@nohost.1161.0> proc_main 3196546 0.7591 3310
<nonode@nohost.1165.0> 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).