Add support for interpolating messages (#670)

Closes #664.

Author: whatyouhide

lib/sentry.ex

@@ -261,6 +261,25 @@ defmodule Sentry do
   Reports a message to Sentry.
 
   `opts` argument is passed as the second argument to `send_event/2`.
+
+  ## Interpolation (since v10.1.0)
+
+  The `message` argument supports interpolation. You can pass a string with formatting
+  markers as `%s`, ant then pass in the `:interpolation_parameters` option as a list
+  of positional parameters to interpolate. For example:
+
+      Sentry.capture_message("Error with user %s", interpolation_parameters: ["John"])
+
+  This way, Sentry will group the messages based on the non-interpolated string, but it
+  will show the interpolated string in the UI.
+
+  > #### Missing or Extra Parameters {: .neutral}
+  >
+  > If the message string has more `%s` markers than parameters, the extra `%s` markers
+  > are included as is and the SDK doesn't raise any error. If you pass in more interpolation
+  > parameters than `%s` markers, the extra parameters are ignored as well. This is because
+  > the SDK doesn't want to be the cause of even more errors in your application when what
+  > you're trying to do is report an error in the first place.
   """
   @spec capture_message(String.t(), keyword()) :: send_result
   def capture_message(message, opts \\ []) when is_binary(message) do

lib/sentry/client.ex

@@ -214,9 +214,12 @@ defmodule Sentry.Client do
 
     event
     |> Event.remove_non_payload_keys()
-    |> update_if_present(:message, &String.slice(&1, 0, @max_message_length))
     |> update_if_present(:breadcrumbs, fn bcs -> Enum.map(bcs, &Map.from_struct/1) end)
     |> update_if_present(:sdk, &Map.from_struct/1)
+    |> update_if_present(:message, fn message ->
+      message = update_in(message.formatted, &String.slice(&1, 0, @max_message_length))
+      Map.from_struct(message)
+    end)
     |> update_if_present(:request, &(&1 |> Map.from_struct() |> remove_nils()))
     |> update_if_present(:extra, &sanitize_non_jsonable_values(&1, json_library))
     |> update_if_present(:user, &sanitize_non_jsonable_values(&1, json_library))

lib/sentry/event.ex

@@ -64,7 +64,7 @@ defmodule Sentry.Event do
           breadcrumbs: [Interfaces.Breadcrumb.t()],
           contexts: Interfaces.context(),
           exception: [Interfaces.Exception.t()],
-          message: String.t() | nil,
+          message: Interfaces.Message.t() | nil,
           request: Interfaces.Request.t() | nil,
           sdk: Interfaces.SDK.t() | nil,
           threads: [Interfaces.Thread.t()] | nil,
@@ -238,6 +238,14 @@ defmodule Sentry.Event do
       The source of the event. This fills in the `:source` field of the
       returned struct. This is not present by default.
       """
+    ],
+    interpolation_parameters: [
+      type: {:list, :string},
+      doc: """
+      The parameters to use for message interpolation. This is only used if the
+      `:message` option is present. This is not present by default. See
+      `Sentry.capture_message/2`. *Available since v10.1.0*.
+      """
     ]
   ]
 
@@ -335,7 +343,7 @@ defmodule Sentry.Event do
       extra: extra,
       fingerprint: Keyword.fetch!(opts, :fingerprint),
       level: Keyword.fetch!(opts, :level),
-      message: message,
+      message: message && build_message_interface(message, opts),
       modules: :persistent_term.get({:sentry, :loaded_applications}),
       original_exception: exception,
       release: Config.release(),
@@ -361,6 +369,38 @@ defmodule Sentry.Event do
     end
   end
 
+  defp build_message_interface(raw_message, opts) do
+    if params = Keyword.get(opts, :interpolation_parameters) do
+      %Interfaces.Message{
+        formatted: interpolate(raw_message, params),
+        message: raw_message,
+        params: params
+      }
+    else
+      %Interfaces.Message{formatted: raw_message}
+    end
+  end
+
+  # Made public for testing.
+  @doc false
+  def interpolate(message, params) do
+    parts = Regex.split(~r{%s}, message, include_captures: true, trim: true)
+
+    {iodata, _params} =
+      Enum.reduce(parts, {"", params}, fn
+        "%s", {acc, [param | rest_params]} ->
+          {[acc, to_string(param)], rest_params}
+
+        "%s", {acc, []} ->
+          {[acc, "%s"], []}
+
+        part, {acc, params} ->
+          {[acc, part], params}
+      end)
+
+    IO.iodata_to_binary(iodata)
+  end
+
   # If we have a message with a stacktrace, but no exceptions, for now we store the stacktrace in
   # the "threads" interface and we don't fill in the "exception" interface altogether. This might
   # be eventually fixed in Sentry itself: https://github.com/getsentry/sentry/issues/61239

lib/sentry/interfaces.ex

@@ -93,6 +93,26 @@ defmodule Sentry.Interfaces do
     defstruct [:name, :version]
   end
 
