Merge pull request rmosolgo#4344 from rmosolgo/better-trace-api

Add Tracing::Trace for method-based tracing

guides/queries/tracing.md

@@ -8,9 +8,7 @@ desc: Observation hooks for execution
 index: 11
 ---
 
-{{ "GraphQL::Tracing" | api_doc }} provides a `.trace` hook to observe events from the GraphQL runtime.
-
-A tracer must implement `.trace`, for example:
+{{ "GraphQL::Tracing::Trace" | api_doc }} provides hooks to observe and modify events during runtime. Tracing hooks are methods, defined in modules and mixed in with {{ "Schema.trace_with" | api_doc }}.
 
 ```ruby
 class MyCustomTracer
@@ -30,20 +28,13 @@ end
 To run a tracer for __every query__, add it to the schema with `tracer`:
 
 ```ruby
-# Run `MyCustomTracer` for all queries
+# Run `MyCustomTrace` for all queries
 class MySchema < GraphQL::Schema
-  tracer(MyCustomTracer)
+  trace_with(MyCustomTrace)
 end
 ```
 
-Or, to run a tracer for __one query only__, add it to `context:` as `tracers: [...]`, for example:
-
-```ruby
-# Run `MyCustomTracer` for this query
-MySchema.execute(..., context: { tracers: [MyCustomTracer]})
-```
-
-For a full list of events, see the {{ "GraphQL::Tracing" | api_doc }} API docs.
+For a full list of methods and their arguments, see {{ "GraphQL::Tracing::Trace" | api_doc }}.
 
 ## ActiveSupport::Notifications
 
@@ -64,8 +55,6 @@ Several monitoring platforms are supported out-of-the box by GraphQL-Ruby (see p
 
 Leaf fields are _not_ monitored (to avoid high cardinality in the metrics service).
 
-Implementations are based on {{ "Tracing::PlatformTracing" | api_doc }}.
-
 ## AppOptics
 
 [AppOptics](https://appoptics.com/) instrumentation will be automatic starting

guides/subscriptions/multi_tenant.md

@@ -62,27 +62,22 @@ There are a few places where subscriptions might need to load data:
 
 Each of these operations will need to select the right tenant in order to load data properly.
 
-For __building the payload__, use a {% internal_link "Tracer", "queries/tracing" %}:
+For __building the payload__, use a {% internal_link "Trace module", "queries/tracing" %}:
 
 ```ruby
-class TenantSelectionTracer
-  def self.trace(event, data)
-    case event
-    when "execute_multiplex" # this is the top-level, umbrella event
-      context = data[:multiplex].queries.first.context # This assumes that all queries in a multiplex have the same tenant
-      MultiTenancy.select_tenant(context[:tenant]) do
+module TenantSelectionTrace
+  def execute_multiplex(multiplex:) # this is the top-level, umbrella event
+    context = data[:multiplex].queries.first.context # This assumes that all queries in a multiplex have the same tenant
+    MultiTenancy.select_tenant(context[:tenant]) do
       # ^^ your multi-tenancy implementation here
-        yield
-      end
-    else
-      yield
+      super # Call through to the rest of execution
     end
   end
 end
 
 # ...
 class MySchema < GraphQL::Schema
