WIP: Improve capture performance

Currently 2-3x faster.

TODO:

Any frozen objects that may be bad? Should we provide some sort of
fallback bath here?
Reduce allocations in RemoveCircularReferences, if possible

Author: nateberkopec

.gitignore

@@ -1,6 +1,7 @@
 coverage
 pkg
 ruby/
+log/
 docs/_build
 .bundle
 *.gem

Gemfile

@@ -12,5 +12,5 @@ group :development do
   gem "pry-coolline"
   gem "benchmark-ips"
   gem "benchmark-ipsa"
-  gem "yajl-ruby", :platforms => :mri
+  gem "ruby-prof"
 end

benchmarks/allocation_report.rb

@@ -0,0 +1,30 @@
+require 'benchmark/ips'
+require 'benchmark/ipsa'
+require 'raven'
+require 'raven/breadcrumbs/logger'
+require 'raven/transports/dummy'
+require_relative "../spec/support/test_rails_app/app"
+
+TestApp.configure do |config|
+  config.middleware.delete ActionDispatch::DebugExceptions
+  config.middleware.delete ActionDispatch::ShowExceptions
+end
+
+Raven.configure do |config|
+  config.logger = Logger.new(nil)
+  config.dsn = "dummy://12345:[email protected]:3000/sentry/42"
+end
+
+TestApp.initialize!
+@app = Rack::MockRequest.new(TestApp)
+RAILS_EXC = begin
+  @app.get("/exception")
+rescue => exc
+  exc
+end
+
+report = MemoryProfiler.report do
+  Raven.capture_exception(RAILS_EXC)
+end
+
+report.pretty_print

benchmarks/async_benchmark.rb

@@ -0,0 +1,49 @@
+require 'benchmark/ips'
+require 'benchmark/ipsa'
+require 'raven'
+require 'raven/breadcrumbs/logger'
+require 'raven/transports/dummy'
+require 'rack/test'
+require_relative "../spec/support/test_rails_app/app"
+
+def build_exception
+  1 / 0
+rescue ZeroDivisionError => exception
+  exception
+end
+
+TestApp.configure do |config|
+  config.middleware.delete ActionDispatch::DebugExceptions
+  config.middleware.delete ActionDispatch::ShowExceptions
+end
+
+Raven.configure do |config|
+  config.logger = Logger.new(nil)
+  config.dsn = "dummy://12345:[email protected]:3000/sentry/42"
+  config.async = lambda { |event| event.to_hash } # Simulate throwing this into a Sidekiq job, etc
+end
+
+TestApp.initialize!
+@app = Rack::MockRequest.new(TestApp)
+RAILS_EXC = begin
+  @app.get("/exception")
+rescue => exc
+  exc
+end
+
+DIVIDE_BY_ZERO = build_exception
+
+LOGGER = Logger.new(nil)
+
+Benchmark.ipsa do |x|
+  x.config(:time => 5, :warmup => 2)
+
+  x.report("simple") { Raven.capture_exception(DIVIDE_BY_ZERO) }
+  x.report("rails") { Raven.capture_exception(RAILS_EXC) }
+  x.report("lots o logs") do
+    100.times { LOGGER.debug(rand(100_000).to_s) }
+    Raven.capture_exception(DIVIDE_BY_ZERO)
+  end
+
+  x.compare!
+end

benchmarks/json.rb

@@ -0,0 +1,35 @@
+require 'raven'
+require 'raven/breadcrumbs/logger'
+require 'raven/transports/dummy'
+require_relative "../spec/support/test_rails_app/app"
+
+TestApp.configure do |config|
+  config.middleware.delete ActionDispatch::DebugExceptions
+  config.middleware.delete ActionDispatch::ShowExceptions
+end
+
+Raven.configure do |config|
+  config.logger = Logger.new(nil)
+  config.dsn = "dummy://12345:[email protected]:3000/sentry/42"
+end
+
+TestApp.initialize!
+@app = Rack::MockRequest.new(TestApp)
+RAILS_EXC = begin
+  @app.get("/exception")
+rescue => exc
+  exc
+end
+
+require 'ruby-prof'
+
+RubyProf.measure_mode = RubyProf::PROCESS_TIME
+
+# profile the code
+result = RubyProf.profile do
+  100.times { Raven.capture_exception(RAILS_EXC) }
+end
+
+# print a graph profile to text
+printer = RubyProf::MultiPrinter.new(result)
+printer.print(:path => "./tmp", :profile => "profile")

