Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Faster permitted_scalar_filter #33758

Merged
merged 1 commit into from
Aug 31, 2018

Conversation

schneems
Copy link
Member

@schneems schneems commented Aug 30, 2018

When running with code triage and derailed benchmarks and focusing on this file:

Before

 16199  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_controller/metal/strong_parameters.r

After

  2280  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_controller/metal/strong_parameters.rb

In an "hello world" app i'm seeing a roughly 20% speed increase.

@schneems schneems force-pushed the schneems/faster_strong_params branch from 7056b9f to 1d62cd9 Compare August 30, 2018 14:59
@schneems schneems closed this Aug 30, 2018
@schneems schneems reopened this Aug 30, 2018
@schneems schneems force-pushed the schneems/faster_strong_params branch from 1d62cd9 to c423f0b Compare August 30, 2018 16:40
@schneems
Copy link
Member Author

Updated along with new numbers. It's pretty close to the original implementation. Few bytes more but not much.

@dhh
Copy link
Member

dhh commented Aug 30, 2018

@schneems Thanks for taking the time to investigate all these optimizations. I'd like to see us contextualize the microbenchmarks with something higher level. Even if it's literally just the dreaded Hello World that runs through an entire Rails request with template rendering and such. That would give us some sense of scale.

Because these optimizations aren't free; code that's more verbose/less idiomatic/uses multiple exits/whatever should pay for its cost with real, measurable benefits for actual applications.

Thanks again for looking into this! I'm sure there are optimizations that sit in hot-paths were the trade-off of worse code is worth the gain 👍

@dhh
Copy link
Member

dhh commented Aug 30, 2018

In fact, I'd go as far as to say it'd be really awesome if we could get a general test app running that we can run any kind of change against. Not just these optimizations, but things we fear might be performance regressions. And a way to measure major versions against each other for improvements.

@schneems
Copy link
Member Author

The memory savings are 0.013919 mb and on codetriage it takes about 0.95 mb of memory for a request. So, in this case, it's a 1.4 % reduction in memory per request. I couldn't get that to show up on a benchmark by itself in any kind of statistically significant way via benchmark.ips or benchmark.bmbm.

This location was bad enough to show up on derailed's top offenders for memory allocation before the change.

Before

allocated memory by file
-----------------------------------
    127779  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/string/output_safety.rb
     97333  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/dalli/server.rb
     49448  /Users/rschneeman/Documents/projects/codetriage/app/views/layouts/_app.html.slim
     49328  /Users/rschneeman/Documents/projects/codetriage/app/views/layouts/application.html.slim
     36044  /Users/rschneeman/Documents/projects/rails/activemodel/lib/active_model/type/helpers/time_value.rb
     34739  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/active_support/cache/dalli_store.rb
     34447  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/marshal.rb
     28264  <internal:prelude>
     25592  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/dalli/socket.rb
     25096  /Users/rschneeman/Documents/projects/codetriage/app/views/pages/_repos_with_pagination.html.slim
     18000  /Users/rschneeman/Documents/projects/rails/activemodel/lib/active_model/attribute_set/builder.rb
     17056  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/digestor.rb
     16199  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_controller/metal/strong_parameters.rb # <============================================
     15888  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/result.rb
     15080  /Users/rschneeman/.gem/ruby/2.5.1/gems/rack-mini-profiler-1.0.0/lib/patches/db/pg.rb
     13984  /Users/rschneeman/Documents/projects/rails/actionpack/lib/abstract_controller/caching/fragments.rb
     11200  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/helpers/cache_helper.rb
     10046  /Users/rschneeman/.gem/ruby/2.5.1/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/storage/file_store.rb
      9289  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/tagged_logging.rb
      8648  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/lookup_context.rb
      8400  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/renderer/partial_renderer.rb
      8304  /Users/rschneeman/Documents/projects/rails/activemodel/lib/active_model/attribute.rb
      7751  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/log_subscriber.rb
      7348  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/logger.rb
      7216  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/object/to_query.rb
      7096  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb
      7024  /Users/rschneeman/.gem/ruby/2.5.1/gems/warden-1.2.6/lib/warden/proxy.rb
      6512  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_dispatch/routing/route_set.rb
      6354  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/dalli/client.rb
      6038  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/helpers/tag_helper.rb
      6000  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/integration.rb
      5680  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/callbacks.rb
      5600  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/persistence.rb
      4916  /Users/rschneeman/.gem/ruby/2.5.1/gems/rack-2.0.5/lib/rack/utils.rb
      4896  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_dispatch/journey/formatter.rb
      4760  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_dispatch/http/response.rb
      4544  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/hash/keys.rb
      4536  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/array/conversions.rb
      4504  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/hash_with_indifferent_access.rb
      4448  /Users/rschneeman/.gem/ruby/2.5.1/gems/hashie-3.5.7/lib/hashie/mash.rb
      4448  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/notifications/instrumenter.rb
      4440  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/attribute_methods.rb
      4360  /Users/rschneeman/.gem/ruby/2.5.1/gems/will_paginate-3.1.0/lib/will_paginate/active_record.rb
      4240  /Users/rschneeman/Documents/projects/rails/actionpack/lib/abstract_controller/helpers.rb
      4160  /Users/rschneeman/Documents/projects/rails/actionpack/lib/abstract_controller/caching.rb
      4000  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb
      3968  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/subscriber.rb
      3888  /Users/rschneeman/.gem/ruby/2.5.1/gems/will_paginate-3.1.0/lib/will_paginate/view_helpers/link_renderer.rb
      3648  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/relation.rb
      3600  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/date_and_time/zones.rb

