Infrequent weird output in tests

 examples were filtered out; ignoring {:focus=>true}
............................................................./host/nateberkopec/Documents/Code.nosync/upstream/rack-mini-profiler/vendor/bundle/ruby/3.1.0/gems/rack-proxy-0.7.6/lib/rack/proxy.rb:130: warning: assigned but unused variable - ssl_verify_none
............#<Rack::MiniProfiler::MemoryStore::CacheCleanupThread:0x0000ffff74dffd80 /host/nateberkopec/Documents/Code.nosync/upstream/rack-mini-profiler/lib/mini_profiler/storage/memory_store.rb:77 run> terminated with exception (report_on_exception is true):
........../host/nateberkopec/Documents/Code.nosync/upstream/rack-mini-profiler/lib/mini_profiler/storage/memory_store.rb:79:in `block in initialize_cleanup_thread': undefined method `sleepy_run' for nil:NilClass (NoMethodError)

            t.sleepy_run
             ^^^^^^^^^^^
........................................................................................................................................................................................................

This took a while to track down (but was a lot of fun too! 😄)

The root cause is that the code block of CacheCleanupThread is scheduled to run as soon as super is called in CacheCleanupThread#initialize. This results in a race condition where the thread may run before the thread class instance is fully instantiated. While this seems counterintuitive, I was tipped off to the possibility here https://www.ruby-forum.com/t/thread-super-should-be-first-line-or-last-line/150617 I later proved this was happening by the code changes that fixed the problem.

There are actually two separate race conditions

The thread may be scheduled to run before the thread instance is returned by CacheCleanupThread.new. When this happens t is undefined inside the thread block. This results in the error "undefined method `sleepy_run' for nil:NilClass" that we see in the test output

def initialize_cleanup_thread(args = {})
  cleanup_interval = args.fetch(:cleanup_interval) { CLEANUP_INTERVAL }
  cleanup_cycle    = args.fetch(:cleanup_cycle)    { CLEANUP_CYCLE }
  t = CacheCleanupThread.new(cleanup_interval, cleanup_cycle, self) do
    until Thread.current[:should_exit] do
      t.sleepy_run # <===== t may be undefined here!
    end
  end
  at_exit { t[:should_exit] = true }
end

This can be fixed by changing t.sleepy_run to Thread.current.sleepy_run

The thread may be scheduled to run before the member variables in CacheCleanupThread#initialize are defined. This results in "undefined method '*' for nil:NilClass" in should_cleanup? (this error only occurs after the first race condition is fixed)

def should_cleanup?
  @cycle_count * @interval >= @cycle
end

This happens because @cycle_count, @interval, and @cycle may be undefined when thread execution starts. It can be fixed by moving super to the bottom of CacheCleanupThread#initialize

def initialize(interval, cycle, store)
  @store       = store
  @interval    = interval
  @cycle       = cycle
  @cycle_count = 1
  super
end

The race conditions causing this intermittent test output are also present in the production code, but I don't know if they actually manifest themselves?

I will open a PR shortly with the fixes

MiniProfiler / rack-mini-profiler

Infrequent weird output in tests #566