Experimental support for multi-threaded profiling using Vernier

CHANGELOG.md

@@ -1,5 +1,9 @@
 ## Unreleased
 
+### Features
+
+- Experimental support for multi-threaded profiling using Vernier ([#2372](https://github.com/getsentry/sentry-ruby/pull/2372))
+
 ### Internal
 
 - Profile items have bigger size limit now ([#2421](https://github.com/getsentry/sentry-ruby/pull/2421))

sentry-ruby/Gemfile

@@ -14,6 +14,7 @@ gem "puma"
 
 gem "timecop"
 gem "stackprof" unless RUBY_PLATFORM == "java"
+gem "vernier", platforms: :ruby if RUBY_VERSION >= "3.2.1"
 
 gem "graphql", ">= 2.2.6" if RUBY_VERSION.to_f >= 2.7
 

sentry-ruby/lib/sentry-ruby.rb

@@ -25,6 +25,7 @@
 require "sentry/backpressure_monitor"
 require "sentry/cron/monitor_check_ins"
 require "sentry/metrics"
+require "sentry/vernier/profiler"
 
 [
   "sentry/rake",

sentry-ruby/lib/sentry/configuration.rb

@@ -3,8 +3,8 @@
 require "concurrent/utility/processor_counter"
 
 require "sentry/utils/exception_cause_chain"
-require 'sentry/utils/custom_inspection'
-require 'sentry/utils/env_helper'
+require "sentry/utils/custom_inspection"
+require "sentry/utils/env_helper"
 require "sentry/dsn"
 require "sentry/release_detector"
 require "sentry/transport/configuration"
@@ -291,6 +291,10 @@
     # @return [Symbol]
     attr_reader :instrumenter
 
+    # The profiler class
+    # @return [Class]
+    attr_reader :profiler_class
+
     # Take a float between 0.0 and 1.0 as the sample rate for capturing profiles.
     # Note that this rate is relative to traces_sample_rate / traces_sampler,
     # i.e. the profile is sampled by this rate after the transaction is sampled.
@@ -387,9 +391,9 @@
       self.auto_session_tracking = true
       self.enable_backpressure_handling = false
       self.trusted_proxies = []
-      self.dsn = ENV['SENTRY_DSN']
+      self.dsn = ENV["SENTRY_DSN"]
 
-      spotlight_env = ENV['SENTRY_SPOTLIGHT']
+      spotlight_env = ENV["SENTRY_SPOTLIGHT"]
       spotlight_bool = Sentry::Utils::EnvHelper.env_to_bool(spotlight_env, strict: true)
       self.spotlight = spotlight_bool.nil? ? (spotlight_env || false) : spotlight_bool
       self.server_name = server_name_from_env
@@ -403,6 +407,8 @@
       self.traces_sampler = nil
       self.enable_tracing = nil
 
+      self.profiler_class = Sentry::Profiler
+
       @transport = Transport::Configuration.new
       @cron = Cron::Configuration.new
       @metrics = Metrics::Configuration.new
@@ -498,6 +504,18 @@
       @profiles_sample_rate = profiles_sample_rate
     end
 
+    def profiler_class=(profiler_class)
+      if profiler_class == Sentry::Vernier::Profiler
+        begin
+          require "vernier"
+        rescue LoadError
+          raise ArgumentError, "Please add the 'vernier' gem to your Gemfile to use the Vernier profiler with Sentry."
+        end
+      end
+
+      @profiler_class = profiler_class
+    end
+
     def sending_allowed?
       spotlight || sending_to_dsn_allowed?
     end

sentry-ruby/lib/sentry/profiler.rb

@@ -1,9 +1,12 @@
 # frozen_string_literal: true
 
 require "securerandom"
+require_relative "profiler/helpers"
 
 module Sentry
   class Profiler
+    include Profiler::Helpers
+
     VERSION = "1"
     PLATFORM = "ruby"
     # 101 Hz in microseconds
@@ -44,6 +47,10 @@ def stop
       log("Stopped")
     end
 
+    def active_thread_id
+      "0"
+    end
+
     # Sets initial sampling decision of the profile.
     # @return [void]
     def set_initial_sample_decision(transaction_sampled)
@@ -188,43 +195,6 @@ def log(message)
       Sentry.logger.debug(LOGGER_PROGNAME) { "[Profiler] #{message}" }
     end
 
-    def in_app?(abs_path)
-      abs_path.match?(@in_app_pattern)
-    end
-
-    # copied from stacktrace.rb since I don't want to touch existing code
-    # TODO-neel-profiler try to fetch this from stackprof once we patch
-    # the native extension
-    def compute_filename(abs_path, in_app)
-      return nil if abs_path.nil?
-
-      under_project_root = @project_root && abs_path.start_with?(@project_root)
-
-      prefix =
-        if under_project_root && in_app
-          @project_root
-        else
-          longest_load_path = $LOAD_PATH.select { |path| abs_path.start_with?(path.to_s) }.max_by(&:size)
-
-          if under_project_root
-            longest_load_path || @project_root
-          else
-            longest_load_path
-          end
-        end
-
-      prefix ? abs_path[prefix.to_s.chomp(File::SEPARATOR).length + 1..-1] : abs_path
-    end
-
-    def split_module(name)
-      # last module plus class/instance method
-      i = name.rindex("::")
-      function = i ? name[(i + 2)..-1] : name
-      mod = i ? name[0...i] : nil
-
-      [function, mod]
-    end
-
     def record_lost_event(reason)
       Sentry.get_current_client&.transport&.record_lost_event(reason, "profile")
     end

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

@@ -0,0 +1,46 @@
+# frozen_string_literal: true
+
+require "securerandom"
+
+module Sentry
+  class Profiler
+    module Helpers
+      def in_app?(abs_path)
+        abs_path.match?(@in_app_pattern)
+      end
+
+      # copied from stacktrace.rb since I don't want to touch existing code
+      # TODO-neel-profiler try to fetch this from stackprof once we patch
+      # the native extension
+      def compute_filename(abs_path, in_app)
+        return nil if abs_path.nil?
+
+        under_project_root = @project_root && abs_path.start_with?(@project_root)
+
+        prefix =
+          if under_project_root && in_app
+            @project_root
+          else
+            longest_load_path = $LOAD_PATH.select { |path| abs_path.start_with?(path.to_s) }.max_by(&:size)
+
+            if under_project_root
+              longest_load_path || @project_root
+            else
+              longest_load_path
+            end
+          end
+
+        prefix ? abs_path[prefix.to_s.chomp(File::SEPARATOR).length + 1..-1] : abs_path
+      end
+
+      def split_module(name)
+        # last module plus class/instance method
+        i = name.rindex("::")
+        function = i ? name[(i + 2)..-1] : name
+        mod = i ? name[0...i] : nil
+
+        [function, mod]
+      end
+    end
+  end
+end

sentry-ruby/lib/sentry/transaction.rb

@@ -85,7 +85,7 @@ def initialize(
       @effective_sample_rate = nil
       @contexts = {}
       @measurements = {}
-      @profiler = Profiler.new(@configuration)
+      @profiler = @configuration.profiler_class.new(@configuration)
       init_span_recorder
     end
 

sentry-ruby/lib/sentry/transaction_event.rb

@@ -74,8 +74,7 @@ def populate_profile(transaction)
           id: event_id,
           name: transaction.name,
           trace_id: transaction.trace_id,
-          # TODO-neel-profiler stubbed for now, see thread_id note in profiler.rb
-          active_thead_id: "0"
+          active_thread_id: transaction.profiler.active_thread_id.to_s
         }
       )
 

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

@@ -0,0 +1,89 @@
+# frozen_string_literal: true
+
+require "json"
+require "rbconfig"
+
+module Sentry
+  module Vernier
+    class Output
+      include Profiler::Helpers
+
+      attr_reader :profile
+
+      def initialize(profile, project_root:, in_app_pattern:, app_dirs_pattern:)
+        @profile = profile
+        @project_root = project_root
+        @in_app_pattern = in_app_pattern
+        @app_dirs_pattern = app_dirs_pattern
+      end
+
+      def to_h
+        @to_h ||= {
+          frames: frames,
+          stacks: stacks,
+          samples: samples,
+          thread_metadata: thread_metadata
+        }
+      end
+
+      private
+
+      def thread_metadata
+        profile.threads.map { |thread_id, thread_info|
+          [thread_id, { name: thread_info[:name] }]
+        }.to_h
+      end
+
+      def samples
+        profile.threads.flat_map { |thread_id, thread_info|
+          started_at = thread_info[:started_at]
+          samples, timestamps = thread_info.values_at(:samples, :timestamps)
+
+          samples.zip(timestamps).map { |stack_id, timestamp|
+            elapsed_since_start_ns = timestamp - started_at
+
+            next if elapsed_since_start_ns < 0
+
+            {
+              thread_id: thread_id.to_s,
+              stack_id: stack_id,
+              elapsed_since_start_ns: elapsed_since_start_ns.to_s
+            }
+          }.compact
+        }
+      end
+
+      def frames
+        funcs = stack_table_hash[:frame_table].fetch(:func)
+        lines = stack_table_hash[:func_table].fetch(:first_line)
+
+        funcs.map do |idx|
+          function, mod = split_module(stack_table_hash[:func_table][:name][idx])
+
+          abs_path = stack_table_hash[:func_table][:filename][idx]
+          in_app = in_app?(abs_path)
+          filename = compute_filename(abs_path, in_app)
+
+          {
+            function: function,
+            module: mod,
+            filename: filename,
+            abs_path: abs_path,
+            lineno: (lineno = lines[idx]) > 0 ? lineno : nil,
+            in_app: in_app
+          }.compact
+        end
+      end
+
+      def stacks
+        profile._stack_table.stack_count.times.map do |stack_id|
+          profile.stack(stack_id).frames.map(&:idx)
+        end
+      end
+
+      def stack_table_hash
+        @stack_table_hash ||= profile._stack_table.to_h
+      end
+    end
+  end
+end