benchmarks/profile.rb

@@ -64,7 +64,7 @@ def transport
 
     def encode(event)
       hash = @processors.reduce(event.to_hash) { |a, e| e.process(a) }
-      encoded = JSON.generate(hash)
+      encoded = JSON.fast_generate(hash)
 
       case configuration.encoding
       when 'gzip'

lib/raven/client.rb

@@ -37,7 +37,7 @@ def initialize(*arguments)
       end
 
       def filename
-        return nil if abs_path.nil?
+        return if abs_path.nil?
 
         prefix =
           if under_project_root? && in_app
@@ -60,7 +60,7 @@ def project_root
       end
 
       def longest_load_path
-        $LOAD_PATH.select { |s| abs_path.start_with?(s.to_s) }.sort_by { |s| s.to_s.length }.last
+        @longest_load_path ||= $LOAD_PATH.select { |s| abs_path.start_with?(s) }.max_by(&:length)
       end
 
       def to_hash(*args)

lib/raven/interfaces/stack_trace.rb

@@ -1,14 +1,16 @@
 module Raven
   class Processor::RemoveCircularReferences < Processor
-    def process(v, visited = [])
-      return "(...)" if visited.include?(v.__id__)
-      visited += [v.__id__]
-      if v.is_a?(Hash)
-        v.each_with_object({}) { |(k, v_), memo| memo[k] = process(v_, visited) }
-      elsif v.is_a?(Array)
-        v.map { |v_| process(v_, visited) }
+    def process(value, visited = [])
+      return "(...)" if visited.include?(value.__id__)
+      visited << value.__id__ if value.is_a?(Array) || value.is_a?(Hash)
+
+      case value
+      when Hash
+        !value.frozen? ? value.merge!(value) { |_, v| process v, visited } : value.merge(value) { |_, v| process v, visited }
+      when Array
+        !value.frozen? ? value.map! { |v| process v, visited } : value.map { |v| process v, visited }
       else
-        v
+        value
       end
     end
   end

lib/raven/processor/removecircularreferences.rb

@@ -14,31 +14,27 @@ def initialize(client)
       self.sanitize_credit_cards = client.configuration.sanitize_credit_cards
     end
 
-    def process(value)
-      return value if value.frozen?
-      value.each_with_object(value) { |(k, v), memo| memo[k] = sanitize(k, v) }
-    end
-
-    def sanitize(k, v)
-      if v.is_a?(Hash)
-        process(v)
-      elsif v.is_a?(Array)
-        v.map { |a| sanitize(k, a) }
-      elsif k.to_s == 'query_string'
-        sanitize_query_string(v)
-      elsif v.is_a?(Integer) && matches_regexes?(k, v)
-        INT_MASK
-      elsif v.is_a?(String)
-        if fields_re.match(v.to_s) && (json = parse_json_or_nil(v))
+    def process(value, key = nil)
+      case value
+      when Hash
+        !value.frozen? ? value.merge!(value) { |k, v| process v, k } : value.merge(value) { |k, v| process v, k }
+      when Array
+        !value.frozen? ? value.map! { |v| process v, key } : value.map { |v| process v, key }
+      when Integer
+        matches_regexes?(key, value.to_s) ? INT_MASK : value
+      when String
+        if value =~ fields_re && (json = parse_json_or_nil(value))
           # if this string is actually a json obj, convert and sanitize
-          json.is_a?(Hash) ? process(json).to_json : v
-        elsif matches_regexes?(k, v)
+          process(json).to_json
+        elsif matches_regexes?(key, value)
           STRING_MASK
+        elsif key == 'query_string' || key == :query_string
+          sanitize_query_string(value)
         else
-          v
+          value
         end
       else
-        v
+        value
       end
     end
 
@@ -51,8 +47,8 @@ def sanitize_query_string(query_string)
     end
 
     def matches_regexes?(k, v)
-      (sanitize_credit_cards && CREDIT_CARD_RE.match(v.to_s)) ||
-        fields_re.match(k.to_s)
+      (sanitize_credit_cards && v =~ CREDIT_CARD_RE) ||
+        k =~ fields_re
     end
 
     def fields_re
