From 8d6427411e03cddf16e5999981cefe750a6457b9 Mon Sep 17 00:00:00 2001
From: Jeff Kreeftmeijer <jeff@kreeft.me>
Date: Tue, 20 Aug 2024 12:08:42 +0200
Subject: [PATCH] Add debug logging for endpoint-events

---
 lib/appsignal_phoenix/event_handler.ex | 73 ++++++++++++++++++++------
 1 file changed, 58 insertions(+), 15 deletions(-)

diff --git a/lib/appsignal_phoenix/event_handler.ex b/lib/appsignal_phoenix/event_handler.ex
index 3f6e415..b723d95 100644
--- a/lib/appsignal_phoenix/event_handler.ex
+++ b/lib/appsignal_phoenix/event_handler.ex
@@ -38,31 +38,58 @@ defmodule Appsignal.Phoenix.EventHandler do
   end
 
   def phoenix_endpoint_start(_event, _measurements, _metadata, _config) do
-    parent = @tracer.current_span()
+    parent_span = @tracer.current_span()
 
-    "http_request"
-    |> @tracer.create_span(parent)
+    span = "http_request"
+    |> @tracer.create_span(parent_span)
     |> @span.set_attribute("appsignal:category", "call.phoenix_endpoint")
+
+    Logger.debug(fn -> """
+    AppSignal.Phoenix.EventHandler received [:phoenix, :endpoint, :start]:
+      root_span: #{inspect(@tracer.root_span())}
+      parent_span: #{inspect(parent_span)}
+      span: #{inspect(span)}
+    """ end)
   end
 
   def phoenix_endpoint_stop(_event, _measurements, metadata, _config) do
-    _root_span = set_span_data(@tracer.root_span(), metadata)
+    root_span = set_span_data(@tracer.root_span(), metadata)
+    span = @tracer.current_span()
 
-    @tracer.current_span()
-    |> @tracer.close_span()
+    Logger.debug(fn -> """
+    AppSignal.Phoenix.EventHandler received [:phoenix, :endpoint, :stop]:
+      root_span: #{inspect(root_span)}
+      span: #{inspect(span)}
+    """ end)
+
+    @tracer.close_span(span)
   end
 
   def phoenix_router_dispatch_start(_event, _measurements, _metadata, _config) do
-    parent = @tracer.current_span()
+    parent_span = @tracer.current_span()
 
-    "http_request"
-    |> @tracer.create_span(parent)
+    span = "http_request"
+    |> @tracer.create_span(parent_span)
     |> @span.set_attribute("appsignal:category", "call.phoenix_router_dispatch")
+
+    Logger.debug(fn -> """
+    AppSignal.Phoenix.EventHandler received [:phoenix, :router_dispatch, :start]:
+      root_span: #{inspect(@tracer.root_span())}
+      parent_span: #{inspect(parent_span)}
+      span: #{inspect(span)}
+    """ end)
   end
 
   def phoenix_router_dispatch_stop(_event, _measurements, _metadata, _config) do
-    @tracer.current_span()
-    |> @tracer.close_span()
+    span = @tracer.current_span()
+
+    Logger.debug(fn -> """
+    AppSignal.Phoenix.EventHandler received [:phoenix, :router_dispatch, :stop]:
+      root_span: #{inspect(@tracer.root_span())}
+      span: #{inspect(span)}
+    """ end)
+
+    @tracer.close_span(span)
   end
 
   def phoenix_router_dispatch_exception(
@@ -71,7 +98,15 @@ defmodule Appsignal.Phoenix.EventHandler do
         %{reason: %Plug.Conn.WrapperError{conn: conn, reason: reason, stack: stack}},
         _config
       ) do
-    add_error(@tracer.root_span(), conn, reason, stack)
+    root_span = @tracer.root_span()
+
+    Logger.debug(fn -> """
+    AppSignal.Phoenix.EventHandler received [:phoenix, :router_dispatch, :exception]:
+      root_span: #{inspect(root_span)}
+      span: #{inspect(@tracer.current_span())}
+    """ end)
+
+    add_error(root_span, conn, reason, stack)
   end
 
   def phoenix_router_dispatch_exception(
@@ -80,7 +115,15 @@ defmodule Appsignal.Phoenix.EventHandler do
         %{conn: conn, reason: reason, stacktrace: stack},
         _config
       ) do
-    add_error(@tracer.root_span(), conn, reason, stack)
+    root_span = @tracer.root_span()
+
+    Logger.debug(fn -> """
+    AppSignal.Phoenix.EventHandler received [:phoenix, :router_dispatch, :exception]:
+      root_span: #{inspect(root_span)}
+      span: #{inspect(@tracer.current_span())}
+    """ end)
+
+    add_error(root_span, conn, reason, stack)
   end
 
   defp add_error(
@@ -106,10 +149,10 @@ defmodule Appsignal.Phoenix.EventHandler do
   end
 
   def phoenix_template_render_start(_event, _measurements, metadata, _config) do
-    parent = @tracer.current_span()
+    parent_span = @tracer.current_span()
 
     "http_request"
-    |> @tracer.create_span(parent)
+    |> @tracer.create_span(parent_span)
     |> @span.set_name(
       "Render #{inspect(metadata.template)} (#{metadata.format}) template from #{module_name(metadata.view)}"
     )