+  defmodule Message do
+    @moduledoc """
+    The struct for the **message** interface.
+
+    See <https://develop.sentry.dev/sdk/event-payloads/message>.
+    """
+
+    @moduledoc since: "10.1.0"
+
+    @typedoc since: "10.1.0"
+    @type t() :: %__MODULE__{
+            message: String.t(),
+            formatted: String.t(),
+            params: [term()]
+          }
+
+    @enforce_keys [:formatted]
+    defstruct [:message, :params, :formatted]
+  end
+
   defmodule Exception do
     @moduledoc """
     The struct for the **exception** interface.

test/event_test.exs

@@ -191,7 +191,7 @@ defmodule Sentry.EventTest do
       end
     end
 
-    test "fills in the message interface when passing the :message option" do
+    test "fills in the message interface when passing the :message option without formatting params" do
       put_test_config(environment_name: "my_env")
 
       assert %Event{
@@ -200,14 +200,45 @@ defmodule Sentry.EventTest do
                exception: [],
                extra: %{},
                level: :error,
-               message: "Test message",
+               message: %Interfaces.Message{} = message,
                platform: :elixir,
                release: nil,
                request: %{},
                tags: %{},
                user: %{},
                contexts: %{os: %{name: _, version: _}, runtime: %{name: _, version: _}}
              } = Event.create_event(message: "Test message")
+
+      assert message == %Interfaces.Message{formatted: "Test message"}
+    end
+
+    test "fills in the message interface when passing the :message option with formatting params" do
+      put_test_config(environment_name: "my_env")
+
+      assert %Event{
+               breadcrumbs: [],
+               environment: "my_env",
+               exception: [],
+               extra: %{},
+               level: :error,
+               message: %Interfaces.Message{} = message,
+               platform: :elixir,
+               release: nil,
+               request: %{},
+               tags: %{},
+               user: %{},
+               contexts: %{os: %{name: _, version: _}, runtime: %{name: _, version: _}}
+             } =
+               Event.create_event(
+                 message: "Interpolated string like %s",
+                 interpolation_parameters: ["this"]
+               )
+
+      assert message == %Interfaces.Message{
+               formatted: "Interpolated string like this",
+               params: ["this"],
+               message: "Interpolated string like %s"
+             }
     end
 
     test "fills in the message and threads interfaces when passing the :message option with :stacktrace" do
@@ -220,7 +251,7 @@ defmodule Sentry.EventTest do
                exception: [],
                extra: %{},
                level: :error,
-               message: "Test message",
+               message: message,
                platform: :elixir,
                release: nil,
                request: %{},
@@ -230,6 +261,12 @@ defmodule Sentry.EventTest do
                threads: [%Interfaces.Thread{id: thread_id, stacktrace: thread_stacktrace}]
              } = Event.create_event(message: "Test message", stacktrace: stacktrace)
 
+      assert message == %Sentry.Interfaces.Message{
+               message: nil,
+               params: nil,
+               formatted: "Test message"
+             }
+
       assert is_binary(thread_id) and byte_size(thread_id) > 0
 
       assert [
@@ -368,4 +405,23 @@ defmodule Sentry.EventTest do
              |> Map.keys()
              |> Enum.sort()
   end
+
+  describe "interpolate/2" do
+    test "works with simple strings" do
+      assert Event.interpolate("Hello %s!", ["world"]) == "Hello world!"
+    end
+
+    test "ignores extra bindings" do
+      assert Event.interpolate("Hello %s", ["world", "extra"]) ==
+               "Hello world"
+    end
+
+    test "works with multiple bindings" do
+      assert Event.interpolate("Hello %s, %s!", ["world", "sup"]) == "Hello world, sup!"
+    end
+
+    test "ignores unknown bindings" do
+      assert Event.interpolate("Hello %s, %s", ["world"]) == "Hello world, %s"
+    end
+  end
 end

test/logger_backend_test.exs

@@ -39,10 +39,10 @@ defmodule Sentry.LoggerBackendTest do
     assert_receive {^ref, event}
     assert [] = event.exception
     assert [thread] = event.threads
-    assert event.message =~ ~s<GenServer #{inspect(pid)} terminating\n>
-    assert event.message =~ ~s<** (stop) bad return value: "I am throwing"\n>
-    assert event.message =~ ~s<Last message: {:"$gen_cast",>
-    assert event.message =~ ~s<State: []>
+    assert event.message.formatted =~ ~s<GenServer #{inspect(pid)} terminating\n>
+    assert event.message.formatted =~ ~s<** (stop) bad return value: "I am throwing"\n>
+    assert event.message.formatted =~ ~s<Last message: {:"$gen_cast",>
+    assert event.message.formatted =~ ~s<State: []>
     assert thread.stacktrace.frames == []
   end
 
@@ -54,10 +54,10 @@ defmodule Sentry.LoggerBackendTest do
     assert_receive {^ref, event}
     assert [] = event.exception
     assert [_thread] = event.threads
-    assert event.message =~ ~s<GenServer #{inspect(pid)} terminating\n>
-    assert event.message =~ ~s<** (stop) :bad_exit\n>
-    assert event.message =~ ~s<Last message: {:"$gen_cast",>
-    assert event.message =~ ~s<State: []>
+    assert event.message.formatted =~ ~s<GenServer #{inspect(pid)} terminating\n>
+    assert event.message.formatted =~ ~s<** (stop) :bad_exit\n>
+    assert event.message.formatted =~ ~s<Last message: {:"$gen_cast",>
+    assert event.message.formatted =~ ~s<State: []>
   end
 
   test "bad function call causing GenServer crash is reported" do
@@ -100,11 +100,11 @@ defmodule Sentry.LoggerBackendTest do
     assert [] = event.exception
     assert [thread] = event.threads
 
-    assert event.message =~
+    assert event.message.formatted =~
              "Task #{inspect(task_pid)} started from #{inspect(self())} terminating\n"
 
-    assert event.message =~ "** (stop) exited in: GenServer.call("
-    assert event.message =~ "** (EXIT) time out"
+    assert event.message.formatted =~ "** (stop) exited in: GenServer.call("
+    assert event.message.formatted =~ "** (EXIT) time out"
     assert length(thread.stacktrace.frames) > 0
   end
 
@@ -147,7 +147,7 @@ defmodule Sentry.LoggerBackendTest do
     Logger.error("test_domain", domain: [:test_domain])
 
     assert_receive {^ref, event}
-    assert event.message == "no domain"
+    assert event.message.formatted == "no domain"
   end
 
   test "includes Logger metadata for keys configured to be included" do
@@ -233,7 +233,7 @@ defmodule Sentry.LoggerBackendTest do
     Logger.error("Testing")
 
     assert_receive {^ref, event}
-    assert event.message == "Testing"
+    assert event.message.formatted == "Testing"
   after
     Logger.configure_backend(Sentry.LoggerBackend, capture_log_messages: false)
   end
@@ -251,7 +251,7 @@ defmodule Sentry.LoggerBackendTest do
 
     assert_receive {^ref, event}
 
-    assert event.message == "Testing"
+    assert event.message.formatted == "Testing"
     assert event.user.user_id == 3
   after
     Logger.configure_backend(Sentry.LoggerBackend, level: :error, capture_log_messages: false)
@@ -269,7 +269,7 @@ defmodule Sentry.LoggerBackendTest do
 
     assert_receive {^ref, event}
 
-    assert event.message == "Error"
+    assert event.message.formatted == "Error"
   after
     Logger.configure_backend(Sentry.LoggerBackend, level: :error, capture_log_messages: false)
   end
@@ -303,7 +303,7 @@ defmodule Sentry.LoggerBackendTest do
     Logger.error("Error", callers: [dead_pid, nil])
 
     assert_receive {^ref, event}
-    assert event.message == "Error"
+    assert event.message.formatted == "Error"
   end
 
   test "doesn't log events with :sentry as a domain" do

test/plug_capture_test.exs

@@ -150,7 +150,7 @@ defmodule Sentry.PlugCaptureTest do
         event = decode_event_from_envelope!(body)
 
         assert event["culprit"] == "Sentry.PlugCaptureTest.PhoenixController.exit/2"
-        assert event["message"] == "Uncaught exit - :test"
+        assert event["message"]["formatted"] == "Uncaught exit - :test"
         Plug.Conn.resp(conn, 200, ~s<{"id": "340"}>)
       end)
 
@@ -164,7 +164,7 @@ defmodule Sentry.PlugCaptureTest do
         event = decode_event_from_envelope!(body)
 
         assert event["culprit"] == "Sentry.PlugCaptureTest.PhoenixController.throw/2"
-        assert event["message"] == "Uncaught throw - :test"
+        assert event["message"]["formatted"] == "Uncaught throw - :test"
         Plug.Conn.resp(conn, 200, ~s<{"id": "340"}>)
       end)
 

test/sentry/client_test.exs

@@ -20,7 +20,7 @@ defmodule Sentry.ClientTest do
     test "truncates the message to a max length" do
       max_length = 8_192
       event = Event.create_event(message: String.duplicate("a", max_length + 1))
-      assert Client.render_event(event).message == String.duplicate("a", max_length)
+      assert Client.render_event(event).message.formatted == String.duplicate("a", max_length)
     end
 
     test "safely inspects terms that cannot be converted to JSON" do
@@ -232,7 +232,11 @@ defmodule Sentry.ClientTest do
         |> Stream.take(10)
         |> Enum.at(0)
 
-      assert event["message"] == "Something went wrong"
+      assert event["message"] == %{
+               "formatted" => "Something went wrong",
+               "message" => nil,
+               "params" => nil
+             }
     end
 
     test "dedupes events", %{bypass: bypass} do