Fix thrashing detection and update readme to be correct

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|<category> [<name>]) [options]
+    run_benchmarks.jl (serial|multithreaded|compiler|fragmentation|slow) (all|<category> [<name>]) [options]
     run_benchmarks.jl -h | --help
     run_benchmarks.jl --version
 Options:
     -n <runs>, --runs=<runs>              Number of runs for each benchmark [default: 10].
-    -t <threads>, --threads=<threads>     Number of mutator threads to use [default: 1].
-    --gcthreasds=<gcthreads>              Number of GC threads to use [default: 1].
-    -s <max>, --scale=<max>               Maximum number of GC threads for scaling test.
+    -t <threads>, --threads=<threads>     Number of threads to use [default: 1].
+    -g <threads>, --gcthreads=<threads>   Number of GC threads to use [default: 0].
+    -s <max>, --scale=<max>               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. |

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}()

run_benchmarks.jl

@@ -59,20 +59,32 @@ 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)
         push!(times, r.times)
         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

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)

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