no logging from logger and client error refactor

Author: mitchellhenke

lib/sentry/client.ex

@@ -56,6 +56,7 @@ defmodule Sentry.Client do
   Attempts to send the event to the Sentry API up to 4 times with exponential backoff.
 
   The event is dropped if it all retries fail.
+  Errors will be logged unless the source is the Sentry.LoggerBackend, which can deadlock by logging within a logger.
 
   ### Options
   * `:result` - Allows specifying how the result should be returned. Options include `:sync`, `:none`, and `:async`.  `:sync` will make the API call synchronously, and return `{:ok, event_id}` if successful.  `:none` sends the event from an unlinked child process under `Sentry.TaskSupervisor` and will return `{:ok, ""}` regardless of the result.  `:async` will start an unlinked task and return a tuple of `{:ok, Task.t}` on success where the Task can be awaited upon to receive the result asynchronously.  When used in an OTP behaviour like GenServer, the task will send a message that needs to be matched with `GenServer.handle_info/2`.  See `Task.Supervisor.async_nolink/2` for more information.  `:async` is the default.
@@ -65,6 +66,7 @@ defmodule Sentry.Client do
   def send_event(%Event{} = event, opts \\ []) do
     result = Keyword.get(opts, :result, :async)
     sample_rate = Keyword.get(opts, :sample_rate) || Config.sample_rate()
+    should_log = event.event_source != :logger
 
     event = maybe_call_before_send_event(event)
 
@@ -76,22 +78,27 @@ defmodule Sentry.Client do
         :unsampled
 
       {%Event{}, true} ->
-        encode_and_send(event, result)
+        encode_and_send(event, result, should_log)
     end
   end
 
-  @spec encode_and_send(Event.t(), result()) :: send_event_result()
-  defp encode_and_send(event, result) do
+  @spec encode_and_send(Event.t(), result(), boolean()) :: send_event_result()
+  defp encode_and_send(event, result, should_log) do
     json_library = Config.json_library()
 
     render_event(event)
     |> json_library.encode()
     |> case do
       {:ok, body} ->
-        do_send_event(event, body, result)
+        result = do_send_event(event, body, result)
+
+        if should_log do
+          maybe_log_result(result)
+        end
+
+        result
 
       {:error, error} ->
-        # log_api_error("Unable to encode Sentry error - #{inspect(error)}")
         {:error, {:invalid_json, error}}
     end
   end
@@ -152,18 +159,12 @@ defmodule Sentry.Client do
        when current_attempt > @max_attempts,
        do: {:error, {:request_failure, last_error}}
 
-  defp try_request(url, headers, {event, body}, current_attempt) do
+  defp try_request(url, headers, {event, body}, {current_attempt, _last_error}) do
     case request(url, headers, body) do
       {:ok, id} ->
         {:ok, id}
 
       {:error, error} ->
-        # if(current_attempt == 1) do
-        #   log_api_error("Event ID: #{event.event_id} - #{inspect(error)} - #{body}")
-        # else
-        #   log_api_error("Event ID: #{event.event_id} - #{inspect(error)}")
-        # end
-
         if current_attempt < @max_attempts, do: sleep(current_attempt)
 
         try_request(url, headers, {event, body}, {current_attempt + 1, error})
@@ -224,14 +225,6 @@ defmodule Sentry.Client do
     "Sentry " <> query
   end
 
