From a711bb4244a5dd9ab421515af55a7de86afb8c4c Mon Sep 17 00:00:00 2001 From: Robert Mosolgo Date: Mon, 17 Feb 2025 14:13:24 -0500 Subject: [PATCH 1/6] Rewrite NewRelicTrace to support fiber stops/starts --- .rubocop.yml | 7 +- ...alls_super_cop.rb => trace_methods_cop.rb} | 37 +++- lib/graphql/execution/interpreter.rb | 4 +- lib/graphql/static_validation/validator.rb | 6 +- lib/graphql/tracing/new_relic_trace.rb | 175 +++++++++++++----- lib/graphql/tracing/perfetto_trace.rb | 9 +- lib/graphql/tracing/trace.rb | 6 +- spec/graphql/tracing/trace_spec.rb | 2 +- spec/support/new_relic.rb | 18 ++ 9 files changed, 198 insertions(+), 66 deletions(-) rename cop/development/{trace_calls_super_cop.rb => trace_methods_cop.rb} (54%) diff --git a/.rubocop.yml b/.rubocop.yml index 1e6fe6a81e..626427e895 100644 --- a/.rubocop.yml +++ b/.rubocop.yml @@ -4,7 +4,7 @@ require: - ./lib/graphql/rubocop/graphql/default_null_true - ./lib/graphql/rubocop/graphql/default_required_true - ./cop/development/context_is_passed_cop - - ./cop/development/trace_calls_super_cop.rb + - ./cop/development/trace_methods_cop.rb AllCops: DisabledByDefault: true @@ -45,9 +45,10 @@ Development/NoFocusCop: Include: - "spec/**/*" -Development/TraceCallsSuperCop: +Development/TraceMethodsCop: Include: - - "lib/graphql/tracing/*_trace.rb" + - "lib/graphql/tracing/perfetto_trace.rb" + - "lib/graphql/tracing/new_relic_trace.rb" # def ... # end diff --git a/cop/development/trace_calls_super_cop.rb b/cop/development/trace_methods_cop.rb similarity index 54% rename from cop/development/trace_calls_super_cop.rb rename to cop/development/trace_methods_cop.rb index f9f0b89b2b..72fd1520cd 100644 --- a/cop/development/trace_calls_super_cop.rb +++ b/cop/development/trace_methods_cop.rb @@ -3,7 +3,7 @@ module Cop module Development - class TraceCallsSuperCop < RuboCop::Cop::Base + class TraceMethodsCop < RuboCop::Cop::Base extend RuboCop::Cop::AutoCorrector TRACE_HOOKS = [ @@ -16,7 +16,7 @@ class TraceCallsSuperCop < RuboCop::Cop::Base :begin_dataloader, :begin_dataloader_source, :begin_execute_field, - :begin_multiplex, + :begin_execute_multiplex, :begin_parse, :begin_resolve_type, :begin_validate, @@ -30,7 +30,7 @@ class TraceCallsSuperCop < RuboCop::Cop::Base :end_dataloader, :end_dataloader_source, :end_execute_field, - :end_multiplex, + :end_execute_multiplex, :end_parse, :end_resolve_type, :end_validate, @@ -51,8 +51,35 @@ class TraceCallsSuperCop < RuboCop::Cop::Base def on_def(node) if TRACE_HOOKS.include?(node.method_name) && !node.each_descendant(:super, :zsuper).any? add_offense(node) do |corrector| - offset = node.loc.column + 2 - corrector.insert_after(node.body.loc.expression, "\n#{' ' * offset}super") + if node.body + offset = node.loc.column + 2 + corrector.insert_after(node.body.loc.expression, "\n#{' ' * offset}super") + end + end + end + end + + def on_module(node) + if node.defined_module_name.to_s.end_with?("Trace") + all_defs = [] + node.body.each_child_node do |body_node| + if body_node.def_type? + all_defs << body_node.method_name + end + end + + missing_defs = TRACE_HOOKS - all_defs + redundant_defs = [:lex, :analyze_query, :execute_query, :execute_query_lazy] + missing_defs.each do |missing_def| + if all_defs.include?(:"begin_#{missing_def}") && all_defs.include?(:"end_#{missing_def}") + redundant_defs << missing_def + redundant_defs << :"#{missing_def}_lazy" + end + end + + missing_defs -= redundant_defs + if missing_defs.any? + add_offense(node, message: "Missing some trace hook methods:\n\n- #{missing_defs.join("\n- ")}") end end end diff --git a/lib/graphql/execution/interpreter.rb b/lib/graphql/execution/interpreter.rb index 0c0739b5ca..f2a4a6481d 100644 --- a/lib/graphql/execution/interpreter.rb +++ b/lib/graphql/execution/interpreter.rb @@ -37,7 +37,7 @@ def run_all(schema, query_options, context: {}, max_complexity: schema.max_compl multiplex = Execution::Multiplex.new(schema: schema, queries: queries, context: context, max_complexity: max_complexity) Fiber[:__graphql_current_multiplex] = multiplex trace = multiplex.current_trace - trace.begin_multiplex(multiplex) + trace.begin_execute_multiplex(multiplex) trace.execute_multiplex(multiplex: multiplex) do schema = multiplex.schema queries = multiplex.queries @@ -155,7 +155,7 @@ def run_all(schema, query_options, context: {}, max_complexity: schema.max_compl end end ensure - trace&.end_multiplex(multiplex) + trace&.end_execute_multiplex(multiplex) end end diff --git a/lib/graphql/static_validation/validator.rb b/lib/graphql/static_validation/validator.rb index 92aa140c28..c1a1ec3718 100644 --- a/lib/graphql/static_validation/validator.rb +++ b/lib/graphql/static_validation/validator.rb @@ -61,13 +61,13 @@ def validate(query, validate: true, timeout: nil, max_errors: nil) } end rescue GraphQL::ExecutionError => e - is_valid = false + errors = [e] { remaining_timeout: nil, - errors: [e], + errors: errors, } ensure - query.current_trace.end_validate(query, validate, is_valid) + query.current_trace.end_validate(query, validate, errors) end # Invoked when static validation times out. diff --git a/lib/graphql/tracing/new_relic_trace.rb b/lib/graphql/tracing/new_relic_trace.rb index 386ff5d745..81934473cc 100644 --- a/lib/graphql/tracing/new_relic_trace.rb +++ b/lib/graphql/tracing/new_relic_trace.rb @@ -5,72 +5,159 @@ module GraphQL module Tracing module NewRelicTrace - include PlatformTrace - # @param set_transaction_name [Boolean] If true, the GraphQL operation name will be used as the transaction name. # This is not advised if you run more than one query per HTTP request, for example, with `graphql-client` or multiplexing. # It can also be specified per-query with `context[:set_new_relic_transaction_name]`. def initialize(set_transaction_name: false, **_rest) @set_transaction_name = set_transaction_name + @nr_field_names = Hash.new do |h, field| + h[field] = "GraphQL/#{field.owner.graphql_name}/#{field.graphql_name}" + end.compare_by_identity + + @nr_authorized_names = Hash.new do |h, type| + h[type] = "GraphQL/Authorized/#{type.graphql_name}" + end.compare_by_identity + + @nr_resolve_type_names = Hash.new do |h, type| + h[type] = "GraphQL/ResolveType/#{type.graphql_name}" + end.compare_by_identity + + @nr_source_names = Hash.new do |h, source_inst| + h[source_inst] = "GraphQL/Source/#{source_inst.class.name}" + end.compare_by_identity + + @nr_parse = @nr_validate = @nr_analyze = @nr_execute = nil + super + end + + def begin_parse(query_str) + @nr_parse = NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: "GraphQL/parse", category: :web) + super + end + + def end_parse(query_str) + @nr_parse.finish + super + end + + def begin_validate(query, validate) + @nr_validate = NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: "GraphQL/validate", category: :web) + super + end + + def end_validate(query, validate, validation_errors) + @nr_validate.finish + super + end + + def begin_analyze_multiplex(multiplex, analyzers) + @nr_analyze = NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: "GraphQL/analyze", category: :web) super end - def execute_query(query:) - set_this_txn_name = query.context[:set_new_relic_transaction_name] - if set_this_txn_name == true || (set_this_txn_name.nil? && @set_transaction_name) + def end_analyze_multiplex(multiplex, analyzers) + @nr_analyze.finish + super + end + + def begin_execute_multiplex(multiplex) + query = multiplex.queries.first + set_this_txn_name = query.context[:set_new_relic_transaction_name] + if set_this_txn_name || (set_this_txn_name.nil? && @set_transaction_name) NewRelic::Agent.set_transaction_name(transaction_name(query)) end - NewRelic::Agent::MethodTracerHelpers.trace_execution_scoped("GraphQL/execute") do - super - end + @nr_execute = NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: "GraphQL/execute", category: :web) + super end - { - "lex" => "GraphQL/lex", - "parse" => "GraphQL/parse", - "validate" => "GraphQL/validate", - "analyze_query" => "GraphQL/analyze", - "analyze_multiplex" => "GraphQL/analyze", - "execute_multiplex" => "GraphQL/execute", - "execute_query_lazy" => "GraphQL/execute", - }.each do |trace_method, platform_key| - module_eval <<-RUBY, __FILE__, __LINE__ - def #{trace_method}(**_keys) - NewRelic::Agent::MethodTracerHelpers.trace_execution_scoped("#{platform_key}") do - super - end - end - RUBY - end - - def platform_execute_field(platform_key) - NewRelic::Agent::MethodTracerHelpers.trace_execution_scoped(platform_key) do - yield - end + def end_execute_multiplex(multiplex) + @nr_execute.finish + super end - def platform_authorized(platform_key) - NewRelic::Agent::MethodTracerHelpers.trace_execution_scoped(platform_key) do - yield - end + def begin_execute_field(field, object, arguments, query) + nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_field_names[field], category: :web) + super end - def platform_resolve_type(platform_key) - NewRelic::Agent::MethodTracerHelpers.trace_execution_scoped(platform_key) do - yield - end + def end_execute_field(field, objects, arguments, query, result) + nr_segment_stack.pop.finish + super end - def platform_field_key(field) - "GraphQL/#{field.owner.graphql_name}/#{field.graphql_name}" + def begin_authorized(type, obj, ctx) + nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_authorized_names[type], category: :web) + super end - def platform_authorized_key(type) - "GraphQL/Authorize/#{type.graphql_name}" + def end_authorized(type, obj, ctx, is_authed) + nr_segment_stack.pop.finish + super + end + + def begin_resolve_type(type, value, context) + nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_resolve_type_names[type], category: :web) + super + end + + def end_resolve_type(type, value, context, resolved_type) + nr_segment_stack.pop.finish + super + end + + def begin_dataloader(dl) + # nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: "GraphQL/dataloader", category: :web) + super + end + + def end_dataloader(dl) + # nr_segment_stack.pop.finish + super + end + + def begin_dataloader_source(source) + nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_source_names[source], category: :web) + super + end + + def end_dataloader_source(source) + nr_segment_stack.pop.finish + super + end + + def dataloader_fiber_yield(source) + current_segment = nr_segment_stack.last + current_segment.finish + super + end + + def dataloader_fiber_resume(source) + prev_segment = nr_segment_stack.pop + seg_partial_name = prev_segment.name.sub(/^.*(GraphQL.*)$/, '\1') + nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: seg_partial_name, category: :web) + super + end + + private + + def nr_segment_stack + Fiber[:graphql_nr_segment_stack] ||= [] + end + + def transaction_name(query) + selected_op = query.selected_operation + txn_name = if selected_op + op_type = selected_op.operation_type + op_name = selected_op.name || fallback_transaction_name(query.context) || "anonymous" + "#{op_type}.#{op_name}" + else + "query.anonymous" + end + "GraphQL/#{txn_name}" end - def platform_resolve_type_key(type) - "GraphQL/ResolveType/#{type.graphql_name}" + def fallback_transaction_name(context) + context[:tracing_fallback_transaction_name] end end end diff --git a/lib/graphql/tracing/perfetto_trace.rb b/lib/graphql/tracing/perfetto_trace.rb index 54a384603b..4653d16512 100644 --- a/lib/graphql/tracing/perfetto_trace.rb +++ b/lib/graphql/tracing/perfetto_trace.rb @@ -66,7 +66,6 @@ def initialize(active_support_notifications_pattern: nil, **_rest) @sequence_id = object_id @pid = Process.pid @flow_ids = Hash.new { |h, source_inst| h[source_inst] = [] }.compare_by_identity - # TODO intern these too: @new_interned_event_names = {} @interned_event_name_iids = Hash.new { |h, k| new_id = 100 + h.size @@ -172,7 +171,7 @@ def initialize(active_support_notifications_pattern: nil, **_rest) end end - def begin_multiplex(m) + def begin_execute_multiplex(m) @packets << trace_packet( type: TrackEvent::Type::TYPE_SLICE_BEGIN, track_uuid: fid, @@ -184,7 +183,7 @@ def begin_multiplex(m) super end - def end_multiplex(m) + def end_execute_multiplex(m) @packets << trace_packet( type: TrackEvent::Type::TYPE_SLICE_END, track_uuid: fid, @@ -286,7 +285,7 @@ def begin_validate(query, validate) super end - def end_validate(query, validate, is_valid) + def end_validate(query, validate, validation_errors) @packets << trace_packet( type: TrackEvent::Type::TYPE_SLICE_END, track_uuid: fid, @@ -298,7 +297,7 @@ def end_validate(query, validate, is_valid) { debug_annotations: [ @begin_validate.track_event.debug_annotations.first, - payload_to_debug("valid?", is_valid) + payload_to_debug("valid?", !validation_errors.empty?) ] } ) diff --git a/lib/graphql/tracing/trace.rb b/lib/graphql/tracing/trace.rb index 5fc459576a..cca0964060 100644 --- a/lib/graphql/tracing/trace.rb +++ b/lib/graphql/tracing/trace.rb @@ -42,7 +42,7 @@ def validate(query:, validate:) def begin_validate(query, validate) end - def end_validate(query, validate, is_valid) + def end_validate(query, validate, errors) end # @param multiplex [GraphQL::Execution::Multiplex] @@ -67,12 +67,12 @@ def analyze_query(query:) # Every Query is technically run _inside_ a {GraphQL::Multiplex}. # @param multiplex [GraphQL::Execution::Multiplex] # @return [void] - def begin_multiplex(multiplex); end; + def begin_execute_multiplex(multiplex); end; # This is the last event of the tracing lifecycle. # @param multiplex [GraphQL::Execution::Multiplex] # @return [void] - def end_multiplex(multiplex); end; + def end_execute_multiplex(multiplex); end; # This wraps an entire `.execute` call. # @param multiplex [GraphQL::Execution::Multiplex] diff --git a/spec/graphql/tracing/trace_spec.rb b/spec/graphql/tracing/trace_spec.rb index 2b37ca0a90..2a54210dd1 100644 --- a/spec/graphql/tracing/trace_spec.rb +++ b/spec/graphql/tracing/trace_spec.rb @@ -3,7 +3,7 @@ describe GraphQL::Tracing::Trace do it "has all its methods in the development cop" do - trace_source = File.read("cop/development/trace_calls_super_cop.rb") + trace_source = File.read("cop/development/trace_methods_cop.rb") superable_methods = GraphQL::Tracing::Trace.instance_methods(false).sort superable_methods_source = superable_methods.map { |m| " #{m.inspect},\n" }.join assert_includes trace_source, superable_methods_source diff --git a/spec/support/new_relic.rb b/spec/support/new_relic.rb index 0dbbfe8268..630977a0ef 100644 --- a/spec/support/new_relic.rb +++ b/spec/support/new_relic.rb @@ -18,6 +18,24 @@ def self.set_transaction_name(name) TRANSACTION_NAMES << name end + module Tracer + def self.start_transaction_or_segment(partial_name:, category:) + EXECUTION_SCOPES << partial_name + Finisher.new(partial_name) + end + + class Finisher + def initialize(name) + @name = name + end + + def finish + EXECUTION_SCOPES << "FINISH #{@name}" + nil + end + end + end + module MethodTracerHelpers def self.trace_execution_scoped(trace_name) EXECUTION_SCOPES << trace_name From 21f2be7ec512785bfde60fb249657c9e070fba1b Mon Sep 17 00:00:00 2001 From: Robert Mosolgo Date: Mon, 17 Feb 2025 16:29:30 -0500 Subject: [PATCH 2/6] Test steps, fix validation errors in trace --- lib/graphql/static_validation/validator.rb | 3 +- spec/graphql/tracing/new_relic_trace_spec.rb | 46 ++++++++++++++++++++ spec/support/new_relic.rb | 8 +++- 3 files changed, 53 insertions(+), 4 deletions(-) diff --git a/lib/graphql/static_validation/validator.rb b/lib/graphql/static_validation/validator.rb index c1a1ec3718..2cd83a4dab 100644 --- a/lib/graphql/static_validation/validator.rb +++ b/lib/graphql/static_validation/validator.rb @@ -27,8 +27,8 @@ def initialize(schema:, rules: GraphQL::StaticValidation::ALL_RULES) # @param max_errors [Integer] Maximum number of errors before aborting validation. Any positive number will limit the number of errors. Defaults to nil for no limit. # @return [Array] def validate(query, validate: true, timeout: nil, max_errors: nil) + errors = nil query.current_trace.begin_validate(query, validate) - is_valid = false query.current_trace.validate(validate: validate, query: query) do begin_t = Time.now errors = if validate == false @@ -53,7 +53,6 @@ def validate(query, validate: true, timeout: nil, max_errors: nil) context.errors end - is_valid = errors.size == 0 { remaining_timeout: timeout ? (timeout - (Time.now - begin_t)) : nil, diff --git a/spec/graphql/tracing/new_relic_trace_spec.rb b/spec/graphql/tracing/new_relic_trace_spec.rb index 801a70e956..8decdcc0e5 100644 --- a/spec/graphql/tracing/new_relic_trace_spec.rb +++ b/spec/graphql/tracing/new_relic_trace_spec.rb @@ -3,10 +3,18 @@ describe GraphQL::Tracing::NewRelicTrace do module NewRelicTraceTest + class OtherSource < GraphQL::Dataloader::Source + def fetch(keys) + keys + end + end class Thing < GraphQL::Schema::Object implements GraphQL::Types::Relay::Node end + class Other < GraphQL::Schema::Object + field :name, String, fallback_value: "other" + end class Query < GraphQL::Schema::Object include GraphQL::Types::Relay::HasNodeField @@ -15,6 +23,12 @@ class Query < GraphQL::Schema::Object def int 1 end + + field :other, Other + + def other + dataloader.with(OtherSource).load(:other) + end end class SchemaWithoutTransactionName < GraphQL::Schema @@ -34,6 +48,7 @@ def self.resolve_type(_type, _obj, _ctx) class SchemaWithTransactionName < GraphQL::Schema query(Query) trace_with(GraphQL::Tracing::NewRelicTrace, set_transaction_name: true) + use GraphQL::Dataloader end class SchemaWithScalarTrace < GraphQL::Schema @@ -92,4 +107,35 @@ class SchemaWithScalarTrace < GraphQL::Schema NewRelicTraceTest::SchemaWithScalarTrace.execute "query X { int }" assert_includes NewRelic::EXECUTION_SCOPES, "GraphQL/Query/int" end + + it "handles fiber pauses" do + NewRelicTraceTest::SchemaWithTransactionName.execute("{ other { name } }") + expected_steps = [ + "GraphQL/parse", + "FINISH GraphQL/parse", + "GraphQL/execute", + + "GraphQL/analyze", + "GraphQL/validate", + "FINISH GraphQL/validate", + "FINISH GraphQL/analyze", + + "GraphQL/Authorized/Query", + "FINISH GraphQL/Authorized/Query", + "GraphQL/Query/other", + "FINISH GraphQL/Query/other", + # Here's the source run: + "GraphQL/Source/NewRelicTraceTest::OtherSource", + "FINISH GraphQL/Source/NewRelicTraceTest::OtherSource", + # And back to the field: + "GraphQL/Query/other", + "FINISH GraphQL/Query/other", + "GraphQL/Authorized/Other", + "FINISH GraphQL/Authorized/Other", + "GraphQL/Other/name", + "FINISH GraphQL/Other/name", + "FINISH GraphQL/execute" + ] + assert_equal expected_steps, NewRelic::EXECUTION_SCOPES + end end diff --git a/spec/support/new_relic.rb b/spec/support/new_relic.rb index 630977a0ef..d60de32bfe 100644 --- a/spec/support/new_relic.rb +++ b/spec/support/new_relic.rb @@ -26,11 +26,15 @@ def self.start_transaction_or_segment(partial_name:, category:) class Finisher def initialize(name) - @name = name + @partial_name = name + end + + def name + "Controller/#{@partial_name}" end def finish - EXECUTION_SCOPES << "FINISH #{@name}" + EXECUTION_SCOPES << "FINISH #{@partial_name}" nil end end From bc6fcdf3828a246ecd896e4bf1fc24f106f1c10d Mon Sep 17 00:00:00 2001 From: Robert Mosolgo Date: Tue, 18 Feb 2025 06:07:48 -0500 Subject: [PATCH 3/6] update tests and lint --- cop/development/trace_methods_cop.rb | 7 ++++++- spec/graphql/tracing/new_relic_trace_spec.rb | 13 ++++++++++++- 2 files changed, 18 insertions(+), 2 deletions(-) diff --git a/cop/development/trace_methods_cop.rb b/cop/development/trace_methods_cop.rb index 72fd1520cd..1d99f69b48 100644 --- a/cop/development/trace_methods_cop.rb +++ b/cop/development/trace_methods_cop.rb @@ -69,7 +69,12 @@ def on_module(node) end missing_defs = TRACE_HOOKS - all_defs - redundant_defs = [:lex, :analyze_query, :execute_query, :execute_query_lazy] + redundant_defs = [ + # Not really necessary for making a good trace: + :lex, :analyze_query, :execute_query, :execute_query_lazy, + # Only useful for isolated event tracking: + :dataloader_fiber_exit, :dataloader_spawn_execution_fiber, :dataloader_spawn_source_fiber + ] missing_defs.each do |missing_def| if all_defs.include?(:"begin_#{missing_def}") && all_defs.include?(:"end_#{missing_def}") redundant_defs << missing_def diff --git a/spec/graphql/tracing/new_relic_trace_spec.rb b/spec/graphql/tracing/new_relic_trace_spec.rb index 8decdcc0e5..4d247a862e 100644 --- a/spec/graphql/tracing/new_relic_trace_spec.rb +++ b/spec/graphql/tracing/new_relic_trace_spec.rb @@ -3,11 +3,17 @@ describe GraphQL::Tracing::NewRelicTrace do module NewRelicTraceTest - class OtherSource < GraphQL::Dataloader::Source + class NestedSource < GraphQL::Dataloader::Source def fetch(keys) keys end end + + class OtherSource < GraphQL::Dataloader::Source + def fetch(keys) + dataloader.with(NestedSource).load_all(keys) + end + end class Thing < GraphQL::Schema::Object implements GraphQL::Types::Relay::Node end @@ -126,6 +132,11 @@ class SchemaWithScalarTrace < GraphQL::Schema "FINISH GraphQL/Query/other", # Here's the source run: "GraphQL/Source/NewRelicTraceTest::OtherSource", + "FINISH GraphQL/Source/NewRelicTraceTest::OtherSource", + # Nested source: + "GraphQL/Source/NewRelicTraceTest::NestedSource", + "FINISH GraphQL/Source/NewRelicTraceTest::NestedSource", + "GraphQL/Source/NewRelicTraceTest::OtherSource", "FINISH GraphQL/Source/NewRelicTraceTest::OtherSource", # And back to the field: "GraphQL/Query/other", From dd7c30c5383470257aa328cda302611c870484fc Mon Sep 17 00:00:00 2001 From: Robert Mosolgo Date: Tue, 18 Feb 2025 06:21:03 -0500 Subject: [PATCH 4/6] Add trace_authorized and trace_resolve_type options --- lib/graphql/tracing/new_relic_trace.rb | 24 +++++++---- spec/graphql/tracing/new_relic_trace_spec.rb | 42 ++++++++++++++++++++ 2 files changed, 59 insertions(+), 7 deletions(-) diff --git a/lib/graphql/tracing/new_relic_trace.rb b/lib/graphql/tracing/new_relic_trace.rb index 81934473cc..9228ef55b7 100644 --- a/lib/graphql/tracing/new_relic_trace.rb +++ b/lib/graphql/tracing/new_relic_trace.rb @@ -8,8 +8,12 @@ module NewRelicTrace # @param set_transaction_name [Boolean] If true, the GraphQL operation name will be used as the transaction name. # This is not advised if you run more than one query per HTTP request, for example, with `graphql-client` or multiplexing. # It can also be specified per-query with `context[:set_new_relic_transaction_name]`. - def initialize(set_transaction_name: false, **_rest) + # @param trace_authorized [Boolean] If `false`, skip tracing `authorized?` calls + # @param trace_resolve_type [Boolean] If `false`, skip tracing `resolve_type?` calls + def initialize(set_transaction_name: false, trace_authorized: true, trace_resolve_type: true, **_rest) @set_transaction_name = set_transaction_name + @trace_authorized = trace_authorized + @trace_resolve_type = trace_resolve_type @nr_field_names = Hash.new do |h, field| h[field] = "GraphQL/#{field.owner.graphql_name}/#{field.graphql_name}" end.compare_by_identity @@ -86,32 +90,38 @@ def end_execute_field(field, objects, arguments, query, result) end def begin_authorized(type, obj, ctx) - nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_authorized_names[type], category: :web) + if @trace_authorized + nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_authorized_names[type], category: :web) + end super end def end_authorized(type, obj, ctx, is_authed) - nr_segment_stack.pop.finish + if @trace_authorized + nr_segment_stack.pop.finish + end super end def begin_resolve_type(type, value, context) - nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_resolve_type_names[type], category: :web) + if @trace_resolve_type + nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: @nr_resolve_type_names[type], category: :web) + end super end def end_resolve_type(type, value, context, resolved_type) - nr_segment_stack.pop.finish + if @trace_resolve_type + nr_segment_stack.pop.finish + end super end def begin_dataloader(dl) - # nr_segment_stack << NewRelic::Agent::Tracer.start_transaction_or_segment(partial_name: "GraphQL/dataloader", category: :web) super end def end_dataloader(dl) - # nr_segment_stack.pop.finish super end diff --git a/spec/graphql/tracing/new_relic_trace_spec.rb b/spec/graphql/tracing/new_relic_trace_spec.rb index 4d247a862e..595d598497 100644 --- a/spec/graphql/tracing/new_relic_trace_spec.rb +++ b/spec/graphql/tracing/new_relic_trace_spec.rb @@ -18,9 +18,19 @@ class Thing < GraphQL::Schema::Object implements GraphQL::Types::Relay::Node end + module Nameable + include GraphQL::Schema::Interface + field :name, String + + def self.resolve_type(abs_type, ctx) + Other + end + end class Other < GraphQL::Schema::Object + implements Nameable field :name, String, fallback_value: "other" end + class Query < GraphQL::Schema::Object include GraphQL::Types::Relay::HasNodeField @@ -35,6 +45,8 @@ def int def other dataloader.with(OtherSource).load(:other) end + + field :nameable, Nameable, fallback_value: :nameable end class SchemaWithoutTransactionName < GraphQL::Schema @@ -61,6 +73,11 @@ class SchemaWithScalarTrace < GraphQL::Schema query(Query) trace_with(GraphQL::Tracing::NewRelicTrace, trace_scalars: true) end + + class SchemaWithoutAuthorizedOrResolveType < GraphQL::Schema + query(Query) + trace_with(GraphQL::Tracing::NewRelicTrace, set_transaction_name: true, trace_authorized: false, trace_resolve_type: false) + end end before do @@ -149,4 +166,29 @@ class SchemaWithScalarTrace < GraphQL::Schema ] assert_equal expected_steps, NewRelic::EXECUTION_SCOPES end + + it "can skip authorized and resolve type" do + NewRelicTraceTest::SchemaWithoutAuthorizedOrResolveType.execute("{ nameable { name } }") + expected_steps = [ + "GraphQL/parse", + "FINISH GraphQL/parse", + "GraphQL/execute", + "GraphQL/analyze", + "GraphQL/validate", + "FINISH GraphQL/validate", + "FINISH GraphQL/analyze", + # "GraphQL/Authorized/Query", + # "FINISH GraphQL/Authorized/Query", + "GraphQL/Query/nameable", + "FINISH GraphQL/Query/nameable", + # "GraphQL/ResolveType/Nameable", + # "FINISH GraphQL/ResolveType/Nameable", + # "GraphQL/Authorized/Other", + # "FINISH GraphQL/Authorized/Other", + "GraphQL/Other/name", + "FINISH GraphQL/Other/name", + "FINISH GraphQL/execute" + ] + assert_equal expected_steps, NewRelic::EXECUTION_SCOPES + end end From 9246b563d61a9ed304c0216007656d8d2b31b879 Mon Sep 17 00:00:00 2001 From: Robert Mosolgo Date: Tue, 18 Feb 2025 06:33:37 -0500 Subject: [PATCH 5/6] improve test coverage --- spec/graphql/tracing/new_relic_trace_spec.rb | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/spec/graphql/tracing/new_relic_trace_spec.rb b/spec/graphql/tracing/new_relic_trace_spec.rb index 595d598497..45eae3c990 100644 --- a/spec/graphql/tracing/new_relic_trace_spec.rb +++ b/spec/graphql/tracing/new_relic_trace_spec.rb @@ -191,4 +191,10 @@ class SchemaWithoutAuthorizedOrResolveType < GraphQL::Schema ] assert_equal expected_steps, NewRelic::EXECUTION_SCOPES end + + it "can generate a transaction name without a selected operation" do + res = NewRelicTraceTest::SchemaWithTransactionName.execute("query Q1 { other { name } } query Q2 { other { name } }") + assert_equal ["An operation name is required"], res["errors"].map { |e| e["message"] } + assert_equal ["GraphQL/query.anonymous"], NewRelic::TRANSACTION_NAMES + end end From 5451eba3c1078234461dcbb29df3387f675ec7f0 Mon Sep 17 00:00:00 2001 From: Robert Mosolgo Date: Tue, 18 Feb 2025 15:03:11 -0500 Subject: [PATCH 6/6] Add hooks for _lazy events --- lib/graphql/execution/interpreter/runtime.rb | 11 ++++- lib/graphql/schema/object.rb | 26 +++++++---- spec/graphql/tracing/new_relic_trace_spec.rb | 48 +++++++++++++++++++- 3 files changed, 71 insertions(+), 14 deletions(-) diff --git a/lib/graphql/execution/interpreter/runtime.rb b/lib/graphql/execution/interpreter/runtime.rb index ac56b699de..dbc40e31d1 100644 --- a/lib/graphql/execution/interpreter/runtime.rb +++ b/lib/graphql/execution/interpreter/runtime.rb @@ -789,8 +789,10 @@ def after_lazy(lazy_obj, field:, owner_object:, arguments:, ast_node:, result:, runtime_state.was_authorized_by_scope_items = was_authorized_by_scope_items # Wrap the execution of _this_ method with tracing, # but don't wrap the continuation below + result = nil inner_obj = begin - if trace + result = if trace + @current_trace.begin_execute_field(field, owner_object, arguments, 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 @@ -805,6 +807,10 @@ def after_lazy(lazy_obj, field:, owner_object:, arguments:, ast_node:, result:, rescue GraphQL::ExecutionError => ex_err ex_err end + ensure + if trace + @current_trace.end_execute_field(field, owner_object, arguments, query, result) + end end yield(inner_obj, runtime_state) end @@ -852,9 +858,11 @@ def resolve_type(type, value) resolved_type, resolved_value = @current_trace.resolve_type(query: query, type: type, object: value) do query.resolve_type(type, value) end + @current_trace.end_resolve_type(type, value, context, resolved_type) if lazy?(resolved_type) GraphQL::Execution::Lazy.new do + @current_trace.begin_resolve_type(type, value, context) @current_trace.resolve_type_lazy(query: query, type: type, object: value) do rt = schema.sync_lazy(resolved_type) @current_trace.end_resolve_type(type, value, context, rt) @@ -862,7 +870,6 @@ def resolve_type(type, value) end end else - @current_trace.end_resolve_type(type, value, context, resolved_type) [resolved_type, resolved_value] end end diff --git a/lib/graphql/schema/object.rb b/lib/graphql/schema/object.rb index 2e542d63bf..e1f5a99f09 100644 --- a/lib/graphql/schema/object.rb +++ b/lib/graphql/schema/object.rb @@ -66,21 +66,28 @@ def wrap(object, context) # @return [GraphQL::Schema::Object, GraphQL::Execution::Lazy] # @raise [GraphQL::UnauthorizedError] if the user-provided hook returns `false` def authorized_new(object, context) - maybe_lazy_auth_val = context.query.current_trace.authorized(query: context.query, type: self, object: object) do - begin - context.query.current_trace.begin_authorized(self, object, context) - authorized?(object, context) - rescue GraphQL::UnauthorizedError => err - context.schema.unauthorized_object(err) - rescue StandardError => err - context.query.handle_or_reraise(err) + context.query.current_trace.begin_authorized(self, object, context) + begin + maybe_lazy_auth_val = context.query.current_trace.authorized(query: context.query, type: self, object: object) do + begin + authorized?(object, context) + rescue GraphQL::UnauthorizedError => err + context.schema.unauthorized_object(err) + rescue StandardError => err + context.query.handle_or_reraise(err) + end end + ensure + context.query.current_trace.end_authorized(self, object, context, maybe_lazy_auth_val) end auth_val = if context.schema.lazy?(maybe_lazy_auth_val) GraphQL::Execution::Lazy.new do + context.query.current_trace.begin_authorized(self, object, context) context.query.current_trace.authorized_lazy(query: context.query, type: self, object: object) do - context.schema.sync_lazy(maybe_lazy_auth_val) + res = context.schema.sync_lazy(maybe_lazy_auth_val) + context.query.current_trace.end_authorized(self, object, context, res) + res end end else @@ -88,7 +95,6 @@ def authorized_new(object, context) end context.query.after_lazy(auth_val) do |is_authorized| - context.query.current_trace.end_authorized(self, object, context, is_authorized) if is_authorized self.new(object, context) else diff --git a/spec/graphql/tracing/new_relic_trace_spec.rb b/spec/graphql/tracing/new_relic_trace_spec.rb index 45eae3c990..62995149db 100644 --- a/spec/graphql/tracing/new_relic_trace_spec.rb +++ b/spec/graphql/tracing/new_relic_trace_spec.rb @@ -23,11 +23,14 @@ module Nameable field :name, String def self.resolve_type(abs_type, ctx) - Other + ctx[:lazy] ? -> { Other } : Other end end class Other < GraphQL::Schema::Object implements Nameable + def self.authorized?(obj, ctx) + ctx[:lazy] ? -> { true } : true + end field :name, String, fallback_value: "other" end @@ -47,6 +50,8 @@ def other end field :nameable, Nameable, fallback_value: :nameable + + field :lazy_nameable, Nameable, fallback_value: -> { :nameable } end class SchemaWithoutTransactionName < GraphQL::Schema @@ -58,7 +63,7 @@ def self.object_from_id(_id, _ctx) :thing end - def self.resolve_type(_type, _obj, _ctx) + def self.resolve_type(_type, _obj, ctx) Thing end end @@ -67,6 +72,7 @@ class SchemaWithTransactionName < GraphQL::Schema query(Query) trace_with(GraphQL::Tracing::NewRelicTrace, set_transaction_name: true) use GraphQL::Dataloader + lazy_resolve(Proc, :call) end class SchemaWithScalarTrace < GraphQL::Schema @@ -197,4 +203,42 @@ class SchemaWithoutAuthorizedOrResolveType < GraphQL::Schema assert_equal ["An operation name is required"], res["errors"].map { |e| e["message"] } assert_equal ["GraphQL/query.anonymous"], NewRelic::TRANSACTION_NAMES end + + it "handles lazies" do + NewRelicTraceTest::SchemaWithTransactionName.execute("{ lazyNameable { name } }", context: { lazy: true }) + expected_steps = [ + "GraphQL/parse", + "FINISH GraphQL/parse", + "GraphQL/execute", + "GraphQL/analyze", + "GraphQL/validate", + "FINISH GraphQL/validate", + "FINISH GraphQL/analyze", + "GraphQL/Authorized/Query", + "FINISH GraphQL/Authorized/Query", + # Eager: + "GraphQL/Query/lazyNameable", + "FINISH GraphQL/Query/lazyNameable", + # Lazy: + "GraphQL/Query/lazyNameable", + "FINISH GraphQL/Query/lazyNameable", + + # Eager/lazy: + "GraphQL/ResolveType/Nameable", + "FINISH GraphQL/ResolveType/Nameable", + "GraphQL/ResolveType/Nameable", + "FINISH GraphQL/ResolveType/Nameable", + + # Eager/lazy: + "GraphQL/Authorized/Other", + "FINISH GraphQL/Authorized/Other", + "GraphQL/Authorized/Other", + "FINISH GraphQL/Authorized/Other", + + "GraphQL/Other/name", + "FINISH GraphQL/Other/name", + "FINISH GraphQL/execute", + ] + assert_equal expected_steps, NewRelic::EXECUTION_SCOPES + end end