GraphQL: Report multiple query errors (#4177)

* GraphQL: Report multiple query errors

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

Co-authored-by: Ivo Anjo <ivo.anjo@datadoghq.com>

* Misc code reviews

* Revert gemfile

---------

Co-authored-by: Ivo Anjo <ivo.anjo@datadoghq.com>

Author: marcotc

.github/forced-tests-list.json

@@ -6,5 +6,8 @@
   "PARAMETRIC":
   [
     "tests/parametric/test_span_events.py"
+  ],
+  "DEFAULT": [
+    "tests/test_graphql.py"
   ]
 }

docs/GettingStarted.md

@@ -880,8 +880,8 @@ The `instrument :graphql` method accepts the following parameters. Additional op
 | ------------------------ | -------------------------- | -------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ---------------- |
 | `enabled`                | `DD_TRACE_GRAPHQL_ENABLED` | `Bool`   | Whether the integration should create spans.                                                                                                                                                                    | `true`           |
 | `schemas`                |                            | `Array`  | Array of `GraphQL::Schema` objects (that support class-based schema only) to trace. If you do not provide any, then tracing will applied to all the schemas.                                                    | `[]`             |
-| `with_unified_tracer`    |                            | `Bool`   | (Recommended) Enable to instrument with `UnifiedTrace` tracer for `graphql` >= v2.2, **enabling support for Endpoints list** in the Service Catalog. `with_deprecated_tracer` has priority over this. Default is `false`, using `GraphQL::Tracing::DataDogTrace` instead | `false` |
-| `with_deprecated_tracer` |                            | `Bool`   | Enable to instrument with deprecated `GraphQL::Tracing::DataDogTracing`. This has priority over `with_unified_tracer`. Default is `false`, using `GraphQL::Tracing::DataDogTrace` instead | `false` |
+| `with_unified_tracer`    | `DD_TRACE_GRAPHQL_WITH_UNIFIED_TRACER` | `Bool`   | (Recommended) Enable to instrument with `UnifiedTrace` tracer for `graphql` >= v2.2, **enabling support for Endpoints list** in the Service Catalog. `with_deprecated_tracer` has priority over this. Default is `false`, using `GraphQL::Tracing::DataDogTrace` instead. This option is disabled by default to maintain backwards compatibility, but **will become the default in `datadog` 3.0.0**. | `false` |
+| `with_deprecated_tracer` |                            | `Bool`   | (Not recommended) Enable to instrument with deprecated `GraphQL::Tracing::DataDogTracing`. This has priority over `with_unified_tracer`. Default is `false`, using `GraphQL::Tracing::DataDogTrace` instead | `false` |
 | `service_name`           |                            | `String` | Service name used for graphql instrumentation                                                                                                                                                                   | `'ruby-graphql'` |
 
 Once an instrumentation strategy is selected (`with_unified_tracer: true`, `with_deprecated_tracer: true`, or *no option set* which defaults to `GraphQL::Tracing::DataDogTrace`), it is not possible to change the instrumentation strategy in the same Ruby process.

lib/datadog/tracing/contrib/graphql/configuration/settings.rb

@@ -44,6 +44,7 @@ class Settings < Contrib::Configuration::Settings
             end
 
             option :with_unified_tracer do |o|
+              o.env Ext::ENV_WITH_UNIFIED_TRACER
               o.type :bool
               o.default false
             end

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

@@ -11,8 +11,12 @@ module Ext
           # @!visibility private
           ENV_ANALYTICS_ENABLED = 'DD_TRACE_GRAPHQL_ANALYTICS_ENABLED'
           ENV_ANALYTICS_SAMPLE_RATE = 'DD_TRACE_GRAPHQL_ANALYTICS_SAMPLE_RATE'
+          ENV_WITH_UNIFIED_TRACER = 'DD_TRACE_GRAPHQL_WITH_UNIFIED_TRACER'
           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

@@ -47,14 +47,26 @@ def execute_multiplex(*args, multiplex:, **kwargs)
           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,
+              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
+              },
+              ->(span) { add_query_error_events(span, query.context.errors) },
+              query: query,
+            )
           end
 
           def execute_query_lazy(*args, query:, multiplex:, **kwargs)
