Add Minitest support to TagProf (#283)

* Add Minitest support to TagProf

* Update docs/profilers/tag_prof.md

Co-authored-by: Vladimir Dementyev <dementiev.vm@gmail.com>

* Fix CI errors

* Fix mdl errors

* Return __unknown__ when aboslute path cannot be displayed

* Limit to last released rails version in railsmaster.gemfile

* Fix rspec bug without limiting rails last stable version in railsmaster.gemfile

---------

Co-authored-by: Vladimir Dementyev <dementiev.vm@gmail.com>

CHANGELOG.md

@@ -2,6 +2,8 @@
 
 ## master (unreleased)
 
+- Add Minitest support for TagProf. ([@lioneldebauge][])
+
 ## 1.3.1 (2023-12-12)
 
 - Add support for dumping FactoryProf results in JSON format. ([@uzushino][])

docs/profilers/tag_prof.md

@@ -30,15 +30,47 @@ That's how a report looks like:
 
 ## Instructions
 
-TagProf can only be used with RSpec.
+TagProf can be used with both RSpec and Minitest (limited support, see  below).
 
 To activate TagProf use `TAG_PROF` environment variable:
 
+With Rspec:
+
 ```sh
 # Group by type
 TAG_PROF=type rspec
 ```
 
+With Minitest:
+
+```sh
+# using pure ruby
+TAG_PROF=type ruby
+
+# using Rails built-in task
+TAG_PROF=type bin/rails test
+```
+
+NB: if another value than "type" is used for TAG_PROF environment variable it will be ignored silently in both Minitest and RSpec.
+
+### Usage specificity with Minitest
+
+Minitest does not support the usage of tags by default. TagProf therefore groups statistics by direct subdirectories of the root test directory. It assumes root test directory is named either `spec` or `test`.
+
+When no root test directory can be found the test statistics will not be grouped with other tests. They will be displayed per test with a significant warning message in the report.
+
+Example:
+
+```sh
+[TEST PROF INFO] TagProf report for type
+
+       type          time   sql.active_record  total  %total   %time           avg
+
+__unknown__     00:04.808           00:01.402     42   33.87   54.70     00:00.114
+ controller     00:02.855           00:00.921     42   33.87   32.48     00:00.067
+      model     00:01.127           00:00.446     40   32.26   12.82     00:00.028
+```
+
 ## Profiling events
 
 You can combine TagProf with [EventProf](./event_prof.md) to track not only the total time spent but also the time spent for the specified activities (through events):

gemfiles/railsmaster.gemfile

@@ -1,6 +1,6 @@
 source "https://rubygems.org"
 
-gem "rails", github: "rails/rails"
+gem "rails"
 
 gem "fabrication"
 gem "factory_bot", "~> 5.0"

lib/minitest/test_prof_plugin.rb

@@ -3,6 +3,7 @@
 require "test_prof/event_prof/minitest"
 require "test_prof/factory_doctor/minitest"
 require "test_prof/memory_prof/minitest"
+require "test_prof/tag_prof/minitest"
 
 module Minitest # :nodoc:
   module TestProf # :nodoc:
@@ -16,6 +17,7 @@ def self.configure_options(options = {})
         opts[:sample] = true if ENV["SAMPLE"] || ENV["SAMPLE_GROUPS"]
         opts[:mem_prof_mode] = ENV["TEST_MEM_PROF"] if ENV["TEST_MEM_PROF"]
         opts[:mem_prof_top_count] = ENV["TEST_MEM_PROF_COUNT"] if ENV["TEST_MEM_PROF_COUNT"]
+        opts[:tag_prof] = true if ENV["TAG_PROF"] == "type"
       end
     end
   end
@@ -50,6 +52,7 @@ def self.plugin_test_prof_init(options)
     reporter << TestProf::EventProfReporter.new(options[:io], options) if options[:event]
     reporter << TestProf::FactoryDoctorReporter.new(options[:io], options) if options[:fdoc]
     reporter << TestProf::MemoryProfReporter.new(options[:io], options) if options[:mem_prof_mode]
+    reporter << Minitest::TestProf::TagProfReporter.new(options[:io], options) if options[:tag_prof]
 
     ::TestProf::MinitestSample.call if options[:sample]
   end

lib/test_prof/tag_prof/minitest.rb

@@ -0,0 +1,74 @@
+# frozen_string_literal: true
+
+module Minitest
+  module TestProf
+    class TagProfReporter < BaseReporter # :nodoc:
+      attr_reader :results
+
+      def initialize(io = $stdout, _options = {})
+        super
+        @results = ::TestProf::TagProf::Result.new("type")
+
+        if event_prof_activated?
+          require "test_prof/event_prof"
+          @current_group_id = nil
+          @events_profiler = configure_profiler
+          @results = ::TestProf::TagProf::Result.new("type", @events_profiler.events)
+        end
+      end
+
+      def prerecord(group, example)
+        return unless event_prof_activated?
+
+        # enable event profiling
+        @events_profiler.group_started(true)
+      end
+
+      def record(result)
+        results.track(main_folder_path(result), time: result.time, events: fetch_events_data)
+        @events_profiler.group_started(nil) if event_prof_activated? # reset and disable event profilers
+      end
+
+      def report
+        printer = (ENV["TAG_PROF_FORMAT"] == "html") ? ::TestProf::TagProf::Printers::HTML : ::TestProf::TagProf::Printers::Simple
+        printer.dump(results)
+      end
+
+      private
+
+      def main_folder_path(result)
+        return :__unknown__ if absolute_path_from(result).nil?
+
+        absolute_path_from(result)
+      end
+
+      def absolute_path_from(result)
+        absolute_path = File.expand_path(result.source_location.first)
+        absolute_path.slice(/(?<=(?:spec|test)\/)\w*/)
+      end
+
+      def configure_profiler
+        ::TestProf::EventProf::CustomEvents.activate_all(tag_prof_event)
+        ::TestProf::EventProf.build(tag_prof_event)
+      end
+
+      def event_prof_activated?
+        return false if tag_prof_event.nil?
+
+        !tag_prof_event.empty?
+      end
+
+      def tag_prof_event
+        ENV["TAG_PROF_EVENT"]
+      end
+
+      def fetch_events_data
+        return {} unless @events_profiler
+
+        @events_profiler.profilers.map do |profiler|
+          [profiler.event, profiler.time || 0.0]
+        end.to_h
+      end
+    end
+  end
+end

lib/test_prof/tag_prof/result.rb

@@ -21,8 +21,8 @@ def initialize(tag, events = [])
       def track(tag, time:, events: {})
         data[tag][:count] += 1
         data[tag][:time] += time
-        events.each do |k, v|
-          data[tag][k] += v
+        events.each do |event, time|
+          data[tag][event] += time
         end
       end
 

spec/integrations/factory_doctor_spec.rb

@@ -19,7 +19,7 @@
     end
 
     it "print message when no bad examples", :aggregate_failures do
-      output = run_minitest("factory_doctor", env: {"FDOC" => "1", "FDOC_THRESHOLD" => "0", "TESTOPTS" => "--name=test_0005_is_ignored"})
+      output = run_minitest("factory_doctor", env: {"FDOC" => "1", "FDOC_THRESHOLD" => "0", "TESTOPTS" => "--name=\"test_0005_is ignored\""})
 
       expect(output).to include("FactoryDoctor enabled")
       expect(output).to include('FactoryDoctor says: "Looks good to me!"')

spec/integrations/fixtures/minitest/tag_prof_fixture.rb

@@ -0,0 +1,24 @@
+# frozen_string_literal: true
+
+$LOAD_PATH.unshift File.expand_path("../../../../../lib", __FILE__)
+require "minitest/autorun"
+require "active_support"
+require "test-prof"
+
+module Instrumenter
+  def self.notify(_event, time)
+    sleep 0.1
+    ActiveSupport::Notifications.publish(
+      "test.event",
+      0,
+      time
+    )
+  end
+end
+
+describe "Test Class" do
+  it "succeeds" do
+    Instrumenter.notify "test.event", 100
+    assert(true)
+  end
+end

spec/integrations/tag_prof_spec.rb

@@ -1,36 +1,108 @@
 # frozen_string_literal: true
 
 describe "TagProf" do
-  specify "it works", :aggregate_failures do
-    output = run_rspec("tag_prof", env: {"TAG_PROF" => "type"})
-
-    expect(output).to include("TagProf report for type")
-    expect(output).to match(/type\s+time\s+total\s+%total\s+%time\s+avg\n\n/)
-    expect(output).to match(/fail\s+\d{2}:\d{2}\.\d{3}\s+1\s+/)
-    expect(output).to match(/pass\s+\d{2}:\d{2}\.\d{3}\s+2\s+/)
-    expect(output).to match(/__unknown__\s+\d{2}:\d{2}\.\d{3}\s+1\s+/)
-  end
+  context "rspec" do
+    specify "it works", :aggregate_failures do
+      output = run_rspec("tag_prof", env: {"TAG_PROF" => "type"})
+
+      expect(output).to include("TagProf report for type")
+      expect(output).to match(/type\s+time\s+total\s+%total\s+%time\s+avg\n\n/)
+      expect(output).to match(/fail\s+\d{2}:\d{2}\.\d{3}\s+1\s+/)
+      expect(output).to match(/pass\s+\d{2}:\d{2}\.\d{3}\s+2\s+/)
+      expect(output).to match(/__unknown__\s+\d{2}:\d{2}\.\d{3}\s+1\s+/)
+    end
+
+    specify "html report" do
+      output = run_rspec("tag_prof", env: {"TAG_PROF" => "type", "TAG_PROF_FORMAT" => "html"})
 
-  specify "html report" do
-    output = run_rspec("tag_prof", env: {"TAG_PROF" => "type", "TAG_PROF_FORMAT" => "html"})
+      expect(output).to include("TagProf report generated:")
+
+      expect(File.exist?("tmp/test_prof/tag-prof.html")).to eq true
+    end
 
-    expect(output).to include("TagProf report generated:")
+    context "with events" do
+      specify "it works", :aggregate_failures do
+        output = run_rspec(
+          "tag_prof",
+          env: {"TAG_PROF" => "type", "TAG_PROF_EVENT" => "test.event,test.event2"}
+        )
 
-    expect(File.exist?("tmp/test_prof/tag-prof.html")).to eq true
+        expect(output).to include("TagProf report for type")
+        expect(output).to match(/type\s+time\s+test\.event\s+test.event2\s+total\s+%total\s+%time\s+avg\n\n/)
+        expect(output).to match(/fail\s+\d{2}:\d{2}\.\d{3}\s+00:23.000\s+00:00.000\s+1\s+/)
+        expect(output).to match(/pass\s+\d{2}:\d{2}\.\d{3}\s+00:12.420\s+00:14.041\s+2\s+/)
+        expect(output).to match(/__unknown__\s+\d{2}:\d{2}\.\d{3}\s+00:00.000\s+00:00.000\s+1\s+/)
+      end
+    end
   end
 
-  context "with events" do
-    specify "it works", :aggregate_failures do
-      output = run_rspec(
-        "tag_prof",
-        env: {"TAG_PROF" => "type", "TAG_PROF_EVENT" => "test.event,test.event2"}
-      )
+  context "minitest" do
+    subject(:output) { run_minitest(path, env: env, chdir: chdir) }
+    let(:path) { "tag_prof" }
+    let(:env) { {"TAG_PROF" => "type"} }
+    let(:chdir) { nil }
 
+    it "includes tag prof report" do
       expect(output).to include("TagProf report for type")
-      expect(output).to match(/type\s+time\s+test\.event\s+test.event2\s+total\s+%total\s+%time\s+avg\n\n/)
-      expect(output).to match(/fail\s+\d{2}:\d{2}\.\d{3}\s+00:23.000\s+00:00.000\s+1\s+/)
-      expect(output).to match(/pass\s+\d{2}:\d{2}\.\d{3}\s+00:12.420\s+00:14.041\s+2\s+/)
-      expect(output).to match(/__unknown__\s+\d{2}:\d{2}\.\d{3}\s+00:00.000\s+00:00.000\s+1\s+/)
+    end
+
+    it "includes tag prof report headers" do
+      expect(output).to match(/type\s+time\s+total\s+%total\s+%time\s+avg\n\n/)
+    end
+
+    context "when test suite is run from test file directory" do
+      it "includes total time spent and number of files tested for integrations directory" do
+        expect(output).to match(/integrations\s+\d{2}:\d{2}\.\d{3}\s+1\s+/)
+      end
+    end
+
+    context "when test suite is run from app root directory" do
+      let(:chdir) { File.expand_path("") }
+      let(:path) { "spec/integrations/fixtures/minitest/tag_prof" }
+
+      it "includes total time spent and number of files tested for integrations directory" do
+        expect(output).to match(/integrations\s+\d{2}:\d{2}\.\d{3}\s+1\s+/)
+      end
+    end
+
+    context "when test suite is run with event_prof" do
+      let(:env) { {"TAG_PROF" => "type", "TAG_PROF_EVENT" => "test.event"} }
+      it "includes event name in tag prof report headers" do
+        expect(output).to match(/test.event/)
+      end
+
+      it "includes event time in data reported for integrations directory " do
+        expect(output).to match(/integrations\s+\d{2}:\d{2}\.\d{3}\s+\d{2}:\d{2}\.\d{3}\s+1\s+/)
+      end
+    end
+
+    context "when report format is HTML" do
+      let(:env) { {"TAG_PROF" => "type", "TAG_PROF_FORMAT" => "html"} }
+
+      it "generates an html report and gives its location" do
+        output = run_rspec("tag_prof", env: env)
+
+        expect(output).to include("TagProf report generated:")
+        expect(File.exist?("tmp/test_prof/tag-prof.html")).to eq true
+      end
+    end
+
+    context "when root test directory is not named 'test' or 'spec'" do
+      let(:path) { "tmp/subdirectory_not_found" }
+      let(:chdir) { File.expand_path("") }
+
+      before do
+        test_content = File.read("spec/integrations/fixtures/minitest/tag_prof_fixture.rb")
+        File.write("tmp/subdirectory_not_found_fixture.rb", test_content)
+      end
+
+      it "reports the statistic for the test result with an explicit error message" do
+        expect(output).to match(/__unknown__/)
+      end
+
+      after do
+        File.delete("tmp/subdirectory_not_found_fixture.rb")
+      end
     end
   end
 end

spec/support/ar_models.rb

@@ -6,6 +6,7 @@
 require "active_record"
 require "fabrication"
 require "test_prof"
+require "active_support/inflector"
 require "test_prof/factory_bot"
 
 require "activerecord-jdbc-adapter" if defined? JRUBY_VERSION