DocSpring Blog

How I Figured Out A Test Coverage Issue With SimpleCov And Spring

Nathan Broadbent -

TL;DR:

If you just want to get things working, I’ve published a shorter blog post that just includes the code:

How To Get Accurate Test Coverage With SimpleCov, Spring, and Rails.

Spring is a Ruby gem that can speed up development for Ruby on Rails applications. It keeps your Rails application running in the background so you don’t need to boot it every time you run a test, rake task or migration.

SimpleCov is a gem that measures code coverage for a test suite. I set up SimpleCov to measure coverage for our RSpec tests, but I noticed that the test coverage was not accurate whenever I ran RSpec with Spring. Some of the coverage wouldn’t include any lines for class and method definitions:

This coverage would be reported accurately whenever I disabled Spring: DISABLE_SPRING=true rspec spec/lib/example_class_spec.rb:

This coverage problem was only happening when Rails required a file while Spring was preloading the application. For this example, I’m requiring the example class from config/application.rb:

# config/application.rb

require File.expand_path('../lib/example_class', __dir__)

In our actual application, the test coverage issue was affecting Shrine uploaders, some models, and some other classes that were being loading while the Rails application was starting.

This issue has been a minor annoyance over the last few years. It was annoying that I always had to decide between speed (with Spring) and test coverage accuracy (without Spring).

If you’re a Rails developer, you’re probably run into some issues with Spring. These issues can usually be fixed by running spring stop, which restarts the Spring server.

Sometimes you run into an issue where Spring doesn’t play nice with other Ruby libraries. And when spring stop doesn’t solve the problem, these issues can be very hard to debug.

A Google search showed me that many other developers have been running into this SimpleCov issue with Spring. I read through all of the blog posts and comments I could find, and I tried all of these solutions, but nothing seemed to work for me.

I’ve fought with Spring in the past. It took me a while to figure out a reloading issue with the stripe-rails, and I’ve had some problems getting Spring to work with bootsnap. So I decided that I would roll up my sleeves and dig into the source code.

Debugging SimpleCov and Spring

I used bundle show to show the file path for these gems:

$ bundle show simplecov
/Users/myuser/.rvm/gems/ruby-2.5.5/gems/simplecov-0.17.1

$ bundle show spring
/Users/myuser/.rvm/gems/ruby-2.5.5/gems/spring-2.1.0

I opened these folders in my text editor (VS Code), so that I could add any print statements and debugger breakpoints (binding.pry).

If you use this approach, it’s important to reset your changes once you’re finished:

$ gem uninstall simplecov spring
$ bundle install

It was also extremely helpful to run the spring server in a separate terminal tab, so that I could view all of the logs:

$ spring server

Start SimpleCov from config/spring.rb

The first change I made was to call SimpleCov.start in config/spring.rb.

I set the command name to “RSpec”, which prevents any issues when SimpleCov tries to parse your shell command.

# config/spring.rb

if ENV['RAILS_ENV'] == 'test'
  require 'simplecov'
  SimpleCov.command_name 'RSpec'
  SimpleCov.start 'rails'
end

I only use rspec in my application. You will need to adjust this code if you use Cucumber, minitest, etc.

I was very surprised to discover that config/spring.rb was always being loaded, even if I started the Rails app without using Spring. This is because Bundler requires all of the gems in your Gemfile, and Spring will automatically load config/spring.rb as soon as the spring gem is required.

I didn’t like this default behavior, so I decided to disable it by adding require: false to all of the Spring gems in my Gemfile:

group :development, :test do
  gem 'spring-commands-rspec', require: false
  gem 'spring-watcher-listen', require: false
  gem 'spring', require: false
  # ...
end

This means that config/spring.rb is only loaded when I’m actually using Spring. I also needed to handle the case where I run rspec without Spring, by adding these lines to the top of spec_helper.rb:

# Spring starts SimpleCov in config/spring.rb
unless defined?(Spring)
  require 'simplecov'
  SimpleCov.command_name 'RSpec'
  SimpleCov.start 'rails'
end

This ensures that SimpleCov will always be started as soon as possible. It also means that SimpleCov will report test coverage for any specs that only require spec_helper.rb (instead of rails_helper.rb).

How Spring Works

Here’s how the Spring server works. Take a look at the following logs from spring server:

$ spring server
[40155] [server] started on /var/folders/9t/hpqz7_5s27dc8_j_2hd7p_7h0000gn/T/spring-501/486764b78e42ed9550f1ed128c07d8bb
[40155] [server] accepted client
[40155] [server] running command rspec
[40155] [application_manager:test] child not running; starting
[40253] [application:test] initialized -> running
[40253] [application:test] got client
[40253] [application:test] [40253] preloading app

