aboutsummaryrefslogtreecommitdiffstats
path: root/erts/doc/src
diff options
context:
space:
mode:
authorLukas Larsson <[email protected]>2014-09-12 16:38:00 +0200
committerLukas Larsson <[email protected]>2016-02-02 10:45:21 +0100
commit664ed2a6fd2b324bb6b56db3d3eca853cfda8f61 (patch)
tree286743a4b1f794948329961e7f5879b5f54f54a5 /erts/doc/src
parenteea5f896780e07f7ca76685061d01e7be5a7abaa (diff)
downloadotp-664ed2a6fd2b324bb6b56db3d3eca853cfda8f61.tar.gz
otp-664ed2a6fd2b324bb6b56db3d3eca853cfda8f61.tar.bz2
otp-664ed2a6fd2b324bb6b56db3d3eca853cfda8f61.zip
erts: Add microstate accounting
Microstate accounting is a way to track which state the different threads within ERTS are in. The main usage area is to pin point performance bottlenecks by checking which states the threads are in and then from there figuring out why and where to optimize. Since checking whether microstate accounting is on or off is relatively expensive if done in a short loop only a few of the states are enabled by default and more states can be enabled through configure. I've done some benchmarking and the overhead with it turned off is not noticible and with it on it is a fraction of a percent. If you enable the extra states, depending on the benchmark, the ovehead when turned off is about 1% and when turned on somewhere inbetween 5-15%. OTP-12345
Diffstat (limited to 'erts/doc/src')
-rw-r--r--erts/doc/src/erlang.xml177
1 files changed, 164 insertions, 13 deletions
diff --git a/erts/doc/src/erlang.xml b/erts/doc/src/erlang.xml
index 6915b35fcb..ddca492040 100644
--- a/erts/doc/src/erlang.xml
+++ b/erts/doc/src/erlang.xml
@@ -5870,6 +5870,146 @@ true</pre>
<func>
<name name="statistics" arity="1" clause_i="6"/>
+ <fsummary>Information about microstate accounting.</fsummary>
+ <desc>
+ <marker id="statistics_microstate_accounting"></marker>
+ <p>
+ Microstate accounting can be used to measure how much time the Erlang
+ runtime system spends doing various tasks. It is designed to be as
+ lightweight as possible, but there will be some overhead when this
+ is enabled. Microstate accounting is meant to be a profiling tool
+ to help figure out performance bottlenecks.
+ To <c>start</c>/<c>stop</c>/<c>reset</c> microstate_accounting you use
+ the system_flag
+ <seealso marker="#system_flag_microstate_accounting">
+ <c>microstate_accounting</c></seealso>.
+ </p>
+ <p>
+ <c>erlang:statistics(microstate_accounting)</c> returns a list of maps
+ representing some of the OS threads within ERTS. Each map contains
+ <c>type</c> and <c>id</c> fields that can be used to identify what
+ thread it is, and also a counters field that contains data about how
+ much time has been spent in the various states.</p>
+ <pre>
+> <input>erlang:statistics(microstate_accounting).</input>
+[#{counters => #{aux => 1899182914,
+ check_io => 2605863602,
+ emulator => 45731880463,
+ gc => 1512206910,
+ other => 5421338456,
+ port => 221631,
+ sleep => 5150294100},
+ id => 1,
+ type => scheduler}|...]
+ </pre>
+ <p>The time unit is the same as returned by
+ <seealso marker="kernel:os#perf_counter/0">
+ <c>os:perf_counter/0</c></seealso>.
+ So to convert it to milliseconds you could do something like this:</p>
+ <pre>
+lists:map(
+ fun(#{ counters := Cnt } = M) ->
+ MsCnt = maps:map(fun(_K, PerfCount) ->
+ erlang:convert_time_unit(PerfCount, perf_counter, 1000)
+ end, Cnt),
+ M#{ counters := MsCnt }
+ end, erlang:statistics(microstate_accounting)).
+ </pre>
+ <p>
+ It is important to note that these values are not guaranteed to be
+ the exact time spent in each state. This is because of various
+ optimisation done in order to keep the overhead as small as possible.
+ </p>
+
+ <p>Currently the following <c><anno>MSAcc_Thread_Type</anno></c> are available:</p>
+ <taglist>
+ <tag><c>scheduler</c></tag>
+ <item>The main execution threads that do most of the work.</item>
+ <tag><c>async</c></tag><item>Async threads are used by various
+ linked-in drivers (mainly the file drivers) do offload non-cpu
+ intensive work.</item>
+ <tag><c>aux</c></tag><item>Takes care of any work that is not
+ specifically assigned to a scheduler.</item>
+ </taglist>
+ <p>Currently the following <c><anno>MSAcc_Thread_State</anno></c>s are available.
+ All states are exclusive, meaning that a thread cannot be in two states
+ at once. So if you add the numbers of all counters in a thread
+ you will get the total run-time for that thread.</p>
+ <taglist>
+ <tag><c>aux</c></tag>
+ <item>Time spent handling auxiliary jobs.</item>
+ <tag><c>check_io</c></tag>
+ <item>Time spent checking for new I/O events.</item>
+ <tag><c>emulator</c></tag>
+ <item>Time spent executing erlang processes.</item>
+ <tag><c>gc</c></tag>
+ <item>Time spent doing garbage collection. When extra states are
+ enabled this is the time spent doing non-fullsweep garbage
+ collections.</item>
+ <tag><c>other</c></tag>
+ <item>Time spent doing unaccounted things.</item>
+ <tag><c>port</c></tag>
+ <item>Time spent executing ports.</item>
+ <tag><c>sleep</c></tag>
+ <item>Time spent sleeping.</item>
+ </taglist>
+ <p>It is possible to add more fine grained <c><anno>MSAcc_Thread_State</anno></c>s
+ through configure.
+ (e.g. <c>./configure --with-microstate-accounting=extra</c>).
+ Enabling these states will cause a performance degradation when
+ microstate accounting is turned off and increase the overhead when
+ it is turned on.</p>
+ <taglist>
+ <tag><c>alloc</c></tag>
+ <item>Time spent managing memory. Without extra states this time is
+ spread out over all other states.</item>
+ <tag><c>bif</c></tag>
+ <item>Time spent in bifs. Without extra states this time is part of
+ the <c>emulator</c> state.</item>
+ <tag><c>busy_wait</c></tag>
+ <item>Time spent busy waiting. This is also the state where a
+ scheduler no longer reports that it is active when using
+ <seealso marker="#statistics_scheduler_wall_time">
+ <c>erlang:statistics(scheduler_wall_time)</c></seealso>.
+ So if you add all other states but this and sleep and then divide that
+ by all time in the thread you should get something very similar to the
+ scheduler_wall_time fraction. Without extra states this time is part
+ of the <c>other</c> state.</item>
+ <tag><c>ets</c></tag>
+ <item>Time spent executing ETS bifs. Without extra states this time is
+ part of the <c>emulator</c> state.</item>
+ <tag><c>gc_full</c></tag>
+ <item>Time spent doing fullsweep garbage collection. Without extra
+ states this time is part of the <c>gc</c> state.</item>
+ <tag><c>nif</c></tag>
+ <item>Time spent in nifs. Without extra states this time is part of
+ the <c>emulator</c> state.</item>
+ <tag><c>send</c></tag>
+ <item>Time spent sending messages (processes only). Without extra
+ states this time is part of the <c>emulator</c> state.</item>
+ <tag><c>timers</c></tag>
+ <item>Time spent managing timers. Without extra states this time is
+ part of the <c>other</c> state.</item>
+ </taglist>
+ <p>There is a utility module called
+ <seealso marker="runtime_tools:msacc"><c>msacc</c></seealso> in
+ runtime_tools that can be used to more easily analyse these
+ statistics.</p>
+
+ <p>
+ Returns <c>undefined</c> if the system flag
+ <seealso marker="#system_flag_microstate_accounting">
+ <c>microstate_accounting</c></seealso>
+ is turned off.
+ </p>
+ <p>The list of thread information is unsorted and may appear in
+ different order between calls.</p>
+ <note><p>The threads and states are subject to change without any
+ prior notice.</p></note>
+ </desc>
+ </func>
+ <func>
+ <name name="statistics" arity="1" clause_i="7"/>
<fsummary>Information about reductions.</fsummary>
<desc>
<marker id="statistics_reductions"></marker>
@@ -5887,7 +6027,7 @@ true</pre>
</func>
<func>
- <name name="statistics" arity="1" clause_i="7"/>
+ <name name="statistics" arity="1" clause_i="8"/>
<fsummary>Information about the run-queues.</fsummary>
<desc><marker id="statistics_run_queue"></marker>
<p>
@@ -5903,7 +6043,7 @@ true</pre>
</func>
<func>
- <name name="statistics" arity="1" clause_i="8"/>
+ <name name="statistics" arity="1" clause_i="9"/>
<fsummary>Information about the run-queue lengths.</fsummary>
<desc><marker id="statistics_run_queue_lengths"></marker>
<p>
@@ -5923,7 +6063,7 @@ true</pre>
</func>
<func>
- <name name="statistics" arity="1" clause_i="9"/>
+ <name name="statistics" arity="1" clause_i="10"/>
<fsummary>Information about runtime.</fsummary>
<desc>
<p>Returns information about runtime, in milliseconds.</p>
@@ -5938,7 +6078,7 @@ true</pre>
</func>
<func>
- <name name="statistics" arity="1" clause_i="10"/>
+ <name name="statistics" arity="1" clause_i="11"/>
<fsummary>Information about each schedulers work time.</fsummary>
<desc>
<marker id="statistics_scheduler_wall_time"></marker>
@@ -6009,7 +6149,7 @@ ok
</func>
<func>
- <name name="statistics" arity="1" clause_i="11"/>
+ <name name="statistics" arity="1" clause_i="12"/>
<fsummary>Information about active processes and ports.</fsummary>
<desc><marker id="statistics_total_active_tasks"></marker>
<p>
@@ -6027,7 +6167,7 @@ ok
</func>
<func>
- <name name="statistics" arity="1" clause_i="12"/>
+ <name name="statistics" arity="1" clause_i="13"/>
<fsummary>Information about the run-queue lengths.</fsummary>
<desc><marker id="statistics_total_run_queue_lengths"></marker>
<p>
@@ -6046,7 +6186,7 @@ ok
</func>
<func>
- <name name="statistics" arity="1" clause_i="13"/>
+ <name name="statistics" arity="1" clause_i="14"/>
<fsummary>Information about wall clock.</fsummary>
<desc>
<p>Returns information about wall clock. <c>wall_clock</c> can
@@ -6280,6 +6420,17 @@ ok
<func>
<name name="system_flag" arity="2" clause_i="5"/>
+ <fsummary>Set system flag microstate_accounting</fsummary>
+ <desc><p><marker id="system_flag_microstate_accounting"></marker>
+ Turns on/off microstate accounting measurements. By passing reset it is possible to reset
+ all counters to 0.</p>
+ <p>For more information see,
+ <seealso marker="#statistics_microstate_accounting">erlang:statistics(microstate_accounting)</seealso>.
+ </p>
+ </desc>
+ </func>
+ <func>
+ <name name="system_flag" arity="2" clause_i="6"/>
<fsummary>Sets system flag <c>min_heap_size</c>.</fsummary>
<desc>
<p>Sets the default minimum heap size for processes. The size
@@ -6294,7 +6445,7 @@ ok
</func>
<func>
- <name name="system_flag" arity="2" clause_i="6"/>
+ <name name="system_flag" arity="2" clause_i="7"/>
<fsummary>Sets system flag <c>min_bin_vheap_size</c>.</fsummary>
<desc>
<p>Sets the default minimum binary virtual heap size for
@@ -6311,7 +6462,7 @@ ok
</func>
<func>
- <name name="system_flag" arity="2" clause_i="7"/>
+ <name name="system_flag" arity="2" clause_i="8"/>
<fsummary>Sets system flag <c>multi_scheduling</c>.</fsummary>
<desc>
<p><marker id="system_flag_multi_scheduling"></marker>
@@ -6349,7 +6500,7 @@ ok
</func>
<func>
- <name name="system_flag" arity="2" clause_i="8"/>
+ <name name="system_flag" arity="2" clause_i="9"/>
<fsummary>Sets system flag <c>scheduler_bind_type</c>.</fsummary>
<type name="scheduler_bind_type"/>
<desc>
@@ -6467,7 +6618,7 @@ ok
</func>
<func>
- <name name="system_flag" arity="2" clause_i="9"/>
+ <name name="system_flag" arity="2" clause_i="10"/>
<fsummary>Sets system flag <c>scheduler_wall_time</c>.</fsummary>
<desc><p><marker id="system_flag_scheduler_wall_time"></marker>
Turns on or off scheduler wall time measurements.</p>
@@ -6477,7 +6628,7 @@ ok
</func>
<func>
- <name name="system_flag" arity="2" clause_i="10"/>
+ <name name="system_flag" arity="2" clause_i="11"/>
<fsummary>Sets system flag <c>schedulers_online</c>.</fsummary>
<desc>
<p><marker id="system_flag_schedulers_online"></marker>
@@ -6502,7 +6653,7 @@ ok
</func>
<func>
- <name name="system_flag" arity="2" clause_i="11"/>
+ <name name="system_flag" arity="2" clause_i="12"/>
<fsummary>Sets system flag <c>trace_control_word</c>.</fsummary>
<desc>
<p>Sets the value of the node trace control word to