diff options
author | John Högberg <[email protected]> | 2019-03-19 17:39:14 +0100 |
---|---|---|
committer | John Högberg <[email protected]> | 2019-03-21 16:25:32 +0100 |
commit | 2f75782815441a161e6157c941b7f482f96bdbcb (patch) | |
tree | 1636fd286073f1fe669a9e3f6a477e23c62ea9bc /lib/kernel/doc | |
parent | 92bd7d3e43b7142d991f15594d783c1031547df5 (diff) | |
download | otp-2f75782815441a161e6157c941b7f482f96bdbcb.tar.gz otp-2f75782815441a161e6157c941b7f482f96bdbcb.tar.bz2 otp-2f75782815441a161e6157c941b7f482f96bdbcb.zip |
seq_trace: Inherit trace token on spawn
Trace tokens can be lost when a process delegates message sending
to a child process, which is pretty surprising and limits the
usefulness of seq tracing. One example of this is gen_statem:call/4
which uses a child process to implement timeouts without the risk
of a late message arriving to the caller.
This commit attempts to remedy this by propagating the trace token
to spawned processes, and adds optional tracing for process
spawning as well.
Diffstat (limited to 'lib/kernel/doc')
-rw-r--r-- | lib/kernel/doc/src/seq_trace.xml | 55 |
1 files changed, 40 insertions, 15 deletions
diff --git a/lib/kernel/doc/src/seq_trace.xml b/lib/kernel/doc/src/seq_trace.xml index 9aef748594..aa9067f082 100644 --- a/lib/kernel/doc/src/seq_trace.xml +++ b/lib/kernel/doc/src/seq_trace.xml @@ -107,6 +107,12 @@ seq_trace:set_token(OldToken), % activate the trace token again enables/disables tracing on message sending. Default is <c>false</c>.</p> </item> + <tag><c>set_token('spawn', <anno>Bool</anno>)</c></tag> + <item> + <p>A trace token flag (<c>true | false</c>) which + enables/disables tracing on process spawning. Default is + <c>false</c>.</p> + </item> <tag><c>set_token('receive', <anno>Bool</anno>)</c></tag> <item> <p>A trace token flag (<c>true | false</c>) which @@ -259,6 +265,11 @@ TimeStamp = {Seconds, Milliseconds, Microseconds} <p>Used when a process <c>From</c> with its trace token flag <c>send</c> set to <c>true</c> has sent a message.</p> </item> + <tag><c>{spawn, Serial, Parent, Child, _}</c></tag> + <item> + <p>Used when a process <c>Parent</c> with its trace token flag + <c>spawn</c> set to <c>true</c> has spawned a process.</p> + </item> <tag><c>{'receive', Serial, From, To, Message}</c></tag> <item> <p>Used when a process <c>To</c> receives a message with a @@ -295,8 +306,8 @@ TimeStamp = {Seconds, Milliseconds, Microseconds} is initiated by a single message. In short, it works as follows:</p> <p>Each process has a <em>trace token</em>, which can be empty or not empty. When not empty, the trace token can be seen as - the tuple <c>{Label, Flags, Serial, From}</c>. The trace token is - passed invisibly with each message.</p> + the tuple <c>{Label, Flags, Serial, From}</c>. The trace token is passed + invisibly to spawned processes and with each message sent.</p> <p>To start a sequential trace, the user must explicitly set the trace token in the process that will send the first message in a sequence.</p> @@ -306,9 +317,10 @@ TimeStamp = {Seconds, Milliseconds, Microseconds} <p>On each Erlang node, a process can be set as the <em>system tracer</em>. This process will receive trace messages each time a message with a trace token is sent or received (if the trace - token flag <c>send</c> or <c>'receive'</c> is set). The system - tracer can then print each trace event, write it to a file, or - whatever suitable.</p> + token flag <c>send</c> or <c>'receive'</c> is set), and when a process + with a non-empty trace token spawns another (if the trace token flag + <c>spawn</c> is set). The system tracer can then print each trace event, + write it to a file, or whatever suitable.</p> <note> <p>The system tracer only receives those trace events that occur locally within the Erlang node. To get the whole picture @@ -322,10 +334,9 @@ TimeStamp = {Seconds, Milliseconds, Microseconds} <section> <title>Trace Token</title> - <p>Each process has a current trace token. Initially, the token is - empty. When the process sends a message to another process, a - copy of the current token is sent "invisibly" along with - the message.</p> + <p>Each process has a current trace token, which is copied from the process + that spawned it. When a process sends a message to another process, a + copy of the current token is sent "invisibly" along with the message.</p> <p>The current token of a process is set in one of the following two ways:</p> <list type="bulleted"> @@ -354,8 +365,9 @@ TimeStamp = {Seconds, Milliseconds, Microseconds} <p>The algorithm for updating <c>Serial</c> can be described as follows:</p> <p>Let each process have two counters, <c>prev_cnt</c> and - <c>curr_cnt</c>, both are set to <c>0</c> when a process is created. - The counters are updated at the following occasions:</p> + <c>curr_cnt</c>, both are set to <c>0</c> when a process is created + outside of a trace sequence. The counters are updated at the following + occasions:</p> <list type="bulleted"> <item> <p><em>When the process is about to send a message and the trace token @@ -370,6 +382,16 @@ tcurr := curr_cnt</pre> passed along with the message.</p> </item> <item> + <p><em>When the process is about to spawn another process and the trace + token is not empty.</em></p> + <p>The counters of the parent process are updated in the same way as + for send above. The trace token is then passed to the child process, + whose counters will be set as follows:</p> + <code> +curr_cnt := tcurr +prev_cnt := tcurr</code> + </item> + <item> <p><em>When the process calls</em> <c>seq_trace:print(Label, Info)</c>, <c>Label</c> <em>matches the label part of the trace token and the trace token print flag is <c>true</c>.</em></p> @@ -487,9 +509,9 @@ tracer() -> print_trace(Label,TraceInfo,false); {seq_trace,Label,TraceInfo,Ts} -> print_trace(Label,TraceInfo,Ts); - Other -> ignore + _Other -> ignore end, - tracer(). + tracer(). print_trace(Label,TraceInfo,false) -> io:format("~p:",[Label]), @@ -504,8 +526,11 @@ print_trace({'receive',Serial,From,To,Message}) -> io:format("~p Received ~p FROM ~p WITH~n~p~n", [To,Serial,From,Message]); print_trace({send,Serial,From,To,Message}) -> - io:format("~p Sent ~p TO ~p WITH~n~p~n", - [From,Serial,To,Message]).</code> + io:format("~p Sent ~p TO ~p WITH~n~p~n", + [From,Serial,To,Message]); +print_trace({spawn,Serial,Parent,Child,_}) -> + io:format("~p Spawned ~p AT ~p~n", + [Parent,Child,Serial]).</code> <p>The code that creates a process that runs this tracer function and sets that process as the system tracer can look like this:</p> <code type="none"> |