Class: NewRelic::Agent::Threading::BacktraceService

Inherits:
Object
  • Object
show all
Defined in:
lib/new_relic/agent/threading/backtrace_service.rb

Constant Summary collapse

ALL_TRANSACTIONS = 
'**ALL**'.freeze
MAX_BUFFER_LENGTH = 
500

Instance Attribute Summary collapse

Class Method Summary collapse

Instance Method Summary collapse

Constructor Details

#initialize(event_listener = nil) ⇒ BacktraceService

Returns a new instance of BacktraceService.



26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 26

def initialize(event_listener = nil)
  @profiles = {}
  @buffer = {}
  @last_poll = nil

  # synchronizes access to @profiles and @buffer above
  @lock = Mutex.new

  @running = false
  @profile_agent_code = false
  @worker_loop = NewRelic::Agent::WorkerLoop.new

  # Memoize overhead % to avoid getting stale OR looked up every poll
  @overhead_percent_threshold = NewRelic::Agent.config[:'thread_profiler.max_profile_overhead']
  NewRelic::Agent.config.register_callback(:'thread_profiler.max_profile_overhead') do |new_value|
    @overhead_percent_threshold = new_value
  end

  event_listener&.subscribe(:transaction_finished, &method(:on_transaction_finished))
end

Instance Attribute Details

#buffer ⇒ Object (readonly)

Returns the value of attribute buffer.



22
23
24
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 22

def buffer
  @buffer
end

#effective_polling_period ⇒ Object

Returns the value of attribute effective_polling_period.



22
23
24
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 22

def effective_polling_period
  @effective_polling_period
end

#overhead_percent_threshold ⇒ Object (readonly)

Returns the value of attribute overhead_percent_threshold.



22
23
24
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 22

def overhead_percent_threshold
  @overhead_percent_threshold
end

#profile_agent_code ⇒ Object

Returns the value of attribute profile_agent_code.



24
25
26
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 24

def profile_agent_code
  @profile_agent_code
end

#profiles ⇒ Object (readonly)

This method is expected to be called with @lock held.



181
182
183
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 181

def profiles
  @profiles
end

#worker_loop ⇒ Object (readonly)

Returns the value of attribute worker_loop.



22
23
24
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 22

def worker_loop
  @worker_loop
end

#worker_thread ⇒ Object

Returns the value of attribute worker_thread.



24
25
26
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 24

def worker_thread
  @worker_thread
end

Class Method Details

.is_resque? ⇒ Boolean

Because of Resque’s forking, we don’t poll thread backtraces for it. To accomplish that would require starting a new backtracing thread in each forked worker, and merging profiles across the pipe channel.

Returns:

  • (Boolean) 


18
19
20
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 18

def self.is_resque?
  NewRelic::Agent.config[:dispatcher] == :resque
end

.is_supported? ⇒ Boolean

Returns:

  • (Boolean) 


11
12
13
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 11

def self.is_supported?
  !is_resque?
end

Instance Method Details

#adjust_polling_time(now, poll_start) ⇒ Object

If our overhead % exceeds the threshold, bump the next poll period relative to how much larger our overhead is than allowed



249
250
251
252
253
254
255
256
257
258
259
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 249

def adjust_polling_time(now, poll_start)
  duration = now - poll_start
  overhead_percent = duration / effective_polling_period

  if overhead_percent > self.overhead_percent_threshold
    scale_up_by = overhead_percent / self.overhead_percent_threshold
    worker_loop.period = effective_polling_period * scale_up_by
  else
    worker_loop.period = effective_polling_period
  end
end

#aggregate_backtraces(backtraces, name, start, duration, bucket, thread) ⇒ Object

This method is expected to be called with @lock held.



130
131
132
133
134
135
136
137
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 130

def aggregate_backtraces(backtraces, name, start, duration, bucket, thread)
  end_time = start + duration
  backtraces.each do |(timestamp, backtrace)|
    if timestamp >= start && timestamp < end_time
      @profiles[name].aggregate(backtrace, bucket, thread)
    end
  end
