diff --git a/config/config.exs b/config/config.exs index e663c2da..4471a559 100644 --- a/config/config.exs +++ b/config/config.exs @@ -9,8 +9,9 @@ if config_env() == :test do root_source_code_paths: [File.cwd!()], hackney_opts: [recv_timeout: 50], send_result: :sync, - send_max_attempts: 1, - __sender_module__: Sentry.TransportSenderMock + send_max_attempts: 1 + + config :logger, backends: [] end config :phoenix, :json_library, Jason diff --git a/lib/sentry/client.ex b/lib/sentry/client.ex index d51dd475..f656973d 100644 --- a/lib/sentry/client.ex +++ b/lib/sentry/client.ex @@ -12,11 +12,6 @@ defmodule Sentry.Client do # Max message length per https://github.com/getsentry/sentry/blob/0fcec33ac94ad81a205f86f208072b0f57b39ff4/src/sentry/conf/server.py#L1021 @max_message_length 8_192 - # We read this at compile time and use it exclusively for tests. Any user of the Sentry - # application will get the real deal, but we'll be able to swap this out with a mock - # in tests. - @sender_module Application.compile_env(:sentry, :__sender_module__, Transport.Sender) - # This is what executes the "Event Pipeline". # See: https://develop.sentry.dev/sdk/unified-api/#event-pipeline @spec send_event(Event.t(), keyword()) :: @@ -95,7 +90,7 @@ defmodule Sentry.Client do end defp encode_and_send(%Event{} = event, _result_type = :none, _request_retries) do - :ok = @sender_module.send_async(event) + :ok = Transport.Sender.send_async(event) Sentry.put_last_event_id_and_source(event.event_id, event.source) {:ok, ""} end diff --git a/lib/sentry/transport/sender.ex b/lib/sentry/transport/sender.ex index 439c2db6..9a9c48f3 100644 --- a/lib/sentry/transport/sender.ex +++ b/lib/sentry/transport/sender.ex @@ -9,14 +9,6 @@ defmodule Sentry.Transport.Sender do @registry Sentry.Transport.SenderRegistry - # This behaviour is only present for mocks in tests. - defmodule Behaviour do - @moduledoc false - @callback send_async(Event.t()) :: :ok - end - - @behaviour Behaviour - ## Public API @spec start_link(keyword()) :: GenServer.on_start() @@ -25,7 +17,6 @@ defmodule Sentry.Transport.Sender do GenServer.start_link(__MODULE__, [], name: {:via, Registry, {@registry, index}}) end - @impl Behaviour @spec send_async(Event.t()) :: :ok def send_async(%Event{} = event) do pool_size = Application.fetch_env!(:sentry, :sender_pool_size) diff --git a/mix.exs b/mix.exs index 3b39008d..17b7c624 100644 --- a/mix.exs +++ b/mix.exs @@ -83,7 +83,6 @@ defmodule Sentry.Mixfile do {:dialyxir, "~> 1.0", only: [:test, :dev], runtime: false}, {:ex_doc, "~> 0.29.0", only: :dev}, {:excoveralls, "~> 0.17.1", only: [:test]}, - {:mox, "~> 1.0", only: [:test]}, {:phoenix, "~> 1.5", only: [:test]}, {:phoenix_html, "~> 2.0", only: [:test]} ] diff --git a/mix.lock b/mix.lock index 791201aa..b6c2347b 100644 --- a/mix.lock +++ b/mix.lock @@ -5,7 +5,6 @@ "cowboy_telemetry": {:hex, :cowboy_telemetry, "0.3.1", "ebd1a1d7aff97f27c66654e78ece187abdc646992714164380d8a041eda16754", [:rebar3], [{:cowboy, "~> 2.7", [hex: :cowboy, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "3a6efd3366130eab84ca372cbd4a7d3c3a97bdfcfb4911233b035d117063f0af"}, "cowlib": {:hex, :cowlib, "2.9.1", "61a6c7c50cf07fdd24b2f45b89500bb93b6686579b069a89f88cb211e1125c78", [:rebar3], [], "hexpm", "e4175dc240a70d996156160891e1c62238ede1729e45740bdd38064dad476170"}, "dialyxir": {:hex, :dialyxir, "1.1.0", "c5aab0d6e71e5522e77beff7ba9e08f8e02bad90dfbeffae60eaf0cb47e29488", [:mix], [{:erlex, ">= 0.2.6", [hex: :erlex, repo: "hexpm", optional: false]}], "hexpm", "07ea8e49c45f15264ebe6d5b93799d4dd56a44036cf42d0ad9c960bc266c0b9a"}, - "earmark": {:hex, :earmark, "1.4.5", "62ffd3bd7722fb7a7b1ecd2419ea0b458c356e7168c1f5d65caf09b4fbdd13c8", [:mix], [], "hexpm", "b7d0e6263d83dc27141a523467799a685965bf8b13b6743413f19a7079843f4f"}, "earmark_parser": {:hex, :earmark_parser, "1.4.32", "fa739a0ecfa34493de19426681b23f6814573faee95dfd4b4aafe15a7b5b32c6", [:mix], [], "hexpm", "b8b0dd77d60373e77a3d7e8afa598f325e49e8663a51bcc2b88ef41838cca755"}, "erlex": {:hex, :erlex, "0.2.6", "c7987d15e899c7a2f34f5420d2a2ea0d659682c06ac607572df55a43753aa12e", [:mix], [], "hexpm", "2ed2e25711feb44d52b17d2780eabf998452f6efda104877a3881c2f8c0c0c75"}, "ex_doc": {:hex, :ex_doc, "0.29.4", "6257ecbb20c7396b1fe5accd55b7b0d23f44b6aa18017b415cb4c2b91d997729", [:mix], [{:earmark_parser, "~> 1.4.31", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "2c6699a737ae46cb61e4ed012af931b57b699643b24dabe2400a8168414bc4f5"}, @@ -19,7 +18,6 @@ "metrics": {:hex, :metrics, "1.0.1", "25f094dea2cda98213cecc3aeff09e940299d950904393b2a29d191c346a8486", [:rebar3], [], "hexpm", "69b09adddc4f74a40716ae54d140f93beb0fb8978d8636eaded0c31b6f099f16"}, "mime": {:hex, :mime, "1.5.0", "203ef35ef3389aae6d361918bf3f952fa17a09e8e43b5aa592b93eba05d0fb8d", [:mix], [], "hexpm", "55a94c0f552249fc1a3dd9cd2d3ab9de9d3c89b559c2bd01121f824834f24746"}, "mimerl": {:hex, :mimerl, "1.2.0", "67e2d3f571088d5cfd3e550c383094b47159f3eee8ffa08e64106cdf5e981be3", [:rebar3], [], "hexpm", "f278585650aa581986264638ebf698f8bb19df297f66ad91b18910dfc6e19323"}, - "mox": {:hex, :mox, "1.0.2", "dc2057289ac478b35760ba74165b4b3f402f68803dd5aecd3bfd19c183815d64", [:mix], [], "hexpm", "f9864921b3aaf763c8741b5b8e6f908f44566f1e427b2630e89e9a73b981fef2"}, "nimble_parsec": {:hex, :nimble_parsec, "1.3.1", "2c54013ecf170e249e9291ed0a62e5832f70a476c61da16f6aac6dca0189f2af", [:mix], [], "hexpm", "2682e3c0b2eb58d90c6375fc0cc30bc7be06f365bf72608804fb9cffa5e1b167"}, "parse_trans": {:hex, :parse_trans, "3.3.1", "16328ab840cc09919bd10dab29e431da3af9e9e7e7e6f0089dd5a2d2820011d8", [:rebar3], [], "hexpm", "07cd9577885f56362d414e8c4c4e6bdf10d43a8767abb92d24cbe8b24c54888b"}, "phoenix": {:hex, :phoenix, "1.5.8", "71cfa7a9bb9a37af4df98939790642f210e35f696b935ca6d9d9c55a884621a4", [:mix], [{:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: true]}, {:phoenix_html, "~> 2.13", [hex: :phoenix_html, repo: "hexpm", optional: true]}, {:phoenix_pubsub, "~> 2.0", [hex: :phoenix_pubsub, repo: "hexpm", optional: false]}, {:plug, "~> 1.10", [hex: :plug, repo: "hexpm", optional: false]}, {:plug_cowboy, "~> 1.0 or ~> 2.2", [hex: :plug_cowboy, repo: "hexpm", optional: true]}, {:plug_crypto, "~> 1.1.2 or ~> 1.2", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "35ded0a32f4836168c7ab6c33b88822eccd201bcd9492125a9bea4c54332d955"}, @@ -30,7 +28,6 @@ "plug_crypto": {:hex, :plug_crypto, "1.2.2", "05654514ac717ff3a1843204b424477d9e60c143406aa94daf2274fdd280794d", [:mix], [], "hexpm", "87631c7ad914a5a445f0a3809f99b079113ae4ed4b867348dd9eec288cecb6db"}, "ranch": {:hex, :ranch, "1.7.1", "6b1fab51b49196860b733a49c07604465a47bdb78aa10c1c16a3d199f7f8c881", [:rebar3], [], "hexpm", "451d8527787df716d99dc36162fca05934915db0b6141bbdac2ea8d3c7afc7d7"}, "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.7", "354c321cf377240c7b8716899e182ce4890c5938111a1296add3ec74cf1715df", [:make, :mix, :rebar3], [], "hexpm", "fe4c190e8f37401d30167c8c405eda19469f34577987c76dde613e838bbc67f8"}, - "ssl_verify_hostname": {:hex, :ssl_verify_hostname, "1.0.5", "2e73e068cd6393526f9fa6d399353d7c9477d6886ba005f323b592d389fb47be", [:make], []}, "telemetry": {:hex, :telemetry, "0.4.2", "2808c992455e08d6177322f14d3bdb6b625fbcfd233a73505870d8738a2f4599", [:rebar3], [], "hexpm", "2d1419bd9dda6a206d7b5852179511722e2b18812310d304620c7bd92a13fcef"}, "unicode_util_compat": {:hex, :unicode_util_compat, "0.7.0", "bc84380c9ab48177092f43ac89e4dfa2c6d62b40b8bd132b1059ecc7232f9a78", [:rebar3], [], "hexpm", "25eee6d67df61960cf6a794239566599b09e17e668d3700247bc498638152521"}, } diff --git a/test/event_test.exs b/test/event_test.exs index eb8d86f3..afbcef64 100644 --- a/test/event_test.exs +++ b/test/event_test.exs @@ -388,7 +388,6 @@ defmodule Sentry.EventTest do :metrics, :mime, :mimerl, - :mox, :parse_trans, :phoenix, :phoenix_html, diff --git a/test/logger_backend_test.exs b/test/logger_backend_test.exs index 9aabe134..12142b2d 100644 --- a/test/logger_backend_test.exs +++ b/test/logger_backend_test.exs @@ -1,40 +1,24 @@ defmodule Sentry.LoggerBackendTest do - use ExUnit.Case - - import Mox + use ExUnit.Case, async: false + alias Sentry.TestEnvironmentHelper alias Sentry.TestGenServer require Logger @moduletag :capture_log - setup :set_mox_global - setup :verify_on_exit! - setup do - {:ok, _} = Logger.add_backend(Sentry.LoggerBackend) + assert {:ok, _} = Logger.add_backend(Sentry.LoggerBackend) - ExUnit.Callbacks.on_exit(fn -> + on_exit(fn -> Logger.configure_backend(Sentry.LoggerBackend, []) :ok = Logger.remove_backend(Sentry.LoggerBackend) end) end - defp expect_sender_call do - pid = self() - ref = make_ref() - - expect(Sentry.TransportSenderMock, :send_async, fn event -> - send(pid, {ref, event}) - :ok - end) - - ref - end - test "a logged raised exception is reported" do - ref = expect_sender_call() + ref = register_before_send() Task.start(fn -> raise "Unique Error" @@ -47,7 +31,7 @@ defmodule Sentry.LoggerBackendTest do end test "a GenServer throw is reported" do - ref = expect_sender_call() + ref = register_before_send() pid = start_supervised!(TestGenServer) Sentry.TestGenServer.throw(pid) @@ -61,7 +45,7 @@ defmodule Sentry.LoggerBackendTest do end test "abnormal GenServer exit is reported" do - ref = expect_sender_call() + ref = register_before_send() pid = start_supervised!(TestGenServer) Sentry.TestGenServer.exit(pid) @@ -75,7 +59,7 @@ defmodule Sentry.LoggerBackendTest do end test "bad function call causing GenServer crash is reported" do - ref = expect_sender_call() + ref = register_before_send() pid = start_supervised!(TestGenServer) @@ -96,7 +80,7 @@ defmodule Sentry.LoggerBackendTest do end test "GenServer timeout is reported" do - ref = expect_sender_call() + ref = register_before_send() pid = start_supervised!(TestGenServer) @@ -120,7 +104,7 @@ defmodule Sentry.LoggerBackendTest do end test "captures errors from spawn/0 in Plug app" do - ref = expect_sender_call() + ref = register_before_send() :get |> Plug.Test.conn("/spawn_error_route") @@ -135,7 +119,7 @@ defmodule Sentry.LoggerBackendTest do test "sends two errors when a Plug process crashes if cowboy domain is not excluded" do Logger.configure_backend(Sentry.LoggerBackend, excluded_domains: []) - ref = expect_sender_call() + ref = register_before_send() {:ok, _plug_pid} = Plug.Cowboy.http(Sentry.ExamplePlugApplication, [], port: 8003) @@ -152,7 +136,7 @@ defmodule Sentry.LoggerBackendTest do excluded_domains: [:test_domain] ) - ref = expect_sender_call() + ref = register_before_send() Logger.error("no domain") Logger.error("test_domain", domain: [:test_domain]) @@ -164,7 +148,7 @@ defmodule Sentry.LoggerBackendTest do test "includes Logger metadata for keys configured to be included" do Logger.configure_backend(Sentry.LoggerBackend, metadata: [:string, :number, :map, :list]) - ref = expect_sender_call() + ref = register_before_send() pid = start_supervised!(TestGenServer) Sentry.TestGenServer.add_logger_metadata(pid, :string, "string") @@ -182,7 +166,7 @@ defmodule Sentry.LoggerBackendTest do test "does not include Logger metadata when disabled" do Logger.configure_backend(Sentry.LoggerBackend, metadata: []) - ref = expect_sender_call() + ref = register_before_send() pid = start_supervised!(TestGenServer) Sentry.TestGenServer.add_logger_metadata(pid, :string, "string") @@ -197,7 +181,7 @@ defmodule Sentry.LoggerBackendTest do test "supports :all for Logger metadata" do Logger.configure_backend(Sentry.LoggerBackend, metadata: :all) - ref = expect_sender_call() + ref = register_before_send() pid = start_supervised!(TestGenServer) Sentry.TestGenServer.add_logger_metadata(pid, :string, "string") @@ -220,7 +204,7 @@ defmodule Sentry.LoggerBackendTest do test "sends all messages if :capture_log_messages is true" do Logger.configure_backend(Sentry.LoggerBackend, capture_log_messages: true) - ref = expect_sender_call() + ref = register_before_send() Logger.error("Testing") @@ -236,7 +220,7 @@ defmodule Sentry.LoggerBackendTest do capture_log_messages: true ) - ref = expect_sender_call() + ref = register_before_send() Sentry.Context.set_user_context(%{user_id: 3}) Logger.log(:warning, "Testing") @@ -252,7 +236,7 @@ defmodule Sentry.LoggerBackendTest do test "does not send debug messages when configured to :error" do Logger.configure_backend(Sentry.LoggerBackend, capture_log_messages: true) - ref = expect_sender_call() + ref = register_before_send() Sentry.Context.set_user_context(%{user_id: 3}) @@ -268,7 +252,7 @@ defmodule Sentry.LoggerBackendTest do test "Sentry metadata and extra context are retrieved from callers" do Logger.configure_backend(Sentry.LoggerBackend, capture_log_messages: true) - ref = expect_sender_call() + ref = register_before_send() Sentry.Context.set_extra_context(%{day_of_week: "Friday"}) Sentry.Context.set_user_context(%{user_id: 3}) @@ -288,7 +272,7 @@ defmodule Sentry.LoggerBackendTest do test "handles malformed :callers metadata" do Logger.configure_backend(Sentry.LoggerBackend, capture_log_messages: true) - ref = expect_sender_call() + ref = register_before_send() dead_pid = spawn(fn -> :ok end) @@ -304,7 +288,7 @@ defmodule Sentry.LoggerBackendTest do capture_log_messages: true ) - ref = expect_sender_call() + ref = register_before_send() Logger.log(:warning, "warn") @@ -326,4 +310,18 @@ defmodule Sentry.LoggerBackendTest do exit(:shutdown) end end + + defp register_before_send(_context \\ %{}) do + pid = self() + ref = make_ref() + + TestEnvironmentHelper.modify_env(:sentry, + before_send_event: fn event -> + send(pid, {ref, event}) + false + end + ) + + ref + end end diff --git a/test/sentry/client_test.exs b/test/sentry/client_test.exs index 3c64af91..a15e1102 100644 --- a/test/sentry/client_test.exs +++ b/test/sentry/client_test.exs @@ -2,19 +2,10 @@ defmodule Sentry.ClientTest do use ExUnit.Case import ExUnit.CaptureLog - import Mox import Sentry.TestEnvironmentHelper alias Sentry.{Client, Event} - setup :set_mox_global - setup :verify_on_exit! - - setup do - Mox.stub_with(Sentry.TransportSenderMock, Sentry.Transport.Sender) - :ok - end - describe "render_event/1" do test "transforms structs into maps" do event = Event.transform_exception(%RuntimeError{message: "foo"}, user: %{id: 1}) diff --git a/test/sentry/logger_handler_test.exs b/test/sentry/logger_handler_test.exs index 1149b469..79814fb6 100644 --- a/test/sentry/logger_handler_test.exs +++ b/test/sentry/logger_handler_test.exs @@ -1,42 +1,52 @@ defmodule Sentry.LoggerHandlerTest do use ExUnit.Case, async: false - import Mox - + alias Sentry.TestEnvironmentHelper alias Sentry.TestGenServer require Logger @moduletag :capture_log - @handler_name :sentry_handler + # This test is problematic on Elixir 1.14 and lower because of issues with logs + # spilling due to a race condition that was fixed in 1.15+. + if Version.match?(System.version(), "< 1.15.4") do + @moduletag :skip + end - setup :set_mox_global - setup :verify_on_exit! + @handler_name :sentry_handler - setup :stub_sender_call + setup :register_before_send + setup :add_handler setup do on_exit(fn -> - _ = :logger.remove_handler(@handler_name) + for %{id: id, module: module} <- :logger.get_handler_config(), + function_exported?(module, :filesync, 1) do + try do + module.filesync(id) + catch + _, _ -> :ok + end + end end) end test "skips logs from a lower level than the configured one" do - add_handler(%{}) - # Default level is :error, so this doesn't get reported. Logger.warning("Warning message") # Change the level to :info and make sure that :debug messages are not reported. assert :ok = :logger.update_handler_config(@handler_name, :level, :info) + on_exit(fn -> + :logger.update_handler_config(@handler_name, :level, :error) + end) + Logger.debug("Debug message") end test "a logged raised exception is reported", %{sender_ref: ref} do - add_handler(%{}) - Task.start(fn -> raise "Unique Error" end) @@ -47,265 +57,251 @@ defmodule Sentry.LoggerHandlerTest do assert exception.value == "Unique Error" end - test "a GenServer throw is reported", %{sender_ref: ref} do - add_handler(%{}) - - pid = start_supervised!(TestGenServer) - TestGenServer.throw(pid) - assert_receive {^ref, event} - assert event.message =~ "** (stop) bad return value: \"I am throwing\"" - end - - test "abnormal GenServer exit is reported", %{sender_ref: ref} do - add_handler(%{}) - - pid = start_supervised!(TestGenServer) - TestGenServer.exit(pid) - assert_receive {^ref, event} - - assert event.message =~ "** (stop) :bad_exit" - - if System.otp_release() >= "26" do - assert hd(event.exception).type == "message" - end - end - - test "bad function call causing GenServer crash is reported", %{sender_ref: ref} do - add_handler(%{}) + test "retrieves context from :callers", %{sender_ref: ref} do + Sentry.Context.set_extra_context(%{day_of_week: "Friday"}) + Sentry.Context.set_user_context(%{user_id: 3}) - pid = start_supervised!(TestGenServer) + {:ok, _task_pid} = Task.start(fn -> raise "oops" end) - TestGenServer.add_sentry_breadcrumb(pid, %{message: "test"}) - TestGenServer.invalid_function(pid) assert_receive {^ref, event} - assert [%{message: "test"}] = event.breadcrumbs - + assert event.user.user_id == 3 + assert event.extra.day_of_week == "Friday" assert [exception] = event.exception - - if System.otp_release() >= "26" do - assert exception.type == "FunctionClauseError" - else - assert event.message =~ "** (stop) :function_clause" - assert exception.type == "message" - end - - assert %{ - in_app: false, - module: NaiveDateTime, - context_line: nil, - pre_context: [], - post_context: [] - } = List.last(exception.stacktrace.frames) + assert exception.type == "RuntimeError" + assert exception.value == "oops" end - test "GenServer timeout is reported", %{sender_ref: ref} do - add_handler(%{}) - - pid = start_supervised!(TestGenServer) - - Task.start(fn -> - TestGenServer.sleep(pid, _timeout = 0) - end) - - assert_receive {^ref, event} - - assert [exception] = event.exception - - assert exception.type == "message" - - assert exception.value =~ "** (stop) exited in: GenServer.call(" - assert exception.value =~ "** (EXIT) time out" - assert length(exception.stacktrace.frames) > 0 - end + describe "with Plug" do + if System.otp_release() < "26", do: @describetag(:skip) - if System.otp_release() >= "26.0" do + @tag handler_config: %{excluded_domains: []} test "captures errors from spawn/0 in Plug app", %{sender_ref: ref} do - add_handler(%{excluded_domains: []}) - :get |> Plug.Test.conn("/spawn_error_route") |> Plug.run([{Sentry.ExamplePlugApplication, []}]) assert_receive {^ref, event} - if System.otp_release() >= "26" do - assert [stacktrace_frame] = hd(event.exception).stacktrace.frames - assert stacktrace_frame.filename == "test/support/example_plug_application.ex" - else - assert event.message =~ "Error in process" - assert event.message =~ "RuntimeError" - end + assert [stacktrace_frame] = hd(event.exception).stacktrace.frames + assert stacktrace_frame.filename == "test/support/example_plug_application.ex" end - test "sends two errors when a Plug process crashes if cowboy domain is not excluded", %{ - sender_ref: ref - } do - add_handler(%{excluded_domains: []}) - + @tag handler_config: %{excluded_domains: []} + test "sends two errors when a Plug process crashes if cowboy domain is not excluded", + %{sender_ref: ref} do {:ok, _plug_pid} = Plug.Cowboy.http(Sentry.ExamplePlugApplication, [], port: 8003) :hackney.get("http://127.0.0.1:8003/error_route", [], "", []) assert_receive {^ref, _event}, 1000 after :ok = Plug.Cowboy.shutdown(Sentry.ExamplePlugApplication.HTTP) - Logger.configure_backend(Sentry.LoggerBackend, excluded_domains: [:cowboy]) end end - test "ignores log messages with excluded domains", %{sender_ref: ref} do - add_handler(%{capture_log_messages: true, excluded_domains: [:test_domain]}) + describe "with capture_log_messages: true" do + @tag handler_config: %{capture_log_messages: true} + test "sends error messages by default", %{sender_ref: ref} do + Logger.error("Testing error") + Logger.info("Testing info") - Logger.error("no domain") - Logger.error("test_domain", domain: [:test_domain]) + assert_receive {^ref, event} + assert event.message == "Testing error" - assert_receive {^ref, event} - assert event.message == "no domain" - end + refute_receive {^ref, _event}, 100 + end - test "includes Logger metadata for keys configured to be included", %{sender_ref: ref} do - add_handler(%{metadata: [:string, :number, :map, :list]}) + @tag handler_config: %{capture_log_messages: true, level: :warning} + test "respects the configured :level", %{sender_ref: ref} do + Logger.log(:warning, "Testing warning") + Logger.log(:info, "Testing info") - pid = start_supervised!(TestGenServer) - TestGenServer.add_logger_metadata(pid, :string, "string") - TestGenServer.add_logger_metadata(pid, :number, 43) - TestGenServer.add_logger_metadata(pid, :map, %{a: "b"}) - TestGenServer.add_logger_metadata(pid, :list, [1, 2, 3]) - TestGenServer.invalid_function(pid) + assert_receive {^ref, event} - assert_receive {^ref, event} - assert event.extra.logger_metadata.string == "string" - assert event.extra.logger_metadata.map == %{a: "b"} - assert event.extra.logger_metadata.list == [1, 2, 3] - assert event.extra.logger_metadata.number == 43 - end + assert event.message == "Testing warning" + assert event.level == "warning" - test "does not include Logger metadata when disabled", %{sender_ref: ref} do - add_handler(%{metadata: []}) + refute_receive {^ref, _event}, 100 + end - pid = start_supervised!(TestGenServer) - TestGenServer.add_logger_metadata(pid, :string, "string") - TestGenServer.add_logger_metadata(pid, :atom, :atom) - TestGenServer.add_logger_metadata(pid, :number, 43) - TestGenServer.add_logger_metadata(pid, :list, []) - TestGenServer.invalid_function(pid) + @tag handler_config: %{capture_log_messages: true} + test "handles malformed :callers metadata", %{sender_ref: ref} do + dead_pid = spawn(fn -> :ok end) - assert_receive {^ref, event} - assert event.extra.logger_metadata == %{} - end + Logger.error("Error", callers: [dead_pid, nil]) - test "supports :all for Logger metadata", %{sender_ref: ref} do - add_handler(%{metadata: :all}) + assert_receive {^ref, event} + assert event.message == "Error" + end - pid = start_supervised!(TestGenServer) - TestGenServer.add_logger_metadata(pid, :string, "string") - TestGenServer.invalid_function(pid) + @tag handler_config: %{capture_log_messages: true, excluded_domains: [:test_domain]} + test "ignores log messages with excluded domains", %{sender_ref: ref} do + Logger.error("no domain") + Logger.error("test_domain", domain: [:test_domain]) - assert_receive {^ref, event} + assert_receive {^ref, event} + assert event.message == "no domain" + end + end + + describe "with a crashing GenServer" do + setup do + %{test_genserver: start_supervised!(TestGenServer, restart: :temporary)} + end - assert event.extra.logger_metadata.string == "string" - assert event.extra.logger_metadata.domain == [:otp] - assert is_integer(event.extra.logger_metadata.time) - assert is_pid(event.extra.logger_metadata.pid) + test "a GenServer throw is reported", %{sender_ref: ref, test_genserver: test_genserver} do + run_and_catch_exit(test_genserver, fn -> + throw(:testing_throw) + end) - if System.otp_release() >= "26" do - assert {%FunctionClauseError{}, _stacktrace} = event.extra.logger_metadata.crash_reason + assert_receive {^ref, event} + assert event.message =~ "** (stop) bad return value: :testing_throw" end - # Make sure that all this stuff is serializable. - assert Sentry.Client.render_event(event).extra.logger_metadata.pid =~ "#PID<" - end + test "abnormal GenServer exit is reported", %{sender_ref: ref, test_genserver: test_genserver} do + run_and_catch_exit(test_genserver, fn -> + {:stop, :bad_exit, :no_state} + end) - test "sends all messages if :capture_log_messages is true", %{sender_ref: ref} do - add_handler(%{capture_log_messages: true}) + assert_receive {^ref, event} - Logger.error("Testing") + assert event.message =~ "** (stop) :bad_exit" - assert_receive {^ref, event} - assert event.message == "Testing" - after - Logger.configure_backend(Sentry.LoggerBackend, capture_log_messages: false) - end + if System.otp_release() >= "26" do + assert hd(event.exception).type == "message" + end + end - test "sends warning messages when configured to :warning", %{sender_ref: ref} do - add_handler(%{level: :warning, capture_log_messages: true}) + @tag handler_config: %{metadata: [:string, :number, :map, :list]} + test "includes Logger metadata for keys configured to be included", + %{sender_ref: ref, test_genserver: test_genserver} do + run_and_catch_exit(test_genserver, fn -> + Logger.metadata( + string: "string", + number: 43, + map: %{a: "b"}, + list: [1, 2, 3] + ) - Sentry.Context.set_user_context(%{user_id: 3}) - Logger.log(:warning, "Testing") + invalid_function() + end) - assert_receive {^ref, event} + assert_receive {^ref, event} + assert event.extra.logger_metadata.string == "string" + assert event.extra.logger_metadata.map == %{a: "b"} + assert event.extra.logger_metadata.list == [1, 2, 3] + assert event.extra.logger_metadata.number == 43 + end - assert event.message == "Testing" - assert event.user.user_id == 3 - end + @tag handler_config: %{metadata: []} + test "does not include Logger metadata when disabled", + %{sender_ref: ref, test_genserver: test_genserver} do + run_and_catch_exit(test_genserver, fn -> + Logger.metadata( + string: "string", + number: 43, + map: %{a: "b"}, + list: [1, 2, 3] + ) - test "does not send debug messages when configured to :error", %{sender_ref: ref} do - add_handler(%{capture_log_messages: true}) + invalid_function() + end) - Sentry.Context.set_user_context(%{user_id: 3}) + assert_receive {^ref, event} + assert event.extra.logger_metadata == %{} + end - Logger.error("Error") - Logger.debug("Debug") + @tag handler_config: %{metadata: :all} + test "supports :all for Logger metadata", %{sender_ref: ref, test_genserver: test_genserver} do + run_and_catch_exit(test_genserver, fn -> + Logger.metadata(my_string: "some string") + invalid_function() + end) - assert_receive {^ref, event} + assert_receive {^ref, event} - assert event.message == "Error" - end + assert event.extra.logger_metadata.my_string == "some string" + assert event.extra.logger_metadata.domain == [:otp] + assert is_integer(event.extra.logger_metadata.time) + assert is_pid(event.extra.logger_metadata.pid) - test "Sentry metadata and extra context are retrieved from callers", %{sender_ref: ref} do - add_handler(%{capture_log_messages: true}) + if System.otp_release() >= "26" do + assert {%FunctionClauseError{}, _stacktrace} = event.extra.logger_metadata.crash_reason + end - Sentry.Context.set_extra_context(%{day_of_week: "Friday"}) - Sentry.Context.set_user_context(%{user_id: 3}) + # Make sure that all this stuff is serializable. + assert Sentry.Client.render_event(event).extra.logger_metadata.pid =~ "#PID<" + end - {:ok, _task_pid} = Task.start(__MODULE__, :task, []) + test "bad function call causing GenServer crash is reported", + %{sender_ref: ref, test_genserver: test_genserver} do + run_and_catch_exit(test_genserver, fn -> + Sentry.Context.add_breadcrumb(%{message: "test"}) + invalid_function() + end) - assert_receive {^ref, event} + assert_receive {^ref, event} - assert event.user.user_id == 3 - assert event.extra.day_of_week == "Friday" - assert [exception] = event.exception - assert exception.type == "RuntimeError" - assert exception.value == "oops" - end + assert [%{message: "test"}] = event.breadcrumbs - test "handles malformed :callers metadata", %{sender_ref: ref} do - add_handler(%{capture_log_messages: true}) + assert [exception] = event.exception - dead_pid = spawn(fn -> :ok end) + assert exception.type == "FunctionClauseError" - Logger.error("Error", callers: [dead_pid, nil]) + assert %{ + in_app: false, + module: NaiveDateTime, + context_line: nil, + pre_context: [], + post_context: [] + } = List.last(exception.stacktrace.frames) + end - assert_receive {^ref, event} - assert event.message == "Error" - end + test "GenServer timeout is reported", %{sender_ref: ref, test_genserver: test_genserver} do + Task.start(fn -> + TestGenServer.run(test_genserver, fn -> Process.sleep(:infinity) end, _timeout = 0) + end) - test "sets event level to Logger message level", %{sender_ref: ref} do - add_handler(%{level: :warning, capture_log_messages: true}) + assert_receive {^ref, event} - Logger.log(:warning, "warn") + assert [exception] = event.exception - assert_receive {^ref, event} - assert event.level == "warning" - end + assert exception.type == "message" - def task do - raise "oops" + assert exception.value =~ "** (stop) exited in: GenServer.call(" + assert exception.value =~ "** (EXIT) time out" + assert length(exception.stacktrace.frames) > 0 + end end - defp stub_sender_call(_context) do + defp register_before_send(_context) do pid = self() ref = make_ref() - stub(Sentry.TransportSenderMock, :send_async, fn event -> - send(pid, {ref, event}) - :ok - end) + TestEnvironmentHelper.modify_env(:sentry, + before_send_event: fn event -> + send(pid, {ref, event}) + false + end + ) %{sender_ref: ref} end - defp add_handler(config) do + defp add_handler(context) do + config = Map.get(context, :handler_config, %{}) assert :ok = :logger.add_handler(@handler_name, Sentry.LoggerHandler, %{config: config}) + + on_exit(fn -> + _ = :logger.remove_handler(@handler_name) + end) + end + + defp run_and_catch_exit(test_genserver_pid, fun) do + catch_exit(TestGenServer.run(test_genserver_pid, fun)) + end + + defp invalid_function do + NaiveDateTime.from_erl({}, {}, {}) end end diff --git a/test/support/mocks.ex b/test/support/mocks.ex deleted file mode 100644 index fb9dc792..00000000 --- a/test/support/mocks.ex +++ /dev/null @@ -1,2 +0,0 @@ -Mox.defmock(Sentry.HTTPClientMock, for: Sentry.HTTPClient) -Mox.defmock(Sentry.TransportSenderMock, for: Sentry.Transport.Sender.Behaviour) diff --git a/test/support/test_gen_server.ex b/test/support/test_gen_server.ex index 008f156c..a6975929 100644 --- a/test/support/test_gen_server.ex +++ b/test/support/test_gen_server.ex @@ -7,6 +7,10 @@ defmodule Sentry.TestGenServer do GenServer.start_link(__MODULE__, test_pid) end + def run(server, fun, timeout \\ :infinity) do + GenServer.call(server, {:run, fun}, timeout) + end + def throw(server) do GenServer.cast(server, :throw) end @@ -36,6 +40,10 @@ defmodule Sentry.TestGenServer do {:ok, test_pid} end + def handle_call({:run, fun}, _from, _state) do + fun.() + end + @impl true def handle_call(:sleep, _from, state) do Process.sleep(:infinity)