Skip CPU time instrumentation if incompatible rollbar is detected

ivoanjo · ivoanjo · commit 2d72e930a621 · 2021-03-29T11:43:10.000+01:00
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.
diff --git 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
@@ -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
@@ -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
@@ -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
