phoenix telemetry

lib/dotcom/application.ex

@@ -27,6 +27,7 @@ defmodule Dotcom.Application do
     children =
       [
         {Application.get_env(:dotcom, :cache, Dotcom.Cache.Multilevel), []},
+        {Dotcom.Telemetry, []},
         {DotcomWeb.Telemetry, []},
         {Req.Telemetry, []}
       ] ++

lib/dotcom_web/stats.ex

@@ -6,9 +6,69 @@ defmodule DotcomWeb.Stats do
   use Agent
 
   @doc """
-  Starts the Agent and attaches to `[:phoenix, ...]` telemetry events.
+  Starts the Agent and attaches to `[:phoenix, :router_dispatch, :stop]` telemetry events.
   """
   def start_link(initial_value \\ %{}) do
+    :telemetry.attach(
+      "phoenix-router_dispatch-stop",
+      [:phoenix, :router_dispatch, :stop],
+      &__MODULE__.handle_event/4,
+      nil
+    )
+
     Agent.start_link(fn -> initial_value end, name: __MODULE__)
   end
+
+  @doc """
+  Handles telemetry events and aggregates them by path and status.
+  """
+  def handle_event(_name, measurement, metadata, _config) do
+    method = metadata.conn.method
+    path = metadata.route
+    status = metadata.conn.status
+    duration = measurement[:duration]
+
+    Agent.update(__MODULE__, fn state ->
+      if Kernel.get_in(state, [method, path, status]) do
+        Kernel.update_in(state, [method, path, status], &(&1 ++ [duration]))
+      else
+        Kernel.put_in(state, [Access.key(method, %{}), Access.key(path, %{}), status], [duration])
+      end
+    end)
+  end
+
+  @doc """
+  Dispatches the aggregated stats to the `[:phoenix, :router_dispatch, :stop]` telemetry event.
+
+  Resets the Agent state after dispatching the stats.
+  """
+  def dispatch_stats() do
+    Enum.each(Agent.get(__MODULE__, & &1), &dispatch_method/1)
+
+    Agent.update(__MODULE__, fn _ -> %{} end)
+  end
+
+  defp dispatch_method({method, stats}) do
+    Enum.each(stats, fn {path, statuses} ->
+      Enum.each(statuses, fn {status, durations} ->
+        dispatch_stat(method, path, status, durations)
+      end)
+    end)
+  end
+
+  defp dispatch_stat(method, path, status, durations) do
+    count = Enum.count(durations)
+
+    avg =
+      durations
+      |> Enum.sum()
+      |> Kernel.div(count)
+      |> System.convert_time_unit(:native, :millisecond)
+
+    :telemetry.execute([:dotcom_web, :request], %{count: count, avg: avg}, %{
+      method: method,
+      path: path,
+      status: status
+    })
+  end
 end

lib/dotcom_web/telemetry.ex

@@ -11,7 +11,6 @@ defmodule DotcomWeb.Telemetry do
     Supervisor.start_link(__MODULE__, arg, name: __MODULE__)
   end
 
-  @impl true
   def init(_arg) do
     telemetry_metrics_splunk_config = Application.get_env(:dotcom, :telemetry_metrics_splunk)
 
@@ -24,17 +23,26 @@ defmodule DotcomWeb.Telemetry do
           url: telemetry_metrics_splunk_config[:url]
         ]
       },
+      {
+        :telemetry_poller,
+        measurements: measurements(), period: :timer.seconds(60), init_delay: :timer.seconds(5)
+      },
       {DotcomWeb.Stats, %{}}
     ]
 
     Supervisor.init(children, strategy: :one_for_one)
   end
 
-  def measurements do
-    []
+  defp measurements do
+    [
+      {DotcomWeb.Stats, :dispatch_stats, []}
+    ]
   end
 
-  def metrics do
-    []
+  defp metrics do
+    [
+      Metrics.last_value("dotcom_web.request.count"),
+      Metrics.last_value("dotcom_web.request.avg")
+    ]
   end
 end

lib/telemetry/helper.ex

@@ -0,0 +1,57 @@
+defmodule Telemetry.Helper do
+  @moduledoc """
+  Helper functions for seeing all telemetry events.
+
+  Only for use in development.
+  """
+
+  require Logger
+
+  @doc """
+  Attach to all telemetry events and log them.
+
+  You can pass in a filter so that you only see telemetry events for a specific module.
+  E.g., if you want to see all telemetry events for Phoenix you can pass in `[:phoenix]`.
+  For more specific events you can pass in more specific names like `[:phoenix, :router_dispatch]` or `[:phoenix, :router_dispatch, :stop]`.
+  """
+  def attach(filter \\ nil) do
+    # Start the tracer
+    :dbg.start()
+
+    # Create tracer process with a function that pattern matches out the three arguments the telemetry calls are made with.
+    :dbg.tracer(
+      :process,
+      {
+        fn
+          {_, _, _, {_mod, :execute, [name, measurement, metadata]}}, _state ->
+            handler(name, metadata, measurement, filter)
+        end,
+        nil
+      }
+    )
+
+    # Trace all processes
+    :dbg.p(:all, :c)
+
+    # Trace calls to the functions used to emit telemetry events
+    :dbg.tp(:telemetry, :execute, 3, [])
+  end
+
+  def stop do
+    :dbg.stop()
+  end
+
+  defp handler(name, metadata, measure, filter) do
+    unless filtered?(name, filter) do
+      IO.inspect(%{name: name, metadata: metadata, measure: measure})
+    end
+  end
+
+  defp filtered?(name, filter) when is_atom(name), do: name == filter
+
+  defp filtered?(_, nil), do: false
+
+  defp filtered?(name, filter) do
+    not Enum.all?(filter, fn entry -> Enum.member?(name, entry) end)
+  end
+end

