Skip to content

Commit 6b632c8

Browse files
sabiwarasabiwara
committed
Write moduledoc for tprof
1 parent 27e56dc commit 6b632c8

File tree

1 file changed

+51
-24
lines changed

1 file changed

+51
-24
lines changed

‎lib/mix/lib/mix/tasks/profile.tprof.ex

Lines changed: 51 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -8,8 +8,10 @@ defmodule Mix.Tasks.Profile.Tprof do
88
99
Requires Erlang/OTP27 or above.
1010
11-
[`:tprof`](`:tprof`) can provide time or memory information of each function call
12-
and can be useful when you want to discover the bottlenecks related to these.
11+
[`:tprof`](`:tprof`) is an experimental module introduced in Erlang/OTP 27 which
12+
provides a unified API for measuring call count, time, and allocation, and aims to
13+
replace [`:eprof`](`:eprof`) and [`:cprof`](`:cprof`).
14+
It can be useful when you want to discover the bottlenecks related to any of these.
1315
1416
Before running the code, it invokes the `app.start` task which compiles
1517
and loads your project. After that, the target expression is profiled together
@@ -28,7 +30,7 @@ defmodule Mix.Tasks.Profile.Tprof do
2830
$ mix profile.tprof -e "Enum.map([1, 2, 3], &Integer.to_string/1)" --type memory
2931
3032
Call count is present with both type `time` and `memory`, but if you only need
31-
the call count information, you can use the type `calls`:
33+
the call count information, you can use the type `calls` which has the lowest footprint:
3234
3335
$ mix profile.tprof -e "Enum.map([1, 2, 3], &Integer.to_string/1)" --type calls
3436
@@ -56,34 +58,59 @@ defmodule Mix.Tasks.Profile.Tprof do
5658
5759
## Profile output
5860
59-
Example output:
61+
Example output (`time` type):
6062
61-
# CALLS % TIME µS/CALL
62-
Total 24 100.0 26 1.08
63-
Enum.reduce_range_inc/4 5 3.85 1 0.20
64-
:erlang.make_fun/3 1 7.69 2 2.00
65-
Enum.each/2 1 7.69 2 2.00
66-
anonymous fn/0 in :elixir_compiler_0.__FILE__/1 1 7.69 2 2.00
67-
:erlang.integer_to_binary/1 5 15.39 4 0.80
68-
:erlang.apply/2 1 15.39 4 4.00
69-
anonymous fn/3 in Enum.each/2 5 19.23 5 1.00
70-
String.Chars.Integer.to_string/1 5 23.08 6 1.20
63+
Profile results of #PID<0.107.0>
64+
# CALLS % TIME µS/CALL
65+
Total 20 100.00 2 0.10
66+
String.Chars.Integer.to_string/1 5 0.00 0 0.00
67+
anonymous fn/0 in :elixir_compiler_1.__FILE__/1 1 0.00 0 0.00
68+
Enum.each/2 1 0.00 0 0.00
69+
Enum.reduce_range/5 3 0.00 0 0.00
70+
:erlang.integer_to_binary/1 5 50.00 1 0.20
71+
anonymous fn/3 in Enum.each/2 5 50.00 1 0.20
7172
72-
Profile done over 8 matching functions
73+
Profile done over 6 matching functions
74+
75+
Example output (`memory` type):
76+
77+
Profile results of #PID<0.107.0>
78+
# CALLS % WORDS PER CALL
79+
Total 6 100.00 19 3.17
80+
Enum.each/2 1 21.05 4 4.00
81+
:erlang.integer_to_binary/1 5 78.95 15 3.00
82+
83+
Profile done over 2 matching functions
84+
85+
Example output (`calls` type)
86+
87+
Profile results over all processes
88+
# CALLS %
89+
Total 20 100.00
90+
anonymous fn/0 in :elixir_compiler_1.__FILE__/1 1 5.00
91+
Enum.each/2 1 5.00
92+
Enum.reduce_range/5 3 15.00
93+
:erlang.integer_to_binary/1 5 25.00
94+
String.Chars.Integer.to_string/1 5 25.00
95+
anonymous fn/3 in Enum.each/2 5 25.00
96+
97+
Profile done over 6 matching functions
7398
7499
The default output contains data gathered from all matching functions. The first
75100
row after the header contains the sums of the partial results and the average time
76-
for all the function calls listed. The following rows contain the function call,
77-
followed by the number of times that the function was called, then by the percentage
78-
of time that the call uses, then the total time for that function in microseconds,
79-
and, finally, the average time per call in microseconds.
101+
or memory usage for all the function calls listed.
102+
The following rows contain the function call, followed by the number of times that
103+
the function was called, then by the percentage of time/memory that the call uses,
104+
then the total time/memory for that function in microseconds/words, and, finally,
105+
the average time/memory per call in microseconds/words.
80106
81107
When `--matching` option is specified, call count tracing will be started only for
82108
the functions matching the given pattern:
83109
84-
# CALLS % TIME µS/CALL
85-
Total 5 100.0 6 1.20
86-
String.Chars.Integer.to_string/1 5 100.0 6 1.20
110+
Profile results of #PID<0.106.0>
111+
# CALLS % TIME µS/CALL
112+
Total 5 100.00 1 0.20
113+
String.Chars.Integer.to_string/1 5 100.00 1 0.20
87114
88115
Profile done over 1 matching functions
89116
@@ -106,8 +133,8 @@ defmodule Mix.Tasks.Profile.Tprof do
106133
You should expect a slowdown in your code execution using this tool since `:tprof` has
107134
some performance impact on the execution, but the impact is considerably lower than
108135
`Mix.Tasks.Profile.Fprof`. If you have a large system try to profile a limited
109-
scenario or focus on the main modules or processes. Another alternative is to use
110-
`Mix.Tasks.Profile.Cprof` that uses [`:cprof`](`:cprof`) and has a low performance degradation effect.
136+
scenario or focus on the main modules or processes. The `calls` type can also be used,
137+
which is more limited but has a lower footprint.
111138
"""
112139

113140
@switches [

0 commit comments

Comments
 (0)