end

#aggregate_global_backtrace(backtrace, bucket, thread) ⇒ Object

This method is expected to be called with @lock held.



221
222
223
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 221

def aggregate_global_backtrace(backtrace, bucket, thread)
  @profiles[ALL_TRANSACTIONS]&.aggregate(backtrace, bucket, thread)
end

#allowed_bucket?(bucket) ⇒ Boolean

Returns:

  • (Boolean) 


202
203
204
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 202

def allowed_bucket?(bucket)
  bucket == :request || bucket == :background
end

#buffer_backtrace_for_thread(thread, timestamp, backtrace, bucket) ⇒ Object

This method is expected to be called with @lock held.



209
210
211
212
213
214
215
216
217
218
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 209

def buffer_backtrace_for_thread(thread, timestamp, backtrace, bucket)
  if should_buffer?(bucket)
    @buffer[thread] ||= []
    if @buffer[thread].length < MAX_BUFFER_LENGTH
      @buffer[thread] << [timestamp, backtrace]
    else
      NewRelic::Agent.increment_metric('Supportability/ThreadProfiler/DroppedBacktraces')
    end
  end
end

#find_effective_polling_period ⇒ Object

This method is expected to be called with @lock held.



238
239
240
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 238

def find_effective_polling_period
  @profiles.values.map { |p| p.requested_period }.min
end

#harvest(transaction_name) ⇒ Object 



102
103
104
105
106
107
108
109
110
111
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 102

def harvest(transaction_name)
  @lock.synchronize do
    if @profiles[transaction_name]
      profile = @profiles.delete(transaction_name)
      profile.finished_at = Process.clock_gettime(Process::CLOCK_REALTIME)
      @profiles[transaction_name] = ThreadProfile.new(profile.command_arguments)
      profile
    end
  end
end

#need_backtrace?(bucket) ⇒ Boolean

This method is expected to be called with @lock held.

Returns:

  • (Boolean) 


189
190
191
192
193
194
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 189

def need_backtrace?(bucket)
  (
    bucket != :ignore &&
    (@profiles[ALL_TRANSACTIONS] || should_buffer?(bucket))
  )
end

#on_transaction_finished(payload) ⇒ Object 



113
114
115
116
117
118
119
120
121
122
123
124
125
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 113

def on_transaction_finished(payload)
  name = payload[:name]
  start = payload[:start_timestamp]
  duration = payload[:duration]
  thread = payload[:thread] || Thread.current
  bucket = payload[:bucket]
  @lock.synchronize do
    backtraces = @buffer.delete(thread)
    if backtraces && @profiles.has_key?(name)
      aggregate_backtraces(backtraces, name, start, duration, bucket, thread)
    end
  end
end

#poll ⇒ Object 



164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 164

def poll
  poll_start = Process.clock_gettime(Process::CLOCK_REALTIME)

  @lock.synchronize do
    AgentThread.list.each do |thread|
      sample_thread(thread)
    end
    @profiles.each_value { |p| p.increment_poll_count }
    @buffer.delete_if { |thread, _| !thread.alive? }
  end

  end_time = Process.clock_gettime(Process::CLOCK_REALTIME)
  adjust_polling_time(end_time, poll_start)
  record_supportability_metrics(end_time, poll_start)
end

#record_polling_time(now, poll_start) ⇒ Object 



266
267
268
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 266

def record_polling_time(now, poll_start)
  NewRelic::Agent.record_metric('Supportability/ThreadProfiler/PollingTime', now - poll_start)
end

#record_skew(poll_start) ⇒ Object 



270
271
272
273
274
275
276
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 270

def record_skew(poll_start)
  if @last_poll
    skew = poll_start - @last_poll - worker_loop.period
    NewRelic::Agent.record_metric('Supportability/ThreadProfiler/Skew', skew)
  end
  @last_poll = poll_start
end

#record_supportability_metrics(now, poll_start) ⇒ Object 



261
262
263
264
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 261

