Skip to content

Commit

Permalink
feat: reports safelisted contents of Logger.metadata
Browse files Browse the repository at this point in the history
  • Loading branch information
grzuy committed Dec 4, 2024
1 parent d13b8a0 commit 81ba6fe
Show file tree
Hide file tree
Showing 9 changed files with 147 additions and 2 deletions.
12 changes: 11 additions & 1 deletion lib/tower/event.ex
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand Down
3 changes: 2 additions & 1 deletion mix.exs
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,8 @@ defmodule Tower.MixProject do
env: [
reporters: [Tower.EphemeralReporter],
log_level: :critical,
ignored_exceptions: []
ignored_exceptions: [],
logger_metadata: []
],
mod: {Tower.Application, []}
]
Expand Down
6 changes: 6 additions & 0 deletions test/support/phoenix_app/home_controller.ex
Original file line number Diff line number Diff line change
Expand Up @@ -6,18 +6,24 @@ defmodule Tower.PhoenixApp.HomeController do
end

def runtime_error(conn, _params) do
Logger.metadata(user_id: 123)

raise "an error"

Plug.Conn.send_resp(conn, 200, "OK")
end

def abnormal_exit(conn, _params) do
Logger.metadata(user_id: 123)

exit(:abnormal)

Plug.Conn.send_resp(conn, 200, "OK")
end

def uncaught_throw(conn, _params) do
Logger.metadata(user_id: 123)

throw("something")

Plug.Conn.send_resp(conn, 200, "OK")
Expand Down
6 changes: 6 additions & 0 deletions test/support/test_app.ex
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand All @@ -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
Expand Down
6 changes: 6 additions & 0 deletions test/support/test_plug.ex
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand Down
25 changes: 25 additions & 0 deletions test/tower/oban_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -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()

Expand All @@ -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()
Expand All @@ -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()

Expand All @@ -61,6 +67,7 @@ defmodule TowerObanTest do
kind: :error,
reason: %Oban.CrashError{reason: "something"},
stacktrace: stacktrace,
metadata: metadata,
by: Tower.ObanExceptionHandler
}
] = Tower.EphemeralReporter.events()
Expand All @@ -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()

Expand All @@ -84,6 +94,7 @@ defmodule TowerObanTest do
kind: :error,
reason: %Oban.CrashError{reason: :abnormal},
stacktrace: stacktrace,
metadata: metadata,
by: Tower.ObanExceptionHandler
}
] = Tower.EphemeralReporter.events()
Expand All @@ -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
Expand Down
25 changes: 25 additions & 0 deletions test/tower/phoenix_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,8 @@ defmodule TowerPhoenixTest do

@tag adapter: :bandit
test "reports runtime error during Phoenix.Endpoint dispatch with Bandit", %{base_url: base_url} do
put_env(:logger_metadata, [:user_id])

url = base_url <> "/runtime-error"

capture_log(fn ->
Expand All @@ -52,6 +54,7 @@ defmodule TowerPhoenixTest do
kind: :error,
reason: %RuntimeError{message: "an error"},
stacktrace: stacktrace,
metadata: metadata,
plug_conn: %Plug.Conn{} = plug_conn,
by: Tower.LoggerHandler
}
Expand All @@ -61,13 +64,16 @@ defmodule TowerPhoenixTest 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

@tag adapter: :bandit
test "reports uncaught throw during Phoenix.Endpoint dispatch with Bandit", %{
base_url: base_url
} do
put_env(:logger_metadata, [:user_id])

url = base_url <> "/uncaught-throw"

capture_log(fn ->
Expand All @@ -83,6 +89,7 @@ defmodule TowerPhoenixTest do
kind: :throw,
reason: "something",
stacktrace: stacktrace,
metadata: metadata,
plug_conn: %Plug.Conn{} = plug_conn,
by: Tower.LoggerHandler
}
Expand All @@ -92,11 +99,14 @@ defmodule TowerPhoenixTest 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

@tag adapter: :bandit
test "reports abnormal exit during Phoenix.Endpoint dispatch with Bandit", %{base_url: base_url} do
put_env(:logger_metadata, [:user_id])

capture_log(fn ->
{:ok, {{_, 500, _}, _, _}} = :httpc.request(base_url <> "/abnormal-exit")
end)
Expand All @@ -110,6 +120,7 @@ defmodule TowerPhoenixTest 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
Expand All @@ -120,6 +131,7 @@ defmodule TowerPhoenixTest do
assert String.length(id) == 36
assert recent_datetime?(datetime)
assert [_ | _] = stacktrace
assert metadata == %{user_id: 123}
end

@tag adapter: :cowboy
Expand All @@ -146,6 +158,19 @@ defmodule TowerPhoenixTest do
assert [] = Tower.EphemeralReporter.events()
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()
Expand Down
Loading

0 comments on commit 81ba6fe

Please sign in to comment.