Add profiling info

This commit is contained in:
Michael Miller 2021-05-16 20:21:04 -06:00
parent 4bb4c2f16e
commit ebf04b360e
No known key found for this signature in database
GPG key ID: FB9F12F7C646A4AD
6 changed files with 58 additions and 15 deletions

View file

@ -0,0 +1,32 @@
require "../../profile"
require "./runtime"
module Spectator::Formatting::Components
struct Profile
def initialize(@profile : Spectator::Profile)
end
def to_s(io)
io << "Top "
io << @profile.size
io << " slowest examples ("
io << Runtime.new(@profile.time)
io << ", "
io << @profile.percentage.round(2)
io.puts "% of total time):"
@profile.each do |example|
example_profile(io, example)
end
end
private def example_profile(io, example)
io << " "
io.puts example
io << " "
io << Runtime.new(example.result.elapsed).colorize.bold
io << ' '
io.puts example.location
end
end
end

View file

@ -1,4 +1,6 @@
require "../example"
require "../profile"
require "../report"
module Spectator::Formatting
# Structure indicating the test suite has started.
@ -10,6 +12,9 @@ module Spectator::Formatting
# Structure containing a subset of examples from the test suite.
record ExampleSummaryNotification, examples : Enumerable(Example)
# Structure containing profiling information.
record ProfileNotification, profile : Profile
# Structure containing summarized information from the outcome of the test suite.
record SummaryNotification, report : Report
end

View file

@ -48,7 +48,8 @@ module Spectator::Formatting
# Invoked after testing completes with profiling information.
# This method is only called if profiling is enabled.
# Called after `#dump_failures` and before `#dump_summary`.
def dump_profile(_notification)
def dump_profile(notification)
io.puts Components::Profile.new(notification.profile)
end
# Invoked after testing completes with summarized information from the test suite.

View file

@ -8,7 +8,16 @@ module Spectator
# Creates the profiling information.
# The *slowest* results must already be sorted, longest time first.
private def initialize(@slowest : Array(Example), @total_time)
def initialize(@slowest : Array(Example), @total_time)
end
# Produces the profile from a report.
def self.generate(examples, size = 10)
finished = examples.select(&.finished?).to_a
total_time = finished.sum(&.result.elapsed)
sorted_examples = finished.sort_by(&.result.elapsed)
slowest = sorted_examples.last(size).reverse
new(slowest, total_time)
end
# Number of results in the profile.
@ -26,17 +35,9 @@ module Spectator
@slowest.sum(&.result.elapsed)
end
# Percentage (from 0 to 1) of time the results in this profile took compared to all examples.
# Percentage (from 0 to 100) of time the results in this profile took compared to all examples.
def percentage
time / @total_time
end
# Produces the profile from a report.
def self.generate(report, size = 10)
examples = report.to_a
sorted_examples = examples.sort_by(&.result.elapsed)
slowest = sorted_examples.last(size).reverse
self.new(slowest, report.example_runtime)
time / @total_time * 100
end
end
end

View file

@ -36,7 +36,7 @@ module Spectator
end
# Triggers the 'dump' events.
private def summarize(report)
private def summarize(report, profile)
formatter.start_dump
notification = Formatting::ExampleSummaryNotification.new(report.pending)
@ -45,7 +45,10 @@ module Spectator
notification = Formatting::ExampleSummaryNotification.new(report.failures)
formatter.dump_failures(notification)
formatter.dump_profile(nil)
if profile
notification = Formatting::ProfileNotification.new(profile)
formatter.dump_profile(notification)
end
notification = Formatting::SummaryNotification.new(report)
formatter.dump_summary(notification)

View file

@ -31,7 +31,8 @@ module Spectator
stop
report = Report.generate(@examples, elapsed, nil) # TODO: Provide random seed.
summarize(report)
profile = Profile.generate(@examples) if @run_flags.profile? && report.counts.run > 0
summarize(report, profile)
false # TODO: Report real result