Rspec-core: Massive performance regression with Ruby 2.4.0?

[Drenmi]

I'm a contributor on the RuboCop project. I noticed that, when switching to Ruby 2.4.0, test runs take about twice (!) as long. At first, I thought that this might be an issue with my local installation, but the problem persists on TravisCI:

I'm hoping this is something project specific, and not a general regression. 😓

# Running on Ruby 2.4.0 x86_64-darwin16
bundle exec rspec --version
3.5.4

[JonRowe]

Our own builds for Ruby 2.4.0 for rspec-core show approximately even times to 2.3.3, (you have to dig into the builds themselves to see the core gem is passing, it's just rspec-rails in conjunction with this that fails, suggesting this is a regression in your specific test suite / project.

Can you reproduce with just rspec code?

[Drenmi]

@JonRowe: Thanks for the reply. I'll dig deeper into this when I have time, to see if I can find out what's going on. I also noticed the boot up time of the suite is extremely long.

[pocke]

Hi. I profiled the rubocop's spec with stackprof.

==================================
  Mode: cpu(1000)
  Samples: 48257 (74.70% miss rate)
  GC: 1293 (2.68%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
     98671 (204.5%)       32849  (68.1%)     #<Module:0x000000024e7698>.module_for
      2312   (4.8%)        2263   (4.7%)     #<Module:0x00000002a95e50>.assign_const
      1390   (2.9%)         885   (1.8%)     Parser::Lexer#advance
       291   (0.6%)         291   (0.6%)     Psych::Nodes::Scalar#initialize
       279   (0.6%)         279   (0.6%)     URI::RFC2396_Parser#initialize_regexp
       263   (0.5%)         263   (0.5%)     RuboCop::Cop::Badge#hash
       259   (0.5%)         259   (0.5%)     #<Module:0x000000025b6010>.thread_local_data
       231   (0.5%)         211   (0.4%)     RSpec::Core::Hooks#hooks
       213   (0.4%)         208   (0.4%)     Psych::ScalarScanner#tokenize
       198   (0.4%)         198   (0.4%)     Parser::Source::Range#initialize
       198   (0.4%)         198   (0.4%)     Parser::Source::Buffer#slice
       403   (0.8%)         195   (0.4%)     AST::Node#initialize
       163   (0.3%)         163   (0.3%)     RuboCop::Cop::Cop.badge
       796   (1.6%)         160   (0.3%)     RuboCop::AST::Node#each_child_node
       208   (0.4%)         160   (0.3%)     Parser::AST::Node#assign_properties
       308   (0.6%)         156   (0.3%)     RSpec::Core::Ordering::Random#jenkins_hash_digest
      2150   (4.5%)         149   (0.3%)     Psych::Visitors::Visitor#visit
       256   (0.5%)         142   (0.3%)     RSpec::Core::ExampleGroup.parent_groups
       133   (0.3%)         133   (0.3%)     #<Module:0x000000025b6088>.configuration
       126   (0.3%)         126   (0.3%)     block (2 levels) in define_reader
       120   (0.2%)         120   (0.2%)     RuboCop::Config#to_s
       310   (0.6%)         112   (0.2%)     RuboCop::Config#initialize
       323   (0.7%)         109   (0.2%)     RuboCop::StringUtil::Jaro#find_common_characters
       106   (0.2%)         106   (0.2%)     Psych::ClassLoader#load
       227   (0.5%)         104   (0.2%)     RuboCop::AST::Builder#node_map
       139   (0.3%)          98   (0.2%)     RSpec::Core::Set#each
        93   (0.2%)          93   (0.2%)     RSpec::Support::ReentrantMutex#initialize
       115   (0.2%)          90   (0.2%)     RuboCop::Cop::Badge.parse
       263   (0.5%)          88   (0.2%)     RuboCop::Cop::Cop#cop_config
        87   (0.2%)          87   (0.2%)     Parser::Source::Buffer.recognize_encoding

module_for is slow. The cause is const_set is slow in Ruby 2.4.
I've reported this problem to ruby trunk. https://bugs.ruby-lang.org/issues/13113

[JonRowe]

Thanks! I'll close this then as it's a problem upstream, hopefully something can be done in 2.4.1