8

Introduce Journey::Ast to avoid extra ast walks by composerinteralia · Pull Requ...

 3 years ago
source link: https://github.com/rails/rails/pull/39935
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.
neoserver,ios ssh client

Conversation

This commit introduces a new Journey::Ast class that wraps the root
node of an ast. The purpose of this class is to reduce the number of
walks through the ast by consolidating necessary processing of nodes in
a single pass and holding onto values that can be used later.

Benefits

  • Performance improvements (see benchmarks below)
  • Keeps various ast manipulations together in a single class, rather
    than scattered throughout
  • Adding some names to things will hopefully make this code a little
    easier to follow for future readers

Benchmarks

We benchmarked loading a real routes file with > 3500 routes.
master was at a9336a6 when we ran these. Note that these benchmarks
also include a few small changes that we didn't include in this commit,
but that we will follow up with after this gets merged - these
additional changes do not change the benchmarks significantly.

Time:

master      - 0.798 ± 0.024 (500 runs)
this branch - 0.695 ± 0.029 (500 runs)

Allocations:

master      - 980149 total allocated objects
this branch - 931357 total allocated objects

Stackprof:

Seeing ActionDispatch::Journey::Visitors::Each#visit more frequently
on the stack is what led us down this path in the first place. These
changes seem to have done the trick.

master:
  TOTAL    (pct)     SAMPLES    (pct)     FRAME
    52   (0.5%)          52   (0.5%)     ActionDispatch::Journey::Nodes::Node#symbol?
    58   (0.5%)          45   (0.4%)     ActionDispatch::Journey::Scanner#scan
    45   (0.4%)          45   (0.4%)     ActionDispatch::Journey::Nodes::Cat#type
    43   (0.4%)          43   (0.4%)     ActionDispatch::Journey::Visitors::FunctionalVisitor#terminal
    303  (2.7%)          43   (0.4%)     ActionDispatch::Journey::Visitors::Each#visit
    69   (0.6%)          40   (0.4%)     ActionDispatch::Routing::Mapper::Scope#each

this commit:
  TOTAL    (pct)     SAMPLES    (pct)     FRAME
    82   (0.6%)          42   (0.3%)     ActionDispatch::Journey::Scanner#next_token
    31   (0.2%)          31   (0.2%)     ActionDispatch::Journey::Nodes::Node#symbol?
    30   (0.2%)          30   (0.2%)     ActionDispatch::Journey::Nodes::Node#initialize

Co-authored-by: Eric Milford [email protected]

@eugeneius this could use an initial review, if you are interested

Copy link

Member

eugeneius commented on Jul 27, 2020

My initial review:

  • This is really cool. 13% faster! horse_racing
  • How did you produce the benchmark results in the description? I'd like to see if I can replicate them on our app at work, which has a similar number of routes.
  • Are these new AST objects needed at runtime, or only while the routes are being defined? If it's the latter, I wonder how much more memory is now retained due to the memoized data. Maybe there's an opportunity to loop through the routes at the end and nil out their ASTs.

I'll take a closer look at the implementation soon.

Copy link

Member

Author

composerinteralia commented on Jul 27, 2020

edited

@eugeneius

How did you produce the benchmark results in the description? I'd like to see if I can replicate them on our app at work, which has a similar number of routes.

I pointed my app to my local Rails and added this to my routes file:

Rails.application.routes.draw do
+  before_object_count = GC.stat[:total_allocated_objects]
+  time = Benchmark.realtime do
    #... all the route definitions
+  end
+  puts GC.stat[:total_allocated_objects] - before_object_count
+  puts time
end

Then ran bin/rails runner true to see the output. The total allocated objects count was pretty consistent, so I didn't feel the need to do multiple runs there.

For the timing I ran this not terribly elegant script, passing the refs I wanted to test out as arguments. You might want to change 500 to something more reasonable - I ran this and then went to bed.

def report(filename, ljust)
  times = File.read("journey_benchmark/#{filename}").lines.map(&:chomp).map(&:to_f)
  median = times.inject(&:+) / times.length
  dev = Math.sqrt((times.map { |time| (time - median)**2 }).inject(&:+) / (times.length - 1))

  puts "#{filename.ljust(ljust)} - #{median.round(3)} ± #{dev.round(3)} (#{times.length} runs)"
end

