檢視原始碼 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,1lcnt: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/3lcnt: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).

另請參閱

LCNT 參考手冊