Upgrade to Pro — share decks privately, control downloads, hide ads and more …

RailsConf 2015 Keynote

RailsConf 2015 Keynote

Aaron Patterson

May 13, 2015
Tweet

More Decks by Aaron Patterson

Other Decks in Technology

Transcript

  1. Click to add title
    Click to add subtitle

    View full-size slide

  2. Why Windows?

    View full-size slide

  3. Kent Beck!!!

    View full-size slide

  4. Welcome To Rails Conf!!!

    View full-size slide

  5. Aaron Patterson

    View full-size slide

  6. Ruby Central

    View full-size slide

  7. @eileencodes

    View full-size slide

  8. Thank You!!! <3

    View full-size slide

  9. Extreme Programming

    View full-size slide

  10. Last Year:
    Thought Leader in Training

    View full-size slide

  11. I Graduated!!

    View full-size slide

  12. Degree in Thought Leadering
    from Online University

    View full-size slide

  13. Trolling DHH

    View full-size slide

  14. "TDD is dead"

    View full-size slide

  15. Turbo Links 3: RJS

    View full-size slide

  16. I should announce something.

    View full-size slide

  17. Action Fanny Pack

    View full-size slide

  18. Performance!
    vroom!!!

    View full-size slide

  19. Adequate Development

    View full-size slide

  20. Automatic Parallel Testing

    View full-size slide

  21. Data Base
    Test Process Test Process Test Process

    View full-size slide

  22. Data Base
    Test Process Test Process Test Process
    Data Base Data Base
    Data Base

    View full-size slide

  23. Caching Compiled Views

    View full-size slide

  24. Today: lazy compile

    View full-size slide

  25. Get lock
    Template Compiled?
    Compile
    Save
    Unlock
    Writes to
    memory

    View full-size slide

  26. Threaded Servers: lock

    View full-size slide

  27. Forking servers:
    waste memory

    View full-size slide

  28. Too many templates!

    View full-size slide

  29. Rendering with Locals

    View full-size slide

  30. Template source
    eval("
    local_variable = variables_hash[:local_variable]
    # rest of the template
    ")

    View full-size slide

  31. Integration Tests

    View full-size slide

  32. Controller Test
    class ControllerTest < ActionController::TestCase
    test "index" do
    get :index
    assert_equal 200, response.status
    end
    end

    View full-size slide

  33. Integration Test
    class IntegrationTest < ActionDispatch::IntegrationTest
    test "index" do
    get '/documents'
    assert_equal 200, response.status
    end
    end

    View full-size slide

  34. Why do we write
    controller tests?

    View full-size slide

  35. Because integration tests
    are slow?

    View full-size slide

  36. If tests are slow,
    is the website slow?

    View full-size slide

  37. Rails 5?: Fast Tests

    View full-size slide

  38. Controller / Integration:
    What’s the difference?

    View full-size slide

  39. Controller:
    no middleware

    View full-size slide

  40. Integration:
    has middleware

    View full-size slide

  41. Rails 5?: Delete controller
    tests
    *We won’t actually delete them

    View full-size slide

  42. Why So Slow?

    View full-size slide

  43. Benchmark
    Benchmark.ips do |bm|
    bm.report 'INDEX: Integration Test' do
    Minitest.run_one_method(IntegrationTest, 'test_index')
    end
    bm.report 'INDEX: Functional Test' do
    Minitest.run_one_method(ControllerTest, 'test_index')
    end
    bm.compare!
    end
    Controller
    Integration
    Compare

    View full-size slide

  44. Result
    Calculating -------------------------------------
    INDEX: Integration Test
    15.000 i/100ms
    INDEX: Functional Test
    39.000 i/100ms
    -------------------------------------------------
    INDEX: Integration Test
    158.019 (± 8.2%) i/s - 795.000
    INDEX: Functional Test
    390.853 (± 9.0%) i/s - 1.950k
    Comparison:
    INDEX: Functional Test: 390.9 i/s
    INDEX: Integration Test: 158.0 i/s - 2.47x slower
    Comparison

    View full-size slide

  45. What is slow?

    View full-size slide

  46. Controller Bottleneck
    Minitest.run_one_method(ControllerTest, 'test_index')
    StackProf.run(mode: :cpu, out: 'stackprof.dump') do
    3000.times do
    Minitest.run_one_method(ControllerTest,
    'test_index')
    end
    end

    View full-size slide

  47. CPU time vs
    Wall time

    View full-size slide

  48. `sleep` is slow, but doesn’t
    use CPU

    View full-size slide

  49. View Stack
    $ stackprof stackprof.dump

    View full-size slide

  50. Stack
    ==================================
    Mode: cpu(1000)
    Samples: 3280 (0.00% miss rate)
    GC: 134 (4.09%)
    ==================================
    TOTAL (pct) SAMPLES (pct) FRAME
    3146 (95.9%) 1740 (53.0%)
    Minitest::Runnable.on_signal
    483 (14.7%) 483 (14.7%)
    Dependencies#search_for_file
    207 (6.3%) 191 (5.8%) SQLite3::Database#prepare
    95 (2.9%) 95 (2.9%) Inflector#underscore
    47 (1.4%) 46 (1.4%) TestRequest#initialize

    View full-size slide

  51. 53.0% in
    Minitest::Runnable.on_signal

    View full-size slide

  52. on_signal
    def self.on_signal name, action # :nodoc:
    supported = SIGNALS[name]
    old_trap = trap name do
    old_trap.call if old_trap.respond_to? :call
    action.call
    end if supported
    yield
    ensure
    trap name, old_trap if supported
    end

    View full-size slide

  53. JUST DELETE IT

    View full-size slide

  54. on_signal
    def self.on_signal name, action
    yield
    end

    View full-size slide

  55. Results
    ==================================
    Mode: cpu(1000)
    Samples: 4246 (0.00% miss rate)
    GC: 386 (9.09%)
    ==================================
    TOTAL (pct) SAMPLES (pct) FRAME
    220 (5.2%) 185 (4.4%)
    SQLite3::Database#prepare
    148 (3.5%) 131 (3.1%) TestRequest#initialize
    113 (2.7%) 113 (2.7%) Event#initialize
    105 (2.5%) 105 (2.5%)
    PerThreadRegistry#instance

    View full-size slide

  56. Time the process
    $ time ruby benchmark.rb
    real 0m12.358s
    user 0m11.732s
    sys 0m0.498s
    $ time ruby benchmark.rb
    real 0m12.055s
    user 0m11.462s
    sys 0m0.475s
    Before
    After

    View full-size slide

  57. Wall should be similar to
    CPU

    View full-size slide

  58. Stack (CPU)
    ==================================
    Mode: cpu(1000)
    Samples: 3280 (0.00% miss rate)
    GC: 134 (4.09%)
    ==================================
    TOTAL (pct) SAMPLES (pct) FRAME
    3146 (95.9%) 1740 (53.0%)
    Minitest::Runnable.on_signal
    483 (14.7%) 483 (14.7%)
    Dependencies#search_for_file
    207 (6.3%) 191 (5.8%) SQLite3::Database#prepare
    95 (2.9%) 95 (2.9%) Inflector#underscore
    47 (1.4%) 46 (1.4%) TestRequest#initialize

    View full-size slide

  59. Stack (WALL)
    ==================================
    Mode: wall(1000)
    Samples: 8797 (0.11% miss rate)
    GC: 535 (6.08%)
    ==================================
    TOTAL (pct) SAMPLES (pct) FRAME
    286 (3.3%) 286 (3.3%) PerThreadRegistry#instance
    233 (2.6%) 233 (2.6%) Formatter#non_recursive
    336 (3.8%) 227 (2.6%) Class#class_attribute
    209 (2.4%) 209 (2.4%)
    NonConcurrentCacheBackend#[]
    198 (2.3%) 198 (2.3%) ActiveRecord::Base.logger

    View full-size slide

  60. Even profilers have bugs!

    View full-size slide

  61. Something useful

    View full-size slide

  62. Integration test profiles.

    View full-size slide

  63. Stack (WALL)
    ==================================
    Mode: wall(1000)
    Samples: 20168 (2.95% miss rate)
    GC: 1247 (6.18%)
    ==================================
    TOTAL (pct) SAMPLES (pct) FRAME
    6401 (31.7%) 5622 (27.9%) block in Module#delegate
    495 (2.5%) 495 (2.5%)
    PerThreadRegistry#instance
    341 (1.7%) 341 (1.7%)
    NonConcurrentCacheBackend#[]
    317 (1.6%) 317 (1.6%) Set#include?

    View full-size slide

  64. Calling `delegate` is slow.

    View full-size slide

  65. Patch
    - delegate :url_for, :optimize_routes_generation?, to: '@_routes'
    + def url_for(options)
    + @_routes.url_for(options)
    + end
    +
    + def optimize_routes_generation?
    + @_routes.optimize_routes_generation?
    + end
    +

    View full-size slide

  66. Check our progress

    View full-size slide

  67. 2.47x slower

    View full-size slide

  68. Result
    Calculating -------------------------------------
    INDEX: Integration Test
    23.000 i/100ms
    INDEX: Functional Test
    37.000 i/100ms
    -------------------------------------------------
    INDEX: Integration Test
    251.487 (±12.7%) i/s - 1.242k
    INDEX: Functional Test
    365.112 (±11.0%) i/s - 1.813k
    Comparison:
    INDEX: Functional Test: 365.1 i/s
    INDEX: Integration Test: 251.5 i/s - 1.45x slower
    Comparison

    View full-size slide

  69. 2.47x to 1.45x

    View full-size slide

  70. Verify
    $ time ruby test.rb
    real 0m26.821s
    user 0m25.277s
    sys 0m0.903s
    $ time ruby test.rb
    real 0m16.632s
    user 0m15.709s
    sys 0m0.638s
    Before
    After

    View full-size slide

  71. Even profilers have bugs

    View full-size slide

  72. Always measure

    View full-size slide

  73. Verify results

    View full-size slide

  74. Today: 10% slower

    View full-size slide

  75. But faster than controller
    tests in previous versions

    View full-size slide

  76. Soup two Nuts
    Performance

    View full-size slide

  77. bin stub source code
    #!/Users/aaron/.rbenv/versions/ruby-trunk/bin/ruby
    #
    # This file was generated by RubyGems.
    #
    # The application 'bundler' is installed as part of a gem, and
    # this file is here to facilitate running it.
    #
    # some unimportant stuff happens here!
    gem 'bundler', version
    load Gem.bin_path('bundler', 'bundle', version)

    View full-size slide

  78. What does
    `gem` do?

    View full-size slide

  79. Finds a gemspec

    View full-size slide

  80. Puts a path on
    $LOAD_PATH

    View full-size slide

  81. Load Path Manipulation
    > x = $LOAD_PATH.dup; nil
    => nil
    > gem 'bundler'
    => true
    > $LOAD_PATH - x
    => ["/Users/aaron/.rbenv/versions/ruby-trunk/lib/ruby/gems/2.3.0/gems/
    bundler-1.9.2/lib"]

    View full-size slide

  82. What Happens
    When File is Required?

    View full-size slide

  83. Is File in
    $LOAD_PATH?
    Load it!
    Is file in
    Gemspec?
    Add gemspec to
    $LOAD_PATH

    View full-size slide

  84. RubyGems performance

    View full-size slide

  85. Test Methodology

    View full-size slide

  86. Require One File
    And Increase Gems

    View full-size slide

  87. Activate one Gem
    And Increase Gems

    View full-size slide

  88. time to require one file
    Time in seconds
    0
    0.08
    0.16
    0.24
    0.32
    Number of Gems on the system
    0 100 200 300 400 500 600 700 800 900 1000
    best
    worst

    View full-size slide

  89. allocations to require one file
    Number of allocations
    0
    22500
    45000
    67500
    90000
    Number of Gems on the system
    0 100 200 300 400 500 600 700 800 900 1000
    best
    worst

    View full-size slide

  90. time to activate one gem
    Time in seconds
    0
    0.06
    0.12
    0.18
    0.24
    Number of Gems on the system
    0 100 200 300 400 500 600 700 800 900 1000
    best
    worst

    View full-size slide

  91. allocations to activate one gem
    Number of allocations
    0
    10000
    20000
    30000
    40000
    Number of Gems on the system
    0 100 200 300 400 500 600 700 800 900 1000

    View full-size slide

  92. Bundler Performance

    View full-size slide

  93. One Gem in Gemfile
    Increase Gems on System

    View full-size slide

  94. Increase Gems in Gemfile
    Constant Gems on System

    View full-size slide

  95. *NO DEPENDENCIES

    View full-size slide

  96. Vary System Gems

    View full-size slide

  97. `bundle update` with one gem
    Time in Seconds
    0
    0.2
    0.4
    0.6
    0.8
    Number of Gems on the system
    100 200 300 400 500 600 700 800 900 1000

    View full-size slide

  98. `bundle exec` with one gem
    Time in Seconds
    0
    0.2
    0.4
    0.6
    0.8
    Number of Gems on the system
    100 200 300 400 500 600 700 800 900 1000

    View full-size slide

  99. Vary Gems in Gemfile

    View full-size slide

  100. `bundle exec` time
    Time in seconds
    1.44
    1.45
    1.46
    1.47
    1.48
    Number of gems in the gemfile
    0 100 200 300 400 500 600 700 800 900 1000
    y = 0.0008x + 1.4603
    R² = 0.1323

    View full-size slide

  101. Bundle Exec Time Breakdown (ms)
    Other?
    750
    Spec Load
    710

    View full-size slide

  102. `bundle update` time
    Time in Seconds
    0
    17.5
    35
    52.5
    70
    Number of Gems in the Gemfile
    0 100 200 300 400 500 600 700 800 900 1000
    y = 0.6984x2 - 2.9466x + 13.856
    R² = 0.999

    View full-size slide

  103. Thanks Excel

    View full-size slide

  104. R Code - Fit curve
    > bundler <- read.csv(file="~/bundle_test/
    run_bundle_updats.csv",head=TRUE,sep=",")
    > fit2 <- lm(bundler$time ~ poly(bundler$gems, 2, raw =
    TRUE))
    > xx <- seq(0, 1000, length=11)
    > plot(bundler$gems, bundler$time)
    > lines(xx, predict(fit2, data.frame(x = xx)), col="red")

    View full-size slide

  105. R Code - Coefficients
    > coefficients(fit2)
    (Intercept) poly(bundler$gems, 2, raw = TRUE)1 poly(bundler$gems, 2, raw = TRUE)2
    1.160827e+01 -1.549806e-02 6.984136e-05
    > summary(fit2)$r.squared
    [1] 0.9989536
    >

    View full-size slide

  106. Make Predictions
    > second_order <- function(newdist, model) {
    + coefs <- coef(model)
    + res <- coefs[1] + (coefs[2] * newdist) + (coefs[3] * newdist^2)
    + return(res)
    + }
    > second_order(0, fit2)
    (Intercept)
    11.60827
    > second_order(10000, fit2)
    (Intercept)
    6840.763
    empty gemfile
    10k gemfile

    View full-size slide

  107. What do we know?

    View full-size slide

  108. bin stub source code
    #!/Users/aaron/.rbenv/versions/ruby-trunk/bin/ruby
    #
    # This file was generated by RubyGems.
    #
    # The application 'bundler' is installed as part of a gem, and
    # this file is here to facilitate running it.
    #
    # some unimportant stuff happens here!
    gem 'bundler', version
    load Gem.bin_path('bundler', 'bundle', version)
    gem
    name

    View full-size slide

  109. Gemfile.lock
    GEM
    specs:
    pkg0 (1)
    PLATFORMS
    ruby
    DEPENDENCIES
    pkg0
    gem name and version!

    View full-size slide

  110. Spec loading code today
    def get_spec name
    spec_cache = Dir[File.join(dir, "*.gemspec")]
    spec_cache.find { |spec| spec.name == name }
    end

    View full-size slide

  111. bundle -v against 100k gems
    [aaron@TC rubygems (master)]$ time GEM_HOME=`pwd`/100k_gems
    GEM_PATH=`pwd`/100k_gems ruby -I lib 100k_gems/bin/bundle -v
    Bundler version 1.9.4
    real 0m50.045s
    user 0m15.815s
    sys 0m11.967s

    View full-size slide

  112. Spec loading code I want
    def get_spec name
    spec_cache = Dir[File.join(dir, "#{name}-*.gemspec")]
    spec_cache.find { |spec| spec.name == name }
    end

    View full-size slide

  113. bundle -v against 100k gems
    [aaron@TC rubygems (specs)]$ time GEM_HOME=`pwd`/100k_gems
    GEM_PATH=`pwd`/100k_gems ruby -I lib 100k_gems/bin/bundle -v
    Bundler version 1.9.4
    real 0m0.632s
    user 0m0.479s
    sys 0m0.124s

    View full-size slide

  114. I think we can make it O(1)

    View full-size slide

  115. Future Work:
    Make `require` O(1)

    View full-size slide

  116. Don’t recalculate
    static data

    View full-size slide

  117. Take measurements

    View full-size slide

  118. Question intuitions

    View full-size slide

  119. I have stickers!

    View full-size slide

  120. THANK YOU!!!

    View full-size slide