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

The Life-Changing Magic of Tidying Up ActiveRecord Allocations

The Life-Changing Magic of Tidying Up ActiveRecord Allocations

Your app is slow. It does not spark joy. In this talk, we will use memory allocation profiling tools to discover performance hotspots, even when they're coming from inside a library. We will use this technique with a real-world application to identify a piece of optimizable code in Active Record that ultimately leads to a patch with a substantial impact on page speed.

Presented by https://speakerdeck.com/schneems, built by me with a brief section on Whence.

Caleb Hearth

May 01, 2019
Tweet

More Decks by Caleb Hearth

Other Decks in Programming

Transcript

  1. the life-changing
    magic of tidying up
    activerecord allocations
    @schneems

    View full-size slide

  2. @calebthompson

    View full-size slide

  3. !"#$#%#&
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  4. !"#$#%#&
    !"#$#%#&
    !"#$#%#&
    !"#$#%#&
    !"#$#%#&
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  5. require 'benchmark/ips'
    def compare_max(a, b)
    return a if a > b
    b
    end
    def allocate_max(a, b)
    array = [a, b]
    array.max
    end
    Benchmark.ips do |x|
    x.report("allocate_max") {
    allocate_max(1, 2)
    }
    x.report("compare_max ") {
    compare_max(1, 2)
    }
    x.compare!
    end

    View full-size slide

  6. b
    end
    def allocate_max(a, b)
    array = [a, b]
    array.max
    end

    View full-size slide

  7. require 'benchmark/ips'
    def compare_max(a, b)
    return a if a > b
    b
    end

    View full-size slide

  8. require 'benchmark/ips'
    def compare_max(a, b)
    return a if a > b
    b
    end
    def allocate_max(a, b)
    array = [a, b]
    array.max
    end
    Benchmark.ips do |x|
    x.report("allocate_max") {
    allocate_max(1, 2)
    }
    x.report("compare_max ") {
    compare_max(1, 2)
    }
    x.compare!
    end

    View full-size slide

  9. Warming up --------------------------------------
    allocate_max 270.687k i/100ms
    compare_max 344.540k i/100ms
    Calculating -------------------------------------
    allocate_max 7.006M (±11.7%) i/s - 34.648M in 5.059666s
    compare_max 14.862M (± 7.2%) i/s - 74.076M in 5.014624s
    Comparison:
    compare_max : 14861805.8 i/s
    allocate_max: 7005910.5 i/s - 2.12x slower

    View full-size slide

  10. malloc
    is slow

    View full-size slide

  11. first, last = Thing.call(input)

    View full-size slide

  12. Bytes allocated is more
    important than object
    count in Ruby

    View full-size slide

  13. Bytes allocated is more
    important than object
    count in Ruby
    (IMHO)

    View full-size slide

  14. Fewer bytes allocated
    Performance improvement

    View full-size slide

  15. Bytes reduced
    is a consistent metric

    View full-size slide

  16. $gem install memory_profiler

    View full-size slide

  17. $gem install derailed_benchmarks

    View full-size slide

  18. $derailed exec perf:objects

    View full-size slide

  19. allocated memory by gem
    -----------------------------------
    227058 activesupport/lib
    134366 codetriage/app
    95343 activerecord/lib
    66406 actionview/lib
    63145 activemodel/lib
    56437 actionpack/lib
    34987 rack-mini-profiler-1.0.0
    12120 will_paginate-3.1.0
    10659 rack-2.0.5
    9360 logger
    8000 warden-1.2.7
    4608 hashie-3.5.7
    3321 devise-fc9aa974ece8
    2232 uri
    1680 sprockets-rails-3.2.1
    1231 railties/lib
    1006 raven-ruby-21669e97ee70
    903 securerandom
    872 base64
    864 i18n-0.9.5
    735 json
    664 omniauth-1.8.1
    528 temple-0.8.0
    464 concurrent-ruby-1.0.5
    432 delegate
    400 scout_apm-2.4.16
    352 set
    168 monitor
    40 openssl
    allocated memory by file

    View full-size slide

  20. 30 …/code/rails/activesupport/lib/active_support/core_ext/string/output_safety.rb:267
    29 …/code/codetriage/.gem/ruby/2.5.3/gems/hashie-3.5.7/lib/hashie/mash.rb:316
    29 …/code/rails/actionview/lib/action_view/template/resolver.rb:146
    27 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-2.0.5/lib/rack/utils.rb:469
    26 …/code/rails/actionview/lib/action_view/lookup_context.rb:205
    25 …/code/rails/actionview/lib/action_view/renderer/renderer.rb:49
    24 …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:526
    22 …/code/rails/actionview/lib/action_view/log_subscriber.rb:60
    21 …/code/codetriage/.gem/ruby/2.5.3/bundler/gems/devise-fc9aa974ece8/lib/devise/controllers/helpers.rb:
    126
    allocated objects by class
    -----------------------------------
    2507 String
    2223 Array
    628 Hash
    174 Time
    100 ActiveModel::Attribute::FromDatabase
    89 MatchData
    50 ActiveModel::AttributeSet
    50 ActiveModel::LazyAttributeHash
    50 Repo
    43 Proc
    42 ActiveSupport::SafeBuffer
    15 ActiveSupport::Notifications::Event
    12 ActiveRecord::Relation
    12 Rational
    11 ActionDispatch::Request
    10 ActiveSupport::JSON::Encoding::JSONGemEncoder::EscapedString
    10 Enumerator
    9 ActiveSupport::HashWithIndifferentAccess
    9 Class
    8 ActionView::PartialRenderer
    7 Arel::Attributes::Attribute
    6 OpenSSL::Cipher

    View full-size slide

  21. allocated memory by file
    -----------------------------------
    126489 …/code/rails/activesupport/lib/active_support/core_ext/string/output_safety.rb
    49448 …/code/codetriage/app/views/layouts/_app.html.slim
    49328 …/code/codetriage/app/views/layouts/application.html.slim
    36097 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb
    25096 …/code/codetriage/app/views/pages/_repos_with_pagination.html.slim
    24432 …/code/rails/activesupport/lib/active_support/core_ext/object/to_query.rb
    23526 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/patches/db/pg.rb
    21912 …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql_adapter.rb
    18000 …/code/rails/activemodel/lib/active_model/attribute_set/builder.rb
    15888 …/code/rails/activerecord/lib/active_record/result.rb
    14610 …/code/rails/activesupport/lib/active_support/cache.rb
    11109 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/storage/file_store.rb
    9824 …/code/rails/actionpack/lib/abstract_controller/caching/fragments.rb
    9360 …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/logger.rb
    8440 …/code/rails/activerecord/lib/active_record/attribute_methods.rb
    8304 …/code/rails/activemodel/lib/active_model/attribute.rb
    8160 …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb
    8000 …/code/rails/activerecord/lib/active_record/integration.rb
    7880 …/code/rails/actionview/lib/action_view/log_subscriber.rb
    7478 …/code/rails/actionview/lib/action_view/helpers/tag_helper.rb
    7096 …/code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb
    7024 …/code/codetriage/.gem/ruby/2.5.3/gems/warden-1.2.7/lib/warden/proxy.rb
    6912 …/code/rails/actionview/lib/action_view/lookup_context.rb
    6512 …/code/rails/actionpack/lib/action_dispatch/routing/route_set.rb
    5680 …/code/rails/activesupport/lib/active_support/callbacks.rb
    5600 …/code/rails/activerecord/lib/active_record/persistence.rb
    4971 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-2.0.5/lib/rack/utils.rb
    4896 …/code/rails/actionpack/lib/action_dispatch/journey/formatter.rb
    4760 …/code/rails/actionpack/lib/action_dispatch/http/response.rb
    4608 …/code/codetriage/.gem/ruby/2.5.3/gems/hashie-3.5.7/lib/hashie/mash.rb
    4558 …/code/rails/activesupport/lib/active_support/cache/memory_store.rb
    4415 …/code/rails/activesupport/lib/active_support/tagged_logging.rb

    View full-size slide

  22. $ALLOW_FILES=active_record/attribute_methods.rb
    bundle exec derailed exec perf:objects

    View full-size slide

  23. allocated memory by gem
    -----------------------------------
    8440 activerecord/lib
    allocated memory by file
    -----------------------------------
    8440 …/code/rails/activerecord/lib/active_record/attribute_methods.rb
    allocated memory by location
    -----------------------------------
    8000 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:270
    320 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:221
    80 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:189
    40 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:187
    allocated memory by class
    -----------------------------------
    8360 String
    80 Array
    allocated objects by gem
    -----------------------------------
    211 activerecord/lib
    allocated objects by file
    -----------------------------------
    211 …/code/rails/activerecord/lib/active_record/attribute_methods.rb
    allocated objects by location
    -----------------------------------

    View full-size slide

  24. allocated memory by gem
    -----------------------------------
    8440 activerecord/lib
    allocated memory by file
    -----------------------------------
    8440 …/code/rails/activerecord/lib/active_record/attribute_methods.rb
    allocated memory by location
    -----------------------------------
    8000 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:270
    320 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:221
    80 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:189
    40 …/code/rails/activerecord/lib/active_record/attribute_methods.rb:187
    allocated memory by class
    -----------------------------------
    8360 String
    80 Array
    allocated objects by gem
    -----------------------------------
    211 activerecord/lib
    allocated objects by file
    -----------------------------------
    211 …/code/rails/activerecord/lib/active_record/attribute_methods.rb
    allocated objects by location

    View full-size slide

  25. 261 def respond_to?(name, include_private = false)
    262 return false unless super
    263
    264 case name
    265 when :to_partial_path
    266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unselected columns.
    275 # We check defined?(@attributes) not to issue warnings if called on objects that
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end

    View full-size slide

  26. 263
    264 case name
    265 when :to_partial_path
    266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for
    274 # For queries selecting a subset of col
    275 # We check defined?(@attributes) not to
    276 # have been allocated but not yet initi
    277 if defined?(@attributes) && self.class.

    View full-size slide

  27. 261 def respond_to?(name, include_private = false)
    262 return false unless super
    263
    264 case name
    265 when :to_partial_path
    266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"

    View full-size slide

  28. 263
    264 case name
    265 when :to_partial_path
    266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for
    274 # For queries selecting a subset of col
    275 # We check defined?(@attributes) not to
    276 # have been allocated but not yet initi
    277 if defined?(@attributes) && self.class.

    View full-size slide

  29. 266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unsele
    275 # We check defined?(@attributes) not to issue warnings if called on
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end

    View full-size slide

  30. 271 end
    272
    273 # If the result is true then check for th
    274 # For queries selecting a subset of colum
    275 # We check defined?(@attributes) not to i
    276 # have been allocated but not yet initial
    277 if defined?(@attributes) && self.class.co
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end

    View full-size slide

  31. 266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unsele
    275 # We check defined?(@attributes) not to issue warnings if called on
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end
    !!'#(#)#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  32. 266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unsele
    275 # We check defined?(@attributes) not to issue warnings if called on
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end
    !"#(#)#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  33. 266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unsele
    275 # We check defined?(@attributes) not to issue warnings if called on
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end
    !"#+#)#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  34. 266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unsele
    275 # We check defined?(@attributes) not to issue warnings if called on
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end
    !"#+#,#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  35. 266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unsele
    275 # We check defined?(@attributes) not to issue warnings if called on
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary
    !"#+#,#*
    ?

    View full-size slide

  36. 261 def respond_to?(name, include_private = false)
    262 return false unless super
    263
    264 case name
    265 when :to_partial_path
    266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the select case.
    274 # For queries selecting a subset of columns, return false for unselected columns.
    275 # We check defined?(@attributes) not to issue warnings if called on objects that
    276 # have been allocated but not yet initialized.
    277 if defined?(@attributes) && self.class.column_names.include?(name)
    278 return has_attribute?(name)
    279 end
    270
    281 true
    282 end

    View full-size slide

  37. 263
    264 case name
    265 when :to_partial_path
    266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the s
    274 # For queries selecting a subset of columns,
    275 # We check defined?(@attributes) not to issu
    276 # have been allocated but not yet initialize
    277 if defined?(@attributes) && self.class.colum

    View full-size slide

  38. 263
    264 case name
    265 when :to_partial_path
    266 name = "to_partial_path"
    267 when :to_model
    268 name = "to_model"
    269 else
    270 name = name.to_s
    271 end
    272
    273 # If the result is true then check for the s
    274 # For queries selecting a subset of columns,
    275 # We check defined?(@attributes) not to issu
    276 # have been allocated but not yet initialize
    277 if defined?(@attributes) && self.class.colum

    View full-size slide

  39. def respond_to?(name, include_private = false)
    return false unless super
    case name
    when :to_partial_path
    name = "to_partial_path"
    when :to_model
    name = "to_model"
    else
    name = name.to_s
    end
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes) && self.class.column_names.include?(name)
    return has_attribute?(name)
    end
    true
    end

    View full-size slide

  40. def respond_to?(name, include_private = false)
    return false unless super
    case name
    when :to_partial_path
    name = "to_partial_path"
    when :to_model
    name = "to_model"
    else
    name = name.to_s
    end
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes) && self.class.column_names.include?(name)
    return has_attribute?(name)
    end
    true
    end
    &

    View full-size slide

  41. def respond_to?(name, include_private = false)
    return false unless super
    case name
    when :to_partial_path
    name = "to_partial_path"
    when :to_model
    name = "to_model"
    else
    name = name.to_s
    end
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes) && self.class.column_names.include?(name)
    return has_attribute?(name)
    end
    true
    end

    View full-size slide

  42. def respond_to?(name, include_private = false)
    return false unless super
    case name
    when :to_partial_path
    name = "to_partial_path"
    when :to_model
    name = "to_model"
    else
    name = name.to_s
    end
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes) && self.class.column_names.include?(name)
    return has_attribute?(name)
    end
    true
    end

    View full-size slide

  43. def respond_to?(name, include_private = false)
    return false unless super
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes) && self.class.column_names.include?(name)
    return has_attribute?(name)
    end
    true
    end

    View full-size slide

  44. def respond_to?(name, include_private = false)
    return false unless super
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes) && self.class.column_names.include?(name)
    return has_attribute?(name)
    end
    true
    end

    View full-size slide

  45. module ActiveRecord
    module ModelSchema

    def symbol_column_to_string(name_symbol) # :nodoc:
    @symbol_column_to_string_name_hash ||= column_names.index_by(&:to_sym)
    @symbol_column_to_string_name_hash[name_symbol]
    end

    View full-size slide

  46. def respond_to?(name, include_private = false)
    return false unless super
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes) && self.class.column_names.include?(name)
    return has_attribute?(name)
    end
    true
    end

    View full-size slide

  47. def respond_to?(name, include_private = false)
    return false unless super
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes)
    if name = self.class.symbol_column_to_string(name.to_sym)
    return has_attribute?(name)
    end
    end
    true
    end

    View full-size slide

  48. def respond_to?(name, include_private = false)
    return false unless super
    # If the result is true then check for the select case.
    # For queries selecting a subset of columns, return false for unselected columns.
    # We check defined?(@attributes) not to issue warnings if called on objects that
    # have been allocated but not yet initialized.
    if defined?(@attributes)
    if name = self.class.symbol_column_to_string(name.to_sym)
    return has_attribute?(name)
    end
    end
    true
    end

    View full-size slide

  49. ARRAY = [1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]
    STRANG = "mystrang"
    require 'memory_profiler'
    report = MemoryProfiler.report do
    ARRAY.dup
    STRANG.dup
    end
    report.pretty_print
    # allocated memory by location
    # -----------------------------------
    # 40 big_o/string_verus_array.rb:10
    # 40 big_o/string_verus_array.rb:9

    View full-size slide

  50. ARRAY = [1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]
    STRANG = "mystrang"
    require 'memory_profiler'
    report = MemoryProfiler.report do
    ARRAY.dup
    STRANG.dup
    end
    report.pretty_print
    # allocated memory by location
    # -----------------------------------
    # 40 big_o/string_verus_array.rb:10
    # 40 big_o/string_verus_array.rb:9

    View full-size slide

  51. ARRAY = [1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]
    STRANG = "mystrang"
    require 'memory_profiler'
    report = MemoryProfiler.report do
    ARRAY.dup
    STRANG.dup
    end
    report.pretty_print
    # allocated memory by location
    # -----------------------------------
    # 40 big_o/string_verus_array.rb:10
    # 40 big_o/string_verus_array.rb:9

    View full-size slide

  52. ARRAY = [1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]
    STRANG = "mystrang"
    require 'benchmark/ips'
    Benchmark.ips do |x|
    x.report("Array") { ARRAY.dup }
    x.report("String") { STRANG.dup }
    x.compare!
    end

    View full-size slide

  53. Warming up --------------------------------------
    Array 237.011k i/100ms
    String 227.975k i/100ms
    Calculating -------------------------------------
    Array 4.725M (± 2.4%) i/s - 23.701M in 5.019109s
    String 4.354M (± 3.4%) i/s - 21.886M in 5.032768s
    Comparison:
    Array: 4725013.7 i/s
    String: 4353765.4 i/s - 1.09x slower

    View full-size slide

  54. Warming up --------------------------------------
    Array 236.636k i/100ms
    String 227.325k i/100ms
    Calculating -------------------------------------
    Array 4.665M (± 2.8%) i/s - 23.427M in 5.026530s
    String 4.271M (± 3.5%) i/s - 21.369M in 5.009076s
    Comparison:
    String: 4664566.9 i/s
    Array: 4271439.1 i/s - 1.09x slower

    View full-size slide

  55. Warming up --------------------------------------
    Array 237.026k i/100ms
    String 227.955k i/100ms
    Calculating -------------------------------------
    Array 4.674M (± 4.8%) i/s - 23.466M in 5.032533s
    String 4.271M (± 4.5%) i/s - 21.428M in 5.027323s
    Comparison:
    Array: 4674310.3 i/s
    String: 4271319.4 i/s - same-ish: difference falls within error

    View full-size slide

  56. Warming up --------------------------------------
    Array 236.636k i/100ms
    String 227.325k i/100ms
    Calculating -------------------------------------
    Array 4.665M (± 2.8%) i/s - 23.427M in 5.026530s
    String 4.271M (± 3.5%) i/s - 21.369M in 5.009076s
    Comparison:
    String: 4664566.9 i/s
    Array: 4271439.1 i/s - 1.09x slower

    View full-size slide

  57. allocated memory by file
    -----------------------------------
    126489 …/code/rails/activesupport/lib/active_support/core_ext/string/output_safety.rb
    49448 …/code/codetriage/app/views/layouts/_app.html.slim
    49328 …/code/codetriage/app/views/layouts/application.html.slim
    36097 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb
    25096 …/code/codetriage/app/views/pages/_repos_with_pagination.html.slim
    24432 …/code/rails/activesupport/lib/active_support/core_ext/object/to_query.rb
    23526 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/patches/db/pg.rb
    21912 …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql_adapter.rb
    18000 …/code/rails/activemodel/lib/active_model/attribute_set/builder.rb
    15888 …/code/rails/activerecord/lib/active_record/result.rb
    14610 …/code/rails/activesupport/lib/active_support/cache.rb
    11148 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/storage/file_store.rb
    9824 …/code/rails/actionpack/lib/abstract_controller/caching/fragments.rb
    9360 …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/logger.rb
    8304 …/code/rails/activemodel/lib/active_model/attribute.rb
    8160 …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb
    8000 …/code/rails/activerecord/lib/active_record/integration.rb
    7880 …/code/rails/actionview/lib/action_view/log_subscriber.rb
    7478 …/code/rails/actionview/lib/action_view/helpers/tag_helper.rb
    7096 …/code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb
    7024 …/code/codetriage/.gem/ruby/2.5.3/gems/warden-1.2.7/lib/warden/proxy.rb
    6912 …/code/rails/actionview/lib/action_view/lookup_context.rb
    6512 …/code/rails/actionpack/lib/action_dispatch/routing/route_set.rb
    5680 …/code/rails/activesupport/lib/active_support/callbacks.rb
    5600 …/code/rails/activerecord/lib/active_record/persistence.rb
    4963 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-2.0.5/lib/rack/utils.rb
    4896 …/code/rails/actionpack/lib/action_dispatch/journey/formatter.rb
    4760 …/code/rails/actionpack/lib/action_dispatch/http/response.rb
    4608 …/code/codetriage/.gem/ruby/2.5.3/gems/hashie-3.5.7/lib/hashie/mash.rb
    4558 …/code/rails/activesupport/lib/active_support/cache/memory_store.rb
    4415 …/code/rails/activesupport/lib/active_support/tagged_logging.rb

    View full-size slide

  58. $bundle exec derailed exec perf:objects

    View full-size slide

  59. allocated memory by file
    -----------------------------------
    126489 …/code/rails/activesupport/lib/active_support/core_ext/string/output_safety.rb
    49448 …/code/codetriage/app/views/layouts/_app.html.slim
    49328 …/code/codetriage/app/views/layouts/application.html.slim
    36097 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb
    25096 …/code/codetriage/app/views/pages/_repos_with_pagination.html.slim
    24432 …/code/rails/activesupport/lib/active_support/core_ext/object/to_query.rb
    23526 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/patches/db/pg.rb
    21912 …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql_adapter.rb
    18000 …/code/rails/activemodel/lib/active_model/attribute_set/builder.rb
    15888 …/code/rails/activerecord/lib/active_record/result.rb
    14610 …/code/rails/activesupport/lib/active_support/cache.rb
    11148 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/storage/file_store.rb
    9824 …/code/rails/actionpack/lib/abstract_controller/caching/fragments.rb
    9360 …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/logger.rb
    8304 …/code/rails/activemodel/lib/active_model/attribute.rb
    8160 …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb
    8000 …/code/rails/activerecord/lib/active_record/integration.rb
    7880 …/code/rails/actionview/lib/action_view/log_subscriber.rb
    7478 …/code/rails/actionview/lib/action_view/helpers/tag_helper.rb
    7096 …/code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb
    7024 …/code/codetriage/.gem/ruby/2.5.3/gems/warden-1.2.7/lib/warden/proxy.rb
    6912 …/code/rails/actionview/lib/action_view/lookup_context.rb
    6512 …/code/rails/actionpack/lib/action_dispatch/routing/route_set.rb
    5680 …/code/rails/activesupport/lib/active_support/callbacks.rb
    5600 …/code/rails/activerecord/lib/active_record/persistence.rb
    4963 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-2.0.5/lib/rack/utils.rb
    4896 …/code/rails/actionpack/lib/action_dispatch/journey/formatter.rb
    4760 …/code/rails/actionpack/lib/action_dispatch/http/response.rb
    4608 …/code/codetriage/.gem/ruby/2.5.3/gems/hashie-3.5.7/lib/hashie/mash.rb
    4558 …/code/rails/activesupport/lib/active_support/cache/memory_store.rb
    4415 …/code/rails/activesupport/lib/active_support/tagged_logging.rb

    View full-size slide

  60. allocated memory by file
    -----------------------------------
    126489 …/code/rails/activesupport/lib/active_support/core_ext/string/output_safety.rb
    49448 …/code/codetriage/app/views/layouts/_app.html.slim
    49328 …/code/codetriage/app/views/layouts/application.html.slim
    36097 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb
    25096 …/code/codetriage/app/views/pages/_repos_with_pagination.html.slim
    24432 …/code/rails/activesupport/lib/active_support/core_ext/object/to_query.rb
    23526 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/patches/db/pg.rb
    21912 …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql_adapter.rb
    18000 …/code/rails/activemodel/lib/active_model/attribute_set/builder.rb
    15888 …/code/rails/activerecord/lib/active_record/result.rb
    14610 …/code/rails/activesupport/lib/active_support/cache.rb
    11148 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-mini-profiler-1.0.0/lib/mini_profiler/storage/file_store.rb
    9824 …/code/rails/actionpack/lib/abstract_controller/caching/fragments.rb
    9360 …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/logger.rb
    8304 …/code/rails/activemodel/lib/active_model/attribute.rb
    8160 …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb
    8000 …/code/rails/activerecord/lib/active_record/integration.rb
    7880 …/code/rails/actionview/lib/action_view/log_subscriber.rb
    7478 …/code/rails/actionview/lib/action_view/helpers/tag_helper.rb
    7096 …/code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb
    7024 …/code/codetriage/.gem/ruby/2.5.3/gems/warden-1.2.7/lib/warden/proxy.rb
    6912 …/code/rails/actionview/lib/action_view/lookup_context.rb
    6512 …/code/rails/actionpack/lib/action_dispatch/routing/route_set.rb
    5680 …/code/rails/activesupport/lib/active_support/callbacks.rb
    5600 …/code/rails/activerecord/lib/active_record/persistence.rb
    4963 …/code/codetriage/.gem/ruby/2.5.3/gems/rack-2.0.5/lib/rack/utils.rb
    4896 …/code/rails/actionpack/lib/action_dispatch/journey/formatter.rb
    4760 …/code/rails/actionpack/lib/action_dispatch/http/response.rb
    4608 …/code/codetriage/.gem/ruby/2.5.3/gems/hashie-3.5.7/lib/hashie/mash.rb
    4558 …/code/rails/activesupport/lib/active_support/cache/memory_store.rb

    View full-size slide

  61. $ALLOW_FILES=active_model/type/helpers/time_value.rb
    bundle exec derailed exec perf:objects

    View full-size slide

  62. Total allocated: 39617 bytes (600 objects)
    Total retained: 0 bytes (0 objects)
    allocated memory by gem
    -----------------------------------
    39617 activemodel/lib
    allocated memory by file
    -----------------------------------
    39617 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb
    allocated memory by location
    -----------------------------------
    17317 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:72
    12000 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:74
    6000 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:73
    4300 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:64

    View full-size slide

  63. Total allocated: 39617 bytes (600 objects)
    Total retained: 0 bytes (0 objects)
    allocated memory by gem
    -----------------------------------
    39617 activemodel/lib
    allocated memory by file
    -----------------------------------
    39617 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb
    allocated memory by location
    -----------------------------------
    17317 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:72
    12000 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:74
    6000 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:73
    4300 …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:64

    View full-size slide

  64. 71 def fast_string_to_time(string)
    72 if string =~ ISO_DATETIME
    73 microsec = ($7.to_r * 1_000_000).to_i
    74 new_time $1.to_i, $2.to_i, $3.to_i, $4.to_i, $5.to_i, $6.to_i, microsec
    75 end
    76 end

    View full-size slide

  65. 71 def fast_string_to_time(string)
    72 if string =~ ISO_DATETIME
    73 microsec = ($7.to_r * 1_000_000).to_i
    74 new_time $1.to_i, $2.to_i, $3.to_i, $4.to_i, $5.to_i, $6.to_i, microsec
    75 end
    76 end

    View full-size slide

  66. 71 def fast_string_to_time(string)
    72 if string =~ ISO_DATETIME
    73 microsec = ($7.to_r * 1_000_000).to_i
    74 new_time $1.to_i, $2.to_i, $3.to_i, $4.to_i, $5.to_i, $6.to_i, microsec
    75 end
    76 end

    View full-size slide

  67. 71 def fast_string_to_time(string)
    72 if string =~ ISO_DATETIME
    73 microsec = ($7.to_r * 1_000_000).to_i
    74 new_time $1.to_i, $2.to_i, $3.to_i, $4.to_i, $5.to_i, $6.to_
    75 end
    76 end

    View full-size slide

  68. i.e. ".1234567"
    #=> 1234567

    View full-size slide

  69. def fast_string_to_time(string)
    if string =~ ISO_DATETIME
    microsec_part = $7
    if microsec_part && microsec_part.start_with?(".") && microsec_part.length == 7
    microsec_part[0] = ""
    microsec = microsec_part.to_i
    else
    microsec = (microsec_part.to_r * 1_000_000).to_i
    end
    new_time $1.to_i, $2.to_i, $3.to_i, $4.to_i, $5.to_i, $6.to_i, microsec
    end

    View full-size slide

  70. def fast_string_to_time(string)
    if string =~ ISO_DATETIME
    microsec_part = $7
    if microsec_part && microsec_part.start_with?(".") && microsec_part.length == 7
    microsec_part[0] = ""
    microsec = microsec_part.to_i
    else
    microsec = (microsec_part.to_r * 1_000_000).to_i
    end
    new_time $1.to_i, $2.to_i, $3.to_i, $4.to_i, $5.to_i, $6.to_i, microsec
    end

    View full-size slide

  71. Is it faster?

    View full-size slide

  72. original_string = ".443959"
    require 'benchmark/ips'
    Benchmark.ips do |x|
    x.report("multiply") {
    string = original_string.dup
    (string.to_r * 1_000_000).to_i
    }
    x.report("new ") {
    string = original_string.dup
    if string && string.start_with?(".".freeze) && string.length == 7
    string[0] = ''.freeze
    string.to_i
    end
    }
    x.compare!
    end
    # Warming up --------------------------------------
    # multiply 125.783k i/100ms

    View full-size slide

  73. string[0] = ''.freeze
    string.to_i
    end
    }
    x.compare!
    end
    # Warming up --------------------------------------
    # multiply 125.783k i/100ms
    # new 146.543k i/100ms
    # Calculating -------------------------------------
    # multiply 1.751M (± 3.3%) i/s - 8.805M in 5.033779s
    # new 2.225M (± 2.1%) i/s - 11.137M in 5.007110s
    # Comparison:
    # new : 2225289.7 i/s
    # multiply: 1751254.2 i/s - 1.27x slower

    View full-size slide

  74. def fast_string_to_time(string)
    if string =~ ISO_DATETIME
    microsec_part = $7
    if microsec_part && microsec_part.start_with?(".") && microsec_part.length == 7
    microsec_part[0] = ""
    microsec = microsec_part.to_i
    else
    microsec = (microsec_part.to_r * 1_000_000).to_i
    end
    new_time $1.to_i, $2.to_i, $3.to_i, $4.to_i, $5.to_i, $6.to_i, microsec
    end

    View full-size slide

  75. ====================================================================================================
    …/code/rails/activemodel/lib/active_model/type/date_time.rb:25:in `cast_value'
    …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql/oid/date_time.rb:16:in `cast_value'
    …/code/rails/activemodel/lib/active_model/type/value.rb:38:in `cast'
    …/code/rails/activemodel/lib/active_model/type/helpers/accepts_multiparameter_time.rb:12:in `block in initialize'
    …/code/rails/activemodel/lib/active_model/type/value.rb:24:in `deserialize'
    …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/delegate.rb:349:in `block in delegating_block'
    …/code/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb:8:in `deserialize'
    …/code/rails/activemodel/lib/active_model/attribute.rb:164:in `type_cast'
    …/code/rails/activemodel/lib/active_model/attribute.rb:42:in `value'
    …/code/rails/activemodel/lib/active_model/attribute_set.rb:48:in `fetch_value'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:77:in `_read_attribute'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:40:in `__temp__57074616475646f51647'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `public_send'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `try'
    …/code/rails/activerecord/lib/active_record/integration.rb:99:in `cache_version'
    …/code/rails/activerecord/lib/active_record/integration.rb:68:in `cache_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:639:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `block in expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `collect'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:608:in `normalize_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:565:in `block in read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `each'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:387:in `block in read_multi'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `block in instrument'
    …/code/rails/activesupport/lib/active_support/notifications.rb:170:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:386:in `read_multi’
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb:18:in `cache_collection_render'
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:326:in `block in render_collection'
    …//code/rails/actionview/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
    …//code/rails/activesupport/lib/active_support/notifications.rb:168:in `block in instrument'

    View full-size slide

  76. …/code/rails/activemodel/lib/active_model/type/helpers/accepts_multiparameter_time.rb:1
    …/code/rails/activemodel/lib/active_model/type/value.rb:24:in `deserialize'
    …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/delegate.rb:349:in `block in delegating_block'
    …/code/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb:8
    …/code/rails/activemodel/lib/active_model/attribute.rb:164:in `type_cast'
    …/code/rails/activemodel/lib/active_model/attribute.rb:42:in `value'
    …/code/rails/activemodel/lib/active_model/attribute_set.rb:48:in `fetch_value'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:77:in `_read_attr
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:40:in `__temp__57
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `public_send
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `try'
    …/code/rails/activerecord/lib/active_record/integration.rb:99:in `cache_version'
    …/code/rails/activerecord/lib/active_record/integration.rb:68:in `cache_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:639:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `block in expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `collect'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:608:in `normalize_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:565:in `block in read_multi_entr
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `each'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:387:in `block in read_multi'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `block in instrument'
    …/code/rails/activesupport/lib/active_support/notifications.rb:170:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:386:in `read_multi’

    View full-size slide

  77. # Product.cache_versioning = false
    # Person.find(5).cache_key # => "people/5-20071224150000" (updated_at available)
    def cache_key(*timestamp_names)
    if new_record?
    "#{model_name.cache_key}/new"
    else
    if cache_version && timestamp_names.none?
    "#{model_name.cache_key}/#{id}"
    else
    timestamp = if timestamp_names.any?
    ActiveSupport::Deprecation.warn(<<-MSG.squish)
    Specifying a timestamp name for #cache_key has been deprecated in favor of
    the explicit #cache_version method that can be overwritten.
    MSG
    max_updated_column_timestamp(timestamp_names)
    else
    max_updated_column_timestamp
    end
    if timestamp
    timestamp = timestamp.utc.to_s(cache_timestamp_format)
    "#{model_name.cache_key}/#{id}-#{timestamp}"
    else
    "#{model_name.cache_key}/#{id}"
    end
    end
    end
    end
    # Returns a cache version that can be used together with the cache key to form

    View full-size slide

  78. # the cache key will also include a version.
    #
    # Product.cache_versioning = false
    # Person.find(5).cache_key # => "people/5-20071224150000" (updated_at ava
    def cache_key(*timestamp_names)
    if new_record?
    "#{model_name.cache_key}/new"
    else
    if cache_version && timestamp_names.none?
    "#{model_name.cache_key}/#{id}"
    else
    timestamp = if timestamp_names.any?
    ActiveSupport::Deprecation.warn(<<-MSG.squish)
    Specifying a timestamp name for #cache_key has been deprecated in
    the explicit #cache_version method that can be overwritten.
    MSG
    max_updated_column_timestamp(timestamp_names)
    else
    max_updated_column_timestamp
    end
    if timestamp

    View full-size slide

  79. max_updated_column_timestamp
    end
    if timestamp
    timestamp = timestamp.utc.to_s(cache_timestamp_format)
    "#{model_name.cache_key}/#{id}-#{timestamp}"
    else
    "#{model_name.cache_key}/#{id}"
    end
    end
    end
    end
    # Returns a cache version that can be used together with the cache key to form
    # a recyclable caching scheme. By default, the #updated_at column is used for the
    # cache_version, but this method can be overwritten to return something else.
    #
    # Note, this method will return nil if ActiveRecord::Base.cache_versioning is set to
    # +false+ (which it is by default until Rails 6.0).
    def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end

    View full-size slide

  80. max_updated_column_timestamp
    end
    if timestamp
    timestamp = timestamp.utc.to_s(cache_timestamp_format)
    "#{model_name.cache_key}/#{id}-#{timestamp}"
    else
    "#{model_name.cache_key}/#{id}"
    end
    end
    end
    end
    # Returns a cache version that can be used together with the cache key to form
    # a recyclable caching scheme. By default, the #updated_at column is used for the
    # cache_version, but this method can be overwritten to return something else.
    #
    # Note, this method will return nil if ActiveRecord::Base.cache_versioning is set to
    # +false+ (which it is by default until Rails 6.0).
    def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end

    View full-size slide

  81. end
    end
    end
    end
    # Returns a cache version that can be used together with the cache key to form
    # a recyclable caching scheme. By default, the #updated_at column is used for the
    # cache_version, but this method can be overwritten to return something else.
    #
    # Note, this method will return nil if ActiveRecord::Base.cache_versioning is set to
    # +false+ (which it is by default until Rails 6.0).
    def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end

    View full-size slide

  82. > User.first.updated_at_before_type_cast
    => "2019-04-24 21:21:09.232249"
    > User.first.updated_at.to_s(:usec)
    => "20190424212109232249"

    View full-size slide

  83. > User.first.updated_at_before_type_cast
    => "2019-04-24 21:21:09.232249"
    > User.first.updated_at.to_s(:usec)
    => "20190424212109232249"

    View full-size slide

  84. > User.first.updated_at_before_type_cast
    => "2019-04-24 21:21:09.232249"
    > User.first.updated_at.to_s(:usec)
    => "20190424212109232249"

    View full-size slide

  85. > User.first.updated_at_before_type_cast
    => "20190424212109232249"
    > User.first.updated_at.to_s(:usec)
    => "20190424212109232249"

    View full-size slide

  86. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end

    View full-size slide

  87. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    !✁
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  88. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    !"#(#)#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  89. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    !"#+#)#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  90. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    !"#+#%#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  91. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    !"#+#%#*
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  92. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    !"#+#%#.
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  93. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end

    View full-size slide

  94. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end

    View full-size slide

  95. def cache_version
    return unless cache_versioning
    return unless has_attribute?("updated_at")
    timestamp = updated_at_before_type_cast
    if can_use_fast_cache_version?(timestamp)
    raw_timestamp_to_cache_version(timestamp)
    elsif timestamp = updated_at
    timestamp.utc.to_s(cache_timestamp_format)
    end
    end

    View full-size slide

  96. def cache_version
    return unless cache_versioning
    return unless has_attribute?("updated_at")
    timestamp = updated_at_before_type_cast
    if can_use_fast_cache_version?(timestamp)
    raw_timestamp_to_cache_version(timestamp)
    elsif timestamp = updated_at
    timestamp.utc.to_s(cache_timestamp_format)
    end
    end

    View full-size slide

  97. def cache_version
    return unless cache_versioning
    return unless has_attribute?("updated_at")
    timestamp = updated_at_before_type_cast
    if can_use_fast_cache_version?(timestamp)
    raw_timestamp_to_cache_version(timestamp)
    elsif timestamp = updated_at
    timestamp.utc.to_s(cache_timestamp_format)
    end
    end

    View full-size slide

  98. def cache_version
    return unless cache_versioning
    return unless has_attribute?("updated_at")
    timestamp = updated_at_before_type_cast
    if can_use_fast_cache_version?(timestamp)
    raw_timestamp_to_cache_version(timestamp)
    elsif timestamp = updated_at
    timestamp.utc.to_s(cache_timestamp_format)
    end
    end

    View full-size slide

  99. def cache_version
    return unless cache_versioning
    return unless has_attribute?("updated_at")
    timestamp = updated_at_before_type_cast
    if can_use_fast_cache_version?(timestamp)
    raw_timestamp_to_cache_version(timestamp)
    elsif timestamp = updated_at
    timestamp.utc.to_s(cache_timestamp_format)
    end
    end

    View full-size slide

  100. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    !"#+#%#.
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  101. Before: Total allocated: 743842 bytes (6626 objects)
    After: Total allocated: 702955 bytes (6063 objects)
    743842 / 702955 => 1.058x or 5% fewer allocations

    View full-size slide

  102. Before: Total allocated: 743842 bytes (6626 objects)
    After: Total allocated: 702955 bytes (6063 objects)
    743842 / 702955 => 1.058x or 5% fewer allocations
    ⚡⚡⚡⚡⚡

    View full-size slide

  103. def cache_version
    return unless cache_versioning
    return unless has_attribute?("updated_at")
    timestamp = updated_at_before_type_cast
    if can_use_fast_cache_version?(timestamp)
    raw_timestamp_to_cache_version(timestamp)
    elsif timestamp = updated_at
    timestamp.utc.to_s(cache_timestamp_format)
    end
    end
    !"#$#,#.
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  104. def cache_version
    if cache_versioning && timestamp = try(:updated_at)
    timestamp.utc.to_s(:usec)
    end
    end
    &

    View full-size slide

  105. ====================================================================================================
    …/code/rails/activemodel/lib/active_model/type/date_time.rb:25:in `cast_value'
    …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql/oid/date_time.rb:16:in `cast_value'
    …/code/rails/activemodel/lib/active_model/type/value.rb:38:in `cast'
    …/code/rails/activemodel/lib/active_model/type/helpers/accepts_multiparameter_time.rb:12:in `block in initialize'
    …/code/rails/activemodel/lib/active_model/type/value.rb:24:in `deserialize'
    …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/delegate.rb:349:in `block in delegating_block'
    …/code/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb:8:in `deserialize'
    …/code/rails/activemodel/lib/active_model/attribute.rb:164:in `type_cast'
    …/code/rails/activemodel/lib/active_model/attribute.rb:42:in `value'
    …/code/rails/activemodel/lib/active_model/attribute_set.rb:48:in `fetch_value'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:77:in `_read_attribute'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:40:in `__temp__57074616475646f51647'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `public_send'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `try'
    …/code/rails/activerecord/lib/active_record/integration.rb:99:in `cache_version'
    …/code/rails/activerecord/lib/active_record/integration.rb:68:in `cache_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:639:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `block in expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `collect'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:608:in `normalize_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:565:in `block in read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `each'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:387:in `block in read_multi'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `block in instrument'
    …/code/rails/activesupport/lib/active_support/notifications.rb:170:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:386:in `read_multi’
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb:18:in `cache_collection_render'
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:326:in `block in render_collection'
    …//code/rails/actionview/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
    …//code/rails/activesupport/lib/active_support/notifications.rb:168:in `block in instrument'

    View full-size slide

  106. ====================================================================================================
    …/code/rails/activemodel/lib/active_model/type/date_time.rb:25:in `cast_value'
    …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql/oid/date_time.rb:16:in `cast_value'
    …/code/rails/activemodel/lib/active_model/type/value.rb:38:in `cast'
    …/code/rails/activemodel/lib/active_model/type/helpers/accepts_multiparameter_time.rb:12:in `block in initialize'
    …/code/rails/activemodel/lib/active_model/type/value.rb:24:in `deserialize'
    …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/delegate.rb:349:in `block in delegating_block'
    …/code/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb:8:in `deserialize'
    …/code/rails/activemodel/lib/active_model/attribute.rb:164:in `type_cast'
    …/code/rails/activemodel/lib/active_model/attribute.rb:42:in `value'
    …/code/rails/activemodel/lib/active_model/attribute_set.rb:48:in `fetch_value'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:77:in `_read_attribute'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:40:in `__temp__57074616475646f51647'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `public_send'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `try'
    …/code/rails/activerecord/lib/active_record/integration.rb:99:in `cache_version'
    …/code/rails/activerecord/lib/active_record/integration.rb:68:in `cache_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:639:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `block in expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `collect'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:608:in `normalize_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:565:in `block in read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `each'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:387:in `block in read_multi'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `block in instrument'
    …/code/rails/activesupport/lib/active_support/notifications.rb:170:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:386:in `read_multi’
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb:18:in `cache_collection_render'
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:326:in `block in render_collection'
    …//code/rails/actionview/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
    …//code/rails/activesupport/lib/active_support/notifications.rb:168:in `block in instrument'

    View full-size slide

  107. ====================================================================================================
    …/code/rails/activemodel/lib/active_model/type/date_time.rb:25:in `cast_value'
    …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql/oid/date_time.rb:16:in `cast_value'
    …/code/rails/activemodel/lib/active_model/type/value.rb:38:in `cast'
    …/code/rails/activemodel/lib/active_model/type/helpers/accepts_multiparameter_time.rb:12:in `block in initialize'
    …/code/rails/activemodel/lib/active_model/type/value.rb:24:in `deserialize'
    …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/delegate.rb:349:in `block in delegating_block'
    …/code/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb:8:in `deserialize'
    …/code/rails/activemodel/lib/active_model/attribute.rb:164:in `type_cast'
    …/code/rails/activemodel/lib/active_model/attribute.rb:42:in `value'
    …/code/rails/activemodel/lib/active_model/attribute_set.rb:48:in `fetch_value'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:77:in `_read_attribute'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:40:in `__temp__57074616475646f51647'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `public_send'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `try'
    …/code/rails/activerecord/lib/active_record/integration.rb:99:in `cache_version'
    …/code/rails/activerecord/lib/active_record/integration.rb:68:in `cache_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:639:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `block in expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `collect'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:608:in `normalize_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:565:in `block in read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `each'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:387:in `block in read_multi'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `block in instrument'
    …/code/rails/activesupport/lib/active_support/notifications.rb:170:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:386:in `read_multi’
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb:18:in `cache_collection_render'
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:326:in `block in render_collection'
    …//code/rails/actionview/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
    …//code/rails/activesupport/lib/active_support/notifications.rb:168:in `block in instrument'

    View full-size slide

  108. ====================================================================================================
    …/code/rails/activemodel/lib/active_model/type/date_time.rb:25:in `cast_value'
    …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql/oid/date_time.rb:16:in `cast_value'
    …/code/rails/activemodel/lib/active_model/type/value.rb:38:in `cast'
    …/code/rails/activemodel/lib/active_model/type/helpers/accepts_multiparameter_time.rb:12:in `block in initialize'
    …/code/rails/activemodel/lib/active_model/type/value.rb:24:in `deserialize'
    …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/delegate.rb:349:in `block in delegating_block'
    …/code/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb:8:in `deserialize'
    …/code/rails/activemodel/lib/active_model/attribute.rb:164:in `type_cast'
    …/code/rails/activemodel/lib/active_model/attribute.rb:42:in `value'
    …/code/rails/activemodel/lib/active_model/attribute_set.rb:48:in `fetch_value'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:77:in `_read_attribute'
    …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:40:in `__temp__57074616475646f51647'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `public_send'
    …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `try'
    …/code/rails/activerecord/lib/active_record/integration.rb:99:in `cache_version'
    …/code/rails/activerecord/lib/active_record/integration.rb:68:in `cache_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:639:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `block in expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `collect'
    …/code/rails/activesupport/lib/active_support/cache.rb:644:in `expanded_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:608:in `normalize_key'
    …/code/rails/activesupport/lib/active_support/cache.rb:565:in `block in read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `each'
    …/code/rails/activesupport/lib/active_support/cache.rb:564:in `read_multi_entries'
    …/code/rails/activesupport/lib/active_support/cache.rb:387:in `block in read_multi'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `block in instrument'
    …/code/rails/activesupport/lib/active_support/notifications.rb:170:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `instrument'
    …/code/rails/activesupport/lib/active_support/cache.rb:386:in `read_multi’
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb:18:in `cache_collection_render'
    …//code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:326:in `block in render_collection'
    …//code/rails/actionview/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
    …//code/rails/activesupport/lib/active_support/notifications.rb:168:in `block in instrument'

    View full-size slide

  109. ! …/code/rails/activemodel/lib/active_model/type/helpers/time_value.rb:73:in `fast_string_to_time' 100
    " …/code/rails/activemodel/lib/active_model/type/date_time.rb:25:in `cast_value' 100
    # ! …/code/rails/activerecord/lib/active_record/connection_adapters/postgresql/oid/date_time.rb:16:in `cast_value' 100
    # ! …/code/rails/activemodel/lib/active_model/type/value.rb:38:in `cast' 100
    # ! …/code/rails/activemodel/lib/active_model/type/helpers/accepts_multiparameter_time.rb:12:in `block in initializ
    # ! …/code/rails/activemodel/lib/active_model/type/value.rb:24:in `deserialize' 100
    # ! …/.rubies/ruby-2.5.3/lib/ruby/2.5.0/delegate.rb:349:in `block in delegating_block' 100
    # ! …/code/rails/activerecord/lib/active_record/attribute_methods/time_zone_conversion.rb:8:in `deserialize'
    # ! …/code/rails/activemodel/lib/active_model/attribute.rb:164:in `type_cast' 100
    # ! …/code/rails/activemodel/lib/active_model/attribute.rb:42:in `value' 100
    # ! …/code/rails/activemodel/lib/active_model/attribute_set.rb:48:in `fetch_value' 100
    # ! …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:77:in `_read_attribute' 100
    # ! …/code/rails/activerecord/lib/active_record/attribute_methods/read.rb:40:in `__temp__5707461647
    # ! …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `public_send' 100
    # ! …/code/rails/activesupport/lib/active_support/core_ext/object/try.rb:16:in `try' 100
    # ! …/code/rails/activerecord/lib/active_record/integration.rb:99:in `cache_version' 100
    # ! …/code/rails/activerecord/lib/active_record/integration.rb:68:in `cache_key' 100
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:639:in `expanded_key' 100
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:644:in `block in expanded_ke
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:644:in `collect' 100
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:644:in `expanded_key' 10
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:608:in `normalize_key'
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:565:in `block in rea
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:564:in `each' 100
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:564:in `read_mul
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:387:in `block
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:672:in `bloc
    # ! …/code/rails/activesupport/lib/active_support/notifications.rb:17
    # " …/code/rails/activesupport/lib/active_support/cache.rb:672:in `

    View full-size slide

  110. record/lib/active_record/integration.rb:68:in `cache_key' 100
    vesupport/lib/active_support/cache.rb:639:in `expanded_key' 100
    tivesupport/lib/active_support/cache.rb:644:in `block in expanded_key' 100
    activesupport/lib/active_support/cache.rb:644:in `collect' 100
    s/activesupport/lib/active_support/cache.rb:644:in `expanded_key' 100
    ils/activesupport/lib/active_support/cache.rb:608:in `normalize_key' 100
    rails/activesupport/lib/active_support/cache.rb:565:in `block in read_multi_entries' 100
    e/rails/activesupport/lib/active_support/cache.rb:564:in `each' 100
    ode/rails/activesupport/lib/active_support/cache.rb:564:in `read_multi_entries' 100
    /code/rails/activesupport/lib/active_support/cache.rb:387:in `block in read_multi' 100
    …/code/rails/activesupport/lib/active_support/cache.rb:672:in `block in instrument' 100
    ! …/code/rails/activesupport/lib/active_support/notifications.rb:170:in `instrument' 100
    " …/code/rails/activesupport/lib/active_support/cache.rb:672:in `instrument' 100
    # ! …/code/rails/activesupport/lib/active_support/cache.rb:386:in `read_multi' 100
    # ! …/code/rails/actionview/lib/action_view/renderer/partial_renderer/collection_caching.rb:18:in `cache_collection_rende
    # ! …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:326:in `block in render_collection' 100
    # ! …/code/rails/actionview/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument' 100
    # ! …/code/rails/activesupport/lib/active_support/notifications.rb:168:in `block in instrument' 300
    # ! …/code/rails/activesupport/lib/active_support/notifications/instrumenter.rb:23:in `instrument' 400
    # ! …/code/rails/activesupport/lib/active_support/notifications.rb:168:in `instrument' 400
    # " …/code/rails/actionview/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument' 300
    # # " …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:319:in `render_collection' 100
    # # # ! …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:310:in `render' 100
    # # # ! …/code/rails/actionview/lib/action_view/renderer/renderer.rb:49:in `render_partial' 100
    # # # " …/code/rails/actionview/lib/action_view/renderer/renderer.rb:23:in `render' 100
    # # # # ! …/code/rails/actionview/lib/action_view/helpers/rendering_helper.rb:33:in `render' 100
    # # # # ! …/code/codetriage/app/views/pages/_repos_with_pagination.html.slim:1:in `_app_views_pages__re
    # # # # ! …/code/rails/actionview/lib/action_view/template.rb:161:in `block in render' 100
    # # # ! …/code/rails/actionview/lib/action_view/helpers/rendering_helper.rb:36:in `render' 100
    # # # ! …/code/codetriage/app/views/pages/index.html.slim:37:in `_app_views_pages_index_html_slim__4370
    # # " …/code/rails/actionview/lib/action_view/renderer/partial_renderer.rb:333:in `render_partial' 100

    View full-size slide

  111. ! test/whence_test.rb:37:in `call_whence' 4
    " test/whence_test.rb:22:in `test_multiple_callers' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:98:in `block (3 levels) in run' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:195:in `capture_exceptions' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:95:in `block (2 levels) in run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:265:in `time_it' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:94:in `block in run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal' 4
    # " …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:211:in `with_info_handler'
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:93:in `run' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:960:in `run_one_method' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:334:in `run_one_method' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:321:in `block (2 levels)
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:320:in `each' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:320:in `block in run
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:347:in `with_info_handler' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:319:in `run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `block in __run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `map' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `__run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:136:in `run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:63:in `block in auto
    " test/whence_test.rb:41:in `call_whence_from_elsewhere' 2
    # " test/whence_test.rb:23:in `test_multiple_callers' 1
    # ! test/whence_test.rb:24:in `test_multiple_callers' 1
    ! test/whence_test.rb:45:in `call_whence_somewhere_else' 1
    ! test/whence_test.rb:24:in `test_multiple_callers' 1

    View full-size slide

  112. ! test/whence_test.rb:37:in `call_whence' 4
    " test/whence_test.rb:22:in `test_multiple_callers' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/min
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/m
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/l
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11
    # " …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minites
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minit
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/min
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/m
    # # ! …/code/whence/.gem/ruby/2.5.3/gems

    View full-size slide

  113. ! test/whence_test.rb:37:in `call_whence' 4
    " test/whence_test.rb:22:in `test_multiple_callers' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/min
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/m
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/l
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11
    # " …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minites
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minit
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/min
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/m
    # # ! …/code/whence/.gem/ruby/2.5.3/gems

    View full-size slide

  114. ! test/whence_test.rb:37:in `call_whence' 4
    " test/whence_test.rb:22:in `test_multiple_callers' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/min
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/m
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/l
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11
    # " …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minites
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minit
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/min
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/m
    # # ! …/code/whence/.gem/ruby/2.5.3/gems

    View full-size slide

  115. ! test/whence_test.rb:37:in `call_whence' 4
    " test/whence_test.rb:22:in `test_multiple_callers' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:98:in `block (3 levels) in run' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:195:in `capture_exceptions' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:95:in `block (2 levels) in run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:265:in `time_it' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:94:in `block in run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal' 4
    # " …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:211:in `with_info_handler'
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:93:in `run' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:960:in `run_one_method' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:334:in `run_one_method' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:321:in `block (2 levels)
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:320:in `each' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:320:in `block in run
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:347:in `with_info_handler' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:319:in `run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `block in __run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `map' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `__run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:136:in `run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:63:in `block in auto
    " test/whence_test.rb:41:in `call_whence_from_elsewhere' 2
    # " test/whence_test.rb:23:in `test_multiple_callers' 1
    # ! test/whence_test.rb:24:in `test_multiple_callers' 1
    ! test/whence_test.rb:45:in `call_whence_somewhere_else' 1
    ! test/whence_test.rb:24:in `test_multiple_callers' 1

    View full-size slide

  116. ! test/whence_test.rb:37:in `call_whence' 4
    " test/whence_test.rb:22:in `test_multiple_callers' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:98:in `block (3 levels) in run' 1
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:195:in `capture_exceptions' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:95:in `block (2 levels) in run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:265:in `time_it' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:94:in `block in run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:360:in `on_signal' 4
    # " …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:211:in `with_info_handler'
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest/test.rb:93:in `run' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:960:in `run_one_method' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:334:in `run_one_method' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:321:in `block (2 levels)
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:320:in `each' 4
    # # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:320:in `block in run
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:347:in `with_info_handler' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:319:in `run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `block in __run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `map' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:159:in `__run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:136:in `run' 4
    # ! …/code/whence/.gem/ruby/2.5.3/gems/minitest-5.11.3/lib/minitest.rb:63:in `block in auto
    " test/whence_test.rb:41:in `call_whence_from_elsewhere' 2
    # " test/whence_test.rb:23:in `test_multiple_callers' 1
    # ! test/whence_test.rb:24:in `test_multiple_callers' 1
    ! test/whence_test.rb:45:in `call_whence_somewhere_else' 1
    ! test/whence_test.rb:24:in `test_multiple_callers' 1

    View full-size slide

  117. $gem install whence

    View full-size slide

  118. Whence.whence

    View full-size slide

  119. Whence.tree
    puts

    View full-size slide

  120. Whence.tree
    puts

    View full-size slide

  121. perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  122. !"#$#%#&
    perfor
    m
    ant
    cle
    an
    use
    ful
    neces
    sary

    View full-size slide

  123. @calebthompson

    View full-size slide