Performance regression on Mash in 3.5.0+ #410

Closed
michaelherold opened this Issue Feb 18, 2017 · 5 comments

Comments

Projects
None yet
2 participants
@michaelherold
Contributor

michaelherold commented Feb 18, 2017

We have a performance regression on Mash's method accessors in the 3.5 release. I'm not sure what the cause it right now but wanted to make sure there's an issue filed for it.

From omniauth/omniauth#886:

OmniAuth performance benchmarks:

namespace :perf do
  task :setup do
    require 'omniauth'
    require 'rack/test'
    app = Rack::Builder.new do |b|
      b.use Rack::Session::Cookie, :secret => 'abc123'
      b.use OmniAuth::Strategies::Developer
      b.run lambda { |_env| [200, {}, ['Not Found']] }
    end.to_app
    @app = Rack::MockRequest.new(app)

    def call_app(path = ENV['GET_PATH'] || '/')
      result = @app.get(path)
      raise "Did not succeed #{result.body}" unless result.status == 200
      result
    end
  end

  task :ips => :setup do
    require 'benchmark/ips'
    Benchmark.ips do |x|
      x.report('ips') { call_app }
    end
  end
end

Results

Hashie v3.4.6

› bundle exec rake perf:ips
Warming up --------------------------------------
                ips     1.109k i/100ms
Calculating -------------------------------------
                ips     11.301k (± 4.9%) i/s -     56.559k in   5.017976s

Hashie v3.5.3

› bundle exec rake perf:ips        
Warming up --------------------------------------
                 ips   178.000  i/100ms
Calculating -------------------------------------
                 ips      1.786k (± 6.3%) i/s -      8.900k in   5.003601s
@michaelherold

This comment has been minimized.

Show comment
Hide comment
@michaelherold

michaelherold Feb 18, 2017

Contributor

The regression is entirely due to my logging of Mash overrides. 😞

I did a git bisect and discovered that the regression was introduced in e35e628.

I'm going to do some stack_prof analysis to see if I can figure out why and squash the regression while keeping the notice.

Contributor

michaelherold commented Feb 18, 2017

The regression is entirely due to my logging of Mash overrides. 😞

I did a git bisect and discovered that the regression was introduced in e35e628.

I'm going to do some stack_prof analysis to see if I can figure out why and squash the regression while keeping the notice.

@dblock

This comment has been minimized.

Show comment
Hide comment
@dblock

dblock Feb 18, 2017

Contributor

This probably means that something in omniauth can be fixed to avoid hitting any of that code.

Contributor

dblock commented Feb 18, 2017

This probably means that something in omniauth can be fixed to avoid hitting any of that code.

@michaelherold

This comment has been minimized.

Show comment
Hide comment
@michaelherold

michaelherold Feb 18, 2017

Contributor

Yeah, there is that. They made some changes to avoid some of it, but I'm still thinking it would be good to look into this on our end.

Contributor

michaelherold commented Feb 18, 2017

Yeah, there is that. They made some changes to avoid some of it, but I'm still thinking it would be good to look into this on our end.

@dblock

This comment has been minimized.

Show comment
Hide comment
@dblock

dblock Feb 18, 2017

Contributor

I bet Hashie::Utils.method_information(method(method_key)) is slow, especially the method part. But I wouldn't over-optimize that since it's not something that should be called more than once per class kind of thing.

Contributor

dblock commented Feb 18, 2017

I bet Hashie::Utils.method_information(method(method_key)) is slow, especially the method part. But I wouldn't over-optimize that since it's not something that should be called more than once per class kind of thing.

@michaelherold

This comment has been minimized.

Show comment
Hide comment
@michaelherold

michaelherold Feb 18, 2017

Contributor

It seems like it's actually the methods.include? - I don't know why I have a habit of doing that. I think if we switch to respond_to? it'll be much faster. Just testing to see if it breaks anything.

Contributor

michaelherold commented Feb 18, 2017

It seems like it's actually the methods.include? - I don't know why I have a habit of doing that. I think if we switch to respond_to? it'll be much faster. Just testing to see if it breaks anything.

michaelherold added a commit to michaelherold/hashie that referenced this issue Feb 18, 2017

Fix a performance regression due to logging
By switching to `#respond_to?` we make the lookup of method collisions
a lot faster while retaining the ability to report on them.

Closes #410

@dblock dblock closed this in #411 Feb 18, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment