Merge pull request #466 from newrelic/vince/auto-error-backend

Use logger primary filter to hook into error reporting

README.md

@@ -72,16 +72,6 @@ config :new_relic_agent,
   httpc_request_options: [connect_timeout: 5000]
 ```
 
-#### For Elixir 1.15 and higher
-
-Due to changes in the Elixir 1.15 Logger, additional logger configuration is needed for NewRelic to capture all errors. Update your logger configuration by setting `handle_sasl_reports` to `true` and adding `NewRelic.ErrorLogger` to your logger backends.
-
-```elixir
-config :logger,
-  handle_sasl_reports: true,
-  backends: [:console, NewRelic.ErrorLogger]
-```
-
 ## Telemetry-based Instrumentation
 
 Some common Elixir packages are auto-instrumented via [`telemetry`](https://github.com/beam-telemetry/telemetry)

config/config.exs

@@ -1,8 +1,4 @@
 import Config
 
-config :logger,
-  handle_sasl_reports: true,
-  backends: [NewRelic.ErrorLogger]
-
 if Mix.env() == :test, do: import_config("test.exs")
 if File.exists?("config/secret.exs"), do: import_config("secret.exs")

lib/new_relic/error/logger_filter.ex

@@ -0,0 +1,62 @@
+defmodule NewRelic.Error.LoggerFilter do
+  @moduledoc false
+
+  # Track errors by attaching a `:logger` primary filter
+  # Always returns `:ignore` so we don't actually filter anything
+
+  def add_filter() do
+    :logger.add_primary_filter(__MODULE__, {&__MODULE__.filter/2, []})
+  end
+
+  def remove_filter() do
+    :logger.remove_primary_filter(__MODULE__)
+  end
+
+  def filter(
+        %{
+          meta: %{error_logger: %{type: :crash_report}},
+          msg: {:report, %{report: [report | _]}}
+        },
+        _opts
+      ) do
+    if NewRelic.Transaction.Sidecar.tracking?() do
+      NewRelic.Error.Reporter.CrashReport.report_error(:transaction, report)
+    else
+      NewRelic.Error.Reporter.CrashReport.report_error(:process, report)
+    end
+
+    :ignore
+  end
+
+  if NewRelic.Util.ConditionalCompile.match?("< 1.15.0") do
+    def filter(
+          %{
+            meta: %{error_logger: %{tag: :error_msg}},
+            msg: {:report, %{label: {_, :terminating}}}
+          },
+          _opts
+        ) do
+      :ignore
+    end
+  end
+
+  def filter(
+        %{
+          meta: %{error_logger: %{tag: :error_msg}},
+          msg: {:report, %{report: %{} = report}}
+        },
+        _opts
+      ) do
+    if NewRelic.Transaction.Sidecar.tracking?() do
+      NewRelic.Error.Reporter.ErrorMsg.report_error(:transaction, report)
+    else
+      NewRelic.Error.Reporter.ErrorMsg.report_error(:process, report)
+    end
+
+    :ignore
+  end
+
+  def filter(_log, _opts) do
+    :ignore
+  end
+end

lib/new_relic/error/reporter.ex → lib/new_relic/error/reporter/crash_report.ex

@@ -1,4 +1,4 @@
-defmodule NewRelic.Error.Reporter do
+defmodule NewRelic.Error.Reporter.CrashReport do
   @moduledoc false
 
   alias NewRelic.Util

lib/new_relic/error/metadata_reporter.ex → lib/new_relic/error/reporter/error_msg.ex

@@ -1,32 +1,26 @@
-defmodule NewRelic.Error.MetadataReporter do
+defmodule NewRelic.Error.Reporter.ErrorMsg do
   @moduledoc false
 
   alias NewRelic.Util
   alias NewRelic.Harvest.Collector
 
-  # Before elixir 1.15, ignore terminating errors so they don't get reported twice
-  if NewRelic.Util.ConditionalCompile.match?("< 1.15.0") do
-    def report_error(_, {{_, :terminating}, _}), do: nil
-  end
-
-  def report_error(:transaction, {_cause, metadata}) do
-    kind = :error
-    {exception, stacktrace} = metadata.reason
-    process_name = parse_process_name(metadata[:registered_name], stacktrace)
+  def report_error(:transaction, report) do
+    {exception, stacktrace} = report.reason
+    process_name = parse_process_name(report[:registered_name], stacktrace)
 
     NewRelic.add_attributes(process: process_name)
 
     NewRelic.Transaction.Reporter.error(%{
-      kind: kind,
+      kind: :error,
       reason: exception,
       stack: stacktrace
     })
   end
 
-  def report_error(:process, {_cause, metadata}) do
-    {exception_type, reason, stacktrace, expected} = parse_reason(metadata.reason)
+  def report_error(:process, report) do
+    {exception_type, reason, stacktrace, expected} = parse_reason(report.reason)
 
-    process_name = parse_process_name(metadata[:registered_name], stacktrace)
+    process_name = parse_process_name(report[:registered_name], stacktrace)
     automatic_attributes = NewRelic.Config.automatic_attributes()
     formatted_stacktrace = Util.Error.format_stacktrace(stacktrace, nil)
 

lib/new_relic/error/supervisor.ex

@@ -16,15 +16,15 @@ defmodule NewRelic.Error.Supervisor do
     ]
 
     if NewRelic.Config.feature?(:error_collector) do
-      add_handler()
+      add_filter()
     end
 
     Supervisor.init(children, strategy: :one_for_one)
   end
 
-  def add_handler(),
-    do: NewRelic.Error.LoggerHandler.add_handler()
+  def add_filter(),
+    do: NewRelic.Error.LoggerFilter.add_filter()
 
-  def remove_handler(),
-    do: NewRelic.Error.LoggerHandler.remove_handler()
+  def remove_filter(),
+    do: NewRelic.Error.LoggerFilter.remove_filter()
 end

lib/new_relic/error_logger.ex

@@ -1,44 +1,16 @@
 defmodule NewRelic.ErrorLogger do
-  @moduledoc """
-  Handle error reporting in elixir >= 1.15
-  """
+  @moduledoc false
+  require Logger
   @behaviour :gen_event
 
-  if NewRelic.Util.ConditionalCompile.match?(">= 1.15.0") do
-    def init(opts) do
-      Logger.add_translator({__MODULE__, :translator})
-      {:ok, opts}
-    end
-  else
-    def init(opts) do
-      {:ok, opts}
-    end
+  def init(_) do
+    Logger.warning("`NewRelic.ErrorLogger` no longer needed, please remove it from :logger configuration")
+    {:ok, nil}
   end
 
   def handle_call(_opts, state), do: {:ok, :ok, state}
-
   def handle_event(_opts, state), do: {:ok, state}
-
   def handle_info(_opts, state), do: {:ok, state}
-
   def code_change(_old_vsn, state, _extra), do: {:ok, state}
-
-  if NewRelic.Util.ConditionalCompile.match?(">= 1.15.0") do
-    def terminate(_reason, _state) do
-      Logger.remove_translator({__MODULE__, :translator})
-      :ok
-    end
-  else
-    def terminate(_reason, _state) do
-      :ok
-    end
-  end
-
-  # Don't log SASL progress reports
-  def translator(_level, _message, _timestamp, {{caller, :progress}, _})
-      when caller in [:supervisor, :application_controller] do
-    :skip
-  end
-
-  def translator(_level, _message, _timestamp, _metadata), do: :none
+  def terminate(_reason, _state), do: :ok
 end

lib/new_relic/graceful_shutdown.ex

@@ -13,7 +13,7 @@ defmodule NewRelic.GracefulShutdown do
 
   def terminate(_reason, _state) do
     NewRelic.log(:info, "Attempting graceful shutdown")
-    NewRelic.Error.Supervisor.remove_handler()
+    NewRelic.Error.Supervisor.remove_filter()
     NewRelic.Harvest.Supervisor.manual_shutdown()
   end
 end

test/error_test.exs

@@ -187,6 +187,7 @@ defmodule ErrorTest do
            end)
   end
 
+  @tag :capture_log
   test "Catch a function clause error inside a Task" do
     TestHelper.restart_harvest_cycle(Collector.TransactionErrorEvent.HarvestCycle)
 

test/error_trace_test.exs

@@ -141,7 +141,7 @@ defmodule ErrorTraceTest do
 
   test "Doesn't report an error if the handler is not installed" do
     TestHelper.restart_harvest_cycle(Collector.ErrorTrace.HarvestCycle)
-    NewRelic.Error.Supervisor.remove_handler()
+    NewRelic.Error.Supervisor.remove_filter()
 
     :proc_lib.spawn(fn ->
       raise "RAISE"
@@ -152,7 +152,7 @@ defmodule ErrorTraceTest do
     traces = TestHelper.gather_harvest(Collector.ErrorTrace.Harvester)
     assert length(traces) == 0
 
-    NewRelic.Error.Supervisor.add_handler()
+    NewRelic.Error.Supervisor.add_filter()
 
     :proc_lib.spawn(fn ->
       raise "RAISE"

test/metric_transaction_test.exs

@@ -160,7 +160,7 @@ defmodule MetricTransactionTest do
 
     metrics = TestHelper.gather_harvest(Collector.Metric.Harvester)
 
-    assert [_, [1, time, time, time, time, 0.0]] =
+    assert [_, [1, time, time, time, time, _]] =
              TestHelper.find_metric(metrics, "WebFrontend/QueueTime")
 
     assert_in_delta time, 0.1, 0.02

test/transaction_error_event_test.exs

@@ -148,6 +148,7 @@ defmodule TransactionErrorEventTest do
     assert_receive {:DOWN, _ref, _, ^second, :shutdown}, 1000
   end
 
+  @tag :capture_log
   test "instrument & harvest" do
     TestHelper.restart_harvest_cycle(Collector.TransactionEvent.HarvestCycle)
     TestHelper.restart_harvest_cycle(Collector.TransactionErrorEvent.HarvestCycle)
@@ -179,6 +180,7 @@ defmodule TransactionErrorEventTest do
     TestHelper.pause_harvest_cycle(Collector.Metric.HarvestCycle)
   end
 
+  @tag :capture_log
   test "cowboy request process exit" do
     TestHelper.restart_harvest_cycle(Collector.ErrorTrace.HarvestCycle)
     Logger.remove_backend(:console)
@@ -211,6 +213,7 @@ defmodule TransactionErrorEventTest do
     TestHelper.pause_harvest_cycle(Collector.TransactionErrorEvent.HarvestCycle)
   end
 
+  @tag :capture_log
   test "Report a nested error inside the transaction if we catch it" do
     Logger.remove_backend(:console)
     TestHelper.restart_harvest_cycle(Collector.ErrorTrace.HarvestCycle)