After

allocated memory by file
-----------------------------------
    127690  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/string/output_safety.rb
     96197  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/dalli/server.rb
     49448  /Users/rschneeman/Documents/projects/codetriage/app/views/layouts/_app.html.slim
     49328  /Users/rschneeman/Documents/projects/codetriage/app/views/layouts/application.html.slim
     36044  /Users/rschneeman/Documents/projects/rails/activemodel/lib/active_model/type/helpers/time_value.rb
     34739  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/active_support/cache/dalli_store.rb
     34447  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/marshal.rb
     28029  <internal:prelude>
     25640  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/dalli/socket.rb
     25096  /Users/rschneeman/Documents/projects/codetriage/app/views/pages/_repos_with_pagination.html.slim
     18000  /Users/rschneeman/Documents/projects/rails/activemodel/lib/active_model/attribute_set/builder.rb
     17056  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/digestor.rb
     15888  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/result.rb
     15080  /Users/rschneeman/.gem/ruby/2.5.1/gems/rack-mini-profiler-1.0.0/lib/patches/db/pg.rb
     13984  /Users/rschneeman/Documents/projects/rails/actionpack/lib/abstract_controller/caching/fragments.rb
     11200  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/helpers/cache_helper.rb
     10046  /Users/rschneeman/.gem/ruby/2.5.1/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/storage/file_store.rb
      9289  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/tagged_logging.rb
      8648  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/lookup_context.rb
      8400  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/renderer/partial_renderer.rb
      8304  /Users/rschneeman/Documents/projects/rails/activemodel/lib/active_model/attribute.rb
      7751  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/log_subscriber.rb
      7348  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/logger.rb
      7216  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/object/to_query.rb
      7096  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb
      7024  /Users/rschneeman/.gem/ruby/2.5.1/gems/warden-1.2.6/lib/warden/proxy.rb
      6512  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_dispatch/routing/route_set.rb
      6354  /Users/rschneeman/.gem/ruby/2.5.1/gems/dalli-2.7.8/lib/dalli/client.rb
      6038  /Users/rschneeman/Documents/projects/rails/actionview/lib/action_view/helpers/tag_helper.rb
      6000  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/integration.rb
      5680  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/callbacks.rb
      5600  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/persistence.rb
      4916  /Users/rschneeman/.gem/ruby/2.5.1/gems/rack-2.0.5/lib/rack/utils.rb
      4896  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_dispatch/journey/formatter.rb
      4760  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_dispatch/http/response.rb
      4544  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/hash/keys.rb
      4536  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/array/conversions.rb
      4504  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/hash_with_indifferent_access.rb
      4448  /Users/rschneeman/.gem/ruby/2.5.1/gems/hashie-3.5.7/lib/hashie/mash.rb
      4448  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/notifications/instrumenter.rb
      4440  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/attribute_methods.rb
      4360  /Users/rschneeman/.gem/ruby/2.5.1/gems/will_paginate-3.1.0/lib/will_paginate/active_record.rb
      4240  /Users/rschneeman/Documents/projects/rails/actionpack/lib/abstract_controller/helpers.rb
      4160  /Users/rschneeman/Documents/projects/rails/actionpack/lib/abstract_controller/caching.rb
      4000  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb
      3968  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/subscriber.rb
      3888  /Users/rschneeman/.gem/ruby/2.5.1/gems/will_paginate-3.1.0/lib/will_paginate/view_helpers/link_renderer.rb
      3648  /Users/rschneeman/Documents/projects/rails/activerecord/lib/active_record/relation.rb
      3600  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/core_ext/date_and_time/zones.rb
      3592  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/duration.rb

Measured with

$ RAILS_SERVE_STATIC_FILES=1 RAILS_LOG_TO_STDOUT=1 DEVISE_SECRET_KEY=foo bundle exec derailed exec perf:objects

On CodeTriage.

@schneems
Copy link
Member Author

@dhh maybe we could re-use some of @noahgibbs work with rails ruby bench.

@noahgibbs
Copy link
Contributor

I'd be happy to run some before/after tests. That would be full end-to-end, though, so anything that doesn't save at least around 2% on the total Rails runtime for Discourse (everything: database, Redis, etc) is going to be hard to measure.

