Skip to content

Commit

Permalink
Overhaul display of a Trial
Browse files Browse the repository at this point in the history 
Use layout inspired by hyperfine, with an added histogram.
  • Loading branch information
@tecosaur
tecosaur committed Jun 9, 2021
1 parent 134675b commit bfa8691
Show file tree
Hide file tree
Showing 3 changed files with 175 additions and 47 deletions.
23 changes: 11 additions & 12 deletions README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -50,18 +50,17 @@ julia> using BenchmarkTools
# The `setup` expression is run once per sample, and is not included in the
# timing results. Note that each sample can require multiple evaluations
# benchmark kernel evaluations. See the BenchmarkTools manual for details.
julia> @benchmark sin(x) setup=(x=rand())
BenchmarkTools.Trial:
memory estimate: 0 bytes
allocs estimate: 0
--------------
minimum time: 4.248 ns (0.00% GC)
median time: 4.631 ns (0.00% GC)
mean time: 5.502 ns (0.00% GC)
maximum time: 60.995 ns (0.00% GC)
--------------
samples: 10000
evals/sample: 1000
julia> @benchmark sort(data) setup=(data=rand(10))
BechmarkTools.Trial:
10000 samples with 968 evaulations took a median time of 90.902 ns (0.00% GC)
Time (mean ± σ): 94.936 ns ± 47.797 ns (GC: 2.78% ± 5.03%)
Range (min … max): 77.655 ns … 954.823 ns (GC: 0.00% … 87.94%)

▁▃▅▆▇█▇▆▅▂▁
▂▂▃▃▄▅▆▇███████████▇▆▄▄▃▃▂▂▂▂▂▂▂▂▂▂▂▁▂▁▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂
77.7 ns Histogram: frequency by time 137 ns

Memory estimate: 160 bytes, allocs estimate: 1.
```

For quick sanity checks, one can use the [`@btime` macro](https://github.com/JuliaCI/BenchmarkTools.jl/blob/master/doc/manual.md#benchmarking-basics), which is a convenience wrapper around `@benchmark` whose output is analogous to Julia's built-in [`@time` macro](https://docs.julialang.org/en/v1/base/base/#Base.@time):
Expand Down
23 changes: 11 additions & 12 deletions docs/src/index.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,18 +16,17 @@ julia> using BenchmarkTools
# The `setup` expression is run once per sample, and is not included in the
# timing results. Note that each sample can require multiple evaluations
# benchmark kernel evaluations. See the BenchmarkTools manual for details.
julia> @benchmark sin(x) setup=(x=rand())
BenchmarkTools.Trial:
memory estimate: 0 bytes
allocs estimate: 0
--------------
minimum time: 4.248 ns (0.00% GC)
median time: 4.631 ns (0.00% GC)
mean time: 5.502 ns (0.00% GC)
maximum time: 60.995 ns (0.00% GC)
--------------
samples: 10000
evals/sample: 1000
julia> @benchmark sort(data) setup=(data=rand(10))
BechmarkTools.Trial:
10000 samples with 968 evaulations took a median time of 90.902 ns (0.00% GC)
Time (mean ± σ): 94.936 ns ± 47.797 ns (GC: 2.78% ± 5.03%)
Range (min … max): 77.655 ns … 954.823 ns (GC: 0.00% … 87.94%)

▁▃▅▆▇█▇▆▅▂▁
▂▂▃▃▄▅▆▇███████████▇▆▄▄▃▃▂▂▂▂▂▂▂▂▂▂▂▁▂▁▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂▂
77.7 ns Histogram: frequency by time 137 ns

Memory estimate: 160 bytes, allocs estimate: 1.
```

