feat: add metadata to telemetry events

Added telemetry support to webhook handler and changed metadata included
in API requests.

API requests metadata contains some low cardinality fields that can be
useful when visualising these metrics in other tools. For example using
'stripe.request.stop' event we can infer metrics for RED method and have
visibility into all Stripe API endpoints.

'url' passed in to 'do_perform_request_and_retry' contains query params
which can contain sensitive data such as emails so it is URI-parsed and
all params are dropped.

Webhooks are often important part of integration with Stripe and having
telemetry in place for that is good idea too imo.

lib/stripe/api.ex

@@ -377,13 +377,21 @@ defmodule Stripe.API do
 
  defp do_perform_request_and_retry(method, url, headers, body, opts, {:attempts, attempts}) do
  response =
- :telemetry.span(~w[stripe request]a, %{url: url, method: method}, fn ->
+ :telemetry.span(~w[stripe request]a, %{}, fn ->
+ telemetry_meta = %{
+ endpoint: URI.parse(url).path,
+ method: method,
+ attempt: attempts,
+ stripe_api_version: headers["Stripe-Version"],
+ status: nil
+ }
+
  case http_module().request(method, url, Map.to_list(headers), body, opts) do
  {:ok, status, _, _} = resp ->
- {resp, %{status: status}}
+ {resp, %{telemetry_meta | status: status}}
 
  error ->
- {error, %{}}
+ {error, telemetry_meta}
  end
  end)
 

lib/stripe/webhook_plug.ex

@@ -159,30 +159,38 @@ if Code.ensure_loaded?(Plug) do
  end
 
  defp handle_event!(handler, %Stripe.Event{} = event) do
- case handler.handle_event(event) do
- {:ok, _} ->
- :ok
-
- :ok ->
- :ok
-
- {:error, reason} when is_binary(reason) ->
- {:handle_error, reason}
-
- {:error, reason} when is_atom(reason) ->
- {:handle_error, Atom.to_string(reason)}
-
- :error ->
- {:handle_error, ""}
-
- resp ->
- raise """
- #{inspect(handler)}.handle_event/1 returned an invalid response. Expected {:ok, term}, :ok, {:error, reason} or :error
- Got: #{inspect(resp)}
-
- Event data: #{inspect(event)}
- """
- end
+ :telemetry.span(~w[stripe webhook]a, %{}, fn ->
+ telemetry_meta = %{event: event.type, handler_status: nil}
+
+ case handler.handle_event(event) do
+ {:ok, _} ->
+ :ok
+
+ :ok ->
+ :ok
+
+ {:error, reason} when is_binary(reason) ->
+ {:handle_error, reason}
+
+ {:error, reason} when is_atom(reason) ->
+ {:handle_error, Atom.to_string(reason)}
+
+ :error ->
+ {:handle_error, ""}
+
+ resp ->
+ raise """
+ #{inspect(handler)}.handle_event/1 returned an invalid response. Expected {:ok, term}, :ok, {:error, reason} or :error
+ Got: #{inspect(resp)}
+
+ Event data: #{inspect(event)}
+ """
+ end
+ |> then(fn
+ :ok -> {:ok, %{telemetry_meta | handler_status: :ok}}
+ result -> {result, %{telemetry_meta | handler_status: :error}}
+ end)
+ end)
  end
 
  defp parse_secret!({m, f, a}), do: apply(m, f, a)

test/stripe/api_test.exs

@@ -2,6 +2,10 @@ defmodule Stripe.APITest do
  import Mox
  use Stripe.StripeCase
 
+ def telemetry_handler_fn(name, measurements, metadata, _config) do
+ send(self(), {:telemetry_event, name, measurements, metadata})
+ end
+
  test "works with non existent responses without issue" do
  {:error, %Stripe.Error{extra: %{http_status: 404}}} =
  Stripe.API.request(%{}, :get, "/", %{}, [])
@@ -87,6 +91,41 @@ defmodule Stripe.APITest do
  end
  end
 
+ describe "telemetry" do
+ test "requests emit :start, :stop telemetry events", %{test: test} do
+ :telemetry.attach_many(
+ "#{test}",
+ [[:stripe, :request, :start], [:stripe, :request, :stop]],
+ &__MODULE__.telemetry_handler_fn/4,
+ nil
+ )
+
+ %{query: ~s|email: "[email protected]"|}
+ |> Stripe.API.request(:get, "/v1/customers/search", %{}, [])
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :request, :start],
+ %{monotonic_time: _},
+ %{telemetry_span_context: _}
+ })
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :request, :stop],
+ %{monotonic_time: _, duration: _},
+ %{
+ telemetry_span_context: _,
+ endpoint: "/v1/customers/search",
+ attempt: 0,
+ method: :get,
+ status: 200,
+ stripe_api_version: _
+ }
+ })
+ end
+ end
+
  @tag :skip
  test "gets default api version" do
  Stripe.API.request(%{}, :get, "products", %{}, [])