@@ -131,7 +143,16 @@ 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 before [Proc, nil] a callable to run before the trace, same as the block parameter
+          # @param after [Proc, nil] a callable to run after the trace, which has access to query values after execution
+          # @param kwargs [Hash] the arguments to pass to `prepare_span`
+          # @yield [Span] the block to run before the trace, same as the `before` parameter
+          def trace(callable, trace_key, resource, before = nil, after = nil, **kwargs, &before_block)
             config = Datadog.configuration.tracing[:graphql]
 
             Tracing.trace(
@@ -144,11 +165,20 @@ def trace(callable, trace_key, resource, **kwargs)
                 Contrib::Analytics.set_sample_rate(span, config[:analytics_sample_rate])
               end
 
-              yield(span) if block_given?
+              # A sanity check for us.
+              raise 'Please provide either `before` or a block, but not both' if before && before_block
+
+              if (before_callable = before || before_block)
+                before_callable.call(span)
+              end
 
               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 +193,48 @@ 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)
+
+              # {::GraphQL::Error#to_h} returns the error formatted in compliance with the GraphQL spec.
+              # This is an unwritten contract in the `graphql` library.
+              # See for an example: https://github.com/rmosolgo/graphql-ruby/blob/0afa241775e5a113863766cce126214dee093464/lib/graphql/execution_error.rb#L32
+              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/tracing/contrib/graphql/ext.rbs

@@ -9,6 +9,8 @@ module Datadog
 
           ENV_ANALYTICS_SAMPLE_RATE: "DD_TRACE_GRAPHQL_ANALYTICS_SAMPLE_RATE"
 
+          ENV_WITH_UNIFIED_TRACER: "DD_TRACE_GRAPHQL_WITH_UNIFIED_TRACER"
+          EVENT_QUERY_ERROR: "dd.graphql.query.error"
           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,10 +22,26 @@ 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 error'
+      end
     end
 
     class #{prefix}TestGraphQLSchema < ::GraphQL::Schema
       query(#{prefix}TestGraphQLQuery)
+
+      rescue_from(RuntimeError) do |err, obj, args, ctx, field|
+        raise GraphQL::ExecutionError.new(err.message, extensions: {
+          'int-1': 1,
+          'str-1': '1',
+          'array-1-2': [1,'2'],
+          '': 'empty string',
+          ',': 'comma',
+        })
+      end
     end
   RUBY
   # rubocop:enable Style/DocumentDynamicEvalDefinition
@@ -76,10 +92,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 +151,47 @@ def unload_test_schema(prefix: '')
       end
     end
   end
+
+  describe 'query with GraphQL errors' do
+    subject(:result) { schema.execute(query: 'query Error{ err1: graphqlError err2: graphqlError }') }
+
+    let(:graphql_execute) { spans.find { |s| s.name == 'graphql.execute' } }
+
+    it 'creates query span for error' do
+      expect(result.to_h['errors'][0]['message']).to eq('GraphQL error')
+      expect(result.to_h['data']).to eq('err1' => nil, 'err2' => 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{ err1: graphqlError err2: 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: {
+            'path' => ['err1'],
+            'locations' => ['1:14'],
+            'message' => 'GraphQL error',
+            'type' => 'GraphQL::ExecutionError',
+            'stacktrace' => include(__FILE__),
+          }
+        ),
+        a_span_event_with(
+          name: 'dd.graphql.query.error',
+          attributes: {
+            'path' => ['err2'],
+            'locations' => ['1:33'],
+            'message' => 'GraphQL error',
+            'type' => 'GraphQL::ExecutionError',
+            'stacktrace' => include(__FILE__),
+          }
+        )
+      )
+    end
+  end
 end

spec/support/span_helpers.rb

@@ -128,4 +128,14 @@ def description_of(actual)
         end
     end
   end
+
+  RSpec::Matchers.define :a_span_event_with do |expected|
+    match do |actual|
+      values_match? Datadog::Tracing::SpanEvent, actual
+
+      expected.all? do |key, value|
+        values_match? value, actual.__send__(key)
+      end
+    end
+  end
 end

vendor/rbs/graphql/0/graphql.rbs

@@ -38,4 +38,8 @@ module GraphQL
     class Multiplex
     end
   end
+
+  class Error
+    def to_h: -> Hash[String, untyped]
+  end
 end