.TH seq_trace 3erl "kernel 9.2.3" "Ericsson AB" "Erlang Module Definition"
.SH NAME
seq_trace \- Sequential tracing of information transfers.
.SH DESCRIPTION
.LP
Sequential tracing makes it possible to trace information flows between processes resulting from one initial transfer of information\&. Sequential tracing is independent of the ordinary tracing in Erlang, which is controlled by the \fIerlang:trace/3\fR\& BIF\&. For more information about what sequential tracing is and how it can be used, see section Sequential Tracing\&.
.LP
\fIseq_trace\fR\& provides functions that control all aspects of sequential tracing\&. There are functions for activation, deactivation, inspection, and for collection of the trace output\&.
.SH DATA TYPES
.nf

\fBtoken()\fR\& = {integer(), boolean(), term(), term(), term()}
.br
.fi
.RS
.LP
An opaque term (a tuple) representing a trace token\&.
.RE

.SH EXPORTS
.LP
.nf

.B
set_token(Token) -> PreviousToken | ok
.br
.fi
.br
.RS
.LP
Types:

.RS 3
Token = PreviousToken = [] | token()
.br
.RE
.RE
.RS
.LP
Sets the trace token for the calling process to \fIToken\fR\&\&. If \fIToken == []\fR\& then tracing is disabled, otherwise \fIToken\fR\& should be an Erlang term returned from \fIget_token/0\fR\& or \fIset_token/1\fR\&\&. \fIset_token/1\fR\& can be used to temporarily exclude message passing from the trace by setting the trace token to empty like this:
.LP
.nf

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
\&...  
.fi
.LP
Returns the previous value of the trace token\&.
.RE

.LP
.nf

.B
set_token(Component, Val) -> OldVal
.br
.fi
.br
.RS
.LP
Types:

.RS 3
Component = component()
.br
Val = OldVal = value()
.br
.nf
\fBcomponent()\fR\& = label | serial | flag()
.fi
.br
.nf
\fBflag()\fR\& = 
.br
    send | \&'receive\&' | print | timestamp | monotonic_timestamp |
.br
    strict_monotonic_timestamp
.fi
.br
.nf
\fBvalue()\fR\& = 
.br
    (Label :: term()) |
.br
    {Previous :: integer() >= 0, Current :: integer() >= 0} |
.br
    (Bool :: boolean())
.fi
.br
.RE
.RE
.RS
.LP
Sets the individual \fIComponent\fR\& of the trace token to \fIVal\fR\&\&. Returns the previous value of the component\&.
.RS 2
.TP 2
.B
\fIset_token(label, Label)\fR\&:
The \fIlabel\fR\& component is a term which identifies all events belonging to the same sequential trace\&. If several sequential traces can be active simultaneously, \fIlabel\fR\& is used to identify the separate traces\&. Default is 0\&.
.LP

.RS -4
.B
Warning:
.RE
Labels were restricted to small signed integers (28 bits) prior to OTP 21\&. The trace token will be silently dropped if it crosses over to a node that does not support the label\&.