def record_supportability_metrics(now, poll_start)
  record_polling_time(now, poll_start)
  record_skew(poll_start)
end

#running? ⇒ Boolean

Public interface

Returns:

  • (Boolean) 


49
50
51
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 49

def running?
  @running
end

#sample_thread(thread) ⇒ Object

This method is expected to be called with @lock held.



226
227
228
229
230
231
232
233
234
235
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 226

def sample_thread(thread)
  bucket = AgentThread.bucket_thread(thread, @profile_agent_code)

  if need_backtrace?(bucket)
    timestamp = Process.clock_gettime(Process::CLOCK_REALTIME)
    backtrace = AgentThread.scrub_backtrace(thread, @profile_agent_code)
    aggregate_global_backtrace(backtrace, bucket, thread)
    buffer_backtrace_for_thread(thread, timestamp, backtrace, bucket)
  end
end

#should_buffer?(bucket) ⇒ Boolean

This method is expected to be called with @lock held.

Returns:

  • (Boolean) 


184
185
186
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 184

def should_buffer?(bucket)
  allowed_bucket?(bucket) && watching_for_transaction?
end

#should_profile_agent_code? ⇒ Boolean

This method is expected to be called with @lock held.

Returns:

  • (Boolean) 


243
244
245
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 243

def should_profile_agent_code?
  @profiles.values.any? { |p| p.profile_agent_code }
end

#start ⇒ Object 



139
140
141
142
143
144
145
146
147
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 139

def start
  return if @running || !self.class.is_supported?

  @running = true
  self.worker_thread = AgentThread.create('Backtrace Service') do
    # Not passing period because we expect it's already been set.
    self.worker_loop.run(&method(:poll))
  end
end

#stop ⇒ Object

This method is expected to be called with @lock held



150
151
152
153
154
155
156
157
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 150

def stop
  return unless @running

  @running = false
  self.worker_loop.stop

  @buffer = {}
end

#subscribe(transaction_name, command_arguments = {}) ⇒ Object 



53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 53

def subscribe(transaction_name, command_arguments = {})
  if self.class.is_resque?
    NewRelic::Agent.logger.info("Backtracing threads on Resque is not supported, so not subscribing transaction '#{transaction_name}'")
    return
  end

  if !self.class.is_supported?
    NewRelic::Agent.logger.debug("Backtracing not supported, so not subscribing transaction '#{transaction_name}'")
    return
  end

  NewRelic::Agent.logger.debug("Backtrace Service subscribing transaction '#{transaction_name}'")

  profile = ThreadProfile.new(command_arguments)

  @lock.synchronize do
    @profiles[transaction_name] = profile
    update_values_from_profiles
  end

  start
  profile
end

#subscribed?(transaction_name) ⇒ Boolean

Returns:

  • (Boolean) 


96
97
98
99
100
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 96

def subscribed?(transaction_name)
  @lock.synchronize do
    @profiles.has_key?(transaction_name)
  end
end

#unsubscribe(transaction_name) ⇒ Object 



77
78
79
80
81
82
83
84
85
86
87
88
89
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 77

def unsubscribe(transaction_name)
  return unless self.class.is_supported?

  NewRelic::Agent.logger.debug("Backtrace Service unsubscribing transaction '#{transaction_name}'")
  @lock.synchronize do
    @profiles.delete(transaction_name)
    if @profiles.empty?
      stop
    else
      update_values_from_profiles
    end
  end
end

#update_values_from_profiles ⇒ Object 



91
92
93
94
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 91

def update_values_from_profiles
  self.effective_polling_period = find_effective_polling_period
  self.profile_agent_code = should_profile_agent_code?
end

#watching_for_transaction? ⇒ Boolean

This method is expected to be called with @lock held

Returns:

  • (Boolean) 


197
198
199
200
 
# File 'lib/new_relic/agent/threading/backtrace_service.rb', line 197

def watching_for_transaction?
  @profiles.size > 1 ||
    (@profiles.size == 1 && @profiles[ALL_TRANSACTIONS].nil?)
end