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.

Transcript

1. the life-changing magic of tidying up activerecord allocations @schneems
2. @schneems
13. @calebthompson
25. !"#$#%#& perfor m ant cle an use ful neces sary
26. !"#$#%#& !"#$#%#& !"#$#%#& !"#$#%#& !"#$#%#& perfor m ant cle an use ful neces sary
30. Quiz Time
31. 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
32. b end def allocate_max(a, b) array = [a, b] array.max end
33. require 'benchmark/ips' def compare_max(a, b) return a if a > b b end
35. 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
36. 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
37. malloc is slow
38. ✂
39. first, last = Thing.call(input)
41. Bytes allocated is more important than object count in Ruby
42. Bytes allocated is more important than object count in Ruby (IMHO)
43. Fewer bytes allocated Performance improvement ≈
44. Bytes reduced is a consistent metric
50. $gem install memory_profiler
51. $gem install derailed_benchmarks
55. In
56. $derailed exec perf:objects
57. 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
58. 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
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 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
60. $ALLOW_FILES=active_record/attribute_methods.rb bundle exec derailed exec perf:objects
61. 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 -----------------------------------
62. 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
63. 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
64. 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.
65. 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"
66. 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.
67. 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
68. 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
69. 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
70. 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
71. 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
72. 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
73. 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 !"#+#,#* ?
74. 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
75. 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
76. 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
79. 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
80. 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 &
81. 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
82. 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
83. 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
84. 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
85. 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
86. 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
87. 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
89. 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
92. T
95. 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
96. 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
97. 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
98. 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
99. 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
100. 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
101. 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
102. 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
110. 0.05
120. 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
123. $bundle exec derailed exec perf:objects
124. 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
125. 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
126. $ALLOW_FILES=active_model/type/helpers/time_value.rb bundle exec derailed exec perf:objects
127. 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
128. 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
129. 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
132. 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
133. 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
134. 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
135. i.e. ".1234567" #=> 1234567
136. 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
137. 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
138. Is it faster?
139. 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
140. 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
143. 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
144. ==================================================================================================== …/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'
145. …/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’
146. # 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
147. # 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
148. 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
149. 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
150. 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
153. > User.first.updated_at_before_type_cast => "2019-04-24 21:21:09.232249" > User.first.updated_at.to_s(:usec) => "20190424212109232249"
154. > User.first.updated_at_before_type_cast => "2019-04-24 21:21:09.232249" > User.first.updated_at.to_s(:usec) => "20190424212109232249"
155. > User.first.updated_at_before_type_cast => "2019-04-24 21:21:09.232249" > User.first.updated_at.to_s(:usec) => "20190424212109232249"
156. > User.first.updated_at_before_type_cast => "20190424212109232249" > User.first.updated_at.to_s(:usec) => "20190424212109232249"
159. def cache_version if cache_versioning && timestamp = try(:updated_at) timestamp.utc.to_s(:usec) end end
160. 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
161. 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
162. 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
163. 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
164. 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
165. 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
166. def cache_version if cache_versioning && timestamp = try(:updated_at) timestamp.utc.to_s(:usec) end end
167. def cache_version if cache_versioning && timestamp = try(:updated_at) timestamp.utc.to_s(:usec) end end
168. 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
169. 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
170. 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
171. 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
172. 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
173. 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
174. Before: Total allocated: 743842 bytes (6626 objects) After: Total allocated: 702955 bytes (6063 objects) 743842 / 702955 => 1.058x or 5% fewer allocations
175. Before: Total allocated: 743842 bytes (6626 objects) After: Total allocated: 702955 bytes (6063 objects) 743842 / 702955 => 1.058x or 5% fewer allocations ⚡⚡⚡⚡⚡
176. 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
180. 1.23×
185. def cache_version if cache_versioning && timestamp = try(:updated_at) timestamp.utc.to_s(:usec) end end &
188. ⚖
189. ⚖
192. 1.01×
194. 1.53×
195. ==================================================================================================== …/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'
196. ==================================================================================================== …/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'
197. ==================================================================================================== …/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'
198. ==================================================================================================== …/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'
199. ! …/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 `
200. 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
201. ! 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
202. ! 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
203. ! 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
204. ! 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
205. ! 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
206. ! 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
207. $gem install whence
208. Whence.whence
209. Whence.tree puts
210. Whence.tree puts
214. perfor m ant cle an use ful neces sary
215. !"#$#%#& perfor m ant cle an use ful neces sary
224. @calebthompson