2021-09-12 19:49:24 +00:00
|
|
|
defmodule OpentelemetryPhoenix do
|
|
|
|
@moduledoc """
|
|
|
|
OpentelemetryPhoenix uses [telemetry](https://hexdocs.pm/telemetry/) handlers to create `OpenTelemetry` spans.
|
|
|
|
|
|
|
|
Current events which are supported include endpoint start/stop, router start/stop,
|
|
|
|
and router exceptions.
|
|
|
|
|
|
|
|
## Usage
|
|
|
|
|
|
|
|
In your application start:
|
|
|
|
|
|
|
|
def start(_type, _args) do
|
|
|
|
OpentelemetryPhoenix.setup()
|
|
|
|
|
|
|
|
children = [
|
|
|
|
{Phoenix.PubSub, name: MyApp.PubSub},
|
|
|
|
MyAppWeb.Endpoint
|
|
|
|
]
|
|
|
|
|
|
|
|
opts = [strategy: :one_for_one, name: MyStore.Supervisor]
|
|
|
|
Supervisor.start_link(children, opts)
|
|
|
|
end
|
|
|
|
|
|
|
|
"""
|
|
|
|
|
|
|
|
require OpenTelemetry.Tracer
|
|
|
|
alias OpenTelemetry.Span
|
|
|
|
alias OpentelemetryPhoenix.Reason
|
|
|
|
|
2021-12-28 23:39:06 +00:00
|
|
|
@tracer_id __MODULE__
|
2021-09-12 19:49:24 +00:00
|
|
|
|
|
|
|
@typedoc "Setup options"
|
|
|
|
@type opts :: [endpoint_prefix()]
|
|
|
|
|
|
|
|
@typedoc "The endpoint prefix in your endpoint. Defaults to `[:phoenix, :endpoint]`"
|
|
|
|
@type endpoint_prefix :: {:endpoint_prefix, [atom()]}
|
|
|
|
|
|
|
|
@doc """
|
|
|
|
Initializes and configures the telemetry handlers.
|
|
|
|
"""
|
|
|
|
@spec setup(opts()) :: :ok
|
|
|
|
def setup(opts \\ []) do
|
|
|
|
opts = ensure_opts(opts)
|
|
|
|
|
|
|
|
attach_endpoint_start_handler(opts)
|
|
|
|
attach_endpoint_stop_handler(opts)
|
|
|
|
attach_router_start_handler()
|
|
|
|
attach_router_dispatch_exception_handler()
|
|
|
|
|
|
|
|
:ok
|
|
|
|
end
|
|
|
|
|
|
|
|
defp ensure_opts(opts), do: Keyword.merge(default_opts(), opts)
|
|
|
|
|
|
|
|
defp default_opts do
|
|
|
|
[endpoint_prefix: [:phoenix, :endpoint]]
|
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def attach_endpoint_start_handler(opts) do
|
|
|
|
:telemetry.attach(
|
|
|
|
{__MODULE__, :endpoint_start},
|
|
|
|
opts[:endpoint_prefix] ++ [:start],
|
|
|
|
&__MODULE__.handle_endpoint_start/4,
|
|
|
|
%{}
|
|
|
|
)
|
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def attach_endpoint_stop_handler(opts) do
|
|
|
|
:telemetry.attach(
|
|
|
|
{__MODULE__, :endpoint_stop},
|
|
|
|
opts[:endpoint_prefix] ++ [:stop],
|
|
|
|
&__MODULE__.handle_endpoint_stop/4,
|
|
|
|
%{}
|
|
|
|
)
|
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def attach_router_start_handler do
|
|
|
|
:telemetry.attach(
|
|
|
|
{__MODULE__, :router_dispatch_start},
|
|
|
|
[:phoenix, :router_dispatch, :start],
|
|
|
|
&__MODULE__.handle_router_dispatch_start/4,
|
|
|
|
%{}
|
|
|
|
)
|
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def attach_router_dispatch_exception_handler do
|
|
|
|
:telemetry.attach(
|
|
|
|
{__MODULE__, :router_dispatch_exception},
|
|
|
|
[:phoenix, :router_dispatch, :exception],
|
|
|
|
&__MODULE__.handle_router_dispatch_exception/4,
|
|
|
|
%{}
|
|
|
|
)
|
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def handle_endpoint_start(_event, _measurements, %{conn: %{adapter: adapter} = conn} = meta, _config) do
|
|
|
|
# TODO: maybe add config for what paths are traced? Via sampler?
|
2021-10-14 03:11:26 +00:00
|
|
|
:otel_propagator_text_map.extract(conn.req_headers)
|
2021-09-12 19:49:24 +00:00
|
|
|
|
|
|
|
peer_data = Plug.Conn.get_peer_data(conn)
|
|
|
|
|
|
|
|
user_agent = header_value(conn, "user-agent")
|
|
|
|
peer_ip = Map.get(peer_data, :address)
|
|
|
|
|
2021-12-28 23:39:06 +00:00
|
|
|
attributes = %{
|
2021-09-12 19:49:24 +00:00
|
|
|
"http.client_ip": client_ip(conn),
|
|
|
|
"http.flavor": http_flavor(adapter),
|
|
|
|
"http.host": conn.host,
|
|
|
|
"http.method": conn.method,
|
|
|
|
"http.scheme": "#{conn.scheme}",
|
|
|
|
"http.target": conn.request_path,
|
|
|
|
"http.user_agent": user_agent,
|
|
|
|
"net.host.ip": to_string(:inet_parse.ntoa(conn.remote_ip)),
|
|
|
|
"net.host.port": conn.port,
|
|
|
|
"net.peer.ip": to_string(:inet_parse.ntoa(peer_ip)),
|
|
|
|
"net.peer.port": peer_data.port,
|
|
|
|
"net.transport": :"IP.TCP"
|
2021-12-28 23:39:06 +00:00
|
|
|
}
|
2021-09-12 19:49:24 +00:00
|
|
|
|
|
|
|
# start the span with a default name. Route name isn't known until router dispatch
|
2021-12-17 16:16:26 +00:00
|
|
|
OpentelemetryTelemetry.start_telemetry_span(@tracer_id, "HTTP #{conn.method}", meta, %{
|
|
|
|
kind: :server,
|
|
|
|
attributes: attributes
|
|
|
|
})
|
2021-09-12 19:49:24 +00:00
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def handle_endpoint_stop(_event, _measurements, %{conn: conn} = meta, _config) do
|
|
|
|
# ensure the correct span is current and update the status
|
|
|
|
ctx = OpentelemetryTelemetry.set_current_telemetry_span(@tracer_id, meta)
|
|
|
|
|
2021-11-19 14:15:43 +00:00
|
|
|
Span.set_attribute(ctx, :"http.status_code", conn.status)
|
2021-09-12 19:49:24 +00:00
|
|
|
|
|
|
|
if conn.status >= 400 do
|
|
|
|
Span.set_status(ctx, OpenTelemetry.status(:error, ""))
|
|
|
|
end
|
|
|
|
|
|
|
|
# end the Phoenix span
|
|
|
|
OpentelemetryTelemetry.end_telemetry_span(@tracer_id, meta)
|
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def handle_router_dispatch_start(_event, _measurements, meta, _config) do
|
2021-12-28 23:39:06 +00:00
|
|
|
attributes = %{
|
2021-09-12 19:49:24 +00:00
|
|
|
"phoenix.plug": meta.plug,
|
|
|
|
"phoenix.action": meta.plug_opts,
|
|
|
|
"http.route": meta.route
|
2021-12-28 23:39:06 +00:00
|
|
|
}
|
2021-09-12 19:49:24 +00:00
|
|
|
|
|
|
|
# Add more info that we now know about but don't close the span
|
|
|
|
ctx = OpentelemetryTelemetry.set_current_telemetry_span(@tracer_id, meta)
|
|
|
|
Span.update_name(ctx, "#{meta.route}")
|
|
|
|
Span.set_attributes(ctx, attributes)
|
|
|
|
end
|
|
|
|
|
|
|
|
@doc false
|
|
|
|
def handle_router_dispatch_exception(
|
|
|
|
_event,
|
|
|
|
_measurements,
|
|
|
|
%{kind: kind, reason: reason, stacktrace: stacktrace} = meta,
|
|
|
|
_config
|
|
|
|
) do
|
Only attempt to record an exception if there is an active span. (#37)
There is an edge case, if you use `forward/4` and use Plug.ErrorHandler,
then when an exception reaches the outer router, then Plug.send_resp
will be called, triggering `[:phoenix, :endpoint, :stop]`, and the span
will be gone by the time the outer router gets the exception. This
causes this telemetry handler to crash and be detached.
Sequence of events:
- [:phoenix, :endpoint, :start]
- [:phoenix, :router_dispatch, :exception] (inner router)
- [:phoenix, :endpoint, :stop]
- [:phoenix, :router_dispatch, :exception] (outer router) ** here there is no span, crashes
2022-03-18 11:21:26 +00:00
|
|
|
if OpenTelemetry.Span.is_recording(OpenTelemetry.Tracer.current_span_ctx()) do
|
|
|
|
ctx = OpentelemetryTelemetry.set_current_telemetry_span(@tracer_id, meta)
|
2021-09-12 19:49:24 +00:00
|
|
|
|
Only attempt to record an exception if there is an active span. (#37)
There is an edge case, if you use `forward/4` and use Plug.ErrorHandler,
then when an exception reaches the outer router, then Plug.send_resp
will be called, triggering `[:phoenix, :endpoint, :stop]`, and the span
will be gone by the time the outer router gets the exception. This
causes this telemetry handler to crash and be detached.
Sequence of events:
- [:phoenix, :endpoint, :start]
- [:phoenix, :router_dispatch, :exception] (inner router)
- [:phoenix, :endpoint, :stop]
- [:phoenix, :router_dispatch, :exception] (outer router) ** here there is no span, crashes
2022-03-18 11:21:26 +00:00
|
|
|
{[reason: reason], attrs} =
|
|
|
|
Reason.normalize(reason)
|
|
|
|
|> Keyword.split([:reason])
|
2021-09-12 19:49:24 +00:00
|
|
|
|
Only attempt to record an exception if there is an active span. (#37)
There is an edge case, if you use `forward/4` and use Plug.ErrorHandler,
then when an exception reaches the outer router, then Plug.send_resp
will be called, triggering `[:phoenix, :endpoint, :stop]`, and the span
will be gone by the time the outer router gets the exception. This
causes this telemetry handler to crash and be detached.
Sequence of events:
- [:phoenix, :endpoint, :start]
- [:phoenix, :router_dispatch, :exception] (inner router)
- [:phoenix, :endpoint, :stop]
- [:phoenix, :router_dispatch, :exception] (outer router) ** here there is no span, crashes
2022-03-18 11:21:26 +00:00
|
|
|
# try to normalize all errors to Elixir exceptions
|
|
|
|
exception = Exception.normalize(kind, reason, stacktrace)
|
2021-09-12 19:49:24 +00:00
|
|
|
|
Only attempt to record an exception if there is an active span. (#37)
There is an edge case, if you use `forward/4` and use Plug.ErrorHandler,
then when an exception reaches the outer router, then Plug.send_resp
will be called, triggering `[:phoenix, :endpoint, :stop]`, and the span
will be gone by the time the outer router gets the exception. This
causes this telemetry handler to crash and be detached.
Sequence of events:
- [:phoenix, :endpoint, :start]
- [:phoenix, :router_dispatch, :exception] (inner router)
- [:phoenix, :endpoint, :stop]
- [:phoenix, :router_dispatch, :exception] (outer router) ** here there is no span, crashes
2022-03-18 11:21:26 +00:00
|
|
|
# record exception and mark the span as errored
|
|
|
|
Span.record_exception(ctx, exception, stacktrace, attrs)
|
|
|
|
Span.set_status(ctx, OpenTelemetry.status(:error, ""))
|
2021-09-12 19:49:24 +00:00
|
|
|
|
Only attempt to record an exception if there is an active span. (#37)
There is an edge case, if you use `forward/4` and use Plug.ErrorHandler,
then when an exception reaches the outer router, then Plug.send_resp
will be called, triggering `[:phoenix, :endpoint, :stop]`, and the span
will be gone by the time the outer router gets the exception. This
causes this telemetry handler to crash and be detached.
Sequence of events:
- [:phoenix, :endpoint, :start]
- [:phoenix, :router_dispatch, :exception] (inner router)
- [:phoenix, :endpoint, :stop]
- [:phoenix, :router_dispatch, :exception] (outer router) ** here there is no span, crashes
2022-03-18 11:21:26 +00:00
|
|
|
# do not close the span as endpoint stop will still be called with
|
|
|
|
# more info, including the status code, which is nil at this stage
|
|
|
|
end
|
2021-09-12 19:49:24 +00:00
|
|
|
end
|
|
|
|
|
|
|
|
defp http_flavor({_adapter_name, meta}) do
|
|
|
|
case Map.get(meta, :version) do
|
|
|
|
:"HTTP/1.0" -> :"1.0"
|
|
|
|
:"HTTP/1.1" -> :"1.1"
|
|
|
|
:"HTTP/2.0" -> :"2.0"
|
|
|
|
:"HTTP/2" -> :"2.0"
|
|
|
|
:SPDY -> :SPDY
|
|
|
|
:QUIC -> :QUIC
|
|
|
|
nil -> ""
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
defp client_ip(%{remote_ip: remote_ip} = conn) do
|
|
|
|
case header_value(conn, "x-forwarded-for") do
|
|
|
|
"" ->
|
|
|
|
remote_ip
|
|
|
|
|> :inet_parse.ntoa()
|
|
|
|
|> to_string()
|
|
|
|
|
|
|
|
ip_address ->
|
|
|
|
ip_address
|
|
|
|
|> String.split(",", parts: 2)
|
|
|
|
|> List.first()
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
defp header_value(conn, header) do
|
|
|
|
case Plug.Conn.get_req_header(conn, header) do
|
|
|
|
[] ->
|
|
|
|
""
|
|
|
|
|
|
|
|
[value | _] ->
|
|
|
|
value
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|