Skip to content

Commit

Permalink
Merge pull request #469 from newrelic/vince/instrument-finch
Browse files Browse the repository at this point in the history
Add finch instrumentation
  • Loading branch information
tpitale authored Jan 13, 2025
2 parents 4ad638c + c1e4f72 commit c3bef0b
Show file tree
Hide file tree
Showing 14 changed files with 443 additions and 59 deletions.
11 changes: 4 additions & 7 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,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

Expand Down Expand Up @@ -108,13 +109,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)
```

Expand All @@ -135,15 +136,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
Expand Down
5 changes: 3 additions & 2 deletions lib/new_relic.ex
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand All @@ -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
Expand Down Expand Up @@ -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 """
Expand Down
6 changes: 6 additions & 0 deletions lib/new_relic/config.ex
Original file line number Diff line number Diff line change
Expand Up @@ -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` (default `true`)
* Controls collection of request queuing metrics
* `:extended_attributes` (default `true`)
Expand Down Expand Up @@ -199,6 +201,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
Expand Down
4 changes: 2 additions & 2 deletions lib/new_relic/distributed_trace.ex
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
5 changes: 5 additions & 0 deletions lib/new_relic/init.ex
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand Down
256 changes: 256 additions & 0 deletions lib/new_relic/telemetry/finch.ex
Original file line number Diff line number Diff line change
@@ -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
3 changes: 2 additions & 1 deletion lib/new_relic/telemetry/supervisor.ex
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,8 @@ defmodule NewRelic.Telemetry.Supervisor do
NewRelic.Telemetry.Redix,
NewRelic.Telemetry.Plug,
NewRelic.Telemetry.Phoenix,
NewRelic.Telemetry.Oban
NewRelic.Telemetry.Oban,
NewRelic.Telemetry.Finch
]
end

Expand Down
Loading

0 comments on commit c3bef0b

Please sign in to comment.