.TP 2
.B
\fIset_token(serial, SerialValue)\fR\&:
\fISerialValue = {Previous, Current}\fR\&\&. The \fIserial\fR\& 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 \fI{0, 0}\fR\&\&.
.TP 2
.B
\fIset_token(send, Bool)\fR\&:
A trace token flag (\fItrue | false\fR\&) which enables/disables tracing on information sending\&. Default is \fIfalse\fR\&\&.
.TP 2
.B
\fIset_token(\&'receive\&', Bool)\fR\&:
A trace token flag (\fItrue | false\fR\&) which enables/disables tracing on information reception\&. Default is \fIfalse\fR\&\&.
.TP 2
.B
\fIset_token(print, Bool)\fR\&:
A trace token flag (\fItrue | false\fR\&) which enables/disables tracing on explicit calls to \fIseq_trace:print/1\fR\&\&. Default is \fIfalse\fR\&\&.
.TP 2
.B
\fIset_token(timestamp, Bool)\fR\&:
A trace token flag (\fItrue | false\fR\&) which enables/disables a timestamp to be generated for each traced event\&. Default is \fIfalse\fR\&\&.
.TP 2
.B
\fIset_token(strict_monotonic_timestamp, Bool)\fR\&:
A trace token flag (\fItrue | false\fR\&) which enables/disables a strict monotonic timestamp to be generated for each traced event\&. Default is \fIfalse\fR\&\&. Timestamps will consist of Erlang monotonic time and a monotonically increasing integer\&. The time-stamp has the same format and value as produced by \fI{erlang:monotonic_time(nanosecond), erlang:unique_integer([monotonic])}\fR\&\&.
.TP 2
.B
\fIset_token(monotonic_timestamp, Bool)\fR\&:
A trace token flag (\fItrue | false\fR\&) which enables/disables a strict monotonic timestamp to be generated for each traced event\&. Default is \fIfalse\fR\&\&. Timestamps will use Erlang monotonic time\&. The time-stamp has the same format and value as produced by \fIerlang:monotonic_time(nanosecond)\fR\&\&.
.RE
.LP
If multiple timestamp flags are passed, \fItimestamp\fR\& has precedence over \fIstrict_monotonic_timestamp\fR\& which in turn has precedence over \fImonotonic_timestamp\fR\&\&. All timestamp flags are remembered, so if two are passed and the one with highest precedence later is disabled the other one will become active\&.
.RE

.LP
.nf

.B
get_token() -> [] | token()
.br
.fi
.br
.RS
.LP
Returns the value of the trace token for the calling process\&. If \fI[]\fR\& 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 \fIset_token/1\fR\& function\&.
.RE

.LP
.nf

.B
get_token(Component) -> [] | {Component, Val}
.br
.fi
.br
.RS
.LP
Types:

.RS 3
Component = component()
.br
Val = value()
.br
.nf
\fBcomponent()\fR\& = label | serial | flag()
.fi
.br
.nf
\fBflag()\fR\& = 
.br
    send | \&'receive\&' | print | timestamp | monotonic_timestamp |
.br
    strict_monotonic_timestamp
.fi
.br
.nf
\fBvalue()\fR\& = 
.br
    (Label :: term()) |
.br
    {Previous :: integer() >= 0, Current :: integer() >= 0} |
.br
    (Bool :: boolean())
.fi
.br
.RE
.RE
.RS
.LP
Returns the value of the trace token component \fIComponent\fR\&\&. See set_token/2 for possible values of \fIComponent\fR\& and \fIVal\fR\&\&.
.RE

.LP
.nf

.B
print(TraceInfo) -> ok
.br
.fi
.br
.RS
.LP
Types:

.RS 3
TraceInfo = term()
.br
.RE
.RE
.RS
.LP
Puts the Erlang term \fITraceInfo\fR\& into the sequential trace output if the calling process currently is executing within a sequential trace and the \fIprint\fR\& flag of the trace token is set\&.
.RE

.LP
.nf

.B
print(Label, TraceInfo) -> ok
.br
.fi
.br
.RS
.LP
Types:

.RS 3
Label = integer()
.br
TraceInfo = term()
.br
.RE
.RE
.RS
.LP
Same as \fIprint/1\fR\& with the additional condition that \fITraceInfo\fR\& is output only if \fILabel\fR\& is equal to the label component of the trace token\&.
.RE

.LP
.nf

.B
reset_trace() -> true
.br
.fi
.br
.RS
.LP
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\&.
.RE

.LP
.nf

.B
set_system_tracer(Tracer) -> OldTracer
.br
.fi
.br
.RS
.LP
Types:

.RS 3
Tracer = OldTracer = tracer()
.br
.nf
\fBtracer()\fR\& = 
.br
    (Pid :: pid()) |
.br
    port() |
.br
    (TracerModule :: {module(), term()}) |
.br
    false
