Module: ApolloFederation::Tracing::Tracer

Defined in:
lib/apollo-federation/tracing/tracer.rb

Constant Summary collapse

EXECUTE_MULTIPLEX =

store string constants to avoid creating new strings for each call to .trace

'execute_multiplex'
EXECUTE_QUERY_LAZY = 
'execute_query_lazy'
EXECUTE_FIELD = 
'execute_field'
EXECUTE_FIELD_LAZY = 
'execute_field_lazy'

Class Method Summary collapse

Instance Method Summary collapse

Class Method Details

.attach_trace_to_result(result) ⇒ Object

rubocop:enable Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity



251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 251

def self.attach_trace_to_result(result)
  return result unless result.context[:tracing_enabled]

  trace = result.context.namespace(ApolloFederation::Tracing::KEY)

  result['errors']&.each do |error|
    trace[:node_map].add_error(error)
  end

  proto = ApolloFederation::Tracing::Trace.new(
    start_time: to_proto_timestamp(trace[:start_time]),
    end_time: to_proto_timestamp(trace[:end_time]),
    duration_ns: trace[:end_time_nanos] - trace[:start_time_nanos],
    root: trace[:node_map].root,
  )

  result[:extensions] ||= {}
  result[:extensions][ApolloFederation::Tracing::KEY] =
    Base64.encode64(proto.class.encode(proto))

  if result.context[:debug_tracing]
    result[:extensions][ApolloFederation::Tracing::DEBUG_KEY] = proto.to_h
  end

  result
end

.execute_field(data, &block) ⇒ Object

Step 2:

  • Record start and end times for the field resolver.

  • Rescue errors so the method doesn’t exit early.

  • Create a trace “node” and attach field details.

  • Propagate the error (if necessary) so it ends up in the top-level errors array.

The values in ‘data` are different depending on the executor runtime. graphql-ruby.org/api-doc/1.9.3/GraphQL/Tracing

Nodes are added the NodeMap stored in the trace hash.

Errors are added to nodes in ‘ApolloFederation::Tracing.attach_trace_to_result` because we don’t have the error ‘location` here. rubocop:disable Metrics/CyclomaticComplexity, Metrics/PerceivedComplexity



164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 164

def self.execute_field(data, &block)
  context = data.fetch(:context, nil) || data.fetch(:query).context
  return block.call unless context && context[:tracing_enabled]

  start_time_nanos = Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond)

  begin
    result = block.call
  rescue StandardError => e
    error = e
  end

  end_time_nanos = Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond)

  # legacy runtime
  if data.include?(:context)
    path = context.path
    field_name = context.field.graphql_name
    field_type = context.field.type.to_s
    parent_type = context.parent_type.graphql_name
  else # interpreter runtime
    path = data.fetch(:path)
    field = data.fetch(:field)
    field_name = field.graphql_name
    field_type = field.type.to_type_signature
    parent_type = data.fetch(:owner).graphql_name
  end

  trace = context.namespace(ApolloFederation::Tracing::KEY)
  node = trace[:node_map].add(path)

  # original_field_name is set only for aliased fields
  node.original_field_name = field_name if field_name != path.last
  node.type = field_type
  node.parent_type = parent_type
  node.start_time = start_time_nanos - trace[:start_time_nanos]
  node.end_time = end_time_nanos - trace[:start_time_nanos]

  raise error if error

  result
end

.execute_field_lazy(data, &block) ⇒ Object

Optional Step 3: Overwrite the end times on the trace node if the resolver was lazy.



209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 209

def self.execute_field_lazy(data, &block)
  context = data.fetch(:context, nil) || data.fetch(:query).context
  return block.call unless context && context[:tracing_enabled]

  begin
    result = block.call
  rescue StandardError => e
    error = e
  end

  end_time_nanos = Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond)

  # legacy runtime
  if data.include?(:context)
    path = context.path
    field = context.field
  else # interpreter runtime
    path = data.fetch(:path)
    field = data.fetch(:field)
  end

  trace = context.namespace(ApolloFederation::Tracing::KEY)

  # When a field is resolved with an array of lazy values, the interpreter fires an
  # `execute_field` for the resolution of the field and then a `execute_field_lazy` event for
  # each lazy value in the array. Since the path here will contain an index (indicating which
  # lazy value we're executing: e.g. ['arrayOfLazies', 0]), we won't have a node for the path.
  # We only care about the end of the parent field (e.g. ['arrayOfLazies']), so we get the
  # node for that path. What ends up happening is we update the end_time for the parent node
  # for each of the lazy values. The last one that's executed becomes the final end time.
  if field.type.list? && path.last.is_a?(Integer)
    path = path[0...-1]
  end
  node = trace[:node_map].node_for_path(path)
  node.end_time = end_time_nanos - trace[:start_time_nanos]

  raise error if error

  result
end

.execute_multiplex(data, &block) ⇒ Object 



94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 94

def self.execute_multiplex(data, &block)
  # Step 1:
  # Create a trace hash on each query's context and record start times.
  data.fetch(:multiplex).queries.each { |query| start_trace(query) }

  results = block.call

  # Step 4.5:
  # Record end times for all queries.
  # This acts as a fallback for queries without lazy values.
  # execute_query_lazy will overwrite these times if lazy values are present.
  data.fetch(:multiplex).queries.each { |query| record_trace_end_time(query) }

  # Step 5
  # Attach the trace to the 'extensions' key of each result
  results.map { |result| attach_trace_to_result(result) }
end

.execute_query_lazy(data, &block) ⇒ Object

Step 4: Record end times and merge them into the trace hash.



124
125
126
127
128
129
130
131
132
133
134
135
136
137
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 124

def self.execute_query_lazy(data, &block)
  result = block.call

  query = data.fetch(:query)
  multiplex = data.fetch(:multiplex)

  if query
    record_trace_end_time(query)
  elsif multiplex
    multiplex.queries.each { |q| record_trace_end_time(q) }
  end

  result
end

.record_trace_end_time(query) ⇒ Object 



139
140
141
142
143
144
145
146
147
148
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 139

def self.record_trace_end_time(query)
  return unless query.context && query.context[:tracing_enabled]

  trace = query.context.namespace(ApolloFederation::Tracing::KEY)

  trace.merge!(
    end_time: Time.now.utc,
    end_time_nanos: Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond),
  )
end

.start_trace(query) ⇒ Object 



112
113
114
115
116
117
118
119
120
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 112

def self.start_trace(query)
  return unless query.context && query.context[:tracing_enabled]

  query.context.namespace(ApolloFederation::Tracing::KEY).merge!(
    start_time: Time.now.utc,
    start_time_nanos: Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond),
    node_map: NodeMap.new,
  )
end

.to_proto_timestamp(time) ⇒ Object 



278
279
280
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 278

def self.to_proto_timestamp(time)
  Google::Protobuf::Timestamp.new(seconds: time.to_i, nanos: time.nsec)
end

.trace(key, data, &block) ⇒ Object

The method below was used by older versions of graphql-ruby. After graphq-ruby 2.3.0 the trace modules should respond to specific methods such as ‘execute_field` above.



