From 92bd7d3e43b7142d991f15594d783c1031547df5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?John=20H=C3=B6gberg?= Date: Tue, 19 Mar 2019 21:44:28 +0100 Subject: seq_trace: Fix typo in documentation --- lib/kernel/doc/src/seq_trace.xml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'lib/kernel/doc/src') diff --git a/lib/kernel/doc/src/seq_trace.xml b/lib/kernel/doc/src/seq_trace.xml index aa29223dd0..9aef748594 100644 --- a/lib/kernel/doc/src/seq_trace.xml +++ b/lib/kernel/doc/src/seq_trace.xml @@ -257,7 +257,7 @@ TimeStamp = {Seconds, Milliseconds, Microseconds} {send, Serial, From, To, Message}

Used when a process From with its trace token flag - print set to true has sent a message.

+ send set to true has sent a message.

 {'receive', Serial, From, To, Message} -- cgit v1.2.3 From 2f75782815441a161e6157c941b7f482f96bdbcb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?John=20H=C3=B6gberg?= Date: Tue, 19 Mar 2019 17:39:14 +0100 Subject: 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. --- lib/kernel/doc/src/seq_trace.xml | 55 +++++++++++++++++++++++++++++----------- 1 file changed, 40 insertions(+), 15 deletions(-) (limited to 'lib/kernel/doc/src') 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 false.

 + set_token('spawn', Bool) + +

A trace token flag (true | false) which + enables/disables tracing on process spawning. Default is + false.

+ set_token('receive', Bool)

A trace token flag (true | false) which @@ -259,6 +265,11 @@ TimeStamp = {Seconds, Milliseconds, Microseconds}

Used when a process From with its trace token flag send set to true has sent a message.

 + {spawn, Serial, Parent, Child, _} + +

Used when a process Parent with its trace token flag + spawn set to true has spawned a process.

+ {'receive', Serial, From, To, Message}

Used when a process To 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:

Each process has a trace token, which can be empty or not empty. When not empty, the trace token can be seen as - the tuple {Label, Flags, Serial, From}. The trace token is - passed invisibly with each message.

+ the tuple {Label, Flags, Serial, From}. The trace token is passed + invisibly to spawned processes and with each message sent.

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.

@@ -306,9 +317,10 @@ TimeStamp = {Seconds, Milliseconds, Microseconds}

On each Erlang node, a process can be set as the system tracer. This process will receive trace messages each time a message with a trace token is sent or received (if the trace - token flag send or 'receive' is set). The system - tracer can then print each trace event, write it to a file, or - whatever suitable.

+ token flag send or 'receive' is set), and when a process + with a non-empty trace token spawns another (if the trace token flag + spawn is set). The system tracer can then print each trace event, + write it to a file, or whatever suitable.

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}

Trace Token -

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.

+

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.

The current token of a process is set in one of the following two ways:

@@ -354,8 +365,9 @@ TimeStamp = {Seconds, Milliseconds, Microseconds}

The algorithm for updating Serial can be described as follows:

Let each process have two counters, prev_cnt and - curr_cnt, both are set to 0 when a process is created. - The counters are updated at the following occasions:

+ curr_cnt, both are set to 0 when a process is created + outside of a trace sequence. The counters are updated at the following + occasions:

When the process is about to send a message and the trace token @@ -369,6 +381,16 @@ tcurr := curr_cnt

The trace token with tprev and tcurr is then passed along with the message.

 + +

When the process is about to spawn another process and the trace + token is not empty.

+

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:

+ +curr_cnt := tcurr +prev_cnt := tcurr +

When the process calls seq_trace:print(Label, Info), Label matches the label part of the trace token and the @@ -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]). + 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]).

The code that creates a process that runs this tracer function and sets that process as the system tracer can look like this:

-- cgit v1.2.3