.fi
.br
.RE
.RE
.RS
.LP
Sets the system tracer\&. The system tracer can be either a process, port or tracer module denoted by \fITracer\fR\&\&. Returns the previous value (which can be \fIfalse\fR\& if no system tracer is active)\&.
.LP
Failure: \fI{badarg, Info}}\fR\& if \fIPid\fR\& is not an existing local pid\&.
.RE

.LP
.nf

.B
get_system_tracer() -> Tracer
.br
.fi
.br
.RS
.LP
Types:

.RS 3
Tracer = tracer()
.br
.nf
\fBtracer()\fR\& = 
.br
    (Pid :: pid()) |
.br
    port() |
.br
    (TracerModule :: {module(), term()}) |
.br
    false
.fi
.br
.RE
.RE
.RS
.LP
Returns the pid, port identifier or tracer module of the current system tracer or \fIfalse\fR\& if no system tracer is activated\&.
.RE

.SH "TRACE MESSAGES SENT TO THE SYSTEM TRACER"

.LP
The format of the messages is one of the following, depending on if flag \fItimestamp\fR\& of the trace token is set to \fItrue\fR\& or \fIfalse\fR\&:
.LP
.nf

{seq_trace, Label, SeqTraceInfo, TimeStamp}
.fi
.LP
or
.LP
.nf

{seq_trace, Label, SeqTraceInfo}
.fi
.LP
Where:
.LP
.nf

Label = int()
TimeStamp = {Seconds, Milliseconds, Microseconds}  
  Seconds = Milliseconds = Microseconds = int()
.fi
.LP
\fISeqTraceInfo\fR\& can have the following formats:
.RS 2
.TP 2
.B
\fI{send, Serial, From, To, Message}\fR\&:
Used when a process \fIFrom\fR\& with its trace token flag \fIsend\fR\& set to \fItrue\fR\& has sent information\&. \fITo\fR\& may be a process identifier, a registered name on a node represented as \fI{NameAtom, NodeAtom}\fR\&, or a node name represented as an atom\&. \fIFrom\fR\& may be a process identifier or a node name represented as an atom\&. \fIMessage\fR\& contains the information passed along in this information transfer\&. If the transfer is done via message passing, it is the actual message\&.
.TP 2
.B
\fI{\&'receive\&', Serial, From, To, Message}\fR\&:
Used when a process \fITo\fR\& receives information with a trace token that has flag \fI\&'receive\&'\fR\& set to \fItrue\fR\&\&. \fITo\fR\& may be a process identifier, or a node name represented as an atom\&. \fIFrom\fR\& may be a process identifier or a node name represented as an atom\&. \fIMessage\fR\& contains the information passed along in this information transfer\&. If the transfer is done via message passing, it is the actual message\&.
.TP 2
.B
\fI{print, Serial, From, _, Info}\fR\&:
Used when a process \fIFrom\fR\& has called \fIseq_trace:print(Label, TraceInfo)\fR\& and has a trace token with flag \fIprint\fR\& set to \fItrue\fR\&, and \fIlabel\fR\& set to \fILabel\fR\&\&.
.RE
.LP
\fISerial\fR\& is a tuple \fI{PreviousSerial, ThisSerial}\fR\&, where:
.RS 2
.TP 2
*
Integer \fIPreviousSerial\fR\& denotes the serial counter passed in the last received information that carried a trace token\&. If the process is the first in a new sequential trace, \fIPreviousSerial\fR\& is set to the value of the process internal "trace clock"\&.
.LP
.TP 2
*
Integer \fIThisSerial\fR\& is the serial counter that a process sets on outgoing messages\&. 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\&.
.LP
.RE

.SH "SEQUENTIAL TRACING"

