Merge pull request #338 from getsentry/logger-metadata

Logger metadata

Author: mitchellhenke

.travis.yml

@@ -3,16 +3,16 @@ elixir:
   - 1.7
   - 1.8
 otp_release:
-  - 20.2
-  - 21.0
+  - 20.3
+  - 21.3
 env:
   - STRICT=true
   - STRICT=false
 matrix:
   exclude:
-    - otp_release: 20.2
+    - otp_release: 20.3
       env: STRICT=true
-    - otp_release: 21.0
+    - otp_release: 21.3
       env: STRICT=false
 notifications:
   email:

CHANGELOG.md

@@ -2,6 +2,9 @@
 
 ## master
 
+* Enhancements
+  * Option to include `Logger.metadata` in `Sentry.LoggerBackend` (#338)
+
 ## 7.0.6 (2019-04-17)
 
 * Enhancements

README.md

@@ -68,6 +68,8 @@ def start(_type, _opts) do
 end
 ```
 
+The backend can also be configured to capture Logger metadata, which is detailed [here](https://hexdocs.pm/sentry/Sentry.LoggerBackend.html).
+
 ### Capture Arbitrary Exceptions
 
 Sometimes you want to capture specific exceptions.  To do so, use `Sentry.capture_exception/2`.

lib/sentry/logger_backend.ex

@@ -1,26 +1,67 @@
 defmodule Sentry.LoggerBackend do
   @moduledoc """
   This module makes use of Elixir 1.7's new Logger metadata to report
-  crashes processes.  It replaces the previous `Sentry.Logger` sytem.
+  crashed processes.  It replaces the previous `Sentry.Logger` sytem.
+
+  To include the backend in your application, the backend can be added in your
+  application file:
+
+    def start(_type, _opts) do
+      children = [
+        supervisor(MyApp.Repo, []),
+        supervisor(MyAppWeb.Endpoint, [])
+      ]
+
+      opts = [strategy: :one_for_one, name: MyApp.Supervisor]
+
+      {:ok, _} = Logger.add_backend(Sentry.LoggerBackend)
+
+      Supervisor.start_link(children, opts)
+    end
+
+  If you are on OTP 21+ and would like to configure the backend to include metadata from
+  `Logger.metadata/0` in reported events, it can be enabled:
+
+      {:ok, _} = Logger.add_backend(Sentry.LoggerBackend)
+      Logger.configure_backend(Sentry.LoggerBackend, include_logger_metadata: true)
+
+
+  It is important to be aware of whether this will include sensitive information
+  in Sentry events before enabling it.
+
+  ## Options
+
+  The supported options are:
+
+    * `:include_logger_metadata` - Enabling this option will read any key/value
+      pairs with with binary, atom or number values from `Logger.metadata/0`
+      and include that dictionary under the `:logger_metadata` key in an
+      event's `:extra` metadata.  This option defaults to `false`.
   """
   @behaviour :gen_event
 
-  defstruct level: nil
+  defstruct level: nil, include_logger_metadata: false
 
   def init(__MODULE__) do
-    config = Application.get_env(:logger, :sentry, [])
+    config = Application.get_env(:logger, __MODULE__, [])
     {:ok, init(config, %__MODULE__{})}
   end
 
   def init({__MODULE__, opts}) when is_list(opts) do
     config =
-      Application.get_env(:logger, :sentry, [])
+      Application.get_env(:logger, __MODULE__, [])
       |> Keyword.merge(opts)
 
     {:ok, init(config, %__MODULE__{})}
   end
 
-  def handle_call({:configure, _options}, state) do
+  def handle_call({:configure, options}, state) do
+    config =
+      Application.get_env(:logger, __MODULE__, [])
+      |> Keyword.merge(options)
+
+    Application.put_env(:logger, __MODULE__, config)
+    state = init(config, state)
     {:ok, :ok, state}
   end
 
@@ -29,16 +70,30 @@ defmodule Sentry.LoggerBackend do
   end
 
   def handle_event({_level, _gl, {Logger, _msg, _ts, meta}}, state) do
+    %{include_logger_metadata: include_logger_metadata} = state
+
+    opts =
+      if include_logger_metadata do
+        [
+          extra: %{
+            logger_metadata: build_logger_metadata(meta)
+          }
+        ]
+      else
+        []
+      end
+
     case Keyword.get(meta, :crash_reason) do
       {reason, stacktrace} ->
         opts =
-          Keyword.put([], :event_source, :logger)
+          opts
+          |> Keyword.put(:event_source, :logger)
           |> Keyword.put(:stacktrace, stacktrace)
 
         Sentry.capture_exception(reason, opts)
 
       reason when is_atom(reason) and not is_nil(reason) ->
-        Sentry.capture_exception(reason, event_source: :logger)
+        Sentry.capture_exception(reason, [{:event_source, :logger} | opts])
 
       _ ->
         :ok
@@ -69,6 +124,15 @@ defmodule Sentry.LoggerBackend do
 
   defp init(config, %__MODULE__{} = state) do
     level = Keyword.get(config, :level)
-    %{state | level: level}
+    include_logger_metadata = Keyword.get(config, :include_logger_metadata)
+    %{state | level: level, include_logger_metadata: include_logger_metadata}
+  end
+
+  defp build_logger_metadata(meta) do
+    meta
+    |> Enum.filter(fn {_key, value} ->
+      is_binary(value) || is_atom(value) || is_number(value)
+    end)
+    |> Enum.into(%{})
   end
 end

test/logger_backend_test.exs

@@ -7,6 +7,7 @@ defmodule Sentry.LoggerBackendTest do
     {:ok, _} = Logger.add_backend(Sentry.LoggerBackend)
 
     ExUnit.Callbacks.on_exit(fn ->
+      Logger.configure_backend(Sentry.LoggerBackend, [])
       :ok = Logger.remove_backend(Sentry.LoggerBackend)
     end)
   end
@@ -147,4 +148,67 @@ defmodule Sentry.LoggerBackendTest do
       assert_receive "API called"
     end)
   end
+
+  if :erlang.system_info(:otp_release) >= '21' do
+    test "includes Logger.metadata when enabled if the key and value are safely JSON-encodable" do
+      Logger.configure_backend(Sentry.LoggerBackend, include_logger_metadata: true)
+      bypass = Bypass.open()
+      Process.flag(:trap_exit, true)
+      pid = self()
+
+      Bypass.expect(bypass, fn conn ->
+        {:ok, body, conn} = Plug.Conn.read_body(conn)
+        json = Jason.decode!(body)
+        assert get_in(json, ["extra", "logger_metadata", "string"]) == "string"
+        assert get_in(json, ["extra", "logger_metadata", "atom"]) == "atom"
+        assert get_in(json, ["extra", "logger_metadata", "number"]) == 43
+        refute Map.has_key?(get_in(json, ["extra", "logger_metadata"]), "list")
+        send(pid, "API called")
+        Plug.Conn.resp(conn, 200, ~s<{"id": "340"}>)
+      end)
+
+      modify_env(:sentry, dsn: "http://public:secret@localhost:#{bypass.port}/1")
+
+      capture_log(fn ->
+        {:ok, pid} = Sentry.TestGenServer.start_link(pid)
+        Sentry.TestGenServer.add_logger_metadata(pid, :string, "string")
+        Sentry.TestGenServer.add_logger_metadata(pid, :atom, :atom)
+        Sentry.TestGenServer.add_logger_metadata(pid, :number, 43)
+        Sentry.TestGenServer.add_logger_metadata(pid, :list, [])
+        Sentry.TestGenServer.invalid_function(pid)
+        assert_receive "terminating"
+        assert_receive "API called"
+      end)
+    end
+
+    test "does not include Logger.metadata when disabled" do
+      Logger.configure_backend(Sentry.LoggerBackend, include_logger_metadata: false)
+      bypass = Bypass.open()
+      Process.flag(:trap_exit, true)
+      pid = self()
+
+      Bypass.expect(bypass, fn conn ->
+        {:ok, body, conn} = Plug.Conn.read_body(conn)
+        json = Jason.decode!(body)
+        refute get_in(json, ["extra", "logger_metadata", "string"]) == "string"
+        refute get_in(json, ["extra", "logger_metadata", "atom"]) == "atom"
+        refute get_in(json, ["extra", "logger_metadata", "number"]) == 43
+        send(pid, "API called")
+        Plug.Conn.resp(conn, 200, ~s<{"id": "340"}>)
+      end)
+
+      modify_env(:sentry, dsn: "http://public:secret@localhost:#{bypass.port}/1")
+
+      capture_log(fn ->
+        {:ok, pid} = Sentry.TestGenServer.start_link(pid)
+        Sentry.TestGenServer.add_logger_metadata(pid, :string, "string")
+        Sentry.TestGenServer.add_logger_metadata(pid, :atom, :atom)
+        Sentry.TestGenServer.add_logger_metadata(pid, :number, 43)
+        Sentry.TestGenServer.add_logger_metadata(pid, :list, [])
+        Sentry.TestGenServer.invalid_function(pid)
+        assert_receive "terminating"
+        assert_receive "API called"
+      end)
+    end
+  end
 end

test/support/test_gen_server.exs

@@ -11,6 +11,10 @@ defmodule Sentry.TestGenServer do
     send(pid, :bad_exit)
   end
 
+  def add_logger_metadata(pid, key, value) do
+    send(pid, {:logger_metadata, key, value})
+  end
+
   def invalid_function(pid) do
     send(pid, :invalid_function)
   end
@@ -32,6 +36,11 @@ defmodule Sentry.TestGenServer do
     {:stop, :bad_exit, state}
   end
 
+  def handle_info({:logger_metadata, key, value}, state) do
+    Logger.metadata([{key, value}])
+    {:noreply, state}
+  end
+
   def handle_info(:invalid_function, state) do
     cond do
       Version.match?(System.version(), ">= 1.5.0") ->