程序追蹤分析工具

tprof 提供便利的輔助工具，使用追蹤 BIF 來分析 Erlang 程序。

警告

此模組旨在將 eprof 和 cprof 整合為一個統一的 API，以測量呼叫次數、時間和記憶體配置。在 Erlang/OTP 27.0 中屬於實驗性質。

可以分析函數的呼叫次數、函數花費的時間以及函數的堆積記憶體配置。分析可以臨時進行，或者以伺服器輔助模式運行，以便更深入地了解生產環境中運行的程式碼。伺服器輔助模式可以使用預設的 tprof 伺服器或通過start(#{ session => atom() })啟動的隔離server/0來運行。

此模組支援三種分析類型

• call_count
• call_time
• call_memory

預設值為 call_count，它對效能的影響和記憶體佔用最小，但它不支援逐程序分析。因此，以下所有範例都使用 call_memory，它會測量堆積記憶體配置，並提供更複雜的功能集來演示。

不適合單個機器字的 Erlang 詞彙會配置在程序的堆積記憶體中。例如，返回兩個元素的 tuple 的函數需要在程序的堆積記憶體上配置 tuple。實際消耗為三個字，因為運行時系統還需要一個額外的字來儲存 tuple 的大小。

注意

啟用分析時，程式執行速度會變慢。

為了方便分析，對於某些追蹤模式中未啟用的函數，會累積測量結果。

top_traced_function(...)
not_traced_function()
bottom_traced_function()

在 not_traced_function 中發生的記憶體配置將會被添加到 top_traced_function 的記憶體配置中。但是，在 bottom_traced_function 中發生的記憶體配置不會包含在 top_traced_function 中。為了僅追蹤每個函數自己的記憶體配置，必須追蹤所有函數。

警告

避免對參與追蹤的模組進行熱碼重新載入。重新載入模組會停用追蹤並捨棄累積的統計資訊。如果分析的程式碼在分析會話期間重新載入，tprof 的結果可能會不正確。

臨時分析

臨時分析對於分析單個函數呼叫非常方便。

例如

1> tprof:profile(lists, seq, [1, 16], #{type => call_memory}).

****** Process <0.92.0>  --  100.00% of total *** 
FUNCTION          CALLS  WORDS  PER CALL  [     %]
lists:seq_loop/3      5     32      6.40  [100.00]
                            32            [ 100.0]
ok

預設情況下，會針對所有模組中的所有函數啟用追蹤。當在互動式 shell 中建立 fun 時，也會追蹤 shell 程式碼的一部分

1> tprof:profile(fun() -> lists:seq(1, 16) end, #{type => call_memory}).

****** Process <0.95.0>  --  100.00% of total *** 
FUNCTION                   CALLS  WORDS  PER CALL  [    %]
erl_eval:do_apply/7            1      3      3.00  [ 3.61]
erl_eval:match_list/6          1      3      3.00  [ 3.61]
lists:reverse/1                1      4      4.00  [ 4.82]
erl_eval:expr_list/7           3      7      2.33  [ 8.43]
erl_eval:ret_expr/3            4     16      4.00  [19.28]
erl_eval:merge_bindings/4      3     18      6.00  [21.69]
lists:seq_loop/3               5     32      6.40  [38.55]
                                     83            [100.0]
ok

但是，可以將追蹤限制為特定的函數或模組

2> tprof:profile(fun() -> lists:seq(1, 16) end,
                 #{type => call_memory, pattern => [{lists, seq_loop, '_'}]}).
****** Process <0.98.0>  --  100.00% of total *** 
FUNCTION          CALLS  WORDS  PER CALL  [     %]
lists:seq_loop/3      5     32      6.40  [100.00]
                            32            [ 100.0]

ok

臨時分析結果可以通過幾種不同的方式列印。以下範例使用定義如下的 test 模組

-module(test).
-export([test_spawn/0]).
test_spawn() ->
    {Pid, MRef} = spawn_monitor(fun () -> lists:seq(1, 32) end),
    receive
        {'DOWN', MRef, process, Pid, normal} ->
            done
    end.

預設情況下，會顯示每個程序的統計資訊

1> tprof:profile(test, test_spawn, [], #{type => call_memory}).

****** Process <0.176.0>    -- 23.66 % of total allocations ***
FUNCTION                CALLS  WORDS  PER CALL  [    %]
erlang:spawn_monitor/1      1      2         2  [ 9.09]
erlang:spawn_opt/4          1      6         6  [27.27]
test:test_spawn/0           1     14        14  [63.64]
                                  22            [100.0]

****** Process <0.177.0>    -- 76.34 % of total allocations ***
FUNCTION           CALLS  WORDS  PER CALL  [    %]
erlang:apply/2         1      7         7  [ 9.86]
lists:seq_loop/3       9     64         7  [90.14]
                             71            [100.0]

以下範例會列印所有程序的組合記憶體配置，並按配置的總字數降序排序

2> tprof:profile(test, test_spawn, [],
                 #{type => call_memory, report => {total, {measurement, descending}}}).

FUNCTION                CALLS  WORDS  PER CALL  [    %]
lists:seq_loop/3            9     64         7  [68.82]
test:test_spawn/0           1     14        14  [15.05]
erlang:apply/2              1      7         7  [ 7.53]
erlang:spawn_opt/4          1      6         6  [ 6.45]
erlang:spawn_monitor/1      1      2         2  [ 2.15]
                                  93            [100.0]

也可以收集分析資料以供進一步檢查

3> {done, ProfileData} = tprof:profile(fun test:test_spawn/0,
                                       #{type => call_memory, report => return}).
<...>
4> tprof:format(tprof:inspect(ProfileData, process, {percent, descending})).

****** Process <0.223.0>    -- 23.66 % of total allocations ***
FUNCTION                CALLS  WORDS  PER CALL  [    %]
test:test_spawn/0           1     14        14  [63.64]
erlang:spawn_opt/4          1      6         6  [27.27]
erlang:spawn_monitor/1      1      2         2  [ 9.09]
                                  22            [100.0]

****** Process <0.224.0>    -- 76.34 % of total allocations ***
FUNCTION           CALLS  WORDS  PER CALL  [    %]
lists:seq_loop/3       9     64         7  [90.14]
erlang:apply/2         1      7         7  [ 9.86]
                             71            [100.0]

分析的程序取決於分析類型。

• call_count (預設) 會計算所有程序中的呼叫次數。

• call_time 和 call_memory 會將分析限制為由使用者提供的函數衍生的程序（使用 trace:process/4 的 set_on_spawn 選項）。

call_time 和 call_memory 可以限制為分析單個程序

2> tprof:profile(test, test_spawn, [],
                 #{type => call_memory, set_on_spawn => false}).

****** Process <0.183.0>    -- 100.00 % of total allocations ***
FUNCTION                CALLS  WORDS  PER CALL  [    %]
erlang:spawn_monitor/1      1      2         2  [ 9.09]
erlang:spawn_opt/4          1      6         6  [27.27]
test:test_spawn/0           1     14        14  [63.64]

Erlang 程式可以在與原始程序不同的程序中執行昂貴的操作。您可以在測量時間或記憶體時，將多個、新的或甚至所有程序包含在追蹤中

7> pg:start_link().
{ok,<0.252.0>}
8> tprof:profile(fun() -> pg:join(group, self()) end,
                 #{type => call_memory, rootset => [pg]}).
****** Process <0.252.0>    -- 52.86 % of total allocations ***
FUNCTION                      CALLS  WORDS  PER CALL  [    %]
pg:leave_local_update_ets/5       1      2         2  [ 1.80]
gen:reply/2                       1      3         3  [ 2.70]
erlang:monitor/2                  1      3         3  [ 2.70]
gen_server:try_handle_call/4      1      3         3  [ 2.70]
gen_server:try_dispatch/4         1      3         3  [ 2.70]
maps:iterator/1                   2      4         2  [ 3.60]
maps:take/2                       1      6         6  [ 5.41]
pg:join_local_update_ets/5        1      8         8  [ 7.21]
pg:handle_info/2                  1      8         8  [ 7.21]
pg:handle_call/3                  1      9         9  [ 8.11]
gen_server:loop/7                 2      9         4  [ 8.11]
ets:lookup/2                      2     10         5  [ 9.01]
pg:join_local/3                   1     11        11  [ 9.91]
pg:notify_group/5                 2     16         8  [14.41]
erlang:setelement/3               2     16         8  [14.41]
                                       111            [100.0]

****** Process <0.255.0>    -- 47.14 % of total allocations ***
FUNCTION                   CALLS  WORDS  PER CALL  [    %]
erl_eval:match_list/6          1      3         3  [ 3.03]
erlang:monitor/2               1      3         3  [ 3.03]
lists:reverse/1                2      4         2  [ 4.04]
pg:join/3                      1      4         4  [ 4.04]
erl_eval:add_bindings/2        1      5         5  [ 5.05]
erl_eval:do_apply/7            2      6         3  [ 6.06]
gen:call/4                     1      8         8  [ 8.08]
erl_eval:expr_list/7           4     10         2  [10.10]
gen:do_call/4                  1     16        16  [16.16]
erl_eval:ret_expr/3            4     16         4  [16.16]
erl_eval:merge_bindings/4      3     24         8  [24.24]
                                     99            [100.0]

預設情況下，分析時間沒有限制。對於臨時分析，可以設定時間限制。如果被分析的函數在該時間到期之前沒有返回，則該程序會被終止，原因為 kill。使用者提供的函數啟動的任何未連結的子程序都會保留；開發人員有責任處理這些程序。

9> tprof:profile(timer, sleep, [100000], #{timeout => 1000}).

預設情況下，任何時間點只允許一個臨時或伺服器輔助分析會話。可以強制多個臨時會話同時進行，但開發人員有責任確保追蹤模式不會重疊

1> tprof:profile(fun() -> lists:seq(1, 32) end,
    #{registered => false, pattern => [{lists, '_', '_'}]}).

伺服器輔助分析

伺服器輔助分析可以在正在運行的系統上進行。為此，請啟動 tprof 伺服器，然後在系統處理實際流量時新增追蹤模式和要追蹤的程序。可以隨時提取、檢查和列印資料。以下範例會追蹤 Kernel supervisor 監督的所有程序的活動

1> tprof:start(#{type => call_memory}).
{ok,<0.200.0>}
2> tprof:enable_trace({all_children, kernel_sup}).
34
3> tprof:set_pattern('_', '_' , '_').
16728
4> Sample = tprof:collect().
{call_memory,
    [{gen_server,try_dispatch,4,[{<0.154.0>,2,6}]},
     {erlang,iolist_to_iovec,1,[{<0.161.0>,1,8}]},
<...>
5 > tprof:format(tprof:inspect(Sample)).

****** Process <0.154.0>    -- 14.21 % of total allocations ***
FUNCTION                   CALLS  WORDS  PER CALL  [    %]
maps:iterator/1                2      4         2  [15.38]
gen_server:try_dispatch/4      2      6         3  [23.08]
net_kernel:handle_info/2       2     16         8  [61.54]
                                     26            [100.0]

****** Process <0.161.0>    -- 85.79 % of total allocations ***
FUNCTION                        CALLS  WORDS  PER CALL  [    %]
disk_log:handle/2                   2      2         1  [ 1.27]
disk_log_1:maybe_start_timer/1      1      3         3  [ 1.91]
disk_log_1:mf_write_cache/1         1      3         3  [ 1.91]
<...>

可以分析整個正在運行的系統，然後檢查個別程序

1> tprof:start(#{type => call_memory}).
2> tprof:enable_trace(all), tprof:set_pattern('_', '_' , '_').
9041
3> timer:sleep(10000), tprof:disable_trace(all), Sample = tprof:collect().
{call_memory,
    [{user_drv,server,3,[{<0.64.0>,12,136}]},
     {user_drv,contains_ctrl_g_or_ctrl_c,1,[{<0.64.0>,80,10}]},
<...>
4> Inspected = tprof:inspect(Sample, process, measurement), Shell = maps:get(self(), Inspected).
{call_memory, 2743,
    [{shell,{enc,0},1,2,2,0.07291286912139992},
<...>
5> tprof:format(Shell).

FUNCTION                           CALLS  WORDS  PER CALL  [    %]
<...>
erl_lint:start/2                       2    300       150  [10.94]
shell:used_records/1                 114    342         3  [12.47]