Provided by: erlang-manpages_18.3-dfsg-1ubuntu3.1_all 
NAME
seq_trace - Sequential Tracing of Messages
DESCRIPTION
Sequential tracing makes it possible to trace all messages resulting from one initial
message. Sequential tracing is completely independent of the ordinary tracing in Erlang,
which is controlled by the erlang:trace/3 BIF. See the chapter What is Sequential Tracing
below for more information about what sequential tracing is and how it can be used.
seq_trace provides functions which control all aspects of sequential tracing. There are
functions for activation, deactivation, inspection and for collection of the trace output.
Note:
The implementation of sequential tracing is in beta status. This means that the
programming interface still might undergo minor adjustments (possibly incompatible) based
on feedback from users.
DATA TYPES
token() = {integer(), boolean(), term(), term(), term()}
An opaque term (a tuple) representing a trace token.
EXPORTS
set_token(Token) -> PreviousToken | ok
Types:
Token = PreviousToken = [] | token()
Sets the trace token for the calling process to Token. If Token == [] then tracing
is disabled, otherwise Token should be an Erlang term returned from get_token/0 or
set_token/1. set_token/1 can be used to temporarily exclude message passing from
the trace by setting the trace token to empty like this:
OldToken = seq_trace:set_token([]), % set to empty and save
% old value
% do something that should not be part of the trace
io:format("Exclude the signalling caused by this~n"),
seq_trace:set_token(OldToken), % activate the trace token again
...
Returns the previous value of the trace token.
set_token(Component, Val) -> {Component, OldVal}
Types:
Component = component()
Val = OldVal = value()
component() = label | serial | flag()
flag() =
send |
'receive' |
print |
timestamp |
monotonic_timestamp |
strict_monotonic_timestamp
value() =
(Integer :: integer() >= 0) |
{Previous :: integer() >= 0, Current :: integer() >= 0} |
(Bool :: boolean())
Sets the individual Component of the trace token to Val. Returns the previous value
of the component.
set_token(label, Integer):
The label component is an integer which identifies all events belonging to the
same sequential trace. If several sequential traces can be active
simultaneously, label is used to identify the separate traces. Default is 0.
set_token(serial, SerialValue):
SerialValue = {Previous, Current}. The serial component contains counters which
enables the traced messages to be sorted, should never be set explicitly by the
user as these counters are updated automatically. Default is {0, 0}.
set_token(send, Bool):
A trace token flag (true | false) which enables/disables tracing on message
sending. Default is false.
set_token('receive', Bool):
A trace token flag (true | false) which enables/disables tracing on message
reception. Default is false.
set_token(print, Bool):
A trace token flag (true | false) which enables/disables tracing on explicit
calls to seq_trace:print/1. Default is false.
set_token(timestamp, Bool):
A trace token flag (true | false) which enables/disables a timestamp to be
generated for each traced event. Default is false.
set_token(strict_monotonic_timestamp, Bool):
A trace token flag (true | false) which enables/disables a strict monotonic
timestamp to be generated for each traced event. Default is false. Timestamps
will consist of Erlang monotonic time and a monotonically increasing integer.
The time-stamp has the same format and value as produced by
{erlang:monotonic_time(nano_seconds), erlang:unique_integer([monotonic])}.
set_token(monotonic_timestamp, Bool):
A trace token flag (true | false) which enables/disables a strict monotonic
timestamp to be generated for each traced event. Default is false. Timestamps
will use Erlang monotonic time. The time-stamp has the same format and value as
produced by erlang:monotonic_time(nano_seconds).
get_token() -> [] | token()
Returns the value of the trace token for the calling process. If [] is returned, it
means that tracing is not active. Any other value returned is the value of an
active trace token. The value returned can be used as input to the set_token/1
function.
get_token(Component) -> {Component, Val}
Types:
Component = component()
Val = value()
component() = label | serial | flag()
flag() =
send |
'receive' |
print |
timestamp |
monotonic_timestamp |
strict_monotonic_timestamp
value() =
(Integer :: integer() >= 0) |
{Previous :: integer() >= 0, Current :: integer() >= 0} |
(Bool :: boolean())
Returns the value of the trace token component Component. See set_token/2 for
possible values of Component and Val.
print(TraceInfo) -> ok
Types:
TraceInfo = term()
Puts the Erlang term TraceInfo into the sequential trace output if the calling
process currently is executing within a sequential trace and the print flag of the
trace token is set.
print(Label, TraceInfo) -> ok
Types:
Label = integer()
TraceInfo = term()
Same as print/1 with the additional condition that TraceInfo is output only if
Label is equal to the label component of the trace token.
reset_trace() -> true
Sets the trace token to empty for all processes on the local node. The process
internal counters used to create the serial of the trace token is set to 0. The
trace token is set to empty for all messages in message queues. Together this will
effectively stop all ongoing sequential tracing in the local node.
set_system_tracer(Tracer) -> OldTracer
Types:
Tracer = OldTracer = tracer()
tracer() = (Pid :: pid()) | port() | false
Sets the system tracer. The system tracer can be either a process or port denoted
by Tracer. Returns the previous value (which can be false if no system tracer is
active).
Failure: {badarg, Info}} if Pid is not an existing local pid.
get_system_tracer() -> Tracer
Types:
Tracer = tracer()
tracer() = (Pid :: pid()) | port() | false
Returns the pid or port identifier of the current system tracer or false if no
system tracer is activated.
TRACE MESSAGES SENT TO THE SYSTEM TRACER
The format of the messages are:
{seq_trace, Label, SeqTraceInfo, TimeStamp}
or
{seq_trace, Label, SeqTraceInfo}
depending on whether the timestamp flag of the trace token is set to true or false. Where:
Label = int()
TimeStamp = {Seconds, Milliseconds, Microseconds}
Seconds = Milliseconds = Microseconds = int()
The SeqTraceInfo can have the following formats:
{send, Serial, From, To, Message}:
Used when a process From with its trace token flag print set to true has sent a
message.
{'receive', Serial, From, To, Message}:
Used when a process To receives a message with a trace token that has the 'receive'
flag set to true.
{print, Serial, From, _, Info}:
Used when a process From has called seq_trace:print(Label, TraceInfo) and has a trace
token with the print flag set to true and label set to Label.
Serial is a tuple {PreviousSerial, ThisSerial}, where the first integer PreviousSerial
denotes the serial counter passed in the last received message which carried a trace
token. If the process is the first one in a new sequential trace, PreviousSerial is set to
the value of the process internal "trace clock". The second integer ThisSerial is the
serial counter that a process sets on outgoing messages and it is based on the process
internal "trace clock" which is incremented by one before it is attached to the trace
token in the message.
WHAT IS SEQUENTIAL TRACING
Sequential tracing is a way to trace a sequence of messages sent between different local
or remote processes, where the sequence is initiated by one single message. In short it
works like this:
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.
In order 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.
The trace token of a process is set each time the process matches a message in a receive
statement, according to the trace token carried by the received message, empty or not.
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.
Note:
The system tracer will only receive those trace events that occur locally within the
Erlang node. To get the whole picture of a sequential trace that involves processes on
several Erlang nodes, the output from the system tracer on each involved node must be
merged (off line).
In the following sections Sequential Tracing and its most fundamental concepts are
described.
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 will be sent "invisibly"
along with the message.
The current token of a process is set in two ways, either
* explicitly by the process itself, through a call to seq_trace:set_token, or
* when a message is received.
In both cases the current token will be set. In particular, if the token of a message
received is empty, the current token of the process is set to empty.
A trace token contains a label, and a set of flags. Both the label and the flags are set
in 1 and 2 above.
SERIAL
The trace token contains a component which is called serial. It consists of two integers
Previous and Current. The purpose is to uniquely identify each traced event within a trace
sequence and to order the messages chronologically and in the different branches if any.
The algorithm for updating Serial can be described as follows:
Let each process have two counters prev_cnt and curr_cnt which both are set to 0 when a
process is created. The counters are updated at the following occasions:
* When the process is about to send a message and the trace token is not empty.
Let the serial of the trace token be tprev and tcurr.
curr_cnt := curr_cnt + 1
tprev := prev_cnt
tcurr := curr_cnt
The trace token with tprev and tcurr is then passed along with the message.
* When the process callsseq_trace:print(Label, Info), Label matches the label part of
the trace token and the trace token print flag is true.
The same algorithm as for send above.
* When a message is received and contains a nonempty trace token.
The process trace token is set to the trace token from the message.
Let the serial of the trace token be tprev and tcurr.
if (curr_cnt < tcurr )
curr_cnt := tcurr
prev_cnt := tcurr
The curr_cnt of a process is incremented each time the process is involved in a sequential
trace. The counter can reach its limit (27 bits) if a process is very long-lived and is
involved in much sequential tracing. If the counter overflows it will not be possible to
use the serial for ordering of the trace events. To prevent the counter from overflowing
in the middle of a sequential trace the function seq_trace:reset_trace/0 can be called to
reset the prev_cnt and curr_cnt of all processes in the Erlang node. This function will
also set all trace tokens in processes and their message queues to empty and will thus
stop all ongoing sequential tracing.
PERFORMANCE CONSIDERATIONS
The performance degradation for a system which is enabled for Sequential Tracing is
negligible as long as no tracing is activated. When tracing is activated there will of
course be an extra cost for each traced message but all other messages will be unaffected.
PORTS
Sequential tracing is not performed across ports.
If the user for some reason wants to pass the trace token to a port this has to be done
manually in the code of the port controlling process. The port controlling processes have
to check the appropriate sequential trace settings (as obtained from seq_trace:get_token/1
and include trace information in the message data sent to their respective ports.
Similarly, for messages received from a port, a port controller has to retrieve trace
specific information, and set appropriate sequential trace flags through calls to
seq_trace:set_token/2.
DISTRIBUTION
Sequential tracing between nodes is performed transparently. This applies to C-nodes built
with Erl_Interface too. A C-node built with Erl_Interface only maintains one trace token,
which means that the C-node will appear as one process from the sequential tracing point
of view.
In order to be able to perform sequential tracing between distributed Erlang nodes, the
distribution protocol has been extended (in a backward compatible way). An Erlang node
which supports sequential tracing can communicate with an older (OTP R3B) node but
messages passed within that node can of course not be traced.
EXAMPLE OF USAGE
The example shown here will give rough idea of how the new primitives can be used and what
kind of output it will produce.
Assume that we have an initiating process with Pid == <0.30.0> like this:
-module(seqex).
-compile(export_all).
loop(Port) ->
receive
{Port,Message} ->
seq_trace:set_token(label,17),
seq_trace:set_token('receive',true),
seq_trace:set_token(print,true),
seq_trace:print(17,"**** Trace Started ****"),
call_server ! {self(),the_message};
{ack,Ack} ->
ok
end,
loop(Port).
And a registered process call_server with Pid == <0.31.0> like this:
loop() ->
receive
{PortController,Message} ->
Ack = {received, Message},
seq_trace:print(17,"We are here now"),
PortController ! {ack,Ack}
end,
loop().
A possible output from the system's sequential_tracer (inspired by AXE-10 and MD-110)
could look like:
17:<0.30.0> Info {0,1} WITH
"**** Trace Started ****"
17:<0.31.0> Received {0,2} FROM <0.30.0> WITH
{<0.30.0>,the_message}
17:<0.31.0> Info {2,3} WITH
"We are here now"
17:<0.30.0> Received {2,4} FROM <0.31.0> WITH
{ack,{received,the_message}}
The implementation of a system tracer process that produces the printout above could look
like this:
tracer() ->
receive
{seq_trace,Label,TraceInfo} ->
print_trace(Label,TraceInfo,false);
{seq_trace,Label,TraceInfo,Ts} ->
print_trace(Label,TraceInfo,Ts);
Other -> ignore
end,
tracer().
print_trace(Label,TraceInfo,false) ->
io:format("~p:",[Label]),
print_trace(TraceInfo);
print_trace(Label,TraceInfo,Ts) ->
io:format("~p ~p:",[Label,Ts]),
print_trace(TraceInfo).
print_trace({print,Serial,From,_,Info}) ->
io:format("~p Info ~p WITH~n~p~n", [From,Serial,Info]);
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]).
The code that creates a process that runs the tracer function above and sets that process
as the system tracer could look like this:
start() ->
Pid = spawn(?MODULE,tracer,[]),
seq_trace:set_system_tracer(Pid), % set Pid as the system tracer
ok.
With a function like test/0 below the whole example can be started.
test() ->
P = spawn(?MODULE, loop, [port]),
register(call_server, spawn(?MODULE, loop, [])),
start(),
P ! {port,message}.