...

[40253] [application:test] forked 40391
[40155] [application_manager:test] got worker pid 40391
[40391] [application:test] inside forked process
[40253] [application:test] 40391 exited with 0

If you look at the process IDs inside the square brackets, you can see that the Spring server starts with PID 40155. Then it starts a new process to preload the Rails application (40253). Finally, it forks this preloaded Rails process (40391) before running any commands.

SimpleCov’s at_exit block

Spring is now starting SimpleCov in config/spring.rb. But when I run rspec, I don’t see any coverage message in the console, and no files are being written to the ./coverage directory.

$ rspec spec/lib/example_class_spec.rb
Running via Spring preloader in process 54552
.

Finished in 0.26505 seconds (files took 0.73401 seconds to load)
1 example, 0 failures

Randomized with seed 61140
$

Also, something really weird is happening when I stop the Spring server:

$ spring server
...
[56472] [application:test] 56560 exited with 0
^C
[56446] [server] shutting down
Coverage report generated for RSpec to ./coverage. 1019 / 5000 LOC (20.38%) covered.
$

The Spring process is writing the coverage results instead of the rspec process, and this should be the other way round.

I found the culprit in SimpleCov’s at_exit block, which is defined in lib/simplecov/defaults.rb:

at_exit do
  # If we are in a different process than called start, don't interfere.
  next if SimpleCov.pid != Process.pid

  SimpleCov.set_exit_exception
  SimpleCov.run_exit_tasks!
end

This PID check was added in PR #377, and it handles cases where the test calls fork to start a new process. However, Spring is actually calling fork to start our test process, so we need to invert this condition.

I fixed this by setting SimpleCov.pid in config/spring.rb:

# config/spring.rb

if ENV['RAILS_ENV'] == 'test'
  require 'simplecov'
  SimpleCov.command_name 'RSpec'
  SimpleCov.start 'rails'

  # Prevent SimpleCov from writing test coverage after the Spring process exits
  SimpleCov.pid = nil
end

Spring.after_fork do
  next unless Rails.env.test?

  # Ensure that SimpleCov writes test coverage for this process
  SimpleCov.pid = Process.pid
end

This Spring.after_fork block is called after Spring forks a new process to run the rspec command.

Test coverage is now being reported when our rspec command exits:

$ rspec spec/lib/example_class_spec.rb
Running via Spring preloader in process 31990
.

Finished in 0.33963 seconds (files took 0.79383 seconds to load)
1 example, 0 failures

Randomized with seed 55974

Coverage report generated for RSpec to ./coverage. 1219 / 5000 LOC (24.38%) covered.
$

And SimpleCov doesn’t do anything when we stop the Spring server.

Now for the tricky part!

We’re starting SimpleCov in the right place, but we’re still missing some coverage for the class and method definitions:

These uncovered lines (red) are executed while Spring is preloading the Rails application, but they’re actually not being “executed” during the test, because the class is already loaded in memory. Even so, SimpleCov should definitely know about these lines, because we call SimpleCov.start before we start loading the Rails app.

What’s happening to the coverage?

I added a lot of logging to Spring::Application#serve:

def serve(client)
  log 'got client'
  # ...

  log "[#{Process.pid} / #{SimpleCov.pid}] Spring::Application#serve " \
    "before fork: Coverage.running?: #{Coverage.running?}"
  log "Coverage.peek_result.count: #{Coverage.peek_result.count}"
  log "=> lib/example_class.rb coverage:"
  log Coverage.peek_result.select { |k, _|
    k.include? "lib/example_class.rb"
  }.first[1].join(",")

  pid = fork do
    log "[#{Process.pid} / #{SimpleCov.pid}] Spring::Application#serve " \
      "after fork: Coverage.running?: #{Coverage.running?}"
    log "Coverage.peek_result.count: #{Coverage.peek_result.count}"
    log "=> lib/example_class.rb coverage:"
    log Coverage.peek_result.select { |k, _|
      k.include? "lib/example_class.rb"
    }.first[1].join(",")
    # ...

You can only call Coverage.result once, because it will disable the coverage measurement and clear the coverage hash after returning it. Coverage.peek_result can be called multiple times without stopping the coverage measurement.

The Coverage.peek_result hash has the following structure:

  {
    "/path/to/file" => [nil, 0, 1]
  }

Each element in the array corresponds to each line in the file.

  • nil: This line doesn’t contain any Ruby code (e.g. comments, blank lines)
  • 0: This line hasn’t been executed yet
  • 1: This line has been executed

My logging code displays the coverage for lib/example_class.rb before and after we fork the preloaded Rails process:

