diff --git a/README.md b/README.md index 0a06834..48e0c80 100644 --- a/README.md +++ b/README.md @@ -3,32 +3,36 @@ This package contains various test programs which measure the efficiency of Garbage Collection (GC) in Julia. + ## Running ``` Usage: - run_benchmarks.jl (serial|multithreaded|slow) (all| []) [options] + run_benchmarks.jl (serial|multithreaded|compiler|fragmentation|slow) (all| []) [options] run_benchmarks.jl -h | --help run_benchmarks.jl --version Options: -n , --runs= Number of runs for each benchmark [default: 10]. - -t , --threads= Number of mutator threads to use [default: 1]. - --gcthreasds= Number of GC threads to use [default: 1]. - -s , --scale= Maximum number of GC threads for scaling test. + -t , --threads= Number of threads to use [default: 1]. + -g , --gcthreads= Number of GC threads to use [default: 0]. + -s , --scale= Maximum number of gcthreads for scaling test. -h, --help Show this screen. --version Show version. + --json Serializes output to `json` file ``` ## Classes -There are three classes of benchmarks: +There are five classes of benchmarks: - *Serial* benchmarks run on a single mutator thread. - *Multithreaded* benchmarks may run on multiple mutator threads. -- *Slow* benchmarks are long-running in comparison with the other two classes. +- *Compiler* benchmarks exercise allocation patterns of the Julia compiler. +- *Fragmentation* benchmarks stress heap fragmentation. +- *Slow* benchmarks are long-running in comparison with the other classes. ## Examples -- Run all serial benchmarks 5 times each using 1 mutator thread and 1 GC thread: +- Run all serial benchmarks 5 times each using 1 mutator thread and the default GC threads: `julia --project=. run_benchmarks.jl serial all -n 5` @@ -40,6 +44,11 @@ There are three classes of benchmarks: `julia --project=. run_benchmarks.jl slow rb_tree rb_tree -n 1 --gcthreads 4` +- Run the red-black tree benchmark at its original 50M-point scale (roughly 20 + minutes per run instead of a few): + + `GCBENCH_RB_TREE_N=50000000 julia --project=. run_benchmarks.jl slow rb_tree rb_tree -n 1` + ## The benchmarks | Class | Category | Name | Description | @@ -50,13 +59,15 @@ There are three classes of benchmarks: | | linked | list.jl | Small pointer-heavy data structure. | | | | tree.jl | Small pointer-heavy data structure. | | | strings | strings.jl | Exercises fragmentation through repeated allocation of short multi-sized strings. | -| | big_arrays | many_refs.jl | Forces a mark-phase traversal through a large array of pointers (all distinct). | -| | big_arrays | single_ref.jl | Forces a mark-phase traversal through a large array of pointers (all the same). | +| | big_arrays | many_refs.jl | Forces a mark-phase traversal through a large array of pointers (all distinct). | +| | big_arrays | single_ref.jl | Forces a mark-phase traversal through a large array of pointers (all the same). | | Multithreaded | binary_tree | tree_immutable.jl | Small pointer-heavy data structure. | | | | tree_mutable.jl | Small pointer-heavy data structure. | | | mergesort_parallel | mergesort_parallel.jl | Parallel merge-sort. | | | mm_divide_and_conquer | mm_divide_and_conquer.jl | Divide-and-conquer matrix multiply. | | | big_arrays | objarray.jl | Allocates large arrays of boxed objects, each containing a small number of references. | | | big_arrays | issue-52937.jl | Parallel allocation of arrays of immutable types. | +| Compiler | inference | inference_benchmarks.jl | Runs type inference on various workloads, stressing compiler allocation patterns. | +| Fragmentation | synthetic | exploit_free_list.jl | Exploits free-list size classes to create heap fragmentation. | | Slow | rb\_tree | rb\_tree.jl | Pointer graph whose minimum linear arrangement has cost Θ(n²). | -| | pidigits | pidigits.jl | Tests large `BigInt`s. | +| | bigint | pidigits.jl | Tests large `BigInt`s. | diff --git a/benches/slow/rb_tree/rb_tree.jl b/benches/slow/rb_tree/rb_tree.jl index b57ef04..9f7f556 100644 --- a/benches/slow/rb_tree/rb_tree.jl +++ b/benches/slow/rb_tree/rb_tree.jl @@ -66,7 +66,14 @@ struct PointByY end Base.isless(a::PointByY, b::PointByY) = isless(a.p.y, b.p.y) -function tvbench(; N = 50_000_000) +# Number of live points held in the indexes. The default is scaled down from the +# original 50M so a run takes minutes rather than ~20; at 10M the live set is +# still >1 GB of Point plus red-black-tree nodes, far beyond any cache or TLB, so +# the poor mark locality this benchmark exists to measure is unaffected. Set +# GCBENCH_RB_TREE_N to run the original scale. +const RB_TREE_N = parse(Int, get(ENV, "GCBENCH_RB_TREE_N", "10000000")) + +function tvbench(; N = RB_TREE_N) t0 = time() queue = Queue{Point}() xtree = RBTree{PointByX}() diff --git a/run_benchmarks.jl b/run_benchmarks.jl index 588994a..eaf399a 100644 --- a/run_benchmarks.jl +++ b/run_benchmarks.jl @@ -59,13 +59,20 @@ function run_bench(runs, threads, gcthreads, file, show_json = false) gc_diff = [] gc_end = [] gc_start = [] + maxrss = [] for _ in 1:runs # uglyness to communicate over non stdout (specifically file descriptor 3) p = Base.PipeEndpoint() _gcthreads = gcthreads == 0 ? `` : `--gcthreads=$gcthreads` cmd = `$JULIAVER --project=. --threads=$threads $_gcthreads $file SERIALIZE` cmd = run(Base.CmdRedirect(cmd, p, 3), stdin, stdout, stderr, wait=false) - r = deserialize(p) + r = try + deserialize(p) + catch + wait(cmd) + @warn "Benchmark run died (exit code $(cmd.exitcode), signal $(cmd.termsignal)); skipping run" file + continue + end @assert success(cmd) # end uglyness push!(value, r.value) @@ -73,6 +80,11 @@ function run_bench(runs, threads, gcthreads, file, show_json = false) push!(gc_diff, r.gc_diff) push!(gc_end, r.gc_end) push!(gc_start, r.gc_start) + push!(maxrss, r.maxrss) + end + if isempty(times) + @warn "All runs of benchmark failed; no results" file + return end gc_times = extract(gc_end, gc_start, :total_time) mark_times = extract(gc_end, gc_start, :total_mark_time) @@ -81,6 +93,10 @@ function run_bench(runs, threads, gcthreads, file, show_json = false) ncollect = extract(gc_end, gc_start, :collect) nfull_sweep = extract(gc_end, gc_start, :full_sweep) + # Use the number of runs that actually produced results, not `runs`: a run + # whose child died is skipped above, and a mismatched column length here + # would throw instead of reporting the runs that did succeed. + nresults = length(times) data = Table( time = times, gc_time = gc_times, @@ -89,10 +105,11 @@ function run_bench(runs, threads, gcthreads, file, show_json = false) time_to_safepoint = times_to_safepoint, ncollections = ncollect, nfull_sweeps = nfull_sweep, - file = [file for _ in 1:runs], - threads = [threads for _ in 1:runs], - gcthreads = [gcthreads for _ in 1:runs], - version = [string(Base.VERSION) for _ in 1:runs], + maxrss = maxrss, + file = [file for _ in 1:nresults], + threads = [threads for _ in 1:nresults], + gcthreads = [gcthreads for _ in 1:nresults], + version = [string(Base.VERSION) for _ in 1:nresults], ) results = joinpath(@__DIR__, "results.csv") CSV.write(results, data; append=isfile(results)) @@ -104,11 +121,11 @@ function run_bench(runs, threads, gcthreads, file, show_json = false) time_to_safepoint = get_stats(times_to_safepoint) ./ 1_000 max_pause = get_stats(map(stat->stat.max_pause, gc_end)) ./ 1_000_000 - max_mem = get_stats(map(stat->stat.max_memory, gc_end)) ./ 1024^2 + max_rss = get_stats(maxrss) ./ 1024^2 pct_gc = get_stats(map((t,stat)->(stat.total_time/t), times, gc_diff)) .* 100 - header = (["", "total time", "gc time", "mark time", "sweep time", "max GC pause", "time to safepoint", "max heap", "percent gc"], - ["", "ms", "ms", "ms", "ms", "ms", "us", "MB", "%" ]) + header = (["", "total time", "gc time", "mark time", "sweep time", "max GC pause", "time to safepoint", "max rss", "percent gc"], + ["", "ms", "ms", "ms", "ms", "ms", "us", "MB", "%" ]) labels = ["minimum", "median", "maximum", "stdev"] highlighters = highlight_col(6, 10, 100) # max pause append!(highlighters, highlight_col(7, 1, 10)) # time to safepoint @@ -121,11 +138,11 @@ function run_bench(runs, threads, gcthreads, file, show_json = false) ("sweep time", sweep_time), ("max pause", max_pause), ("ttsp", time_to_safepoint), - ("max memory", max_mem), + ("max rss", max_rss), ("pct gc", pct_gc)]) JSON.print(data) else - data = hcat(labels, total_stats, gc_time, mark_time, sweep_time, max_pause, time_to_safepoint, max_mem, pct_gc) + data = hcat(labels, total_stats, gc_time, mark_time, sweep_time, max_pause, time_to_safepoint, max_rss, pct_gc) pretty_table(data; header, formatters=ft_printf("%0.0f"), highlighters) end end diff --git a/util/compare_bins.jl b/util/compare_bins.jl index a8865cb..ba83e75 100644 --- a/util/compare_bins.jl +++ b/util/compare_bins.jl @@ -23,7 +23,7 @@ function main(args) "mark time [ms]", "sweep time [ms]", "max pause [ms]", - "max memory [MB]", + "max rss [MB]", "pct gc"] header = ["", f1, f2] @@ -33,7 +33,7 @@ function main(args) js1["mark time"][2] js2["mark time"][2]; js1["sweep time"][2] js2["sweep time"][2]; js1["max pause"][2] js2["max pause"][2]; - js1["max memory"][2] js2["max memory"][2]; + js1["max rss"][2] js2["max rss"][2]; js1["pct gc"][2] js2["pct gc"][2]] data = hcat(labels, raw_data) diff --git a/util/utils.jl b/util/utils.jl index fec3e28..ec615ac 100644 --- a/util/utils.jl +++ b/util/utils.jl @@ -15,18 +15,24 @@ thrashing_stamps = zeros(UInt64, 3) function gc_cb_on_pressure() t = time_ns() + # Once the GC's thrashing estimator trips, it notifies on every collection, + # so notifications less than 1s apart are one episode: only count the first. + if idx[] > 0 && t - thrashing_stamps[(idx[] - 1) % 3 + 1] < 1_000_000_000 + return nothing + end thrashing_stamps[idx[] % 3 + 1] = t idx[] += 1 if idx[] >= 3 - # three thrashing stamps in ten seconds: abort + # three distinct thrashing episodes in ten seconds: abort if t - thrashing_stamps[idx[] % 3 + 1] <= 10_000_000_000 - @ccall abort()::Cvoid + print(stderr, "GCBenchmarks: GC thrashing detected (3 pressure episodes in 10s), aborting benchmark\n") + exit(1) end end nothing end -@info "Setting GC memory pressure callback" +@debug "Setting GC memory pressure callback" ccall(:jl_gc_set_cb_notify_gc_pressure, Cvoid, (Ptr{Cvoid}, Cint), @cfunction(gc_cb_on_pressure, Cvoid, ()), true) @@ -50,7 +56,12 @@ macro gctime(ex) times = (end_time - start_time), gc_diff = Base.GC_Diff(end_gc_num, start_gc_num), gc_start = start_gc_num, - gc_end = end_gc_num + gc_end = end_gc_num, + # Peak RSS as the OS saw it (getrusage ru_maxrss), which unlike + # the GC's own `max_memory` accounting includes everything the + # process actually paid for: code, stacks, malloc'd memory, and + # any heap the GC mapped but did not charge itself. + maxrss = Sys.maxrss() ) catch e @show e @@ -59,7 +70,8 @@ macro gctime(ex) times = NaN, gc_diff = Base.GC_Diff(end_gc_num, start_gc_num), gc_start = start_gc_num, - gc_end = end_gc_num + gc_end = end_gc_num, + maxrss = Sys.maxrss() ) end