diff --git a/README.md b/README.md index f1695fd..86b88ee 100644 --- a/README.md +++ b/README.md @@ -48,7 +48,7 @@ etc. What you do with these captured metrics is up to you! **NOTE**: If any non-`graphql-ruby` gem-related exceptions occur in your application during query document -parsing and validation, **runtime metrics** for queries (like `query_duration`, `parsing_start_time_offset` etc.) as well as field +parsing and validation, **runtime metrics** for queries (like `query_duration`, etc.) as well as field resolver timings (like `resolver_timings`, `lazy_resolver_timings`) **may not be present** in the extracted `metrics` hash, even if you opt to collect them by using `GraphQL::Metrics::Analyzer` and `GraphQL::Metrics::Tracer`. @@ -75,13 +75,9 @@ even if you opt to collect them by using `GraphQL::Metrics::Analyzer` and `Graph # operation_name: "PostDetails", # query_start_time: 1573833076.027327, # query_duration: 2.0207119999686256, - # lexing_start_time_offset: 0.0010339999571442604, # lexing_duration: 0.0008190000080503523, - # parsing_start_time_offset: 0.0010339999571442604, # parsing_duration: 0.0008190000080503523, - # validation_start_time_offset: 0.0030819999519735575, # validation_duration: 0.01704599999357015, - # analysis_start_time_offset: 0.0010339999571442604, # analysis_duration: 0.0008190000080503523, # multiplex_start_time: 0.0008190000080503523, # } @@ -129,12 +125,10 @@ even if you opt to collect them by using `GraphQL::Metrics::Analyzer` and `Graph # deprecated: false, # path: ["post", "id"], # resolver_timings: [ - # start_time_offset: 0.011901999998372048, - # duration: 5.999987479299307e-06 + # 5.999987479299307e-06, # ], # lazy_resolver_timings: [ - # start_time_offset: 0.031901999998372048, - # duration: 5.999987479299307e-06 + # 5.999987479299307e-06, # ], # } def field_extracted(metrics) diff --git a/lib/graphql/metrics.rb b/lib/graphql/metrics.rb index 11af214..9318643 100644 --- a/lib/graphql/metrics.rb +++ b/lib/graphql/metrics.rb @@ -27,13 +27,9 @@ module Metrics MULTIPLEX_START_TIME_MONOTONIC = :multiplex_start_time_monotonic QUERY_START_TIME = :query_start_time QUERY_START_TIME_MONOTONIC = :query_start_time_monotonic - LEXING_START_TIME_OFFSET = :lexing_start_time_offset LEXING_DURATION = :lexing_duration - PARSING_START_TIME_OFFSET = :parsing_start_time_offset PARSING_DURATION = :parsing_duration - VALIDATION_START_TIME_OFFSET = :validation_start_time_offset VALIDATION_DURATION = :validation_duration - ANALYSIS_START_TIME_OFFSET = :analysis_start_time_offset ANALYSIS_DURATION = :analysis_duration INLINE_FIELD_TIMINGS = :inline_field_timings LAZY_FIELD_TIMINGS = :lazy_field_timings @@ -51,40 +47,11 @@ def self.current_time_monotonic Process.clock_gettime(Process::CLOCK_MONOTONIC) end - def self.time(offset_time = nil) + def self.time start_time = current_time_monotonic result = yield duration = current_time_monotonic - start_time - time_since_offset = start_time - offset_time if offset_time - TimedResult.new(start_time, duration, time_since_offset, result) - end - - class TimedResult - # NOTE: `time_since_offset` is used to produce start times timed phases of execution (validation, field - # resolution). These start times are relative to the executed operation's start time, which is captured at the - # outset of document parsing. - # - # The times produced are intentionally similar to: - # https://github.com/apollographql/apollo-tracing#response-format - # - # Taking a field resolver start offset example: - # - # < start offset > - # |------------------|----------|---------> - # OS (t=0) FS (t=1) FE (t=2) - # - # OS = Operation start time - # FS = Field resolver start time - # FE = Field resolver end time - # - attr_reader :result, :start_time, :duration, :time_since_offset - - def initialize(start_time, duration, time_since_offset, result) - @start_time = start_time - @duration = duration - @time_since_offset = time_since_offset - @result = result - end + [result, duration] end end end diff --git a/lib/graphql/metrics/instrumentation.rb b/lib/graphql/metrics/instrumentation.rb index d5e8ab8..a7eaa0a 100644 --- a/lib/graphql/metrics/instrumentation.rb +++ b/lib/graphql/metrics/instrumentation.rb @@ -41,13 +41,9 @@ def after_query(query) runtime_query_metrics = { query_start_time: ns[GraphQL::Metrics::QUERY_START_TIME], query_duration: query_duration, - parsing_start_time_offset: ns[GraphQL::Metrics::PARSING_START_TIME_OFFSET], parsing_duration: ns[GraphQL::Metrics::PARSING_DURATION], - validation_start_time_offset: ns[GraphQL::Metrics::VALIDATION_START_TIME_OFFSET], validation_duration: ns[GraphQL::Metrics::VALIDATION_DURATION], - lexing_start_time_offset: ns[GraphQL::Metrics::LEXING_START_TIME_OFFSET], lexing_duration: ns[GraphQL::Metrics::LEXING_DURATION], - analysis_start_time_offset: ns[GraphQL::Metrics::ANALYSIS_START_TIME_OFFSET], analysis_duration: ns[GraphQL::Metrics::ANALYSIS_DURATION], multiplex_start_time: ns[GraphQL::Metrics::MULTIPLEX_START_TIME], } diff --git a/lib/graphql/metrics/trace.rb b/lib/graphql/metrics/trace.rb index b1d0804..1b06a0a 100644 --- a/lib/graphql/metrics/trace.rb +++ b/lib/graphql/metrics/trace.rb @@ -82,17 +82,13 @@ def skip_tracing?(query_or_multiplex) PreContext = Struct.new( :multiplex_start_time, :multiplex_start_time_monotonic, - :parsing_start_time_offset, :parsing_duration, - :lexing_start_time_offset, :lexing_duration ) do def reset self[:multiplex_start_time] = nil self[:multiplex_start_time_monotonic] = nil - self[:parsing_start_time_offset] = nil self[:parsing_duration] = nil - self[:lexing_start_time_offset] = nil self[:lexing_duration] = nil end end @@ -112,21 +108,19 @@ def capture_multiplex_start_time end def capture_lexing_time - timed_result = GraphQL::Metrics.time { yield } + result, duration = GraphQL::Metrics.time { yield } - pre_context.lexing_start_time_offset = timed_result.start_time - pre_context.lexing_duration = timed_result.duration + pre_context.lexing_duration = duration - timed_result.result + result end def capture_parsing_time - timed_result = GraphQL::Metrics.time { yield } + result, duration = GraphQL::Metrics.time { yield } - pre_context.parsing_start_time_offset = timed_result.start_time - pre_context.parsing_duration = timed_result.duration + pre_context.parsing_duration = duration - timed_result.result + result end # Also consolidates parsing timings (if any) from the `pre_context` @@ -134,39 +128,33 @@ def capture_validation_time(context) # Queries may already be lexed and parsed before execution (whether a single query or multiplex). # If we don't have those values, use some sane defaults. if [nil, 0].include?(pre_context.lexing_duration) - pre_context.lexing_start_time_offset = pre_context.multiplex_start_time pre_context.lexing_duration = 0.0 end if pre_context.parsing_duration.nil? - pre_context.parsing_start_time_offset = pre_context.multiplex_start_time pre_context.parsing_duration = 0.0 end - timed_result = GraphQL::Metrics.time(pre_context.multiplex_start_time_monotonic) { yield } + result, duration = GraphQL::Metrics.time { yield } ns = context.namespace(CONTEXT_NAMESPACE) ns[MULTIPLEX_START_TIME] = pre_context.multiplex_start_time ns[MULTIPLEX_START_TIME_MONOTONIC] = pre_context.multiplex_start_time_monotonic - ns[LEXING_START_TIME_OFFSET] = pre_context.lexing_start_time_offset ns[LEXING_DURATION] = pre_context.lexing_duration - ns[PARSING_START_TIME_OFFSET] = pre_context.parsing_start_time_offset ns[PARSING_DURATION] = pre_context.parsing_duration - ns[VALIDATION_START_TIME_OFFSET] = timed_result.time_since_offset - ns[VALIDATION_DURATION] = timed_result.duration + ns[VALIDATION_DURATION] = duration - timed_result.result + result end def capture_analysis_time(context) ns = context.namespace(CONTEXT_NAMESPACE) - timed_result = GraphQL::Metrics.time(ns[MULTIPLEX_START_TIME_MONOTONIC]) { yield } + result, duration = GraphQL::Metrics.time { yield } - ns[ANALYSIS_START_TIME_OFFSET] = timed_result.time_since_offset - ns[ANALYSIS_DURATION] = timed_result.duration + ns[ANALYSIS_DURATION] = duration - timed_result.result + result end def capture_query_start_time(context) @@ -179,20 +167,13 @@ def capture_query_start_time(context) def trace_field(context_key, query) ns = query.context.namespace(CONTEXT_NAMESPACE) - offset_time = ns[GraphQL::Metrics::QUERY_START_TIME_MONOTONIC] - start_time = GraphQL::Metrics.current_time_monotonic path = query.context[:current_path] - result = yield - - duration = GraphQL::Metrics.current_time_monotonic - start_time - time_since_offset = start_time - offset_time if offset_time + result, duration = GraphQL::Metrics.time { yield } path_excluding_numeric_indicies = path.select { |p| p.is_a?(String) } ns[context_key][path_excluding_numeric_indicies] ||= [] - ns[context_key][path_excluding_numeric_indicies] << { - start_time_offset: time_since_offset, duration: duration - } + ns[context_key][path_excluding_numeric_indicies] << duration result end diff --git a/test/unit/graphql/metrics/integration_test.rb b/test/unit/graphql/metrics/integration_test.rb index 2f70a91..a63a6d7 100644 --- a/test/unit/graphql/metrics/integration_test.rb +++ b/test/unit/graphql/metrics/integration_test.rb @@ -548,13 +548,9 @@ def self.parse_error(err, _context) :operation_name=>"PostDetails", :query_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration=>SomeNumber.new(at_least: 2), - :lexing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration=>SomeNumber.new(at_least: 0), - :parsing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration=>SomeNumber.new(at_least: 0), - :validation_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), } @@ -590,8 +586,6 @@ def self.parse_error(err, _context) second_query_result = second_query_context[:simple_extractor_results][:queries][0] - assert(first_query_result[:lexing_start_time_offset] < second_query_result[:lexing_start_time_offset]) - assert(first_query_result[:parsing_start_time_offset] < second_query_result[:parsing_start_time_offset]) assert_equal(0.0, second_query_result[:lexing_duration]) assert_equal(0.0, second_query_result[:parsing_duration]) end @@ -655,13 +649,9 @@ def self.parse_error(err, _context) :operation_name => "OtherQuery", :query_start_time => SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :lexing_start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration => SomeNumber.new(at_least: 0), - :parsing_start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration => SomeNumber.new(at_least: 0), - :validation_start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), }] @@ -672,10 +662,7 @@ def self.parse_error(err, _context) :parent_type_name => "Post", :deprecated => false, :path => ["post", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "title", @@ -683,10 +670,7 @@ def self.parse_error(err, _context) :parent_type_name => "Post", :deprecated => false, :path => ["post", "title"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "post", @@ -694,10 +678,7 @@ def self.parse_error(err, _context) :parent_type_name => "QueryRoot", :deprecated => false, :path => ["post"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }] @@ -1042,13 +1023,9 @@ def shared_expected_arguments_metrics :operation_name=>"PostCreate", :query_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :lexing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration=>SomeNumber.new(at_least: lexing_duration_for_graphql_version), - :parsing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :validation_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), } @@ -1064,10 +1041,7 @@ def shared_expected_arguments_metrics :parent_type_name => "Post", :deprecated => false, :path => ["postCreate", "post", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "post", @@ -1075,10 +1049,7 @@ def shared_expected_arguments_metrics :parent_type_name => "PostCreatePayload", :deprecated => false, :path => ["postCreate", "post"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "postCreate", @@ -1086,10 +1057,7 @@ def shared_expected_arguments_metrics :parent_type_name => "MutationRoot", :deprecated => false, :path => ["postCreate"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }] @@ -1481,13 +1449,9 @@ def kitchen_sink_expected_queries :operation_name=>"PostDetails", :query_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration=>SomeNumber.new(at_least: 2), - :lexing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration=>SomeNumber.new(at_least: lexing_duration_for_graphql_version), - :parsing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :validation_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), } @@ -1501,10 +1465,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "title", @@ -1512,10 +1473,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "title"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1523,10 +1481,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "ignoredAlias"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "deprecatedBody", @@ -1534,10 +1489,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => true, :path => ["post", "deprecatedBody"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "id", @@ -1545,13 +1497,10 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1559,13 +1508,10 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "body"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "id", @@ -1573,19 +1519,12 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "comments", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1593,19 +1532,12 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "comments", "body"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "comments", @@ -1613,47 +1545,36 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "comments"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], - :lazy_resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: 1) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }] + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], + :lazy_resolver_timings => [ + SomeNumber.new(at_least: 1), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], }, { :field_name => "comments", :return_type_name => "Comment", :parent_type_name => "Post", :deprecated => false, :path => ["post", "comments"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], - :lazy_resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: 1) - }] + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], + :lazy_resolver_timings => [ + SomeNumber.new(at_least: 1), + ], }, { :field_name => "id", :return_type_name => "ID", :parent_type_name => "Comment", :deprecated => false, :path => ["post", "otherComments", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1661,13 +1582,10 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "otherComments", "body"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "comments", @@ -1675,24 +1593,21 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "otherComments"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], - :lazy_resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }] + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], + :lazy_resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], }, { :field_name => "post", :return_type_name => "Post", :parent_type_name => "QueryRoot", :deprecated => false, :path => ["post"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }] end diff --git a/test/unit/graphql/metrics/trace_integration_test.rb b/test/unit/graphql/metrics/trace_integration_test.rb index c2f27ce..b556a6a 100644 --- a/test/unit/graphql/metrics/trace_integration_test.rb +++ b/test/unit/graphql/metrics/trace_integration_test.rb @@ -508,13 +508,9 @@ def self.parse_error(err, _context) :operation_name=>"PostDetails", :query_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration=>SomeNumber.new(at_least: 2), - :lexing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration=>SomeNumber.new(at_least: lexing_duration_for_graphql_version), - :parsing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration=>SomeNumber.new(at_least: 0), - :validation_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), } @@ -583,13 +579,9 @@ def self.parse_error(err, _context) :operation_name => "OtherQuery", :query_start_time => SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :lexing_start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration => SomeNumber.new(at_least: lexing_duration_for_graphql_version), - :parsing_start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration => SomeNumber.new(at_least: 0), - :validation_start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), }] @@ -600,10 +592,7 @@ def self.parse_error(err, _context) :parent_type_name => "Post", :deprecated => false, :path => ["post", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "title", @@ -611,10 +600,7 @@ def self.parse_error(err, _context) :parent_type_name => "Post", :deprecated => false, :path => ["post", "title"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "post", @@ -622,10 +608,7 @@ def self.parse_error(err, _context) :parent_type_name => "QueryRoot", :deprecated => false, :path => ["post"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }] @@ -970,13 +953,9 @@ def shared_expected_arguments_metrics :operation_name=>"PostCreate", :query_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :lexing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration=>SomeNumber.new(at_least: lexing_duration_for_graphql_version), - :parsing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :validation_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), } @@ -992,10 +971,7 @@ def shared_expected_arguments_metrics :parent_type_name => "Post", :deprecated => false, :path => ["postCreate", "post", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "post", @@ -1003,10 +979,7 @@ def shared_expected_arguments_metrics :parent_type_name => "PostCreatePayload", :deprecated => false, :path => ["postCreate", "post"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "postCreate", @@ -1014,10 +987,7 @@ def shared_expected_arguments_metrics :parent_type_name => "MutationRoot", :deprecated => false, :path => ["postCreate"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }] @@ -1409,13 +1379,9 @@ def kitchen_sink_expected_queries :operation_name=>"PostDetails", :query_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), :query_duration=>SomeNumber.new(at_least: 2), - :lexing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :lexing_duration=>SomeNumber.new(at_least: lexing_duration_for_graphql_version), - :parsing_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :parsing_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :validation_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :validation_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :analysis_start_time_offset=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :analysis_duration=>SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), :multiplex_start_time=>SomeNumber.new(at_least: REASONABLY_RECENT_UNIX_TIME), } @@ -1429,10 +1395,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "title", @@ -1440,10 +1403,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "title"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1451,10 +1411,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "ignoredAlias"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "deprecatedBody", @@ -1462,10 +1419,7 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => true, :path => ["post", "deprecatedBody"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [SomeNumber.new(at_least: SMALL_NONZERO_NUMBER)], :lazy_resolver_timings => [], }, { :field_name => "id", @@ -1473,13 +1427,10 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1487,13 +1438,10 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "body"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "id", @@ -1501,19 +1449,12 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "comments", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1521,19 +1462,12 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "comments", "body"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "comments", @@ -1541,47 +1475,36 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "comments", "comments"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], - :lazy_resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: 1) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }] + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], + :lazy_resolver_timings => [ + SomeNumber.new(at_least: 1), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], }, { :field_name => "comments", :return_type_name => "Comment", :parent_type_name => "Post", :deprecated => false, :path => ["post", "comments"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], - :lazy_resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: 1) - }] + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], + :lazy_resolver_timings => [ + SomeNumber.new(at_least: 1), + ], }, { :field_name => "id", :return_type_name => "ID", :parent_type_name => "Comment", :deprecated => false, :path => ["post", "otherComments", "id"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "body", @@ -1589,13 +1512,10 @@ def kitchen_sink_expected_fields :parent_type_name => "Comment", :deprecated => false, :path => ["post", "otherComments", "body"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }, { - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }, { :field_name => "comments", @@ -1603,24 +1523,21 @@ def kitchen_sink_expected_fields :parent_type_name => "Post", :deprecated => false, :path => ["post", "otherComments"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], - :lazy_resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }] + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], + :lazy_resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], }, { :field_name => "post", :return_type_name => "Post", :parent_type_name => "QueryRoot", :deprecated => false, :path => ["post"], - :resolver_timings => [{ - :start_time_offset => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), - :duration => SomeNumber.new(at_least: SMALL_NONZERO_NUMBER) - }], + :resolver_timings => [ + SomeNumber.new(at_least: SMALL_NONZERO_NUMBER), + ], :lazy_resolver_timings => [], }] end