Prevent starting Vernier in nested transactions (#2528)

* Prevent starting Vernier in nested transactions

* Update CHANGELOG

* Document new Hub methods as private

Author: solnic

CHANGELOG.md

@@ -7,6 +7,7 @@
 ### Bug Fixes
 
 - Fix argument serialization for ranges that consist of ActiveSupport::TimeWithZone ([#2548](https://github.com/getsentry/sentry-ruby/pull/2548))
+- Prevent starting Vernier in nested transactions ([#2528](https://github.com/getsentry/sentry-ruby/pull/2528))
 
 ### Miscellaneous
 

sentry-ruby/lib/sentry/hub.rb

@@ -8,12 +8,42 @@ module Sentry
   class Hub
     include ArgumentCheckingHelper
 
+    MUTEX = Mutex.new
+
     attr_reader :last_event_id
 
+    attr_reader :current_profiler
+
     def initialize(client, scope)
       first_layer = Layer.new(client, scope)
       @stack = [first_layer]
       @last_event_id = nil
+      @current_profiler = {}
+    end
+
+    # This is an internal private method
+    # @api private
+    def start_profiler!(transaction)
+      MUTEX.synchronize do
+        transaction.start_profiler!
+        @current_profiler[transaction.__id__] = transaction.profiler
+      end
+    end
+
+    # This is an internal private method
+    # @api private
+    def stop_profiler!(transaction)
+      MUTEX.synchronize do
+        @current_profiler.delete(transaction.__id__)&.stop
+      end
+    end
+
+    # This is an internal private method
+    # @api private
+    def profiler_running?
+      MUTEX.synchronize do
+        !@current_profiler.empty?
+      end
     end
 
     def new_from_top
@@ -96,7 +126,7 @@ def start_transaction(transaction: nil, custom_sampling_context: {}, instrumente
       sampling_context.merge!(custom_sampling_context)
       transaction.set_initial_sample_decision(sampling_context: sampling_context)
 
-      transaction.start_profiler!
+      start_profiler!(transaction)
 
       transaction
     end

sentry-ruby/lib/sentry/transaction.rb

@@ -85,7 +85,11 @@ def initialize(
       @effective_sample_rate = nil
       @contexts = {}
       @measurements = {}
-      @profiler = @configuration.profiler_class.new(@configuration)
+
+      unless @hub.profiler_running?
+        @profiler = @configuration.profiler_class.new(@configuration)
+      end
+
       init_span_recorder
     end
 
@@ -257,7 +261,7 @@ def finish(hub: nil, end_timestamp: nil)
         @name = UNLABELD_NAME
       end
 
-      @profiler.stop
+      @hub.stop_profiler!(self)
 
       if @sampled
         event = hub.current_client.event_from_transaction(self)
@@ -299,6 +303,8 @@ def set_context(key, value)
     # Start the profiler.
     # @return [void]
     def start_profiler!
+      return unless profiler
+
       profiler.set_initial_sample_decision(sampled)
       profiler.start
     end

sentry-ruby/lib/sentry/transaction_event.rb

@@ -59,8 +59,11 @@ def to_hash
 
     private
 
+    EMPTY_PROFILE = {}.freeze
+
     def populate_profile(transaction)
-      profile_hash = transaction.profiler.to_hash
+      profile_hash = transaction.profiler&.to_hash || EMPTY_PROFILE
+
       return if profile_hash.empty?
 
       profile_hash.merge!(

sentry-ruby/lib/sentry/vernier/profiler.rb

@@ -74,6 +74,7 @@ def stop
         return unless @started
 
         @result = ::Vernier.stop_profile
+        @started = false
 
         log("Stopped")
       rescue RuntimeError => e
@@ -89,13 +90,13 @@ def active_thread_id
       end
 
       def to_hash
-        return EMPTY_RESULT unless @started
-
         unless @sampled
           record_lost_event(:sample_rate)
           return EMPTY_RESULT
         end
 
+        return EMPTY_RESULT unless result
+
         { **profile_meta, profile: output.to_h }
       end
 

sentry-ruby/spec/sentry/transactions/profiler_spec.rb

@@ -0,0 +1,33 @@
+# frozen_string_literal: true
+
+require "spec_helper"
+require 'contexts/with_request_mock'
+
+RSpec.describe Sentry, 'transactions / profiler', when: [:vernier_installed?, :rack_available?] do
+  include_context "with request mock"
+
+  before do
+    perform_basic_setup do |config|
+      config.traces_sample_rate = 1.0
+      config.profiles_sample_rate = 1.0
+      config.profiler_class = Sentry::Vernier::Profiler
+    end
+  end
+
+  it 'starts profiler just once inside nested transactions' do
+    10.times do
+      parent_transaction = Sentry.start_transaction(name: "parent")
+      nested_transaction = Sentry.start_transaction(name: "nested")
+
+      ProfilerTest::Bar.bar
+
+      expect(Sentry.get_current_hub.profiler_running?).to be(true)
+
+      expect(parent_transaction.profiler).to_not be_nil
+      expect(nested_transaction.profiler).to be_nil
+
+      nested_transaction.finish
+      parent_transaction.finish
+    end
+  end
+end