mix.exs

@@ -143,7 +143,7 @@ defmodule DotCom.Mixfile do
       {:sweet_xml, "0.7.4", only: [:prod, :dev]},
       {:telemetry, "1.2.1", override: true},
       {:telemetry_metrics, "1.0.0", override: true},
-      {:telemetry_metrics_splunk, "0.0.1-alpha"},
+      {:telemetry_metrics_splunk, "0.0.2-alpha"},
       {:telemetry_poller, "1.1.0"},
       {:telemetry_test, "0.1.2", only: [:test]},
       # latest version is 3.7.11; cannot upgrade because tests fail

mix.lock

@@ -100,7 +100,7 @@
   "sweet_xml": {:hex, :sweet_xml, "0.7.4", "a8b7e1ce7ecd775c7e8a65d501bc2cd933bff3a9c41ab763f5105688ef485d08", [:mix], [], "hexpm", "e7c4b0bdbf460c928234951def54fe87edf1a170f6896675443279e2dbeba167"},
   "telemetry": {:hex, :telemetry, "1.2.1", "68fdfe8d8f05a8428483a97d7aab2f268aaff24b49e0f599faa091f1d4e7f61c", [:rebar3], [], "hexpm", "dad9ce9d8effc621708f99eac538ef1cbe05d6a874dd741de2e689c47feafed5"},
   "telemetry_metrics": {:hex, :telemetry_metrics, "1.0.0", "29f5f84991ca98b8eb02fc208b2e6de7c95f8bb2294ef244a176675adc7775df", [:mix], [{:telemetry, "~> 0.4 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "f23713b3847286a534e005126d4c959ebcca68ae9582118ce436b521d1d47d5d"},
-  "telemetry_metrics_splunk": {:hex, :telemetry_metrics_splunk, "0.0.1-alpha", "2104f9d79d5a278edde4976ce0905f09abfade81a5b4e96972a9d35618a89ea8", [:mix], [{:jason, "1.4.1", [hex: :jason, repo: "hexpm", optional: false]}, {:recase, "0.7.0", [hex: :recase, repo: "hexpm", optional: false]}, {:telemetry, "1.2.1", [hex: :telemetry, repo: "hexpm", optional: false]}, {:telemetry_metrics, "1.0.0", [hex: :telemetry_metrics, repo: "hexpm", optional: false]}], "hexpm", "2f40676055ee8a44f6a2515be9ee171016a9635de66ddb3f4c86cf4b23169306"},
+  "telemetry_metrics_splunk": {:hex, :telemetry_metrics_splunk, "0.0.2-alpha", "f0a25d582b4315b5461840a55c77f2b0ad625c8afceaec56ce0b198f6c87f741", [:mix], [{:jason, "1.4.1", [hex: :jason, repo: "hexpm", optional: false]}, {:recase, "0.7.0", [hex: :recase, repo: "hexpm", optional: false]}, {:telemetry, "1.2.1", [hex: :telemetry, repo: "hexpm", optional: false]}, {:telemetry_metrics, "1.0.0", [hex: :telemetry_metrics, repo: "hexpm", optional: false]}], "hexpm", "c6ea80ee987a19df3c5d3bb87a5b94c3acf4a8d4df778e0f3ede2987426eba8f"},
   "telemetry_metrics_statsd": {:hex, :telemetry_metrics_statsd, "0.7.0", "92732fae63db31ef2508df6faee7d81401883e33f2976715a82f296a33a45cee", [:mix], [{:nimble_options, "~> 0.4 or ~> 1.0", [hex: :nimble_options, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}, {:telemetry_metrics, "~> 0.6", [hex: :telemetry_metrics, repo: "hexpm", optional: false]}], "hexpm", "797e34a856376dfd4e96347da0f747fcff4e0cadf6e6f0f989598f563cad05ff"},
   "telemetry_poller": {:hex, :telemetry_poller, "1.1.0", "58fa7c216257291caaf8d05678c8d01bd45f4bdbc1286838a28c4bb62ef32999", [:rebar3], [{:telemetry, "~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "9eb9d9cbfd81cbd7cdd24682f8711b6e2b691289a0de6826e58452f28c103c8f"},
   "telemetry_test": {:hex, :telemetry_test, "0.1.2", "122d927567c563cf57773105fa8104ae4299718ec2cbdddcf6776562c7488072", [:mix], [{:telemetry, "~> 1.2", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "7bd41a49ecfd33ecd82d2c7edae19a5736f0d2150206d0ee290dcf3885d0e14d"},