params[k] = self[k]
end
permitted_string_key = permitted_key.to_s
keys.each do |key|
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You could use each_key here to avoid allocating an intermediate array (#17099).

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice.

if permitted_scalar?(self[k])
params[k] = self[k]
end
permitted_string_key = permitted_key.to_s
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We might not need this value if the block returns on the first line, so perhaps we should inline the to_s call.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh, but then we might end up calling it multiple times. Never mind 🙄

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You actually can amortize it, though, by moving this line up higher: has_key? will also need to stringify its parameter.

@dhh
Copy link
Member

dhh commented Aug 30, 2018

@noahgibbs Would be nice to be able to quickly call in the Performance Budget Accessor on any PR and get a verdict. That would be a dream 😄

@noahgibbs
Copy link
Contributor

In general I'm happy to. Feel free to call me in where you're curious. My specific benchmark is a giant, concurrent end-to-end test based on Discourse - so it's only good for finding larger deltas in runtime and it can be finicky to set up. But when it works, it's a pretty realistic assessment. I'm running it against this change right now, but it takes at least a couple of hours.

@dhh
Copy link
Member

dhh commented Aug 30, 2018

@noahgibbs Awesome. Thanks! I wonder if there's a way we can think about having multiple layers of this. There's the microbenchmark, then there's the whole shebang that takes hours to run. Probably some thing good in the middle too.

@noahgibbs
Copy link
Contributor

Pretty certainly. I'm working on an intermediate benchmark now - still a Rails app, but one with a lot fewer dependencies and less non-Ruby time. With luck, that will be a good "something in the middle." For microbenchmarks, you'd probably want an approach kind of like what the Ruby repo does internally - a lot of tiny benchmarks that just hit a few methods each. ActiveSupport would be really easy to do this with and I expect it would work really well. It's also pretty similar to what @schneems did when writing this, just checked into the tree to be rerunnable.

@noahgibbs
Copy link
Contributor

It doesn't look like 'try' is much of the end-to-end performance. Specifically, with half a million HTTP requests for each version, I see the version with @schneems' change running 0.08% faster for the median request (like, less than a tenth of one percent.) But my variance on that measurement is around 3.2 reqs/second (std dev around 1.79), on a difference of about 0.14 requests/second. Basically it's far too small a measurement to be meaningful at this test size and variance.

@schneems schneems force-pushed the schneems/faster_strong_params branch from c423f0b to 832614f Compare August 31, 2018 14:40
@schneems
Copy link
Member Author

schneems commented Aug 31, 2018

I adopted the new suggestions. Thanks! I had to add a delegation of each_key because it previously did not exist.

In the interest of seeing any difference, I decided to benchmark this on a "hello world" app.

First I made a dev app that points to my local rails codebase:

bundle exec rails new ../my-test-app --dev

Then I added a controller action that hits this codepath:

class WelcomeController < ApplicationController
  def index
    params.permit(:language, :per_page, :page, :foo, :bar, :baz, :email, :name, :username)
    render plain: "hello world" and return
  end
end

I then hit the app using derailed benchmarks with and without this patch.

memory profiling "hello world" app

For memory I ran:

$ RAILS_SERVE_STATIC_FILES=1 RAILS_LOG_TO_STDOUT=1 TEST_COUNT=10_000 bundle exec derailed exec perf:objects

Without patch:

Total allocated: 67586 bytes (807 objects)

With patch:

Total allocated: 53072 bytes (705 objects)

Difference:

(67586 - 53072) / 67586.0 => 21% less memory allocated

Raw speed "hello world app"

For raw speed I hit this endpoint 10,000 times:

$ RAILS_SERVE_STATIC_FILES=1 RAILS_LOG_TO_STDOUT=1 TEST_COUNT=10_000 bundle exec derailed exec perf:test

With patch

10.319185 seconds

Without patch

12.999985 seconds

Difference:

(12.999985 - 10.319185) / 12.999985 # => 20.6% faster

Conclusions

From everything i've seen in profiling % of memory allocation decrease is roughly a 1:1 correlation with execution speed. Profiling memory allocation is also way easier and much more consistent with less variability.

In terms of how much faster this makes an app entirely depends on the app. For codetriage it's about a 1% bump, for discourse 0.8% (ish) for an app that practically does nothing a 20% bump provided that you're "permit" -ing lots of keys. Mostly it's a question of how much memory is the app in question allocating.

I can pretty confidently say that this code is faster. I cannot with any certainty try to say exactly what the impact is.

@schneems schneems force-pushed the schneems/faster_strong_params branch from 832614f to 11a2eb9 Compare August 31, 2018 16:16
When running with code triage and derailed benchmarks and focusing on this file:

Before

     16199  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_controller/metal/strong_parameters.r

After

      2280  /Users/rschneeman/Documents/projects/rails/actionpack/lib/action_controller/metal/strong_parameters.rb
@schneems schneems force-pushed the schneems/faster_strong_params branch from 11a2eb9 to daa3565 Compare August 31, 2018 16:17
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants