Setting seq_trace on another process

Question

I understand that I can set a seq_trace in erlang to the current process that is executing. But how can I set it on another process from the shell, or remote shell like dbg tracing?

Answer 1

You can enable sequential tracing on another process using dbg. For example, let's say we have a module x with an exported call/2 function:

call(Pid, Msg) ->
    Pid ! {self(), Msg},
    receive      
        {Pid, Reply} -> Reply
    end.

This function implements a simple call-response. Let's also say we have a module y that has a looping receiver function:

loop() ->
    receive
        {Pid, Msg} ->
            seq_trace:print({?MODULE, self(), Pid, Msg}),
            Pid ! {self(), {Msg, os:timestamp()}};
        _ -> ok
    end,
    ?MODULE:loop().

This function expects a message of the form sent by x:call/2, and when it receives one it prints a message into the sequential trace, if enabled, and then sends the original message back to the caller augmented with a timestamp. It ignores all other messages.

We also need a function to collect the sequential trace. The recursive systracer/1 function below just collects seq_trace tuples into a list, and produces the list of seq_trace messages when asked:

systracer(Acc) ->
    receive
        {seq_trace,_,_,_}=S ->
            systracer([S|Acc]);
        {seq_trace,_,_}=S ->
            systracer([S|Acc]);
        {dump, Pid} ->
            Pid ! lists:reverse(Acc),
            systracer([]);
        stop -> ok
    end.

Let's assume our systracer/1 function is exported from module x as well.

Let's use our Erlang shell to set this all up. First, let's spawn y:loop/0 and x:systracer/1:

1> Y = spawn(y,loop,[]).
<0.36.0>
2> S = spawn(x,systracer,[[]]).
<0.38.0>
3> seq_trace:set_system_tracer(S).
false

After spawning x:systracer/1 we set the process as the seq_trace system tracer. Now we need to start dbg:

4> dbg:tracer(), dbg:p(all,call).
{ok,[{matched,nonode@nohost,28}]}

These dbg calls are pretty standard, but you can feel free to vary them as needed especially if you plan to use dbg tracing during your debug session as well.

In practice when you enable sequential tracing with dbg, you typically do so by keying on a particular argument to a function. This enables you to get a trace specific to a given function invocation without getting traces for all invocations of that function. Along these lines, we'll use dbg:tpl/3 to turn on sequential trace flags when x:call/2 is invoked with its second argument having the value of the atom trace. First, we use dbg:fun2ms/1 to create the appropriate match specification to enable the sequential tracing flags we want, then we'll apply the match spec with dbg:tpl/3:

5> Ms = dbg:fun2ms(fun([_,trace]) -> set_seq_token(send,true), set_seq_token('receive',true), set_seq_token(print,true) end).
[{['_',trace],
  [],
  [{set_seq_token,send,true},
   {set_seq_token,'receive',true},
   {set_seq_token,print,true}]}]
6> dbg:tpl(x,call,Ms).
{ok,[{matched,nonode@nohost,1},{saved,1}]}

Now we can call x:call/2 with the second argument trace to cause sequential tracing to occur. We make this call from a spawned process to avoid having shell I/O-related messages appearing in the resulting trace:

7> spawn(fun() -> x:call(Y, trace), x:call(Y, foo) end).
(<0.46.0>) call x:call(<0.36.0>,trace)
<0.46.0>

The first line of output comes from normal dbg tracing, since we specified dbg:p(all, call) earlier. To get the sequential trace results, we need to get a dump from our systrace/1 process:

8> S ! {dump, self()}.
{dump,<0.34.0>}

This sends all sequential trace collected so far to our shell process. We can use the shell flush() command to view them:

9> flush().
Shell got [{seq_trace,0,{send,{0,1},<0.47.0>,<0.36.0>,{<0.47.0>,trace}}},
           {seq_trace,0,{'receive',{0,1},<0.47.0>,<0.36.0>,{<0.47.0>,trace}}},
           {seq_trace,0,{print,{1,2},<0.36.0>,[],{y,<0.36.0>,<0.47.0>,trace}}},
           {seq_trace,0,
                      {send,{1,3},
                            <0.36.0>,<0.47.0>,
                            {<0.36.0>,{trace,{1423,709096,206121}}}}},
           {seq_trace,0,
                      {'receive',{1,3},
                                 <0.36.0>,<0.47.0>,
                                 {<0.36.0>,{trace,{1423,709096,206121}}}}},
           {seq_trace,0,{send,{3,4},<0.47.0>,<0.36.0>,{<0.47.0>,foo}}},
           {seq_trace,0,{'receive',{3,4},<0.47.0>,<0.36.0>,{<0.47.0>,foo}}},
           {seq_trace,0,{print,{4,5},<0.36.0>,[],{y,<0.36.0>,<0.47.0>,foo}}},
           {seq_trace,0,
                      {send,{4,6},
                            <0.36.0>,<0.47.0>,
                            {<0.36.0>,{foo,{1423,709096,206322}}}}},
           {seq_trace,0,
                      {'receive',{4,6},
                                 <0.36.0>,<0.47.0>,
                                 {<0.36.0>,{foo,{1423,709096,206322}}}}}]

And sure enough, these are the sequential trace messages we expected to see. First, for the message containing the trace atom, we have the send from x:call/2 followed by the reception in y:loop/0 and the result of seq_trace:print/1, then the send from y:loop/0 back to the caller of x:call/2. Then, since x:call(Y,foo) is called in the same process, which means all the sequential tracing flags are still enabled, the first set of sequential trace messages is followed by a similar set for the x:call(Y,foo) invocation.

If we just call x:call(Y,foo) we can see we get no sequential trace messages:

10> spawn(fun() -> x:call(Y, foo) end).
<0.55.0>
11> S ! {dump, self()}.
{dump,<0.34.0>}
12> flush().
Shell got []

This is because our match spec enables sequential tracing only when the second argument to x:call/2 is the atom trace.

For more information, see the seq_trace and dbg man pages, and also read the match specification chapter of the Erlang Run-Time System Application (ERTS) User's Guide.