[47898] [application:test] [47898 / 47898] Spring::Application#serve
before fork: Coverage.running?: true
[47898] [application:test] Coverage.peek_result.count: 5780
[47898] [application:test] => lib/example_class.rb coverage:
[47898] [application:test] ,,,,1,1,0,0,,
[47898] [application:test] forked 47933
[47877] [application_manager:test] got worker pid 47933
[47933] [application:test] [47933 / 47898] Spring::Application#serve
after fork: Coverage.running?: true
[47933] [application:test] Coverage.peek_result.count: 5780
[47933] [application:test] => lib/example_class.rb coverage:
[47933] [application:test] ,,,,0,0,0,0,,

Aha! You can see that the first two lines of Ruby code in lib/example_class.rb are covered in process 47898. Then the coverage is reset to 0 after the process is forked (47933).

I added the same logging calls to SimpleCov.result, which is called in the rspec process:

1 example, 0 failures

Randomized with seed 34143

[71423 / 71423] SimpleCov#result: Coverage.running?: true
Coverage.peek_result.count: 6204
=> lib/example_class.rb coverage:
,,,,0,0,1,1,,

So you can see that the last two lines of code are being called during the test.

To recap:

  • The Spring server process starts a new process that preloads the Rails application
  • lib/example_class.rb coverage: 1,1,0,0
  • After forking the preloaded Rails process:
  • lib/example_class.rb coverage: 0,0,0,0
  • After the RSpec test finishes:
  • lib/example_class.rb coverage: 0,0,1,1

So now we just need to find a way to merge these two coverage results together, so that we get the actual test coverage: 1,1,1,1.

Storing The Rails App Coverage

I added a new class-level instance variable to the SimpleCov module. This means that I can store the coverage for the preloaded Rails application, and read it from the forked RSpec process:

module SimpleCov
  class << self
    attr_accessor :spring_preload_result
  end
end

I was hoping that I could monkey-patch Spring::Application so that it would set spring_preload_result after it finishes preloading the app. However, the #preload method is actually responsible for loading our Rails application, so we’re already inside the method that I want to override.

My next thought was to add a config.after_initialize callback in config/application.rb, but I discovered that this was being called too early. I saw that some Shrine uploader classes were being required after this after_initialize callback had fired.

I added some more logging, and I realized that I could add some code at the end of config/environment.rb. I saw that everything was loaded after the Rails.application.initialize! call had returned. (I’m surprised that Rails doesn’t seem to provide a callback for this.)

So I added the following lines to the end of config/environment.rb:

if defined?(Spring) && defined?(SimpleCov) && Coverage.running?
  SimpleCov.spring_preload_result = Coverage.peek_result
end

Now we’ve stored all of the coverage that was collected while preloading the Rails app.

The last step is to merge these coverage results together, so I overrode the SimpleCov.result method. SimpleCov has a merge_results method that we can use:

SimpleCov.class_eval do
  class << self
    attr_accessor :spring_preload_result

    # Returns the result for the current coverage run, merging it across test suites
    # from cache using SimpleCov::ResultMerger if use_merging is activated (default).
    def result
      return @result if result?

      # Collect our coverage result. If we are using Spring, merge the
      # coverage from the preloaded Rails process.
      if running
        raw_result = add_not_loaded_files(Coverage.result)
        if SimpleCov.spring_preload_result
          raw_result = SimpleCov::RawCoverage.merge_results(
            SimpleCov.spring_preload_result,
            raw_result
          )
        end
        @result = SimpleCov::Result.new(raw_result)
      end

      # If we're using merging of results, store the current result
      # first (if there is one), then merge the results and return those
      if use_merging
        SimpleCov::ResultMerger.store_result(@result) if result?
        @result = SimpleCov::ResultMerger.merged_result
      end

      @result
    ensure
      self.running = false
    end
  end
end

It works!

Putting It All Together

I’ve also published a shorter blog post that includes all of the code.

This code has been tested with the following library versions:

  • spring: 2.0.2, 2.1.0
  • simplecov: 0.16.1, 0.17.1
  • rspec: 3.8.0, 3.9.0
  • rails: 5.2.3


Final Thoughts

This was a challenging puzzle, and I really enjoyed solving it. Spring provides a great speed boost, but it can also cause some issues that are hard to debug. I run Rails commands and tests very regularly, so I think it’s worth investing the time and effort to fix issues like this.

I’m not sure why the coverage hash is being reset after the Ruby process is forked. Maybe this is the intended behavior, or it could be a bug in Ruby. Either way, this Spring configuration and SimpleCov monkey-patch will solve the problem.

I hope you found this post interesting, and I hope you’re able to get SimpleCov working with Spring. Thanks for reading!

References

Here’s a list of links that I found useful while I was investigating this issue: