Testing and Telemetry events: how to test if they are sent?

Hello elixir forum,
I’m currently playing with Telemetry and Prometheus and at some point I wonder how to check that the events are sent.

In my code, I have:

def create_user(data) do
    with %Changeset{valid?: true} = changeset <- User.changeset(%User{}, data),
         ...
         {:ok, user} <- GraphRepo.insert(changeset) do
      :telemetry.execute([:user, :create], %{count: 1})
      {:ok, user}
    end

and

def business_logic_metrics do
    [
      counter("user.create.count")
    ]
  end

with Telemetry.Metrics aded in Supervisor and everything’s fine.
But for testing, I added in one of mys test support file:

Telemetry.Metrics.ConsoleReporter.start_link(metrics: business_logic_metrics())

I can now see the output when I launch my test:

[Telemetry.Metrics.ConsoleReporter] Got new event!
Event name: user.create
All measurements: %{count: 1}
All metadata: %{}

Metric measurement: :count (counter)
Tag values: %{}

But is there a way to catch this output and transform it in something I can assert on?
I’ve seen that a IO.device can be specified in ConsoleReporter options but I don’t really understand how I can use it.
The best would be end up with something like this: assert_metrics "user.create", %{count: 1}
My idea would be have a process to work as an IO.device storing every ConsoleReporter output and assert_metrics checking in that process state in the desired event in present.
Is it viable (and do-able)?

Thanks for the help.

2 Likes

You can pretty easily wire up another telemetry handler inside your test and it’ll run inline with the call to execute. From inside there you could do literally anything - send a message, store some state, etc.

https://hexdocs.pm/telemetry/telemetry.html#attach-4

2 Likes

It may be useful as a reference to checkout how telemetry events are tested in Broadway https://github.com/plataformatec/broadway/blob/master/test/broadway_test.exs#L593

1 Like

Thank you both @binaryseed and @akoutmos, I tried to end up with something complicated and you showed a much easier way!

I will mix the broadway approach with tag and an adhoc macro to get something nice.

Ii finally end up with this:

defmodule MyApp.MetricsCase do
  @moduledoc """
  This module defines the setup for tests requiring metrics tests.
  """
  use ExUnit.CaseTemplate

  using do
    quote do
      import Sharon.MetricsCase
    end
  end

  @doc """
  Add a tag for metrics testing.
  Takes a list of metrics as paramater.

  ## Usage

      @tag metrics: [[:my_app, :metrics1], [:my_app, :metrics2, :sub]]
  """
  setup tags do
    if metrics = tags[:metrics] do
      self = self()

      :telemetry.attach_many(
        tags[:test],
        metrics,
        fn name, measurements, metadata, _ ->
          send(self, {:telemetry_event, name, measurements, metadata})
        end,
        nil
      )
    end

    :ok
  end

  @doc """
  Assert that given event has been sent.
  """
  defmacro assert_metrics(name, measurements, metadata \\ %{}),
    do: do_assert_metrics(name, measurements, metadata)

  defp do_assert_metrics(name, measurements, %{}) do
    do_assert_metrics(name, measurements, Macro.escape(%{}))
  end

  defp do_assert_metrics(name, measurements, metadata) do
    quote do
      assert_receive {:telemetry_event, unquote(name), unquote(measurements), unquote(metadata)}
    end
  end
end

which can be used in both test support file and test file.

My example test is now:

@tag metrics: [[:user, :create], [:user, :registration]]
test "user creation ok" do
  Repo.insert!(user_data)
  
  assert_metrics([:user, :create], %{count: 1})
  assert_metrics([:user, :registration], %{count: 1}, %{stage: :creation})
end
2 Likes

I’ve came to a new solution that solve the problem of mixing telemetry events and metrics.
The previous solution use assert_metrics to check if a particular Telemetry events occured, which could cause some confusion.
Additionally, I wanted to also test for metrics produced by Telemetry.Metrics, the here is the final test support file:

