From 9571519e532bf38fb3168bd73f16b380e6dd0f0c Mon Sep 17 00:00:00 2001 From: Juan P Barrios Date: Sat, 23 Mar 2024 15:21:47 +0200 Subject: [PATCH 1/3] Log measurement name with conversion fun name --- lib/telemetry_metrics/console_reporter.ex | 11 +++++- test/console_reporter_test.exs | 44 +++++++++++++++++++++-- 2 files changed, 51 insertions(+), 4 deletions(-) diff --git a/lib/telemetry_metrics/console_reporter.ex b/lib/telemetry_metrics/console_reporter.ex index b128656..eaa10a0 100644 --- a/lib/telemetry_metrics/console_reporter.ex +++ b/lib/telemetry_metrics/console_reporter.ex @@ -85,7 +85,7 @@ defmodule Telemetry.Metrics.ConsoleReporter do for %struct{} = metric <- metrics do header = """ - Metric measurement: #{inspect(metric.measurement)} (#{metric(struct)}) + Metric measurement: #{measurement_name(metric)} (#{metric(struct)}) """ [ @@ -133,6 +133,15 @@ defmodule Telemetry.Metrics.ConsoleReporter do IO.puts(device, [prelude | parts]) end + defp measurement_name(%{measurement: measurement}) when is_atom(measurement), + do: inspect(measurement) + + defp measurement_name(%{measurement: fun, name: name}) when is_function(fun) do + measurement = List.last(name) + + "#{inspect(measurement)} [via #{inspect(fun)}]" + end + defp keep?(%{keep: nil}, _metadata), do: true defp keep?(metric, metadata), do: metric.keep.(metadata) diff --git a/test/console_reporter_test.exs b/test/console_reporter_test.exs index a99f03e..9c5be34 100644 --- a/test/console_reporter_test.exs +++ b/test/console_reporter_test.exs @@ -30,7 +30,8 @@ defmodule Telemetry.Metrics.ConsoleReporterTest do ), distribution("phoenix.endpoint.stop.duration", measurement: &__MODULE__.measurement/1 - ) + ), + summary("my_app.repo.query.query_time", unit: {:native, :millisecond}) ] {:ok, device} = StringIO.open("") @@ -158,7 +159,7 @@ defmodule Telemetry.Metrics.ConsoleReporterTest do All measurements: %{} All metadata: %{key: :value} - Metric measurement: &Telemetry.Metrics.ConsoleReporterTest.metadata_measurement/2 (sum) + Metric measurement: :metadata [via &Telemetry.Metrics.ConsoleReporterTest.metadata_measurement/2] (sum) With value: 1 Tag values: %{} @@ -176,10 +177,47 @@ defmodule Telemetry.Metrics.ConsoleReporterTest do All measurements: %{duration: 100} All metadata: %{} - Metric measurement: &Telemetry.Metrics.ConsoleReporterTest.measurement/1 (distribution) + Metric measurement: :duration [via &Telemetry.Metrics.ConsoleReporterTest.measurement/1] (distribution) With value: 100 Tag values: %{} """ end + + test "can convert native system time unit", %{device: device, formatter: formatter} do + event = [:my_app, :repo, :query] + native_time = :erlang.system_time() + + expected_millisecond = native_time * (1 / System.convert_time_unit(1, :millisecond, :native)) + expected_measurement_fun = measurement_fun(event, :query_time, formatter, device) + + :telemetry.execute(event, %{query_time: native_time}) + + {_in, out} = StringIO.contents(device) + + assert out == """ + [Telemetry.Metrics.ConsoleReporter] Got new event! + Event name: my_app.repo.query + All measurements: %{query_time: #{native_time}} + All metadata: %{} + + Metric measurement: :query_time [via #{inspect(expected_measurement_fun)}] (summary) + With value: #{expected_millisecond} millisecond + Tag values: %{} + + """ + end + + defp measurement_fun(event, measurement, formatter, device) do + name = event ++ [measurement] + + event + |> :telemetry.list_handlers() + |> Enum.find_value(fn + %{id: {Telemetry.Metrics.ConsoleReporter, ^event, ^formatter}, config: {config, ^device}} -> + Enum.find_value(config, fn %{name: ^name, measurement: fun} -> + fun + end) + end) + end end From f0c58d7e5ee6667e550c5b1b2355e098ce508534 Mon Sep 17 00:00:00 2001 From: Juan Barrios <03juan@users.noreply.github.com> Date: Sun, 24 Mar 2024 21:27:06 +0200 Subject: [PATCH 2/3] Rename test --- test/console_reporter_test.exs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/test/console_reporter_test.exs b/test/console_reporter_test.exs index 9c5be34..4771e0e 100644 --- a/test/console_reporter_test.exs +++ b/test/console_reporter_test.exs @@ -184,11 +184,12 @@ defmodule Telemetry.Metrics.ConsoleReporterTest do """ end - test "can convert native system time unit", %{device: device, formatter: formatter} do + test "can show metric name and unit conversion fun", %{device: device, formatter: formatter} do event = [:my_app, :repo, :query] native_time = :erlang.system_time() expected_millisecond = native_time * (1 / System.convert_time_unit(1, :millisecond, :native)) + expected_measurement_fun = measurement_fun(event, :query_time, formatter, device) :telemetry.execute(event, %{query_time: native_time}) From 6b30fdf27ee24d22239762ea56096c7b5612e716 Mon Sep 17 00:00:00 2001 From: Juan Barrios <03juan@users.noreply.github.com> Date: Sun, 24 Mar 2024 22:40:11 +0200 Subject: [PATCH 3/3] Type match on measurement function in test helper Pull out the first actual function in case of duplicate measurements --- test/console_reporter_test.exs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/console_reporter_test.exs b/test/console_reporter_test.exs index 4771e0e..027b5a7 100644 --- a/test/console_reporter_test.exs +++ b/test/console_reporter_test.exs @@ -216,7 +216,7 @@ defmodule Telemetry.Metrics.ConsoleReporterTest do |> :telemetry.list_handlers() |> Enum.find_value(fn %{id: {Telemetry.Metrics.ConsoleReporter, ^event, ^formatter}, config: {config, ^device}} -> - Enum.find_value(config, fn %{name: ^name, measurement: fun} -> + Enum.find_value(config, fn %{name: ^name, measurement: fun} when is_function(fun) -> fun end) end)