WIP

sentry-ruby/lib/sentry/envelope.rb

@@ -19,10 +19,7 @@ def type
       end
 
       def to_s
-        <<~ITEM
-          #{JSON.generate(@headers)}
-          #{JSON.generate(@payload)}
-        ITEM
+        [JSON.generate(@headers), JSON.generate(@payload)].join("\n")
       end
 
       def serialize

sentry-ruby/lib/sentry/hub.rb

@@ -90,6 +90,10 @@ def start_transaction(transaction: nil, custom_sampling_context: {}, instrumente
       sampling_context.merge!(custom_sampling_context)
 
       transaction.set_initial_sample_decision(sampling_context: sampling_context)
+
+      #TODO-neel-profiler sample
+      transaction.profiler.start
+
       transaction
     end
 

sentry-ruby/lib/sentry/profiler.rb

@@ -0,0 +1,131 @@
+# frozen_string_literal: true
+
+require 'etc'
+require 'stackprof'
+require 'securerandom'
+
+module Sentry
+  class Profiler
+
+    VERSION = '1'
+    PLATFORM = 'ruby'
+    # 101 Hz in microseconds
+    DEFAULT_INTERVAL = 1e6 / 101
+
+    def initialize
+      @event_id = SecureRandom.uuid.delete('-')
+      @started = false
+    end
+
+    def start
+      @started = StackProf.start(interval: DEFAULT_INTERVAL,
+                                 mode: :wall,
+                                 raw: true,
+                                 aggregate: false)
+
+      log('Not started since running elsewhere') unless @started
+    end
+
+    def stop
+      StackProf.stop
+    end
+
+    def to_hash
+      return nil unless Sentry.initialized?
+
+      results = StackProf.results
+      return nil unless results
+      return nil if results.empty?
+
+      frame_map = {}
+
+      frames = results[:frames].to_enum.with_index.map do |frame, idx|
+        frame_id, frame_data = frame
+
+        # need to map over stackprof frame ids to ours
+        frame_map[frame_id] = idx
+
+        # TODO-neel module, filename, in_app
+        {
+          abs_path: frame_data[:file],
+          function: frame_data[:name],
+          lineno: frame_data[:line]
+        }.compact
+      end
+
+      idx = 0
+      stacks = []
+      num_seen = []
+
+      # extract stacks from raw
+      # raw is a single array of [.., len_stack, *stack_frames(len_stack), num_stack_seen , ..]
+      while (len = results[:raw][idx])
+        idx += 1
+
+        # our call graph is reversed
+        stack = results[:raw].slice(idx, len).map { |id| frame_map[id] }.compact.reverse
+        stacks << stack
+
+        num_seen << results[:raw][idx + len]
+        idx += len + 1
+
+        log('Unknown frame in stack') if stack.size != len
+      end
+
+      idx = 0
+      elapsed_since_start_ns = 0
+      samples = []
+
+      num_seen.each_with_index do |n, i|
+        n.times do
+          # stackprof deltas are in microseconds
+          delta = results[:raw_timestamp_deltas][idx]
+          elapsed_since_start_ns += (delta * 1e3).to_i
+          idx += 1
+
+          # Not sure why but some deltas are very small like 0/1 values,
+          # they pollute our flamegraph so just ignore them for now.
+          # Open issue at https://github.com/tmm1/stackprof/issues/201
+          next if delta < 10
+
+          samples << {
+            stack_id: i,
+            # TODO-neel we need to patch rb_profile_frames and write our own C extension to enable threading info
+            # till then, on multi-threaded servers like puma, we will get frames from other active threads when the one
+            # we're profiling is idle/sleeping/waiting for IO etc
+            # https://bugs.ruby-lang.org/issues/10602
+            thread_id: '0',
+            elapsed_since_start_ns: elapsed_since_start_ns.to_s
+          }
+        end
+      end
+
+      log('Some samples thrown away') if samples.size != results[:samples]
+
+      if samples.size <= 2
+        log('Not enough samples, discarding profiler')
+        return nil
+      end
+
+      profile = {
+        frames: frames,
+        stacks: stacks,
+        samples: samples
+      }
+
+      {
+        event_id: @event_id,
+        platform: PLATFORM,
+        version: VERSION,
+        profile: profile
+      }
+    end
+
+    private
+
+    def log(message)
+      Sentry.logger.debug(LOGGER_PROGNAME) { "[Profiler] #{message}" }
+    end
+
+  end
+end

sentry-ruby/lib/sentry/scope.rb

@@ -309,7 +309,8 @@ def os_context
               name: uname[:sysname] || RbConfig::CONFIG["host_os"],
               version: uname[:version],
               build: uname[:release],
-              kernel_version: uname[:version]
+              kernel_version: uname[:version],
+              machine: uname[:machine]
             }
           end
       end

