Skip to content

Commit 45d40be

Browse files
committed
compact + percentiles
1 parent c021029 commit 45d40be

File tree

1 file changed

+130
-98
lines changed

1 file changed

+130
-98
lines changed

src/trials.jl

Lines changed: 130 additions & 98 deletions
Original file line numberDiff line numberDiff line change
@@ -118,9 +118,13 @@ function Base.maximum(trial::Trial)
118118
return TrialEstimate(trial, trial.times[i], trial.gctimes[i])
119119
end
120120

121+
Statistics.quantile(trial::Trial, p::Real) = TrialEstimate(trial, quantile(trial.times, p), quantile(trial.gctimes, p))
121122
Statistics.median(trial::Trial) = TrialEstimate(trial, median(trial.times), median(trial.gctimes))
122123
Statistics.mean(trial::Trial) = TrialEstimate(trial, mean(trial.times), mean(trial.gctimes))
123124
Statistics.std(trial::Trial) = TrialEstimate(trial, std(trial.times), std(trial.gctimes))
125+
# mean absolute deviation
126+
meanad(xs::AbstractArray; mean = Statistics.mean(xs)) = Statistics.mean(x -> abs(x - mean), xs)
127+
meanad(trial::Trial) = TrialEstimate(trial, meanad(trial.times), meanad(trial.gctimes))
124128

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

@@ -279,6 +283,10 @@ function prettymemory(b)
279283
return string(@sprintf("%.2f", value), " ", units)
280284
end
281285

286+
function prettycount(n::Integer)
287+
join(reverse(join.(reverse.(Iterators.partition(digits(n), 3)))), '_')
288+
end
289+
282290
function withtypename(f, io, t)
283291
needtype = get(io, :typeinfo, Nothing) !== typeof(t)
284292
if needtype
@@ -338,11 +346,13 @@ Base.show(io::IO, t::TrialEstimate) = _show(io, t)
338346
Base.show(io::IO, t::TrialRatio) = _show(io, t)
339347
Base.show(io::IO, t::TrialJudgement) = _show(io, t)
340348

349+
_percentile() = 99 # to tweak this live, TODO remove
350+
341351
function Base.show(io::IO, ::MIME"text/plain", t::Trial)
342352

343353
pad = get(io, :pad, "")
344-
print(io, "BenchmarkTools.Trial: ", length(t), " sample", if length(t) > 1 "s" else "" end,
345-
" with ", t.params.evals, " evaluation", if t.params.evals > 1 "s" else "" end ,".\n")
354+
355+
showpercentile = _percentile()
346356

347357
perm = sortperm(t.times)
348358
times = t.times[perm]
@@ -351,21 +361,29 @@ function Base.show(io::IO, ::MIME"text/plain", t::Trial)
351361
if length(t) > 1
352362
med = median(t)
353363
avg = mean(t)
354-
std = Statistics.std(t)
355364
min = minimum(t)
356365
max = maximum(t)
357-
358-
medtime, medgc = prettytime(time(med)), prettypercent(gcratio(med))
359-
avgtime, avggc = prettytime(time(avg)), prettypercent(gcratio(avg))
360-
stdtime, stdgc = prettytime(time(std)), prettypercent(Statistics.std(gctimes ./ times))
361-
mintime, mingc = prettytime(time(min)), prettypercent(gcratio(min))
362-
maxtime, maxgc = prettytime(time(max)), prettypercent(gcratio(max))
363-
364-
memorystr = string(prettymemory(memory(min)))
365-
allocsstr = string(allocs(min))
366+
q99 = quantile(t, showpercentile/100)
367+
368+
mintime = prettytime(time(min))
369+
medtime = prettytime(time(med))
370+
avgtime = prettytime(time(avg))
371+
q99time = prettytime(time(q99))
372+
373+
# Mean GC time is just that; then we take the percentage of the mean time
374+
avggctime, avegcpercent = prettytime(mean(gctimes)), prettypercent(mean(gctimes) / mean(times))
375+
q99gctime = prettytime(quantile(gctimes, showpercentile/100))
376+
# Maximum GC time has a percentage which is of the same run, not necc. the longest run
377+
_t, _i = findmax(gctimes)
378+
maxgctime, maxgcpercent = prettytime(_t), prettypercent(_t / times[_i])
379+
380+
memorystr = prettymemory(memory(min))
381+
allocsstr = prettycount(allocs(min)) * (allocs(min)==1 ? " allocation" : " allocations")
366382
elseif length(t) == 1
383+
# TODO update this!
384+
367385
print(io, pad, " Single result which took ")
368-
printstyled(io, prettytime(times[1]); color=:blue)
386+
printstyled(io, prettytime(times[1]); color=:light_blue)
369387
print(io, " (", prettypercent(gctimes[1]/times[1]), " GC) ")
370388
print(io, "to evaluate,\n")
371389
print(io, pad, " with a memory estimate of ")
@@ -379,74 +397,58 @@ function Base.show(io::IO, ::MIME"text/plain", t::Trial)
379397
return
380398
end
381399