defmodule MayApp.MetricsCase do
  @moduledoc """
  This module defines the setup for tests requiring metrics tests.

  Available tags:
    - `telemetry_events`: list the Telemetry events to listen
    - `metrics`: Specify the list of Telemetry.Metrics to used (format: [Module, :function, [args]])

  Available assertions:
    - `assert_telemetry_event(name, measurements, metadata \\ %{})`
    - `assert_metric(name, measurement, metadata \\ %{})`

  ## Example:

  @tag telemetry_events: [[:user, :subscription, :email_confirmation]],
       metrics: [MayApp.Metrics, :metrics, []]
  test "my test" do
    ...
    assert_telemetry_event([:user, :subscription, :email_confirmation], %{count: 1}, %{result: :error})
    assert_metric([:user, :subscription, :email_confirmation, :count], 1, %{success: false})
  end

  """
  use ExUnit.CaseTemplate

  using do
    quote do
      import MayApp.MetricsCase
    end
  end

  setup tags do
    if telemetry_events = tags[:telemetry_events] do
      metrics = get_metrics_from_tag(tags)

      self = self()

      groups = Enum.group_by(metrics, & &1.event_name)

      :telemetry.attach_many(
        tags[:test],
        telemetry_events,
        fn name, measurements, metadata, _config ->
          send(self, {:telemetry_event, name, measurements, metadata})

          # Send related metrics
          if Enum.count(metrics) > 0 do
            Enum.each(Map.get(groups, name, []), fn metric ->
              send(
                self,
                {:metric, metric.name, Map.get(measurements, metric.measurement),
                 extract_tags(metric, metadata)}
              )
            end)
          end
        end,
        nil
      )
    end

    :ok
  end

  defp extract_tags(metric, metadata) do
    tag_values = metric.tag_values.(metadata)
    Map.take(tag_values, metric.tags)
  end

  defp get_metrics_from_tag(%{metrics: [m, f, args]}) do
    apply(m, f, args)
  end

  defp get_metrics_from_tag(_) do
    []
  end

  @doc """
  Assert that given event has been sent.
  """
  defmacro assert_telemetry_event(name, measurements, metadata \\ %{}),
    do: do_assert_telemetry_event(name, measurements, metadata)

  defp do_assert_telemetry_event(name, measurements, %{}) do
    do_assert_telemetry_event(name, measurements, Macro.escape(%{}))
  end

  defp do_assert_telemetry_event(name, measurements, metadata) do
    do_assert_receive(:telemetry_event, name, measurements, metadata)
  end

  defmacro assert_metric(name, measurement, metadata \\ %{}),
    do: do_assert_metric(name, measurement, metadata)

  defp do_assert_metric(name, measurement, %{}) do
    do_assert_metric(name, measurement, Macro.escape(%{}))
  end

  defp do_assert_metric(name, measurement, metadata) do
    do_assert_receive(:metric, name, measurement, metadata)
  end

  defp do_assert_receive(msg_type, name, measurement, metadata) do
    quote do
      assert_receive {unquote(msg_type), unquote(name), unquote(measurement), unquote(metadata)}
    end
  end
end

Hope this will help other with the same need of testing both telemetry events and telemetry.metrics

5 Likes

test_helper.exs

defmodule Telemetry do
  @moduledoc """
  defmodule TelemetryTest do
    use ExUnit.Case

    defmodule Broadcaster do

      def fun_a do
        :telemetry.execute([:a], %{measurement: :a}, %{metadata: :a})
        true
      end
    
      def fun_b do
        :telemetry.execute([:b, :c], %{measurement: :b}, %{metadata: :c})
        true
      end
    
    end

    describe "stuff expecting telemetry messages" do

      setup do
        Telemetry.attach(__ENV__, [[:a], [:b, :c]])
      end

      test "fun_a/0 sends telemetry message" do
        assert Broadcaster.fun_a()
        assert_receive {:telemetry, [:a], %{measurement: :a}, %{metadata: :a}}
      end

      test "fun_b/0 sends telemetry message" do
        assert Broadcaster.fun_b()
        assert_receive {:telemetry, [:b, :c], %{measurement: :b}, %{metadata: :c}}
      end

    end

  end
  """

  def attach(%{module: module, line: line}, events, verbose \\ false) do
    handler = fn event, measurements, metadata, _config ->
      msg = {:telemetry, event, measurements, metadata}
      if verbose, do: IO.inspect msg
      send self(), msg
    end
    :telemetry.attach_many("#{module}_#{line}", events, handler, nil)
    :ok
  end

end

ExUnit.start()