Merge pull request #355 from getsentry/fix-plug-duplication

fix Plug duplicate error

Author: mitchellhenke

lib/sentry/logger_backend.ex

@@ -36,10 +36,13 @@ defmodule Sentry.LoggerBackend do
       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`.
+    * `:ignore_plug` - Enabling this option will ignore any events that
+      appear to be from a Plug process crashing.  This is to prevent
+      duplicate errors being reported to Sentry alongside `Sentry.Plug`.
   """
   @behaviour :gen_event
 
-  defstruct level: nil, include_logger_metadata: false
+  defstruct level: nil, include_logger_metadata: false, ignore_plug: true
 
   def init(__MODULE__) do
     config = Application.get_env(:logger, __MODULE__, [])
@@ -69,7 +72,7 @@ defmodule Sentry.LoggerBackend do
   end
 
   def handle_event({_level, _gl, {Logger, _msg, _ts, meta}}, state) do
-    %{include_logger_metadata: include_logger_metadata} = state
+    %{include_logger_metadata: include_logger_metadata, ignore_plug: ignore_plug} = state
 
     opts =
       if include_logger_metadata do
@@ -84,12 +87,20 @@ defmodule Sentry.LoggerBackend do
 
     case Keyword.get(meta, :crash_reason) do
       {reason, stacktrace} ->
-        opts =
-          opts
-          |> Keyword.put(:event_source, :logger)
-          |> Keyword.put(:stacktrace, stacktrace)
-
-        Sentry.capture_exception(reason, opts)
+        if ignore_plug &&
+             Enum.any?(stacktrace, fn {module, function, arity, _file_line} ->
+               match?({^module, ^function, ^arity}, {Plug.Cowboy.Handler, :init, 2}) ||
+                 match?({^module, ^function, ^arity}, {Phoenix.Endpoint.Cowboy2Handler, :init, 2})
+             end) do
+          :ok
+        else
+          opts =
+            opts
+            |> Keyword.put(:event_source, :logger)
+            |> Keyword.put(:stacktrace, stacktrace)
+
+          Sentry.capture_exception(reason, opts)
+        end
 
       reason when is_atom(reason) and not is_nil(reason) ->
         Sentry.capture_exception(reason, [{:event_source, :logger} | opts])
@@ -122,9 +133,19 @@ defmodule Sentry.LoggerBackend do
   end
 
   defp init(config, %__MODULE__{} = state) do
-    level = Keyword.get(config, :level)
-    include_logger_metadata = Keyword.get(config, :include_logger_metadata)
-    %{state | level: level, include_logger_metadata: include_logger_metadata}
+    level = Keyword.get(config, :level, state.level)
+
+    include_logger_metadata =
+      Keyword.get(config, :include_logger_metadata, state.include_logger_metadata)
+
+    ignore_plug = Keyword.get(config, :ignore_plug, state.ignore_plug)
+
+    %{
+      state
+      | level: level,
+        include_logger_metadata: include_logger_metadata,
+        ignore_plug: ignore_plug
+    }
   end
 
   defp build_logger_metadata(meta) do

mix.lock

@@ -2,8 +2,8 @@
   "bunt": {:hex, :bunt, "0.2.0", "951c6e801e8b1d2cbe58ebbd3e616a869061ddadcc4863d0a2182541acae9a38", [:mix], [], "hexpm"},
   "bypass": {:hex, :bypass, "1.0.0", "b78b3dcb832a71aca5259c1a704b2e14b55fd4e1327ff942598b4e7d1a7ad83d", [:mix], [{:plug, "~> 1.7", [hex: :plug, repo: "hexpm", optional: false]}, {:plug_cowboy, "~> 1.0 or ~> 2.0", [hex: :plug_cowboy, repo: "hexpm", optional: false]}], "hexpm"},
   "certifi": {:hex, :certifi, "2.5.1", "867ce347f7c7d78563450a18a6a28a8090331e77fa02380b4a21962a65d36ee5", [:rebar3], [{:parse_trans, "~>3.3", [hex: :parse_trans, repo: "hexpm", optional: false]}], "hexpm"},
-  "cowboy": {:hex, :cowboy, "2.6.1", "f2e06f757c337b3b311f9437e6e072b678fcd71545a7b2865bdaa154d078593f", [:rebar3], [{:cowlib, "~> 2.7.0", [hex: :cowlib, repo: "hexpm", optional: false]}, {:ranch, "~> 1.7.1", [hex: :ranch, repo: "hexpm", optional: false]}], "hexpm"},
-  "cowlib": {:hex, :cowlib, "2.7.0", "3ef16e77562f9855a2605900cedb15c1462d76fb1be6a32fc3ae91973ee543d2", [:rebar3], [], "hexpm"},
+  "cowboy": {:hex, :cowboy, "2.6.3", "99aa50e94e685557cad82e704457336a453d4abcb77839ad22dbe71f311fcc06", [:rebar3], [{:cowlib, "~> 2.7.3", [hex: :cowlib, repo: "hexpm", optional: false]}, {:ranch, "~> 1.7.1", [hex: :ranch, repo: "hexpm", optional: false]}], "hexpm"},
+  "cowlib": {:hex, :cowlib, "2.7.3", "a7ffcd0917e6d50b4d5fb28e9e2085a0ceb3c97dea310505f7460ff5ed764ce9", [:rebar3], [], "hexpm"},
   "credo": {:hex, :credo, "1.1.0", "e0c07b2fd7e2109495f582430a1bc96b2c71b7d94c59dfad120529f65f19872f", [:mix], [{:bunt, "~> 0.2.0", [hex: :bunt, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}], "hexpm"},
   "dialyxir": {:hex, :dialyxir, "0.5.1", "b331b091720fd93e878137add264bac4f644e1ddae07a70bf7062c7862c4b952", [:mix], [], "hexpm"},
   "earmark": {:hex, :earmark, "1.3.2", "b840562ea3d67795ffbb5bd88940b1bed0ed9fa32834915125ea7d02e35888a5", [:mix], [], "hexpm"},
@@ -20,8 +20,8 @@
   "parse_trans": {:hex, :parse_trans, "3.3.0", "09765507a3c7590a784615cfd421d101aec25098d50b89d7aa1d66646bc571c1", [:rebar3], [], "hexpm"},
   "phoenix": {:hex, :phoenix, "1.4.0", "56fe9a809e0e735f3e3b9b31c1b749d4b436e466d8da627b8d82f90eaae714d2", [:mix], [{:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: true]}, {:phoenix_pubsub, "~> 1.1", [hex: :phoenix_pubsub, repo: "hexpm", optional: false]}, {:plug, "~> 1.7", [hex: :plug, repo: "hexpm", optional: false]}, {:plug_cowboy, "~> 1.0 or ~> 2.0", [hex: :plug_cowboy, repo: "hexpm", optional: true]}], "hexpm"},
   "phoenix_pubsub": {:hex, :phoenix_pubsub, "1.1.1", "6668d787e602981f24f17a5fbb69cc98f8ab085114ebfac6cc36e10a90c8e93c", [:mix], [], "hexpm"},
-  "plug": {:hex, :plug, "1.7.1", "8516d565fb84a6a8b2ca722e74e2cd25ca0fc9d64f364ec9dbec09d33eb78ccd", [:mix], [{:mime, "~> 1.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}], "hexpm"},
-  "plug_cowboy": {:hex, :plug_cowboy, "2.0.1", "d798f8ee5acc86b7d42dbe4450b8b0dadf665ce588236eb0a751a132417a980e", [:mix], [{:cowboy, "~> 2.5", [hex: :cowboy, repo: "hexpm", optional: false]}, {:plug, "~> 1.7", [hex: :plug, repo: "hexpm", optional: false]}], "hexpm"},
+  "plug": {:hex, :plug, "1.8.2", "0bcce1daa420f189a6491f3940cc77ea7fb1919761175c9c3b59800d897440fc", [:mix], [{:mime, "~> 1.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4", [hex: :telemetry, repo: "hexpm", optional: true]}], "hexpm"},
+  "plug_cowboy": {:hex, :plug_cowboy, "2.1.0", "b75768153c3a8a9e8039d4b25bb9b14efbc58e9c4a6e6a270abff1cd30cbe320", [:mix], [{:cowboy, "~> 2.5", [hex: :cowboy, repo: "hexpm", optional: false]}, {:plug, "~> 1.7", [hex: :plug, repo: "hexpm", optional: false]}], "hexpm"},
   "plug_crypto": {:hex, :plug_crypto, "1.0.0", "18e49317d3fa343f24620ed22795ec29d4a5e602d52d1513ccea0b07d8ea7d4d", [:mix], [], "hexpm"},
   "ranch": {:hex, :ranch, "1.7.1", "6b1fab51b49196860b733a49c07604465a47bdb78aa10c1c16a3d199f7f8c881", [:rebar3], [], "hexpm"},
   "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.4", "f0eafff810d2041e93f915ef59899c923f4568f4585904d010387ed74988e77b", [:make, :mix, :rebar3], [], "hexpm"},

test/logger_backend_test.exs

@@ -149,6 +149,38 @@ defmodule Sentry.LoggerBackendTest do
     end)
   end
 
+  test "only sends one error when a Plug process crashes" do
+    Code.compile_string("""
+      defmodule SentryApp do
+        use Plug.Router
+        use Plug.ErrorHandler
+        use Sentry.Plug
+        plug :match
+        plug :dispatch
+        forward("/", to: Sentry.ExampleApp)
+      end
+    """)
+
+    bypass = Bypass.open()
+    pid = self()
+    modify_env(:sentry, dsn: "http://public:secret@localhost:#{bypass.port}/1")
+
+    {:ok, _plug_pid} = Plug.Cowboy.http(SentryApp, [], port: 8003)
+
+    Bypass.expect(bypass, fn conn ->
+      {:ok, body, conn} = Plug.Conn.read_body(conn)
+      _json = Jason.decode!(body)
+      send(pid, "API called")
+      Plug.Conn.resp(conn, 200, ~s<{"id": "340"}>)
+    end)
+
+    capture_log(fn ->
+      :hackney.get("http://127.0.0.1:8003/error_route", [], "", [])
+      assert_receive "API called"
+      refute_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)

test/plug_test.exs

@@ -44,7 +44,7 @@ defmodule Sentry.PlugTest do
 
     conn = conn(:post, "/error_route", %{})
 
-    assert_raise(RuntimeError, "Error", fn ->
+    assert_raise(Plug.Conn.WrapperError, "** (RuntimeError) Error", fn ->
       OverrideApp.call(conn, [])
     end)
 
@@ -75,7 +75,7 @@ defmodule Sentry.PlugTest do
 
     modify_env(:sentry, dsn: "http://public:secret@localhost:#{bypass.port}/1")
 
-    assert_raise(RuntimeError, "Error", fn ->
+    assert_raise(Plug.Conn.WrapperError, "** (RuntimeError) Error", fn ->
       conn(:post, "/error_route", %{
         "secret" => "world",
         "password" => "test",
@@ -120,7 +120,7 @@ defmodule Sentry.PlugTest do
     modify_env(:sentry, dsn: "http://public:secret@localhost:#{bypass.port}/1")
     upload = %Plug.Upload{path: "test/fixtures/my_image.png", filename: "my_image.png"}
 
-    assert_raise(RuntimeError, "Error", fn ->
+    assert_raise(Plug.Conn.WrapperError, "** (RuntimeError) Error", fn ->
       conn(:post, "/error_route", %{"image" => upload, "password" => "my_password"})
       |> put_req_cookie("cookie_key", "cookie_value")
       |> put_req_header("accept-language", "en-US")
@@ -154,7 +154,7 @@ defmodule Sentry.PlugTest do
 
     modify_env(:sentry, dsn: "http://public:secret@localhost:#{bypass.port}/1")
 
-    assert_raise(RuntimeError, "Error", fn ->
+    assert_raise(Plug.Conn.WrapperError, "** (RuntimeError) Error", fn ->
       conn(:get, "/error_route")
       |> update_req_cookie("secret", "secretvalue")
       |> update_req_cookie("regular", "value")

test/sources_test.exs

@@ -45,7 +45,7 @@ defmodule Sentry.SourcesTest do
 
     modify_env(:sentry, dsn: "http://public:secret@localhost:#{bypass.port}/1")
 
-    assert_raise(RuntimeError, "Error", fn ->
+    assert_raise(Plug.Conn.WrapperError, "** (RuntimeError) Error", fn ->
       conn(:get, "/error_route")
       |> SourcesApp.call([])
     end)