.LP
Sequential tracing is a way to trace a sequence of information transfers between different local or remote processes, where the sequence is initiated by a single transfer\&. The typical information transfer is an ordinary Erlang message passed between two processes, but information is transferred also in other ways\&. In short, it works as follows:
.LP
Each process has a \fItrace token\fR\&, which can be empty or not empty\&. When not empty, the trace token can be seen as the tuple \fI{Label, Flags, Serial, From}\fR\&\&. The trace token is passed invisibly when information is passed between processes\&. In most cases the information is passed in ordinary messages between processes, but information is also passed between processes by other means\&. For example, by spawning a new process\&. An information transfer between two processes is represented by a send event and a receive event regardless of how it is passed\&.
.LP
To start a sequential trace, the user must explicitly set the trace token in the process that will send the first information in a sequence\&.
.LP
The trace token of a process is set each time the process receives information\&. This is typically when the process matches a message in a receive statement, according to the trace token carried by the received message, empty or not\&.
.LP
On each Erlang node, a process can be set as the \fIsystem tracer\fR\&\&. This process will receive trace messages each time information with a trace token is sent or received (if the trace token flag \fIsend\fR\& or \fI\&'receive\&'\fR\& is set)\&. The system tracer can then print each trace event, write it to a file, or whatever suitable\&.
.LP

.RS -4
.B
Note:
.RE
The system tracer only receives those trace events that occur locally within the Erlang node\&. To get the whole picture of a sequential trace, involving processes on many Erlang nodes, the output from the system tracer on each involved node must be merged (offline)\&.

.LP
The following sections describe sequential tracing and its most fundamental concepts\&.
.SH "DIFFERENT INFORMATION TRANSFERS"

.LP
Information flows between processes in a lot of different ways\&. Not all flows of information will be covered by sequential tracing\&. One example is information passed via ETS tables\&. Below is a list of information paths that are covered by sequential tracing:
.RS 2
.TP 2
.B
Message Passing:
All ordinary messages passed between Erlang processes\&.
.TP 2
.B
Exit signals:
An exit signal is represented as an \fI{\&'EXIT\&', Pid, Reason}\fR\& tuple\&.
.TP 2
.B
Process Spawn:
A process spawn is represented as multiple information transfers\&. At least one spawn request and one spawn reply\&. The actual amount of information transfers depends on what type of spawn it is and may also change in future implementations\&. Note that this is more or less an internal protocol that you are peeking at\&. The spawn request will be represented as a tuple with the first element containing the atom \fIspawn_request\fR\&, but this is more or less all that you can depend on\&.
.RE
.LP

.RS -4
.B
Note:
.RE
If you do ordinary \fIsend\fR\& or \fIreceive\fR\& trace on the system, you will only see ordinary message passing, not the other information transfers listed above\&.

.LP

.RS -4
.B
Note:
.RE
When a send event and corresponding receive event do not both correspond to ordinary Erlang messages, the \fIMessage\fR\& part of the trace messages may not be identical\&. This since all information not necessarily are available when generating the trace messages\&.

.SH "TRACE TOKEN"

.LP
Each process has a current trace token which is "invisibly" passed from the parent process on creation of the process\&.
.LP
The current token of a process is set in one of the following two ways:
.RS 2
.TP 2
*
Explicitly by the process itself, through a call to \fIseq_trace:set_token/1,2\fR\&
.LP
.TP 2
*
When information is received\&. This is typically when a received message is matched out in a receive expression, but also when information is received in other ways\&.
.LP
.RE

.LP
In both cases, the current token is set\&. In particular, if the token of a received message is empty, the current token of the process is set to empty\&.
.LP
A trace token contains a label and a set of flags\&. Both the label and the flags are set in both alternatives above\&.
.SH "SERIAL"

.LP
The trace token contains a component called \fIserial\fR\&\&. It consists of two integers, \fIPrevious\fR\& and \fICurrent\fR\&\&. The purpose is to uniquely identify each traced event within a trace sequence, as well as to order the messages chronologically and in the different branches, if any\&.
.LP
The algorithm for updating \fISerial\fR\& can be described as follows:
.LP
Let each process have two counters, \fIprev_cnt\fR\& and \fIcurr_cnt\fR\&, both are set to \fI0\fR\& when a process is created outside of a trace sequence\&. The counters are updated at the following occasions:
.RS 2
.TP 2
*
\fIWhen the process is about to pass along information to another process and the trace token is not empty\&.\fR\& This typically occurs when sending a message, but also, for example, when spawning another process\&.
.RS 2
.LP
Let the serial of the trace token be \fItprev\fR\& and \fItcurr\fR\&\&.
.RE

