BugFix: Random test failure when tracking compilation time

[CodeMeister]

Summary

When running the full test suite, it would randomly fail an activesupport_instrumentation test. On re-running the suite several times, everything would pass.

Test:

• "tracks proper time of compiling the factory"

Source:

• acceptance/activesupport_instrumentation_spec.rb:99

The Problem:

it "tracks proper time of compiling the factory" do
    time_to_execute = 0
    callback = ->(_name, start, finish, _id, _payload) { time_to_execute = finish - start }
    ActiveSupport::Notifications.subscribed(callback, "factory_bot.compile_factory") do
      FactoryBot.build(:user)
    end

    expect(time_to_execute).to be > 0
  end

The test would fail roughly once in every 30 runs , always with a :time_to_execute of 0:

The Cause

The cause, was that "factory_bot.compile_factory" instrumentation triggered twice, not just once.

• First for :user
• Second for :configuration

The :configuration compilation time, which can indeed be 0, is the last one triggered, so that's the elapsed time recorded by :time_to_execute.

The Solution

By changing :time_to_execute to a hash, and recording the individual compilations, we can check just the :user compilation time with time_to_execute[:user].

it "tracks proper time of compiling the factory" do
  time_to_execute = {user: 0}
  callback = ->(_name, start, finish, _id, _payload) {
    time_to_execute[_payload[:name]] = (finish - start)
  }
  ActiveSupport::Notifications.subscribed(callback, "factory_bot.compile_factory") do
    FactoryBot.build(:user)
  end

  expect(time_to_execute[:user]).to be > 0
end

[neilvcarvalho]

Thank you for fixing it! I could see this test failure, but didn't dig deep into it. I added a minimal change that I can commit myself if you'd like.

[CodeMeister]

@neilvcarvalho happy for you to change it