FactoryDoc: detect useless data generation in tests

factory_doctor.rb

# frozen_string_literal: true

module FactoryBot
  module Doctor
    module FloatDuration
      refine Float do
        def duration
          t = self
          format("%02d:%02d.%03d", t / 60, t % 60, t.modulo(1) * 1000)
        end
      end
    end

    using FloatDuration

    module FactoryExt
      def run(strategy = @strategy)
        Doctor.within_factory(strategy) { super }
      end
    end

    class << self
      attr_reader :count, :time

      def init
        @depth = 0
        reset
        FactoryBot::FactoryRunner.prepend FactoryExt
      end

      def within_factory(strategy)
        return yield if ignore?

        ts = Time.zone.now if @depth.zero?
        @depth += 1
        @count += 1 if strategy == :create
        yield
      ensure
        @depth -= 1

        if @depth.zero?
          delta = (Time.zone.now - ts)
          @time += delta
        end
      end

      def ignore
        @ignored = true
        res = yield
        @ignored = false
        res
      end

      def reset
        @count = 0
        @time = 0.0
      end

      def within_factory?
        @depth.positive?
      end

      def ignore?
        @ignored == true
      end
    end

    class Profiler
      IGNORED_QUERIES_PATTERN = %r{(
        pg_table|
        pg_attribute|
        pg_namespace|
        show\stables|
        pragma|
        sqlite_master/rollback|
        \ATRUNCATE TABLE|
        \AALTER TABLE|
        \ABEGIN|
        \ACOMMIT|
        \AROLLBACK|
        \ARELEASE|
        \ASAVEPOINT
      )}xi.freeze

      NOTIFICATIONS = [:example_started, :example_finished].freeze

      def initialize
        @queries = []
        @example_groups = Hash.new { |h, k| h[k] = [] }

        ActiveSupport::Notifications.subscribe("sql.active_record") do |_name, _start, _finish, _id, query|
          next if Doctor.within_factory?
          next if IGNORED_QUERIES_PATTERN.match?(query[:sql])

          @queries << query[:sql]
        end
      end

      def example_started(_notification)
        @queries.clear
        Doctor.reset
      end

      def example_finished(notification)
        return if notification.example.pending?

        if Doctor.count.positive? && @queries.size.zero?
          group = notification.example.example_group.parent_groups.last
          notification.example.metadata.merge!(
            factories: Doctor.count,
            time: Doctor.time
          )
          @example_groups[group] << notification.example
        end
      end

      def print
        return if @example_groups.empty?

        output.puts(
          "\n\nFactoryDoctor found useless data generation "\
          "in the following examples\n"
        )

        total_time = 0.0

        @example_groups.each do |group, examples|
          out = ["#{group.description} (#{group.metadata[:location]})"]
          examples.each do |ex|
            total_time += ex.metadata[:time]
            out << "  #{ex.description} (#{ex.metadata[:location]}) – #{ex.metadata[:factories]} created objects, #{ex.metadata[:time].duration}"
          end
          output.puts out.join("\n")
        end

        output.puts "\nTotal wasted time: #{total_time.duration}\n"
      end

      private

      def output
        RSpec.configuration.output_stream
      end
    end
  end
end

if ENV["FDOC"]
  FactoryBot::Doctor.init

  RSpec.configure do |config|
    listener = FactoryBot::Doctor::Profiler.new

    config.reporter.register_listener(listener, *FactoryBot::Doctor::Profiler::NOTIFICATIONS)

    config.after(:suite) { listener.print }
  end
end

cudos to https://gist.github.com/palkan/4088ab57191f6b537ef3e4d75939a190#file-factory_doctor-rb-L123