.LP
.nf

curr_cnt := curr_cnt + 1
tprev := prev_cnt
tcurr := curr_cnt
.fi
.RS 2
.LP
The trace token with \fItprev\fR\& and \fItcurr\fR\& is then passed along with the information passed to the other process\&.
.RE

.LP
.TP 2
*
\fIWhen the process calls\fR\& \fIseq_trace:print(Label, Info)\fR\&, \fILabel\fR\& \fImatches the label part of the trace token and the trace token print flag is \fItrue\fR\&\&.\fR\&
.RS 2
.LP
The algorithm is the same as for send above\&.
.RE

.LP
.TP 2
*
\fIWhen information is received that also contains a non-empty trace token\&. For example, when a message is matched out in a receive expression, or when a new process is spawned\&.\fR\&
.RS 2
.LP
The process trace token is set to the trace token from the message\&.
.RE

.RS 2
.LP
Let the serial of the trace token be \fItprev\fR\& and \fItcurr\fR\&\&.
.RE

.LP
.nf

if (curr_cnt < tcurr )
   curr_cnt := tcurr
prev_cnt := tcurr
.fi
.LP
.RE

.LP
\fIcurr_cnt\fR\& 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, the serial for ordering of the trace events cannot be used\&. To prevent the counter from overflowing in the middle of a sequential trace, function \fIseq_trace:reset_trace/0\fR\& can be called to reset \fIprev_cnt\fR\& and \fIcurr_cnt\fR\& of all processes in the Erlang node\&. This function also sets all trace tokens in processes and their message queues to empty, and thus stops all ongoing sequential tracing\&.
.SH "PERFORMANCE CONSIDERATIONS"

.LP
The performance degradation for a system that is enabled for sequential tracing is negligible as long as no tracing is activated\&. When tracing is activated, there is an extra cost for each traced message, but all other messages are unaffected\&.
.SH "PORTS"

.LP
Sequential tracing is not performed across ports\&.
.LP
If the user for some reason wants to pass the trace token to a port, this must 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 \fIseq_trace:get_token/1\fR\&) and include trace information in the message data sent to their respective ports\&.
.LP
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 \fIseq_trace:set_token/2\fR\&\&.
.SH "DISTRIBUTION"

.LP
Sequential tracing between nodes is performed transparently\&. This applies to C-nodes built with \fIErl_Interface\fR\& too\&. A C-node built with \fIErl_Interface\fR\& only maintains one trace token, which means that the C-node appears as one process from the sequential tracing point of view\&.
.SH "EXAMPLE OF USE"

.LP
This example gives a rough idea of how the new primitives can be used and what kind of output it produces\&.
.LP
Assume that you have an initiating process with \fIPid == <0\&.30\&.0>\fR\& like this:
.LP
.nf

-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).
.fi
.LP
And a registered process \fIcall_server\fR\& with \fIPid == <0\&.31\&.0>\fR\& like this:
.LP
.nf

loop() ->
    receive
        {PortController,Message} ->
            Ack = {received, Message},
            seq_trace:print(17,"We are here now"),
            PortController ! {ack,Ack}
    end,
    loop().
.fi
.LP
A possible output from the system\&'s \fIsequential_tracer\fR\& can be like this:
.LP
.nf

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}}
.fi
.LP
The implementation of a system tracer process that produces this printout can look like this:
.LP
.nf

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]).
.fi
.LP
The code that creates a process that runs this tracer function and sets that process as the system tracer can look like this:
.LP
.nf

start() ->
    Pid = spawn(?MODULE,tracer,[]),
    seq_trace:set_system_tracer(Pid), % set Pid as the system tracer 
    ok.
.fi
.LP
With a function like \fItest/0\fR\&, the whole example can be started:
.LP
.nf

test() ->
    P = spawn(?MODULE, loop, [port]),
    register(call_server, spawn(?MODULE, loop, [])),
    start(),
    P ! {port,message}.
.fi