From 38982819c1c00da4229bd0bcfe2a78afc5fb8e3c Mon Sep 17 00:00:00 2001 From: Ivo Anjo Date: Thu, 11 Feb 2021 14:36:04 +0000 Subject: [PATCH] Skip CPU time instrumentation if incompatible rollbar is detected When I initially worked on #1300 ("Warn on incompatible rollbar version") my understanding of the issue on rollbar/rollbar-gem#1018 was incomplete and I did not realize that old rollbar versions, beyond breaking datadog profiler's CPU time instrumentation, could actually break the customer's application. One of our private beta customers mentioned he had seen both the warning but also had seen a stack trace: ``` [1] ! Unable to load application: SystemStackError: stack level too deep /usr/local/bundle/gems/rollbar-3.1.1/lib/rollbar/plugins/thread.rb:5:in `initialize_with_rollbar': stack level too deep (SystemStackError) from /usr/local/bundle/gems/ddtrace-0.45.0.feature.profiling.109457/lib/ddtrace/profiling/ext/cthread.rb:47:in `initialize' from /usr/local/bundle/gems/rollbar-3.1.1/lib/rollbar/plugins/thread.rb:6:in `initialize_with_rollbar' from /usr/local/bundle/gems/ddtrace-0.45.0.feature.profiling.109457/lib/ddtrace/profiling/ext/cthread.rb:47:in `initialize' ``` This led me to try to reproduce this issue. I discovered that with ```ruby ENV['DD_PROFILING_ENABLED'] = 'true' require 'ddtrace/profiling/preload' require 'rollbar' Rollbar.configure do |c| c.access_token = "nope" end Thread.new { }.join ``` I could trigger the issue, and that the current behavior was that the warning from #1300 would be printed, but then the application would proceed to fail. Having a bit more experience with the codebase now, I realize that the correct place to put this check is in the CPU extension #unsupported_reason method, which will ensure the extension is not loaded at all if an incompatible version of rollbar is around. The resulting behavior is that even with an old rollbar version, profiler will happily load and work; it will just omit the CPU time profiling, similarly to how it behaves on other platforms where for different reasons we don't support CPU time profiling. --- lib/ddtrace/profiling/ext/cpu.rb | 15 ++++++ lib/ddtrace/profiling/tasks/setup.rb | 17 ------ spec/ddtrace/profiling/ext/cpu_spec.rb | 26 +++++++++- spec/ddtrace/profiling/tasks/setup_spec.rb | 60 ---------------------- 4 files changed, 39 insertions(+), 79 deletions(-) diff --git a/lib/ddtrace/profiling/ext/cpu.rb b/lib/ddtrace/profiling/ext/cpu.rb index d0a5d0955b5..7eb7be20b0e 100644 --- a/lib/ddtrace/profiling/ext/cpu.rb +++ b/lib/ddtrace/profiling/ext/cpu.rb @@ -5,6 +5,17 @@ module Ext module CPU FFI_MINIMUM_VERSION = Gem::Version.new('1.0') + # We cannot apply our CPU extension if a broken rollbar is around because that can cause customer apps to fail + # with a SystemStackError: stack level too deep. + # + # This occurs whenever our extensions to Thread are applied BEFORE rollbar applies its own. This happens + # because a loop forms: our extension tries to call Thread#initialize, but it's intercepted by rollbar, which + # then tries to call the original Thread#initialize as well, but instead alls our extension, leading to stack + # exhaustion. + # + # See https://github.com/rollbar/rollbar-gem/pull/1018 for more details on the issue + ROLLBAR_INCOMPATIBLE_VERSIONS = Gem::Requirement.new('<= 3.1.1') + def self.supported? unsupported_reason.nil? end @@ -37,6 +48,10 @@ def self.unsupported_reason elsif Gem.loaded_specs['ffi'].version < FFI_MINIMUM_VERSION 'Your ffi gem dependency is too old; ensure that you have ffi >= 1.0 by ' \ "adding `gem 'ffi', '~> 1.0'` to your Gemfile or gems.rb file" + elsif Gem::Specification.find_all_by_name('rollbar', ROLLBAR_INCOMPATIBLE_VERSIONS).any? + 'You have an incompatible rollbar gem version installed; ensure that you have rollbar >= 3.1.2 by ' \ + "adding `gem 'rollbar', '>= 3.1.2'` to your Gemfile or gems.rb file. " \ + 'See https://github.com/rollbar/rollbar-gem/pull/1018 for details.' end end end diff --git a/lib/ddtrace/profiling/tasks/setup.rb b/lib/ddtrace/profiling/tasks/setup.rb index af044cd913a..bc8802efaac 100644 --- a/lib/ddtrace/profiling/tasks/setup.rb +++ b/lib/ddtrace/profiling/tasks/setup.rb @@ -9,7 +9,6 @@ module Tasks # Takes care of loading our extensions/monkey patches and starting up profiler class Setup def run - check_warnings! activate_main_extensions autostart_profiler end @@ -80,22 +79,6 @@ def autostart_profiler log "[DDTRACE] Could not autostart profiling. Cause: #{e.message} Location: #{e.backtrace.first}" end - def check_warnings! - warn_if_incompatible_rollbar_gem_detected - end - - # See https://github.com/rollbar/rollbar-gem/pull/1018 for details on the incompatibility - def warn_if_incompatible_rollbar_gem_detected - incompatible_rollbar_versions = Gem::Requirement.new('<= 3.1.1') - - if Gem::Specification.find_all_by_name('rollbar', incompatible_rollbar_versions).any? - log "[DDTRACE] Incompatible version of the rollbar gem is installed (#{incompatible_rollbar_versions}). " \ - 'Loading this version of the rollbar gem will disable ddtrace\'s CPU profiling. ' \ - 'Please upgrade to the latest rollbar version. ' \ - 'See https://github.com/rollbar/rollbar-gem/pull/1018 for details.' - end - end - private def log(message) diff --git a/spec/ddtrace/profiling/ext/cpu_spec.rb b/spec/ddtrace/profiling/ext/cpu_spec.rb index 20ce6b8a9dd..f43cb2ff444 100644 --- a/spec/ddtrace/profiling/ext/cpu_spec.rb +++ b/spec/ddtrace/profiling/ext/cpu_spec.rb @@ -74,7 +74,29 @@ include_context 'loaded gems', ffi: described_class::FFI_MINIMUM_VERSION - it { is_expected.to be nil } + let(:last_version_of_rollbar_affected) { '3.1.1' } + + context 'when incompatible rollbar gem is installed' do + before do + expect(Gem::Specification) + .to receive(:find_all_by_name) + .with('rollbar', Gem::Requirement.new("<= #{last_version_of_rollbar_affected}")) + .and_return([instance_double(Gem::Specification), instance_double(Gem::Specification)]) + end + + it { is_expected.to include 'rollbar >= 3.1.2'} + end + + context 'when compatible rollbar gem is installed or no version at all is installed' do + before do + expect(Gem::Specification) + .to receive(:find_all_by_name) + .with('rollbar', Gem::Requirement.new("<= #{last_version_of_rollbar_affected}")) + .and_return([]) # Because we search with a <= requirement, not installed/compatible version installed both lead to empty return here + end + + it { is_expected.to be nil } + end end end end @@ -89,7 +111,7 @@ before { stub_const('Thread', ::Thread.dup) } context 'when native CPU time is supported' do - before { skip 'CPU profiling not supported' unless described_class.supported? } + before { skip 'CPU profiling not supported on current platform' unless described_class.supported? } it 'adds Thread extensions' do apply! diff --git a/spec/ddtrace/profiling/tasks/setup_spec.rb b/spec/ddtrace/profiling/tasks/setup_spec.rb index 5d77dcf5d5c..0d80f745931 100644 --- a/spec/ddtrace/profiling/tasks/setup_spec.rb +++ b/spec/ddtrace/profiling/tasks/setup_spec.rb @@ -12,7 +12,6 @@ subject(:run) { task.run } it do - expect(task).to receive(:check_warnings!).ordered expect(task).to receive(:activate_main_extensions).ordered expect(task).to receive(:autostart_profiler).ordered run @@ -347,63 +346,4 @@ end end end - - describe '#check_warnings!' do - subject(:check_warnings!) { task.check_warnings! } - - it do - expect(task).to receive(:warn_if_incompatible_rollbar_gem_detected) - - check_warnings! - end - end - - describe '#warn_if_incompatible_rollbar_gem_detected' do - subject(:warn_if_incompatible_rollbar_gem_detected) { task.warn_if_incompatible_rollbar_gem_detected } - - let(:last_version_of_rollbar_affected) { '3.1.1' } - - before do - # Simulate the result of the gem apis, so that we can check different combinations of having or not having the - # rollbar gem and affected versions - expect(Gem::Specification) - .to receive(:find_all_by_name) - .with('rollbar', Gem::Requirement.new("<= #{last_version_of_rollbar_affected}")) - .and_return(rollbar_versions_found) - end - - context 'when rollbar gem is not installed' do - let(:rollbar_versions_found) { [] } - - it 'does not display a warning to STDOUT' do - expect(STDOUT).to_not receive(:puts) - - warn_if_incompatible_rollbar_gem_detected - end - end - - context 'when compatible version of rollbar gem is installed' do - # same as "no gem installed" because we use a version requirement when - # calling find_all_by_name, so only incompatible versions get returned - let(:rollbar_versions_found) { [] } - - it 'does not display a warning to STDOUT' do - expect(STDOUT).to_not receive(:puts) - - warn_if_incompatible_rollbar_gem_detected - end - end - - context 'when incompatible version of rollbar gem is installed' do - let(:rollbar_versions_found) { [instance_double(Gem::Specification), instance_double(Gem::Specification)] } - - it 'displays a warning to STDOUT' do - expect(STDOUT).to receive(:puts) do |message| - expect(message).to include('Incompatible version of the rollbar') - end - - warn_if_incompatible_rollbar_gem_detected - end - end - end end