diff --git a/CHANGELOG.md b/CHANGELOG.md index ce9f2a7..9b79326 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,34 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added + +* Ensure dashboard profiles list respects the selected limit + +### Changed + +#### `use PhoenixProfiler` on your Endpoint + +PhoenixProfiler needs to wrap the whole Plug pipeline to get +a complete picture of each request. Make the following changes +in your Endpoint module(s): + +1. Add `use PhoenixProfiler` directly after `use Phoenix.Endpoint`: + +```diff +defmodule MyAppWeb.Endpoint do + use Phoenix.Endpoint, otp_app: :my_app ++ use PhoenixProfiler +``` + +2. Remove the plug from the `code_reloading?` block: + +```diff +if code_reloading? do +- plug PhoenixProfiler +end +``` + ## [0.2.0] - 2022-09-28 ### Added diff --git a/README.md b/README.md index 67b6a99..a42127d 100644 --- a/README.md +++ b/README.md @@ -24,10 +24,10 @@ Provides a **development tool** that gives detailed information about the execut To start using the profiler, you will need the following steps: 1. Add the `phoenix_profiler` dependency -2. Define a profiler on your supervision tree -3. Enable the profiler on your Endpoint +2. Define a profiler server on your supervision tree +3. Enable your profiler on your Endpoint config 4. Configure LiveView -5. Add the `PhoenixProfiler` plug +5. Use `PhoenixProfiler` on your Endpoint module 6. Mount the profiler on your LiveViews 7. Add the profiler page on your LiveDashboard (optional) @@ -39,10 +39,10 @@ Add phoenix_profiler to your `mix.exs`: {:phoenix_profiler, "~> 0.2.0"} ``` -### 2. Define a profiler on your supervision tree +### 2. Define a profiler server on your supervision tree -You define a profiler on your main application's telemetry supervision -tree (usually in `lib/my_app_web/telemetry.ex`): +You define a profiler on your telemetry supervision tree +(usually in `lib/my_app_web/telemetry.ex`): ```elixir children = [ @@ -61,7 +61,7 @@ The following options are available: * `:request_sweep_interval` - How often to sweep the ETS table where the profiles are stored. Default is `24h` in milliseconds. -### 3. Enable the profiler on your Endpoint +### 3. Enable your profiler on your Endpoint config PhoenixProfiler is disabled by default. In order to enable it, you must update your endpoint's `:dev` configuration to include the @@ -104,24 +104,26 @@ config :my_app, MyAppWeb.Endpoint, live_view: [signing_salt: "SECRET_SALT"] ``` -### 5. Add the PhoenixProfiler plug +### 5. Use PhoenixProfiler -Add the `PhoenixProfiler` plug within the `code_reloading?` -block on your Endpoint (usually in `lib/my_app_web/endpoint.ex`): +Add `use PhoenixProfiler` on your Endpoint module +(usually in `lib/my_app_web/endpoint.ex`): ```elixir - if code_reloading? do + defmodule MyAppWeb.Endpoint do + use Phoenix.Endpoint, otp_app: :my_app + use PhoenixProfiler + # plugs... - plug PhoenixProfiler end ``` -### 6. Mount the profiler on your LiveViews +### 6. Mount PhoenixProfiler on your LiveViews Note this section is required only if you are using LiveView, otherwise you may skip it. -Add the profiler hook to the `live_view` function on your -web module (usually in `lib/my_app_web.ex`): +Add PhoenixProfiler to the `live_view` function on your web +module (usually in `lib/my_app_web.ex`): ```elixir def live_view do diff --git a/dev.exs b/dev.exs index 22940ee..09c8c95 100644 --- a/dev.exs +++ b/dev.exs @@ -224,8 +224,8 @@ defmodule DemoWeb.AppLive.Index do defp apply_profiler_toggle(socket) do if connected?(socket) do - profile = socket.private.phoenix_profiler - next = if profile.info == :enable, do: :disable, else: :enable + info = socket.private.phoenix_profiler.info + next = if info == :enable, do: :disable, else: :enable assign(socket, :toggle_text, String.capitalize(to_string(next)) <> " Profiler") else assign(socket, :toggle_text, nil) @@ -269,8 +269,8 @@ defmodule DemoWeb.AppLive.Index do end def handle_event("toggle-profiler", _, socket) do - profile = socket.private.phoenix_profiler - next = if profile.info == :enable, do: :disable, else: :enable + info = socket.private.phoenix_profiler.info + next = if info == :enable, do: :disable, else: :enable socket = apply(PhoenixProfiler, next, [socket]) {:noreply, apply_profiler_toggle(socket)} @@ -335,8 +335,7 @@ end defmodule DemoWeb.Endpoint do use Phoenix.Endpoint, otp_app: :phoenix_profiler - - plug PhoenixProfiler + use PhoenixProfiler @session_options [ store: :cookie, diff --git a/lib/phoenix_profiler.ex b/lib/phoenix_profiler.ex index b1b19a9..611a412 100644 --- a/lib/phoenix_profiler.ex +++ b/lib/phoenix_profiler.ex @@ -5,6 +5,21 @@ defmodule PhoenixProfiler do |> String.split("") |> Enum.fetch!(1) + defmacro __using__(_) do + quote do + unquote(plug()) + + @before_compile PhoenixProfiler.Endpoint + end + end + + defp plug do + # todo: ensure we are within a Phoenix.Endpoint + quote location: :keep do + plug PhoenixProfiler.Plug + end + end + @doc """ Returns the child specification to start the profiler under a supervision tree. @@ -12,18 +27,10 @@ defmodule PhoenixProfiler do def child_spec(opts) do %{ id: opts[:name] || PhoenixProfiler, - start: {PhoenixProfiler.Supervisor, :start_link, [opts]} + start: {PhoenixProfiler.Profiler, :start_link, [opts]} } end - @behaviour Plug - - @impl Plug - defdelegate init(opts), to: PhoenixProfiler.Plug - - @impl Plug - defdelegate call(conn, opts), to: PhoenixProfiler.Plug - # TODO: Remove when we require LiveView v0.17+. @doc false def mount(params, session, socket) do @@ -39,73 +46,63 @@ defmodule PhoenixProfiler do """ def on_mount(_arg, _params, _session, socket) do - {:cont, PhoenixProfiler.Utils.maybe_mount_profile(socket)} + {:cont, PhoenixProfiler.Utils.maybe_mount_profiler(socket)} end @doc """ Enables the profiler on a given `conn` or connected `socket`. - Normally you do not need to invoke this function manually. It is invoked - automatically by the PhoenixProfiler plug in the Endpoint when a - profiler is enabled. In LiveView v0.16+ it is invoked automatically when - you define `on_mount PhoenixProfiler` on your LiveView. + Useful when choosing to start a profiler with + `[enable: false]`, but normally you do not need to invoke it + manually. - This function will raise if the endpoint is not configured with a profiler, - or if the configured profiler is not running. For LiveView specifically, - this function also raises if the given socket is not connected. + Note the profiler server must be running and the `conn` or + `socket` must have been configured for profiling for this + function to have any effect. ## Example - Within a Phoenix Controller (for example, on a show callback): + Within a Phoenix Controller (for example on a `show` callback): def show(conn, params) do conn = PhoenixProfiler.enable(conn) # code... end - Within a LiveView (for example, on the mount callback): - - def mount(params, session, socket) do - socket = - if connected?(socket) do - PhoenixProfiler.enable(socket) - else - socket - end + Within a LiveView (for example on a `handle_info` callback): + def handle_info(:debug_me, socket) do + socket = PhoenixProfiler.enable(socket) # code... end """ - defdelegate enable(conn_or_socket), to: PhoenixProfiler.Utils, as: :enable_profiler + defdelegate enable(conn_or_socket), to: PhoenixProfiler.Profiler @doc """ Disables profiling on a given `conn` or `socket`. ## Examples - Within a Phoenix Controller (for example, on an update callback): + Within a Phoenix Controller (for example on an `update` callback): def update(conn, params) do conn = PhoenixProfiler.disable(conn) # code... end - Within in a LiveView (for example, on a handle_event callback): + Within in a LiveView (for example on a `handle_event` callback): def handle_event("some-event", _, socket) do socket = PhoenixProfiler.disable(socket) # code... end - Note that only for LiveView, if you invoke `disable/1` on - the LiveView `mount` callback, the profiler may not be - registered yet and it will not receive the disable message. - If you need on-demand profiling, it is recommended you - start with the profiler in a disabled state and enable it - after the LiveView has mounted. + Note that for LiveView, you must invoke `disable/1` _after_ + the LiveView has completed its connected mount for this function + to have any effect. """ - defdelegate disable(conn_or_socket), to: PhoenixProfiler.Utils, as: :disable_profiler + defdelegate disable(conn_or_socket), to: PhoenixProfiler.Profiler @doc """ Resets the storage of the given `profiler`. diff --git a/lib/phoenix_profiler/dashboard.ex b/lib/phoenix_profiler/dashboard.ex index b0e9f53..04412f4 100644 --- a/lib/phoenix_profiler/dashboard.ex +++ b/lib/phoenix_profiler/dashboard.ex @@ -15,6 +15,7 @@ if Code.ensure_loaded?(Phoenix.LiveDashboard) do """ use Phoenix.LiveDashboard.PageBuilder + alias PhoenixProfiler.Profile alias PhoenixProfiler.ProfileStore alias PhoenixProfiler.Utils @@ -188,7 +189,7 @@ if Code.ensure_loaded?(Phoenix.LiveDashboard) do end defp render_panel(:request, assigns) do - conn = assigns.profile.conn + conn = assigns.profile.data.conn nav_bar( items: [ @@ -297,29 +298,26 @@ if Code.ensure_loaded?(Phoenix.LiveDashboard) do defp fetch_profiles(params, profiler, node) do %{search: search, sort_by: sort_by, sort_dir: sort_dir, limit: limit} = params - {profiles, total} = fetch_profiles(node, profiler, search, sort_by, sort_dir, limit) + {profiles, total} = + ProfileStore.remote_list_advanced(node, profiler, search, sort_by, sort_dir, limit) rows = - for {token, prof} <- profiles do - %{at: at, conn: %Plug.Conn{} = conn} = prof + for {token, profile} <- profiles do + %Profile{ + data: %{conn: %Plug.Conn{} = conn}, + system_time: system_time + } = profile conn |> Map.take([:host, :status, :method, :remote_ip]) |> Map.put(:url, Plug.Conn.request_url(conn)) |> Map.put(:token, token) - |> Map.put(:at, at) + |> Map.put(:system_time, system_time) end {rows, total} end - defp fetch_profiles(node, profiler, search, sort_by, sort_dir, limit) do - profiles = - ProfileStore.remote_list_advanced(node, profiler, search, sort_by, sort_dir, limit) - - {profiles, length(profiles)} - end - defp columns do [ %{ @@ -339,8 +337,8 @@ if Code.ensure_loaded?(Phoenix.LiveDashboard) do header: "URL" }, %{ - field: :at, - header: "Profiled at", + field: :system_time, + header: "Time", sortable: :desc, format: &format_time/1 }, diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex new file mode 100644 index 0000000..960cc7a --- /dev/null +++ b/lib/phoenix_profiler/endpoint.ex @@ -0,0 +1,94 @@ +defmodule PhoenixProfiler.Endpoint do + # Overrides Phoenix.Endpoint.call/2 for profiling. + @moduledoc false + + defmacro __before_compile__(%{module: _module}) do + quote do + defoverridable call: 2 + + # Ignore requests from :phoenix_live_reload + def call(%Plug.Conn{path_info: ["phoenix", "live_reload", "frame" | _suffix]} = conn, opts) do + super(conn, opts) + end + + def call(conn, opts) do + start_time = System.monotonic_time() + + case PhoenixProfiler.Profiler.preflight(__MODULE__) do + {:ok, profile} -> + try do + conn + |> PhoenixProfiler.Endpoint.__prologue__(profile) + |> super(opts) + |> PhoenixProfiler.Endpoint.__epilogue__(start_time) + catch + kind, reason -> + stack = __STACKTRACE__ + PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, profile, start_time) + end + + :error -> + super(conn, opts) + end + end + end + end + + alias PhoenixProfiler.{Profile, Profiler} + + def __prologue__(conn, %Profile{} = profile) do + {:ok, pid} = Profiler.start_collector(conn, profile) + telemetry_execute(:start, %{system_time: System.system_time()}, %{conn: conn}) + + conn + |> Plug.Conn.put_private(:phoenix_profiler, profile) + |> Plug.Conn.put_private(:phoenix_profiler_collector, pid) + end + + def __epilogue__(conn, start_time) do + profile = Map.fetch!(conn.private, :phoenix_profiler) + telemetry_execute(:stop, %{duration: duration(start_time)}, %{conn: conn}) + late_collect(conn, profile) + end + + def __epilogue__(conn, kind, reason, stack, profile, start_time) do + telemetry_execute(:exception, %{duration: duration(start_time)}, %{ + conn: conn, + profile: profile, + kind: kind, + reason: reason, + stacktrace: stack + }) + + {_, pid} = PhoenixProfiler.Utils.collector_info(profile.server, conn) + late_collect(conn, profile, pid) + end + + def __catch__(conn, kind, reason, stack, profile, start_time) do + __epilogue__(conn, kind, reason, stack, profile, start_time) + :erlang.raise(kind, reason, stack) + end + + defp telemetry_execute(action, measurements, metadata) do + :telemetry.execute([:phoenix_profiler, :endpoint, action], measurements, metadata) + end + + defp duration(start_time) when is_integer(start_time) do + System.monotonic_time() - start_time + end + + defp late_collect(conn, profile) do + late_collect(conn, profile, conn.private.phoenix_profiler_collector) + end + + defp late_collect(conn, profile, collector_pid) do + case PhoenixProfiler.Profiler.collect(profile, collector_pid) do + {:ok, profile} -> + true = PhoenixProfiler.Profiler.insert_profile(profile) + conn + + :error -> + conn + end + end +end diff --git a/lib/phoenix_profiler/plug.ex b/lib/phoenix_profiler/plug.ex index de53118..b546676 100644 --- a/lib/phoenix_profiler/plug.ex +++ b/lib/phoenix_profiler/plug.ex @@ -5,30 +5,29 @@ defmodule PhoenixProfiler.Plug do alias PhoenixProfiler.ToolbarView require Logger + @behaviour Plug + @token_header_key "x-debug-token" @profiler_header_key "x-debug-token-link" + @impl Plug def init(opts) do opts end - # TODO: remove this clause when we add config for profiler except_patterns - def call(%Plug.Conn{path_info: ["phoenix", "live_reload", "frame" | _suffix]} = conn, _) do - # this clause is to ignore the phoenix live reload iframe in case someone installs - # the toolbar plug above the LiveReloader plug in their Endpoint. - conn - end - + @impl Plug def call(conn, _) do endpoint = conn.private.phoenix_endpoint - config = endpoint.config(:phoenix_profiler) + start_time = System.monotonic_time() - if config do - conn - |> PhoenixProfiler.Utils.enable_profiler(endpoint, config, System.system_time()) - |> before_send_profile(endpoint, config) - else - conn + case conn.private do + %{phoenix_profiler: %Profile{}} -> + conn + |> telemetry_execute(:start, %{system_time: System.system_time()}) + |> before_send_profile(endpoint, [], start_time) + + _ -> + conn end end @@ -38,21 +37,32 @@ defmodule PhoenixProfiler.Plug do |> put_resp_header(@profiler_header_key, profile.url) end - defp before_send_profile(conn, endpoint, config) do + defp before_send_profile(conn, endpoint, config, start_time) do register_before_send(conn, fn conn -> - case Map.get(conn.private, :phoenix_profiler) do - %Profile{info: :enable} = profile -> - conn - |> apply_profile_headers(profile) - |> PhoenixProfiler.Utils.on_send_resp(profile) - |> maybe_inject_debug_toolbar(profile, endpoint, config) - - _ -> + # todo: look for exceptions in the conn + telemetry_execute(conn, :stop, %{duration: System.monotonic_time() - start_time}) + + case PhoenixProfiler.Profiler.collect( + conn.private.phoenix_profiler, + conn.private.phoenix_profiler_collector + ) do + {:ok, profile} -> + conn = apply_profile_headers(conn, profile) + true = PhoenixProfiler.Profiler.insert_profile(profile) + maybe_inject_debug_toolbar(conn, profile, endpoint, config) + + :error -> conn end end) end + defp telemetry_execute(%Plug.Conn{} = conn, action, measurements) + when action in [:start, :stop] do + :telemetry.execute([:phoenix_profiler, :plug, action], measurements, %{conn: conn}) + conn + end + defp maybe_inject_debug_toolbar(%{resp_body: nil} = conn, _, _, _), do: conn defp maybe_inject_debug_toolbar(conn, profile, endpoint, config) do @@ -106,11 +116,17 @@ defmodule PhoenixProfiler.Plug do name: "Phoenix Web Debug Toolbar" ) + # Note: if the session keys change then you must bump the version: ToolbarView |> Phoenix.View.render("index.html", %{ conn: conn, - session: %{"_" => profile}, - profile: profile, + session: %{ + "vsn" => 1, + "node" => profile.node, + "server" => profile.server, + "token" => profile.token + }, + token: profile.token, toolbar_attrs: attrs }) |> Phoenix.HTML.Safe.to_iodata() diff --git a/lib/phoenix_profiler/profile.ex b/lib/phoenix_profiler/profile.ex index 9800f1d..5a9a507 100644 --- a/lib/phoenix_profiler/profile.ex +++ b/lib/phoenix_profiler/profile.ex @@ -2,19 +2,17 @@ defmodule PhoenixProfiler.Profile do # An internal data structure for a request profile. @moduledoc false defstruct [ - :collector_pid, + :endpoint, :info, :node, :server, - :start_time, :system, :system_time, :token, - :url + :url, + data: %{} ] - @type info :: nil | :enable | :disable - @type system :: %{ :otp => String.t(), :elixir => String.t(), @@ -24,38 +22,35 @@ defmodule PhoenixProfiler.Profile do } @type t :: %__MODULE__{ - :collector_pid => nil | pid(), - :info => info(), + :data => map(), + :endpoint => module(), + :info => nil | :disable | :enable, :token => String.t(), :server => module(), :node => node(), - :start_time => integer(), :system => system(), - :system_time => integer(), + :system_time => nil | integer(), :url => String.t() } @doc """ Returns a new profile. """ - def new(node \\ node(), server, token, info, base_url, system_time) - when is_atom(server) and is_binary(token) and - is_atom(info) and info in [nil, :enable, :disable] and - is_binary(base_url) and is_integer(system_time) do + def new(endpoint, server, token, base_url, info) + when is_atom(endpoint) and is_atom(server) and + is_binary(token) and is_binary(base_url) and + is_atom(info) do + params = %{nav: inspect(server), panel: :request, token: token} + url = base_url <> "?" <> URI.encode_query(params) + %__MODULE__{ + endpoint: endpoint, info: info, - node: node, + node: node(), server: server, - start_time: System.monotonic_time(), system: PhoenixProfiler.ProfileStore.system(server), - system_time: system_time, token: token, - url: build_url(server, token, base_url) + url: url } end - - defp build_url(server, token, base_url) do - params = %{nav: inspect(server), panel: :request, token: token} - base_url <> "?" <> URI.encode_query(params) - end end diff --git a/lib/phoenix_profiler/profile_store.ex b/lib/phoenix_profiler/profile_store.ex index 30c906c..896acd9 100644 --- a/lib/phoenix_profiler/profile_store.ex +++ b/lib/phoenix_profiler/profile_store.ex @@ -71,7 +71,7 @@ defmodule PhoenixProfiler.ProfileStore do """ def profiler(%Plug.Conn{} = conn) do case conn.private[:phoenix_profiler] do - %Profile{server: server} when is_atom(server) -> server + %Profile{server: server} -> server nil -> nil end end @@ -99,17 +99,22 @@ defmodule PhoenixProfiler.ProfileStore do @doc """ Returns a filtered list of profiles. """ - def list_advanced(profiler, _search, sort_by, sort_dir, _limit) do - Utils.sort_by(list(profiler), fn {_, profile} -> profile[sort_by] end, sort_dir) + def list_advanced(profiler, _search, :at, sort_dir, limit) do + results = Utils.sort_by(list(profiler), fn {_, %Profile{} = p} -> p.system_time end, sort_dir) + + {Enum.take(results, limit), length(results)} + end + + def list_advanced(profiler, _search, sort_by, sort_dir, limit) do + results = + Utils.sort_by(list(profiler), fn {_, %Profile{} = p} -> p.data[sort_by] end, sort_dir) + + {Enum.take(results, limit), length(results)} end @doc """ Fetches a profile on a remote node. """ - def remote_get(%Profile{} = profile) do - remote_get(profile.node, profile.server, profile.token) - end - def remote_get(node, profiler, token) do :rpc.call(node, __MODULE__, :get, [profiler, token]) end diff --git a/lib/phoenix_profiler/profiler.ex b/lib/phoenix_profiler/profiler.ex new file mode 100644 index 0000000..4316adb --- /dev/null +++ b/lib/phoenix_profiler/profiler.ex @@ -0,0 +1,134 @@ +defmodule PhoenixProfiler.Profiler do + @moduledoc false + use Supervisor + alias PhoenixProfiler.Profile + alias PhoenixProfiler.ProfileStore + alias PhoenixProfiler.Telemetry + alias PhoenixProfiler.TelemetryServer + alias PhoenixProfiler.Utils + + @doc """ + Builds a profile from data collected for a given `conn`. + """ + def collect(%Profile{info: :enable} = profile, collector_pid) when is_pid(collector_pid) do + time = System.system_time() + + data = + PhoenixProfiler.TelemetryCollector.reduce( + collector_pid, + %{metrics: %{endpoint_duration: nil}}, + fn + {:telemetry, _, _, _, %{endpoint_duration: duration}}, acc -> + %{acc | metrics: Map.put(acc.metrics, :endpoint_duration, duration)} + + {:telemetry, _, _, _, %{metrics: _} = entry}, acc -> + {metrics, rest} = Utils.map_pop!(entry, :metrics) + acc = Map.merge(acc, rest) + %{acc | metrics: Map.merge(acc.metrics, metrics)} + + {:telemetry, _, _, _, data}, acc -> + Map.merge(acc, data) + end + ) + + {:ok, %Profile{profile | data: data, system_time: time}} + end + + def collect(%Profile{info: :disable}, _) do + :error + end + + @doc """ + Inserts a profile into term storage. + """ + def insert_profile(%Profile{} = profile) do + profile + |> ProfileStore.table() + |> :ets.insert({profile.token, profile}) + end + + @doc """ + Disables profiling for a given `conn` or `socket`. + """ + def disable(%{private: %{phoenix_profiler: profile}} = conn_or_socket) do + :ok = TelemetryServer.disable_key(profile.server, Utils.target_pid(conn_or_socket)) + Utils.put_private(conn_or_socket, :phoenix_profiler, %{profile | info: :disable}) + end + + def disable(conn_or_socket), do: conn_or_socket + + @doc """ + Enables profiling for a given `conn` or `socket`. + """ + def enable(%{private: %{phoenix_profiler: profile}} = conn_or_socket) do + :ok = TelemetryServer.enable_key(profile.server, Utils.target_pid(conn_or_socket)) + Utils.put_private(conn_or_socket, :phoenix_profiler, %{profile | info: :enable}) + end + + def enable(conn_or_socket), do: conn_or_socket + + @doc """ + Returns a sparse data structure for a profile. + + Useful mostly for initializing the profile at the beginning of a request. + """ + def preflight(endpoint) do + preflight(endpoint, endpoint.config(:phoenix_profiler)) + end + + def preflight(_endpoint, nil), do: :error + def preflight(endpoint, config), do: preflight(endpoint, config[:server], config) + + defp preflight(endpoint, nil = _server, _config) do + IO.warn("no profiler server found for endpoint #{inspect(endpoint)}") + :error + end + + defp preflight(endpoint, server, config) when is_atom(server) do + info = if config[:enable] == false, do: :disable, else: :enable + token = Utils.random_unique_id() + url = endpoint.url() <> Utils.profile_base_path(config) + + {:ok, Profile.new(endpoint, server, token, url, info)} + end + + def start_link(opts) do + {name, opts} = opts |> Enum.into([]) |> Keyword.pop(:name) + + unless name do + raise ArgumentError, "the :name option is required to start PhoenixProfiler" + end + + Supervisor.start_link(__MODULE__, {name, opts}, name: name) + end + + @impl Supervisor + def init({name, opts}) do + events = (opts[:telemetry] || []) ++ Telemetry.events() + + children = [ + {ProfileStore, {name, opts}}, + {TelemetryServer, [filter: &Telemetry.collect/4, server: name, events: events]} + ] + + Supervisor.init(children, strategy: :one_for_one) + end + + @doc """ + Starts a telemetry collector for `conn` for a given `profile`. + """ + def start_collector(conn, %Profile{} = profile) do + case TelemetryServer.listen(profile.server, Utils.target_pid(conn), nil, profile.info) do + {:ok, pid} -> + {:ok, pid} + + {:error, {:already_registered, pid}} -> + case profile.info do + :disable -> TelemetryServer.disable_key(profile.server, Utils.target_pid(conn)) + :enable -> TelemetryServer.enable_key(profile.server, Utils.target_pid(conn)) + end + + {:ok, pid} + end + end +end diff --git a/lib/phoenix_profiler/supervisor.ex b/lib/phoenix_profiler/supervisor.ex deleted file mode 100644 index 9a02de2..0000000 --- a/lib/phoenix_profiler/supervisor.ex +++ /dev/null @@ -1,28 +0,0 @@ -defmodule PhoenixProfiler.Supervisor do - @moduledoc false - use Supervisor - alias PhoenixProfiler.ProfileStore - alias PhoenixProfiler.Telemetry - alias PhoenixProfiler.TelemetryServer - - def start_link(opts) do - {name, opts} = opts |> Enum.into([]) |> Keyword.pop(:name) - - unless name do - raise ArgumentError, "the :name option is required to start PhoenixProfiler" - end - - Supervisor.start_link(__MODULE__, {name, opts}, name: name) - end - - def init({name, opts}) do - events = (opts[:telemetry] || []) ++ Telemetry.events() - - children = [ - {ProfileStore, {name, opts}}, - {TelemetryServer, [filter: &Telemetry.collect/4, server: name, events: events]} - ] - - Supervisor.init(children, strategy: :one_for_one) - end -end diff --git a/lib/phoenix_profiler/telemetry.ex b/lib/phoenix_profiler/telemetry.ex index 4a7acf8..b0e17ab 100644 --- a/lib/phoenix_profiler/telemetry.ex +++ b/lib/phoenix_profiler/telemetry.ex @@ -10,7 +10,9 @@ defmodule PhoenixProfiler.Telemetry do plug_events = [ [:phoenix, :endpoint, :stop], - [:phxprof, :plug, :stop] + [:phoenix, :error_rendered], + [:phoenix_profiler, :endpoint, :exception], + [:phoenix_profiler, :plug, :stop] ] @events plug_events ++ live_view_events @@ -27,24 +29,23 @@ defmodule PhoenixProfiler.Telemetry do {:keep, %{endpoint_duration: duration}} end - def collect(_, [:phxprof, :plug, :stop], measures, %{conn: conn}) do - profile = conn.private.phoenix_profiler + def collect(_, [:phoenix_profiler, :plug, :stop], measures, %{conn: conn}) do + {:keep, + %{ + conn: %{conn | resp_body: nil, assigns: Map.delete(conn.assigns, :content)}, + metrics: %{ + memory: collect_memory(conn.owner), + total_duration: measures.duration + } + }} + end - case profile.info do - :disable -> - :skip + def collect(_, [:phoenix, :error_rendered], _, meta) do + {:keep, %{exception: Map.take(meta, [:kind, :reason, :stacktrace])}} + end - info when info in [nil, :enable] -> - {:keep, - %{ - at: profile.system_time, - conn: %{conn | resp_body: nil, assigns: Map.delete(conn.assigns, :content)}, - metrics: %{ - memory: collect_memory(conn.owner), - total_duration: measures.duration - } - }} - end + def collect(_, [:phoenix_profiler, :endpoint, :exception], _, meta) do + {:keep, %{exception: Map.take(meta, [:kind, :reason, :stacktrace])}} end def collect(_, [:phoenix, :live_view | _] = event, measures, %{socket: socket} = meta) do diff --git a/lib/phoenix_profiler/telemetry/collector.ex b/lib/phoenix_profiler/telemetry/collector.ex index c9bf139..7c8581c 100644 --- a/lib/phoenix_profiler/telemetry/collector.ex +++ b/lib/phoenix_profiler/telemetry/collector.ex @@ -48,6 +48,18 @@ defmodule PhoenixProfiler.TelemetryCollector do alias PhoenixProfiler.TelemetryRegistry alias PhoenixProfiler.Utils + @doc """ + Disables a given `collector`. + + Disabled collectors will not receive telemetry events. + """ + def disable(collector), do: GenServer.call(collector, {__MODULE__, :disable}) + + @doc """ + Enables a given `collector`. + """ + def enable(collector), do: GenServer.call(collector, {__MODULE__, :enable}) + @doc """ Starts a collector linked to the current process. @@ -88,17 +100,6 @@ defmodule PhoenixProfiler.TelemetryCollector do GenServer.call(pid, {:reduce, initial, func}) end - @doc """ - Sends a message to `collector_pid` to update its status. - - The collector process will update its registry value to - to status returned by `func`, a function that accepts the - current status and returns one of `:enable` or `:disable`. - """ - def update_info(collector_pid, func) when is_function(func, 1) do - send(collector_pid, {:collector_update_info, func}) - end - @impl GenServer def init({server, pid, arg, info}) do case TelemetryRegistry.register(server, pid, {self(), arg}, info) do @@ -112,6 +113,13 @@ defmodule PhoenixProfiler.TelemetryCollector do {:reply, Utils.queue_fold(func, initial, q), state} end + @impl GenServer + def handle_call({__MODULE__, action}, _from, %{pid: pid} = state) + when action in [:disable, :enable] do + _ = TelemetryRegistry.update_info(pid, fn _ -> action end) + {:reply, :ok, state} + end + @impl GenServer def handle_info( {:telemetry, {pid, _}, _, _, _} = event, @@ -120,9 +128,4 @@ defmodule PhoenixProfiler.TelemetryCollector do when pid == self() do {:noreply, %{state | queue: :queue.in(event, q)}} end - - def handle_info({:collector_update_info, func}, %{pid: pid} = state) do - TelemetryRegistry.update_info(pid, func) - {:noreply, state} - end end diff --git a/lib/phoenix_profiler/telemetry/registry.ex b/lib/phoenix_profiler/telemetry/registry.ex index 99ba713..45b3dc4 100644 --- a/lib/phoenix_profiler/telemetry/registry.ex +++ b/lib/phoenix_profiler/telemetry/registry.ex @@ -63,10 +63,20 @@ defmodule PhoenixProfiler.TelemetryRegistry do defp lookup(server, callers) do Enum.reduce_while(callers, :error, fn caller, acc -> - case Registry.lookup(__MODULE__, caller) do - [{_, {^server, _, _}} = collector] -> {:halt, {:ok, collector}} - _ -> {:cont, acc} + case lookup_key(server, caller) do + {:ok, _} = ok -> {:halt, ok} + :error -> {:cont, acc} end end) end + + @doc """ + Returns the collector for `server` registered for `key` if it exists. + """ + def lookup_key(server, key) do + case Registry.lookup(__MODULE__, key) do + [{_, {^server, _, _}} = collector] -> {:ok, collector} + _ -> :error + end + end end diff --git a/lib/phoenix_profiler/telemetry/server.ex b/lib/phoenix_profiler/telemetry/server.ex index 66cc414..d8eedb6 100644 --- a/lib/phoenix_profiler/telemetry/server.ex +++ b/lib/phoenix_profiler/telemetry/server.ex @@ -4,9 +4,6 @@ defmodule PhoenixProfiler.TelemetryServer do alias PhoenixProfiler.TelemetryCollector alias PhoenixProfiler.TelemetryRegistry - @disable_event [:phoenix_profiler, :internal, :collector, :disable] - @enable_event [:phoenix_profiler, :internal, :collector, :enable] - @doc """ Starts a collector for `server` for a given `pid`. """ @@ -22,6 +19,38 @@ defmodule PhoenixProfiler.TelemetryServer do ) end + @doc """ + Disables the collector for `key` if it exists. + """ + def disable_key(server, key) do + case TelemetryRegistry.lookup_key(server, key) do + {:ok, {pid, {_, _, :enable}}} -> + TelemetryCollector.disable(pid) + + {:ok, _} -> + :ok + + :error -> + :error + end + end + + @doc """ + Enables the collector for `key` if it exists. + """ + def enable_key(server, key) do + case TelemetryRegistry.lookup_key(server, key) do + {:ok, {pid, {_, _, :disable}}} -> + TelemetryCollector.enable(pid) + + {:ok, _} -> + :ok + + :error -> + :error + end + end + @doc """ Starts a telemetry server linked to the current process. """ @@ -32,23 +61,13 @@ defmodule PhoenixProfiler.TelemetryServer do GenServer.start_link(__MODULE__, config) end - @doc """ - Executes the collector event for `info` for the current process. - """ - def collector_info_exec(:disable), do: telemetry_exec(@disable_event) - def collector_info_exec(:enable), do: telemetry_exec(@enable_event) - - defp telemetry_exec(event) do - :telemetry.execute(event, %{system_time: System.system_time()}, %{}) - end - @impl true def init(%{events: events, filter: filter, server: server}) do Process.flag(:trap_exit, true) :telemetry.attach_many( {__MODULE__, self()}, - events ++ [@disable_event, @enable_event], + events, &__MODULE__.handle_execute/4, %{filter: filter, server: server} ) @@ -59,17 +78,6 @@ defmodule PhoenixProfiler.TelemetryServer do @doc """ Forwards telemetry events to a registered collector, if it exists. """ - def handle_execute([_, _, _, info] = event, _, _, %{server: server}) - when event in [@disable_event, @enable_event] do - case TelemetryRegistry.lookup(server) do - {:ok, {pid, {^server, _, old_info}}} when old_info !== info -> - TelemetryCollector.update_info(pid, fn _ -> info end) - - _ -> - :ok - end - end - def handle_execute(event, measurements, metadata, %{filter: filter, server: server}) do with {:ok, {pid, {^server, arg, :enable}}} <- TelemetryRegistry.lookup(server) do # todo: ensure span ref is set on data (or message) if it exists diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.ex b/lib/phoenix_profiler/toolbar/toolbar_live.ex index c958339..c78b7cd 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_live.ex +++ b/lib/phoenix_profiler/toolbar/toolbar_live.ex @@ -3,26 +3,25 @@ defmodule PhoenixProfiler.ToolbarLive do @moduledoc false use Phoenix.LiveView, container: {:div, [class: "phxprof-toolbar-view"]} require Logger + alias PhoenixProfiler.Profile alias PhoenixProfiler.ProfileStore alias PhoenixProfiler.Routes alias PhoenixProfiler.TelemetryRegistry alias PhoenixProfiler.Utils @impl Phoenix.LiveView - def mount(_, %{"_" => %PhoenixProfiler.Profile{} = profile}, socket) do - socket = - socket - |> assign_defaults() - |> assign(:profile, profile) + # Note if the session keys change you must bump the version. + def mount(_, %{"vsn" => 1, "node" => node, "server" => server, "token" => token}, socket) do + socket = assign_defaults(socket) socket = - case ProfileStore.remote_get(profile) do + case ProfileStore.remote_get(node, server, token) do nil -> assign_error_toolbar(socket) remote_profile -> assign_toolbar(socket, remote_profile) end if connected?(socket) do - {:ok, _} = TelemetryRegistry.register(profile.server, Utils.transport_pid(socket), nil) + {:ok, _} = TelemetryRegistry.register(server, Utils.transport_pid(socket), nil) end {:ok, socket, temporary_assigns: [exits: []]} @@ -37,6 +36,7 @@ defmodule PhoenixProfiler.ToolbarLive do defp assign_defaults(socket) do assign(socket, + profile: %Profile{system: %{phoenix: nil}}, durations: nil, exits: [], exits_count: 0, @@ -65,9 +65,19 @@ defmodule PhoenixProfiler.ToolbarLive do end defp assign_toolbar(socket, profile) do - %{metrics: metrics} = profile + %Profile{data: %{metrics: metrics}} = profile + + socket = + case profile.data[:exception] do + %{kind: kind, reason: reason, stacktrace: stack} -> + apply_exception(socket, kind, reason, stack) + + _ -> + socket + end socket + |> assign(:profile, profile) |> apply_request(profile) |> assign(:durations, %{ total: duration(metrics.total_duration), @@ -78,7 +88,7 @@ defmodule PhoenixProfiler.ToolbarLive do end defp apply_request(socket, profile) do - %{conn: %Plug.Conn{} = conn} = profile + %Profile{data: %{conn: %Plug.Conn{} = conn}} = profile router = conn.private[:phoenix_router] {helper, plug, action} = Routes.info(socket.assigns.profile.node, conn) socket = %{socket | private: Map.put(socket.private, :phoenix_router, router)} @@ -151,16 +161,18 @@ defmodule PhoenixProfiler.ToolbarLive do {:noreply, socket} end - def handle_info({:collector_update_info, func}, socket) do - TelemetryRegistry.update_info(transport_pid(socket), func) - {:noreply, socket} - end - def handle_info(other, socket) do Logger.debug("ToolbarLive received an unknown message: #{inspect(other)}") {:noreply, socket} end + @impl Phoenix.LiveView + def handle_call({PhoenixProfiler.TelemetryCollector, action}, _, socket) + when action in [:disable, :enable] do + TelemetryRegistry.update_info(Utils.transport_pid(socket), fn _ -> action end) + {:reply, :ok, socket} + end + defp maybe_apply_navigation(socket, data) do if connected?(socket) and not is_nil(data.router) and socket.assigns.root_pid != data.root_pid do @@ -171,17 +183,8 @@ defmodule PhoenixProfiler.ToolbarLive do end defp apply_lifecycle(socket, _stage, :exception, data) do - %{kind: kind, reason: reason, stacktrace: stacktrace} = data - - exception = %{ - ref: Phoenix.LiveView.Utils.random_id(), - reason: Exception.format(kind, reason, stacktrace), - at: Time.utc_now() |> Time.truncate(:second) - } - - socket - |> update(:exits, &[exception | &1]) - |> update(:exits_count, &(&1 + 1)) + %{kind: kind, reason: reason, stacktrace: stack} = data + apply_exception(socket, kind, reason, stack) end defp apply_lifecycle(socket, _stage, _action, _data) do @@ -200,6 +203,18 @@ defmodule PhoenixProfiler.ToolbarLive do socket end + defp apply_exception(socket, kind, reason, stack) do + exception = %{ + ref: Phoenix.LiveView.Utils.random_id(), + reason: Exception.format(kind, reason, stack), + at: Time.utc_now() |> Time.truncate(:second) + } + + socket + |> update(:exits, &[exception | &1]) + |> update(:exits_count, &(&1 + 1)) + end + defp current_duration(durations) do if event = durations.latest_event, do: {event.value, event.label}, diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.html.heex b/lib/phoenix_profiler/toolbar/toolbar_live.html.heex index f0bb060..eaaad06 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_live.html.heex +++ b/lib/phoenix_profiler/toolbar/toolbar_live.html.heex @@ -109,7 +109,7 @@ -
+ <% end %>