How to use recon_trace.calls properly?

Background

I have an app that prints out the following error every few seconds:

=ERROR REPORT==== 17-Jun-2019::13:50:08.172872 ===
Unexpected message: {#Ref<0.2741279221.3080978449.3817>,badarg}

I am trying to find out where it comes from.

Research done

Upon reading the message, I was convinced it originated from a missing handle_info somewhere. So I tested my theory by running the following recon_trace command:

:code.all_loaded()                                                # returns  list of {module_name, path} tuples, containing all modules in the app
|> Stream.map(fn({module, _path}) -> module end)                  # we just want the module_name
|> Stream.filter(&:erlang.function_exported(&1, :handle_info, 2)) # verifies if the given module has a :handle_info/2 callback
|> Stream.map(&{&1, :handle_info, :_})                            # returns a tuple of {module_name, :handle_info, :_}  
|> Enum.map(&:recon_trace.calls(&1, 100))                         # uses recon to trace and print the first 100 calls, from all modules to :handle_info 

In theory, this code should print the first 100 calls to :handle_info for all modules. However, it is only printing information about memsup.

memsup:handle_info(time_to_collect, {state,{unix,linux},
       true,
       {3541655552,31605788672},
       {<0.7027.0>,12120624},
       false,60000,30000,0.8,0.05,<0.286.0>,undefined,undefined,[],[]})

Question

This either means that :memsup is the only process making use of :handle_info (and I know this is false because we have several processes that make use of :handle_info) or the code I posted above is incorrect.

What am I doing wrong?

1 Like

It looks right to me. Did you throw in some intermediary IO.inspect calls to make sure your outputs are what you expect? I think the last line would be a good one. Enum.map(&(:recon_trace.calls(&1 |> IO.inspect(), 100))

From my experiments, you can only have a single trace. Therefore do as I suggested in the other thread, pass a list of tspec rather than create a trace for each tspec

trace_specs = :code.all_loaded()
|> Stream.map(fn({module, _path}) -> module end)
|> Stream.filter(&:erlang.function_exported(&1, :handle_info, 2))
|> Stream.map(&{&1, :handle_info, :_})

:recon_trace.calls(trace_specs, 100)
3 Likes

I didn’t realize you could only have one trace call going. What about using :_ for the module?

Seems to be not possible:

The mod type shows that it can be. https://ferd.github.io/recon/recon_trace.html#type-mod

It is also part of the tspec that is used. https://ferd.github.io/recon/recon_trace.html#type-tspec

I guess I should just try it.

Well, @Fl4m3Ph03n1xhas tried and it didn’t work… Just read earlier posts in the linked thread