For quick sanity checks, one can use the [`@btime` macro](https://github.com/JuliaCI/BenchmarkTools.jl/blob/master/doc/manual.md#benchmarking-basics), which is a convenience wrapper around `@benchmark` whose output is analogous to Julia's built-in [`@time` macro](https://docs.julialang.org/en/v1/base/base/#Base.@time):
Expand Down
176 changes: 153 additions & 23 deletions src/trials.jl
View file
Original file line number Diff line number Diff line change
Expand Up @@ -120,6 +120,7 @@ end

Statistics.median(trial::Trial) = TrialEstimate(trial, median(trial.times), median(trial.gctimes))
Statistics.mean(trial::Trial) = TrialEstimate(trial, mean(trial.times), mean(trial.gctimes))
Statistics.std(trial::Trial) = TrialEstimate(trial, std(trial.times), std(trial.gctimes))

Base.isless(a::TrialEstimate, b::TrialEstimate) = isless(time(a), time(b))

Expand Down Expand Up @@ -289,6 +290,32 @@ function withtypename(f, io, t)
end
end

function bindata(sorteddata, nbins)
min, max = sorteddata[[1; end]]
Δ = (max - min) / nbins
bins = zeros(nbins)
lastpos = 0
for i ∈ 1:nbins
pos = searchsortedlast(sorteddata, min + i * Δ)
bins[i] = pos - lastpos
lastpos = pos
end
bins
end

function asciihist(bins, height=1)
histbars = ['▁', '▂', '▃', '▄', '▅', '▆', '▇', '█']
if minimum(bins) == 0
barheights = 2 .+ round.(Int, (height * length(histbars) - 2) * bins ./ maximum(bins))
barheights[bins .== 0] .= 1
else
barheights = 1 .+ round.(Int, (height * length(histbars) - 1) * bins ./ maximum(bins))
end
[let bheight = barheights[b] - (h-1) * length(histbars)
bheight < 1 ? ' ' : histbars[minimum([length(histbars), bheight])]
end for h in height:-1:1, b in 1:length(bins)]
end

_summary(io, t, args...) = withtypename(() -> print(io, args...), io, t)

Base.summary(io::IO, t::Trial) = _summary(io, t, prettytime(time(t)))
Expand All @@ -313,36 +340,139 @@ Base.show(io::IO, t::TrialJudgement) = _show(io, t)

function Base.show(io::IO, ::MIME"text/plain", t::Trial)
if length(t) > 0
min = minimum(t)
max = maximum(t)
med = median(t)
avg = mean(t)
std = Statistics.std(t)
min = minimum(t)
max = maximum(t)

medtime, medgc = prettytime(time(med)), prettypercent(gcratio(med))
avgtime, avggc = prettytime(time(avg)), prettypercent(gcratio(avg))
stdtime, stdgc = prettytime(time(std)), prettypercent(Statistics.std(t.gctimes ./ t.times))
mintime, mingc = prettytime(time(min)), prettypercent(gcratio(min))
maxtime, maxgc = prettytime(time(max)), prettypercent(gcratio(max))

memorystr = string(prettymemory(memory(min)))
allocsstr = string(allocs(min))
minstr = string(prettytime(time(min)), " (", prettypercent(gcratio(min)), " GC)")
maxstr = string(prettytime(time(max)), " (", prettypercent(gcratio(max)), " GC)")
medstr = string(prettytime(time(med)), " (", prettypercent(gcratio(med)), " GC)")
meanstr = string(prettytime(time(avg)), " (", prettypercent(gcratio(avg)), " GC)")
else
memorystr = "N/A"
allocsstr = "N/A"
minstr = "N/A"
maxstr = "N/A"
medstr = "N/A"
meanstr = "N/A"
medtime, medgc = "N/A", "N/A"
avgtime, avggc = "N/A", "N/A"
stdtime, stdgc = "N/A", "N/A"
mintime, mingc = "N/A", "N/A"
maxtime, maxgc = "N/A", "N/A"
memorystr, allocsstr = "N/A", "N/A"
end
println(io, "BenchmarkTools.Trial: ")

lmaxtimewidth = maximum(length.([medtime, avgtime, mintime]))
rmaxtimewidth = maximum(length.([stdtime, maxtime]))
lmaxgcwidth = maximum(length.([medgc, avggc, mingc]))
rmaxgcwidth = maximum(length.([stdgc, maxgc]))

# Main stats

pad = get(io, :pad, "")
println(io, pad, " memory estimate: ", memorystr)
println(io, pad, " allocs estimate: ", allocsstr)
println(io, pad, " --------------")
println(io, pad, " minimum time: ", minstr)
println(io, pad, " median time: ", medstr)
println(io, pad, " mean time: ", meanstr)
println(io, pad, " maximum time: ", maxstr)
println(io, pad, " --------------")
println(io, pad, " samples: ", length(t))
print(io, pad, " evals/sample: ", t.params.evals)
print(io, "BechmarkTools.Trial: ")
printstyled(io, length(t); bold=true)
print(io, " samples with ")
printstyled(io, t.params.evals; bold=true)
print(io, " evaluations.")

print(io, "\n", pad, " Time ")
printstyled(io, "("; color=:light_black)
printstyled(io, "median"; color=:blue, bold=true)
printstyled(io, "): "; color=:light_black)
printstyled(io, lpad(medtime, lmaxtimewidth), rpad(" ", rmaxtimewidth + 5); color=:blue, bold=true)
printstyled(io, "┊"; color=:light_black)
print(io, " GC ")
printstyled(io, "("; color=:light_black)
print(io, "median")
printstyled(io, "): "; color=:light_black)
print(io, lpad(medgc, lmaxgcwidth))

print(io, "\n", pad, " Time ")
printstyled(io, "("; color=:light_black)
printstyled(io, "mean"; color=:green, bold=true)
print(io, " ± ")
printstyled(io, "σ"; color=:green)
printstyled(io, "): "; color=:light_black)
printstyled(io, lpad(avgtime, lmaxtimewidth); color=:green, bold=true)
print(io, " ± ")
printstyled(io, lpad(stdtime, rmaxtimewidth); color=:green)
print(io, " ")
printstyled(io, "┊"; color=:light_black)
print(io, " GC ")
printstyled(io, "("; color=:light_black)
print(io, "mean ± σ")
printstyled(io, "): "; color=:light_black)
print(io, lpad(avggc, lmaxgcwidth), " ± ", lpad(stdgc, rmaxgcwidth))

print(io, "\n", pad, " Range ")
printstyled(io, "("; color=:light_black)
printstyled(io, "min"; color=:cyan, bold=true)
print(io, " … ")
printstyled(io, "max"; color=:magenta)
printstyled(io, "): "; color=:light_black)
printstyled(io, lpad(mintime, lmaxtimewidth); color=:cyan, bold=true)
print(io, " … ")
printstyled(io, lpad(maxtime, rmaxtimewidth); color=:magenta)
print(io, " ")
printstyled(io, "┊"; color=:light_black)
print(io, " GC ")
printstyled(io, "("; color=:light_black)
print(io, "min … max")
printstyled(io, "): "; color=:light_black)
print(io, lpad(mingc, lmaxgcwidth), " … ", lpad(maxgc, rmaxgcwidth))

# Histogram

histtimes = t.times[1:round(Int, 0.99*end)]
totalwidth = 45 + lmaxtimewidth + rmaxtimewidth
bins, logbins = bindata(histtimes, totalwidth), false
# if median size of (bins with >10% average data/bin) is less than 5% of max bin size, log the bin sizes
if median(filter(b -> b > 0.1 * length(t.times) / totalwidth, bins)) / maximum(bins) < 0.05
bins, logbins = log.(1 .+ bins), true
end
hist = asciihist(bins, 2)
maxbin = maximum(bins)

delta1 = (histtimes[end] - histtimes[1]) / (totalwidth - 1)
medpos = 1 + round(Int, (histtimes[length(histtimes) ÷ 2] - histtimes[1]) / delta1)
avgpos = 1 + round(Int, (mean(histtimes) - histtimes[1]) / delta1)

print(io, "\n")
for histrow in eachrow(hist)
print(io, "\n", pad, " ")
for (i, bar) in enumerate(histrow)
color = :default
if i == avgpos color = :green end
if i == medpos color = :blue end
printstyled(io, bar; color=color)
end
end

function remtrailingzeros(timestr)
if ! isnothing(match(r"\.0+", timestr))
replace(timestr, r"\.0+" => "")
else
replace(timestr, r"(\.\d+?)0+" => s"\1")
end
end
minhisttime, maxhisttime = remtrailingzeros.(prettytime.(round.(histtimes[[1; end]], sigdigits=3)))

caption = "Histogram: " * ( logbins ? "log(frequency)" : "frequency" ) * " by time"
print(io, "\n", pad, " ", minhisttime)
printstyled(io, " " ^ ((totalwidth - length(caption)) ÷ 2 - length(minhisttime)), caption; color=:light_black)
print(io, lpad(maxhisttime, ceil(Int, (totalwidth - length(caption)) / 2)))

# Memory info

print(io, "\n\n", pad, " Memory estimate")
printstyled(io, ": "; color=:light_black)
printstyled(io, memorystr; color=:yellow)
print(io, ", allocs estimate")
printstyled(io, ": "; color=:light_black)
printstyled(io, allocsstr; color=:yellow)
print(io, ".")
end

function Base.show(io::IO, ::MIME"text/plain", t::TrialEstimate)
Expand Down

0 comments on commit bfa8691

Please sign in to comment.