ActiveSupport::FileUpdateChecker triggers unnecessary reloads in tests using time travel

[grodowski]

My team discovered this issue troubleshooting a flaky test that depended on class state that was (re)created at load time. We found that when Time.now is stubbed with time travel test helpers, the checker treats all files as updated and reloads even when files haven't been changed. Our temporary fix was to enable cache_classes in the Rails config for tests (which does make sense in general), but this led me to a possible change to the FileUpdateChecker to avoid those unnecessary file reloads caused by time travel in tests.

Steps to reproduce

Run ruby file_update_checker_time_travel.rb --seed 23705 with the following structure and observe the constant is reloaded:

  1) Failure:
BugTest#test_without_time_travel [file_update_checker_time_travel.rb:58]:
--- expected
+++ actual
@@ -1,3 +1,3 @@
 # encoding: ASCII-8BIT
 #    valid: true
-"243"
+"437"

This is the smallest setup I could get to show that a test, when executed following one that uses time travel helpers, will experience unnecessary reloads.

.
├── app
│   └── models
│       └── user.rb
├── config
│   └── routes.rb
└── file_update_checker_time_travel.rb

# app/models/user.rb
class User
  puts "Loading User..."
  cattr_accessor :random_value do
    rand(1000)
  end
end

# config/routes.rb
Rails.application.routes.draw do
  get "/", to: "test#index"
end

# file_update_checker_time_travel.rb
# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  gem "rails"
end

require "action_controller/railtie"
require "minitest/autorun"
require "rack/test"

class TestApp < Rails::Application
  config.load_defaults Rails::VERSION::STRING.to_f
  config.root = __dir__
  config.eager_load = false
  config.hosts << "example.org"
  config.secret_key_base = "secret_key_base"
  config.logger = Logger.new($stdout)

  config.enable_reloading = true
end

Rails.application.initialize!

# moved routes to config/routes.rb - otherwise the RoutesReloader runs before tests start and
# @loaded is already true => the bug isn't reproduced
# Rails.application.routes.draw do
#   get "/", to: "test#index"
# end

class TestController < ActionController::Base
  include Rails.application.routes.url_helpers

  def index
    render plain: User.random_value
  end
end

class BugTest < ActionDispatch::IntegrationTest
  include Rack::Test::Methods

  $initial_random_value = nil
  def test_with_time_travel # ensure with a --seed value that this runs first
    travel_to Time.utc(2023) do
      get "/"
      assert last_response.ok?
      $initial_random_value = last_response.body
      puts last_response.body
    end
  end

  def test_without_time_travel # ensure this runs last
    get "/"
    assert last_response.ok?
    assert_equal last_response.body, $initial_random_value
  end

  private

  def app
    Rails.application
  end
end

# extra debugging for FileUpdateChecker
module ActiveSupport
  class FileUpdateChecker
    alias_method :original_initialize, :initialize
    alias_method :original_updated?, :updated?
    alias_method :original_execute, :execute
    def initialize(files, dirs = {}, &block)
      original_initialize(files, dirs = {}, &block)
      if caller.any? { |line| line.include?("routes_reloader") }
        puts "[initializing FileUpdateChecker] #{self.object_id} for #{files.inspect}, #{dirs.inspect}, @last_update_at: #{@last_update_at.inspect}"
      end
    end

    def updated?
      original_updated?.tap do
        if caller.any? { |line| line.include?("routes_reloader") }
          puts "[updated? #{self.object_id}] @last_update_at: #{@last_update_at.inspect}"
        end
      end
    end

    def execute
      original_execute.tap do
        if caller.any? { |line| line.include?("routes_reloader") }
          puts "[execute #{self.object_id}] set @last_update_at to #{@last_update_at.inspect}"
        end
      end
    end
  end
end

Expected behavior

Unchanged files are not reloaded.

Actual behavior

FileUpdateChecker sets @last_update_at to Time.at(0) and treats all files as changed.

Proposed fixes (pull request pending)

• replace Time.now with system time in FileUpdateChecker: Use process time instead of Time.now in FileUpdateChecker
• kind of a bonus, but using the EventedFileUpdateChecker for reloading routes also fixed our issue: Respect the file_watcher config in the routes reloader

Additional notes

New Rails apps disable reloading in the test environment by default, so they won't be affected by this.

# While tests run files are not watched, reloading is not necessary.
config.enable_reloading = false

System configuration

Rails version: 8.0.2.1

Ruby version: 3.4.5

[skipkayhil]

I think this is the same problem as #55114 was trying to solve (so we can close if we accept 55710 instead)