-  tracer(TenantSelectionTracer)
+  trace_with(TenantSelectionTrace)
 end
 ```
 

lib/graphql.rb

@@ -42,8 +42,8 @@ def default_parser
   # Turn a query string or schema definition into an AST
   # @param graphql_string [String] a GraphQL query string or schema definition
   # @return [GraphQL::Language::Nodes::Document]
-  def self.parse(graphql_string, tracer: GraphQL::Tracing::NullTracer)
-    parse_with_racc(graphql_string, tracer: tracer)
+  def self.parse(graphql_string, trace: GraphQL::Tracing::NullTrace)
+    parse_with_racc(graphql_string, trace: trace)
   end
 
   # Read the contents of `filename` and parse them as GraphQL
@@ -54,8 +54,8 @@ def self.parse_file(filename)
     parse_with_racc(content, filename: filename)
   end
 
-  def self.parse_with_racc(string, filename: nil, tracer: GraphQL::Tracing::NullTracer)
-    GraphQL::Language::Parser.parse(string, filename: filename, tracer: tracer)
+  def self.parse_with_racc(string, filename: nil, trace: GraphQL::Tracing::NullTrace)
+    GraphQL::Language::Parser.parse(string, filename: filename, trace: trace)
   end
 
   # @return [Array<GraphQL::Language::Token>]

lib/graphql/analysis/ast.rb

@@ -21,7 +21,7 @@ module AST
       def analyze_multiplex(multiplex, analyzers)
         multiplex_analyzers = analyzers.map { |analyzer| analyzer.new(multiplex) }
 
-        multiplex.trace("analyze_multiplex", { multiplex: multiplex }) do
+        multiplex.current_trace.analyze_multiplex(multiplex: multiplex) do
           query_results = multiplex.queries.map do |query|
             if query.valid?
               analyze_query(
@@ -48,7 +48,7 @@ def analyze_multiplex(multiplex, analyzers)
       # @param analyzers [Array<GraphQL::Analysis::AST::Analyzer>]
       # @return [Array<Any>] Results from those analyzers
       def analyze_query(query, analyzers, multiplex_analyzers: [])
-        query.trace("analyze_query", { query: query }) do
+        query.current_trace.analyze_query(query: query) do
           query_analyzers = analyzers
             .map { |analyzer| analyzer.new(query) }
             .select { |analyzer| analyzer.analyze? }

lib/graphql/execution/interpreter.rb

@@ -34,7 +34,7 @@ def run_all(schema, query_options, context: {}, max_complexity: schema.max_compl
           end
 
           multiplex = Execution::Multiplex.new(schema: schema, queries: queries, context: context, max_complexity: max_complexity)
-          multiplex.trace("execute_multiplex", { multiplex: multiplex }) do
+          multiplex.current_trace.execute_multiplex(multiplex: multiplex) do
             schema = multiplex.schema
             queries = multiplex.queries
             query_instrumenters = schema.instrumenters[:query]
@@ -70,7 +70,7 @@ def run_all(schema, query_options, context: {}, max_complexity: schema.max_compl
                           runtime = Runtime.new(query: query)
                           query.context.namespace(:interpreter_runtime)[:runtime] = runtime
 
-                          query.trace("execute_query", {query: query}) do
+                          query.current_trace.execute_query(query: query) do
                             runtime.run_eager
                           end
                         rescue GraphQL::ExecutionError => err
@@ -95,7 +95,7 @@ def run_all(schema, query_options, context: {}, max_complexity: schema.max_compl
                       runtime ? runtime.final_result : nil
                     end
                     final_values.compact!
-                    tracer.trace("execute_query_lazy", {multiplex: multiplex, query: query}) do
+                    tracer.current_trace.execute_query_lazy(multiplex: multiplex, query: query) do
                       Interpreter::Resolve.resolve_all(final_values, multiplex.dataloader)
                     end
                     queries.each do |query|

lib/graphql/execution/interpreter/runtime.rb

@@ -507,7 +507,7 @@ def evaluate_selection_with_args(arguments, field_defn, next_path, ast_node, fie
             field_result = call_method_on_directives(:resolve, object, directives) do
               # Actually call the field resolver and capture the result
               app_result = begin
-                query.trace("execute_field", {owner: owner_type, field: field_defn, path: next_path, ast_node: ast_node, query: query, object: object, arguments: kwarg_arguments}) do
+                query.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
               rescue GraphQL::ExecutionError => err
@@ -923,7 +923,7 @@ def after_lazy(lazy_obj, owner:, field:, path:, owner_object:, arguments:, ast_n
               # but don't wrap the continuation below
               inner_obj = begin
                 if trace
-                  query.trace("execute_field_lazy", {owner: owner, field: field, path: path, query: query, object: owner_object, arguments: arguments, ast_node: ast_node}) do
+                  query.current_trace.execute_field_lazy(field: field, query: query, object: owner_object, arguments: arguments, ast_node: ast_node) do
                     schema.sync_lazy(lazy_obj)
                   end
                 else
@@ -973,14 +973,13 @@ def delete_interpreter_context(key)
         end
 
         def resolve_type(type, value, path)
-          trace_payload = { context: context, type: type, object: value, path: path }
-          resolved_type, resolved_value = query.trace("resolve_type", trace_payload) do
+          resolved_type, resolved_value = query.current_trace.resolve_type(query: query, type: type, object: value) do
             query.resolve_type(type, value)
           end
 
           if lazy?(resolved_type)
             GraphQL::Execution::Lazy.new do
-              query.trace("resolve_type_lazy", trace_payload) do
+              query.current_trace.resolve_type_lazy(query: query, type: type, object: value) do
                 schema.sync_lazy(resolved_type)
               end
             end

lib/graphql/execution/multiplex.rb

@@ -25,13 +25,14 @@ module Execution
     class Multiplex
       include Tracing::Traceable
 
-      attr_reader :context, :queries, :schema, :max_complexity, :dataloader
+      attr_reader :context, :queries, :schema, :max_complexity, :dataloader, :current_trace
 
       def initialize(schema:, queries:, context:, max_complexity:)
         @schema = schema
         @queries = queries
         @queries.each { |q| q.multiplex = self }
         @context = context
+        @current_trace = @context[:trace] || schema.new_trace(multiplex: self)
         @dataloader = @context[:dataloader] ||= @schema.dataloader_class.new
         @tracers = schema.tracers + (context[:tracers] || [])
         # Support `context: {backtrace: true}`

lib/graphql/language/parser.y

@@ -448,22 +448,22 @@ end
 
 EMPTY_ARRAY = [].freeze
 
-def initialize(query_string, filename:, tracer: Tracing::NullTracer)
+def initialize(query_string, filename:, trace: Tracing::NullTrace)
   raise GraphQL::ParseError.new("No query string was present", nil, nil, query_string) if query_string.nil?
   @query_string = query_string
   @filename = filename
-  @tracer = tracer
+  @trace = trace
   @reused_next_token = [nil, nil]
 end
 
 def parse_document
   @document ||= begin
     # Break the string into tokens
-    @tracer.trace("lex", {query_string: @query_string}) do
+    @trace.lex(query_string: @query_string) do
       @tokens ||= GraphQL.scan(@query_string)
     end
     # From the tokens, build an AST
-    @tracer.trace("parse", {query_string: @query_string}) do
+    @trace.parse(query_string: @query_string) do
       if @tokens.empty?
         raise GraphQL::ParseError.new("Unexpected end of document", nil, nil, @query_string)
       else
@@ -476,17 +476,17 @@ end
 class << self
   attr_accessor :cache
 
-  def parse(query_string, filename: nil, tracer: GraphQL::Tracing::NullTracer)
-    new(query_string, filename: filename, tracer: tracer).parse_document
+  def parse(query_string, filename: nil, trace: GraphQL::Tracing::NullTrace)
+    new(query_string, filename: filename, trace: trace).parse_document
   end
 
-  def parse_file(filename, tracer: GraphQL::Tracing::NullTracer)
+  def parse_file(filename, trace: GraphQL::Tracing::NullTrace)
     if cache
       cache.fetch(filename) do
-        parse(File.read(filename), filename: filename, tracer: tracer)
+        parse(File.read(filename), filename: filename, trace: trace)
       end
     else
-      parse(File.read(filename), filename: filename, tracer: tracer)
+      parse(File.read(filename), filename: filename, trace: trace)
     end
   end
 end

lib/graphql/query.rb

@@ -95,12 +95,20 @@ def initialize(schema, query_string = nil, query: nil, document: nil, context: n
       @fragments = nil
       @operations = nil
       @validate = validate
-      @tracers = schema.tracers + (context ? context.fetch(:tracers, []) : [])
+      context_tracers = (context ? context.fetch(:tracers, []) : [])
+      @tracers = schema.tracers + context_tracers
+
       # Support `ctx[:backtrace] = true` for wrapping backtraces
       if context && context[:backtrace] && !@tracers.include?(GraphQL::Backtrace::Tracer)
+        context_tracers += [GraphQL::Backtrace::Tracer]
         @tracers << GraphQL::Backtrace::Tracer
       end
 
+      if context_tracers.any? && !(schema.trace_class <= GraphQL::Tracing::LegacyTrace)
+        raise ArgumentError, "context[:tracers] and context[:backtrace] are not supported without `tracer_class(GraphQL::Tracing::LegacyTrace)` in the schema configuration, please add it."
+      end
+
+
       @analysis_errors = []
       if variables.is_a?(String)
         raise ArgumentError, "Query variables should be a Hash, not a String. Try JSON.parse to prepare variables."
@@ -157,6 +165,11 @@ def interpreter?
 
     attr_accessor :multiplex
 
+    # @return [GraphQL::Tracing::Trace]
+    def current_trace
+      @current_trace ||= multiplex ? multiplex.current_trace : schema.new_trace(multiplex: multiplex, query: self)
+    end
+
     def subscription_update?
       @subscription_topic && subscription?
     end
@@ -362,7 +375,7 @@ def prepare_ast
       parse_error = nil
       @document ||= begin
         if query_string
-          GraphQL.parse(query_string, tracer: self)
+          GraphQL.parse(query_string, trace: self.current_trace)
         end
       rescue GraphQL::ParseError => err
         parse_error = err

lib/graphql/schema.rb

@@ -143,6 +143,15 @@ def subscriptions=(new_implementation)
         @subscriptions = new_implementation
       end
 
+      def trace_class(new_class = nil)
+        if new_class
+          @trace_class = new_class
+        elsif !defined?(@trace_class)
+          @trace_class = Class.new(GraphQL::Tracing::Trace)
+        end
+        @trace_class
+      end
+
       # Returns the JSON response of {Introspection::INTROSPECTION_QUERY}.
       # @see {#as_json}
       # @return [String]
@@ -926,13 +935,32 @@ def default_directives
       end
 
       def tracer(new_tracer)
+        if defined?(@trace_class) && !(@trace_class < GraphQL::Tracing::LegacyTrace)
+          raise ArgumentError, "Can't add tracer after configuring a `trace_class`, use GraphQL::Tracing::LegacyTrace to merge legacy tracers into a trace class instead."
+        elsif !defined?(@trace_class)
+          @trace_class = Class.new(GraphQL::Tracing::LegacyTrace)
+        end
+
         own_tracers << new_tracer
       end
 
       def tracers
         find_inherited_value(:tracers, EMPTY_ARRAY) + own_tracers
       end
 
+      def trace_with(trace_mod, **options)
+        @trace_options ||= {}
+        @trace_options.merge!(options)
+        trace_class.include(trace_mod)
+      end
+
+      def new_trace(**options)
+        if defined?(@trace_options)
+          options = @trace_options.merge(options)
+        end
+        trace_class.new(**options)
+      end
+
       def query_analyzer(new_analyzer)
         own_query_analyzers << new_analyzer
       end