def run_benchmark(ref)
  puts "Running benchmark for '#{ref}'"

  Dir.chdir("path/to/local/rails") do
    `git checkout #{ref}`
  end

  500.times do 
    `bin/rails runner true | tail -1 >> "journey_benchmark/#{ref}"`
  end
end

Dir.chdir("path/to/application") do
  ARGV.each do |ref|
    run_benchmark(ref)
  end

  ljust = ARGV.map(&:length).max
  ARGV.each do |ref|
    report(ref, ljust)
  end
end

I'm sure there is a better way to do this...

Copy link

Member

Author

composerinteralia commented on Jul 27, 2020

edited

Are these new AST objects needed at runtime, or only while the routes are being defined? If it's the latter, I wonder how much more memory is now retained due to the memoized data. Maybe there's an opportunity to loop through the routes at the end and nil out their ASTs.

Great question. We should try to measure the retained memory. We might not need the ast objects anymore after building the simulator in lib/action_dispatch/journey/routes.rb, but we may have to do something to make clearing them out work with clear_cache!. I will think about it.

composerinteralia

force-pushed the

composerinteralia:journey-performance-improvements

branch from ccabbc0 to 5c8c836

on Jul 27, 2020

Copy link

Member

Author

composerinteralia commented on Jul 27, 2020

edited

I put this in RouteSet#eager_load! and then eager loaded the routes at the bottom of my routes file.

      def eager_load!
        router.eager_load!
        routes.each(&:eager_load!)
        require 'objspace'
        GC.start
        puts ObjectSpace.each_object(Object).count
        nil
      end
master      - 1141852
this commit - 1159326

Is this a reasonable way to measure what was retained?

Update: if I wipe out the references from within eager_load! this number goes down to 1110148. I'm unsure whether this is actually the right place to do that, but the idea seems generally promising.

Copy link

Member

Author

composerinteralia commented on Jul 28, 2020

edited

Are these new AST objects needed at runtime, or only while the routes are being defined? If it's the latter, I wonder how much more memory is now retained due to the memoized data. Maybe there's an opportunity to loop through the routes at the end and nil out their ASTs.

Once possibility is to clear out the AST objects at the end of RouteSet#eager_load!. This would ensure that we don't retain these extra objects in any environment that eager loads (although we would still retain them in other environments, like the standard dev and test environments). But one concern we have here is whether there is ever a case where somebody would add routes after eager loading. If so, that could be a problem because adding a new route would clear out the ast and simulator, at which point we would not have what we need to rebuild the simulator.

We found two tests that involve creating a simulator and then adding a new route after, but I don't know how realistic these tests are. These two test also don't have anything to do with eager loading.

  • def test_routes_changed_correctly_after_clear rs = ::ActionDispatch::Routing::RouteSet.new rs.draw do get "ca" => "ca#aa" get "cb" => "cb#ab" get "cc" => "cc#ac" ActiveSupport::Deprecation.silence do get ":controller/:action/:id" get ":controller/:action/:id.:format" end end hash = rs.recognize_path "/cc" assert_not_nil hash assert_equal %w(cc ac), [hash[:controller], hash[:action]] rs.draw do get "cb" => "cb#ab" get "cc" => "cc#ac" ActiveSupport::Deprecation.silence do get ":controller/:action/:id" get ":controller/:action/:id.:format" end end hash = rs.recognize_path "/cc" assert_not_nil hash assert_equal %w(cc ac), [hash[:controller], hash[:action]] end end
  • def test_simulator_changes mapper.get "/foo(/:id)", to: "foo#bar", as: "aaron" sim = routes.simulator mapper.get "/foo(/:id)", to: "foo#bar", as: "gorby" assert_not_equal sim, routes.simulator end

Update:

After some discussion with Rafael França and Matthew Draper I think we should preserve the ability to add more routes after eager loading. So instead we can clear out all the cached values inside the ast objects after eager loading, then recalculate those values again if necessary.

Copy link

Contributor

casperisfine commented on Jul 28, 2020

Is this a reasonable way to measure what was retained?

Somewhat yes. But I'd suggest using http://github.com/SamSaffron/memory_profiler for a breakdown of what was retained etc.

Copy link

Contributor

casperisfine commented on Jul 28, 2020

Profiling this branch against our application full boot sequence.