382-
lmaxtimewidth = maximum(length.((medtime, avgtime, mintime)))
383-
rmaxtimewidth = maximum(length.((stdtime, maxtime)))
384-
lmaxgcwidth = maximum(length.((medgc, avggc, mingc)))
385-
rmaxgcwidth = maximum(length.((stdgc, maxgc)))
386-
387-
# Main stats
388-
389-
print(io, pad, " Range ")
390-
printstyled(io, "("; color=:light_black)
391-
printstyled(io, "min"; color=:cyan, bold=true)
392-
print(io, "")
393-
printstyled(io, "max"; color=:magenta)
394-
printstyled(io, "): "; color=:light_black)
395-
printstyled(io, lpad(mintime, lmaxtimewidth); color=:cyan, bold=true)
396-
print(io, "")
397-
printstyled(io, lpad(maxtime, rmaxtimewidth); color=:magenta)
398-
print(io, " ")
399-
printstyled(io, ""; color=:light_black)
400-
print(io, " GC ")
401-
printstyled(io, "("; color=:light_black)
402-
print(io, "min … max")
403-
printstyled(io, "): "; color=:light_black)
404-
print(io, lpad(mingc, lmaxgcwidth), "", lpad(maxgc, rmaxgcwidth))
405-
406-
print(io, "\n", pad, " Time ")
407-
printstyled(io, "("; color=:light_black)
408-
printstyled(io, "median"; color=:blue, bold=true)
409-
printstyled(io, "): "; color=:light_black)
410-
printstyled(io, lpad(medtime, lmaxtimewidth), rpad(" ", rmaxtimewidth + 5); color=:blue, bold=true)
411-
printstyled(io, ""; color=:light_black)
412-
print(io, " GC ")
413-
printstyled(io, "("; color=:light_black)
414-
print(io, "median")
415-
printstyled(io, "): "; color=:light_black)
416-
print(io, lpad(medgc, lmaxgcwidth))
417-
418-
print(io, "\n", pad, " Time ")
419-
printstyled(io, "("; color=:light_black)
420-
printstyled(io, "mean"; color=:green, bold=true)
421-
print(io, " ± ")
422-
printstyled(io, "σ"; color=:green)
423-
printstyled(io, "): "; color=:light_black)
424-
printstyled(io, lpad(avgtime, lmaxtimewidth); color=:green, bold=true)
425-
print(io, " ± ")
426-
printstyled(io, lpad(stdtime, rmaxtimewidth); color=:green)
427-
print(io, " ")
428-
printstyled(io, ""; color=:light_black)
429-
print(io, " GC ")
430-
printstyled(io, "("; color=:light_black)
431-
print(io, "mean ± σ")
432-
printstyled(io, "): "; color=:light_black)
433-
print(io, lpad(avggc, lmaxgcwidth), " ± ", lpad(stdgc, rmaxgcwidth))
400+
# New block
401+
# println(io, "┌ BenchmarkTools.Trial:")
402+
println(io, "BenchmarkTools.Trial:")
403+
404+
print(io, pad, "")
405+
printstyled(io, "min "; color=:default)
406+
printstyled(io, mintime; color=:default, bold=true)
407+
print(io, ", ")
408+
printstyled(io, "median "; color=:light_blue)
409+
printstyled(io, medtime; color=:light_blue, bold=true)
410+
printstyled(io, " (½)"; color=:light_blue)
411+
print(io, ", ")
412+
printstyled(io, "mean "; color=:green)
413+
printstyled(io, avgtime; color=:green, bold=true)
414+
printstyled(io, " (*)"; color=:green)
415+
print(io, ", ")
416+
print(io, showpercentile, "ᵗʰ ")
417+
printstyled(q99time; bold=true)
418+
println(io)
419+
420+
print(io, pad, "", allocsstr)
421+
if allocs(min) != 0
422+
println(io, ", ", memorystr)
423+
else
424+
println(io)
425+
end
426+
if !all(iszero, gctimes)
427+
print(io, pad, "", "GC time: mean ", avggctime)
428+
printstyled(io, " (", avegcpercent, ")"; color=:green)
429+
println(io, ", max ", maxgctime, " (", maxgcpercent, ")")
430+
end
431+
432+
print(io, pad, "", prettycount(length(t)), " sample", if length(t) > 1 "s" else "" end,
433+
", each ", prettycount(t.params.evals), " evaluation", if t.params.evals > 1 "s" else "" end , ":")
434434

