GraphQL: Report multiple query errors

lib/datadog/tracing/contrib/graphql/ext.rb

@@ -13,6 +13,9 @@ module Ext
           ENV_ANALYTICS_SAMPLE_RATE = 'DD_TRACE_GRAPHQL_ANALYTICS_SAMPLE_RATE'
           SERVICE_NAME = 'graphql'
           TAG_COMPONENT = 'graphql'
+
+          # Span event name for query-level errors
+          EVENT_QUERY_ERROR = 'dd.graphql.query.error'
         end
       end
     end

lib/datadog/tracing/contrib/graphql/unified_trace.rb

@@ -17,44 +17,74 @@ def initialize(*args, **kwargs)
           end
 
           def lex(*args, query_string:, **kwargs)
-            trace(proc { super }, 'lex', query_string, query_string: query_string)
+            trace(proc { super }, 'lex', query_string, { query_string: query_string })
           end
 
           def parse(*args, query_string:, **kwargs)
-            trace(proc { super }, 'parse', query_string, query_string: query_string) do |span|
-              span.set_tag('graphql.source', query_string)
-            end
+            trace(
+              proc { super },
+              'parse',
+              query_string,
+              { query_string: query_string },
+              before: ->(span) { span.set_tag('graphql.source', query_string) }
+            )
           end
 
           def validate(*args, query:, validate:, **kwargs)
-            trace(proc { super }, 'validate', query.selected_operation_name, query: query, validate: validate) do |span|
-              span.set_tag('graphql.source', query.query_string)
-            end
+            trace(
+              proc {
+                super
+              },
+              'validate',
+              query.selected_operation_name,
+              { query: query, validate: validate },
+              before: ->(span) { span.set_tag('graphql.source', query.query_string) }
+            )
           end
 
           def analyze_multiplex(*args, multiplex:, **kwargs)
-            trace(proc { super }, 'analyze_multiplex', multiplex_resource(multiplex), multiplex: multiplex)
+            trace(proc { super }, 'analyze_multiplex', multiplex_resource(multiplex), { multiplex: multiplex })
           end
 
           def analyze_query(*args, query:, **kwargs)
-            trace(proc { super }, 'analyze', query.query_string, query: query)
+            trace(proc { super }, 'analyze', query.query_string, { query: query })
           end
 
           def execute_multiplex(*args, multiplex:, **kwargs)
-            trace(proc { super }, 'execute_multiplex', multiplex_resource(multiplex), multiplex: multiplex) do |span|
-              span.set_tag('graphql.source', "Multiplex[#{multiplex.queries.map(&:query_string).join(', ')}]")
-            end
+            trace(
+              proc {
+                super
+              },
+              'execute_multiplex',
+              multiplex_resource(multiplex),
+              { multiplex: multiplex },
+              before: lambda { |span|
+                span.set_tag('graphql.source', "Multiplex[#{multiplex.queries.map(&:query_string).join(', ')}]")
+              }
+            )
           end
 
           def execute_query(*args, query:, **kwargs)
-            trace(proc { super }, 'execute', query.selected_operation_name, query: query) do |span|
-              span.set_tag('graphql.source', query.query_string)
-              span.set_tag('graphql.operation.type', query.selected_operation.operation_type)
-              span.set_tag('graphql.operation.name', query.selected_operation_name) if query.selected_operation_name
-              query.variables.instance_variable_get(:@storage).each do |key, value|
-                span.set_tag("graphql.variables.#{key}", value)
-              end
-            end
+            trace(
+              proc { super },
+              'execute',
+              query.selected_operation_name,
+              { query: query },
+              before: lambda { |span|
+                span.set_tag('graphql.source', query.query_string)
+                span.set_tag('graphql.operation.type', query.selected_operation.operation_type)
+                if query.selected_operation_name
+                  span.set_tag(
+                    'graphql.operation.name',
+                    query.selected_operation_name
+                  )
+                end
+                query.variables.instance_variable_get(:@storage).each do |key, value|
+                  span.set_tag("graphql.variables.#{key}", value)
+                end
+              },
+              after: ->(span) { add_query_error_events(span, query.context.errors) }
+            )
           end
 
           def execute_query_lazy(*args, query:, multiplex:, **kwargs)
