Add finch instrumentation

README.md

@@ -90,6 +90,7 @@ Some common Elixir packages are auto-instrumented via [`telemetry`](https://gith
 * [`Phoenix`](https://github.com/phoenixframework/phoenix): See [NewRelic.Telemetry.Phoenix](https://hexdocs.pm/new_relic_agent/NewRelic.Telemetry.Phoenix.html) for details.
 * [`Ecto`](https://github.com/elixir-ecto/ecto): See [NewRelic.Telemetry.Ecto](https://hexdocs.pm/new_relic_agent/NewRelic.Telemetry.Ecto.html) for details.
 * [`Redix`](https://github.com/whatyouhide/redix): See [NewRelic.Telemetry.Redix](https://hexdocs.pm/new_relic_agent/NewRelic.Telemetry.Redix.html) for details.
+* [`Finch`](https://github.com/sneako/finch): See [NewRelic.Telemetry.Finch](https://hexdocs.pm/new_relic_agent/NewRelic.Telemetry.Finch.html) for details.
 
 ## Agent features
 
@@ -118,13 +119,13 @@ spawn(fn ->
 end)
 ```
 
-If you are using a `Task` to spawn work, you can use the pre-instrumented `NewRelic.Instrumented.Task` convienince module to make this easier. Just `alias` it in your module and all your Tasks will be instrumented. You may also use the functions directly.
+If you are using a `Task` to spawn work, you can use the pre-instrumented `NewRelic.Instrumented.Task` convenience module to make this easier. Just `alias` it in your module and all your Tasks will be instrumented. You may also use the functions directly.
 
 ```elixir
 alias NewRelic.Instrumented.Task
 
 Task.Supervisor.async_nolink(MyTaskSupervisor, fn ->
-  # This process wil be automatically connected to the Transaction...
+  # This process will be automatically connected to the current Transaction...
 end)
 ```
 
@@ -145,15 +146,11 @@ end
 
 #### Distributed Tracing
 
-Requests to other services can be traced with the combination of an additional outgoing header and an `:external` tracer.
+Requests to other services can be connected with an additional outgoing header.
 
 ```elixir
 defmodule MyExternalService do
-  use NewRelic.Tracer
-
-  @trace {:request, category: :external}
   def request(method, url, headers) do
-    NewRelic.set_span(:http, url: url, method: method, component: "HttpClient")
     headers = headers ++ NewRelic.distributed_trace_headers(:http)
     HttpClient.request(method, url, headers)
   end

lib/new_relic.ex

@@ -163,7 +163,7 @@ defmodule NewRelic do
 
   @doc """
   Advanced:
-  Call to manually disconnect the current proccess from the current Transaction.
+  Call to manually disconnect the current process from the current Transaction.
   """
   defdelegate disconnect_from_transaction(), to: NewRelic.Transaction.Reporter
 
@@ -174,7 +174,7 @@ defmodule NewRelic do
   - `:type`
     - `:generic` - Pass custom attributes
     - `:http` - Pass attributes `:url`, `:method`, `:component`
-    - `:datastore` - Pass attrributes `:statement`, `:instance`, `:address`, `:hostname`,
+    - `:datastore` - Pass attributes `:statement`, `:instance`, `:address`, `:hostname`,
       `:component`
 
   ## Examples
@@ -205,6 +205,7 @@ defmodule NewRelic do
   * Call `distributed_trace_headers` immediately before making the
   request since calling the function marks the "start" time of the request.
   """
+  @spec distributed_trace_headers(:http) :: [{key :: binary, value :: binary}]
   defdelegate distributed_trace_headers(type), to: NewRelic.DistributedTrace
 
   @doc """

lib/new_relic/config.ex

@@ -153,6 +153,8 @@ defmodule NewRelic.Config do
     * Controls all Redix instrumentation
   * `:oban_instrumentation_enabled` (default `true`)
     * Controls all Oban instrumentation
+  * `:finch_instrumentation_enabled` (default `true`)
+    * Controls all Finch instrumentation
   * `:request_queuing_metrics_enabled`
     * Controls collection of request queuing metrics
 
@@ -197,6 +199,10 @@ defmodule NewRelic.Config do
     get(:features, :oban_instrumentation)
   end
 
+  def feature?(:finch_instrumentation) do
+    get(:features, :finch_instrumentation)
+  end
+
   def feature?(:function_argument_collection) do
     get(:features, :function_argument_collection)
   end

lib/new_relic/distributed_trace.ex

@@ -244,8 +244,8 @@ defmodule NewRelic.DistributedTrace do
 
   def set_current_span(label: label, ref: ref) do
     current = {label, ref}
-    previous_span = Process.get(:nr_current_span)
-    previous_span_attrs = Process.get(:nr_current_span_attrs)
+    previous_span = Process.delete(:nr_current_span)
+    previous_span_attrs = Process.delete(:nr_current_span_attrs)
     Process.put(:nr_current_span, current)
     {current, previous_span, previous_span_attrs}
   end

lib/new_relic/init.ex

@@ -103,6 +103,11 @@ defmodule NewRelic.Init do
           "NEW_RELIC_OBAN_INSTRUMENTATION_ENABLED",
           :oban_instrumentation_enabled
         ),
+      finch_instrumentation:
+        determine_feature(
+          "NEW_RELIC_FINCH_INSTRUMENTATION_ENABLED",
+          :finch_instrumentation_enabled
+        ),
       function_argument_collection:
         determine_feature(
           "NEW_RELIC_FUNCTION_ARGUMENT_COLLECTION_ENABLED",

lib/new_relic/telemetry/finch.ex

@@ -0,0 +1,256 @@
+defmodule NewRelic.Telemetry.Finch do
+  use GenServer
+  require Logger
+
+  @moduledoc """
+  Provides `Finch` instrumentation via `telemetry`.
+
+  Finch requests are auto-discovered and instrumented as "external" calls.
+
+  We automatically gather:
+  * Transaction segments
+  * External metrics
+  * External spans
+
+  You can opt-out of this instrumentation via configuration. See `NewRelic.Config` for details.
+  """
+  def start_link(_) do
+    config = %{
+      enabled?: NewRelic.Config.feature?(:finch_instrumentation),
+      handler_id: {:new_relic, :finch}
+    }
+
+    GenServer.start_link(__MODULE__, config, name: __MODULE__)
+  end
+
+  @finch_request_start [:finch, :request, :start]
+  @finch_request_stop [:finch, :request, :stop]
+  @finch_request_exception [:finch, :request, :exception]
+
+  @finch_events [
+    @finch_request_start,
+    @finch_request_stop,
+    @finch_request_exception
+  ]
+
+  @doc false
+  def init(%{enabled?: false}), do: :ignore
+
+  def init(%{enabled?: true} = config) do
+    :telemetry.attach_many(
+      config.handler_id,
+      @finch_events,
+      &__MODULE__.handle_event/4,
+      config
+    )
+
+    Process.flag(:trap_exit, true)
+    {:ok, config}
+  end
+
+  @doc false
+  def terminate(_reason, %{handler_id: handler_id}) do
+    :telemetry.detach(handler_id)
+  end
+
+  def handle_event(
+        @finch_request_start,
+        %{monotonic_time: monotonic_time, system_time: system_time},
+        %{request: request},
+        config
+      ) do
+    if instrument?() do
+      {span, previous_span, previous_span_attrs} =
+        NewRelic.DistributedTrace.set_current_span(
+          label: {request.method, request.scheme, request.host, request.path},
+          ref: make_ref()
+        )
+
+      Process.put(
+        config.handler_id,
+        %{
+          start_time_mono: monotonic_time,
+          system_time: system_time,
+          span: span,
+          previous_span: previous_span,
+          previous_span_attrs: previous_span_attrs
+        }
+      )
+    end
+  end
+
+  def handle_event(
+        @finch_request_stop,
+        %{monotonic_time: end_time_mono, duration: duration},
+        %{name: finch_pool, request: request, result: result},
+        config
+      ) do
+    if instrument?() do
+      %{
+        start_time_mono: start_time_mono,
+        system_time: start_time,
+        span: span,
+        previous_span: previous_span,
+        previous_span_attrs: previous_span_attrs
+      } = Process.delete(config.handler_id)
+
+      metric_name = "External/#{request.host}/Finch/#{request.method}"
+      secondary_name = "#{request.host} - Finch/#{request.method}"
+
+      duration_ms = System.convert_time_unit(duration, :native, :millisecond)
+      duration_s = duration_ms / 1000
+
+      id = span
+      parent_id = previous_span || :root
+
+      url =
+        URI.to_string(%URI{scheme: "#{request.scheme}", host: request.host, path: request.path})
+
+      result_attrs =
+        case result do
+          {:ok, %{__struct__: Finch.Response} = response} -> %{"response.status": response.status}
+          {:ok, _acc} -> %{}
+          {:error, exception} -> %{error: true, "error.message": Exception.message(exception)}
+        end
+
+      NewRelic.Transaction.Reporter.add_trace_segment(%{
+        primary_name: metric_name,
+        secondary_name: secondary_name,
+        attributes: %{},
+        pid: self(),
+        id: span,
+        parent_id: parent_id,
+        start_time: start_time,
+        start_time_mono: start_time_mono,
+        end_time_mono: end_time_mono
+      })
+
+      NewRelic.report_span(
+        timestamp_ms: System.convert_time_unit(start_time, :native, :millisecond),
+        duration_s: duration_s,
+        name: metric_name,
+        edge: [span: id, parent: parent_id],
+        category: "http",
+        attributes:
+          %{
+            "request.url": url,
+            "request.method": request.method,
+            "request.client": "Finch",
+            "finch.pool": finch_pool
+          }
+          |> Map.merge(result_attrs)
+      )
+
+      NewRelic.incr_attributes(
+        "external.#{request.host}.call_count": 1,
+        "external.#{request.host}.duration_ms": duration_ms
+      )
+
+      NewRelic.report_metric(
+        {:external, url, "Finch", request.method},
+        duration_s: duration_s
+      )
+
+      NewRelic.Transaction.Reporter.track_metric({
+        {:external, url, "Finch", request.method},
+        duration_s: duration_s
+      })
+
+      NewRelic.DistributedTrace.reset_span(
+        previous_span: previous_span,
+        previous_span_attrs: previous_span_attrs
+      )
+    end
+  end
+
+  def handle_event(
+        @finch_request_exception,
+        %{duration: duration},
+        %{kind: kind, reason: reason, name: finch_pool, request: request},
+        config
+      ) do
+    if instrument?() do
+      %{
+        system_time: start_time,
+        span: span,
+        previous_span: previous_span,
+        previous_span_attrs: previous_span_attrs
+      } = Process.delete(config.handler_id)
+
+      metric_name = "External/#{request.host}/Finch/#{request.method}"
+
+      duration_ms = System.convert_time_unit(duration, :native, :millisecond)
+      duration_s = duration_ms / 1000
+
+      id = span
+      parent_id = previous_span || :root
+
+      url =
+        URI.to_string(%URI{scheme: "#{request.scheme}", host: request.host, path: request.path})
+
+      error_message = NewRelic.Util.Error.format_reason(kind, reason)
+
+      NewRelic.report_span(
+        timestamp_ms: System.convert_time_unit(start_time, :native, :millisecond),
+        duration_s: duration_s,
+        name: metric_name,
+        edge: [span: id, parent: parent_id],
+        category: "http",
+        attributes: %{
+          error: true,
+          "error.message": error_message,
+          "request.url": url,
+          "request.method": request.method,
+          "request.client": "Finch",
+          "finch.pool": finch_pool
+        }
+      )
+
+      NewRelic.DistributedTrace.reset_span(
+        previous_span: previous_span,
+        previous_span_attrs: previous_span_attrs
+      )
+    end
+  end
+
+  def handle_event(_event, _measurements, _meta, config) do
+    with %{
+           previous_span: previous_span,
+           previous_span_attrs: previous_span_attrs
+         } <- Process.delete(config.handler_id) do
+      NewRelic.DistributedTrace.reset_span(
+        previous_span: previous_span,
+        previous_span_attrs: previous_span_attrs
+      )
+    end
+  end
+
+  # Avoid double instrumenting in situation where
+  # application has manually instrumented externals already
+  defp instrument?() do
+    case Process.get(:nr_already_tracing_external) do
+      true ->
+        warn_once(
+          "[New Relic] Trace `:external` deprecated in favor of automatic Finch instrumentation. " <>
+            "Please remove @trace `category: :external` annotations from Finch requests, or disable " <>
+            "automatic Finch instrumentation."
+        )
+
+        false
+
+      _ ->
+        true
+    end
+  end
+
+  defp warn_once(message) do
+    case :persistent_term.get(__MODULE__, :not_logged) do
+      :logged ->
+        :skip
+
+      :not_logged ->
+        :persistent_term.put(__MODULE__, :logged)
+        Logger.warning(message)
+    end
+  end
+end

lib/new_relic/telemetry/supervisor.ex

@@ -13,7 +13,8 @@ defmodule NewRelic.Telemetry.Supervisor do
       NewRelic.Telemetry.Redix,
       NewRelic.Telemetry.Plug,
       NewRelic.Telemetry.Phoenix,
-      NewRelic.Telemetry.Oban
+      NewRelic.Telemetry.Oban,
+      NewRelic.Telemetry.Finch
     ]
 
     Supervisor.init(children, strategy: :one_for_one)