how to find the time taken for each testcase in Rspec

Question

I am using Rspec in my project where I would like to print the time taken by each testcase, Is there any way Rspec is providing any prebuilt function? I can take the starting time of the testcase by example.execution_result.started_at but I don't know how to take the end time of testcase, If I can take the end time, then I can subtract the end time from starting time to get the time duration for each testcase. Is there any one help me at this place? I have written this code

around(:each) do |example|
  startTime=Time.now
  var=example.run
  puts var
  endTime=Time.now
  duration=endTime-startTime
  puts "Time Taken->#{duration.to_f/60.to_f}"
end

But I strongly believe Rspec must be giving some predefined method to return the duration of each testcase, do you anyone know that?

Answer 1

If you want more detail and/or want to control the formatting, you can create a custom formatter.

For example, given the following specs:

RSpec.describe 'some thing' do
  it 'does stuff' do
    sleep(3)
    raise('some error')
  end

  it 'does more stuff' do
    sleep(2)
  end
end

Output - Text

We can add a custom formatter to output the full test description, status, run time and exception:

class ExampleFormatter < RSpec::Core::Formatters::JsonFormatter
  RSpec::Core::Formatters.register self

  def close(_notification)
    @output_hash[:examples].map do |ex|
      output.puts [ex[:full_description], ex[:status], ex[:run_time], ex[:exception]].join(' | ')
    end
  end
end

RSpec.configure do |c|
  c.formatter = ExampleFormatter
end

This gives us:

some thing does stuff | failed | 3.010178 | {:class=>"RuntimeError", :message=>"some error", :backtrace=>["my_spec.rb:21:in `block... (truncated for example)
some thing does more stuff | passed | 2.019578 | 

The output can be modified to add headers, have nicer formatting, etc.

Output - CSV

The formatter can be modified to output to a CSV:

require 'csv'

class ExampleFormatter < RSpec::Core::Formatters::JsonFormatter
  RSpec::Core::Formatters.register self

  def close(_notification)
    with_headers = {write_headers: true, headers: ['Example', 'Status', 'Run Time', 'Exception']}
    CSV.open(output.path, 'w', with_headers) do |csv|
      @output_hash[:examples].map do |ex|
        csv << [ex[:full_description], ex[:status], ex[:run_time], ex[:exception]]
      end
    end
  end
end

RSpec.configure do |c|
  c.add_formatter(ExampleFormatter, 'my_spec_log.csv')
end

Which gives:

Example,Status,Run Time,Exception
some thing does stuff,failed,3.020176,"{:class=>""RuntimeError"", :message=>""some error"", :backtrace=>[""my_spec.rb:25:in `block...(truncated example)"
some thing does more stuff,passed,2.020113,