Packages

Zero-config APM SDK for Elixir — Phoenix, Plug, Ecto. Add the dep and set METRIXWIRE_KEY; every request/query/HTTP call is traced automatically.

Current section

Files

Jump to
metrixwire lib metrixwire telemetry.ex
Raw

lib/metrixwire/telemetry.ex

defmodule MetrixWire.Telemetry do
@moduledoc """
The single set of `:telemetry` handlers that instruments the whole Elixir
ecosystem. Attached once at boot by `MetrixWire.Application` via
`:telemetry.attach_many/4`, so no framework code changes are needed.
Covers:
* **Phoenix** request lifecycle → open/close a trace (route, method, status).
* **Ecto** `[_, :repo, :query]` → `db_query` spans (SQL, duration, rowCount).
* **Finch** / **Tesla** → `http_call` spans (statusCode).
Ecto/Finch telemetry runs in the CALLER process, so the process-dictionary
`Context` correlation attaches those spans to the active request trace. Every
handler is wrapped so a bad event can never crash the emitting process.
"""
require Logger
alias MetrixWire.{Context, Span, Trace}
alias MetrixWire.Instrument.SourceLocation
@handler_id "metrixwire-telemetry"
# Phoenix opens/closes the trace. Ecto/Finch/Tesla add spans to it.
#
# We hook `router_dispatch` (emitted by Phoenix.Router itself) rather than
# `[:phoenix, :endpoint, :*]`, because endpoint telemetry is only emitted when the
# app's endpoint happens to include a `Plug.Telemetry` plug — not guaranteed.
# `router_dispatch` is truly automatic, so this stays zero-config. The `:stop`
# event fires after the controller has set the response status, so the conn there
# carries the final status we need.
@events [
[:phoenix, :router_dispatch, :start],
[:phoenix, :router_dispatch, :stop],
[:phoenix, :router_dispatch, :exception],
[:finch, :request, :stop],
[:finch, :request, :exception],
[:tesla, :request, :stop]
]
@doc """
Attach every handler. Idempotent — detaches any prior attachment first. Ecto
query events are attached separately (per-repo prefix) via `attach_ecto/0`.
"""
def attach do
detach()
:telemetry.attach_many(@handler_id, @events, &__MODULE__.handle_event/4, %{})
attach_ecto()
:ok
rescue
_ -> :ok
end
def detach do
:telemetry.detach(@handler_id)
rescue
_ -> :ok
end
# ── Ecto ───────────────────────────────────────────────────────────────────
# Ecto emits `[<otp_app>, <repo>, :query]`; the prefix is app-configurable, so we
# discover the configured repos and attach to each. If none are discoverable yet
# (repos start after us), a broad fallback covers the common `[_, :repo, :query]`
# convention by attaching to every known telemetry event prefix at boot AND
# re-running discovery is unnecessary because we also attach to router_dispatch
# start (below) which is guaranteed present under Phoenix.
@doc "Attach a `db_query` handler to every configured Ecto repo's query event."
def attach_ecto do
for {event, id} <- ecto_events() do
:telemetry.attach(id, event, &__MODULE__.handle_ecto_query/4, %{})
end
:ok
rescue
_ -> :ok
end
# Build the list of {telemetry_event, handler_id} pairs for all discoverable repos.
defp ecto_events do
discover_repos()
|> Enum.map(fn repo ->
prefix = repo.config()[:telemetry_prefix] || default_prefix(repo)
event = prefix ++ [:query]
{event, "metrixwire-ecto-" <> Enum.map_join(event, "-", &to_string/1)}
end)
|> Enum.uniq()
rescue
_ -> []
end
# Ecto's default telemetry prefix is [<otp_app>, <last-segment-of-repo-module>].
defp default_prefix(repo) do
otp_app = repo.config()[:otp_app] || :app
last = repo |> Module.split() |> List.last() |> Macro.underscore() |> String.to_atom()
[otp_app, last]
rescue
_ -> [:app, :repo]
end
# Find modules that `use Ecto.Repo` across loaded applications.
defp discover_repos do
for {app, _, _} <- Application.loaded_applications(),
{:ok, mods} = safe_modules(app),
mod <- mods,
ecto_repo?(mod) do
mod
end
|> Enum.uniq()
rescue
_ -> []
end
defp safe_modules(app) do
case :application.get_key(app, :modules) do
{:ok, mods} -> {:ok, mods}
_ -> {:ok, []}
end
rescue
_ -> {:ok, []}
end
defp ecto_repo?(mod) do
Code.ensure_loaded?(mod) and function_exported?(mod, :__adapter__, 0) and
function_exported?(mod, :config, 0)
rescue
_ -> false
end
# ── event dispatch ──────────────────────────────────────────────────────────
@doc false
def handle_event(event, measurements, metadata, config) do
do_handle(event, measurements, metadata, config)
rescue
_ -> :ok
catch
_, _ -> :ok
end
# Phoenix request start — open a trace with the matched route, park it in the
# process dictionary. (router_dispatch runs in the request process.)
defp do_handle([:phoenix, :router_dispatch, :start], _measurements, metadata, _config) do
if MetrixWire.enabled?() do
conn = metadata[:conn]
method = conn_method(conn)
route = dispatch_route(metadata) || "#{method} #{conn_path(conn)}"
Context.put(Trace.new(route, method))
end
:ok
end
# Phoenix request stop — the controller has run and set the response status;
# finalize + enqueue.
defp do_handle([:phoenix, :router_dispatch, :stop], _measurements, metadata, _config) do
case Context.current() do
%Trace{} = trace ->
status = conn_status(metadata[:conn])
trace =
trace
|> maybe_error_status(status)
|> Trace.finalize()
MetrixWire.enqueue(trace)
Context.clear()
_ ->
:ok
end
end
# Router-level exception → mark the trace as an error, then finalize + enqueue
# (the request process is about to unwind, so we close the trace here).
defp do_handle([:phoenix, :router_dispatch, :exception], _measurements, metadata, _config) do
case Context.current() do
%Trace{} = trace ->
error = metadata[:reason] || metadata[:error] || metadata[:exception]
stack = metadata[:stacktrace]
trace =
trace
|> Trace.capture_exception(error, stack)
|> Trace.finalize()
MetrixWire.enqueue(trace)
Context.clear()
_ ->
:ok
end
end
# Finch outbound HTTP call → http_call span.
defp do_handle([:finch, :request, :stop], measurements, metadata, _config) do
duration = native_to_ms(measurements[:duration])
desc = finch_description(metadata)
status = finch_status(metadata[:result])
add_span("http_call", desc, duration, status && %{"statusCode" => status})
end
defp do_handle([:finch, :request, :exception], measurements, metadata, _config) do
duration = native_to_ms(measurements[:duration])
desc = finch_description(metadata)
add_span("http_call", desc, duration, nil)
end
# Tesla outbound HTTP call → http_call span.
defp do_handle([:tesla, :request, :stop], measurements, metadata, _config) do
duration = native_to_ms(measurements[:duration])
env = metadata[:env] || (metadata[:result] |> tesla_env())
desc = tesla_description(env)
status = tesla_status(env)
add_span("http_call", desc, duration, status && %{"statusCode" => status})
end
defp do_handle(_event, _measurements, _metadata, _config), do: :ok
# ── Ecto handler ────────────────────────────────────────────────────────────
@schema_sql ~r/\A\s*(BEGIN|COMMIT|ROLLBACK|SAVEPOINT|RELEASE|SET|SHOW|PRAGMA|EXPLAIN)\b/i
@doc false
def handle_ecto_query(_event, measurements, metadata, _config) do
with %Trace{} <- Context.current(),
sql when is_binary(sql) <- metadata[:query],
false <- Regex.match?(@schema_sql, sql) do
total = ecto_total_time(measurements)
duration = native_to_ms(total)
meta = row_count_meta(metadata[:result])
add_span("db_query", sql, duration, meta)
else
_ -> :ok
end
rescue
_ -> :ok
catch
_, _ -> :ok
end
# total_time = query_time + decode_time + queue_time (all in native units).
defp ecto_total_time(measurements) do
case measurements[:total_time] do
nil ->
(measurements[:query_time] || 0) + (measurements[:decode_time] || 0) +
(measurements[:queue_time] || 0)
total ->
total
end
end
defp row_count_meta(result) do
case result do
{:ok, %{num_rows: n}} when is_integer(n) -> %{"rowCount" => n}
%{num_rows: n} when is_integer(n) -> %{"rowCount" => n}
_ -> nil
end
rescue
_ -> nil
end
# ── span construction ───────────────────────────────────────────────────────
defp add_span(_type, nil, _duration, _meta), do: :ok
defp add_span(_type, "", _duration, _meta), do: :ok
defp add_span(type, description, duration, meta) do
Context.update(fn trace ->
span =
Span.new(type, description, MetrixWire.iso8601_ago(duration), duration,
source_location: SourceLocation.nearest(),
meta: meta
)
Trace.add_span(trace, span)
end)
:ok
end
# ── helpers ─────────────────────────────────────────────────────────────────
defp maybe_error_status(trace, status) when is_integer(status) and status >= 500 do
%{trace | status: "error"}
end
defp maybe_error_status(trace, _status), do: trace
defp native_to_ms(nil), do: 0
defp native_to_ms(native) when is_integer(native) do
System.convert_time_unit(native, :native, :microsecond) / 1000.0
rescue
_ -> 0
end
defp native_to_ms(_), do: 0
# ── conn accessors (defensive: never assume Plug.Conn is loaded) ─────────────
defp conn_method(%{method: method}) when is_binary(method), do: method
defp conn_method(_), do: "GET"
defp conn_path(%{request_path: path}) when is_binary(path) and path != "", do: path
defp conn_path(_), do: "/"
defp conn_status(%{status: status}) when is_integer(status), do: status
defp conn_status(_), do: nil
# Refine "GET /users/:id" from the matched Phoenix route.
defp dispatch_route(metadata) do
route = metadata[:route]
conn = metadata[:conn]
method = conn_method(conn)
cond do
is_binary(route) and route != "" -> "#{method} #{route}"
true -> nil
end
rescue
_ -> nil
end
# ── Finch / Tesla description + status ───────────────────────────────────────
defp finch_description(metadata) do
req = metadata[:request]
case req do
%{scheme: scheme, host: host, port: port, path: path, method: method} ->
"#{method} #{scheme}://#{host_port(scheme, host, port)}#{path || "/"}"
_ ->
nil
end
rescue
_ -> nil
end
defp finch_status({:ok, %{status: status}}) when is_integer(status), do: status
defp finch_status(%{status: status}) when is_integer(status), do: status
defp finch_status(_), do: nil
defp tesla_env({:ok, env}), do: env
defp tesla_env(env) when is_map(env), do: env
defp tesla_env(_), do: nil
defp tesla_description(nil), do: nil
defp tesla_description(env) do
method = env |> Map.get(:method, :get) |> to_string() |> String.upcase()
url = Map.get(env, :url)
if is_binary(url), do: "#{method} #{String.split(url, "?") |> hd()}", else: nil
rescue
_ -> nil
end
defp tesla_status(%{status: status}) when is_integer(status), do: status
defp tesla_status(_), do: nil
defp host_port(scheme, host, port) do
default? = (scheme in [:https, "https"] and port == 443) or (scheme in [:http, "http"] and port == 80)
if default? or is_nil(port), do: host, else: "#{host}:#{port}"
end
end