Thursday, October 17, 2013

Tracing OTP processes

Sometimes it is good to know what is happening inside of a gen_server, gen_fsm when things go wrong. We are lucky since OTP has tracing capability for the OTP managed processes. The only thing we need to do is to start the - let us say - gen_server with debug trace options.

gen_server:start_link(?MODULE, [], [{debug, [trace]}]).

It is ok, it works but the problem is that we need to recompile our code and we need to either restart the application or do hot code loading. Sometimes it is not even possible.

When I ran into this problem I felt there might be a better solution.

Sys module

The sys module just solves that problem. It is for debugging system processes. It can modify trace options, set logging, install tracing functions, get the status of the process and many other things.

To illustrate the usage of the sys:trace we have two modules, one is a subscription service and the other is a simple listener. The listener will be a bare process while the subscription service will be a gen_server. Here is the listener.erl



start() ->
    spawn(fun() -> init() end).

init() ->

loop() ->
        {notify, Event} ->
            io:format("Notification: ~p~n", [Event]),
        _ ->

The listener starts and then subscribe to the service with its pid. Then in a loop it just processes notify events it gets.

...and the service.erl


%% exports...

-record(state, {
        pids = []

start() ->
    gen_server:start_link({local, ?MODULE}, ?MODULE,
                          [], []).

subscribe(Pid) ->
    gen_server:call(?MODULE, {subscribe, Pid}).

init(_Args) ->
    {ok, #state{}, 10000}.

handle_call({subscribe, Pid}, _From, State) ->
    #state{pids = Pids} = State,
    {reply, ok,
     State#state{pids = [Pid | Pids]}, 10000}.

handle_info(timeout, #state{pids = Pids} = State) ->
    io:format("Heartbeat, sending notifications~n"),
    [P ! {notify, heartbeat} || P <- Pids],
    {noreply, State, 10000}.

The subscriber sends heartbeat signals after ten seconds idle time. Otherwise it manages the subscriptions of listener processes.

Erlang R15B01 (erts-5.9.1) [source] [64-bit] [smp:4:4] [async-threads:0] [kernel-poll:false]

Eshell V5.9.1  (abort with ^G)
1> service:start().
2> listener:start().
Heartbeat, sending notifications
Notification: heartbeat
3> sys:trace(pid(0,33,0),true).
*DBG* service got timeout
Heartbeat, sending notifications
*DBG* service new state {state,[<0.35.0>]}
Notification: heartbeat

That is nice, we are getting trace information about the gen_server. We can switch it off by calling sys:trace(pid(0, 33, 0), false). Let us see the state of the gen_server.

4> sys:get_status(pid(0, 33, 0)).
         [{header,"Status for generic server service"},
                 {"Logged events",[]}]},

We can see that we have only one listener whose pid is <0,35,0>. If we start a new listener we will see its pid in the pid list of the state record.



Post a Comment

Richard Jonas. Powered by Blogger.

About me

My name is Richárd Jónás, live in Budapest, Hungary. In this blog I want to share my coding experiences in Erlang, Elixir and other languages I use. Some topics are simpler ones but you can use them as a reference. I also present some of my thoughts about developing distributed systems.