Class: Datadog::Profiling::Collectors::OldStack

Inherits:
Core::Worker
  • Object
show all
Includes:
Core::Workers::Polling
Defined in:
lib/datadog/profiling/collectors/old_stack.rb

Overview

Collects stack trace samples from Ruby threads for both CPU-time (if available) and wall-clock. Runs on its own background thread.

This class has the prefix “Old” because it will be deprecated by the new native CPU Profiler

Constant Summary collapse

DEFAULT_MAX_TIME_USAGE_PCT = 
2.0
MIN_INTERVAL = 
0.01
THREAD_LAST_CPU_TIME_KEY = 
:datadog_profiler_last_cpu_time
THREAD_LAST_WALL_CLOCK_KEY = 
:datadog_profiler_last_wall_clock
SYNTHETIC_STACK_IN_NATIVE_CODE = 
[BacktraceLocation.new('', 0, 'In native code').freeze].freeze
DEFAULT_MAX_THREADS_SAMPLED =

This default was picked based on the current sampling performance and on expected concurrency on an average Ruby MRI application. Lowering this optimizes for latency (less impact each time we sample), and raising optimizes for coverage (less chance to miss what a given thread is doing).

16

Constants included from Core::Workers::Polling

Core::Workers::Polling::SHUTDOWN_TIMEOUT

Instance Attribute Summary collapse

Attributes inherited from Core::Worker

#task

Instance Method Summary collapse

Methods included from Core::Workers::Polling

#enabled=, #enabled?, included, #stop

Constructor Details

#initialize(recorder, max_frames:, trace_identifiers_helper:, ignore_thread: nil, max_time_usage_pct: DEFAULT_MAX_TIME_USAGE_PCT, max_threads_sampled: DEFAULT_MAX_THREADS_SAMPLED, thread_api: Thread, cpu_time_provider: Profiling::NativeExtension, fork_policy: Core::Workers::Async::Thread::FORK_POLICY_RESTART, interval: MIN_INTERVAL, enabled: true) ⇒ OldStack

Returns a new instance of OldStack.



39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 39

def initialize(
  recorder,
  max_frames:,
  trace_identifiers_helper:, # Usually an instance of Profiling::TraceIdentifiers::Helper
  ignore_thread: nil,
  max_time_usage_pct: DEFAULT_MAX_TIME_USAGE_PCT,
  max_threads_sampled: DEFAULT_MAX_THREADS_SAMPLED,
  thread_api: Thread,
  cpu_time_provider: Profiling::NativeExtension,
  fork_policy: Core::Workers::Async::Thread::FORK_POLICY_RESTART, # Restart in forks by default
  interval: MIN_INTERVAL,
  enabled: true
)
  @recorder = recorder
  @max_frames = max_frames
  @trace_identifiers_helper = trace_identifiers_helper
  @ignore_thread = ignore_thread
  @max_time_usage_pct = max_time_usage_pct
  @max_threads_sampled = max_threads_sampled
  @thread_api = thread_api
  # Only set the provider if it's able to work in the current Ruby/OS combo
  @cpu_time_provider = cpu_time_provider unless cpu_time_provider.cpu_time_ns_for(thread_api.current).nil?

  # Workers::Async::Thread settings
  self.fork_policy = fork_policy

  # Workers::IntervalLoop settings
  self.loop_base_interval = interval

  # Workers::Polling settings
  self.enabled = enabled

  # Cache this proc, since it's pretty expensive to keep recreating it
  @build_backtrace_location = method(:build_backtrace_location).to_proc
  # Cache this buffer, since it's pretty expensive to keep accessing it
  @stack_sample_event_recorder = recorder[Events::StackSample]
  # See below for details on why this is needed
  @needs_process_waiter_workaround = Gem::Version.new(RUBY_VERSION) < Gem::Version.new('2.7')
end

Instance Attribute Details

#cpu_time_provider ⇒ Object (readonly)

Returns the value of attribute cpu_time_provider.



30
31
32
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 30

def cpu_time_provider
  @cpu_time_provider
end

#ignore_thread ⇒ Object (readonly)

Returns the value of attribute ignore_thread.



30
31
32
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 30

def ignore_thread
  @ignore_thread
end

#max_frames ⇒ Object (readonly)

Returns the value of attribute max_frames.



30
31
32
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 30

def max_frames
  @max_frames
end

#max_time_usage_pct ⇒ Object (readonly)

Returns the value of attribute max_time_usage_pct.



30
31
32
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 30

def max_time_usage_pct
  @max_time_usage_pct
end

#recorder ⇒ Object (readonly)

Returns the value of attribute recorder.



30
31
32
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 30

def recorder
  @recorder
end

#thread_api ⇒ Object (readonly)

Returns the value of attribute thread_api.



30
31
32
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 30

def thread_api
  @thread_api
end

#trace_identifiers_helper ⇒ Object (readonly)

Returns the value of attribute trace_identifiers_helper.



30
31
32
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 30

def trace_identifiers_helper
  @trace_identifiers_helper
end

Instance Method Details

#build_backtrace_location(_id, base_label, lineno, path) ⇒ Object 



207
208
209
210
211
212
213
214
215
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 207