@@ -70,6 +66,7 @@ def special_characters?(string)
     end
 
     def parse_json_or_nil(string)
+      return unless string.start_with?("[", "{")
       JSON.parse(string)
     rescue JSON::ParserError, NoMethodError
       nil

lib/raven/processor/sanitizedata.rb

@@ -1,29 +1,28 @@
 module Raven
   class Processor::UTF8Conversion < Processor
     def process(value)
-      if value.is_a? Array
-        value.map { |v| process v }
-      elsif value.is_a? Hash
-        value.merge(value) { |_, v| process v }
-      elsif value.is_a?(Exception) && !value.message.valid_encoding?
+      case value
+      when Array
+        !value.frozen? ? value.map! { |v| process v } : value.map { |v| process v }
+      when Hash
+        !value.frozen? ? value.merge!(value) { |_, v| process v } : value.merge(value) { |_, v| process v }
+      when Exception
+        return value if value.message.valid_encoding?
         clean_exc = value.class.new(clean_invalid_utf8_bytes(value.message))
         clean_exc.set_backtrace(value.backtrace)
         clean_exc
-      else
+      when String
+        return value if value.valid_encoding?
         clean_invalid_utf8_bytes(value)
+      else
+        value
       end
     end
 
     private
 
     def clean_invalid_utf8_bytes(obj)
-      if obj.respond_to?(:to_utf8)
-        obj.to_utf8
-      elsif obj.respond_to?(:encoding) && obj.is_a?(String)
-        obj.encode('UTF-16', :invalid => :replace, :undef => :replace, :replace => '').encode('UTF-8')
-      else
-        obj
-      end
+      obj.encode('UTF-16', :invalid => :replace, :undef => :replace, :replace => '').encode('UTF-8')
     end
   end
 end

lib/raven/processor/utf8conversion.rb

@@ -41,8 +41,31 @@
     expect(JSON.parse("[123e090000000]")).to eq [+1.0 / 0.0]
   end
 
-  it 'it raises the correct error on strings that look like incomplete objects' do
-    expect { JSON.parse("{") }.to raise_error(JSON::ParserError)
-    expect { JSON.parse("[") }.to raise_error(JSON::ParserError)
+  if RUBY_VERSION.to_f >= 2.0 # 1.9 just hangs on this.
+    it 'it raises the correct error on strings that look like incomplete objects' do
+      expect { JSON.parse("{") }.to raise_error(JSON::ParserError)
+      expect { JSON.parse("[") }.to raise_error(JSON::ParserError)
+    end
+
+    it "raises an error on bad UTF8 input" do
+      expect do
+        JSON.parse("invalid utf8 string goes here\255".force_encoding('UTF-8'))
+      end.to raise_error(JSON::ParserError)
+    end
+
+    it "blows up on circular references" do
+      data = {}
+      data['data'] = data
+      data['ary'] = []
+      data['ary'].push('x' => data['ary'])
+      data['ary2'] = data['ary']
+      data['leave intact'] = { 'not a circular reference' => true }
+
+      if RUBY_PLATFORM == 'java'
+        expect { JSON.dump(data) }.to raise_error
+      else
+        expect { JSON.dump(data) }.to raise_error(SystemStackError)
+      end
+    end
   end
 end

spec/raven/json_spec.rb

@@ -19,7 +19,7 @@
     result = @processor.process(data)
     expect(result['data']).to eq('(...)')
     expect(result['ary'].first['x']).to eq('(...)')
-    expect(result['ary2']).not_to eq('(...)')
+    expect(result['ary2']).to eq("(...)")
     expect(result['leave intact']).to eq('not a circular reference' => true)
   end
 end

spec/raven/processors/removecirculareferences_spec.rb

@@ -111,15 +111,6 @@
     expect { JSON.parse(result["data"]["invalid"]) }.to raise_exception(JSON::ParserError)
   end
 
-  it 'should not sanitize frozen objects' do
-    data = {
-      'ccnumba' => '4242424242424242'
-    }.freeze
-
-    result = @processor.process(data)
-    expect(result["ccnumba"]).to eq('4242424242424242')
-  end
-
   it 'should filter credit card values' do
     data = {
       'ccnumba' => '4242424242424242',