Split telemetry into parse, validate and execution

lib/absinthe/phase/document/validation/init.ex

@@ -0,0 +1,27 @@
+defmodule Absinthe.Phase.Document.Validation.Init do
+  @moduledoc false
+
+  # Init validation
+
+  alias Absinthe.{Blueprint, Phase}
+
+  use Absinthe.Phase
+
+  @doc """
+  Run the validation.
+  """
+  @spec run(Blueprint.t(), Keyword.t()) :: Phase.result_t()
+  def run(blueprint, _options \\ []) do
+    id = :erlang.unique_integer()
+    system_time = System.system_time()
+    start_time_mono = System.monotonic_time()
+
+    :telemetry.execute(
+      [:absinthe, :validate, :start],
+      %{system_time: system_time},
+      %{telemetry_span_context: id, blueprint: blueprint}
+    )
+
+    {:ok, %{blueprint | telemetry: %{id: id, start_time_mono: start_time_mono}}}
+  end
+end

lib/absinthe/phase/document/validation/result.ex

@@ -22,6 +22,16 @@ defmodule Absinthe.Phase.Document.Validation.Result do
     errors = :lists.reverse(errors)
     result = put_in(input.execution.validation_errors, errors)
 
+    with %{id: id, start_time_mono: start_time_mono} <- result.telemetry do
+      end_time_mono = System.monotonic_time()
+
+      :telemetry.execute(
+        [:absinthe, :validate, :stop],
+        %{duration: end_time_mono - start_time_mono},
+        %{telemetry_span_context: id, blueprint: result}
+      )
+    end
+
     case {errors, jump} do
       {[], _} ->
         {:ok, result}

lib/absinthe/phase/init.ex

@@ -9,7 +9,7 @@ defmodule Absinthe.Phase.Init do
   def run(input, _options \\ []) do
     {:record_phases, make_blueprint(input),
      fn bp, phases ->
-       %{bp | initial_phases: phases}
+       %{bp | initial_phases: phases, source: bp.input}
      end}
   end
 

lib/absinthe/phase/parse.ex

@@ -12,17 +12,22 @@ defmodule Absinthe.Phase.Parse do
   def run(input, options \\ [])
 
   def run(%Absinthe.Blueprint{} = blueprint, options) do
-    options = Map.new(options)
-
-    case parse(blueprint.input) do
-      {:ok, value} ->
-        {:ok, %{blueprint | input: value}}
-
-      {:error, error} ->
-        blueprint
-        |> add_validation_error(error)
-        |> handle_error(options)
-    end
+    :telemetry.span([:absinthe, :parse], %{}, fn ->
+      options = Map.new(options)
+
+      result =
+        case parse(blueprint.input) do
+          {:ok, value} ->
+            {:ok, %{blueprint | input: value}}
+
+          {:error, error} ->
+            blueprint
+            |> add_validation_error(error)
+            |> handle_error(options)
+        end
+
+      {result, %{}}
+    end)
   end
 
   def run(input, options) do

lib/absinthe/phase/telemetry.ex

@@ -29,8 +29,7 @@ defmodule Absinthe.Phase.Telemetry do
     {:ok,
      %{
        blueprint
-       | source: blueprint.input,
-         telemetry: %{id: id, start_time_mono: start_time_mono}
+       | telemetry: %{id: id, start_time_mono: start_time_mono}
      }}
   end
 

lib/absinthe/pipeline.ex

@@ -52,7 +52,6 @@ defmodule Absinthe.Pipeline do
 
     [
       Phase.Init,
-      {Phase.Telemetry, Keyword.put(options, :event, [:execute, :operation, :start])},
       # Parse Document
       {Phase.Parse, options},
       # Convert to Blueprint
@@ -63,6 +62,7 @@ defmodule Absinthe.Pipeline do
       # Mark Fragment/Variable Usage
       Phase.Document.Uses,
       # Validate Document Structure
+      Phase.Document.Validation.Init,
       {Phase.Document.Validation.NoFragmentCycles, options},
       Phase.Document.Validation.LoneAnonymousOperation,
       {Phase.Document.Validation.SelectedCurrentOperation, options},
@@ -105,6 +105,7 @@ defmodule Absinthe.Pipeline do
       # Check Validation
       {Phase.Document.Validation.Result, options},
       # Prepare for Execution
+      {Phase.Telemetry, Keyword.put(options, :event, [:execute, :operation, :start])},
       Phase.Document.Arguments.Data,
       # Apply Directives
       Phase.Document.Directives,
@@ -114,9 +115,9 @@ defmodule Absinthe.Pipeline do
       # Execution
       {Phase.Subscription.SubscribeSelf, options},
       {Phase.Document.Execution.Resolution, options},
+      {Phase.Telemetry, Keyword.put(options, :event, [:execute, :operation, :stop])},
       # Format Result
-      Phase.Document.Result,
-      {Phase.Telemetry, Keyword.put(options, :event, [:execute, :operation, :stop])}
+      Phase.Document.Result
     ]
   end
 

test/absinthe/pipeline_test.exs

@@ -21,7 +21,7 @@ defmodule Absinthe.PipelineTest do
         Pipeline.for_document(Schema)
         |> Pipeline.upto(Phase.Blueprint)
 
-      assert {:ok, %Blueprint{}, [Phase.Blueprint, Phase.Parse, Phase.Telemetry, Phase.Init]} =
+      assert {:ok, %Blueprint{}, [Phase.Blueprint, Phase.Parse, Phase.Init]} =
                Pipeline.run(@query, pipeline)
     end
   end