@@ -63,19 +93,25 @@ def execute_query_lazy(*args, query:, multiplex:, **kwargs)
                        else
                          multiplex_resource(multiplex)
                        end
-            trace(proc { super }, 'execute_lazy', resource, query: query, multiplex: multiplex)
+            trace(proc { super }, 'execute_lazy', resource, { query: query, multiplex: multiplex })
           end
 
           def execute_field_span(callable, span_key, **kwargs)
             # @platform_key_cache is initialized upstream, in ::GraphQL::Tracing::PlatformTrace
             platform_key = @platform_key_cache[UnifiedTrace].platform_field_key_cache[kwargs[:field]]
 
             if platform_key
-              trace(callable, span_key, platform_key, **kwargs) do |span|
-                kwargs[:arguments].each do |key, value|
-                  span.set_tag("graphql.variables.#{key}", value)
-                end
-              end
+              trace(
+                callable,
+                span_key,
+                platform_key,
+                kwargs,
+                before: lambda { |span|
+                  kwargs[:arguments].each do |key, value|
+                    span.set_tag("graphql.variables.#{key}", value)
+                  end
+                }
+              )
             else
               callable.call
             end
@@ -89,9 +125,10 @@ def execute_field_lazy(*args, **kwargs)
             execute_field_span(proc { super }, 'resolve_lazy', **kwargs)
           end
 
-          def authorized_span(callable, span_key, **kwargs)
+          def authorized_span(callable, span_key, *args, **kwargs)
+            puts "authorized_span:authorized_span:#{callable},#{span_key},#{args},#{kwargs}"
             platform_key = @platform_key_cache[UnifiedTrace].platform_authorized_key_cache[kwargs[:type]]
-            trace(callable, span_key, platform_key, **kwargs)
+            trace(callable, span_key, platform_key, kwargs)
           end
 
           def authorized(*args, **kwargs)
@@ -104,7 +141,7 @@ def authorized_lazy(*args, **kwargs)
 
           def resolve_type_span(callable, span_key, **kwargs)
             platform_key = @platform_key_cache[UnifiedTrace].platform_resolve_type_key_cache[kwargs[:type]]
-            trace(callable, span_key, platform_key, **kwargs)
+            trace(callable, span_key, platform_key, kwargs)
           end
 
           def resolve_type(*args, **kwargs)
@@ -131,7 +168,15 @@ def platform_resolve_type_key(type, *args, **kwargs)
 
           private
 
