Skip to content

Commit adf24b6

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

File tree

1 file changed

+52
-24
lines changed

1 file changed

+52
-24
lines changed

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

Lines changed: 52 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -8,8 +8,11 @@ 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
15+
measurements.
1316
1417
Before running the code, it invokes the `app.start` task which compiles
1518
and loads your project. After that, the target expression is profiled together
@@ -28,7 +31,7 @@ defmodule Mix.Tasks.Profile.Tprof do
2831
$ mix profile.tprof -e "Enum.map([1, 2, 3], &Integer.to_string/1)" --type memory
2932
3033
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`:
34+
the call count information, you can use the type `calls` which has the lowest footprint:
3235
3336
$ mix profile.tprof -e "Enum.map([1, 2, 3], &Integer.to_string/1)" --type calls
3437
@@ -56,34 +59,59 @@ defmodule Mix.Tasks.Profile.Tprof do
5659
5760
## Profile output
5861
59-
Example output:
62+
Example output (`time` type):
6063
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
64+
Profile results of #PID<0.107.0>
65+
# CALLS % TIME µS/CALL
66+
Total 20 100.00 2 0.10
67+
String.Chars.Integer.to_string/1 5 0.00 0 0.00
68+
anonymous fn/0 in :elixir_compiler_1.__FILE__/1 1 0.00 0 0.00
69+
Enum.each/2 1 0.00 0 0.00
70+
Enum.reduce_range/5 3 0.00 0 0.00
71+
:erlang.integer_to_binary/1 5 50.00 1 0.20
72+
anonymous fn/3 in Enum.each/2 5 50.00 1 0.20
7173
72-
Profile done over 8 matching functions
74+
Profile done over 6 matching functions
75+
76+
Example output (`memory` type):
77+
78+
Profile results of #PID<0.107.0>
79+
# CALLS % WORDS PER CALL
80+
Total 6 100.00 19 3.17
81+
Enum.each/2 1 21.05 4 4.00
82+
:erlang.integer_to_binary/1 5 78.95 15 3.00
83+
84+
Profile done over 2 matching functions
85+
86+
Example output (`calls` type)
87+
88+
Profile results over all processes
89+
# CALLS %
90+
Total 20 100.00
91+
anonymous fn/0 in :elixir_compiler_1.__FILE__/1 1 5.00
92+
Enum.each/2 1 5.00
93+
Enum.reduce_range/5 3 15.00
94+
:erlang.integer_to_binary/1 5 25.00
95+
String.Chars.Integer.to_string/1 5 25.00
96+
anonymous fn/3 in Enum.each/2 5 25.00
97+
98+
Profile done over 6 matching functions
7399
74100
The default output contains data gathered from all matching functions. The first
75101
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.
102+
or memory usage for all the function calls listed.
103+
The following rows contain the function call, followed by the number of times that
104+
the function was called, then by the percentage of time/memory that the call uses,
105+
then the total time/memory for that function in microseconds/words, and, finally,
106+
the average time/memory per call in microseconds/words.
80107
81108
When `--matching` option is specified, call count tracing will be started only for
82109
the functions matching the given pattern:
83110
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
111+
Profile results of #PID<0.106.0>
112+
# CALLS % TIME µS/CALL
113+
Total 5 100.00 1 0.20
114+
String.Chars.Integer.to_string/1 5 100.00 1 0.20
87115
88116
Profile done over 1 matching functions
89117
@@ -106,8 +134,8 @@ defmodule Mix.Tasks.Profile.Tprof do
106134
You should expect a slowdown in your code execution using this tool since `:tprof` has
107135
some performance impact on the execution, but the impact is considerably lower than
108136
`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.
137+
scenario or focus on the main modules or processes. The `calls` type can also be used,
138+
which is more limited but has a lower footprint.
111139
"""
112140

113141
@switches [

0 commit comments

Comments
 (0)