sentry-ruby/lib/sentry/transaction.rb

@@ -1,6 +1,7 @@
 # frozen_string_literal: true
 
 require "sentry/baggage"
+require "sentry/profiler"
 
 module Sentry
   class Transaction < Span
@@ -83,6 +84,7 @@ def initialize(
       @effective_sample_rate = nil
       @contexts = {}
       @measurements = {}
+      @profiler = nil
       init_span_recorder
     end
 
@@ -254,6 +256,9 @@ def finish(hub: nil, end_timestamp: nil)
         @name = UNLABELD_NAME
       end
 
+      # TODO-neel-profiler sample
+      @profiler&.stop
+
       if @sampled
         event = hub.current_client.event_from_transaction(self)
         hub.capture_event(event)
@@ -288,6 +293,12 @@ def set_context(key, value)
       @contexts[key] = value
     end
 
+    # The stackprof profiler instance
+    # @return [Profiler]
+    def profiler
+      @profiler ||= Profiler.new
+    end
+
     protected
 
     def init_span_recorder(limit = 1000)

sentry-ruby/lib/sentry/transaction_event.rb

@@ -17,6 +17,9 @@ class TransactionEvent < Event
     # @return [Float, nil]
     attr_reader :start_timestamp
 
+    # @return [Hash, nil]
+    attr_accessor :profile
+
     def initialize(transaction:, **options)
       super(**options)
 
@@ -32,6 +35,9 @@ def initialize(transaction:, **options)
 
       finished_spans = transaction.span_recorder.spans.select { |span| span.timestamp && span != transaction }
       self.spans = finished_spans.map(&:to_hash)
+
+      # TODO-neel-profiler cleanup sampling etc
+      self.profile = populate_profile(transaction)
     end
 
     # Sets the event's start_timestamp.
@@ -49,5 +55,27 @@ def to_hash
       data[:measurements] = @measurements
       data
     end
+
+    private
+
+    def populate_profile(transaction)
+      return nil unless transaction.profiler
+
+      transaction.profiler.to_hash.merge(
+        environment: environment,
+        release: release,
+        timestamp: Time.at(start_timestamp).iso8601,
+        device: { architecture: Scope.os_context[:machine] },
+        os: { name: Scope.os_context[:name], version: Scope.os_context[:version] },
+        runtime: Scope.runtime_context,
+        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'
+        }
+      )
+    end
   end
 end

sentry-ruby/lib/sentry/transport.rb

@@ -61,6 +61,7 @@ def send_envelope(envelope)
 
       if data
         log_info("[Transport] Sending envelope with items [#{serialized_items.map(&:type).join(', ')}] #{envelope.event_id} to Sentry")
+        File.open('/tmp/dump', 'w') { |file| file.write(data) } if envelope.items.map(&:type).include?('profile')
         send_data(data)
       end
     end
@@ -154,6 +155,13 @@ def envelope_from_event(event)
         event_payload
       )
 
+      if event.is_a?(TransactionEvent) && event.profile
+        envelope.add_item(
+          { type: 'profile', content_type: 'application/json' },
+          event.profile
+        )
+      end
+
       client_report_headers, client_report_payload = fetch_pending_client_report
       envelope.add_item(client_report_headers, client_report_payload) if client_report_headers
 

sentry-ruby/sentry-ruby.gemspec

@@ -21,4 +21,6 @@ Gem::Specification.new do |spec|
   spec.require_paths = ["lib"]
 
   spec.add_dependency "concurrent-ruby", '~> 1.0', '>= 1.0.2'
+  # TODO-neel-profiler make peer dep
+  spec.add_dependency "stackprof", '~> 0.2.23'
 end