435435
# Histogram
436436

437-
histquantile = 0.99
438-
# The height and width of the printed histogram in characters.
437+
# Axis ends at this quantile, same as displayed time, ideally:
438+
histquantile = showpercentile/100
439+
# The height and width of the printed histogram in characters:
439440
histheight = 2
440-
histwidth = 42 + lmaxtimewidth + rmaxtimewidth
441+
histwidth = 74 # fits into 78 chars, as does 1st line with 4 times
441442

443+
# This needs sorted times:
442444
histtimes = times[1:round(Int, histquantile*end)]
443-
histmin = get(io, :histmin, first(histtimes))
444-
histmax = get(io, :histmax, last(histtimes))
445+
histmin = get(io, :histmin, low_edge(histtimes))
446+
histmax = get(io, :histmax, high_edge(histtimes))
445447
logbins = get(io, :logbins, nothing)
446448
bins = bindata(histtimes, histwidth - 1, histmin, histmax)
447449
append!(bins, [1, floor((1-histquantile) * length(times))])
448450
# if median size of (bins with >10% average data/bin) is less than 5% of max bin size, log the bin sizes
449-
if logbins === true || (logbins === nothing && median(filter(b -> b > 0.1 * length(times) / histwidth, bins)) / maximum(bins) < 0.05)
451+
if logbins === true # || (logbins === nothing && median(filter(b -> b > 0.1 * length(times) / histwidth, bins)) / maximum(bins) < 0.05)
450452
bins, logbins = log.(1 .+ bins), true
451453
else
452454
logbins = false
@@ -463,44 +465,74 @@ function Base.show(io::IO, ::MIME"text/plain", t::Trial)
463465
medpos, avgpos = 1, 1
464466
end
465467

466-
print(io, "\n")
468+
# Above the histogram bars, print markers for special ones:
469+
print(io, "\n", pad, "")
470+
for i in axes(hist, 2)
471+
if i == avgpos
472+
printstyled(io, "*", color=:green, bold=true) # or μ, or t̄?
473+
elseif i == medpos || (medpos==avgpos && i==medpos-1)
474+
# marker for "median" is moved one to the left if they collide
475+
printstyled(io, "½", color=:light_blue) # sadly "㊿" is often double wide. ½, |, ‖, ↓ maybe?
476+
else
477+
print(io, " ")
478+
end
479+
end
480+
467481
for r in axes(hist, 1)
468-
print(io, "\n", pad, " ")
482+
print(io, "\n", pad, " ")
469483
for (i, bar) in enumerate(view(hist, r, :))
470484
color = :default
471-
if i == avgpos color = :green end
472-
if i == medpos color = :blue end
485+
if i == avgpos
486+
color = :green
487+
elseif i == medpos # if the bars co-incide, colour the mean? matches labels
488+
color = :light_blue
489+
elseif bins[i] == 0
490+
color = :light_black
491+
end
473492
printstyled(io, bar; color=color)
474493
end
475494
end
476495