test/stripe/webhook_plug_test.exs

@@ -3,7 +3,7 @@ defmodule Stripe.WebhookPlugTest do
  use Plug.Test
  alias Stripe.WebhookPlug
 
- @valid_payload ~S({"object": "event"})
+ @valid_payload ~S({"object": "event", "type": "customer.updated"})
  @secret "secret"
 
  @opts WebhookPlug.init(
@@ -46,6 +46,10 @@ defmodule Stripe.WebhookPlugTest do
 
  def get_value(:secret), do: @secret
 
+ def telemetry_handler_fn(name, measurements, metadata, _config) do
+ send(self(), {:telemetry_event, name, measurements, metadata})
+ end
+
  defp generate_signature_header(payload) do
  timestamp = System.system_time(:second)
 
@@ -185,5 +189,96 @@ defmodule Stripe.WebhookPlugTest do
  WebhookPlug.call(conn, opts)
  end
  end
+
+ test "emits :start, :exception telemetry events on exception", %{conn: conn, test: test} do
+ :telemetry.attach_many(
+ "#{test}",
+ [[:stripe, :webhook, :start], [:stripe, :webhook, :exception]],
+ &__MODULE__.telemetry_handler_fn/4,
+ nil
+ )
+
+ opts =
+ WebhookPlug.init(
+ at: "/webhook/stripe",
+ handler: __MODULE__.BadHandler,
+ secret: @secret
+ )
+
+ assert_raise RuntimeError, fn ->
+ WebhookPlug.call(conn, opts)
+ end
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :webhook, :start],
+ %{monotonic_time: _},
+ %{telemetry_span_context: _}
+ })
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :webhook, :exception],
+ %{monotonic_time: _, duration: _},
+ %{kind: _, reason: _, stacktrace: _, telemetry_span_context: _}
+ })
+ end
+
+ test "emits :start, :stop telemetry events on soft failure", %{conn: conn, test: test} do
+ :telemetry.attach_many(
+ "#{test}",
+ [[:stripe, :webhook, :start], [:stripe, :webhook, :stop]],
+ &__MODULE__.telemetry_handler_fn/4,
+ nil
+ )
+
+ opts =
+ WebhookPlug.init(
+ at: "/webhook/stripe",
+ handler: __MODULE__.ErrorTupleAtomHandler,
+ secret: @secret
+ )
+
+ WebhookPlug.call(conn, opts)
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :webhook, :start],
+ %{monotonic_time: _},
+ %{telemetry_span_context: _}
+ })
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :webhook, :stop],
+ %{monotonic_time: _, duration: _},
+ %{handler_status: :error, telemetry_span_context: _}
+ })
+ end
+
+ test "emits :start, :stop telemetry events on success", %{conn: conn, test: test} do
+ :telemetry.attach_many(
+ "#{test}",
+ [[:stripe, :webhook, :start], [:stripe, :webhook, :stop]],
+ &__MODULE__.telemetry_handler_fn/4,
+ nil
+ )
+
+ WebhookPlug.call(conn, @opts)
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :webhook, :start],
+ %{monotonic_time: _},
+ %{telemetry_span_context: _}
+ })
+
+ assert_received({
+ :telemetry_event,
+ [:stripe, :webhook, :stop],
+ %{monotonic_time: _, duration: _},
+ %{handler_status: :ok, event: "customer.updated", telemetry_span_context: _}
+ })
+ end
  end
 end