From fcf7b0605e5305409d674091a1553b607ff1767b Mon Sep 17 00:00:00 2001 From: Gonzalo <456459+grzuy@users.noreply.github.com> Date: Tue, 26 Nov 2024 12:09:53 -0300 Subject: [PATCH] feat: reports safelisted contents of Logger.metadata --- lib/tower/event.ex | 12 +++++++++++- mix.exs | 3 ++- test/support/test_app.ex | 6 ++++++ test/support/test_plug.ex | 6 ++++++ test/tower/oban_test.exs | 25 +++++++++++++++++++++++++ test/tower/plug_test.exs | 25 +++++++++++++++++++++++++ test/tower_test.exs | 24 ++++++++++++++++++++++++ 7 files changed, 99 insertions(+), 2 deletions(-) diff --git a/lib/tower/event.ex b/lib/tower/event.ex index 57c7fff..2160daf 100644 --- a/lib/tower/event.ex +++ b/lib/tower/event.ex @@ -133,7 +133,7 @@ defmodule Tower.Event do datetime: event_datetime(log_event), log_event: log_event, plug_conn: plug_conn(options), - metadata: Keyword.get(options, :metadata, %{}), + metadata: Map.merge(logger_metadata(log_event), Keyword.get(options, :metadata, %{})), by: Keyword.get(options, :by) } end @@ -156,6 +156,16 @@ defmodule Tower.Event do Keyword.get(options, :plug_conn, Keyword.get(options, :log_event)[:meta][:conn]) end + defp logger_metadata(log_event) do + (log_event[:meta] || %{}) + |> Map.merge(Enum.into(Logger.metadata(), %{})) + |> Map.take(logger_metadata_keys()) + end + + defp logger_metadata_keys do + Application.fetch_env!(:tower, :logger_metadata) + end + defp put_similarity_id(%__MODULE__{} = event) do struct!(event, similarity_id: :erlang.phash2(Map.take(event, @similarity_source_attributes))) end diff --git a/mix.exs b/mix.exs index e95294a..87d16b6 100644 --- a/mix.exs +++ b/mix.exs @@ -35,7 +35,8 @@ defmodule Tower.MixProject do env: [ reporters: [Tower.EphemeralReporter], log_level: :critical, - ignored_exceptions: [] + ignored_exceptions: [], + logger_metadata: [] ], mod: {Tower.Application, []} ] diff --git a/test/support/test_app.ex b/test/support/test_app.ex index 9cc5db5..a3b6276 100644 --- a/test/support/test_app.ex +++ b/test/support/test_app.ex @@ -3,6 +3,8 @@ defmodule TestApp.UncaughtThrowWorker do @impl Oban.Worker def perform(%Oban.Job{}) do + Logger.metadata(user_id: 123, secret: "secret") + throw("something") :ok @@ -14,6 +16,8 @@ defmodule TestApp.AbnormalExitWorker do @impl Oban.Worker def perform(%Oban.Job{}) do + Logger.metadata(user_id: 123, secret: "secret") + exit(:abnormal) :ok @@ -25,6 +29,8 @@ defmodule TestApp.RuntimeErrorWorker do @impl Oban.Worker def perform(%Oban.Job{}) do + Logger.metadata(user_id: 123, secret: "secret") + raise "error from an Oban worker" :ok diff --git a/test/support/test_plug.ex b/test/support/test_plug.ex index 5ebee86..f930e18 100644 --- a/test/support/test_plug.ex +++ b/test/support/test_plug.ex @@ -5,18 +5,24 @@ defmodule Tower.TestPlug do plug(:dispatch) get "/runtime-error" do + Logger.metadata(user_id: 123, secret: "secret") + raise "an error" send_resp(conn, 200, "OK") end get "/abnormal-exit" do + Logger.metadata(user_id: 123, secret: "secret") + exit(:abnormal) send_resp(conn, 200, "OK") end get "/uncaught-throw" do + Logger.metadata(user_id: 123, secret: "secret") + throw("something") send_resp(conn, 200, "OK") diff --git a/test/tower/oban_test.exs b/test/tower/oban_test.exs index d3ef15d..e65486b 100644 --- a/test/tower/oban_test.exs +++ b/test/tower/oban_test.exs @@ -26,6 +26,8 @@ defmodule TowerObanTest do end test "reports raised exception in an Oban worker" do + put_env(:logger_metadata, [:user_id]) + TestApp.RuntimeErrorWorker.new(%{}, max_attempts: 1) |> Oban.insert() @@ -38,6 +40,7 @@ defmodule TowerObanTest do kind: :error, reason: %RuntimeError{message: "error from an Oban worker"}, stacktrace: stacktrace, + metadata: metadata, by: Tower.ObanExceptionHandler } ] = Tower.EphemeralReporter.events() @@ -46,9 +49,12 @@ defmodule TowerObanTest do assert String.length(id) == 36 assert recent_datetime?(datetime) assert [_ | _] = stacktrace + assert metadata == %{user_id: 123} end test "reports uncaught throw generated in an Oban worker" do + put_env(:logger_metadata, [:user_id]) + TestApp.UncaughtThrowWorker.new(%{}, max_attempts: 1) |> Oban.insert() @@ -61,6 +67,7 @@ defmodule TowerObanTest do kind: :error, reason: %Oban.CrashError{reason: "something"}, stacktrace: stacktrace, + metadata: metadata, by: Tower.ObanExceptionHandler } ] = Tower.EphemeralReporter.events() @@ -69,9 +76,12 @@ defmodule TowerObanTest do assert String.length(id) == 36 assert recent_datetime?(datetime) assert [_ | _] = stacktrace + assert metadata == %{user_id: 123} end test "reports abnormal exit generated in an Oban worker" do + put_env(:logger_metadata, [:user_id]) + TestApp.AbnormalExitWorker.new(%{}, max_attempts: 1) |> Oban.insert() @@ -84,6 +94,7 @@ defmodule TowerObanTest do kind: :error, reason: %Oban.CrashError{reason: :abnormal}, stacktrace: stacktrace, + metadata: metadata, by: Tower.ObanExceptionHandler } ] = Tower.EphemeralReporter.events() @@ -92,6 +103,20 @@ defmodule TowerObanTest do assert String.length(id) == 36 assert recent_datetime?(datetime) assert [_ | _] = stacktrace + assert metadata == %{user_id: 123} + end + + defp put_env(key, value) do + original_value = Application.get_env(:tower, key) + Application.put_env(:tower, key, value) + + on_exit(fn -> + if original_value == nil do + Application.delete_env(:tower, key) + else + Application.put_env(:tower, key, original_value) + end + end) end defp recent_datetime?(datetime) do diff --git a/test/tower/plug_test.exs b/test/tower/plug_test.exs index c992eb0..0dae997 100644 --- a/test/tower/plug_test.exs +++ b/test/tower/plug_test.exs @@ -109,6 +109,8 @@ defmodule TowerPlugTest do end test "reports runtime error during plug dispatch with Bandit" do + put_env(:logger_metadata, [:user_id]) + # An ephemeral port hopefully not being in the host running this code plug_port = 51111 url = "http://127.0.0.1:#{plug_port}/runtime-error" @@ -128,6 +130,7 @@ defmodule TowerPlugTest do kind: :error, reason: %RuntimeError{message: "an error"}, stacktrace: stacktrace, + metadata: metadata, plug_conn: %Plug.Conn{} = plug_conn, by: Tower.LoggerHandler } @@ -137,10 +140,13 @@ defmodule TowerPlugTest do assert String.length(id) == 36 assert recent_datetime?(datetime) assert [_ | _] = stacktrace + assert metadata == %{user_id: 123} assert Plug.Conn.request_url(plug_conn) == url end test "reports uncaught throw during plug dispatch with Bandit" do + put_env(:logger_metadata, [:user_id]) + # An ephemeral port hopefully not being in the host running this code plug_port = 51111 url = "http://127.0.0.1:#{plug_port}/uncaught-throw" @@ -160,6 +166,7 @@ defmodule TowerPlugTest do kind: :throw, reason: "something", stacktrace: stacktrace, + metadata: metadata, plug_conn: %Plug.Conn{} = plug_conn, by: Tower.LoggerHandler } @@ -169,10 +176,13 @@ defmodule TowerPlugTest do assert String.length(id) == 36 assert recent_datetime?(datetime) assert [_ | _] = stacktrace + assert metadata == %{user_id: 123} assert Plug.Conn.request_url(plug_conn) == url end test "reports abnormal exit during plug dispatch with Bandit" do + put_env(:logger_metadata, [:user_id]) + # An ephemeral port hopefully not being in the host running this code plug_port = 51111 url = "http://127.0.0.1:#{plug_port}/abnormal-exit" @@ -192,6 +202,7 @@ defmodule TowerPlugTest do kind: :exit, reason: :abnormal, stacktrace: stacktrace, + metadata: metadata, # Bandit doesn't handle exits so it doesn't provide the conn in the metadata plug_conn: nil, by: Tower.LoggerHandler @@ -202,6 +213,7 @@ defmodule TowerPlugTest do assert String.length(id) == 36 assert recent_datetime?(datetime) assert [_ | _] = stacktrace + assert metadata == %{user_id: 123} end test "reports message plug_conn manually" do @@ -224,6 +236,19 @@ defmodule TowerPlugTest do ) end + defp put_env(key, value) do + original_value = Application.get_env(:tower, key) + Application.put_env(:tower, key, value) + + on_exit(fn -> + if original_value == nil do + Application.delete_env(:tower, key) + else + Application.put_env(:tower, key, original_value) + end + end) + end + defp recent_datetime?(datetime) do diff = :logger.timestamp() diff --git a/test/tower_test.exs b/test/tower_test.exs index b8c3a3e..eb98e8c 100644 --- a/test/tower_test.exs +++ b/test/tower_test.exs @@ -681,6 +681,30 @@ defmodule TowerTest do ) end + test "reports logger metadata" do + put_env(:logger_metadata, [:user_id]) + + capture_log(fn -> + in_unlinked_process(fn -> + Logger.metadata(user_id: 123, secret: "secret") + + raise "an error" + end) + end) + + assert_eventually( + [ + %{ + kind: :error, + reason: %RuntimeError{message: "an error"}, + metadata: metadata + } + ] = reported_events() + ) + + assert metadata == %{user_id: 123} + end + defp in_unlinked_process(fun) when is_function(fun, 0) do {:ok, pid} = Task.Supervisor.start_link()