From f095d1f82cdf18ffc69226fd59ce36a7fc2ffb44 Mon Sep 17 00:00:00 2001
From: Jeff Kreeftmeijer <jeffkreeftmeijer@gmail.com>
Date: Tue, 22 Nov 2022 12:31:28 +0100
Subject: [PATCH] Add telemetry events to Controller.render_with_layouts/4
 (#5122)

Adding :telemetry events to the render_with_layouts/4 function in allows
APMs to record template rendering times, which was previously possible
through extending an app's view module, but not anymore from Phoenix 1.7
onward.
---
 lib/phoenix/controller.ex               | 22 +++++++--
 test/phoenix/controller/render_test.exs | 63 +++++++++++++++++++++++++
 2 files changed, 82 insertions(+), 3 deletions(-)

diff --git a/lib/phoenix/controller.ex b/lib/phoenix/controller.ex
index cd208cc5b4..98f20d571c 100644
--- a/lib/phoenix/controller.ex
+++ b/lib/phoenix/controller.ex
@@ -880,15 +880,31 @@ defmodule Phoenix.Controller do
     case root_layout(conn, format) do
       {layout_mod, layout_tpl} ->
         {layout_base, _} = split_template(layout_tpl)
-        inner = Phoenix.Template.render(view, template, format, render_assigns)
+        inner = template_render(view, template, format, render_assigns)
         root_assigns = render_assigns |> Map.put(:inner_content, inner) |> Map.delete(:layout)
-        Phoenix.Template.render_to_iodata(layout_mod, layout_base, format, root_assigns)
+        template_render_to_iodata(layout_mod, layout_base, format, root_assigns)
 
       false ->
-        Phoenix.Template.render_to_iodata(view, template, format, render_assigns)
+        template_render_to_iodata(view, template, format, render_assigns)
     end
   end
 
+  defp template_render(view, template, format, assigns) do
+    metadata = %{view: view, template: template, format: format}
+
+    :telemetry.span([:phoenix, :controller, :render], metadata, fn ->
+      {Phoenix.Template.render(view, template, format, assigns), metadata}
+    end)
+  end
+
+  defp template_render_to_iodata(view, template, format, assigns) do
+    metadata = %{view: view, template: template, format: format}
+
+    :telemetry.span([:phoenix, :controller, :render], metadata, fn ->
+      {Phoenix.Template.render_to_iodata(view, template, format, assigns), metadata}
+    end)
+  end
+
   defp prepare_assigns(conn, assigns, template, format) do
     assigns = to_map(assigns)
 
diff --git a/test/phoenix/controller/render_test.exs b/test/phoenix/controller/render_test.exs
index 76bb683154..b1b7c53e23 100644
--- a/test/phoenix/controller/render_test.exs
+++ b/test/phoenix/controller/render_test.exs
@@ -162,4 +162,67 @@ defmodule Phoenix.Controller.RenderTest do
       render(conn() |> put_view(nil), "index.html")
     end
   end
+
+  describe "telemetry" do
+    @render_start_event [:phoenix, :controller, :render, :start]
+    @render_stop_event [:phoenix, :controller, :render, :stop]
+    @render_exception_event [:phoenix, :controller, :render, :exception]
+
+    @render_events [
+      @render_start_event,
+      @render_stop_event,
+      @render_exception_event
+    ]
+
+    setup context do
+      test_pid = self()
+      test_name = context.test
+
+      :telemetry.attach_many(
+        test_name,
+        @render_events,
+        fn event, measures, metadata, config ->
+          send(test_pid, {:telemetry_event, event, {measures, metadata, config}})
+        end,
+        nil
+      )
+    end
+
+    test "phoenix.controller.render.start and .stop are emitted on success" do
+      render(conn(), "index.html", title: "Hello")
+
+      assert_received {:telemetry_event, [:phoenix, :controller, :render, :start],
+                       {_, %{format: "html", template: "index", view: MyApp.UserView}, _}}
+
+      assert_received {:telemetry_event, [:phoenix, :controller, :render, :stop],
+                       {_, %{format: "html", template: "index", view: MyApp.UserView}, _}}
+
+      refute_received {:telemetry_event, [:phoenix, :controller, :render, :exception], _}
+    end
+
+    test "phoenix.controller.render.exception is emitted on failure" do
+      :ok =
+        try do
+          render(conn(), "index.html")
+        rescue
+          ArgumentError ->
+            :ok
+        end
+
+      assert_received {:telemetry_event, [:phoenix, :controller, :render, :start],
+                       {_, %{format: "html", template: "index", view: MyApp.UserView}, _}}
+
+      refute_received {:telemetry_event, [:phoenix, :controller, :render, :stop], _}
+
+      assert_received {:telemetry_event, [:phoenix, :controller, :render, :exception],
+                       {_,
+                        %{
+                          format: "html",
+                          template: "index",
+                          view: MyApp.UserView,
+                          kind: :error,
+                          reason: %ArgumentError{}
+                        }, _}}
+    end
+  end
 end