Fix flow tracking in AsyncDataloader

rmosolgo · Jan 31, 2025 · f0d6077 · f0d6077
1 parent 201a42f
commit f0d6077
Show file tree

Hide file tree

Showing 4 changed files with 100 additions and 31 deletions.
diff --git a/lib/graphql/execution/interpreter/runtime.rb b/lib/graphql/execution/interpreter/runtime.rb
@@ -246,7 +246,6 @@ def evaluate_selections(gathered_selections, selections_result, target_result, r
         # @return [void]
         def evaluate_selection(result_name, field_ast_nodes_or_ast_node, selections_result) # rubocop:disable Metrics/ParameterLists
           return if selections_result.graphql_dead
-          @current_trace.begin_execute_field(selections_result, result_name)
           # As a performance optimization, the hash key will be a `Node` if
           # there's only one selection of the field. But if there are multiple
           # selections of the field, it will be an Array of nodes
@@ -376,6 +375,7 @@ def evaluate_selection_with_resolved_keyword_args(kwarg_arguments, resolved_argu
             end
             # Actually call the field resolver and capture the result
             app_result = begin
+              @current_trace.begin_execute_field(selection_result, result_name)
               @current_trace.execute_field(field: field_defn, ast_node: ast_node, query: query, object: object, arguments: kwarg_arguments) do
                 field_defn.resolve(object, kwarg_arguments, context)
               end

diff --git a/lib/graphql/tracing/appoptics_trace.rb b/lib/graphql/tracing/appoptics_trace.rb
@@ -83,7 +83,7 @@ def execute_field(query:, field:, ast_node:, arguments:, object:)
         end
       end
 
-      def execute_field_lazy(query:, field:, ast_node:, arguments:, object:)
+      def execute_field_lazy(query:, field:, ast_node:, arguments:, object:)  # rubocop:disable Development/TraceCallsSuperCop
         execute_field(query: query, field: field, ast_node: ast_node, arguments: arguments, object: object)
       end
 

diff --git a/spec/graphql/dataloader/async_dataloader_spec.rb b/spec/graphql/dataloader/async_dataloader_spec.rb
@@ -322,7 +322,6 @@ class TraceAsyncSchema < AsyncSchema
       include AsyncDataloaderAssertions
       include PerfettoSnapshot
 
-      focus
       it "produces a trace" do
         query_str = <<-GRAPHQL
         {

diff --git a/spec/graphql/dataloader/snapshots/example.json b/spec/graphql/dataloader/snapshots/example.json
@@ -196,24 +196,60 @@
         "name": ".s1",
         "extraCounterTrackUuids": [
           "10101010101010"
+        ],
+        "flowIds": [
+          "10101010101010"
         ]
       }
     },
     {
       "timestamp": "10101010101010",
       "trustedPacketSequenceId": 101010101010,
       "trackEvent": {
-        "type": "TYPE_SLICE_BEGIN",
+        "type": "TYPE_SLICE_END",
+        "trackUuid": "10101010101010"
+      }
+    },
+    {
+      "timestamp": "10101010101010",
+      "trustedPacketSequenceId": 101010101010,
+      "trackEvent": {
+        "type": "TYPE_INSTANT",
+        "trackUuid": "10101010101010",
+        "categories": [
+          "dataloader"
+        ],
+        "name": "Fiber Yield"
+      }
+    },
+    {
+      "timestamp": "10101010101010",
+      "trustedPacketSequenceId": 101010101010,
+      "trackEvent": {
+        "type": "TYPE_INSTANT",
         "trackUuid": "10101010101010",
         "extraCounterValues": [
+          "10101010101010",
           "10101010101010"
         ],
-        "name": ".s2",
+        "categories": [
+          "dataloader"
+        ],
+        "name": "Create Execution Fiber",
         "extraCounterTrackUuids": [
+          "10101010101010",
           "10101010101010"
         ]
       }
     },
+    {
+      "trackDescriptor": {
+        "uuid": "10101010101010",
+        "name": "Exec Fiber #1010",
+        "parentUuid": "10101010101010",
+        "childOrdering": "CHRONOLOGICAL"
+      }
+    },
     {
       "timestamp": "10101010101010",
       "trustedPacketSequenceId": 101010101010,
@@ -223,7 +259,7 @@
         "extraCounterValues": [
           "10101010101010"
         ],
-        "name": ".s3",
+        "name": ".s2",
         "extraCounterTrackUuids": [
           "10101010101010"
         ],
@@ -284,40 +320,26 @@
       "timestamp": "10101010101010",
       "trustedPacketSequenceId": 101010101010,
       "trackEvent": {
-        "type": "TYPE_INSTANT",
-        "trackUuid": "10101010101010",
-        "categories": [
-          "dataloader"
-        ],
-        "name": "Fiber Yield"
-      }
-    },
-    {
-      "timestamp": "10101010101010",
-      "trustedPacketSequenceId": 101010101010,
-      "trackEvent": {
-        "type": "TYPE_INSTANT",
+        "type": "TYPE_SLICE_BEGIN",
         "trackUuid": "10101010101010",
         "extraCounterValues": [
-          "10101010101010",
           "10101010101010"
         ],
-        "categories": [
-          "dataloader"
-        ],
-        "name": "Create Execution Fiber",
+        "name": ".s3",
         "extraCounterTrackUuids": [
-          "10101010101010",
+          "10101010101010"
+        ],
+        "flowIds": [
           "10101010101010"
         ]
       }
     },
     {
-      "trackDescriptor": {
-        "uuid": "10101010101010",
-        "name": "Exec Fiber #1010",
-        "parentUuid": "10101010101010",
-        "childOrdering": "CHRONOLOGICAL"
+      "timestamp": "10101010101010",
+      "trustedPacketSequenceId": 101010101010,
+      "trackEvent": {
+        "type": "TYPE_SLICE_END",
+        "trackUuid": "10101010101010"
       }
     },
     {
@@ -444,6 +466,9 @@
         "name": "AsyncSchema::SleepSource",
         "extraCounterTrackUuids": [
           "10101010101010"
+        ],
+        "flowIds": [
+          "10101010101010"
         ]
       }
     },
@@ -500,6 +525,9 @@
         "name": "AsyncSchema::SleepSource",
         "extraCounterTrackUuids": [
           "10101010101010"
+        ],
+        "flowIds": [
+          "10101010101010"
         ]
       }
     },