79
80
81
82
83
84
85
86
87
88
89
90
91
92
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 79

def self.trace(key, data, &block)
  case key
  when EXECUTE_MULTIPLEX
    execute_multiplex(data, &block)
  when EXECUTE_QUERY_LAZY
    execute_query_lazy(data, &block)
  when EXECUTE_FIELD
    execute_field(data, &block)
  when EXECUTE_FIELD_LAZY
    execute_field_lazy(data, &block)
  else
    yield
  end
end

Instance Method Details

#execute_field(field:, query:, ast_node:, arguments:, object:) ⇒ Object 



53
54
55
56
57
58
59
60
61
62
63
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 53

def execute_field(field:, query:, ast_node:, arguments:, object:)
  ApolloFederation::Tracing::Tracer.execute_field(
    field: field,
    query: query,
    ast_node: ast_node,
    arguments: arguments,
    object: object,
    owner: field.owner,
    path: query.context[:current_path],
  ) { yield }
end

#execute_field_lazy(field:, query:, ast_node:, arguments:, object:) ⇒ Object 



65
66
67
68
69
70
71
72
73
74
75
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 65

def execute_field_lazy(field:, query:, ast_node:, arguments:, object:)
  ApolloFederation::Tracing::Tracer.execute_field_lazy(
    field: field,
    query: query,
    ast_node: ast_node,
    arguments: arguments,
    object: object,
    owner: field.owner,
    path: query.context[:current_path],
  ) { yield }
end

#execute_multiplex(multiplex:) ⇒ Object 



45
46
47
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 45

def execute_multiplex(multiplex:)
  ApolloFederation::Tracing::Tracer.execute_multiplex(multiplex: multiplex) { yield }
end

#execute_query_lazy(query:, multiplex:) ⇒ Object 



49
50
51
 
# File 'lib/apollo-federation/tracing/tracer.rb', line 49

def execute_query_lazy(query:, multiplex:)
  ApolloFederation::Tracing::Tracer.execute_query_lazy(query: query, multiplex: multiplex) { yield }
end