def build_backtrace_location(_id, base_label, lineno, path)
  string_table = @stack_sample_event_recorder.string_table

  Profiling::BacktraceLocation.new(
    string_table.fetch_string(base_label),
    lineno,
    string_table.fetch_string(path)
  )
end

#collect_and_wait ⇒ Object 



88
89
90
91
92
93
94
95
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 88

def collect_and_wait
  run_time = Core::Utils::Time.measure do
    collect_events
  end

  # Update wait time to throttle profiling
  self.loop_wait_time = compute_wait_time(run_time)
end

#collect_events ⇒ Object 



97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 97

def collect_events
  events = []
  current_wall_time_ns = get_current_wall_time_timestamp_ns

  # Collect backtraces from each thread
  threads_to_sample.each do |thread|
    next unless thread.alive?
    next if ignore_thread.is_a?(Proc) && ignore_thread.call(thread)

    event = collect_thread_event(thread, current_wall_time_ns)
    events << event unless event.nil?
  end

  # Send events to recorder
  recorder.push(events) unless events.empty?

  events
end

#collect_thread_event(thread, current_wall_time_ns) ⇒ Object 



116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 116

def collect_thread_event(thread, current_wall_time_ns)
  locations = thread.backtrace_locations
  return if locations.nil?

  # Having empty locations means that the thread is alive, but we don't know what it's doing:
  #
  # 1. It can be starting up
  #    ```
  #    > Thread.new { sleep }.backtrace
  #    => [] # <-- note the thread hasn't actually started running sleep yet, we got there first
  #    ```
  # 2. It can be running native code
  #    ```
  #    > t = Process.detach(fork { sleep })
  #    => #<Process::Waiter:0x00007ffe7285f7a0 run>
  #    > t.backtrace
  #    => [] # <-- this can happen even minutes later, e.g. it's not a race as in 1.
  #    ```
  #    This effect has been observed in threads created by the Iodine web server and the ffi gem
  #
  # To give customers visibility into these threads, we replace the empty stack with one containing a
  # synthetic placeholder frame, so that these threads are properly represented in the UX.
  locations = SYNTHETIC_STACK_IN_NATIVE_CODE if locations.empty?

  # Get actual stack size then trim the stack
  stack_size = locations.length
  locations = locations[0..(max_frames - 1)]

  # Convert backtrace locations into structs
  locations = convert_backtrace_locations(locations)

  thread_id = thread.object_id
  root_span_id, span_id, trace_resource = trace_identifiers_helper.trace_identifiers_for(thread)
  cpu_time = get_cpu_time_interval!(thread)
  wall_time_interval_ns =
    get_elapsed_since_last_sample_and_set_value(thread, THREAD_LAST_WALL_CLOCK_KEY, current_wall_time_ns)

  Events::StackSample.new(
    nil,
    locations,
    stack_size,
    thread_id,
    root_span_id,
    span_id,
    trace_resource,
    cpu_time,
    wall_time_interval_ns
  )
end

#compute_wait_time(used_time) ⇒ Object 



176
177
178
179
180
181
182
183
184
185
186
187
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 176

def compute_wait_time(used_time)
  # We took used_time to get the last sample.
  #
  # What we're computing here is -- if used_time corresponds to max_time_usage_pct of the time we should
  # spend working, how much is (100% - max_time_usage_pct) of the time?
  #
  # For instance, if we took 10ms to sample, and max_time_usage_pct is 1%, then the other 99% is 990ms, which
  # means we need to sleep for 990ms to guarantee that we don't spend more than 1% of the time working.
  used_time_ns = used_time * 1e9
  interval = (used_time_ns / (max_time_usage_pct / 100.0)) - used_time_ns
  [interval / 1e9, MIN_INTERVAL].max
end

#convert_backtrace_locations(locations) ⇒ Object

Convert backtrace locations into structs Re-use old backtrace location objects if they already exist in the buffer



191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 191

def convert_backtrace_locations(locations)
  locations.collect do |location|
    # Re-use existing BacktraceLocation if identical copy, otherwise build a new one.
    @stack_sample_event_recorder.cache(:backtrace_locations).fetch(
      # Function name
      location.base_label,
      # Line number
      location.lineno,
      # Filename
      location.path,
      # Build function
      &@build_backtrace_location
    )
  end
end

#get_cpu_time_interval!(thread) ⇒ Object 



166
167
168
169
170
171
172
173
174
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 166

def get_cpu_time_interval!(thread)
  return unless cpu_time_provider

  current_cpu_time_ns = cpu_time_provider.cpu_time_ns_for(thread)

  return unless current_cpu_time_ns

  get_elapsed_since_last_sample_and_set_value(thread, THREAD_LAST_CPU_TIME_KEY, current_cpu_time_ns)
end

#perform ⇒ Object 



84
85
86
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 84

def perform
  collect_and_wait
end

#reset_after_fork ⇒ Object 



217
218
219
220
221
222
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 217

def reset_after_fork
  recorder.reset_after_fork

  # NOTE: We could perhaps also call #reset_cpu_time_tracking here, although it's not needed because we always
  # call in in #start.
end

#start ⇒ Object 



79
80
81
82
 
# File 'lib/datadog/profiling/collectors/old_stack.rb', line 79

def start
  reset_cpu_time_tracking
  perform
end