@@ -764,7 +792,7 @@
         "extraCounterValues": [
           "10101010101010"
         ],
-        "name": ".s3",
+        "name": ".s1",
         "extraCounterTrackUuids": [
           "10101010101010"
         ],
@@ -842,6 +870,24 @@
         "name": "Fiber Resume"
       }
     },
+    {
+      "timestamp": "10101010101010",
+      "trustedPacketSequenceId": 101010101010,
+      "trackEvent": {
+        "type": "TYPE_SLICE_BEGIN",
+        "trackUuid": "10101010101010",
+        "extraCounterValues": [
+          "10101010101010"
+        ],
+        "name": ".s2",
+        "extraCounterTrackUuids": [
+          "10101010101010"
+        ],
+        "flowIds": [
+          "10101010101010"
+        ]
+      }
+    },
     {
       "timestamp": "10101010101010",
       "trustedPacketSequenceId": 101010101010,
@@ -855,6 +901,9 @@
         "extraCounterTrackUuids": [
           "10101010101010",
           "10101010101010"
+        ],
+        "terminatingFlowIds": [
+          "10101010101010"
         ]
       }
     },
@@ -908,6 +957,24 @@
         "name": "Fiber Resume"
       }
     },
+    {
+      "timestamp": "10101010101010",
+      "trustedPacketSequenceId": 101010101010,
+      "trackEvent": {
+        "type": "TYPE_SLICE_BEGIN",
+        "trackUuid": "10101010101010",
+        "extraCounterValues": [
+          "10101010101010"
+        ],
+        "name": ".s3",
+        "extraCounterTrackUuids": [
+          "10101010101010"
+        ],
+        "flowIds": [
+          "10101010101010"
+        ]
+      }
+    },
     {
       "timestamp": "10101010101010",
       "trustedPacketSequenceId": 101010101010,
@@ -921,6 +988,9 @@
         "extraCounterTrackUuids": [
           "10101010101010",
           "10101010101010"
+        ],
+        "terminatingFlowIds": [
+          "10101010101010"
         ]
       }
     },
-Original file line number
+Diff line change
@@ Expand Up @@
             end
           end
-          def execute_field_lazy(query:, field:, ast_node:, arguments:, object:)
+          def execute_field_lazy(query:, field:, ast_node:, arguments:, object:)  # rubocop:disable Development/TraceCallsSuperCop
             execute_field(query: query, field: field, ast_node: ast_node, arguments: arguments, object: object)
           end
@@ Expand Down @@