-          def trace(callable, trace_key, resource, **kwargs)
+          # Traces the given callable with the given trace key, resource, and kwargs.
+          #
+          # @param callable [Proc] the original method call
+          # @param trace_key [String] the sub-operation name (`"graphql.#{trace_key}"`)
+          # @param resource [String] the resource name for the trace
+          # @param kwargs [Hash] the arguments to pass to `prepare_span`
+          # @param before [Proc, nil] a callable to run before the trace
+          # @param after [Proc, nil] a callable to run after the trace, which has access to query values after execution
+          def trace(callable, trace_key, resource, kwargs, before: nil, after: nil)
             config = Datadog.configuration.tracing[:graphql]
 
             Tracing.trace(
@@ -144,11 +189,15 @@ def trace(callable, trace_key, resource, **kwargs)
                 Contrib::Analytics.set_sample_rate(span, config[:analytics_sample_rate])
               end
 
-              yield(span) if block_given?
+              before.call(span) if before
 
               prepare_span(trace_key, kwargs, span) if @has_prepare_span
 
-              callable.call
+              ret = callable.call
+
+              after.call(span) if after
+
+              ret
             end
           end
 
@@ -163,6 +212,44 @@ def multiplex_resource(multiplex)
               operations
             end
           end
+
+          # Create a Span Event for each error that occurs at query level.
+          #
+          # These are represented in the Datadog App as special GraphQL errors,
+          # given their event name `dd.graphql.query.error`.
+          def add_query_error_events(span, errors)
+            errors.each do |error|
+              e = Core::Error.build_from(error)
+              err = error.to_h
+
+              span.span_events << Datadog::Tracing::SpanEvent.new(
+                Ext::EVENT_QUERY_ERROR,
+                attributes: {
+                  message: err['message'],
+                  type: e.type,
+                  stacktrace: e.backtrace,
+                  locations: serialize_error_locations(err['locations']),
+                  path: err['path'],
+                }
+              )
+            end
+          end
+
+          # Serialize error's `locations` array as an array of Strings, given
+          # Span Events do not support hashes nested inside arrays.
+          #
+          # Here's an example in which `locations`:
+          #   [
+          #    {"line" => 3, "column" => 10},
+          #    {"line" => 7, "column" => 8},
+          #   ]
+          # is serialized as:
+          #   ["3:10", "7:8"]
+          def serialize_error_locations(locations)
+            locations.map do |location|
+              "#{location['line']}:#{location['column']}"
+            end
+          end
         end
       end
     end

sig/datadog/core/error.rbs

@@ -1,25 +1,28 @@
 module Datadog
   module Core
     class Error
-      attr_reader type: untyped
+      attr_reader type: String
 
-      attr_reader message: untyped
+      attr_reader message: String
 
-      attr_reader backtrace: untyped
+      attr_reader backtrace: String
 
-      def self.build_from: (untyped value) -> untyped
+      interface _ContainsMessage
+        def message: () -> String
+      end
+
+      def self.build_from: ((Error | Array[untyped] | ::Exception | _ContainsMessage | ::String) value) -> Error
 
       private
-      def self.full_backtrace: (untyped ex) -> untyped
-      def self.backtrace_for: (untyped ex, untyped backtrace) -> (nil | untyped)
+      def self.full_backtrace: (Exception ex) -> String
+      def self.backtrace_for: (Exception ex, String backtrace) -> void
 
       public
 
-      def initialize: (?untyped? `type`, ?untyped? message, ?untyped? backtrace) -> void
-
-      BlankError: untyped
+      def initialize: (?Object? `type`, ?Object? message, ?Object? backtrace) -> void
 
-      ContainsMessage: untyped
+      BlankError: Error
+      ContainsMessage: ^(Object) -> bool
     end
   end
 end

sig/datadog/core/utils.rbs

@@ -5,7 +5,7 @@ module Datadog
 
       EMPTY_STRING: untyped
       def self.truncate: (untyped value, untyped size, ?untyped omission) -> untyped
-      def self.utf8_encode: (untyped str, ?binary: bool, ?placeholder: untyped) -> untyped
+      def self.utf8_encode: (Object str, ?binary: bool, ?String: untyped) -> String
       def self.without_warnings: () { () -> untyped } -> untyped
       def self.extract_host_port: (untyped host_port) -> (nil | ::Array[untyped])
     end

sig/datadog/tracing/contrib/graphql/ext.rbs

@@ -9,6 +9,7 @@ module Datadog
 
           ENV_ANALYTICS_SAMPLE_RATE: "DD_TRACE_GRAPHQL_ANALYTICS_SAMPLE_RATE"
 
+          EVENT_QUERY_ERROR: String
           SERVICE_NAME: "graphql"
 
           TAG_COMPONENT: "graphql"

sig/datadog/tracing/contrib/graphql/unified_trace.rbs

@@ -65,8 +65,12 @@ module Datadog
           type traceKwargsValues = GraphQL::Query | GraphQL::Schema::Union | GraphQL::Schema::Object | GraphQL::Schema::Field | GraphQL::Execution::Multiplex | GraphQL::Language::Nodes::Field | Hash[Symbol, String] | String | bool | nil
 
           type traceResult = lexerArray | GraphQL::Language::Nodes::Document | { remaining_timeout: Float?, error: Array[StandardError] } | Array[Object] | GraphQL::Schema::Object? | [GraphQL::Schema::Object, nil]
-
-          def trace: (Proc callable, String trace_key, String resource, **Hash[Symbol, traceKwargsValues ] kwargs) ?{ (Datadog::Tracing::SpanOperation) -> void } -> traceResult
+
+          def add_query_error_events: (SpanOperation span, Array[::GraphQL::Error] errors) -> void
+
+          def serialize_error_locations: (Array[{"line" => Integer, "column" => Integer}] locations)-> Array[String]
+
+          def trace: (Proc callable, String trace_key, String resource, ?Hash[Symbol, traceKwargsValues ] kwargs, ?before: ^(SpanOperation)-> void, ?after: ^(SpanOperation)-> void) ?{ (SpanOperation) -> void } -> traceResult
 
           def multiplex_resource: (GraphQL::Execution::Multiplex multiplex) -> String?
         end

spec/datadog/tracing/contrib/graphql/support/application_schema.rb

@@ -63,6 +63,12 @@ def userByName(name:)
       OpenStruct.new(id: 1, name: name)
     end
 
+    field :unexpected_error, UserType, description: 'Raises error'
+
+    def unexpected_error
+      raise 'Unexpected error'
+    end
+
     field :mutationUserByName, UserType, null: false, description: 'Find an user by name' do
       argument :name, ::GraphQL::Types::String, required: true
     end

spec/datadog/tracing/contrib/graphql/test_schema_examples.rb

@@ -22,6 +22,12 @@ class #{prefix}TestGraphQLQuery < ::GraphQL::Schema::Object
       def user(id:)
         OpenStruct.new(id: id, name: 'Bits')
       end
+
+      field :graphql_error, ::GraphQL::Types::Int, description: 'Raises error'
+
+      def graphql_error
+        raise ::GraphQL::ExecutionError, 'GraphQL error'
+      end
     end
 
     class #{prefix}TestGraphQLSchema < ::GraphQL::Schema
@@ -76,10 +82,11 @@ def unload_test_schema(prefix: '')
 end
 
 RSpec.shared_examples 'graphql instrumentation with unified naming convention trace' do |prefix: ''|
+  let(:schema) { Object.const_get("#{prefix}TestGraphQLSchema") }
+  let(:service) { defined?(super) ? super() : tracer.default_service }
+
   describe 'query trace' do
     subject(:result) { schema.execute(query: 'query Users($var: ID!){ user(id: $var) { name } }', variables: { var: 1 }) }
-    let(:schema) { Object.const_get("#{prefix}TestGraphQLSchema") }
-    let(:service) { defined?(super) ? super() : tracer.default_service }
 
     matrix = [
       ['graphql.analyze', 'query Users($var: ID!){ user(id: $var) { name } }'],
@@ -134,4 +141,41 @@ def unload_test_schema(prefix: '')
       end
     end
   end
+
+  describe 'query with a GraphQL error' do
+    subject(:result) { schema.execute(query: 'query Error{ graphqlError }', variables: { var: 1 }) }
+
+    let(:graphql_execute) { spans.find { |s| s.name == 'graphql.execute' } }
+
+    it 'creates query span for error' do
+      expect(result.to_h['errors']).to contain_exactly(
+        'message' => 'GraphQL error',
+        'locations' => [{ 'line' => 1, 'column' => 14 }],
+        'path' => ['graphqlError']
+      )
+      expect(result.to_h['data']).to eq('graphqlError' => nil)
+
+      expect(graphql_execute.resource).to eq('Error')
+      expect(graphql_execute.service).to eq(service)
+      expect(graphql_execute.type).to eq('graphql')
+
+      expect(graphql_execute.get_tag('graphql.source')).to eq('query Error{ graphqlError }')
+
+      expect(graphql_execute.get_tag('graphql.operation.type')).to eq('query')
+      expect(graphql_execute.get_tag('graphql.operation.name')).to eq('Error')
+
+      expect(graphql_execute.events).to contain_exactly(
+        a_span_event_with(
+          name: 'dd.graphql.query.error',
+          attributes: {
+            message: 'GraphQL error',
+            type: 'GraphQL::ExecutionError',
+            stacktrace: include(__FILE__),
+            locations: ['1:14'],
+            path: ['graphqlError'],
+          }
+        )
+      )
+    end
+  end
 end