-  @spec authorization_headers(String.t(), String.t()) :: list({String.t(), String.t()})
-  defp authorization_headers(public_key, secret_key) do
-    [
-      {"User-Agent", @sentry_client},
-      {"X-Sentry-Auth", authorization_header(public_key, secret_key)}
-    ]
-  end
-
   @doc """
   Get a Sentry DSN which is simply a URI.
 
@@ -251,7 +244,6 @@ defmodule Sentry.Client do
       {endpoint, public_key, secret_key}
     else
       _ ->
-        # log_api_error("Cannot send event because of invalid DSN")
         {:error, :invalid_dsn}
     end
   end
@@ -337,6 +329,43 @@ defmodule Sentry.Client do
     end
   end
 
+  def maybe_log_result(result) do
+    message =
+      case result do
+        {:error, :invalid_dsn} ->
+          "Cannot send Sentry event because of invalid DSN"
+
+        {:error, {:invalid_json, error}} ->
+          "Unable to encode JSON Sentry error - #{inspect(error)}"
+
+        {:error, {:request_failure, last_error}} ->
+          "Error in HTTP Request to Sentry - #{inspect(last_error)}"
+
+        {:error, error} ->
+          inspect(error)
+
+        _ ->
+          nil
+      end
+
+    if message != nil do
+      Logger.log(
+        Config.log_level(),
+        fn ->
+          ["Failed to send Sentry event.", message]
+        end
+      )
+    end
+  end
+
+  @spec authorization_headers(String.t(), String.t()) :: list({String.t(), String.t()})
+  defp authorization_headers(public_key, secret_key) do
+    [
+      {"User-Agent", @sentry_client},
+      {"X-Sentry-Auth", authorization_header(public_key, secret_key)}
+    ]
+  end
+
   defp keys_from_userinfo(userinfo) do
     case String.split(userinfo, ":", parts: 2) do
       [public, secret] -> [public, secret]
@@ -345,7 +374,8 @@ defmodule Sentry.Client do
     end
   end
 
-  @spec get_headers_and_endpoint :: {String.t(), String.t(), String.t()} | {:error, :invalid_dsn}
+  @spec get_headers_and_endpoint ::
+          {String.t(), list({String.t(), String.t()})} | {:error, :invalid_dsn}
   defp get_headers_and_endpoint do
     case get_dsn() do
       {endpoint, public_key, secret_key} ->
@@ -356,15 +386,6 @@ defmodule Sentry.Client do
     end
   end
 
-  defp log_api_error(body) do
-    # Logger.log(
-    #   Config.log_level(),
-    #   fn ->
-    #     ["Failed to send Sentry event.", inspect(body)]
-    #   end
-    # )
-  end
-
   @spec sleep(pos_integer()) :: :ok
   defp sleep(1), do: :timer.sleep(2000)
   defp sleep(2), do: :timer.sleep(4000)

test/client_test.exs

@@ -44,41 +44,31 @@ defmodule Sentry.ClientTest do
   test "errors on bad public keys" do
     modify_env(:sentry, dsn: "https://app.getsentry.com/1")
 
-    capture_log(fn ->
-      assert :error = Sentry.Client.get_dsn()
-    end)
+    assert {:error, :invalid_dsn} = Sentry.Client.get_dsn()
   end
 
   test "errors on non-integer project_id" do
     modify_env(:sentry, dsn: "https://public:[email protected]/Mitchell")
 
-    capture_log(fn ->
-      assert :error = Sentry.Client.get_dsn()
-    end)
+    assert {:error, :invalid_dsn} = Sentry.Client.get_dsn()
   end
 
   test "errors on no project_id" do
     modify_env(:sentry, dsn: "https://public:[email protected]")
 
-    capture_log(fn ->
-      assert :error = Sentry.Client.get_dsn()
-    end)
+    assert {:error, :invalid_dsn} = Sentry.Client.get_dsn()
   end
 
   test "errors on nil dsn" do
     modify_env(:sentry, dsn: nil)
 
-    capture_log(fn ->
-      assert :error = Sentry.Client.get_dsn()
-    end)
+    assert {:error, :invalid_dsn} = Sentry.Client.get_dsn()
   end
 
   test "errors on atom dsn" do
     modify_env(:sentry, dsn: :error)
 
-    capture_log(fn ->
-      assert :error = Sentry.Client.get_dsn()
-    end)
+    assert {:error, :invalid_dsn} = Sentry.Client.get_dsn()
   end
 
   test "logs api errors" do
@@ -114,7 +104,7 @@ defmodule Sentry.ClientTest do
     unencodable_event = %Sentry.Event{message: "error", level: {:a, :b}}
 
     capture_log(fn ->
-      assert :error = Sentry.Client.send_event(unencodable_event)
+      assert {:error, {:invalid_json, _}} = Sentry.Client.send_event(unencodable_event)
     end)
   end
 

test/mix/sentry.send_test_event_test.exs

@@ -55,7 +55,7 @@ defmodule Mix.Tasks.Sentry.SendTestEventTest do
            """
   end
 
-  test "handles :error when Sentry server is failing" do
+  test "handles error when Sentry server is failing" do
     bypass = Bypass.open()
 
     Bypass.expect(bypass, fn conn ->
@@ -78,7 +78,7 @@ defmodule Mix.Tasks.Sentry.SendTestEventTest do
                     hackney_opts: [recv_timeout: 50]
 
                     Sending test event...
-                    Error sending event!
+                    Error sending event: "Received 500 from Sentry server: "
                     """
            end) =~ "Failed to send Sentry event"
   end

test/sentry_test.exs

@@ -55,9 +55,9 @@ defmodule SentryTest do
       dsn: "http://public:secret@localhost:#{bypass.port}/1"
     )
 
-    assert capture_log(fn ->
-             assert :error = Sentry.capture_message("error", [])
-           end) =~ "Failed to send Sentry event"
+    capture_log(fn ->
+      assert {:error, _} = Sentry.capture_message("error", [])
+    end)
 
     Bypass.pass(bypass)
   end

test/support/test_client.exs

@@ -26,7 +26,7 @@ defmodule Sentry.TestClient do
               end
             )
 
-            :error
+            {:error, error}
         end
 
       {:error, error} ->
@@ -35,7 +35,7 @@ defmodule Sentry.TestClient do
           "Error sending in Sentry.TestClient: #{inspect(error)}"
         )
 
-        :error
+        {:error, error}
     end
   end
 end