Faster RSpec: Profiling FactoryGirl

One way to speed up a slow test suite is to optimize how FactoryGirl is used, but where do you focus your efforts?

Before tuning your factory usage, consider measuring which factories are adding the most time to your test runs. You may discover the time spent in factories is fine and decide to speed up another area of your suite.

Introduce FactoryGirlProfiler below to an RSpec project. It will only report when the --profile/-p flag is passed to the rspec command:

# File: spec/support/factory_girl_profiler.rb
# Ensure this file is required by spec_helper.rb or rails_helper.rb
class FactoryGirlProfiler

  attr_accessor :results

  def self.setup
    profiler = self.new

    RSpec.configure do |config|
      config.before(:suite) { profiler.subscribe }
      config.after(:suite) { profiler.dump }
    end
  end

  def initialize
    self.results = {}
  end

  def subscribe
    ActiveSupport::Notifications.subscribe("factory_girl.run_factory") do |name, start, finish, id, payload|
      factory, strategy = payload.values_at(:name, :strategy)

      factory_result = results[factory] ||= {}
      strategy_result = factory_result[strategy] ||= { duration_in_secs: 0.0, count: 0 }

      duration_in_secs = finish - start
      strategy_result[:duration_in_secs] += duration_in_secs
      strategy_result[:count] += 1
    end
  end

  def dump
    puts "\nFactoryGirl Profiles"
    total_in_secs = 0.0
    results.each do |factory_name, factory_profile|
      puts "\n  #{factory_name}"
      factory_profile.each do |strategy, profile|
        puts "    #{strategy} called #{profile[:count]} times took #{profile[:duration_in_secs].round(2)} seconds total"
        total_in_secs += profile[:duration_in_secs]
      end
    end
    puts "\n Total FactoryGirl time #{total_in_secs.round(2)} seconds"
  end

end

RSpec.configure do |config|
  config.add_setting :profile_factories, default: false
  config.profile_factories = config.profile_examples? || ARGV.include?('--profile') || ARGV.include?('-p')
  FactoryGirlProfiler.setup if config.profile_factories?
end

Source: https://github.com/eliotsykes/rails-testing-toolbox/blob/master/factory_girl_profiler.rb

Now run rspec --profile and review the output to find results formatted like below:

FactoryGirl Profiles

  invoice
    create called 4 times took 0.18 seconds total

  product
    build called 7 times took 0.07 seconds total
    create called 17 times took 0.22 seconds total

  user
	build called 12 times took 0.06 seconds total
    build_stubbed called 2 times took 0.01 seconds total
	create called 28 times took 1.51 seconds total

 Total FactoryGirl time 2.05 seconds

This will show the factories that are taking up the most time and help you decide where to focus your optimization work.