Stratus3D

A blog on software engineering by Trevor Brown

Show All Telemetry Events in Erlang and Elixir

Telemetry is an Erlang library for dynamically dispatching events to event handlers. Many popular Erlang and Elixir packages use the Telemetry library to emit events. Telemetry event data typically ends up in logs or metric databases like Prometheus.

Events are identified by name. You can register a function as an event handler and get invoked when events with a specific name occur. A name or list of names must be specified when registering a handler using the telemetry:attach/4 and telemetry:attach_many/4 functions.

The Problem

Often it’s not obvious what telemetry events are being generated by a dependency, or even an entire system. Sometimes it is helpful to see all telemetry events the system generates. Unfortunately there is no way to subscribe to ALL events with the telemetry API. We need to know the names of telemetry events before we can register to receive them. And there is no way to get the names of all possible events. Telemetry only invokes handlers registered for a specific event name when emitting an event.

The Solution

Erlang’s tracing features can be used to capture all events emitted. All events are emitted via the telemetry:execute/3 and telemetry:span/3 functions. These two function calls can be traced to get the same event data the telemetry handlers would be invoked with.

To trace these function calls several functions in the dbg module will be used. Tracing all function calls requires invoking these functions with various arguments so it’s easier if we put the tracing code in a function. The function can be named start and a corresponding stop function can be defined to stop tracing telemetry events. It would be nice to have the functions available in the Elixir and Erlang shells when developing locally. It’s pretty easy to do this for both Erlang and Elixir.

For Erlang, copy and paste the following into your user_default module. Note that you’ll need this module compiled before it will be loaded by the Erlang shell:


% telemetry_attach_all/0 prints out all telemetry events received
telemetry_attach_all() ->
  telemetry_attach_all(fun(Name, MetaOrMeasure, MetaOrFun) ->
      % Print out telemetry info
      io:format("Telemetry event: ~w~nwith ~p and ~p~n", [Name, MetaOrMeasure, MetaOrFun])
    end).

% telemetry_attach_all/1 allows you to specify a handler function that
% will be invoked with the same three arguments that the
% `telemetry:execute/3` and `telemetry:span/3` functions were invoked
% with.
telemetry_attach_all(Function) ->
  % Start the dbg tracer
  dbg:start(),

  % Create tracer process with a function that pattern matches out the three arguments the telemetry calls are made with.
  dbg:tracer(process, {fun({_, _, _, {_Mod, _Fun, [Name, MetaOrMeasure, MetaOrFun]}}, _State) ->
      Function(Name, MetaOrMeasure, MetaOrFun)
    end, undefined}),

  % Trace all processes
  dbg:p(all, c),

  % Trace calls to the functions used to emit telemetry events
  dbg:tp(telemetry, execute, 3, []),
  dbg:tp(telemetry, span, 3, []).

telemetry_stop() ->
  dbg:stop_clear().

For Elixir define a module in .iex.exs. Copy and paste the code below into your .iex.exs file:

defmodule TelemetryHelper do
  @moduledoc """
  Helper functions for seeing all telemetry events.
  Only for use in development.
  """

  @doc """
  attach_all/0 prints out all telemetry events received by default.
  Optionally, you can specify a handler function that will be invoked
  with the same three arguments that the `:telemetry.execute/3` and
  `:telemetry.span/3` functions were invoked with.
  """
  def attach_all(function \\ &default_handler_fn/3) do
    # Start the tracer
    :dbg.start()

    # Create tracer process with a function that pattern matches out the three arguments the telemetry calls are made with.
    :dbg.tracer(
      :process,
      {fn
         {_, _, _, {_mod, :execute, [name, measurement, metadata]}}, _state ->
           function.(name, metadata, measurement)

         {_, _, _, {_mod, :span, [name, metadata, span_fun]}}, _state ->
           function.(name, metadata, span_fun)
       end, nil}
    )

    # Trace all processes
    :dbg.p(:all, :c)

    # Trace calls to the functions used to emit telemetry events
    :dbg.tp(:telemetry, :execute, 3, [])
    :dbg.tp(:telemetry, :span, 3, [])
  end

  def stop do
    # Stop tracer
    :dbg.stop_clear()
  end

  defp default_handler_fn(name, metadata, measure_or_fun) do
    # Print out telemetry info
    IO.puts(
      "Telemetry event:#{inspect(name)}\nwith #{inspect(measure_or_fun)} and #{inspect(metadata)}"
    )
  end
end

Once you have added to the code above, start a shell with your application running. Then invoke the attach_all function.

In Erlang:

> telemetry_attach_all()

In Elixir:

> TelemetryHelper.attach_all()

Then interact with the system and you’ll see all trace events printed out. Then when finished stop the tracing:

In Erlang:

> telemetry_stop()

In Elixir:

> TelemetryHelper.stop()

Conclusion

The downside to this approach is that it relies on tracing so it’s not suitable for use in application code. But it’s great for use in development. Tracing is an easy way to grab data that is passing through any system on the Erlang virtual machine. It’s an invaluable tool that can speed up debugging in many different situations.

References