From 9f1fe169963a493d365b10c0750c90ae875805a9 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Fri, 25 Feb 2022 15:27:13 -0800 Subject: [PATCH 01/38] Simplify tests --- lib/phoenix_profiler/telemetry/server.ex | 1 + .../integrations/phoenix_profiler_test.exs | 16 +++------------- test/phoenix_profiler/plug_test.exs | 8 ++++---- 3 files changed, 8 insertions(+), 17 deletions(-) diff --git a/lib/phoenix_profiler/telemetry/server.ex b/lib/phoenix_profiler/telemetry/server.ex index 66cc414..21a53dc 100644 --- a/lib/phoenix_profiler/telemetry/server.ex +++ b/lib/phoenix_profiler/telemetry/server.ex @@ -35,6 +35,7 @@ defmodule PhoenixProfiler.TelemetryServer do @doc """ Executes the collector event for `info` for the current process. """ + @spec collector_info_exec(info :: :disable | :enable) :: :ok def collector_info_exec(:disable), do: telemetry_exec(@disable_event) def collector_info_exec(:enable), do: telemetry_exec(@enable_event) diff --git a/test/phoenix_profiler/integrations/phoenix_profiler_test.exs b/test/phoenix_profiler/integrations/phoenix_profiler_test.exs index e0f4923..97cfe98 100644 --- a/test/phoenix_profiler/integrations/phoenix_profiler_test.exs +++ b/test/phoenix_profiler/integrations/phoenix_profiler_test.exs @@ -22,8 +22,6 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do assert url == "http://localhost:4000/dashboard/_profiler?nav=PhoenixProfilerTest.Profiler&panel=request&token=#{token}" - assert profiler = ProfileStore.profiler(conn) - %{ conn: %Plug.Conn{ host: "www.example.com", @@ -39,7 +37,7 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do status: 200 }, metrics: metrics - } = ProfileStore.get(profiler, token) + } = conn |> ProfileStore.profiler() |> ProfileStore.get(token) assert metrics.total_duration > 0 assert metrics.endpoint_duration > 0 @@ -50,8 +48,7 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do conn = get(conn, "/plug-router") assert [token] = Plug.Conn.get_resp_header(conn, @token_header_key) assert [_] = Plug.Conn.get_resp_header(conn, @profiler_header_key) - assert profiler = ProfileStore.profiler(conn) - assert ProfileStore.get(profiler, token) + assert conn |> ProfileStore.profiler() |> ProfileStore.get(token) end test "profiling an api request", %{conn: conn} do @@ -63,8 +60,6 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do assert url == "http://localhost:4000/dashboard/_profiler?nav=PhoenixProfilerTest.Profiler&panel=request&token=#{token}" - assert profiler = ProfileStore.profiler(conn) - %{ conn: %Plug.Conn{ host: "www.example.com", @@ -80,7 +75,7 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do status: 200 }, metrics: metrics - } = ProfileStore.get(profiler, token) + } = conn |> ProfileStore.profiler() |> ProfileStore.get(token) assert metrics.endpoint_duration > 0 assert metrics.memory > 0 @@ -91,10 +86,5 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do assert Plug.Conn.get_resp_header(conn, @token_header_key) == [] assert Plug.Conn.get_resp_header(conn, @profiler_header_key) == [] - - assert %PhoenixProfiler.Profile{info: :disable, server: server, token: token} = - conn.private.phoenix_profiler - - refute ProfileStore.get(server, token) end end diff --git a/test/phoenix_profiler/plug_test.exs b/test/phoenix_profiler/plug_test.exs index 69227cd..159187a 100644 --- a/test/phoenix_profiler/plug_test.exs +++ b/test/phoenix_profiler/plug_test.exs @@ -49,10 +49,10 @@ defmodule PhoenixProfiler.PlugTest do |> PhoenixProfiler.call(opts) |> send_resp(200, "

PhoenixProfiler

") - profile = conn.private.phoenix_profiler + assert [token] = get_resp_header(conn, @token_header_key) assert to_string(conn.resp_body) =~ - ~s[

PhoenixProfiler

\n
] + ~s[

PhoenixProfiler

\n
] end test "skips debug toolbar injection when disabled at the Endpoint" do @@ -91,9 +91,9 @@ defmodule PhoenixProfiler.PlugTest do |> PhoenixProfiler.call(opts) |> send_resp(200, "") - profile = conn.private.phoenix_profiler + assert [token] = get_resp_header(conn, @token_header_key) refute to_string(conn.resp_body) =~ - ~s(
Date: Sat, 26 Feb 2022 14:38:49 -0800 Subject: [PATCH 02/38] wip: profile --- dev.exs | 8 +- lib/phoenix_profiler.ex | 11 +- lib/phoenix_profiler/configurator.ex | 117 ++++++++++ lib/phoenix_profiler/plug.ex | 49 ++-- lib/phoenix_profiler/profile.ex | 15 +- lib/phoenix_profiler/profile_store.ex | 6 +- lib/phoenix_profiler/profiler.ex | 69 ++++++ lib/phoenix_profiler/telemetry.ex | 25 +- lib/phoenix_profiler/toolbar/toolbar_live.ex | 18 +- lib/phoenix_profiler/toolbar/toolbar_view.ex | 4 +- lib/phoenix_profiler/utils.ex | 215 ++---------------- .../integrations/phoenix_profiler_test.exs | 61 ++--- test/phoenix_profiler/live_view_test.exs | 49 ++++ test/phoenix_profiler/utils_test.exs | 45 ---- test/phoenix_profiler_test.exs | 123 +++++----- 15 files changed, 424 insertions(+), 391 deletions(-) create mode 100644 lib/phoenix_profiler/configurator.ex create mode 100644 lib/phoenix_profiler/profiler.ex create mode 100644 test/phoenix_profiler/live_view_test.exs diff --git a/dev.exs b/dev.exs index 1fd4f21..42ecf2e 100644 --- a/dev.exs +++ b/dev.exs @@ -214,8 +214,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) @@ -259,8 +259,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)} diff --git a/lib/phoenix_profiler.ex b/lib/phoenix_profiler.ex index b1b19a9..66eeb6b 100644 --- a/lib/phoenix_profiler.ex +++ b/lib/phoenix_profiler.ex @@ -39,7 +39,12 @@ defmodule PhoenixProfiler do """ def on_mount(_arg, _params, _session, socket) do - {:cont, PhoenixProfiler.Utils.maybe_mount_profile(socket)} + with true <- Phoenix.LiveView.connected?(socket), + {:ok, socket} <- PhoenixProfiler.Configurator.configure(socket) do + {:cont, socket} + else + _ -> {:cont, socket} + end end @doc """ @@ -77,7 +82,7 @@ defmodule PhoenixProfiler do end """ - defdelegate enable(conn_or_socket), to: PhoenixProfiler.Utils, as: :enable_profiler + defdelegate enable(conn_or_socket), to: PhoenixProfiler.Configurator @doc """ Disables profiling on a given `conn` or `socket`. @@ -105,7 +110,7 @@ defmodule PhoenixProfiler do start with the profiler in a disabled state and enable it after the LiveView has mounted. """ - defdelegate disable(conn_or_socket), to: PhoenixProfiler.Utils, as: :disable_profiler + defdelegate disable(conn_or_socket), to: PhoenixProfiler.Configurator @doc """ Resets the storage of the given `profiler`. diff --git a/lib/phoenix_profiler/configurator.ex b/lib/phoenix_profiler/configurator.ex new file mode 100644 index 0000000..924ef02 --- /dev/null +++ b/lib/phoenix_profiler/configurator.ex @@ -0,0 +1,117 @@ +defmodule PhoenixProfiler.Configurator do + @moduledoc false + alias Phoenix.LiveView + alias PhoenixProfiler.TelemetryServer + alias PhoenixProfiler.Utils + + @doc """ + Disables profiling for a given `conn` or `socket`. + """ + def disable(conn_or_socket) do + update_info(conn_or_socket, :disable) + end + + @doc """ + Enables profiling for a given `conn` or `socket`. + """ + def enable(conn_or_socket) do + update_info(conn_or_socket, :enable) + end + + defp update_info(conn_or_socket, action) when action in [:disable, :enable] do + TelemetryServer.collector_info_exec(action) + Utils.put_private(conn_or_socket, :phoenix_profiler_info, action) + end + + @doc """ + Configures profiling for a given `conn` or `socket`. + """ + def configure(conn_or_socket) do + case apply_profiler_info(conn_or_socket) do + {:ok, conn_or_socket} -> + {:ok, conn_or_socket} + + {:error, :profiler_not_available} -> + {:error, :profiler_not_available} + + {:error, reason} -> + configure_profile_error(conn_or_socket, :configure, reason) + end + end + + defp apply_profiler_info(conn_or_socket) do + endpoint = Utils.endpoint(conn_or_socket) + + with {:ok, config} <- Utils.check_configuration(endpoint), + :ok <- maybe_check_socket_connection(conn_or_socket), + {:ok, profiler} <- check_profiler_running(config), + info = if(config[:enable] == false, do: :disable, else: :enable), + {:ok, collector_pid} <- start_collector(conn_or_socket, profiler, info) do + {:ok, + conn_or_socket + |> Utils.put_private(:phoenix_profiler, profiler) + |> Utils.put_private(:phoenix_profiler_collector, collector_pid) + |> Utils.put_private(:phoenix_profiler_info, info)} + end + end + + defp maybe_check_socket_connection(%Plug.Conn{}), do: :ok + + defp maybe_check_socket_connection(%LiveView.Socket{} = socket) do + Utils.check_socket_connection(socket) + end + + defp check_profiler_running(config) do + profiler = config[:server] + + cond do + GenServer.whereis(profiler) -> + {:ok, profiler} + + profiler -> + {:error, :profiler_not_running} + + true -> + {:error, :profiler_not_available} + end + end + + defp start_collector(%LiveView.Socket{}, _, _) do + {:ok, nil} + end + + defp start_collector(conn_or_socket, server, info) do + case TelemetryServer.listen(server, Utils.target_pid(conn_or_socket), nil, info) do + {:ok, pid} -> + {:ok, pid} + + {:error, {:already_registered, pid}} -> + TelemetryServer.collector_info_exec(info) + {:ok, pid} + end + end + + defp configure_profile_error(%LiveView.Socket{}, action, :waiting_for_connection) do + raise """ + "PhoenixProfiler attempted to #{action} a profiler on the given socket, but it is disconnected + + In your LiveView mount callback, do the following: + + socket = + if connected?(socket) do + PhoenixProfiler.enable(socket) + else + socket + end + + """ + end + + defp configure_profile_error(%{__struct__: struct}, action, :profiler_not_running) do + raise "PhoenixProfiler attempted to #{action} a profiler " <> + "on the given #{kind(struct)}, but the profiler is not running" + end + + defp kind(Plug.Conn), do: :conn + defp kind(LiveView.Socket), do: :socket +end diff --git a/lib/phoenix_profiler/plug.ex b/lib/phoenix_profiler/plug.ex index e9fa470..d7c6ed3 100644 --- a/lib/phoenix_profiler/plug.ex +++ b/lib/phoenix_profiler/plug.ex @@ -21,14 +21,16 @@ defmodule PhoenixProfiler.Plug do 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 PhoenixProfiler.Configurator.configure(conn) do + {:ok, conn} -> + conn + |> telemetry_execute(:start, %{system_time: System.system_time()}) + |> before_send_profile(endpoint, [], start_time) + + {:error, :profiler_not_available} -> + conn end end @@ -38,21 +40,28 @@ 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) + telemetry_execute(conn, :stop, %{duration: System.monotonic_time() - start_time}) - _ -> + case PhoenixProfiler.Profiler.collect(conn) 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([:phxprof, :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 +115,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" => node(), + "server" => profile.server, + "token" => profile.token + }, + token: profile.token, toolbar_attrs: attrs(attrs) }) |> Phoenix.HTML.Safe.to_iodata() diff --git a/lib/phoenix_profiler/profile.ex b/lib/phoenix_profiler/profile.ex index 9800f1d..c2cd938 100644 --- a/lib/phoenix_profiler/profile.ex +++ b/lib/phoenix_profiler/profile.ex @@ -3,18 +3,15 @@ defmodule PhoenixProfiler.Profile do @moduledoc false defstruct [ :collector_pid, - :info, + :data, :node, :server, - :start_time, :system, :system_time, :token, :url ] - @type info :: nil | :enable | :disable - @type system :: %{ :otp => String.t(), :elixir => String.t(), @@ -25,11 +22,10 @@ defmodule PhoenixProfiler.Profile do @type t :: %__MODULE__{ :collector_pid => nil | pid(), - :info => info(), + :data => map(), :token => String.t(), :server => module(), :node => node(), - :start_time => integer(), :system => system(), :system_time => integer(), :url => String.t() @@ -38,15 +34,12 @@ defmodule PhoenixProfiler.Profile do @doc """ Returns a new profile. """ - def new(node \\ node(), server, token, info, base_url, system_time) + def new(server, token, 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 %__MODULE__{ - info: info, - node: node, + node: node(), server: server, - start_time: System.monotonic_time(), system: PhoenixProfiler.ProfileStore.system(server), system_time: system_time, token: token, diff --git a/lib/phoenix_profiler/profile_store.ex b/lib/phoenix_profiler/profile_store.ex index 30c906c..6fe392a 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 + server when is_atom(server) -> server nil -> nil end end @@ -106,10 +106,6 @@ defmodule PhoenixProfiler.ProfileStore do @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..9888597 --- /dev/null +++ b/lib/phoenix_profiler/profiler.ex @@ -0,0 +1,69 @@ +defmodule PhoenixProfiler.Profiler do + @moduledoc false + + alias PhoenixProfiler.Profile + alias PhoenixProfiler.ProfileStore + alias PhoenixProfiler.Utils + + @default_profiler_link_base "/dashboard/_profiler" + + @doc """ + Builds a profile from data collected for a given `conn`. + """ + def collect(%Plug.Conn{} = conn) do + endpoint = conn.private.phoenix_endpoint + config = endpoint.config(:phoenix_profiler) + + link_base = + case Keyword.fetch(config, :profiler_link_base) do + {:ok, path} when is_binary(path) and path != "" -> + "/" <> String.trim_leading(path, "/") + + _ -> + @default_profiler_link_base + end + + if conn.private.phoenix_profiler_info == :enable do + time = System.system_time() + + data = + PhoenixProfiler.TelemetryCollector.reduce( + conn.private.phoenix_profiler_collector, + %{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 + ) + + profiler_base_url = endpoint.url() <> link_base + + profile = + Profile.new( + conn.private.phoenix_profiler, + Utils.random_unique_id(), + profiler_base_url, + time + ) + + {:ok, %Profile{profile | data: data}} + else + :error + end + end + + @doc false + def insert_profile(%Profile{} = profile) do + profile + |> ProfileStore.table() + |> :ets.insert({profile.token, profile}) + end +end diff --git a/lib/phoenix_profiler/telemetry.ex b/lib/phoenix_profiler/telemetry.ex index 4a7acf8..910d7da 100644 --- a/lib/phoenix_profiler/telemetry.ex +++ b/lib/phoenix_profiler/telemetry.ex @@ -28,23 +28,14 @@ defmodule PhoenixProfiler.Telemetry do end def collect(_, [:phxprof, :plug, :stop], measures, %{conn: conn}) do - profile = conn.private.phoenix_profiler - - case profile.info do - :disable -> - :skip - - 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 + {:keep, + %{ + 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, :live_view | _] = event, measures, %{socket: socket} = meta) do diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.ex b/lib/phoenix_profiler/toolbar/toolbar_live.ex index c958339..e686bb1 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: []]} @@ -65,9 +64,10 @@ defmodule PhoenixProfiler.ToolbarLive do end defp assign_toolbar(socket, profile) do - %{metrics: metrics} = profile + %Profile{data: %{metrics: metrics}} = profile socket + |> assign(:profile, profile) |> apply_request(profile) |> assign(:durations, %{ total: duration(metrics.total_duration), @@ -78,7 +78,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)} diff --git a/lib/phoenix_profiler/toolbar/toolbar_view.ex b/lib/phoenix_profiler/toolbar/toolbar_view.ex index e175fbf..d67d772 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_view.ex +++ b/lib/phoenix_profiler/toolbar/toolbar_view.ex @@ -21,8 +21,8 @@ defmodule PhoenixProfiler.ToolbarView do ~L""" > -
-
+
+
<%= live_render(@conn, ToolbarLive, session: @session) %>
diff --git a/lib/phoenix_profiler/utils.ex b/lib/phoenix_profiler/utils.ex index f89e05c..077d8e5 100644 --- a/lib/phoenix_profiler/utils.ex +++ b/lib/phoenix_profiler/utils.ex @@ -1,108 +1,23 @@ defmodule PhoenixProfiler.Utils do @moduledoc false alias Phoenix.LiveView - alias PhoenixProfiler.Profile - alias PhoenixProfiler.TelemetryServer - - @default_profiler_link_base "/dashboard/_profiler" @doc """ - Mounts the profile if it has been enabled on the endpoint. + Returns info for `server` about the registered collector for a given `conn` or `socket`. """ - def maybe_mount_profile(%LiveView.Socket{} = socket) do - if LiveView.connected?(socket) and configured?(socket) do - enable_profiler(socket) - else - socket + def collector_info(server, conn_or_socket) do + case Registry.lookup(PhoenixProfiler.TelemetryRegistry, target_pid(conn_or_socket)) do + [{pid, {^server, {pid, nil}, info}}] when is_pid(pid) -> {info, pid} + [] -> :error end end - defp configured?(conn_or_socket) do - endpoint(conn_or_socket).config(:phoenix_profiler, false) != false - end - @doc """ - Enables the profiler on a given `conn` or `socket`. - - Raises if the profiler is not defined or is not started. - For a LiveView socket, raises if the socket is not connected. + Returns the pid to target when collecting data. """ - def enable_profiler(conn_or_socket) do - endpoint = endpoint(conn_or_socket) - config = endpoint.config(:phoenix_profiler) || [] - enable_profiler(conn_or_socket, endpoint, config, System.system_time()) - end - - def enable_profiler(conn_or_socket, endpoint, config, system_time) - when is_atom(endpoint) and is_list(config) and is_integer(system_time) do - with :ok <- check_requires_profile(conn_or_socket), - :ok <- maybe_check_socket_connection(conn_or_socket), - {:ok, profiler} <- check_profiler_running(config) do - conn_or_socket - |> new_profile(endpoint, profiler, config, system_time) - |> start_collector(profiler) - |> telemetry_execute(:start, %{system_time: system_time}) - else - {:error, reason} -> enable_profiler_error(conn_or_socket, reason) - end - end - - defp check_requires_profile(conn_or_socket) do - case conn_or_socket.private do - %{:phoenix_profiler => %Profile{}} -> - {:error, :profile_already_exists} - - _ -> - :ok - end - end - - defp maybe_check_socket_connection(%Plug.Conn{}), do: :ok - - defp maybe_check_socket_connection(%LiveView.Socket{} = socket) do - check_socket_connection(socket) - end - - defp new_profile(conn_or_socket, endpoint, profiler, config, system_time) do - info = if config[:enable] == false, do: :disable, else: :enable - profiler_base_url = profiler_base_url(endpoint, config) - profile = Profile.new(profiler, random_unique_id(), info, profiler_base_url, system_time) - put_private(conn_or_socket, :phoenix_profiler, profile) - end - - defp profiler_base_url(endpoint, config) do - endpoint.url() <> profiler_link_base(config[:profiler_link_base]) - end - - defp profiler_link_base(path) when is_binary(path) and path != "", do: path - defp profiler_link_base(_), do: @default_profiler_link_base - - defp start_collector(%Plug.Conn{} = conn, server) do - profile = conn.private.phoenix_profiler - - collector_pid = - if is_pid(profile.collector_pid) and Process.alive?(profile.collector_pid) do - TelemetryServer.collector_info_exec(profile.info) - {:ok, profile.collector_pid} - else - TelemetryServer.listen(server, conn.owner, nil, profile.info) - end - |> case do - {:ok, collector_pid} -> collector_pid - {:error, {:already_registered, collector_pid}} -> collector_pid - end - - put_private(conn, :phoenix_profiler, %{profile | collector_pid: collector_pid}) - end - - defp start_collector(%LiveView.Socket{} = socket, _server) do - # ToolbarLive acts as the LiveView Socket collector so we never - # start a collector here, but we can execute telemetry to notify it - # that the state changed. - info = socket.private.phoenix_profiler.info - TelemetryServer.collector_info_exec(info) - socket - end + def target_pid(conn_or_socket) + def target_pid(%Plug.Conn{owner: owner}), do: owner + def target_pid(%LiveView.Socket{} = socket), do: transport_pid(socket) @doc """ Returns the endpoint for a given `conn` or `socket`. @@ -111,57 +26,18 @@ defmodule PhoenixProfiler.Utils do def endpoint(%Plug.Conn{} = conn), do: conn.private.phoenix_endpoint def endpoint(%LiveView.Socket{endpoint: endpoint}), do: endpoint - defp enable_profiler_error(conn_or_socket, :profile_already_exists) do - # notify state change and ensure profile info is :enable - profile = conn_or_socket.private.phoenix_profiler - TelemetryServer.collector_info_exec(:enable) - put_private(conn_or_socket, :phoenix_profiler, %{profile | info: :enable}) - end - - defp enable_profiler_error(%LiveView.Socket{}, :waiting_for_connection) do - raise """ - attempted to enable profiling on a disconnected socket - - In your LiveView mount callback, do the following: - - socket = - if connected?(socket) do - PhoenixProfiler.enable(socket) - else - socket - end - - """ - end - - defp enable_profiler_error(_, :profiler_not_available) do - raise "attempted to enable profiling but no profiler is configured on the endpoint" - end - - defp enable_profiler_error(_, :profiler_not_running) do - raise "attempted to enable profiling but the profiler is not running" - end - @doc """ - Disables the profiler on a given `conn` or `socket`. - - If a profile is not present on the data structure, this function has no effect. + Checks whether or not a configuration exists. """ - def disable_profiler( - %{__struct__: kind, private: %{phoenix_profiler: %Profile{} = profile}} = conn_or_socket - ) - when kind in [Plug.Conn, LiveView.Socket] do - conn_or_socket - |> put_private(:phoenix_profiler, %{profile | info: :disable}) - |> unregister_collector() + def check_configuration(endpoint) when is_atom(endpoint) do + case endpoint.config(:phoenix_profiler) do + [_ | _] = config -> {:ok, config} + _ -> {:error, :profiler_not_available} + end end - def disable_profiler(%Plug.Conn{} = conn), do: conn - def disable_profiler(%LiveView.Socket{} = socket), do: socket - - defp unregister_collector(conn_or_socket) do - TelemetryServer.collector_info_exec(:disable) - conn_or_socket + def check_configuration(%_{} = struct) do + struct |> endpoint() |> check_configuration() end @doc """ @@ -177,25 +53,6 @@ defmodule PhoenixProfiler.Utils do end end - # Note: if we ever call this from the dashboard, we will - # need to ensure we are checking the proper node. - defp check_profiler_running(config) do - cond do - config == [] -> - {:error, :profiler_not_available} - - profiler = config[:server] -> - if GenServer.whereis(profiler) do - {:ok, profiler} - else - {:error, :profiler_not_running} - end - - true -> - {:error, :profiler_not_available} - end - end - @doc """ Assigns a new private key and value in the socket. """ @@ -247,44 +104,6 @@ defmodule PhoenixProfiler.Utils do end) end - @doc false - def on_send_resp(conn, %Profile{} = profile) do - duration = System.monotonic_time() - profile.start_time - conn = telemetry_execute(conn, :stop, %{duration: duration}) - - data = - PhoenixProfiler.TelemetryCollector.reduce( - profile.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} = map_pop!(entry, :metrics) - acc = Map.merge(acc, rest) - %{acc | metrics: Map.merge(acc.metrics, metrics)} - - {:telemetry, _, _, _, data}, acc -> - Map.merge(acc, data) - end - ) - - profile - |> PhoenixProfiler.ProfileStore.table() - |> :ets.insert({profile.token, data}) - - conn - end - - defp telemetry_execute(%LiveView.Socket{} = socket, _, _), do: socket - - defp telemetry_execute(%Plug.Conn{} = conn, action, measurements) - when action in [:start, :stop] do - :telemetry.execute([:phxprof, :plug, action], measurements, %{conn: conn}) - conn - end - @doc false def sort_by(enumerable, sort_by_fun, :asc) do Enum.sort_by(enumerable, sort_by_fun, &<=/2) diff --git a/test/phoenix_profiler/integrations/phoenix_profiler_test.exs b/test/phoenix_profiler/integrations/phoenix_profiler_test.exs index 97cfe98..b67e68b 100644 --- a/test/phoenix_profiler/integrations/phoenix_profiler_test.exs +++ b/test/phoenix_profiler/integrations/phoenix_profiler_test.exs @@ -1,6 +1,7 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do use ExUnit.Case, async: true import Phoenix.ConnTest + alias PhoenixProfiler.Profile alias PhoenixProfiler.ProfileStore alias PhoenixProfilerTest.Endpoint @@ -22,21 +23,23 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do assert url == "http://localhost:4000/dashboard/_profiler?nav=PhoenixProfilerTest.Profiler&panel=request&token=#{token}" - %{ - conn: %Plug.Conn{ - host: "www.example.com", - method: "GET", - path_info: [], - private: %{ - phoenix_action: :index, - phoenix_controller: PhoenixProfilerTest.PageController, - phoenix_endpoint: PhoenixProfilerTest.Endpoint, - phoenix_router: PhoenixProfilerTest.Router, - phoenix_view: PhoenixProfilerTest.PageView + %Profile{ + data: %{ + conn: %Plug.Conn{ + host: "www.example.com", + method: "GET", + path_info: [], + private: %{ + phoenix_action: :index, + phoenix_controller: PhoenixProfilerTest.PageController, + phoenix_endpoint: PhoenixProfilerTest.Endpoint, + phoenix_router: PhoenixProfilerTest.Router, + phoenix_view: PhoenixProfilerTest.PageView + }, + status: 200 }, - status: 200 - }, - metrics: metrics + metrics: metrics + } } = conn |> ProfileStore.profiler() |> ProfileStore.get(token) assert metrics.total_duration > 0 @@ -60,21 +63,23 @@ defmodule PhoenixProfiler.PhoenixProfilerTest do assert url == "http://localhost:4000/dashboard/_profiler?nav=PhoenixProfilerTest.Profiler&panel=request&token=#{token}" - %{ - conn: %Plug.Conn{ - host: "www.example.com", - method: "GET", - path_info: ["api"], - private: %{ - phoenix_action: :index, - phoenix_controller: PhoenixProfilerTest.APIController, - phoenix_endpoint: PhoenixProfilerTest.Endpoint, - phoenix_router: PhoenixProfilerTest.Router, - phoenix_view: PhoenixProfilerTest.APIView + %Profile{ + data: %{ + conn: %Plug.Conn{ + host: "www.example.com", + method: "GET", + path_info: ["api"], + private: %{ + phoenix_action: :index, + phoenix_controller: PhoenixProfilerTest.APIController, + phoenix_endpoint: PhoenixProfilerTest.Endpoint, + phoenix_router: PhoenixProfilerTest.Router, + phoenix_view: PhoenixProfilerTest.APIView + }, + status: 200 }, - status: 200 - }, - metrics: metrics + metrics: metrics + } } = conn |> ProfileStore.profiler() |> ProfileStore.get(token) assert metrics.endpoint_duration > 0 diff --git a/test/phoenix_profiler/live_view_test.exs b/test/phoenix_profiler/live_view_test.exs new file mode 100644 index 0000000..0508e87 --- /dev/null +++ b/test/phoenix_profiler/live_view_test.exs @@ -0,0 +1,49 @@ +defmodule PhoenixProfiler.LiveViewTest do + use ExUnit.Case + alias Phoenix.LiveView.Socket + + defp build_socket(endpoint \\ PhoenixProfilerTest.Endpoint) do + %Socket{endpoint: endpoint} + end + + defp connect(%Socket{} = socket) do + # TODO: replace with struct update when we require LiveView v0.15+. + socket = Map.put(socket, :transport_pid, self()) + + # TODO: remove when we require LiveView v0.15+. + if Map.has_key?(socket, :connected?) do + Map.put(socket, :connected?, true) + else + socket + end + end + + describe "on_mount/4" do + test "when the socket is disconnected, is a no-op" do + socket = build_socket() + assert PhoenixProfiler.on_mount(:default, %{}, %{}, socket) == {:cont, socket} + end + + test "when the profiler is enabled on the endpoint, configures an enabled profile" do + {:ok, socket} = build_socket() |> connect() |> PhoenixProfiler.Configurator.configure() + + assert {:cont, %{private: %{phoenix_profiler: _profiler, phoenix_profiler_info: :enable}}} = + PhoenixProfiler.on_mount(:default, %{}, %{}, socket) + end + + test "when the profiler is disabled on the endpoint, configures a disabled profile" do + socket = + PhoenixProfilerTest.EndpointDisabled + |> build_socket() + |> connect() + + assert {:cont, %Socket{private: %{phoenix_profiler_info: :disable}}} = + PhoenixProfiler.on_mount(:default, %{}, %{}, socket) + end + + test "when the profiler is not defined on the endpoint, is a no-op" do + socket = PhoenixProfilerTest.EndpointNotConfigured |> build_socket() |> connect() + assert PhoenixProfiler.on_mount(:default, %{}, %{}, socket) == {:cont, socket} + end + end +end diff --git a/test/phoenix_profiler/utils_test.exs b/test/phoenix_profiler/utils_test.exs index d158232..4c8a855 100644 --- a/test/phoenix_profiler/utils_test.exs +++ b/test/phoenix_profiler/utils_test.exs @@ -1,48 +1,3 @@ defmodule PhoenixProfiler.UtilsTest do use ExUnit.Case - alias Phoenix.LiveView - - defp build_socket(endpoint \\ PhoenixProfilerTest.Endpoint) do - %LiveView.Socket{endpoint: endpoint} - end - - defp connect(%LiveView.Socket{} = socket) do - # TODO: replace with struct update when we require LiveView v0.15+. - socket = Map.put(socket, :transport_pid, self()) - - # TODO: remove when we require LiveView v0.15+. - if Map.has_key?(socket, :connected?) do - Map.put(socket, :connected?, true) - else - socket - end - end - - describe "maybe_mount_profile1/" do - test "when the socket is disconnected, is a no-op" do - socket = build_socket() - refute socket.private[:phoenix_profiler] - assert PhoenixProfiler.Utils.maybe_mount_profile(socket) == socket - end - - test "when the profiler is enabled on the endpoint, configures an enabled profile" do - socket = build_socket() |> connect() |> PhoenixProfiler.Utils.maybe_mount_profile() - assert %PhoenixProfiler.Profile{info: :enable} = socket.private.phoenix_profiler - end - - test "when the profiler is disabled on the endpoint, configures a disabled profile" do - socket = - PhoenixProfilerTest.EndpointDisabled - |> build_socket() - |> connect() - |> PhoenixProfiler.Utils.maybe_mount_profile() - - assert %PhoenixProfiler.Profile{info: :disable} = socket.private.phoenix_profiler - end - - test "when the profiler is not defined on the endpoint, is a no-op" do - socket = PhoenixProfilerTest.EndpointNotConfigured |> build_socket() |> connect() - assert PhoenixProfiler.Utils.maybe_mount_profile(socket) == socket - end - end end diff --git a/test/phoenix_profiler_test.exs b/test/phoenix_profiler_test.exs index fd4b2e2..6ac9d1d 100644 --- a/test/phoenix_profiler_test.exs +++ b/test/phoenix_profiler_test.exs @@ -1,7 +1,6 @@ defmodule PhoenixProfilerUnitTest do use ExUnit.Case, async: true alias Phoenix.LiveView.Socket - alias PhoenixProfiler.Profile doctest PhoenixProfiler @@ -50,100 +49,120 @@ defmodule PhoenixProfilerUnitTest do assert [AllRunning_1, AllRunning_2] -- PhoenixProfiler.all_running() == [] end - describe "enable/1 with Plug.Conn" do - test "raises when the profiler is not defined on the endpoint" do - assert_raise RuntimeError, - ~r/attempted to enable profiling but no profiler is configured on the endpoint/, - fn -> - NoConfigEndpoint - |> build_conn() - |> PhoenixProfiler.enable() - end + describe "configure/1 with Plug.Conn" do + test "returns {:error, :profiler_not_available} when the profiler is not defined on the endpoint" do + assert NoConfigEndpoint + |> build_conn() + |> PhoenixProfiler.Configurator.configure() == {:error, :profiler_not_available} end test "raises when the profiler is not running" do assert_raise RuntimeError, - ~r/attempted to enable profiling but the profiler is not running/, + ~r/attempted to configure a profiler on the given conn, but the profiler is not running/, fn -> EndpointMock |> build_conn() - |> PhoenixProfiler.enable() + |> PhoenixProfiler.Configurator.configure() end end - test "puts a profile on the conn" do - start_supervised!({PhoenixProfiler, name: MyProfiler}) + test "starts a collector" do + profiler_name = MyProfiler + start_supervised!({PhoenixProfiler, name: profiler_name}) + + conn = build_conn() + + assert PhoenixProfiler.Utils.collector_info(profiler_name, conn) == :error - conn = - build_conn() - |> PhoenixProfiler.Utils.put_private(:phoenix_endpoint, EndpointMock) - |> PhoenixProfiler.enable() + assert {:ok, conn} = + conn + |> PhoenixProfiler.Utils.put_private(:phoenix_endpoint, EndpointMock) + |> PhoenixProfiler.Configurator.configure() - %Profile{server: MyProfiler, info: :enable} = conn.private.phoenix_profiler + assert {:enable, collector_pid} = PhoenixProfiler.Utils.collector_info(profiler_name, conn) + + assert Process.alive?(collector_pid) end end - describe "enable/1 with LiveView.Socket" do + describe "configure/1 with LiveView.Socket" do test "raises when socket is not connected" do assert_raise RuntimeError, - ~r/attempted to enable profiling on a disconnected socket/, + ~r/attempted to configure a profiler on the given socket, but it is disconnected/, fn -> - PhoenixProfiler.enable(build_socket()) + PhoenixProfiler.Configurator.configure(build_socket()) end end - test "raises when the profiler is not configured on the endpoint" do - assert_raise RuntimeError, - ~r/attempted to enable profiling but no profiler is configured on the endpoint/, - fn -> - build_socket() - |> Map.put(:endpoint, NoConfigEndpoint) - |> connect() - |> PhoenixProfiler.enable() - end + test "returns {:error, :profiler_not_available} when the profiler is not defined on the endpoint" do + assert build_socket() + |> Map.put(:endpoint, NoConfigEndpoint) + |> connect() + |> PhoenixProfiler.Configurator.configure() == {:error, :profiler_not_available} end test "raises when the profiler is not running" do assert_raise RuntimeError, - ~r/attempted to enable profiling but the profiler is not running/, + ~r/attempted to configure a profiler on the given socket, but the profiler is not running/, fn -> - build_socket() |> connect() |> PhoenixProfiler.enable() + build_socket() |> connect() |> PhoenixProfiler.Configurator.configure() end end - test "puts a profile on the socket" do - start_supervised!({PhoenixProfiler, name: MyProfiler}) - socket = build_socket() |> connect() |> PhoenixProfiler.enable() - assert %Profile{server: MyProfiler, info: :enable} = socket.private.phoenix_profiler - end - end + test "does not start a collector" do + profiler_name = MyProfiler + start_supervised!({PhoenixProfiler, name: profiler_name}) + socket = build_socket() |> connect() - test "disable/1 when no profile is set" do - conn = build_conn(EndpointMock) - assert PhoenixProfiler.disable(conn) == conn + assert PhoenixProfiler.Utils.collector_info(profiler_name, socket) == :error - socket = build_socket() |> connect() |> PhoenixProfiler.disable() - assert PhoenixProfiler.disable(socket) == socket + assert {:ok, socket} = PhoenixProfiler.Configurator.configure(socket) + + assert PhoenixProfiler.Utils.collector_info(profiler_name, socket) == :error + end end test "disable/1 with Plug.Conn" do - start_supervised!({PhoenixProfiler, name: MyProfiler}) + profiler = start_profiler!() conn = build_conn() |> PhoenixProfiler.Utils.put_private(:phoenix_endpoint, EndpointMock) - |> PhoenixProfiler.enable() - assert conn.private.phoenix_profiler.info == :enable + assert PhoenixProfiler.Utils.collector_info(profiler, conn) == :error + + {:ok, conn} = PhoenixProfiler.Configurator.configure(conn) + assert {:enable, _pid} = PhoenixProfiler.Utils.collector_info(profiler, conn) + conn = PhoenixProfiler.disable(conn) - assert conn.private.phoenix_profiler.info == :disable + assert conn.private.phoenix_profiler_info == :disable end test "disable/1 with LiveView.Socket" do - start_supervised!({PhoenixProfiler, name: MyProfiler}) - socket = build_socket() |> connect() |> PhoenixProfiler.enable() - assert socket.private.phoenix_profiler.info == :enable + profiler = start_profiler!() + + socket = build_socket() |> connect() + assert PhoenixProfiler.Utils.collector_info(profiler, socket) == :error + + {:ok, socket} = PhoenixProfiler.Configurator.configure(socket) + + {:ok, pid} = + PhoenixProfiler.TelemetryServer.listen( + profiler, + PhoenixProfiler.Utils.transport_pid(socket) + ) + + assert {:enable, ^pid} = PhoenixProfiler.Utils.collector_info(profiler, socket) + socket = PhoenixProfiler.disable(socket) - assert socket.private.phoenix_profiler.info == :disable + assert socket.private.phoenix_profiler_info == :disable + + :timer.sleep(10) + assert {:disable, ^pid} = PhoenixProfiler.Utils.collector_info(profiler, socket) + end + + defp start_profiler!(name \\ MyProfiler) do + start_supervised!({PhoenixProfiler, name: name}) + name end end From b9c77f0006f0dff60cb9fc42db9ed69690f05e3b Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sat, 26 Feb 2022 20:46:27 -0800 Subject: [PATCH 03/38] maybe mount profile --- lib/phoenix_profiler.ex | 7 +------ lib/phoenix_profiler/utils.ex | 16 +++++++++++++++- 2 files changed, 16 insertions(+), 7 deletions(-) diff --git a/lib/phoenix_profiler.ex b/lib/phoenix_profiler.ex index 66eeb6b..54c5e95 100644 --- a/lib/phoenix_profiler.ex +++ b/lib/phoenix_profiler.ex @@ -39,12 +39,7 @@ defmodule PhoenixProfiler do """ def on_mount(_arg, _params, _session, socket) do - with true <- Phoenix.LiveView.connected?(socket), - {:ok, socket} <- PhoenixProfiler.Configurator.configure(socket) do - {:cont, socket} - else - _ -> {:cont, socket} - end + {:cont, PhoenixProfiler.Utils.maybe_mount_profiler(socket)} end @doc """ diff --git a/lib/phoenix_profiler/utils.ex b/lib/phoenix_profiler/utils.ex index 077d8e5..0dd4876 100644 --- a/lib/phoenix_profiler/utils.ex +++ b/lib/phoenix_profiler/utils.ex @@ -3,7 +3,21 @@ defmodule PhoenixProfiler.Utils do alias Phoenix.LiveView @doc """ - Returns info for `server` about the registered collector for a given `conn` or `socket`. + Mounts the profiler on a connected LiveView socket only if + it is enabled on the Endpoint. + """ + def maybe_mount_profiler(%LiveView.Socket{} = socket) do + with true <- Phoenix.LiveView.connected?(socket), + {:ok, socket} <- PhoenixProfiler.Configurator.configure(socket) do + socket + else + _ -> socket + end + end + + @doc """ + Returns info for `server` about the registered collector for a + given `conn` or `socket`. """ def collector_info(server, conn_or_socket) do case Registry.lookup(PhoenixProfiler.TelemetryRegistry, target_pid(conn_or_socket)) do From 29d0790ab25caba77571ed54d29e5f1a81be0d43 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 00:14:06 -0800 Subject: [PATCH 04/38] Consolidate profiler modules --- lib/phoenix_profiler.ex | 6 +- lib/phoenix_profiler/configurator.ex | 117 ------------------- lib/phoenix_profiler/plug.ex | 2 +- lib/phoenix_profiler/profiler.ex | 142 ++++++++++++++++++++++- lib/phoenix_profiler/supervisor.ex | 28 ----- lib/phoenix_profiler/utils.ex | 2 +- test/phoenix_profiler/live_view_test.exs | 2 +- test/phoenix_profiler_test.exs | 18 +-- 8 files changed, 155 insertions(+), 162 deletions(-) delete mode 100644 lib/phoenix_profiler/configurator.ex delete mode 100644 lib/phoenix_profiler/supervisor.ex diff --git a/lib/phoenix_profiler.ex b/lib/phoenix_profiler.ex index 54c5e95..622f2b5 100644 --- a/lib/phoenix_profiler.ex +++ b/lib/phoenix_profiler.ex @@ -12,7 +12,7 @@ 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 @@ -77,7 +77,7 @@ defmodule PhoenixProfiler do end """ - defdelegate enable(conn_or_socket), to: PhoenixProfiler.Configurator + defdelegate enable(conn_or_socket), to: PhoenixProfiler.Profiler @doc """ Disables profiling on a given `conn` or `socket`. @@ -105,7 +105,7 @@ defmodule PhoenixProfiler do start with the profiler in a disabled state and enable it after the LiveView has mounted. """ - defdelegate disable(conn_or_socket), to: PhoenixProfiler.Configurator + defdelegate disable(conn_or_socket), to: PhoenixProfiler.Profiler @doc """ Resets the storage of the given `profiler`. diff --git a/lib/phoenix_profiler/configurator.ex b/lib/phoenix_profiler/configurator.ex deleted file mode 100644 index 924ef02..0000000 --- a/lib/phoenix_profiler/configurator.ex +++ /dev/null @@ -1,117 +0,0 @@ -defmodule PhoenixProfiler.Configurator do - @moduledoc false - alias Phoenix.LiveView - alias PhoenixProfiler.TelemetryServer - alias PhoenixProfiler.Utils - - @doc """ - Disables profiling for a given `conn` or `socket`. - """ - def disable(conn_or_socket) do - update_info(conn_or_socket, :disable) - end - - @doc """ - Enables profiling for a given `conn` or `socket`. - """ - def enable(conn_or_socket) do - update_info(conn_or_socket, :enable) - end - - defp update_info(conn_or_socket, action) when action in [:disable, :enable] do - TelemetryServer.collector_info_exec(action) - Utils.put_private(conn_or_socket, :phoenix_profiler_info, action) - end - - @doc """ - Configures profiling for a given `conn` or `socket`. - """ - def configure(conn_or_socket) do - case apply_profiler_info(conn_or_socket) do - {:ok, conn_or_socket} -> - {:ok, conn_or_socket} - - {:error, :profiler_not_available} -> - {:error, :profiler_not_available} - - {:error, reason} -> - configure_profile_error(conn_or_socket, :configure, reason) - end - end - - defp apply_profiler_info(conn_or_socket) do - endpoint = Utils.endpoint(conn_or_socket) - - with {:ok, config} <- Utils.check_configuration(endpoint), - :ok <- maybe_check_socket_connection(conn_or_socket), - {:ok, profiler} <- check_profiler_running(config), - info = if(config[:enable] == false, do: :disable, else: :enable), - {:ok, collector_pid} <- start_collector(conn_or_socket, profiler, info) do - {:ok, - conn_or_socket - |> Utils.put_private(:phoenix_profiler, profiler) - |> Utils.put_private(:phoenix_profiler_collector, collector_pid) - |> Utils.put_private(:phoenix_profiler_info, info)} - end - end - - defp maybe_check_socket_connection(%Plug.Conn{}), do: :ok - - defp maybe_check_socket_connection(%LiveView.Socket{} = socket) do - Utils.check_socket_connection(socket) - end - - defp check_profiler_running(config) do - profiler = config[:server] - - cond do - GenServer.whereis(profiler) -> - {:ok, profiler} - - profiler -> - {:error, :profiler_not_running} - - true -> - {:error, :profiler_not_available} - end - end - - defp start_collector(%LiveView.Socket{}, _, _) do - {:ok, nil} - end - - defp start_collector(conn_or_socket, server, info) do - case TelemetryServer.listen(server, Utils.target_pid(conn_or_socket), nil, info) do - {:ok, pid} -> - {:ok, pid} - - {:error, {:already_registered, pid}} -> - TelemetryServer.collector_info_exec(info) - {:ok, pid} - end - end - - defp configure_profile_error(%LiveView.Socket{}, action, :waiting_for_connection) do - raise """ - "PhoenixProfiler attempted to #{action} a profiler on the given socket, but it is disconnected - - In your LiveView mount callback, do the following: - - socket = - if connected?(socket) do - PhoenixProfiler.enable(socket) - else - socket - end - - """ - end - - defp configure_profile_error(%{__struct__: struct}, action, :profiler_not_running) do - raise "PhoenixProfiler attempted to #{action} a profiler " <> - "on the given #{kind(struct)}, but the profiler is not running" - end - - defp kind(Plug.Conn), do: :conn - defp kind(LiveView.Socket), do: :socket -end diff --git a/lib/phoenix_profiler/plug.ex b/lib/phoenix_profiler/plug.ex index d7c6ed3..56ab27a 100644 --- a/lib/phoenix_profiler/plug.ex +++ b/lib/phoenix_profiler/plug.ex @@ -23,7 +23,7 @@ defmodule PhoenixProfiler.Plug do endpoint = conn.private.phoenix_endpoint start_time = System.monotonic_time() - case PhoenixProfiler.Configurator.configure(conn) do + case PhoenixProfiler.Profiler.configure(conn) do {:ok, conn} -> conn |> telemetry_execute(:start, %{system_time: System.system_time()}) diff --git a/lib/phoenix_profiler/profiler.ex b/lib/phoenix_profiler/profiler.ex index 9888597..f7a7583 100644 --- a/lib/phoenix_profiler/profiler.ex +++ b/lib/phoenix_profiler/profiler.ex @@ -1,8 +1,11 @@ defmodule PhoenixProfiler.Profiler do @moduledoc false - + use Supervisor + alias Phoenix.LiveView alias PhoenixProfiler.Profile alias PhoenixProfiler.ProfileStore + alias PhoenixProfiler.Telemetry + alias PhoenixProfiler.TelemetryServer alias PhoenixProfiler.Utils @default_profiler_link_base "/dashboard/_profiler" @@ -60,10 +63,145 @@ defmodule PhoenixProfiler.Profiler do end end - @doc false + @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(conn_or_socket) do + update_info(conn_or_socket, :disable) + end + + @doc """ + Enables profiling for a given `conn` or `socket`. + """ + def enable(conn_or_socket) do + update_info(conn_or_socket, :enable) + end + + @doc """ + Configures profiling for a given `conn` or `socket`. + """ + def configure(conn_or_socket) do + case apply_profiler_info(conn_or_socket) do + {:ok, conn_or_socket} -> + {:ok, conn_or_socket} + + {:error, :profiler_not_available} -> + {:error, :profiler_not_available} + + {:error, reason} -> + configure_profile_error(conn_or_socket, :configure, reason) + end + 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 + + defp update_info(conn_or_socket, action) when action in [:disable, :enable] do + TelemetryServer.collector_info_exec(action) + Utils.put_private(conn_or_socket, :phoenix_profiler_info, action) + end + + defp apply_profiler_info(conn_or_socket) do + endpoint = Utils.endpoint(conn_or_socket) + + with {:ok, config} <- Utils.check_configuration(endpoint), + :ok <- maybe_check_socket_connection(conn_or_socket), + {:ok, profiler} <- check_profiler_running(config), + info = if(config[:enable] == false, do: :disable, else: :enable), + {:ok, collector_pid} <- start_collector(conn_or_socket, profiler, info) do + {:ok, + conn_or_socket + |> Utils.put_private(:phoenix_profiler, profiler) + |> Utils.put_private(:phoenix_profiler_collector, collector_pid) + |> Utils.put_private(:phoenix_profiler_info, info)} + end + end + + defp maybe_check_socket_connection(%Plug.Conn{}), do: :ok + + defp maybe_check_socket_connection(%LiveView.Socket{} = socket) do + Utils.check_socket_connection(socket) + end + + defp check_profiler_running(config) do + profiler = config[:server] + + cond do + GenServer.whereis(profiler) -> + {:ok, profiler} + + profiler -> + {:error, :profiler_not_running} + + true -> + {:error, :profiler_not_available} + end + end + + defp start_collector(%LiveView.Socket{}, _, _) do + {:ok, nil} + end + + defp start_collector(conn_or_socket, server, info) do + case TelemetryServer.listen(server, Utils.target_pid(conn_or_socket), nil, info) do + {:ok, pid} -> + {:ok, pid} + + {:error, {:already_registered, pid}} -> + TelemetryServer.collector_info_exec(info) + {:ok, pid} + end + end + + defp configure_profile_error(%LiveView.Socket{}, action, :waiting_for_connection) do + raise """ + "PhoenixProfiler attempted to #{action} a profiler on the given socket, but it is disconnected + + In your LiveView mount callback, do the following: + + socket = + if connected?(socket) do + PhoenixProfiler.enable(socket) + else + socket + end + + """ + end + + defp configure_profile_error(%{__struct__: struct}, action, :profiler_not_running) do + raise "PhoenixProfiler attempted to #{action} a profiler " <> + "on the given #{kind(struct)}, but the profiler is not running" + end + + defp kind(Plug.Conn), do: :conn + defp kind(LiveView.Socket), do: :socket 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/utils.ex b/lib/phoenix_profiler/utils.ex index 0dd4876..e46b676 100644 --- a/lib/phoenix_profiler/utils.ex +++ b/lib/phoenix_profiler/utils.ex @@ -8,7 +8,7 @@ defmodule PhoenixProfiler.Utils do """ def maybe_mount_profiler(%LiveView.Socket{} = socket) do with true <- Phoenix.LiveView.connected?(socket), - {:ok, socket} <- PhoenixProfiler.Configurator.configure(socket) do + {:ok, socket} <- PhoenixProfiler.Profiler.configure(socket) do socket else _ -> socket diff --git a/test/phoenix_profiler/live_view_test.exs b/test/phoenix_profiler/live_view_test.exs index 0508e87..7f0d33a 100644 --- a/test/phoenix_profiler/live_view_test.exs +++ b/test/phoenix_profiler/live_view_test.exs @@ -25,7 +25,7 @@ defmodule PhoenixProfiler.LiveViewTest do end test "when the profiler is enabled on the endpoint, configures an enabled profile" do - {:ok, socket} = build_socket() |> connect() |> PhoenixProfiler.Configurator.configure() + {:ok, socket} = build_socket() |> connect() |> PhoenixProfiler.Profiler.configure() assert {:cont, %{private: %{phoenix_profiler: _profiler, phoenix_profiler_info: :enable}}} = PhoenixProfiler.on_mount(:default, %{}, %{}, socket) diff --git a/test/phoenix_profiler_test.exs b/test/phoenix_profiler_test.exs index 6ac9d1d..fdcc7c4 100644 --- a/test/phoenix_profiler_test.exs +++ b/test/phoenix_profiler_test.exs @@ -53,7 +53,7 @@ defmodule PhoenixProfilerUnitTest do test "returns {:error, :profiler_not_available} when the profiler is not defined on the endpoint" do assert NoConfigEndpoint |> build_conn() - |> PhoenixProfiler.Configurator.configure() == {:error, :profiler_not_available} + |> PhoenixProfiler.Profiler.configure() == {:error, :profiler_not_available} end test "raises when the profiler is not running" do @@ -62,7 +62,7 @@ defmodule PhoenixProfilerUnitTest do fn -> EndpointMock |> build_conn() - |> PhoenixProfiler.Configurator.configure() + |> PhoenixProfiler.Profiler.configure() end end @@ -77,7 +77,7 @@ defmodule PhoenixProfilerUnitTest do assert {:ok, conn} = conn |> PhoenixProfiler.Utils.put_private(:phoenix_endpoint, EndpointMock) - |> PhoenixProfiler.Configurator.configure() + |> PhoenixProfiler.Profiler.configure() assert {:enable, collector_pid} = PhoenixProfiler.Utils.collector_info(profiler_name, conn) @@ -90,7 +90,7 @@ defmodule PhoenixProfilerUnitTest do assert_raise RuntimeError, ~r/attempted to configure a profiler on the given socket, but it is disconnected/, fn -> - PhoenixProfiler.Configurator.configure(build_socket()) + PhoenixProfiler.Profiler.configure(build_socket()) end end @@ -98,14 +98,14 @@ defmodule PhoenixProfilerUnitTest do assert build_socket() |> Map.put(:endpoint, NoConfigEndpoint) |> connect() - |> PhoenixProfiler.Configurator.configure() == {:error, :profiler_not_available} + |> PhoenixProfiler.Profiler.configure() == {:error, :profiler_not_available} end test "raises when the profiler is not running" do assert_raise RuntimeError, ~r/attempted to configure a profiler on the given socket, but the profiler is not running/, fn -> - build_socket() |> connect() |> PhoenixProfiler.Configurator.configure() + build_socket() |> connect() |> PhoenixProfiler.Profiler.configure() end end @@ -116,7 +116,7 @@ defmodule PhoenixProfilerUnitTest do assert PhoenixProfiler.Utils.collector_info(profiler_name, socket) == :error - assert {:ok, socket} = PhoenixProfiler.Configurator.configure(socket) + assert {:ok, socket} = PhoenixProfiler.Profiler.configure(socket) assert PhoenixProfiler.Utils.collector_info(profiler_name, socket) == :error end @@ -131,7 +131,7 @@ defmodule PhoenixProfilerUnitTest do assert PhoenixProfiler.Utils.collector_info(profiler, conn) == :error - {:ok, conn} = PhoenixProfiler.Configurator.configure(conn) + {:ok, conn} = PhoenixProfiler.Profiler.configure(conn) assert {:enable, _pid} = PhoenixProfiler.Utils.collector_info(profiler, conn) conn = PhoenixProfiler.disable(conn) @@ -144,7 +144,7 @@ defmodule PhoenixProfilerUnitTest do socket = build_socket() |> connect() assert PhoenixProfiler.Utils.collector_info(profiler, socket) == :error - {:ok, socket} = PhoenixProfiler.Configurator.configure(socket) + {:ok, socket} = PhoenixProfiler.Profiler.configure(socket) {:ok, pid} = PhoenixProfiler.TelemetryServer.listen( From d9fccc6c766d0def46b28280a42895fa4e92f87b Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Fri, 14 Jan 2022 14:10:39 -0800 Subject: [PATCH 05/38] WIP: Add profiler Endpoint --- README.md | 14 +++-- lib/phoenix_profiler/endpoint.ex | 100 +++++++++++++++++++++++++++++++ 2 files changed, 108 insertions(+), 6 deletions(-) create mode 100644 lib/phoenix_profiler/endpoint.ex diff --git a/README.md b/README.md index 160af70..370a9c8 100644 --- a/README.md +++ b/README.md @@ -27,7 +27,7 @@ To start using the profiler, you will need the following steps: 2. Define a profiler on your supervision tree 3. Enable the profiler on your Endpoint 4. Configure LiveView -5. Add the `PhoenixProfiler` plug +5. Use `PhoenixProfiler.Endpoint` 6. Mount the profiler on your LiveViews 7. Add the profiler page on your LiveDashboard (optional) @@ -106,15 +106,17 @@ config :my_app, MyAppWeb.Endpoint, live_view: [signing_salt: "SECRET_SALT"] ``` -### 5. Add the PhoenixProfiler plug +### 5. Use PhoenixProfiler.Endpoint -Add the `PhoenixProfiler` plug within the `code_reloading?` -block on your Endpoint (usually in `lib/my_app_web/endpoint.ex`): +Add `use PhoenixProfiler.Endpoint` to your Endpoint +(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.Endpoint + # plugs... - plug PhoenixProfiler end ``` diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex new file mode 100644 index 0000000..9d02166 --- /dev/null +++ b/lib/phoenix_profiler/endpoint.ex @@ -0,0 +1,100 @@ +defmodule PhoenixProfiler.Endpoint do + @moduledoc false + + 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 false + defmacro __before_compile__(%{module: _module}) do + quote do + defoverridable call: 2 + + def call(conn, opts) do + start_time = System.monotonic_time() + + try do + conn + |> PhoenixProfiler.Endpoint.__prologue__(__MODULE__) + |> super(opts) + |> PhoenixProfiler.Endpoint.__epilogue__(start_time) + rescue + # todo: rescue any profiler errors and handle them appropriately. + e in Plug.Conn.WrapperError -> + %{conn: conn, kind: kind, reason: reason, stack: stack} = e + PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, config, start_time) + catch + kind, reason -> + stack = __STACKTRACE__ + PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, config, start_time) + end + end + end + end + + def __prologue__(conn, endpoint) do + config = endpoint.config(:phoenix_profiler) + + if config do + conn = PhoenixProfiler.Utils.configure_profile(conn, endpoint, config, System.system_time()) + telemetry_execute(:start, %{system_time: System.system_time()}, %{conn: conn}) + conn + else + conn + end + end + + @doc false + def __catch__(conn, kind, reason, stack, config, start_time) do + __epilogue__(conn, kind, reason, stack, config, start_time) + :erlang.raise(kind, reason, stack) + end + + @doc false + # todo: this should be all be handled in telemetry events (aka not special)) + # - late collect (this can be its *own* telemetry event) + # - compile/persist the profile (built-in data collector than runs last?) + def __epilogue__(conn, start_time) do + if profile = conn.private[:phoenix_profiler] do + telemetry_execute(:stop, %{duration: duration(start_time)}, %{ + conn: conn, + profile: profile + }) + + conn + else + conn + end + end + + def __epilogue__(conn, start_time, kind, reason, stack, _config) do + if profile = conn.private[:phoenix_profiler] do + telemetry_execute(:exception, %{duration: duration(start_time)}, %{ + conn: conn, + profile: profile, + kind: kind, + reason: reason, + stacktrace: stack + }) + end + 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 +end From 4cd967aea3fca5baf9afb24dee5176332e645c18 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 00:50:27 -0800 Subject: [PATCH 06/38] profile thru endpoint --- dev.exs | 3 +- lib/phoenix_profiler.ex | 8 ----- lib/phoenix_profiler/endpoint.ex | 46 ++++++++++++++++++----------- lib/phoenix_profiler/plug.ex | 17 +++++------ lib/phoenix_profiler/profiler.ex | 8 ++--- test/phoenix_profiler/plug_test.exs | 39 +++++++++++++++--------- test/test_helper.exs | 5 +++- 7 files changed, 70 insertions(+), 56 deletions(-) diff --git a/dev.exs b/dev.exs index 42ecf2e..4e7f5e8 100644 --- a/dev.exs +++ b/dev.exs @@ -322,8 +322,7 @@ end defmodule DemoWeb.Endpoint do use Phoenix.Endpoint, otp_app: :phoenix_profiler - - plug PhoenixProfiler + use PhoenixProfiler.Endpoint @session_options [ store: :cookie, diff --git a/lib/phoenix_profiler.ex b/lib/phoenix_profiler.ex index 622f2b5..c95b1f7 100644 --- a/lib/phoenix_profiler.ex +++ b/lib/phoenix_profiler.ex @@ -16,14 +16,6 @@ defmodule PhoenixProfiler do } 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 diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex index 9d02166..e60abe2 100644 --- a/lib/phoenix_profiler/endpoint.ex +++ b/lib/phoenix_profiler/endpoint.ex @@ -33,31 +33,30 @@ defmodule PhoenixProfiler.Endpoint do # todo: rescue any profiler errors and handle them appropriately. e in Plug.Conn.WrapperError -> %{conn: conn, kind: kind, reason: reason, stack: stack} = e - PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, config, start_time) + PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, start_time) catch kind, reason -> stack = __STACKTRACE__ - PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, config, start_time) + PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, start_time) end end end end def __prologue__(conn, endpoint) do - config = endpoint.config(:phoenix_profiler) + case PhoenixProfiler.Profiler.configure(conn, endpoint) do + {:ok, conn} -> + telemetry_execute(:start, %{system_time: System.system_time()}, %{conn: conn}) + conn - if config do - conn = PhoenixProfiler.Utils.configure_profile(conn, endpoint, config, System.system_time()) - telemetry_execute(:start, %{system_time: System.system_time()}, %{conn: conn}) - conn - else - conn + {:error, :profiler_not_available} -> + conn end end @doc false - def __catch__(conn, kind, reason, stack, config, start_time) do - __epilogue__(conn, kind, reason, stack, config, start_time) + def __catch__(conn, kind, reason, stack, start_time) do + __epilogue__(conn, start_time, kind, reason, stack) :erlang.raise(kind, reason, stack) end @@ -66,27 +65,29 @@ defmodule PhoenixProfiler.Endpoint do # - late collect (this can be its *own* telemetry event) # - compile/persist the profile (built-in data collector than runs last?) def __epilogue__(conn, start_time) do - if profile = conn.private[:phoenix_profiler] do + if profiler = conn.private[:phoenix_profiler] do telemetry_execute(:stop, %{duration: duration(start_time)}, %{ conn: conn, - profile: profile + profiler: profiler }) - conn + late_collect(conn) else conn end end - def __epilogue__(conn, start_time, kind, reason, stack, _config) do - if profile = conn.private[:phoenix_profiler] do + def __epilogue__(conn, start_time, kind, reason, stack) do + if profiler = conn.private[:phoenix_profiler] do telemetry_execute(:exception, %{duration: duration(start_time)}, %{ conn: conn, - profile: profile, + profiler: profiler, kind: kind, reason: reason, stacktrace: stack }) + + late_collect(conn, {kind, stack, reason}) end end @@ -97,4 +98,15 @@ defmodule PhoenixProfiler.Endpoint do defp duration(start_time) when is_integer(start_time) do System.monotonic_time() - start_time end + + defp late_collect(conn, _error \\ nil) do + case PhoenixProfiler.Profiler.collect(conn) 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 56ab27a..8da2118 100644 --- a/lib/phoenix_profiler/plug.ex +++ b/lib/phoenix_profiler/plug.ex @@ -5,31 +5,28 @@ 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 start_time = System.monotonic_time() - case PhoenixProfiler.Profiler.configure(conn) do - {:ok, conn} -> + case conn.private do + %{phoenix_profiler: profiler} when is_atom(profiler) -> conn |> telemetry_execute(:start, %{system_time: System.system_time()}) |> before_send_profile(endpoint, [], start_time) - {:error, :profiler_not_available} -> + _ -> conn end end diff --git a/lib/phoenix_profiler/profiler.ex b/lib/phoenix_profiler/profiler.ex index f7a7583..635671f 100644 --- a/lib/phoenix_profiler/profiler.ex +++ b/lib/phoenix_profiler/profiler.ex @@ -89,8 +89,8 @@ defmodule PhoenixProfiler.Profiler do @doc """ Configures profiling for a given `conn` or `socket`. """ - def configure(conn_or_socket) do - case apply_profiler_info(conn_or_socket) do + def configure(conn_or_socket, endpoint \\ nil) do + case apply_profiler_info(conn_or_socket, endpoint) do {:ok, conn_or_socket} -> {:ok, conn_or_socket} @@ -129,8 +129,8 @@ defmodule PhoenixProfiler.Profiler do Utils.put_private(conn_or_socket, :phoenix_profiler_info, action) end - defp apply_profiler_info(conn_or_socket) do - endpoint = Utils.endpoint(conn_or_socket) + defp apply_profiler_info(conn_or_socket, endpoint) do + endpoint = endpoint || Utils.endpoint(conn_or_socket) with {:ok, config} <- Utils.check_configuration(endpoint), :ok <- maybe_check_socket_connection(conn_or_socket), diff --git a/test/phoenix_profiler/plug_test.exs b/test/phoenix_profiler/plug_test.exs index 159187a..51586ba 100644 --- a/test/phoenix_profiler/plug_test.exs +++ b/test/phoenix_profiler/plug_test.exs @@ -5,19 +5,27 @@ defmodule PhoenixProfiler.PlugTest do @token_header_key "x-debug-token" @profiler_header_key "x-debug-token-link" - defp conn(path) do :get |> conn(path) |> put_private(:phoenix_endpoint, PhoenixProfilerTest.Endpoint) + + conn(:get, path) + end + + defp profile_thru(conn, endpoint) do + conn = put_private(conn, :phoenix_endpoint, endpoint) + {:ok, conn} = PhoenixProfiler.Profiler.configure(conn) + conn end test "injects debug token headers if configured" do - opts = PhoenixProfiler.init([]) + opts = PhoenixProfiler.Plug.init([]) conn = conn("/") - |> PhoenixProfiler.call(opts) + |> profile_thru(PhoenixProfilerTest.Endpoint) + |> PhoenixProfiler.Plug.call(opts) |> send_resp(200, "") assert [token] = Plug.Conn.get_resp_header(conn, @token_header_key) @@ -28,12 +36,12 @@ defmodule PhoenixProfiler.PlugTest do end test "skips debug token when disabled at the Endpoint" do - opts = PhoenixProfiler.init([]) + opts = PhoenixProfiler.Plug.init([]) conn = conn("/") - |> put_private(:phoenix_endpoint, PhoenixProfilerTest.EndpointDisabled) - |> PhoenixProfiler.call(opts) + |> profile_thru(PhoenixProfilerTest.EndpointDisabled) + |> PhoenixProfiler.Plug.call(opts) |> send_resp(200, "") assert get_resp_header(conn, @token_header_key) == [] @@ -41,12 +49,13 @@ defmodule PhoenixProfiler.PlugTest do end test "injects debug toolbar for html requests if configured and contains the tag" do - opts = PhoenixProfiler.init([]) + opts = PhoenixProfiler.Plug.init([]) conn = conn("/") + |> profile_thru(PhoenixProfilerTest.Endpoint) |> put_resp_content_type("text/html") - |> PhoenixProfiler.call(opts) + |> PhoenixProfiler.Plug.call(opts) |> send_resp(200, "

PhoenixProfiler

") assert [token] = get_resp_header(conn, @token_header_key) @@ -56,13 +65,13 @@ defmodule PhoenixProfiler.PlugTest do end test "skips debug toolbar injection when disabled at the Endpoint" do - opts = PhoenixProfiler.init([]) + opts = PhoenixProfiler.Plug.init([]) conn = conn("/") |> put_private(:phoenix_endpoint, PhoenixProfilerTest.EndpointDisabled) |> put_resp_content_type("text/html") - |> PhoenixProfiler.call(opts) + |> PhoenixProfiler.Plug.call(opts) |> send_resp(200, "

PhoenixProfiler

") assert get_resp_header(conn, @token_header_key) == [] @@ -71,24 +80,26 @@ defmodule PhoenixProfiler.PlugTest do end test "skips toolbar injection if html response is missing the body tag" do - opts = PhoenixProfiler.init([]) + opts = PhoenixProfiler.Plug.init([]) conn = conn("/") + |> profile_thru(PhoenixProfilerTest.Endpoint) |> put_resp_content_type("text/html") - |> PhoenixProfiler.call(opts) + |> PhoenixProfiler.Plug.call(opts) |> send_resp(200, "

PhoenixProfiler

") assert to_string(conn.resp_body) == "

PhoenixProfiler

" end test "skips toolbar injection if not an html request" do - opts = PhoenixProfiler.init([]) + opts = PhoenixProfiler.Plug.init([]) conn = conn("/") + |> profile_thru(PhoenixProfilerTest.Endpoint) |> put_resp_content_type("application/json") - |> PhoenixProfiler.call(opts) + |> PhoenixProfiler.Plug.call(opts) |> send_resp(200, "") assert [token] = get_resp_header(conn, @token_header_key) diff --git a/test/test_helper.exs b/test/test_helper.exs index 5e8a509..219d3ad 100644 --- a/test/test_helper.exs +++ b/test/test_helper.exs @@ -107,8 +107,8 @@ end defmodule PhoenixProfilerTest.Endpoint do use Phoenix.Endpoint, otp_app: :phoenix_profiler + use PhoenixProfiler.Endpoint - plug PhoenixProfiler plug Plug.Telemetry, event_prefix: [:phoenix, :endpoint] plug Plug.Session, @@ -121,6 +121,9 @@ end defmodule PhoenixProfilerTest.EndpointDisabled do use Phoenix.Endpoint, otp_app: :phoenix_profiler + use PhoenixProfiler.Endpoint + + plug Plug.Telemetry, event_prefix: [:phoenix, :endpoint] end defmodule PhoenixProfilerTest.EndpointNotConfigured do From aaddcc696864464087270b438933ae8e22b90a1e Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 00:51:11 -0800 Subject: [PATCH 07/38] Clarify endpoint config --- README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 370a9c8..ab202f3 100644 --- a/README.md +++ b/README.md @@ -25,7 +25,7 @@ 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 +3. Enable the profiler on your Endpoint config 4. Configure LiveView 5. Use `PhoenixProfiler.Endpoint` 6. Mount the profiler on your LiveViews @@ -63,7 +63,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 the 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 From d2dd397a1fb338faf5b030bf37ee686c9546ea0a Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 11:02:32 -0800 Subject: [PATCH 08/38] docs --- lib/phoenix_profiler/endpoint.ex | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex index e60abe2..85b622c 100644 --- a/lib/phoenix_profiler/endpoint.ex +++ b/lib/phoenix_profiler/endpoint.ex @@ -1,5 +1,7 @@ defmodule PhoenixProfiler.Endpoint do - @moduledoc false + @moduledoc """ + Provides profiling on an [`Endpoint`](`Phoenix.Endpoint`). + """ defmacro __using__(_) do quote do @@ -61,9 +63,6 @@ defmodule PhoenixProfiler.Endpoint do end @doc false - # todo: this should be all be handled in telemetry events (aka not special)) - # - late collect (this can be its *own* telemetry event) - # - compile/persist the profile (built-in data collector than runs last?) def __epilogue__(conn, start_time) do if profiler = conn.private[:phoenix_profiler] do telemetry_execute(:stop, %{duration: duration(start_time)}, %{ From fb43de4c45d2c0e13e97224fe2353f9f2b1feb07 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 11:57:25 -0800 Subject: [PATCH 09/38] docs --- README.md | 14 ++++++-------- 1 file changed, 6 insertions(+), 8 deletions(-) diff --git a/README.md b/README.md index ab202f3..4671405 100644 --- a/README.md +++ b/README.md @@ -27,7 +27,7 @@ To start using the profiler, you will need the following steps: 2. Define a profiler on your supervision tree 3. Enable the profiler on your Endpoint config 4. Configure LiveView -5. Use `PhoenixProfiler.Endpoint` +5. Use `PhoenixProfiler.Endpoint` on your Endpoint module 6. Mount the profiler on your LiveViews 7. Add the profiler page on your LiveDashboard (optional) @@ -41,20 +41,18 @@ Add phoenix_profiler to your `mix.exs`: ### 2. Define a profiler on your supervision tree -You define a profiler on your main application's supervision -tree (usually in `lib/my_app/application.ex`): +You define a profiler on your main application's telemetry supervision +tree (usually in `lib/my_app_web/telemetry.ex`): ```elixir children = [ {PhoenixProfiler, name: MyAppWeb.Profiler}, - # MyApp.Repo - # MyAppWeb.Endpoint, - # etc... + # :telemetry_poller, etc. ] ``` Note that the profiler must be running for data to be collected, -so it must come before any endpoints in your supervision tree. +so it must come before any Endpoint modules in your supervision tree. The following options are available: @@ -108,7 +106,7 @@ config :my_app, MyAppWeb.Endpoint, ### 5. Use PhoenixProfiler.Endpoint -Add `use PhoenixProfiler.Endpoint` to your Endpoint +Add `use PhoenixProfiler.Endpoint` on your Endpoint module (usually in `lib/my_app_web/endpoint.ex`): ```elixir From eac19148d1964fc7c754cf1cff4605ac018e4e37 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 12:01:41 -0800 Subject: [PATCH 10/38] remove unused key --- lib/phoenix_profiler/profile.ex | 2 -- 1 file changed, 2 deletions(-) diff --git a/lib/phoenix_profiler/profile.ex b/lib/phoenix_profiler/profile.ex index c2cd938..c6652d7 100644 --- a/lib/phoenix_profiler/profile.ex +++ b/lib/phoenix_profiler/profile.ex @@ -2,7 +2,6 @@ defmodule PhoenixProfiler.Profile do # An internal data structure for a request profile. @moduledoc false defstruct [ - :collector_pid, :data, :node, :server, @@ -21,7 +20,6 @@ defmodule PhoenixProfiler.Profile do } @type t :: %__MODULE__{ - :collector_pid => nil | pid(), :data => map(), :token => String.t(), :server => module(), From b0ff21d69444fdc11b23f8527b9bea2999613a52 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 13:08:28 -0800 Subject: [PATCH 11/38] use PhoenixProfiler --- README.md | 6 +++--- dev.exs | 2 +- lib/phoenix_profiler.ex | 15 +++++++++++++++ lib/phoenix_profiler/endpoint.ex | 23 ++--------------------- test/test_helper.exs | 4 ++-- 5 files changed, 23 insertions(+), 27 deletions(-) diff --git a/README.md b/README.md index 4671405..4174207 100644 --- a/README.md +++ b/README.md @@ -27,7 +27,7 @@ To start using the profiler, you will need the following steps: 2. Define a profiler on your supervision tree 3. Enable the profiler on your Endpoint config 4. Configure LiveView -5. Use `PhoenixProfiler.Endpoint` on your Endpoint module +5. Use `PhoenixProfiler` on your Endpoint module 6. Mount the profiler on your LiveViews 7. Add the profiler page on your LiveDashboard (optional) @@ -106,13 +106,13 @@ config :my_app, MyAppWeb.Endpoint, ### 5. Use PhoenixProfiler.Endpoint -Add `use PhoenixProfiler.Endpoint` on your Endpoint module +Add `use PhoenixProfiler` on your Endpoint module (usually in `lib/my_app_web/endpoint.ex`): ```elixir defmodule MyAppWeb.Endpoint do use Phoenix.Endpoint, otp_app: :my_app - use PhoenixProfiler.Endpoint + use PhoenixProfiler # plugs... end diff --git a/dev.exs b/dev.exs index 4e7f5e8..ff7f2d7 100644 --- a/dev.exs +++ b/dev.exs @@ -322,7 +322,7 @@ end defmodule DemoWeb.Endpoint do use Phoenix.Endpoint, otp_app: :phoenix_profiler - use PhoenixProfiler.Endpoint + use PhoenixProfiler @session_options [ store: :cookie, diff --git a/lib/phoenix_profiler.ex b/lib/phoenix_profiler.ex index c95b1f7..4193c6e 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. diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex index 85b622c..607d89c 100644 --- a/lib/phoenix_profiler/endpoint.ex +++ b/lib/phoenix_profiler/endpoint.ex @@ -1,24 +1,7 @@ defmodule PhoenixProfiler.Endpoint do - @moduledoc """ - Provides profiling on an [`Endpoint`](`Phoenix.Endpoint`). - """ + # Overrides Phoenix.Endpoint.call/2 for profiling. + @moduledoc false - 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 false defmacro __before_compile__(%{module: _module}) do quote do defoverridable call: 2 @@ -56,13 +39,11 @@ defmodule PhoenixProfiler.Endpoint do end end - @doc false def __catch__(conn, kind, reason, stack, start_time) do __epilogue__(conn, start_time, kind, reason, stack) :erlang.raise(kind, reason, stack) end - @doc false def __epilogue__(conn, start_time) do if profiler = conn.private[:phoenix_profiler] do telemetry_execute(:stop, %{duration: duration(start_time)}, %{ diff --git a/test/test_helper.exs b/test/test_helper.exs index 219d3ad..ce0dd62 100644 --- a/test/test_helper.exs +++ b/test/test_helper.exs @@ -107,7 +107,7 @@ end defmodule PhoenixProfilerTest.Endpoint do use Phoenix.Endpoint, otp_app: :phoenix_profiler - use PhoenixProfiler.Endpoint + use PhoenixProfiler plug Plug.Telemetry, event_prefix: [:phoenix, :endpoint] @@ -121,7 +121,7 @@ end defmodule PhoenixProfilerTest.EndpointDisabled do use Phoenix.Endpoint, otp_app: :phoenix_profiler - use PhoenixProfiler.Endpoint + use PhoenixProfiler plug Plug.Telemetry, event_prefix: [:phoenix, :endpoint] end From a595d16e2057a44512117ed768f055dd82d67205 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 13:33:30 -0800 Subject: [PATCH 12/38] docs --- README.md | 20 ++++++++++---------- lib/phoenix_profiler.ex | 40 +++++++++++++++------------------------- 2 files changed, 25 insertions(+), 35 deletions(-) diff --git a/README.md b/README.md index 4174207..dafd9a0 100644 --- a/README.md +++ b/README.md @@ -24,8 +24,8 @@ 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 config +2. Define a profiler server on your supervision tree +3. Enable your profiler on your Endpoint config 4. Configure LiveView 5. Use `PhoenixProfiler` on your Endpoint module 6. Mount the profiler on your LiveViews @@ -39,10 +39,10 @@ Add phoenix_profiler to your `mix.exs`: {:phoenix_profiler, "~> 0.1.0", github: "mcrumm/phoenix_profiler"} ``` -### 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 config +### 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,7 +104,7 @@ config :my_app, MyAppWeb.Endpoint, live_view: [signing_salt: "SECRET_SALT"] ``` -### 5. Use PhoenixProfiler.Endpoint +### 5. Use PhoenixProfiler Add `use PhoenixProfiler` on your Endpoint module (usually in `lib/my_app_web/endpoint.ex`): @@ -118,12 +118,12 @@ Add `use PhoenixProfiler` on your Endpoint module 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/lib/phoenix_profiler.ex b/lib/phoenix_profiler.ex index 4193c6e..611a412 100644 --- a/lib/phoenix_profiler.ex +++ b/lib/phoenix_profiler.ex @@ -52,34 +52,27 @@ defmodule PhoenixProfiler do @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 @@ -91,26 +84,23 @@ defmodule PhoenixProfiler do ## 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.Profiler From 321c0c141292567ed131358e33e67659c49df6e6 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 14:04:43 -0800 Subject: [PATCH 13/38] Fix dashboard --- lib/phoenix_profiler/dashboard.ex | 7 ++++--- lib/phoenix_profiler/profile_store.ex | 6 +++++- 2 files changed, 9 insertions(+), 4 deletions(-) diff --git a/lib/phoenix_profiler/dashboard.ex b/lib/phoenix_profiler/dashboard.ex index 44628f1..a54c4b8 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: [ @@ -300,8 +301,8 @@ if Code.ensure_loaded?(Phoenix.LiveDashboard) do {profiles, total} = fetch_profiles(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: at} = profile conn |> Map.take([:host, :status, :method, :remote_ip]) diff --git a/lib/phoenix_profiler/profile_store.ex b/lib/phoenix_profiler/profile_store.ex index 6fe392a..9e92c47 100644 --- a/lib/phoenix_profiler/profile_store.ex +++ b/lib/phoenix_profiler/profile_store.ex @@ -99,8 +99,12 @@ defmodule PhoenixProfiler.ProfileStore do @doc """ Returns a filtered list of profiles. """ + def list_advanced(profiler, _search, :at, sort_dir, _limit) do + Utils.sort_by(list(profiler), fn {_, %Profile{system_time: at}} -> at end, sort_dir) + end + def list_advanced(profiler, _search, sort_by, sort_dir, _limit) do - Utils.sort_by(list(profiler), fn {_, profile} -> profile[sort_by] end, sort_dir) + Utils.sort_by(list(profiler), fn {_, %Profile{data: data}} -> data[sort_by] end, sort_dir) end @doc """ From a1197b3a24f03e930926abbf8f8c41cb4072e661 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 14:15:59 -0800 Subject: [PATCH 14/38] Apply limit to dashboard profile list --- lib/phoenix_profiler/dashboard.ex | 10 ++-------- lib/phoenix_profiler/profile_store.ex | 13 +++++++++---- 2 files changed, 11 insertions(+), 12 deletions(-) diff --git a/lib/phoenix_profiler/dashboard.ex b/lib/phoenix_profiler/dashboard.ex index a54c4b8..005ed45 100644 --- a/lib/phoenix_profiler/dashboard.ex +++ b/lib/phoenix_profiler/dashboard.ex @@ -298,7 +298,8 @@ 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, profile} <- profiles do @@ -314,13 +315,6 @@ if Code.ensure_loaded?(Phoenix.LiveDashboard) do {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 [ %{ diff --git a/lib/phoenix_profiler/profile_store.ex b/lib/phoenix_profiler/profile_store.ex index 9e92c47..5b2e706 100644 --- a/lib/phoenix_profiler/profile_store.ex +++ b/lib/phoenix_profiler/profile_store.ex @@ -99,12 +99,17 @@ defmodule PhoenixProfiler.ProfileStore do @doc """ Returns a filtered list of profiles. """ - def list_advanced(profiler, _search, :at, sort_dir, _limit) do - Utils.sort_by(list(profiler), fn {_, %Profile{system_time: at}} -> at end, sort_dir) + def list_advanced(profiler, _search, :at, sort_dir, limit) do + results = Utils.sort_by(list(profiler), fn {_, %Profile{system_time: at}} -> at end, sort_dir) + + {Enum.take(results, limit), length(results)} end - def list_advanced(profiler, _search, sort_by, sort_dir, _limit) do - Utils.sort_by(list(profiler), fn {_, %Profile{data: data}} -> data[sort_by] end, sort_dir) + def list_advanced(profiler, _search, sort_by, sort_dir, limit) do + results = + Utils.sort_by(list(profiler), fn {_, %Profile{data: data}} -> data[sort_by] end, sort_dir) + + {Enum.take(results, limit), length(results)} end @doc """ From d3dcadd8af041e9c1473768ca1b86b7cd726b8dc Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 14:30:22 -0800 Subject: [PATCH 15/38] dashboard profile time --- lib/phoenix_profiler/dashboard.ex | 11 +++++++---- lib/phoenix_profiler/profile_store.ex | 4 ++-- 2 files changed, 9 insertions(+), 6 deletions(-) diff --git a/lib/phoenix_profiler/dashboard.ex b/lib/phoenix_profiler/dashboard.ex index 005ed45..9986072 100644 --- a/lib/phoenix_profiler/dashboard.ex +++ b/lib/phoenix_profiler/dashboard.ex @@ -303,13 +303,16 @@ if Code.ensure_loaded?(Phoenix.LiveDashboard) do rows = for {token, profile} <- profiles do - %Profile{data: %{conn: %Plug.Conn{} = conn}, system_time: at} = profile + %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} @@ -334,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/profile_store.ex b/lib/phoenix_profiler/profile_store.ex index 5b2e706..a1b1a95 100644 --- a/lib/phoenix_profiler/profile_store.ex +++ b/lib/phoenix_profiler/profile_store.ex @@ -100,14 +100,14 @@ defmodule PhoenixProfiler.ProfileStore do Returns a filtered list of profiles. """ def list_advanced(profiler, _search, :at, sort_dir, limit) do - results = Utils.sort_by(list(profiler), fn {_, %Profile{system_time: at}} -> at end, sort_dir) + 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{data: data}} -> data[sort_by] end, sort_dir) + Utils.sort_by(list(profiler), fn {_, %Profile{} = p} -> p.data[sort_by] end, sort_dir) {Enum.take(results, limit), length(results)} end From 26ec171335443aa03fc74f830999052c66ab07b8 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Sun, 27 Feb 2022 14:30:39 -0800 Subject: [PATCH 16/38] ignore live_reload --- lib/phoenix_profiler/endpoint.ex | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex index 607d89c..0f62042 100644 --- a/lib/phoenix_profiler/endpoint.ex +++ b/lib/phoenix_profiler/endpoint.ex @@ -28,6 +28,11 @@ defmodule PhoenixProfiler.Endpoint do end end + # TODO: remove this clause when we add config for profiler exclude_patterns + def __prologue__(%Plug.Conn{path_info: ["phoenix", "live_reload", "frame" | _suffix]} = conn, _) do + conn + end + def __prologue__(conn, endpoint) do case PhoenixProfiler.Profiler.configure(conn, endpoint) do {:ok, conn} -> From 688982008c30fb8d56f41ae779c27f4b30806d36 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Tue, 1 Mar 2022 09:29:01 -0800 Subject: [PATCH 17/38] endpoint tests --- lib/phoenix_profiler/endpoint.ex | 44 +-- lib/phoenix_profiler/profiler.ex | 47 ++- lib/phoenix_profiler/utils.ex | 15 + mix.exs | 2 +- test/phoenix_profiler/endpoint_test.exs | 58 ++++ .../integration/endpoint_test.exs | 277 ++++++++++++++++++ test/support/endpoint_helper.exs | 49 ++++ test/support/http_client.exs | 75 +++++ test/test_helper.exs | 35 ++- 9 files changed, 541 insertions(+), 61 deletions(-) create mode 100644 test/phoenix_profiler/endpoint_test.exs create mode 100644 test/phoenix_profiler/integration/endpoint_test.exs create mode 100644 test/support/endpoint_helper.exs create mode 100644 test/support/http_client.exs diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex index 0f62042..280befb 100644 --- a/lib/phoenix_profiler/endpoint.ex +++ b/lib/phoenix_profiler/endpoint.ex @@ -6,46 +6,48 @@ defmodule PhoenixProfiler.Endpoint 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() + endpoint = __MODULE__ + config = endpoint.config(:phoenix_profiler) + conn = PhoenixProfiler.Endpoint.__prologue__(conn, endpoint, config) try do conn - |> PhoenixProfiler.Endpoint.__prologue__(__MODULE__) |> super(opts) |> PhoenixProfiler.Endpoint.__epilogue__(start_time) - rescue - # todo: rescue any profiler errors and handle them appropriately. - e in Plug.Conn.WrapperError -> - %{conn: conn, kind: kind, reason: reason, stack: stack} = e - PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, start_time) catch kind, reason -> stack = __STACKTRACE__ - PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, start_time) + PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, config, start_time) end end end end - # TODO: remove this clause when we add config for profiler exclude_patterns - def __prologue__(%Plug.Conn{path_info: ["phoenix", "live_reload", "frame" | _suffix]} = conn, _) do + # Skip profiling if no configuration set on the Endpoint + def __prologue__(conn, _endpoint, nil) do conn end - def __prologue__(conn, endpoint) do - case PhoenixProfiler.Profiler.configure(conn, endpoint) do - {:ok, conn} -> - telemetry_execute(:start, %{system_time: System.system_time()}, %{conn: conn}) - conn - - {:error, :profiler_not_available} -> - conn + def __prologue__(conn, endpoint, config) do + if server = config[:server] do + conn = PhoenixProfiler.Profiler.apply_configuration(conn, endpoint, server, config) + telemetry_execute(:start, %{system_time: System.system_time()}, %{conn: conn}) + conn + else + IO.warn("no profiler server found for endpoint #{inspect(endpoint)}") + conn end end - def __catch__(conn, kind, reason, stack, start_time) do - __epilogue__(conn, start_time, kind, reason, stack) + def __catch__(conn, kind, reason, stack, config, start_time) do + __epilogue__(conn, kind, reason, stack, config, start_time) :erlang.raise(kind, reason, stack) end @@ -62,7 +64,7 @@ defmodule PhoenixProfiler.Endpoint do end end - def __epilogue__(conn, start_time, kind, reason, stack) do + def __epilogue__(conn, kind, reason, stack, _config, start_time) do if profiler = conn.private[:phoenix_profiler] do telemetry_execute(:exception, %{duration: duration(start_time)}, %{ conn: conn, @@ -72,7 +74,7 @@ defmodule PhoenixProfiler.Endpoint do stacktrace: stack }) - late_collect(conn, {kind, stack, reason}) + late_collect(conn, {kind, reason, stack}) end end diff --git a/lib/phoenix_profiler/profiler.ex b/lib/phoenix_profiler/profiler.ex index 635671f..66cc9aa 100644 --- a/lib/phoenix_profiler/profiler.ex +++ b/lib/phoenix_profiler/profiler.ex @@ -8,26 +8,13 @@ defmodule PhoenixProfiler.Profiler do alias PhoenixProfiler.TelemetryServer alias PhoenixProfiler.Utils - @default_profiler_link_base "/dashboard/_profiler" - @doc """ Builds a profile from data collected for a given `conn`. """ def collect(%Plug.Conn{} = conn) do - endpoint = conn.private.phoenix_endpoint - config = endpoint.config(:phoenix_profiler) - - link_base = - case Keyword.fetch(config, :profiler_link_base) do - {:ok, path} when is_binary(path) and path != "" -> - "/" <> String.trim_leading(path, "/") - - _ -> - @default_profiler_link_base - end - if conn.private.phoenix_profiler_info == :enable do time = System.system_time() + profiler_base_url = conn.private.phoenix_profiler_base_url data = PhoenixProfiler.TelemetryCollector.reduce( @@ -47,8 +34,6 @@ defmodule PhoenixProfiler.Profiler do end ) - profiler_base_url = endpoint.url() <> link_base - profile = Profile.new( conn.private.phoenix_profiler, @@ -90,7 +75,7 @@ defmodule PhoenixProfiler.Profiler do Configures profiling for a given `conn` or `socket`. """ def configure(conn_or_socket, endpoint \\ nil) do - case apply_profiler_info(conn_or_socket, endpoint) do + case validate_apply_configuration(conn_or_socket, endpoint) do {:ok, conn_or_socket} -> {:ok, conn_or_socket} @@ -129,19 +114,26 @@ defmodule PhoenixProfiler.Profiler do Utils.put_private(conn_or_socket, :phoenix_profiler_info, action) end - defp apply_profiler_info(conn_or_socket, endpoint) do + def apply_configuration(conn_or_socket, endpoint, server, config) + when is_atom(endpoint) and is_atom(server) do + info = if config[:enable] == false, do: :disable, else: :enable + base_url = endpoint.url() <> Utils.profile_base_path(config) + {:ok, collector_pid} = start_collector(conn_or_socket, server, info) + + conn_or_socket + |> Utils.put_private(:phoenix_profiler, server) + |> Utils.put_private(:phoenix_profiler_base_url, base_url) + |> Utils.put_private(:phoenix_profiler_collector, collector_pid) + |> Utils.put_private(:phoenix_profiler_info, info) + end + + defp validate_apply_configuration(conn_or_socket, endpoint) do endpoint = endpoint || Utils.endpoint(conn_or_socket) with {:ok, config} <- Utils.check_configuration(endpoint), :ok <- maybe_check_socket_connection(conn_or_socket), - {:ok, profiler} <- check_profiler_running(config), - info = if(config[:enable] == false, do: :disable, else: :enable), - {:ok, collector_pid} <- start_collector(conn_or_socket, profiler, info) do - {:ok, - conn_or_socket - |> Utils.put_private(:phoenix_profiler, profiler) - |> Utils.put_private(:phoenix_profiler_collector, collector_pid) - |> Utils.put_private(:phoenix_profiler_info, info)} + {:ok, profiler} <- check_profiler_running(config) do + {:ok, apply_configuration(conn_or_socket, endpoint, profiler, config)} end end @@ -166,6 +158,9 @@ defmodule PhoenixProfiler.Profiler do end end + # We do not start a collector for a LiveView Socket– + # ToolbarLive will register itself as a collector for its + # Socket's transport_pid. defp start_collector(%LiveView.Socket{}, _, _) do {:ok, nil} end diff --git a/lib/phoenix_profiler/utils.ex b/lib/phoenix_profiler/utils.ex index e46b676..ffd5595 100644 --- a/lib/phoenix_profiler/utils.ex +++ b/lib/phoenix_profiler/utils.ex @@ -2,6 +2,8 @@ defmodule PhoenixProfiler.Utils do @moduledoc false alias Phoenix.LiveView + @default_profiler_base_path "/dashboard/_profiler" + @doc """ Mounts the profiler on a connected LiveView socket only if it is enabled on the Endpoint. @@ -15,6 +17,19 @@ defmodule PhoenixProfiler.Utils do end end + @doc """ + Returns the base path for profile links. + """ + def profile_base_path(config) do + case Keyword.fetch(config, :profiler_link_base) do + {:ok, path} when is_binary(path) and path != "" -> + "/" <> String.trim_leading(path, "/") + + _ -> + @default_profiler_base_path + end + end + @doc """ Returns info for `server` about the registered collector for a given `conn` or `socket`. diff --git a/mix.exs b/mix.exs index 6ee0215..280c507 100644 --- a/mix.exs +++ b/mix.exs @@ -43,7 +43,7 @@ defmodule PhoenixProfiler.MixProject do {:phoenix_live_view, "~> 0.17.0 or ~> 0.16.0 or ~> 0.15.0 or ~> 0.14.3"}, {:phoenix_live_dashboard, "~> 0.6.0 or ~> 0.5.0 or ~> 0.4.0 or ~> 0.3.0", optional: true}, {:phoenix_live_reload, "~> 1.3", only: :dev}, - {:plug_cowboy, "~> 2.0", only: :dev}, + {:plug_cowboy, "~> 2.0", only: [:dev, :test]}, {:jason, "~> 1.0", only: [:dev, :test, :docs]}, {:ex_doc, "~> 0.25", only: :docs}, {:esbuild, "~> 0.2", runtime: false}, diff --git a/test/phoenix_profiler/endpoint_test.exs b/test/phoenix_profiler/endpoint_test.exs new file mode 100644 index 0000000..fd99c21 --- /dev/null +++ b/test/phoenix_profiler/endpoint_test.exs @@ -0,0 +1,58 @@ +defmodule PhoenixProfiler.EndpointTest do + use ExUnit.Case, async: true + use Plug.Test + alias __MODULE__.Profiler + + Application.put_env(:phoenix_profiler, __MODULE__.Endpoint, + url: [host: "example.com"], + server: false, + http: [port: 80], + https: [port: 443], + phoenix_profiler: [server: Profiler] + ) + + defmodule Endpoint do + use Phoenix.Endpoint, otp_app: :phoenix_profiler + use PhoenixProfiler + end + + Application.put_env(:phoenix_profiler, __MODULE__.NoProfilerServerEndpoint, phoenix_profiler: []) + + defmodule NoProfilerServerEndpoint do + use Phoenix.Endpoint, otp_app: :phoenix_profiler + use PhoenixProfiler + end + + setup_all do + start_supervised!({PhoenixProfiler, name: Profiler}) + ExUnit.CaptureLog.capture_log(fn -> start_supervised!(Endpoint) end) + :ok + end + + test "warns if there is no server on the profiler configuration" do + start_supervised!(NoProfilerServerEndpoint) + + assert ExUnit.CaptureIO.capture_io(:stderr, fn -> + conn = conn(:get, "/") + NoProfilerServerEndpoint.call(conn, []) + end) =~ "no profiler server" + end + + test "puts profiler info on conn" do + conn = Endpoint.call(conn(:get, "/"), []) + assert conn.private.phoenix_profiler == Profiler + assert conn.private.phoenix_profiler_base_url == "https://example.com/dashboard/_profiler" + assert is_pid(conn.private.phoenix_profiler_collector) + assert conn.private.phoenix_profiler_info == :enable + end + + test "skips profiling live_reload frame" do + for path <- ["/phoenix/live_reload/frame", "/phoenix/live_reload/frame/suffix"] do + conn = Endpoint.call(conn(:get, path), []) + refute Map.has_key?(conn.private, :phoenix_profiler) + refute Map.has_key?(conn.private, :phoenix_profiler_base_url) + refute Map.has_key?(conn.private, :phoenix_profiler_collector) + refute Map.has_key?(conn.private, :phoenix_profiler_info) + end + end +end diff --git a/test/phoenix_profiler/integration/endpoint_test.exs b/test/phoenix_profiler/integration/endpoint_test.exs new file mode 100644 index 0000000..9cf79eb --- /dev/null +++ b/test/phoenix_profiler/integration/endpoint_test.exs @@ -0,0 +1,277 @@ +Code.require_file("../../support/endpoint_helper.exs", __DIR__) +Code.require_file("../../support/http_client.exs", __DIR__) + +defmodule PhoenixProfiler.Integration.EndpointTest do + use ExUnit.Case, async: true + import ExUnit.CaptureLog + + import PhoenixProfiler.Integration.EndpointHelper + + alias __MODULE__.DebugEndpoint + alias __MODULE__.DisabledEndpoint + alias __MODULE__.EnabledEndpoint + alias __MODULE__.NotConfiguredEndpoint + alias __MODULE__.Profiler + + [debug, disabled, enabled, noconf] = get_unused_port_numbers(4) + @debug debug + @disabled disabled + @enabled enabled + @noconf noconf + + Application.put_env(:phoenix_profiler, DebugEndpoint, + http: [port: @debug], + live_view: [signing_salt: gen_salt()], + secret_key_base: gen_secret_key(), + server: true, + drainer: false, + debug_errors: true, + phoenix_profiler: [server: Profiler] + ) + + Application.put_env(:phoenix_profiler, DisabledEndpoint, + http: [port: @disabled], + live_view: [signing_salt: gen_salt()], + secret_key_base: gen_secret_key(), + server: true, + drainer: false, + phoenix_profiler: [server: Profiler, enable: false] + ) + + Application.put_env(:phoenix_profiler, EnabledEndpoint, + http: [port: @enabled], + live_view: [signing_salt: gen_salt()], + secret_key_base: gen_secret_key(), + server: true, + drainer: false, + phoenix_profiler: [server: Profiler] + ) + + Application.put_env(:phoenix_profiler, NotConfiguredEndpoint, + http: [port: @noconf], + secret_key_base: gen_secret_key(), + live_view: [signing_salt: gen_salt()], + server: true, + drainer: false + ) + + defmodule Router do + @moduledoc """ + Let's use a plug router to test this endpoint. + """ + use Plug.Router + + plug :content_type + plug :match + plug :dispatch + + get "/" do + send_resp(conn, 200, "ok") + end + + get "/router/oops" do + _ = conn + raise "oops" + end + + get "/router/catch" do + _ = conn + throw(:oops) + end + + match _ do + raise Phoenix.Router.NoRouteError, conn: conn, router: __MODULE__ + end + + def __routes__ do + [] + end + + def content_type(conn, _) do + put_resp_header(conn, "content-type", "text/html") + end + end + + for mod <- [DebugEndpoint, DisabledEndpoint, EnabledEndpoint, NotConfiguredEndpoint] do + defmodule mod do + use Phoenix.Endpoint, otp_app: :phoenix_profiler + use PhoenixProfiler + + plug :oops + plug Router + + @doc """ + Verify errors from the plug stack too (before the router). + """ + def oops(conn, _opts) do + if conn.path_info == ~w(oops) do + raise "oops" + else + conn + end + end + end + end + + alias PhoenixProfiler.Integration.HTTPClient + + setup do + pid = start_supervised!({PhoenixProfiler, name: Profiler}) + {:ok, profiler_pid: pid} + end + + test "starts collector and injects headers and toolbar and saves profile to storage for debug" do + # with debug_errors: true + {:ok, _} = DebugEndpoint.start_link([]) + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@debug}", %{}) + assert resp.status == 200 + assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + assert link =~ "/dashboard/_profiler" + assert resp.body =~ ~s|
+ # {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@debug}/oops", %{}) + # assert resp.status == 500 + # assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + # assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + # assert link =~ "/dashboard/_profiler" + # assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@debug}/router/oops", %{}) + assert resp.status == 500 + assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + assert link =~ "/dashboard/_profiler" + assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) + + Supervisor.stop(DebugEndpoint) + end) =~ "** (RuntimeError) oops" + end + + test "starts collector and injects headers and toolbar and saves profile to storage for enabled" do + # with debug_errors: false + {:ok, _} = EnabledEndpoint.start_link([]) + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}", %{}) + assert resp.status == 200 + assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + assert link =~ "/dashboard/_profiler" + assert resp.body =~ ~s|
+ # {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}/oops", %{}) + # assert resp.status == 500 + # assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + # assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + # assert link =~ "/dashboard/_profiler" + # assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}/router/oops", %{}) + assert resp.status == 500 + assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + assert link =~ "/dashboard/_profiler" + assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) + + Supervisor.stop(EnabledEndpoint) + end) =~ "** (RuntimeError) oops" + end + + test "skips injecting headers and toolbar and profile storage for disabled" do + {:ok, _} = DisabledEndpoint.start_link([]) + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@disabled}", %{}) + assert resp.status == 200 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + refute resp.body =~ ~s|class="phxprof-toolbar"| + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@disabled}/unknown", %{}) + assert resp.status == 404 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + refute resp.body =~ ~s|class="phxprof-toolbar"| + + capture_log(fn -> + # {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}/oops", %{}) + # assert resp.status == 500 + # assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + # assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + # assert link =~ "/dashboard/_profiler" + # assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@disabled}/router/oops", %{}) + assert resp.status == 500 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + + Supervisor.stop(DisabledEndpoint) + end) =~ "** (RuntimeError) oops" + end + + test "skips headers and toolbar and profile storage for not configured" do + {:ok, _} = NotConfiguredEndpoint.start_link([]) + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@noconf}", %{}) + assert resp.status == 200 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + refute resp.body =~ ~s|class="phxprof-toolbar"| + + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@noconf}/unknown", %{}) + assert resp.status == 404 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + refute resp.body =~ ~s|class="phxprof-toolbar"| + + capture_log(fn -> + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@noconf}/router/oops", %{}) + assert resp.status == 500 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + + Supervisor.stop(NotConfiguredEndpoint) + end) =~ "** (RuntimeError) oops" + end + + test "skips injecting header and toolbar for phoenix_live_reload iframes" do + start_supervised!(EnabledEndpoint) + start_supervised!(DisabledEndpoint) + + for port <- [@disabled, @enabled], + path <- ["phoenix/live_reload/frame", "phoenix/live_reload/frame/suffix"] do + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{port}/#{path}", %{}) + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + end + end +end diff --git a/test/support/endpoint_helper.exs b/test/support/endpoint_helper.exs new file mode 100644 index 0000000..91aedbe --- /dev/null +++ b/test/support/endpoint_helper.exs @@ -0,0 +1,49 @@ +# Copyright (c) 2021 Chris McCord +# https://github.com/phoenixframework/phoenix/blob/aa9e708fec303f1114b9aa9c41a32a3f72c8a06c/test/support/endpoint_helper.exs +defmodule PhoenixProfiler.Integration.EndpointHelper do + @moduledoc """ + Utility functions for integration testing endpoints. + """ + + @doc """ + Finds `n` unused network port numbers. + """ + def get_unused_port_numbers(n) when is_integer(n) and n > 1 do + 1..n + # Open up `n` sockets at the same time, so we don't get + # duplicate port numbers + |> Enum.map(&listen_on_os_assigned_port/1) + |> Enum.map(&get_port_number_and_close/1) + end + + defp listen_on_os_assigned_port(_) do + {:ok, socket} = :gen_tcp.listen(0, []) + socket + end + + defp get_port_number_and_close(socket) do + {:ok, port_number} = :inet.port(socket) + :gen_tcp.close(socket) + port_number + end + + @doc """ + Generates a signing salt for a LiveView configuration. + """ + def gen_salt do + gen_secret(8) + end + + @doc """ + Generates a secret key base for an Endpoint configuration. + """ + def gen_secret_key do + gen_secret(64) + end + + defp gen_secret(length) do + :crypto.strong_rand_bytes(length) + |> Base.encode64(padding: false) + |> binary_part(0, length) + end +end diff --git a/test/support/http_client.exs b/test/support/http_client.exs new file mode 100644 index 0000000..acdaef0 --- /dev/null +++ b/test/support/http_client.exs @@ -0,0 +1,75 @@ +# Copyright (c) 2014 Chris McCord +# https://github.com/phoenixframework/phoenix/blob/aa9e708fec303f1114b9aa9c41a32a3f72c8a06c/test/support/http_client.exs +defmodule PhoenixProfiler.Integration.HTTPClient do + @doc """ + Performs HTTP Request and returns Response + + * method - The http method, for example :get, :post, :put, etc + * url - The string url, for example "http://example.com" + * headers - The map of headers + * body - The optional string body. If the body is a map, it is converted + to a URI encoded string of parameters + + ## Examples + + iex> HTTPClient.request(:get, "http://127.0.0.1", %{}) + {:ok, %Response{..}) + + iex> HTTPClient.request(:post, "http://127.0.0.1", %{}, param1: "val1") + {:ok, %Response{..}) + + iex> HTTPClient.request(:get, "http://unknownhost", %{}, param1: "val1") + {:error, ...} + + """ + def request(method, url, headers, body \\ "") + + def request(method, url, headers, body) when is_map(body) do + request(method, url, headers, URI.encode_query(body)) + end + + def request(method, url, headers, body) do + url = String.to_charlist(url) + headers = headers |> Map.put_new("content-type", "text/html") + ct_type = headers["content-type"] |> String.to_charlist() + + header = + Enum.map(headers, fn {k, v} -> + {String.to_charlist(k), String.to_charlist(v)} + end) + + # Generate a random profile per request to avoid reuse + profile = :crypto.strong_rand_bytes(4) |> Base.encode16() |> String.to_atom() + {:ok, pid} = :inets.start(:httpc, profile: profile) + + resp = + case method do + :get -> :httpc.request(:get, {url, header}, [], [body_format: :binary], pid) + _ -> :httpc.request(method, {url, header, ct_type, body}, [], [body_format: :binary], pid) + end + + :inets.stop(:httpc, pid) + format_resp(resp) + end + + defp format_resp({:ok, {{_http, status, _status_phrase}, headers, body}}) do + headers = Enum.map(headers, fn {k, v} -> {to_string(k), to_string(v)} end) + {:ok, %{status: status, headers: headers, body: body}} + end + + defp format_resp({:error, reason}), do: {:error, reason} + + @doc """ + Returns the values of the response header specified by `key`. + + ## Examples + + iex> req = %{req | headers: [{"content-type", "text/plain"}]} + iex> HTTPClient.get_resp_header(req, "content-type") + ["text/plain"] + + """ + def get_resp_header(%{headers: headers}, key) when is_list(headers) and is_binary(key) do + for {^key, value} <- headers, do: value + end +end diff --git a/test/test_helper.exs b/test/test_helper.exs index ce0dd62..2f970a5 100644 --- a/test/test_helper.exs +++ b/test/test_helper.exs @@ -1,8 +1,11 @@ +Code.require_file("support/endpoint_helper.exs", __DIR__) + +alias PhoenixProfiler.Integration.EndpointHelper + Application.put_env(:phoenix_profiler, PhoenixProfilerTest.Endpoint, url: [host: "localhost", port: 4000], - secret_key_base: "LIyk9co9Mt8KowH/g1WeMkufq/9Bz1XuEZMhCZAwnBc7VFKCfkDq/vRw+Xso4Q0q", - live_view: [signing_salt: "NbA2FdHo"], - render_errors: [view: PhoenixProfilerTest.ErrorView], + secret_key_base: EndpointHelper.gen_secret_key(), + live_view: [signing_salt: EndpointHelper.gen_salt()], check_origin: false, pubsub_server: PhoenixProfilerTest.PubSub, phoenix_profiler: [server: PhoenixProfilerTest.Profiler] @@ -10,9 +13,8 @@ Application.put_env(:phoenix_profiler, PhoenixProfilerTest.Endpoint, Application.put_env(:phoenix_profiler, PhoenixProfilerTest.EndpointDisabled, url: [host: "localhost", port: 4000], - secret_key_base: "LIyk9co9Mt8KowH/g1WeMkufq/9Bz1XuEZMhCZAwnBc7VFKCfkDq/vRw+Xso4Q0q", - live_view: [signing_salt: "NbA2FdHo"], - render_errors: [view: PhoenixProfilerTest.ErrorView], + secret_key_base: EndpointHelper.gen_secret_key(), + live_view: [signing_salt: EndpointHelper.gen_salt()], check_origin: false, pubsub_server: PhoenixProfilerTest.PubSub, phoenix_profiler: [server: PhoenixProfilerTest.Profiler, enable: false] @@ -20,18 +22,25 @@ Application.put_env(:phoenix_profiler, PhoenixProfilerTest.EndpointDisabled, Application.put_env(:phoenix_profiler, PhoenixProfilerTest.EndpointNotConfigured, url: [host: "localhost", port: 4000], - secret_key_base: "LIyk9co9Mt8KowH/g1WeMkufq/9Bz1XuEZMhCZAwnBc7VFKCfkDq/vRw+Xso4Q0q", - live_view: [signing_salt: "NbA2FdHo"], - render_errors: [view: PhoenixProfilerTest.ErrorView], + secret_key_base: EndpointHelper.gen_secret_key(), + live_view: [signing_salt: EndpointHelper.gen_salt()], check_origin: false, pubsub_server: PhoenixProfilerTest.PubSub ) -defmodule PhoenixProfilerTest.ErrorView do - use Phoenix.View, root: "test/templates" +defmodule PhoenixProfiler.ErrorView do + def render(template, %{conn: conn}) do + unless conn.private.phoenix_endpoint do + raise "no endpoint in error view" + end + + err = "#{template} from PhoenixProfiler.ErrorView" - def template_not_found(template, _assigns) do - Phoenix.Controller.status_message_from_template(template) + if String.ends_with?(template, ".html") do + Phoenix.HTML.html_escape("#{err}") + else + err + end end end From 155a1026504176286723da67c6c7432cb44c4e66 Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Tue, 1 Mar 2022 11:32:45 -0800 Subject: [PATCH 18/38] Collect exception from endpoint --- lib/phoenix_profiler/endpoint.ex | 4 +- lib/phoenix_profiler/profiler.ex | 4 +- lib/phoenix_profiler/telemetry.ex | 5 ++ lib/phoenix_profiler/toolbar/toolbar_live.ex | 34 +++++++---- .../integration/endpoint_test.exs | 57 +++++++------------ 5 files changed, 55 insertions(+), 49 deletions(-) diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex index 280befb..7a34d2a 100644 --- a/lib/phoenix_profiler/endpoint.ex +++ b/lib/phoenix_profiler/endpoint.ex @@ -74,7 +74,7 @@ defmodule PhoenixProfiler.Endpoint do stacktrace: stack }) - late_collect(conn, {kind, reason, stack}) + late_collect(conn) end end @@ -86,7 +86,7 @@ defmodule PhoenixProfiler.Endpoint do System.monotonic_time() - start_time end - defp late_collect(conn, _error \\ nil) do + defp late_collect(conn) do case PhoenixProfiler.Profiler.collect(conn) do {:ok, profile} -> true = PhoenixProfiler.Profiler.insert_profile(profile) diff --git a/lib/phoenix_profiler/profiler.ex b/lib/phoenix_profiler/profiler.ex index 66cc9aa..48be205 100644 --- a/lib/phoenix_profiler/profiler.ex +++ b/lib/phoenix_profiler/profiler.ex @@ -15,6 +15,7 @@ defmodule PhoenixProfiler.Profiler do if conn.private.phoenix_profiler_info == :enable do time = System.system_time() profiler_base_url = conn.private.phoenix_profiler_base_url + token = Map.get_lazy(conn.private, :phoenix_profiler_token, &Utils.random_unique_id/0) data = PhoenixProfiler.TelemetryCollector.reduce( @@ -37,7 +38,7 @@ defmodule PhoenixProfiler.Profiler do profile = Profile.new( conn.private.phoenix_profiler, - Utils.random_unique_id(), + token, profiler_base_url, time ) @@ -125,6 +126,7 @@ defmodule PhoenixProfiler.Profiler do |> Utils.put_private(:phoenix_profiler_base_url, base_url) |> Utils.put_private(:phoenix_profiler_collector, collector_pid) |> Utils.put_private(:phoenix_profiler_info, info) + |> Utils.put_private(:phoenix_profiler_token, Utils.random_unique_id()) end defp validate_apply_configuration(conn_or_socket, endpoint) do diff --git a/lib/phoenix_profiler/telemetry.ex b/lib/phoenix_profiler/telemetry.ex index 910d7da..7917d27 100644 --- a/lib/phoenix_profiler/telemetry.ex +++ b/lib/phoenix_profiler/telemetry.ex @@ -10,6 +10,7 @@ defmodule PhoenixProfiler.Telemetry do plug_events = [ [:phoenix, :endpoint, :stop], + [:phoenix_profiler, :endpoint, :exception], [:phxprof, :plug, :stop] ] @@ -38,6 +39,10 @@ defmodule PhoenixProfiler.Telemetry do }} 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 cond do Map.has_key?(socket, :root_view) and socket.root_view == PhoenixProfiler.ToolbarLive -> diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.ex b/lib/phoenix_profiler/toolbar/toolbar_live.ex index e686bb1..0d4c5e5 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_live.ex +++ b/lib/phoenix_profiler/toolbar/toolbar_live.ex @@ -66,6 +66,15 @@ defmodule PhoenixProfiler.ToolbarLive do defp assign_toolbar(socket, profile) do %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) @@ -171,17 +180,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 +200,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/test/phoenix_profiler/integration/endpoint_test.exs b/test/phoenix_profiler/integration/endpoint_test.exs index 9cf79eb..a7a28ab 100644 --- a/test/phoenix_profiler/integration/endpoint_test.exs +++ b/test/phoenix_profiler/integration/endpoint_test.exs @@ -137,16 +137,20 @@ defmodule PhoenixProfiler.Integration.EndpointTest do assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") assert link =~ "/dashboard/_profiler" - # assert resp.body =~ ~s|
- # {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@debug}/oops", %{}) - # assert resp.status == 500 - # assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") - # assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") - # assert link =~ "/dashboard/_profiler" - # assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) + # Errors in the Plug stack will not be caught by the profiler + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@debug}/oops", %{}) + assert resp.status == 500 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@debug}/router/oops", %{}) assert resp.status == 500 @@ -177,7 +181,8 @@ defmodule PhoenixProfiler.Integration.EndpointTest do assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") assert link =~ "/dashboard/_profiler" - # assert resp.body =~ ~s|
- # {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}/oops", %{}) - # assert resp.status == 500 - # assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") - # assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") - # assert link =~ "/dashboard/_profiler" - # assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) + # Errors in the Plug stack will not be caught by the Profiler + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}/oops", %{}) + assert resp.status == 500 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + assert link =~ "/dashboard/_profiler" + assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}/router/oops", %{}) assert resp.status == 500 @@ -222,13 +228,6 @@ defmodule PhoenixProfiler.Integration.EndpointTest do refute resp.body =~ ~s|class="phxprof-toolbar"| capture_log(fn -> - # {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@enabled}/oops", %{}) - # assert resp.status == 500 - # assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") - # assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") - # assert link =~ "/dashboard/_profiler" - # assert %PhoenixProfiler.Profile{} = PhoenixProfiler.ProfileStore.get(Profiler, token) - {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@disabled}/router/oops", %{}) assert resp.status == 500 assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] @@ -238,7 +237,7 @@ defmodule PhoenixProfiler.Integration.EndpointTest do end) =~ "** (RuntimeError) oops" end - test "skips headers and toolbar and profile storage for not configured" do + test "skips headers and toolbar and profile storage for noconf" do {:ok, _} = NotConfiguredEndpoint.start_link([]) {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@noconf}", %{}) @@ -262,16 +261,4 @@ defmodule PhoenixProfiler.Integration.EndpointTest do Supervisor.stop(NotConfiguredEndpoint) end) =~ "** (RuntimeError) oops" end - - test "skips injecting header and toolbar for phoenix_live_reload iframes" do - start_supervised!(EnabledEndpoint) - start_supervised!(DisabledEndpoint) - - for port <- [@disabled, @enabled], - path <- ["phoenix/live_reload/frame", "phoenix/live_reload/frame/suffix"] do - {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{port}/#{path}", %{}) - assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] - assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] - end - end end From 640c318c1dfc2decf053328e08a4fcab40d7342b Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Tue, 1 Mar 2022 17:15:14 -0800 Subject: [PATCH 19/38] Rename plug telemetry --- lib/phoenix_profiler/plug.ex | 2 +- lib/phoenix_profiler/telemetry.ex | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/phoenix_profiler/plug.ex b/lib/phoenix_profiler/plug.ex index 8da2118..d4b1bff 100644 --- a/lib/phoenix_profiler/plug.ex +++ b/lib/phoenix_profiler/plug.ex @@ -55,7 +55,7 @@ defmodule PhoenixProfiler.Plug do defp telemetry_execute(%Plug.Conn{} = conn, action, measurements) when action in [:start, :stop] do - :telemetry.execute([:phxprof, :plug, action], measurements, %{conn: conn}) + :telemetry.execute([:phoenix_profiler, :plug, action], measurements, %{conn: conn}) conn end diff --git a/lib/phoenix_profiler/telemetry.ex b/lib/phoenix_profiler/telemetry.ex index 7917d27..d6ba8ae 100644 --- a/lib/phoenix_profiler/telemetry.ex +++ b/lib/phoenix_profiler/telemetry.ex @@ -11,7 +11,7 @@ defmodule PhoenixProfiler.Telemetry do plug_events = [ [:phoenix, :endpoint, :stop], [:phoenix_profiler, :endpoint, :exception], - [:phxprof, :plug, :stop] + [:phoenix_profiler, :plug, :stop] ] @events plug_events ++ live_view_events @@ -28,7 +28,7 @@ defmodule PhoenixProfiler.Telemetry do {:keep, %{endpoint_duration: duration}} end - def collect(_, [:phxprof, :plug, :stop], measures, %{conn: conn}) do + def collect(_, [:phoenix_profiler, :plug, :stop], measures, %{conn: conn}) do {:keep, %{ conn: %{conn | resp_body: nil, assigns: Map.delete(conn.assigns, :content)}, From 00e6b2fd37e3aa5c0c010799d5944adafa19977b Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Wed, 2 Mar 2022 22:05:53 -0800 Subject: [PATCH 20/38] Sync (dis|en)abling telemetry collector --- lib/phoenix_profiler/telemetry/collector.ex | 35 ++++++----- lib/phoenix_profiler/telemetry/registry.ex | 16 ++++- lib/phoenix_profiler/telemetry/server.ex | 59 +++++++++++-------- .../telemetry/collector_test.exs | 54 ++++++++++++----- .../telemetry/server_test.exs | 18 ++---- 5 files changed, 109 insertions(+), 73 deletions(-) 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 21a53dc..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,24 +61,13 @@ defmodule PhoenixProfiler.TelemetryServer do GenServer.start_link(__MODULE__, config) end - @doc """ - Executes the collector event for `info` for the current process. - """ - @spec collector_info_exec(info :: :disable | :enable) :: :ok - 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} ) @@ -60,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/test/phoenix_profiler/telemetry/collector_test.exs b/test/phoenix_profiler/telemetry/collector_test.exs index bf6dc78..d02683f 100644 --- a/test/phoenix_profiler/telemetry/collector_test.exs +++ b/test/phoenix_profiler/telemetry/collector_test.exs @@ -6,6 +6,38 @@ defmodule PhoenixProfiler.TelemetryCollectorTest do doctest TelemetryCollector + defmodule Collector do + use GenServer + + def start_link(init_arg) do + GenServer.start_link(__MODULE__, init_arg) + end + + @impl true + def init({server, pid}) do + TelemetryRegistry.register(server, pid) + {:ok, pid} + end + + @impl true + def handle_call({TelemetryCollector, :disable}, _from, pid) do + TelemetryRegistry.update_info(pid, fn _ -> :disable end) + {:reply, :ok, pid} + end + + @impl true + def handle_call({TelemetryCollector, :enable}, _from, pid) do + TelemetryRegistry.update_info(pid, fn _ -> :enable end) + {:reply, :ok, pid} + end + + @impl true + def handle_info({:telemetry, _, _, _, _} = event, pid) do + send(pid, {:collector, event}) + {:noreply, pid} + end + end + describe "collecting telemetry" do test "events from watched pid" do name = unique_debug_name() @@ -114,30 +146,20 @@ defmodule PhoenixProfiler.TelemetryCollectorTest do name = unique_debug_name() start_supervised!({PhoenixProfiler, name: name, telemetry: [[:debug, :me]]}) - {:ok, _} = TelemetryRegistry.register(name, self()) + start_supervised!({Collector, {name, self()}}) :ok = :telemetry.execute([:debug, :me], %{system_time: 1}, %{}) - assert_received {:telemetry, nil, [:debug, :me], 1, _} + assert_receive {:collector, {:telemetry, nil, [:debug, :me], 1, _}}, 10 - :ok = TelemetryServer.collector_info_exec(:disable) - - receive do - {:collector_update_info, func} -> - TelemetryRegistry.update_info(self(), func) - end + :ok = TelemetryServer.disable_key(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 2}, %{}) - refute_received {:telemetry, nil, [:debug, :me], 2, _} - - :ok = TelemetryServer.collector_info_exec(:enable) + refute_receive {:collector, {:telemetry, nil, [:debug, :me], 2, _}}, 10 - receive do - {:collector_update_info, func} -> - TelemetryRegistry.update_info(self(), func) - end + :ok = TelemetryServer.enable_key(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 3}, %{}) - assert_received {:telemetry, nil, [:debug, :me], 3, _} + assert_receive {:collector, {:telemetry, nil, [:debug, :me], 3, _}}, 10 end end diff --git a/test/phoenix_profiler/telemetry/server_test.exs b/test/phoenix_profiler/telemetry/server_test.exs index 7e17e10..c875695 100644 --- a/test/phoenix_profiler/telemetry/server_test.exs +++ b/test/phoenix_profiler/telemetry/server_test.exs @@ -77,11 +77,9 @@ defmodule PhoenixProfiler.TelemetryServerTest do {:ok, collector_pid} = TelemetryServer.listen(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 1}, %{}) - :ok = TelemetryServer.collector_info_exec(:disable) - :timer.sleep(1) + :ok = TelemetryServer.disable_key(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 2}, %{}) - :ok = TelemetryServer.collector_info_exec(:enable) - :timer.sleep(1) + :ok = TelemetryServer.enable_key(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 3}, %{}) assert reduce_events(collector_pid) == [ @@ -100,15 +98,11 @@ defmodule PhoenixProfiler.TelemetryServerTest do {:ok, collector_pid} = TelemetryServer.listen(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 1}, %{}) - :ok = TelemetryServer.collector_info_exec(:disable) - :timer.sleep(1) - :ok = TelemetryServer.collector_info_exec(:disable) - :timer.sleep(1) + :ok = TelemetryServer.disable_key(name, self()) + :ok = TelemetryServer.disable_key(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 2}, %{}) - :ok = TelemetryServer.collector_info_exec(:enable) - :timer.sleep(1) - :ok = TelemetryServer.collector_info_exec(:enable) - :timer.sleep(1) + :ok = TelemetryServer.enable_key(name, self()) + :ok = TelemetryServer.enable_key(name, self()) :ok = :telemetry.execute([:debug, :me], %{system_time: 3}, %{}) assert reduce_events(collector_pid) == [ From 670c55b1b3768514937b082cbef21037f6cbeafc Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Wed, 2 Mar 2022 22:19:06 -0800 Subject: [PATCH 21/38] Stabilize profiler responses --- dev.exs | 4 +- lib/phoenix_profiler/endpoint.ex | 99 ++++----- lib/phoenix_profiler/plug.ex | 9 +- lib/phoenix_profiler/profile.ex | 30 +-- lib/phoenix_profiler/profile_store.ex | 2 +- lib/phoenix_profiler/profiler.ex | 200 ++++++------------ lib/phoenix_profiler/toolbar/toolbar_live.ex | 7 + lib/phoenix_profiler/utils.ex | 15 +- mix.exs | 4 - test/phoenix_profiler/endpoint_test.exs | 13 +- .../integration/endpoint_test.exs | 42 +++- test/phoenix_profiler/live_view_test.exs | 7 +- test/phoenix_profiler/plug_test.exs | 9 +- test/phoenix_profiler_test.exs | 95 +-------- test/support/profiler_helper.exs | 29 +++ test/test_helper.exs | 1 + 16 files changed, 241 insertions(+), 325 deletions(-) create mode 100644 test/support/profiler_helper.exs diff --git a/dev.exs b/dev.exs index ff7f2d7..c7a771c 100644 --- a/dev.exs +++ b/dev.exs @@ -214,7 +214,7 @@ defmodule DemoWeb.AppLive.Index do defp apply_profiler_toggle(socket) do if connected?(socket) do - info = socket.private.phoenix_profiler_info + 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 @@ -259,7 +259,7 @@ defmodule DemoWeb.AppLive.Index do end def handle_event("toggle-profiler", _, socket) do - info = socket.private.phoenix_profiler_info + info = socket.private.phoenix_profiler.info next = if info == :enable, do: :disable, else: :enable socket = apply(PhoenixProfiler, next, [socket]) diff --git a/lib/phoenix_profiler/endpoint.ex b/lib/phoenix_profiler/endpoint.ex index 7a34d2a..960cc7a 100644 --- a/lib/phoenix_profiler/endpoint.ex +++ b/lib/phoenix_profiler/endpoint.ex @@ -13,69 +13,60 @@ defmodule PhoenixProfiler.Endpoint do def call(conn, opts) do start_time = System.monotonic_time() - endpoint = __MODULE__ - config = endpoint.config(:phoenix_profiler) - conn = PhoenixProfiler.Endpoint.__prologue__(conn, endpoint, config) - - try do - conn - |> super(opts) - |> PhoenixProfiler.Endpoint.__epilogue__(start_time) - catch - kind, reason -> - stack = __STACKTRACE__ - PhoenixProfiler.Endpoint.__catch__(conn, kind, reason, stack, config, start_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 - # Skip profiling if no configuration set on the Endpoint - def __prologue__(conn, _endpoint, nil) do + 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 __prologue__(conn, endpoint, config) do - if server = config[:server] do - conn = PhoenixProfiler.Profiler.apply_configuration(conn, endpoint, server, config) - telemetry_execute(:start, %{system_time: System.system_time()}, %{conn: conn}) - conn - else - IO.warn("no profiler server found for endpoint #{inspect(endpoint)}") - conn - 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 __catch__(conn, kind, reason, stack, config, start_time) do - __epilogue__(conn, kind, reason, stack, config, start_time) - :erlang.raise(kind, reason, stack) - 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 + }) - def __epilogue__(conn, start_time) do - if profiler = conn.private[:phoenix_profiler] do - telemetry_execute(:stop, %{duration: duration(start_time)}, %{ - conn: conn, - profiler: profiler - }) - - late_collect(conn) - else - conn - end + {_, pid} = PhoenixProfiler.Utils.collector_info(profile.server, conn) + late_collect(conn, profile, pid) end - def __epilogue__(conn, kind, reason, stack, _config, start_time) do - if profiler = conn.private[:phoenix_profiler] do - telemetry_execute(:exception, %{duration: duration(start_time)}, %{ - conn: conn, - profiler: profiler, - kind: kind, - reason: reason, - stacktrace: stack - }) - - late_collect(conn) - 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 @@ -86,8 +77,12 @@ defmodule PhoenixProfiler.Endpoint do System.monotonic_time() - start_time end - defp late_collect(conn) do - case PhoenixProfiler.Profiler.collect(conn) do + 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 diff --git a/lib/phoenix_profiler/plug.ex b/lib/phoenix_profiler/plug.ex index d4b1bff..e67b928 100644 --- a/lib/phoenix_profiler/plug.ex +++ b/lib/phoenix_profiler/plug.ex @@ -21,7 +21,7 @@ defmodule PhoenixProfiler.Plug do start_time = System.monotonic_time() case conn.private do - %{phoenix_profiler: profiler} when is_atom(profiler) -> + %{phoenix_profiler: %Profile{}} -> conn |> telemetry_execute(:start, %{system_time: System.system_time()}) |> before_send_profile(endpoint, [], start_time) @@ -41,7 +41,10 @@ defmodule PhoenixProfiler.Plug do register_before_send(conn, fn conn -> telemetry_execute(conn, :stop, %{duration: System.monotonic_time() - start_time}) - case PhoenixProfiler.Profiler.collect(conn) do + 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) @@ -118,7 +121,7 @@ defmodule PhoenixProfiler.Plug do conn: conn, session: %{ "vsn" => 1, - "node" => node(), + "node" => profile.node, "server" => profile.server, "token" => profile.token }, diff --git a/lib/phoenix_profiler/profile.ex b/lib/phoenix_profiler/profile.ex index c6652d7..5a9a507 100644 --- a/lib/phoenix_profiler/profile.ex +++ b/lib/phoenix_profiler/profile.ex @@ -2,13 +2,15 @@ defmodule PhoenixProfiler.Profile do # An internal data structure for a request profile. @moduledoc false defstruct [ - :data, + :endpoint, + :info, :node, :server, :system, :system_time, :token, - :url + :url, + data: %{} ] @type system :: %{ @@ -21,32 +23,34 @@ defmodule PhoenixProfiler.Profile do @type t :: %__MODULE__{ :data => map(), + :endpoint => module(), + :info => nil | :disable | :enable, :token => String.t(), :server => module(), :node => node(), :system => system(), - :system_time => integer(), + :system_time => nil | integer(), :url => String.t() } @doc """ Returns a new profile. """ - def new(server, token, base_url, system_time) - when is_atom(server) and is_binary(token) 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(), server: server, 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 a1b1a95..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 - server when is_atom(server) -> server + %Profile{server: server} -> server nil -> nil end end diff --git a/lib/phoenix_profiler/profiler.ex b/lib/phoenix_profiler/profiler.ex index 48be205..4316adb 100644 --- a/lib/phoenix_profiler/profiler.ex +++ b/lib/phoenix_profiler/profiler.ex @@ -1,7 +1,6 @@ defmodule PhoenixProfiler.Profiler do @moduledoc false use Supervisor - alias Phoenix.LiveView alias PhoenixProfiler.Profile alias PhoenixProfiler.ProfileStore alias PhoenixProfiler.Telemetry @@ -11,42 +10,32 @@ defmodule PhoenixProfiler.Profiler do @doc """ Builds a profile from data collected for a given `conn`. """ - def collect(%Plug.Conn{} = conn) do - if conn.private.phoenix_profiler_info == :enable do - time = System.system_time() - profiler_base_url = conn.private.phoenix_profiler_base_url - token = Map.get_lazy(conn.private, :phoenix_profiler_token, &Utils.random_unique_id/0) - - data = - PhoenixProfiler.TelemetryCollector.reduce( - conn.private.phoenix_profiler_collector, - %{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 - ) - - profile = - Profile.new( - conn.private.phoenix_profiler, - token, - profiler_base_url, - time - ) - - {:ok, %Profile{profile | data: data}} - else - :error - end + 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 """ @@ -61,31 +50,46 @@ defmodule PhoenixProfiler.Profiler do @doc """ Disables profiling for a given `conn` or `socket`. """ - def disable(conn_or_socket) do - update_info(conn_or_socket, :disable) + 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(conn_or_socket) do - update_info(conn_or_socket, :enable) + 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 """ - Configures profiling for a given `conn` or `socket`. + Returns a sparse data structure for a profile. + + Useful mostly for initializing the profile at the beginning of a request. """ - def configure(conn_or_socket, endpoint \\ nil) do - case validate_apply_configuration(conn_or_socket, endpoint) do - {:ok, conn_or_socket} -> - {:ok, conn_or_socket} + def preflight(endpoint) do + preflight(endpoint, endpoint.config(:phoenix_profiler)) + end - {:error, :profiler_not_available} -> - {:error, :profiler_not_available} + def preflight(_endpoint, nil), do: :error + def preflight(endpoint, config), do: preflight(endpoint, config[:server], config) - {:error, reason} -> - configure_profile_error(conn_or_socket, :configure, reason) - end + 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 @@ -110,95 +114,21 @@ defmodule PhoenixProfiler.Profiler do Supervisor.init(children, strategy: :one_for_one) end - defp update_info(conn_or_socket, action) when action in [:disable, :enable] do - TelemetryServer.collector_info_exec(action) - Utils.put_private(conn_or_socket, :phoenix_profiler_info, action) - end - - def apply_configuration(conn_or_socket, endpoint, server, config) - when is_atom(endpoint) and is_atom(server) do - info = if config[:enable] == false, do: :disable, else: :enable - base_url = endpoint.url() <> Utils.profile_base_path(config) - {:ok, collector_pid} = start_collector(conn_or_socket, server, info) - - conn_or_socket - |> Utils.put_private(:phoenix_profiler, server) - |> Utils.put_private(:phoenix_profiler_base_url, base_url) - |> Utils.put_private(:phoenix_profiler_collector, collector_pid) - |> Utils.put_private(:phoenix_profiler_info, info) - |> Utils.put_private(:phoenix_profiler_token, Utils.random_unique_id()) - end - - defp validate_apply_configuration(conn_or_socket, endpoint) do - endpoint = endpoint || Utils.endpoint(conn_or_socket) - - with {:ok, config} <- Utils.check_configuration(endpoint), - :ok <- maybe_check_socket_connection(conn_or_socket), - {:ok, profiler} <- check_profiler_running(config) do - {:ok, apply_configuration(conn_or_socket, endpoint, profiler, config)} - end - end - - defp maybe_check_socket_connection(%Plug.Conn{}), do: :ok - - defp maybe_check_socket_connection(%LiveView.Socket{} = socket) do - Utils.check_socket_connection(socket) - end - - defp check_profiler_running(config) do - profiler = config[:server] - - cond do - GenServer.whereis(profiler) -> - {:ok, profiler} - - profiler -> - {:error, :profiler_not_running} - - true -> - {:error, :profiler_not_available} - end - end - - # We do not start a collector for a LiveView Socket– - # ToolbarLive will register itself as a collector for its - # Socket's transport_pid. - defp start_collector(%LiveView.Socket{}, _, _) do - {:ok, nil} - end - - defp start_collector(conn_or_socket, server, info) do - case TelemetryServer.listen(server, Utils.target_pid(conn_or_socket), nil, info) do + @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}} -> - TelemetryServer.collector_info_exec(info) + 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 - - defp configure_profile_error(%LiveView.Socket{}, action, :waiting_for_connection) do - raise """ - "PhoenixProfiler attempted to #{action} a profiler on the given socket, but it is disconnected - - In your LiveView mount callback, do the following: - - socket = - if connected?(socket) do - PhoenixProfiler.enable(socket) - else - socket - end - - """ - end - - defp configure_profile_error(%{__struct__: struct}, action, :profiler_not_running) do - raise "PhoenixProfiler attempted to #{action} a profiler " <> - "on the given #{kind(struct)}, but the profiler is not running" - end - - defp kind(Plug.Conn), do: :conn - defp kind(LiveView.Socket), do: :socket end diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.ex b/lib/phoenix_profiler/toolbar/toolbar_live.ex index 0d4c5e5..4e90cee 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_live.ex +++ b/lib/phoenix_profiler/toolbar/toolbar_live.ex @@ -170,6 +170,13 @@ defmodule PhoenixProfiler.ToolbarLive do {:noreply, socket} end + @impl Phoenix.LiveView + def handle_call({TelemetryCollector, action}, _, socket) + when action in [:disable, :enable] do + TelemetryRegistry.update_info(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 diff --git a/lib/phoenix_profiler/utils.ex b/lib/phoenix_profiler/utils.ex index ffd5595..1be2d4b 100644 --- a/lib/phoenix_profiler/utils.ex +++ b/lib/phoenix_profiler/utils.ex @@ -7,11 +7,22 @@ defmodule PhoenixProfiler.Utils do @doc """ Mounts the profiler on a connected LiveView socket only if it is enabled on the Endpoint. + + ## Example + + def mount(_params, _session, socket) do + socket = PhoenixProfiler.Utils.maybe_mount_profiler(socket) + + #code... + + {:ok, socket} + end + """ def maybe_mount_profiler(%LiveView.Socket{} = socket) do with true <- Phoenix.LiveView.connected?(socket), - {:ok, socket} <- PhoenixProfiler.Profiler.configure(socket) do - socket + {:ok, profile} <- PhoenixProfiler.Profiler.preflight(socket.endpoint) do + put_private(socket, :phoenix_profiler, profile) else _ -> socket end diff --git a/mix.exs b/mix.exs index 280c507..b9502d6 100644 --- a/mix.exs +++ b/mix.exs @@ -10,7 +10,6 @@ defmodule PhoenixProfiler.MixProject do version: @version, elixir: "~> 1.8", compilers: [:phoenix] ++ Mix.compilers(), - elixirc_paths: elixirc_paths(Mix.env()), package: package(), deps: deps(), docs: docs(), @@ -20,9 +19,6 @@ defmodule PhoenixProfiler.MixProject do ] end - defp elixirc_paths(:dev), do: ["lib", "dev"] - defp elixirc_paths(_), do: ["lib"] - def application do [ extra_applications: [:logger], diff --git a/test/phoenix_profiler/endpoint_test.exs b/test/phoenix_profiler/endpoint_test.exs index fd99c21..54b9da4 100644 --- a/test/phoenix_profiler/endpoint_test.exs +++ b/test/phoenix_profiler/endpoint_test.exs @@ -40,19 +40,22 @@ defmodule PhoenixProfiler.EndpointTest do test "puts profiler info on conn" do conn = Endpoint.call(conn(:get, "/"), []) - assert conn.private.phoenix_profiler == Profiler - assert conn.private.phoenix_profiler_base_url == "https://example.com/dashboard/_profiler" + profile = conn.private.phoenix_profiler + assert %PhoenixProfiler.Profile{} = profile + assert conn.private.phoenix_profiler.server == Profiler + assert conn.private.phoenix_profiler.info == :enable + + assert conn.private.phoenix_profiler.url == + "https://example.com/dashboard/_profiler?nav=#{inspect(Profiler)}&panel=request&token=#{profile.token}" + assert is_pid(conn.private.phoenix_profiler_collector) - assert conn.private.phoenix_profiler_info == :enable end test "skips profiling live_reload frame" do for path <- ["/phoenix/live_reload/frame", "/phoenix/live_reload/frame/suffix"] do conn = Endpoint.call(conn(:get, path), []) refute Map.has_key?(conn.private, :phoenix_profiler) - refute Map.has_key?(conn.private, :phoenix_profiler_base_url) refute Map.has_key?(conn.private, :phoenix_profiler_collector) - refute Map.has_key?(conn.private, :phoenix_profiler_info) end end end diff --git a/test/phoenix_profiler/integration/endpoint_test.exs b/test/phoenix_profiler/integration/endpoint_test.exs index a7a28ab..489b844 100644 --- a/test/phoenix_profiler/integration/endpoint_test.exs +++ b/test/phoenix_profiler/integration/endpoint_test.exs @@ -74,9 +74,22 @@ defmodule PhoenixProfiler.Integration.EndpointTest do raise "oops" end - get "/router/catch" do - _ = conn - throw(:oops) + get "/router/enable" do + conn + |> PhoenixProfiler.enable() + |> send_resp(200, "enable") + end + + get "/router/disable" do + conn + |> PhoenixProfiler.disable() + |> send_resp(200, "disable") + end + + def do_before_send(conn, _) do + Enum.reduce(conn.private[:before_send] || [], conn, fn func, conn -> + func.(conn) + end) end match _ do @@ -185,12 +198,10 @@ defmodule PhoenixProfiler.Integration.EndpointTest do refute resp.body =~ ~s|
# Errors in the Plug stack will not be caught by the Profiler @@ -227,6 +238,14 @@ defmodule PhoenixProfiler.Integration.EndpointTest do assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] refute resp.body =~ ~s|class="phxprof-toolbar"| + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@disabled}/router/enable", %{}) + assert resp.status == 200 + assert [token] = HTTPClient.get_resp_header(resp, "x-debug-token") + assert [link] = HTTPClient.get_resp_header(resp, "x-debug-token-link") + assert link =~ "/dashboard/_profiler" + assert resp.body =~ ~s|
{:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@disabled}/router/oops", %{}) assert resp.status == 500 @@ -253,6 +272,11 @@ defmodule PhoenixProfiler.Integration.EndpointTest do refute resp.body =~ ~s|class="phxprof-toolbar"| capture_log(fn -> + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@noconf}/oops", %{}) + assert resp.status == 500 + assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] + assert HTTPClient.get_resp_header(resp, "x-debug-token-link") == [] + {:ok, resp} = HTTPClient.request(:get, "http://127.0.0.1:#{@noconf}/router/oops", %{}) assert resp.status == 500 assert HTTPClient.get_resp_header(resp, "x-debug-token") == [] diff --git a/test/phoenix_profiler/live_view_test.exs b/test/phoenix_profiler/live_view_test.exs index 7f0d33a..640fbe7 100644 --- a/test/phoenix_profiler/live_view_test.exs +++ b/test/phoenix_profiler/live_view_test.exs @@ -1,6 +1,7 @@ defmodule PhoenixProfiler.LiveViewTest do use ExUnit.Case alias Phoenix.LiveView.Socket + alias PhoenixProfiler.Profile defp build_socket(endpoint \\ PhoenixProfilerTest.Endpoint) do %Socket{endpoint: endpoint} @@ -25,9 +26,9 @@ defmodule PhoenixProfiler.LiveViewTest do end test "when the profiler is enabled on the endpoint, configures an enabled profile" do - {:ok, socket} = build_socket() |> connect() |> PhoenixProfiler.Profiler.configure() + socket = build_socket() |> connect() |> PhoenixProfiler.Utils.maybe_mount_profiler() - assert {:cont, %{private: %{phoenix_profiler: _profiler, phoenix_profiler_info: :enable}}} = + assert {:cont, %{private: %{phoenix_profiler: %Profile{info: :enable}}}} = PhoenixProfiler.on_mount(:default, %{}, %{}, socket) end @@ -37,7 +38,7 @@ defmodule PhoenixProfiler.LiveViewTest do |> build_socket() |> connect() - assert {:cont, %Socket{private: %{phoenix_profiler_info: :disable}}} = + assert {:cont, %Socket{private: %{phoenix_profiler: %Profile{info: :disable}}}} = PhoenixProfiler.on_mount(:default, %{}, %{}, socket) end diff --git a/test/phoenix_profiler/plug_test.exs b/test/phoenix_profiler/plug_test.exs index 51586ba..b879113 100644 --- a/test/phoenix_profiler/plug_test.exs +++ b/test/phoenix_profiler/plug_test.exs @@ -1,7 +1,6 @@ defmodule PhoenixProfiler.PlugTest do use ExUnit.Case, async: true - import Plug.Test - import Plug.Conn + use ProfilerHelper @token_header_key "x-debug-token" @profiler_header_key "x-debug-token-link" @@ -13,12 +12,6 @@ defmodule PhoenixProfiler.PlugTest do conn(:get, path) end - defp profile_thru(conn, endpoint) do - conn = put_private(conn, :phoenix_endpoint, endpoint) - {:ok, conn} = PhoenixProfiler.Profiler.configure(conn) - conn - end - test "injects debug token headers if configured" do opts = PhoenixProfiler.Plug.init([]) diff --git a/test/phoenix_profiler_test.exs b/test/phoenix_profiler_test.exs index fdcc7c4..643ee71 100644 --- a/test/phoenix_profiler_test.exs +++ b/test/phoenix_profiler_test.exs @@ -1,5 +1,6 @@ defmodule PhoenixProfilerUnitTest do use ExUnit.Case, async: true + use ProfilerHelper alias Phoenix.LiveView.Socket doctest PhoenixProfiler @@ -18,11 +19,6 @@ defmodule PhoenixProfilerUnitTest do Plug.Test.conn(:get, "/") end - defp build_conn(endpoint) do - build_conn() - |> PhoenixProfiler.Utils.put_private(:phoenix_endpoint, endpoint) - end - defp build_socket(view \\ TestLive) do %Socket{endpoint: EndpointMock, view: view} end @@ -49,102 +45,25 @@ defmodule PhoenixProfilerUnitTest do assert [AllRunning_1, AllRunning_2] -- PhoenixProfiler.all_running() == [] end - describe "configure/1 with Plug.Conn" do - test "returns {:error, :profiler_not_available} when the profiler is not defined on the endpoint" do - assert NoConfigEndpoint - |> build_conn() - |> PhoenixProfiler.Profiler.configure() == {:error, :profiler_not_available} - end - - test "raises when the profiler is not running" do - assert_raise RuntimeError, - ~r/attempted to configure a profiler on the given conn, but the profiler is not running/, - fn -> - EndpointMock - |> build_conn() - |> PhoenixProfiler.Profiler.configure() - end - end - - test "starts a collector" do - profiler_name = MyProfiler - start_supervised!({PhoenixProfiler, name: profiler_name}) - - conn = build_conn() - - assert PhoenixProfiler.Utils.collector_info(profiler_name, conn) == :error - - assert {:ok, conn} = - conn - |> PhoenixProfiler.Utils.put_private(:phoenix_endpoint, EndpointMock) - |> PhoenixProfiler.Profiler.configure() - - assert {:enable, collector_pid} = PhoenixProfiler.Utils.collector_info(profiler_name, conn) - - assert Process.alive?(collector_pid) - end - end - - describe "configure/1 with LiveView.Socket" do - test "raises when socket is not connected" do - assert_raise RuntimeError, - ~r/attempted to configure a profiler on the given socket, but it is disconnected/, - fn -> - PhoenixProfiler.Profiler.configure(build_socket()) - end - end - - test "returns {:error, :profiler_not_available} when the profiler is not defined on the endpoint" do - assert build_socket() - |> Map.put(:endpoint, NoConfigEndpoint) - |> connect() - |> PhoenixProfiler.Profiler.configure() == {:error, :profiler_not_available} - end - - test "raises when the profiler is not running" do - assert_raise RuntimeError, - ~r/attempted to configure a profiler on the given socket, but the profiler is not running/, - fn -> - build_socket() |> connect() |> PhoenixProfiler.Profiler.configure() - end - end - - test "does not start a collector" do - profiler_name = MyProfiler - start_supervised!({PhoenixProfiler, name: profiler_name}) - socket = build_socket() |> connect() - - assert PhoenixProfiler.Utils.collector_info(profiler_name, socket) == :error - - assert {:ok, socket} = PhoenixProfiler.Profiler.configure(socket) - - assert PhoenixProfiler.Utils.collector_info(profiler_name, socket) == :error - end - end - test "disable/1 with Plug.Conn" do profiler = start_profiler!() - conn = - build_conn() - |> PhoenixProfiler.Utils.put_private(:phoenix_endpoint, EndpointMock) - + conn = build_conn() assert PhoenixProfiler.Utils.collector_info(profiler, conn) == :error - {:ok, conn} = PhoenixProfiler.Profiler.configure(conn) + conn = profile_thru(conn, EndpointMock) assert {:enable, _pid} = PhoenixProfiler.Utils.collector_info(profiler, conn) conn = PhoenixProfiler.disable(conn) - assert conn.private.phoenix_profiler_info == :disable + assert conn.private.phoenix_profiler.info == :disable end test "disable/1 with LiveView.Socket" do profiler = start_profiler!() - socket = build_socket() |> connect() - assert PhoenixProfiler.Utils.collector_info(profiler, socket) == :error + socket = build_socket() |> connect() |> PhoenixProfiler.Utils.maybe_mount_profiler() - {:ok, socket} = PhoenixProfiler.Profiler.configure(socket) + assert PhoenixProfiler.Utils.collector_info(profiler, socket) == :error {:ok, pid} = PhoenixProfiler.TelemetryServer.listen( @@ -155,7 +74,7 @@ defmodule PhoenixProfilerUnitTest do assert {:enable, ^pid} = PhoenixProfiler.Utils.collector_info(profiler, socket) socket = PhoenixProfiler.disable(socket) - assert socket.private.phoenix_profiler_info == :disable + assert socket.private.phoenix_profiler.info == :disable :timer.sleep(10) assert {:disable, ^pid} = PhoenixProfiler.Utils.collector_info(profiler, socket) diff --git a/test/support/profiler_helper.exs b/test/support/profiler_helper.exs new file mode 100644 index 0000000..09343a5 --- /dev/null +++ b/test/support/profiler_helper.exs @@ -0,0 +1,29 @@ +defmodule ProfilerHelper do + @moduledoc """ + Helpers for testing profilers. + + Must not be used to test endpoints because they perform + some setup that could skew the results of the endpoint + tests. + """ + + import Plug.Conn, only: [put_private: 3] + alias PhoenixProfiler.Profiler + + defmacro __using__(_) do + quote do + use Plug.Test + import ProfilerHelper + end + end + + def profile_thru(%Plug.Conn{} = conn, endpoint) do + {:ok, profile} = Profiler.preflight(endpoint) + {:ok, pid} = Profiler.start_collector(conn, profile) + + conn + |> put_private(:phoenix_endpoint, endpoint) + |> put_private(:phoenix_profiler, profile) + |> put_private(:phoenix_profiler_collector, pid) + end +end diff --git a/test/test_helper.exs b/test/test_helper.exs index 2f970a5..81a5101 100644 --- a/test/test_helper.exs +++ b/test/test_helper.exs @@ -1,4 +1,5 @@ Code.require_file("support/endpoint_helper.exs", __DIR__) +Code.require_file("support/profiler_helper.exs", __DIR__) alias PhoenixProfiler.Integration.EndpointHelper From d83bc07000e400babf6ba80578aafe573b80394c Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Wed, 2 Mar 2022 22:22:39 -0800 Subject: [PATCH 22/38] Update collector controls on ToolbarLive --- lib/phoenix_profiler/toolbar/toolbar_live.ex | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.ex b/lib/phoenix_profiler/toolbar/toolbar_live.ex index 4e90cee..a5034df 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_live.ex +++ b/lib/phoenix_profiler/toolbar/toolbar_live.ex @@ -160,20 +160,15 @@ 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({TelemetryCollector, action}, _, socket) + def handle_call({PhoenixProfiler.TelemetryCollector, action}, _, socket) when action in [:disable, :enable] do - TelemetryRegistry.update_info(transport_pid(socket), fn _ -> action end) + TelemetryRegistry.update_info(Utils.transport_pid(socket), fn _ -> action end) {:reply, :ok, socket} end From a54ffb5419725708d2e726ace71dee076a96503b Mon Sep 17 00:00:00 2001 From: Michael Crumm Date: Wed, 2 Mar 2022 22:32:16 -0800 Subject: [PATCH 23/38] Fix empty toolbar render --- lib/phoenix_profiler/toolbar/toolbar_live.ex | 1 + lib/phoenix_profiler/toolbar/toolbar_live.html.leex | 4 ++-- 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.ex b/lib/phoenix_profiler/toolbar/toolbar_live.ex index a5034df..c78b7cd 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_live.ex +++ b/lib/phoenix_profiler/toolbar/toolbar_live.ex @@ -36,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, diff --git a/lib/phoenix_profiler/toolbar/toolbar_live.html.leex b/lib/phoenix_profiler/toolbar/toolbar_live.html.leex index a5d1030..f1b24c4 100644 --- a/lib/phoenix_profiler/toolbar/toolbar_live.html.leex +++ b/lib/phoenix_profiler/toolbar/toolbar_live.html.leex @@ -109,7 +109,7 @@
-
+ <%= if @profile.system[:elixir] do %>
@@ -142,7 +142,7 @@ Made with by @mcrumm
-
+
<% end %>