477496
remtrailingzeros(timestr) = replace(timestr, r"\.?0+ " => " ")
478497
minhisttime, maxhisttime = remtrailingzeros.(prettytime.(round.([histmin, histmax], sigdigits=3)))
479498

480-
print(io, "\n", pad, " ", minhisttime)
481-
caption = "Histogram: " * ( logbins ? "log(frequency)" : "frequency" ) * " by time"
482-
if logbins
483-
printstyled(io, " " ^ ((histwidth - length(caption)) ÷ 2 - length(minhisttime)); color=:light_black)
484-
printstyled(io, "Histogram: "; color=:light_black)
485-
printstyled(io, "log("; bold=true, color=:light_black)
486-
printstyled(io, "frequency"; color=:light_black)
487-
printstyled(io, ")"; bold=true, color=:light_black)
488-
printstyled(io, " by time"; color=:light_black)
489-
else
490-
printstyled(io, " " ^ ((histwidth - length(caption)) ÷ 2 - length(minhisttime)), caption; color=:light_black)
491-
end
499+
print(io, "\n", pad, "", minhisttime)
500+
# Caption is only printed if logbins has been selected:
501+
caption = logbins ? "log(counts) by time" : ""
502+
printstyled(io, " " ^ ((histwidth - length(caption)) ÷ 2 - length(minhisttime)), caption; color=:light_black)
492503
print(io, lpad(maxhisttime, ceil(Int, (histwidth - length(caption)) / 2) - 1), " ")
493-
printstyled(io, "<"; bold=true)
494-
495-
# Memory info
496-
497-
print(io, "\n\n", pad, " Memory estimate")
498-
printstyled(io, ": "; color=:light_black)
499-
printstyled(io, memorystr; color=:yellow)
500-
print(io, ", allocs estimate")
501-
printstyled(io, ": "; color=:light_black)
502-
printstyled(io, allocsstr; color=:yellow)
503-
print(io, ".")
504+
printstyled(io, "+")
505+
end
506+
507+
# These two functions allow endpoints 6, 7, 8, 10, 15, 20, 30, 40, ... perhaps too coarse?
508+
# exp.(range(log(1), log(10), length=11)) ≈ [1, 1.25, 1.6, 2, 2.5, 3.2, 4, 5, 6.3, 8, 10]
509+
510+
# round.(0:0.01:10, sigdigits=3, base=2) |> unique # looks good in 1:10, not great outside
511+
function low_edge(times)
512+
# return 0
513+
min = minimum(times)
514+
# return round(min, RoundDown; sigdigits = 3, base = 2)
515+
return round(min, RoundDown; sigdigits = 2)
516+
# dec = round(min, RoundDown; sigdigits = 1)
517+
# if first(string(dec)) == '1'
518+
# min > 1.5 * dec && return 1.5 * dec
519+
# # min > 1.2 * dec && return 1.2 * dec
520+
# elseif first(string(dec)) == '9'
521+
# return round((8//9) * dec, sigdigits = 2)
522+
# end
523+
# dec
524+
end
525+
function high_edge(times)
526+
max = maximum(times)
527+
# return round(max, RoundUp; sigdigits = 3, base = 2)
528+
return round(max, RoundUp; sigdigits = 2)
529+
# dec = round(max, RoundUp; sigdigits = 1)
530+
# if first(string(dec)) == '2'
531+
# max < 0.75 * dec && return 0.75 * dec
532+
# elseif first(string(dec)) == '9'
533+
# return round((10//9) * dec, sigdigits = 2)
534+
# end
535+
# dec
504536
end
505537

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

0 commit comments

Comments
 (0)