Baseline is e2cc2d1dfca51d15567671f2634fc28025480c1b (because I had it handy)
Tested commit is: 5c8c8364c361140c89bab88452ac54d231e51ad9
So diff is: e2cc2d1...5c8c836

Most stackprof results will be CPU profiles unless specified otherwise.

First I do see the nice #visit reduction (2.5% -> 1.7%):

$ bundle exec bin/stackprof ~/Downloads/rails-stackprof-cpu-baseline.dump --method='ActionDispatch::Journey::Visitors::Each#visit'
ActionDispatch::Journey::Visitors::Each#visit (/tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/visitors.rb:160)
  samples:   115 self (0.2%)  /   1284 total (2.5%)
  callers:
    6223  (  484.7%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#binary
    1284  (  100.0%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#accept
     221  (   17.2%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#nary
     167  (   13.0%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#unary
  callees (1169 total):
    6988  (  597.8%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#visit
     289  (   24.7%)  ActionDispatch::Journey::GTG::Builder#build_followpos
     199  (   17.0%)  ActionDispatch::Journey::Nodes::Node#symbol?
     171  (   14.6%)  ActionDispatch::Routing::Mapper::Mapping#initialize
      62  (    5.3%)  ActionDispatch::Journey::Nodes::Node#group?
      35  (    3.0%)  ActionDispatch::Journey::Nodes::Terminal#terminal?
      17  (    1.5%)  ActionDispatch::Journey::Nodes::Node#terminal?
      17  (    1.5%)  ActionDispatch::Journey::Nodes::Symbol#symbol?
       2  (    0.2%)  ActionDispatch::Journey::Nodes::Group#group?
$ bundle exec bin/stackprof ~/Downloads/rails-stackprof-cpu-journey.dump --method='ActionDispatch::Journey::Visitors::Each#visit'
ActionDispatch::Journey::Visitors::Each#visit (/tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/visitors.rb:160)
  samples:    10 self (0.0%)  /    706 total (1.7%)
  callers:
    3252  (  460.6%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#binary
     706  (  100.0%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#accept
     200  (   28.3%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#nary
      96  (   13.6%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#unary
  callees (696 total):
    3710  (  533.0%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#visit
     250  (   35.9%)  ActionDispatch::Journey::GTG::Builder#build_followpos
     149  (   21.4%)  ActionDispatch::Journey::Ast#initialize
      70  (   10.1%)  ActionDispatch::Journey::Nodes::Node#group?
      58  (    8.3%)  ActionDispatch::Journey::Nodes::Node#symbol?
       4  (    0.6%)  ActionDispatch::Journey::Nodes::Symbol#symbol?
       3  (    0.4%)  ActionDispatch::Journey::Nodes::Group#group?

If I look at Rails::Application::RoutesReloader#reload! it's marginally faster now, but it's definitely called much less:

$ bundle exec bin/stackprof ~/Downloads/rails-stackprof-cpu-baseline.dump --method='Rails::Application::RoutesReloader#reload!'
Rails::Application::RoutesReloader#reload! (/tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/railties/lib/rails/application/routes_reloader.rb:19)
  samples:     0 self (0.0%)  /   6108 total (11.8%)
  callers:
    6108  (  100.0%)  Rails::Application::RoutesReloader#updater
  callees (6108 total):
    4837  (   79.2%)  Rails::Application::RoutesReloader#load_paths
    1269  (   20.8%)  ActionDispatch::Routing::RouteSet#eager_load!
       2  (    0.0%)  Rails::Application::RoutesReloader#finalize!
$ bundle exec bin/stackprof ~/Downloads/rails-stackprof-cpu-journey.dump --method='Rails::Application::RoutesReloader#reload!'
Rails::Application::RoutesReloader#reload! (/tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/railties/lib/rails/application/routes_reloader.rb:19)
  samples:     0 self (0.0%)  /   4886 total (11.6%)
  callers:
    4886  (  100.0%)  Rails::Application::RoutesReloader#updater
  callees (4886 total):
    3775  (   77.3%)  Rails::Application::RoutesReloader#load_paths
    1110  (   22.7%)  ActionDispatch::Routing::RouteSet#eager_load!
       1  (    0.0%)  Rails::Application::RoutesReloader#finalize!

On the memory front, I see a slight increase.

The total retention post boot is up by 2.7MB for us (to take with a grain of salt as there are some variance. We're a bit above what I consider to be the margin of error, but not by that much).

On the retentions attributed to journey itself (NB: again these are not perfectly precise, a retention can very easily attributed to the wrong source):

The total allocations during boot is up by about 12800 (again can very well be in the margin of error).

Baseline:
allocated memory by file
-----------------------------------
  33.25 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/routing/mapper.rb
  20.89 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/path/pattern.rb
   9.74 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/gtg/builder.rb
   8.00 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/visitors.rb
   4.61 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/parser.rb
   4.49 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/scanner.rb

retained memory by file
-----------------------------------
   7.89 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/path/pattern.rb
   4.61 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/parser.rb
   4.45 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/routing/mapper.rb
   2.36 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/visitors.rb
   1.84 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/gtg/transition_table.rb
   1.69 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/routing/route_set.rb
   1.11 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-e2cc2d1dfca5/actionpack/lib/action_dispatch/journey/route.rb
 969.32 kB  /tmp/bundle/ruby/2.7.0/gems/graphql-1.10.14/lib/graphql/schema.rb

Patch:
allocated memory by file
-----------------------------------
  32.64 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/routing/mapper.rb
  20.56 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/path/pattern.rb
   9.74 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/gtg/builder.rb
   8.76 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/visitors.rb
   4.89 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/nodes/node.rb
   4.61 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/parser.rb

retained memory by file
-----------------------------------
   7.69 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/path/pattern.rb
   4.89 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/routing/mapper.rb
   4.61 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/parser.rb
   2.48 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/nodes/node.rb
   2.36 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/visitors.rb
   1.84 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/gtg/transition_table.rb
   1.69 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/routing/route_set.rb
   1.11 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-5c8c8364c361/actionpack/lib/action_dispatch/journey/route.rb

So the speedup does indeed seem visible on our app, and the memory increase if any isn't a show stopper.

instead we can clear out all the cached values inside the ast objects after eager loading

Let me know if you'd like me to memory profile that.

composerinteralia

force-pushed the

composerinteralia:journey-performance-improvements

branch from cc13db6 to 45f657e

on Jul 29, 2020

@casperisfine thanks so much for running those profiles. @emilford and I added a commit that will hopefully cut down on the retained memory, and would be most grateful if you could run the profile again with the new commit.

This is what I am seeing:

Before clearing out ast objects in 45f657e

retained memory by file                                                                                                             
-----------------------------------                                                                                                 
   3834102  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/path/pattern.rb                            
   3025661  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/routing/mapper.rb                                  
   2964176  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/parser.rb                                  
   2110720  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/routing/route_set.rb                               
   1932016  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/nodes/node.rb                              
   1633624  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/visitors.rb                                
   1257578  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/gtg/transition_table.rb                    
    808310  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/route.rb                                   
    230664  /Users/daniel/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/set.rb 

After clearing out ast objects in 45f657e

retained memory by file                                                                                                               
-----------------------------------                                                                                                   
   3989742  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/path/pattern.rb                              
   2964176  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/parser.rb                                    
   2690877  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/routing/mapper.rb                                    
   2110720  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/routing/route_set.rb                                 
   1633624  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/visitors.rb                                  
   1257578  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/gtg/transition_table.rb                      
    808310  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/route.rb                                     
    230664  /Users/daniel/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/set.rb   

Baseline

retained memory by file                                                                                                                                                                                                                                                    
-----------------------------------                                                                                                 
   3834102  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/path/pattern.rb                            
   2707037  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/routing/mapper.rb                                  
   2110720  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/routing/route_set.rb                               
   1633624  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/visitors.rb                                
   1557832  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/parser.rb                                  
   1257578  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/gtg/transition_table.rb                    
    808310  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/route.rb                                   
    239200  /Users/daniel/Desktop/oss/rails/rails/actionpack/lib/action_dispatch/journey/nodes/node.rb                              
    230664  /Users/daniel/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/set.rb 

We could probably do a little better in path/pattern, except that we have to hold onto the ast root node to make the new test_drawing_more_routes_after_eager_loading test pass. This is a weird test, and I think an unlikely scenario, but it is currently the way things work and we wanted to preserve that for now.

Copy link

Contributor

casperisfine commented on Jul 29, 2020

$ bundle exec bin/stackprof ~/Downloads/stackprof-shopify-boot-production-cpu\ \(3\).dump  --method='ActionDispatch::Journey::Visitors::Each#visit'
ActionDispatch::Journey::Visitors::Each#visit (/tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/journey/visitors.rb:160)
  samples:     8 self (0.0%)  /    824 total (1.6%)
  callers:
    3794  (  460.4%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#binary
     824  (  100.0%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#accept
     240  (   29.1%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#nary
     110  (   13.3%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#unary
  callees (816 total):
    4324  (  529.9%)  ActionDispatch::Journey::Visitors::FunctionalVisitor#visit
     302  (   37.0%)  ActionDispatch::Journey::GTG::Builder#build_followpos
     202  (   24.8%)  ActionDispatch::Journey::Ast#initialize
      71  (    8.7%)  ActionDispatch::Journey::Nodes::Node#symbol?
      53  (    6.5%)  ActionDispatch::Journey::Nodes::Node#group?
       6  (    0.7%)  ActionDispatch::Journey::Nodes::Symbol#symbol?
       2  (    0.2%)  ActionDispatch::Journey::Nodes::Group#group?
$ bundle exec bin/stackprof ~/Downloads/stackprof-shopify-boot-production-cpu\ \(3\).dump --method='Rails::Application::RoutesReloader#reload!'
Rails::Application::RoutesReloader#reload! (/tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/railties/lib/rails/application/routes_reloader.rb:19)
  samples:     0 self (0.0%)  /   5651 total (11.0%)
  callers:
    5651  (  100.0%)  Rails::Application::RoutesReloader#updater
  callees (5651 total):
    4418  (   78.2%)  Rails::Application::RoutesReloader#load_paths
    1231  (   21.8%)  ActionDispatch::Routing::RouteSet#eager_load!
       2  (    0.0%)  Rails::Application::RoutesReloader#finalize!

Total memory retention is now down by about 2MB (compared to the previous baseline).

retained memory by file
-----------------------------------
   7.69 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/journey/path/pattern.rb
   4.46 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/routing/mapper.rb
   2.37 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/journey/parser.rb
   2.36 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/journey/visitors.rb
   1.84 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/journey/gtg/transition_table.rb
   1.68 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/routing/route_set.rb
   1.11 MB  /tmp/bundle/ruby/2.7.0/bundler/gems/rails-45f657eca631/actionpack/lib/action_dispatch/journey/route.rb

So that looks very good from my end.

Copy link

Member

Author

composerinteralia commented on Jul 30, 2020

edited

Tests added and all the numbers seem to be looking pretty good. This is ready for another review when somebody has a chance.

if node.terminal?

terminals << node

end

end

eileencodes on Aug 4, 2020

edited

Member

This feels like a lot for initialize - what do you think about pulling the tree iteration out into a private method and then calling that from initialize?

composerinteralia on Aug 4, 2020

Author

Member

Yeah, that makes sense to me. Thanks!

composerinteralia

force-pushed the

composerinteralia:journey-performance-improvements

branch from 7843c50 to f984804

on Aug 4, 2020

composerinteralia

force-pushed the

composerinteralia:journey-performance-improvements

branch from f984804 to 56e3e85

on Aug 19, 2020

@tenderlove I would be interested in getting your thoughts on this PR at some point as well (no rush). The tl;dr for the benchmarks is that this seems to be a positive change for shopify and github/github.

Base automatically changed from master to main on Jan 14

Copy link

rails-bot bot commented on Apr 14

This pull request has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.
Thank you for your contributions.

Copy link

Member

Author

composerinteralia commented on Apr 19

@eileencodes @jhawthorn this is something @emilford and I had worked on to improve boot time for GitHub. If this is something you are still interested in I'd be happy to revive this PR, otherwise I'll go ahead and close it.

Copy link

Contributor

casperisfine commented on Apr 20

@composerinteralia I'll be happy to merge it.

Copy link

rails-bot bot commented 13 days ago

This pull request has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.
Thank you for your contributions.

Copy link

Member

eileencodes commented 5 days ago

@composerinteralia do you want to pick this up again? There were some changes to journey so it'll need a rebase and possible a new benchmark/profile.

Copy link

Member

Author

composerinteralia commented 5 days ago

Oh right, I forgot about this. I'd planned on working on it a few months ago, but got distracted by an unexpected job search. Yeah, I should be able to get to it in the next couple weeks.

composerinteralia

force-pushed the

composerinteralia:journey-performance-improvements

branch 2 times, most recently from 2242d7c to bf86dac

4 days ago

Copy link

Member

Author

composerinteralia commented 4 days ago

edited

Rebased and reworked a little to take #41024 into consideration. I also wrote a cleaner benchmark to show that drawing routes is a bit faster with this PR:

Before:

Warming up --------------------------------------
drawing a simple route
                       435.000  i/100ms
drawing a complex route
                       306.000  i/100ms
Calculating -------------------------------------
drawing a simple route
                          4.067k (± 9.7%) i/s -     20.445k in   5.074692s
drawing a complex route
                          2.852k (± 6.2%) i/s -     14.382k in   5.063012s

After:

Warming up --------------------------------------
drawing a simple route
                       517.000  i/100ms
drawing a complex route
                       393.000  i/100ms
Calculating -------------------------------------
drawing a simple route
                          4.725k (± 6.2%) i/s -     23.782k in   5.052018s
drawing a complex route
                          3.532k (± 5.0%) i/s -     17.685k in   5.019272s

Benchmark

Copy link

Member

Author

composerinteralia commented 4 days ago

This CI failures don't look obviously related. Are there any known problems at the moment, or do I need to do some digging?

Copy link

Member

byroot commented 4 days ago

Are there any known problems at the moment, or do I need to do some digging?

Most of the failures are ruby-head. We just passed midnight UTC so we got a new version, some upstream change must have broken the suite, I'll likely have a look.

And yeah the one Ruby 3.0 postgres failure is clearly unrelated.

Copy link

Member

byroot commented 4 days ago

Ah most of these I already fixed with bbaf40b, a few remaining ones in Active Record will need some extra work.

composerinteralia

force-pushed the

composerinteralia:journey-performance-improvements

branch from bf86dac to 2369b1e

4 days ago

Copy link

Contributor

casperisfine commented 4 days ago

So I tested this against our app again. Not sure if intended, and we can probably update our code, but it does break one test:

NoMethodError: undefined method `names' for #<ActionDispatch::Journey::Nodes::Cat:0x00007f03518f1870 @left=#<ActionDispatch::Journey::Ast:0x00007f...

As for boot performance, ActionDispatch::Journey::Visitors::Each#visit is down from 2.3% to 1.1%, and Rails::Application::RoutesReloader#reload! is down from 6.3% to 4.3%.

As for memory, heap-profiler is reporting a 2MiB increase overall, but again it's not necessarily significant.

So +1 from my end, but maybe have a look at that NoMethodError, maybe it's private API, in which case it's on us to update.

Other than that, I'm still happy to merge, you'll just have to squash your commits into one.

Copy link

Member

Author

composerinteralia commented 3 days ago

Thank you for doing that! Are you able to look into that NoMethodError a bit more, or provide more of the stack trace? Seems like there is a Journey::Path::Pattern getting initialized with a CAT node wrapping the AST, instead of the AST directly. I'm not sure how that would happen.

Copy link

Member

rafaelfranca commented 3 days ago

We have some monkey patch in the routing code that is creating the ActionDispatch::Journey::Nodes::Cat object directly. This is the code:

        def concat_paths(prefix, suffix)
          joined_ast = ActionDispatch::Journey::Nodes::Cat.new(prefix.ast, suffix.ast)
          prefix_sep = prefix.instance_variable_get(:@separators).split
          suffix_sep = suffix.instance_variable_get(:@separators).split
          build_pattern(
            joined_ast,
            prefix.requirements.merge(suffix.requirements),
            (prefix_sep + suffix_sep).uniq,
            prefix.anchored,
          )
        end

We should just fix that.

composerinteralia

force-pushed the

composerinteralia:journey-performance-improvements

branch from 2369b1e to f353057

2 days ago

Copy link

Member

kaspth left a comment

Quite the Journey on this PR! Glad we're doing less walking around these trees, an Astute find!

rafaelfranca

merged commit a41f810 into rails:main 2 days ago

4 checks passed

composerinteralia

deleted the

composerinteralia:journey-performance-improvements

branch

2 days ago

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

None yet

Milestone

No milestone

Linked issues

Successfully merging this pull request may close these issues.

None yet

7 participants

About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK