23. Measuring Performance: Does Any of It Make the Code Fast?¶
What you will understand: how to measure a compiler's output honestly, and what the measurements say about Mountain Goat's matrix product. Every chapter so far said "no performance claim is made". This chapter makes some, carefully: it times one operation under different compiler settings and loop transforms, compares it with hand-written C++, shows the noise in its own numbers, and looks at the machine code to explain one result. It also finds, on the way, a bug in the driver that had been there since Chapter 20.
What you need to know first: Chapter 7 (loop tiling and the other loop transforms), Chapter 17 (those transforms on dynamic bounds), Chapters 20 and 21 (the mgc driver and @, the matrix product). No performance background is assumed; the terms are explained below.
Compile and run
cd docs/part23/code
../part22/code/build.sh # once: Chapter 22's mg-opt (this chapter changes only the driver)
./machine_info.sh > machine_info_out.txt # what machine the numbers come from
./run_bench.sh > bench_out_1.txt # build and time every variant (takes about a minute)
./run_bench.sh > bench_out_2.txt # a second, independent pass
python3 summarize.py bench_out_1.txt bench_out_2.txt > summary.txt
./inspect_asm.sh > inspect_asm_out.txt # look at the machine code behind one result
./mgc run examples/matmul_odd.mg -O2 --passes "--affine-loop-tile=tile-size=2" # the new options on one program
./mgc_mutation.py > mgc_mutation_out.txt # breaks mgc on purpose to test the tests
cd ../part15/code && ./run_lit.sh # the whole test suite
Why this page shows FAIL lines, and why that is good
The mutation output near the end comes from a negative control: deliberately broken code run against the tests. There a "caught by" line (a test failed) is the expected, wanted result. The baseline lines must say "all tests pass", and they do.
Primer: what is being measured¶
Throughput and GFLOP/s. Multiplying two N by N matrices takes N³ multiplications and N³ additions, so 2·N³ floating-point operations (FLOPs). Dividing that by the time gives a speed in GFLOP/s (billions of floating-point operations per second). It is a fair way to compare implementations of the same operation at the same size, and a bad way to compare different sizes or machines, because caches and clock speeds matter.
Why speeds differ so much between correct programs. All the programs below compute exactly the same numbers. They differ in how the computer is asked to do it:
- Optimization level.
-O0tells the C compiler (clang) to do almost no optimization;-O2and-O3ask for increasingly aggressive rewriting. Until this chapter every Mountain Goat program was built at-O0(clang's default for a.llfile), which is fine for demonstrating correctness and wrong for anything about speed. - Memory and caches. A processor reads memory through small, fast caches. Reading consecutive addresses is fast; jumping around memory is slow, because each jump may miss the cache. In the textbook matrix-product loop the innermost loop walks down a column of the right-hand matrix, which in row-major storage means jumping a whole row's length each step.
- Loop tiling (also called blocking, Chapter 7) restructures the loops to work on small square tiles at a time, so the data a tile needs stays in cache while it is reused. Here the tile is 32 by 32 numbers; three of them (one from each matrix) are 24 KiB, which fits in this machine's 48 KiB of L1 data cache per core.
- Vectorization (SIMD) uses instructions that operate on several numbers at once.
-march=nativetells clang it may use every instruction this particular CPU supports, which includes wide vector instructions on this machine. - Loop order. The same triple loop can be written with its three loops in different orders (
i,j,kori,k,j), which changes which memory is read in what pattern. Order matters enormously and the compiler will not reliably change it for you.
What makes a measurement trustworthy. Computers are noisy. A fair measurement runs the code once to warm up (page faults, cold caches), repeats it several times, reports the median (robust to a slow outlier) and the minimum (the least disturbed run), checks that the answer is still right, says what machine it ran on, and repeats the whole experiment to show how much results move between runs.
Two new options for mgc¶
mgc gains two options (and two environment variables) so that these experiments are one-line changes:
-O0,-O1,-O2,-O3: the optimization level for the final clang step (default-O0, so nothing earlier changes).--passes "…": extramg-optpasses run on the affine loops before they are lowered further. For example--passes "--affine-loop-tile=tile-size=32"runs Chapter 7's tiling pass on every loop nest in the program.MGC_CFLAGS: extra flags for clang, such as-march=native.MGC_CLANG: which clang to call (a test seam, explained below).
The change against Chapter 22's driver:
--- ../../part22/code/mgc 2026-10-02 16:29:34.479578094 +0000
+++ mgc 2026-10-02 16:31:18.251194699 +0000
@@ -5,36 +5,39 @@
# mgc lib prog.mg [-o dir] compile the 'def's to prog.o plus a C++ header prog.h (no main), for linking into your own program
# mgc mlir prog.mg print the mg-dialect MLIR the front end produces
# mgc ptx prog.mg compile to PTX (no launch: this machine has no GPU) and print the PTX
-# Env: MG_OPT (default Chapter 22 build), MGC_KEEP=dir (keep every intermediate file there).
+# Options (Chapter 23): -O0|-O1|-O2|-O3 optimization level for the final clang step (default -O0, as in every earlier chapter)
+# --passes "--affine-loop-tile=tile-size=32" extra mg-opt passes run on the affine IR, before lowering (quote as one argument)
+# Env: MG_OPT (default Chapter 22 build), MGC_KEEP=dir (keep every intermediate file there), MGC_CFLAGS (extra flags for clang, e.g. -march=native),
+# MGC_CLANG (the clang to call; tests set it to `echo` to see exactly which flags mgc passes).
set -e
HERE=$(cd "$(dirname "$0")" && pwd)
MG_OPT=${MG_OPT:-$HERE/../../part22/code/build/mg-opt}
LIBDIR=${MLIR_LIBDIR:-/usr/lib/llvm-18/lib}
-usage() { echo "usage: mgc run|build|lib|mlir|ptx prog.mg [-o exe]" >&2; exit 2; }
+usage() { echo "usage: mgc run|build|lib|mlir|ptx prog.mg [-o exe] [-O0..-O3] [--passes \"...\"]" >&2; exit 2; }
[ $# -ge 2 ] || usage
-cmd=$1; src=$2; shift 2; out=
-while [ $# -gt 0 ]; do case $1 in -o) out=$2; shift 2;; *) usage;; esac; done
+cmd=$1; src=$2; shift 2; out=; OPT=; PASSES=
+while [ $# -gt 0 ]; do case $1 in -o) out=$2; shift 2;; -O0|-O1|-O2|-O3) OPT=$1; shift;; --passes) PASSES=$2; shift 2;; *) usage;; esac; done
[ -f "$src" ] || { echo "mgc: no such file: $src" >&2; exit 2; }
W=${MGC_KEEP:-$(mktemp -d)}; mkdir -p "$W"
base=$(basename "$src" .mg)
LIBFLAG=; [ "$cmd" = lib ] && LIBFLAG=--lib
-python3 "$HERE/mgfront.py" $LIBFLAG "$src" > "$W/$base.mlir" # 1. surface syntax -> mg dialect (exit 1 + message on a syntax/shape error)
+python3 "$HERE/../../part22/code/mgfront.py" $LIBFLAG "$src" > "$W/$base.mlir" # 1. surface syntax -> mg dialect (exit 1 + message on a syntax/shape error)
[ "$cmd" = mlir ] && { cat "$W/$base.mlir"; exit 0; }
[ -x "$MG_OPT" ] || { echo "mgc: no mg-opt at $MG_OPT (run part22/code/build.sh)" >&2; exit 2; }
case $cmd in
build|run|lib)
LOWER='--lower-affine --convert-scf-to-cf --mg-lower-assert-to-stderr --convert-arith-to-llvm --finalize-memref-to-llvm --convert-func-to-llvm --reconcile-unrealized-casts'
- $MG_OPT "$W/$base.mlir" --convert-mg-to-affine -o "$W/$base.affine.mlir" # 2. mg -> affine/memref/arith (+ runtime shape checks)
+ $MG_OPT "$W/$base.mlir" --convert-mg-to-affine $PASSES -o "$W/$base.affine.mlir" # 2. mg -> affine/memref/arith (+ runtime shape checks)
$MG_OPT "$W/$base.affine.mlir" $LOWER -o "$W/$base.llvm.mlir" # 3. -> LLVM dialect, assertions -> write(2,..)+abort
mlir-translate-18 --mlir-to-llvmir "$W/$base.llvm.mlir" -o "$W/$base.ll" # 4. -> LLVM IR
if [ "$cmd" = lib ]; then # object + header; the object is linked by the caller
dir=${out:-$W}; mkdir -p "$dir"
- clang-18 -c "$W/$base.ll" -o "$dir/$base.o" 2>/dev/null
- python3 "$HERE/mgfront.py" --header "$src" > "$dir/$base.h"
+ ${MGC_CLANG:-clang-18} $OPT $MGC_CFLAGS -c "$W/$base.ll" -o "$dir/$base.o" 2>/dev/null
+ python3 "$HERE/../../part22/code/mgfront.py" --header "$src" > "$dir/$base.h"
echo "wrote $dir/$base.o and $dir/$base.h"; exit 0
fi
exe=${out:-$W/$base.exe}
- clang-18 "$W/$base.ll" -o "$exe" -L"$LIBDIR" -lmlir_runner_utils -Wl,-rpath,"$LIBDIR" 2>/dev/null # 5. -> native executable
+ ${MGC_CLANG:-clang-18} $OPT $MGC_CFLAGS "$W/$base.ll" -o "$exe" -L"$LIBDIR" -lmlir_runner_utils -Wl,-rpath,"$LIBDIR" 2>/dev/null # 5. -> native executable
if [ "$cmd" = run ]; then exec "$exe"; fi # (Chapter 23: this used to be `[ ... ] && exec`, which made `mgc build` exit with status 1 on success)
;;
ptx)
@@ -43,7 +46,7 @@
--pass-pipeline='builtin.module(func.func(affine-parallelize,lower-affine,gpu-map-parallel-loops,convert-parallel-loops-to-gpu),gpu-kernel-outlining)' -o "$W/$base.gpu.mlir"
mlir-opt-18 "$W/$base.gpu.mlir" \
--pass-pipeline='builtin.module(lower-affine,nvvm-attach-target{chip=sm_70 features=+ptx60},gpu.module(convert-scf-to-cf,convert-gpu-to-nvvm{index-bitwidth=64},reconcile-unrealized-casts),gpu-module-to-binary{format=isa})' -o "$W/$base.bin.mlir"
- python3 "$HERE/decode_ptx.py" "$W/$base.bin.mlir"
+ python3 "$HERE/../../part22/code/decode_ptx.py" "$W/$base.bin.mlir"
;;
*) usage;;
esac
A bug found while writing the tests. Testing mgc build showed that it exited with status 1 even on success. The last line of the script was [ "$cmd" = run ] && exec "$exe", and when the command is build that comparison is false, so the script's final status is 1. Chapters 20 to 22 only ever used mgc run (which replaces the shell with the program) and mgc lib (which exits explicitly), so nothing noticed. It is fixed in all four copies of mgc (Chapters 20 to 23), and the new test tiling-structure builds with mgc build and would fail on the old behavior.
The experiment¶
The function being measured is a matrix product, once with dynamic sizes and once with a fixed 256 by 256 shape:
# The function being measured: a matrix product, once with dynamic sizes and once with a fixed 256x256 shape.
def mm_dyn(a: tensor[?x?], b: tensor[?x?]) = a @ b
def mm_256(a: tensor[256x256], b: tensor[256x256]) = a @ b
The harness times it from C++ (the compiled code is linked in through the generated object file, as in Chapter 20) at N = 64, 128, 256 and 512. It computes a reference answer with an ordinary triple loop and checks every variant's result against it (the inputs are small whole numbers, so every product and sum is exact and the comparison is exact equality, not a tolerance). Each variant is built from the same harness source; only the object being timed changes:
// Times one matrix-product implementation at several sizes and checks every result against a reference.
// Built once per variant: -DVARIANT_MG links the Mountain Goat object (mm_dyn, and mm_256 at N=256);
// -DVARIANT_IJK / -DVARIANT_IKJ time a plain C++ triple loop in that loop order. Everything else is identical.
#include <algorithm>
#include <chrono>
#include <cmath>
#include <cstdint>
#include <cstdio>
#include <cstdlib>
#include <string>
#include <vector>
#ifdef VARIANT_MG
// The memref calling convention (Chapters 1, 8, 20): each matrix is (allocated, aligned, offset, size0, size1, stride0, stride1).
struct Desc { double *allocated, *aligned; int64_t offset, sizes[2], strides[2]; };
extern "C" Desc mm_dyn(double*, double*, int64_t, int64_t, int64_t, int64_t, int64_t, double*, double*, int64_t, int64_t, int64_t, int64_t, int64_t);
extern "C" Desc mm_256(double*, double*, int64_t, int64_t, int64_t, int64_t, int64_t, double*, double*, int64_t, int64_t, int64_t, int64_t, int64_t);
#endif
using Clock = std::chrono::steady_clock;
static double seconds(Clock::time_point a, Clock::time_point b) { return std::chrono::duration<double>(b - a).count(); }
static void ref_ijk(const double *a, const double *b, double *c, int n) {
for (int i = 0; i < n; i++) for (int j = 0; j < n; j++) { double s = 0; for (int k = 0; k < n; k++) s += a[i * n + k] * b[k * n + j]; c[i * n + j] = s; }
}
static void ref_ikj(const double *a, const double *b, double *c, int n) {
std::fill(c, c + (size_t)n * n, 0.0);
for (int i = 0; i < n; i++) for (int k = 0; k < n; k++) { double x = a[i * n + k]; for (int j = 0; j < n; j++) c[i * n + j] += x * b[k * n + j]; }
}
// Run `f` (which writes an n*n result into c) enough times to measure, and return per-call seconds for each of `trials` trials.
template <typename F> static std::vector<double> measure(F f, int trials) {
f(); // warm-up (page faults, caches, lazy binding)
auto t0 = Clock::now(); f(); double one = seconds(t0, Clock::now());
int reps = std::max(1, (int)std::ceil(0.05 / std::max(one, 1e-9))); // aim for at least 50 ms per trial
std::vector<double> t;
for (int k = 0; k < trials; k++) { auto s = Clock::now(); for (int r = 0; r < reps; r++) f(); t.push_back(seconds(s, Clock::now()) / reps); }
std::sort(t.begin(), t.end());
return t;
}
static void report(const char *label, int n, const std::vector<double> &t, bool ok) {
double med = t[t.size() / 2], mn = t[0], flops = 2.0 * n * n * n;
std::printf("%-26s N=%-4d min %9.3f ms median %9.3f ms %7.2f GFLOP/s (median) %s\n", label, n, mn * 1e3, med * 1e3, flops / med / 1e9, ok ? "result ok" : "RESULT WRONG");
}
int main(int argc, char **argv) {
const char *label = argc > 1 ? argv[1] : "variant";
int trials = 7;
for (int n : {64, 128, 256, 512}) {
std::vector<double> a((size_t)n * n), b((size_t)n * n), c((size_t)n * n), want((size_t)n * n);
for (size_t i = 0; i < a.size(); i++) { a[i] = (double)((i * 7) % 11) - 5; b[i] = (double)((i * 5) % 13) - 6; } // small integers: every product and sum is exact
ref_ijk(a.data(), b.data(), want.data(), n);
auto same = [&](const double *x) { for (size_t i = 0; i < want.size(); i++) if (x[i] != want[i]) return false; return true; };
#if defined(VARIANT_IJK)
auto t = measure([&] { ref_ijk(a.data(), b.data(), c.data(), n); }, trials); report(label, n, t, same(c.data()));
#elif defined(VARIANT_IKJ)
auto t = measure([&] { ref_ikj(a.data(), b.data(), c.data(), n); }, trials); report(label, n, t, same(c.data()));
#elif defined(VARIANT_MG)
bool ok = true;
auto run = [&](Desc (*fn)(double*, double*, int64_t, int64_t, int64_t, int64_t, int64_t, double*, double*, int64_t, int64_t, int64_t, int64_t, int64_t)) {
return [&, fn] { Desc d = fn(a.data(), a.data(), 0, n, n, n, 1, b.data(), b.data(), 0, n, n, n, 1);
ok = ok && same(d.aligned + d.offset); std::free(d.allocated); };
};
auto t = measure(run(mm_dyn), trials); report((std::string(label) + " (dynamic sizes)").c_str(), n, t, ok);
if (n == 256) { ok = true; auto t2 = measure(run(mm_256), trials); report((std::string(label) + " (static 256)").c_str(), n, t2, ok); }
#endif
}
return 0;
}
The script that builds and runs all the variants:
#!/bin/sh
# Build and time every variant of the matrix product. Output: bench_out_1.txt, bench_out_2.txt (two complete passes).
# What is timed: one call to a 64..512 square matrix product, per-call time over 7 trials (each trial repeats the call until it lasts >= 50 ms).
# Every variant's result is compared against a reference computed with an ordinary triple loop (small integers, so every sum is exact).
HERE=$(cd "$(dirname "$0")" && pwd); W=$HERE/work/bench; mkdir -p $W
MGC=$HERE/mgc; SRC=$HERE/bench/matmul.mg; H=$HERE/bench/bench.cpp
CORE=; command -v taskset >/dev/null && CORE="taskset -c 3" # pin to one core to reduce scheduler noise
build_mg() { # name mgc-flags... (MGC_CFLAGS may be set by the caller)
name=$1; shift; mkdir -p $W/$name
$MGC lib $SRC -o $W/$name "$@" >/dev/null
clang++-18 -std=c++17 -O2 -DVARIANT_MG $H $W/$name/matmul.o -o $W/$name/bench
}
build_mg mg_O0
build_mg mg_O2 -O2
build_mg mg_O2_tile32 -O2 --passes "--affine-loop-tile=tile-size=32"
MGC_CFLAGS=-march=native build_mg mg_O3_native -O3
MGC_CFLAGS=-march=native build_mg mg_O3_native_tile32 -O3 --passes "--affine-loop-tile=tile-size=32"
clang++-18 -std=c++17 -O2 -DVARIANT_IJK $H -o $W/ref_ijk
clang++-18 -std=c++17 -O3 -march=native -DVARIANT_IKJ $H -o $W/ref_ikj_native
echo "machine: $(nproc) CPUs, $(grep -m1 'model name' /proc/cpuinfo | sed 's/.*: //'), $(clang++-18 --version | head -1)"
echo "pinned with: ${CORE:-nothing} load average before: $(cut -d' ' -f1-3 /proc/loadavg)"
for v in mg_O0 mg_O2 mg_O2_tile32 mg_O3_native mg_O3_native_tile32; do $CORE $W/$v/bench $v; done
$CORE $W/ref_ijk "C++ ijk loop, clang -O2"
$CORE $W/ref_ikj_native "C++ ikj loop, -O3 native"
echo "load average after: $(cut -d' ' -f1-3 /proc/loadavg)"
The variants:
| Name | What it is |
|---|---|
mg_O0 |
Mountain Goat's matmul, built the way every earlier chapter built things |
mg_O2 |
the same, with clang -O2 |
mg_O2_tile32 |
-O2, and the loops tiled 32 by 32 by Chapter 7's pass |
mg_O3_native |
-O3 -march=native (all of this CPU's instructions) |
mg_O3_native_tile32 |
-O3 -march=native and tiled |
C++ ijk loop, clang -O2 |
the textbook triple loop, in the same loop order Mountain Goat generates, written in C++ |
C++ ikj loop, -O3 native |
what a person who knows about caches would write: the middle two loops swapped, built with every optimization |
The machine¶
CPU: Intel(R) Xeon(R) Processor @ 2.10GHz
CPU(s): 4
Thread(s) per core: 1
Core(s) per socket: 4
Socket(s): 1
L1d cache: 192 KiB (4 instances)
L2 cache: 8 MiB (4 instances)
L3 cache: 260 MiB (1 instance)
vector extensions available: avx avx2 avx512f fma sse4_2
memory: 16094 MiB
kernel: Linux 6.18.44-fc-v51
compiler: Ubuntu clang version 18.1.3 (1ubuntu1)
mlir: Ubuntu LLVM version 18.1.3
This is a shared cloud virtual machine, not a quiet benchmarking box; see the chapter for what that means for the numbers.
This is a shared cloud virtual machine, not a quiet benchmarking host. Other tenants may be using the same physical hardware, the clock speed is not fixed by me, and the cache sizes shown are what the virtual machine reports. The harness pins itself to one core (taskset -c 3) to reduce scheduler noise, which helps but does not remove it. Treat every number below as "what happened on this machine in this session", not as a property of Mountain Goat.
Results¶
The raw output of both passes (click to expand):
Pass 1: bench_out_1.txt
machine: 4 CPUs, Intel(R) Xeon(R) Processor @ 2.10GHz, Ubuntu clang version 18.1.3 (1ubuntu1)
pinned with: taskset -c 3 load average before: 0.57 0.39 0.16
mg_O0 (dynamic sizes) N=64 min 0.641 ms median 0.652 ms 0.80 GFLOP/s (median) result ok
mg_O0 (dynamic sizes) N=128 min 4.806 ms median 5.377 ms 0.78 GFLOP/s (median) result ok
mg_O0 (dynamic sizes) N=256 min 48.290 ms median 60.533 ms 0.55 GFLOP/s (median) result ok
mg_O0 (static 256) N=256 min 41.836 ms median 43.641 ms 0.77 GFLOP/s (median) result ok
mg_O0 (dynamic sizes) N=512 min 846.780 ms median 985.506 ms 0.27 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=64 min 0.078 ms median 0.126 ms 4.16 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=128 min 2.232 ms median 2.256 ms 1.86 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=256 min 17.257 ms median 18.489 ms 1.81 GFLOP/s (median) result ok
mg_O2 (static 256) N=256 min 16.208 ms median 17.697 ms 1.90 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=512 min 393.451 ms median 438.605 ms 0.61 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=64 min 0.094 ms median 0.094 ms 5.55 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=128 min 0.877 ms median 1.197 ms 3.50 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=256 min 6.202 ms median 6.691 ms 5.01 GFLOP/s (median) result ok
mg_O2_tile32 (static 256) N=256 min 5.561 ms median 6.464 ms 5.19 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=512 min 79.821 ms median 82.943 ms 3.24 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=64 min 0.115 ms median 0.123 ms 4.28 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=128 min 2.106 ms median 2.284 ms 1.84 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=256 min 15.787 ms median 17.117 ms 1.96 GFLOP/s (median) result ok
mg_O3_native (static 256) N=256 min 16.755 ms median 17.475 ms 1.92 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=512 min 430.051 ms median 457.523 ms 0.59 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=64 min 0.094 ms median 0.108 ms 4.88 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=128 min 0.730 ms median 0.765 ms 5.48 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=256 min 8.011 ms median 8.426 ms 3.98 GFLOP/s (median) result ok
mg_O3_native_tile32 (static 256) N=256 min 2.714 ms median 3.454 ms 9.72 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=512 min 75.085 ms median 76.763 ms 3.50 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=64 min 0.088 ms median 0.089 ms 5.88 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=128 min 2.233 ms median 2.243 ms 1.87 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=256 min 17.162 ms median 18.716 ms 1.79 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=512 min 413.616 ms median 429.951 ms 0.62 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=64 min 0.038 ms median 0.039 ms 13.30 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=128 min 0.419 ms median 0.497 ms 8.44 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=256 min 3.366 ms median 3.514 ms 9.55 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=512 min 35.847 ms median 36.792 ms 7.30 GFLOP/s (median) result ok
load average after: 0.76 0.46 0.19
Pass 2: bench_out_2.txt
machine: 4 CPUs, Intel(R) Xeon(R) Processor @ 2.10GHz, Ubuntu clang version 18.1.3 (1ubuntu1)
pinned with: taskset -c 3 load average before: 0.66 0.46 0.19
mg_O0 (dynamic sizes) N=64 min 0.589 ms median 0.612 ms 0.86 GFLOP/s (median) result ok
mg_O0 (dynamic sizes) N=128 min 4.930 ms median 5.955 ms 0.70 GFLOP/s (median) result ok
mg_O0 (dynamic sizes) N=256 min 42.032 ms median 42.235 ms 0.79 GFLOP/s (median) result ok
mg_O0 (static 256) N=256 min 39.039 ms median 41.589 ms 0.81 GFLOP/s (median) result ok
mg_O0 (dynamic sizes) N=512 min 693.236 ms median 872.763 ms 0.31 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=64 min 0.092 ms median 0.093 ms 5.66 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=128 min 2.126 ms median 2.239 ms 1.87 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=256 min 16.380 ms median 17.584 ms 1.91 GFLOP/s (median) result ok
mg_O2 (static 256) N=256 min 16.753 ms median 17.039 ms 1.97 GFLOP/s (median) result ok
mg_O2 (dynamic sizes) N=512 min 401.258 ms median 428.123 ms 0.63 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=64 min 0.095 ms median 0.101 ms 5.19 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=128 min 0.749 ms median 0.764 ms 5.49 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=256 min 6.563 ms median 7.045 ms 4.76 GFLOP/s (median) result ok
mg_O2_tile32 (static 256) N=256 min 6.098 ms median 6.259 ms 5.36 GFLOP/s (median) result ok
mg_O2_tile32 (dynamic sizes) N=512 min 77.953 ms median 84.527 ms 3.18 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=64 min 0.102 ms median 0.128 ms 4.09 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=128 min 2.047 ms median 2.219 ms 1.89 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=256 min 16.391 ms median 16.639 ms 2.02 GFLOP/s (median) result ok
mg_O3_native (static 256) N=256 min 16.541 ms median 17.779 ms 1.89 GFLOP/s (median) result ok
mg_O3_native (dynamic sizes) N=512 min 435.270 ms median 481.596 ms 0.56 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=64 min 0.093 ms median 0.105 ms 5.01 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=128 min 0.867 ms median 0.895 ms 4.69 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=256 min 8.011 ms median 8.551 ms 3.92 GFLOP/s (median) result ok
mg_O3_native_tile32 (static 256) N=256 min 2.586 ms median 3.501 ms 9.58 GFLOP/s (median) result ok
mg_O3_native_tile32 (dynamic sizes) N=512 min 76.260 ms median 78.824 ms 3.41 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=64 min 0.089 ms median 0.092 ms 5.71 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=128 min 2.183 ms median 2.372 ms 1.77 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=256 min 16.488 ms median 16.990 ms 1.97 GFLOP/s (median) result ok
C++ ijk loop, clang -O2 N=512 min 402.685 ms median 424.304 ms 0.63 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=64 min 0.039 ms median 0.042 ms 12.59 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=128 min 0.487 ms median 0.513 ms 8.18 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=256 min 3.385 ms median 3.481 ms 9.64 GFLOP/s (median) result ok
C++ ikj loop, -O3 native N=512 min 34.685 ms median 35.454 ms 7.57 GFLOP/s (median) result ok
load average after: 0.81 0.52 0.23
And the two passes combined by summarize.py. The columns are the median time per call in each pass, how much the two passes differ (a rough measure of noise), the average GFLOP/s, and the speedup compared with the plain mgc -O2 build at the same size (above 1.00 is faster). Every result was checked against the reference:
implementation N pass 1 ms pass 2 ms differ GFLOP/s vs mg -O2 results
mg_O0 (dynamic sizes) 64 0.652 0.612 6% 0.83 0.17x ok
mg_O2 (dynamic sizes) 64 0.126 0.093 30% 4.91 1.00x ok
mg_O2_tile32 (dynamic sizes) 64 0.094 0.101 7% 5.37 1.12x ok
mg_O3_native (dynamic sizes) 64 0.123 0.128 4% 4.19 0.87x ok
mg_O3_native_tile32 (dynamic sizes) 64 0.108 0.105 3% 4.95 1.03x ok
C++ ijk loop, clang -O2 64 0.089 0.092 3% 5.79 1.21x ok
C++ ikj loop, -O3 native 64 0.039 0.042 7% 12.95 2.70x ok
mg_O0 (dynamic sizes) 128 5.377 5.955 10% 0.74 0.40x ok
mg_O2 (dynamic sizes) 128 2.256 2.239 1% 1.87 1.00x ok
mg_O2_tile32 (dynamic sizes) 128 1.197 0.764 44% 4.50 2.29x ok
mg_O3_native (dynamic sizes) 128 2.284 2.219 3% 1.86 1.00x ok
mg_O3_native_tile32 (dynamic sizes) 128 0.765 0.895 16% 5.09 2.71x ok
C++ ijk loop, clang -O2 128 2.243 2.372 6% 1.82 0.97x ok
C++ ikj loop, -O3 native 128 0.497 0.513 3% 8.31 4.45x ok
mg_O0 (dynamic sizes) 256 60.533 42.235 36% 0.67 0.35x ok
mg_O0 (static 256) 256 43.641 41.589 5% 0.79 0.42x ok
mg_O2 (dynamic sizes) 256 18.489 17.584 5% 1.86 1.00x ok
mg_O2 (static 256) 256 17.697 17.039 4% 1.94 1.04x ok
mg_O2_tile32 (dynamic sizes) 256 6.691 7.045 5% 4.88 2.63x ok
mg_O2_tile32 (static 256) 256 6.464 6.259 3% 5.28 2.84x ok
mg_O3_native (dynamic sizes) 256 17.117 16.639 3% 1.99 1.07x ok
mg_O3_native (static 256) 256 17.475 17.779 2% 1.90 1.02x ok
mg_O3_native_tile32 (dynamic sizes) 256 8.426 8.551 1% 3.95 2.12x ok
mg_O3_native_tile32 (static 256) 256 3.454 3.501 1% 9.65 5.19x ok
C++ ijk loop, clang -O2 256 18.716 16.990 10% 1.88 1.01x ok
C++ ikj loop, -O3 native 256 3.514 3.481 1% 9.60 5.16x ok
mg_O0 (dynamic sizes) 512 985.506 872.763 12% 0.29 0.47x ok
mg_O2 (dynamic sizes) 512 438.605 428.123 2% 0.62 1.00x ok
mg_O2_tile32 (dynamic sizes) 512 82.943 84.527 2% 3.21 5.18x ok
mg_O3_native (dynamic sizes) 512 457.523 481.596 5% 0.57 0.92x ok
mg_O3_native_tile32 (dynamic sizes) 512 76.763 78.824 3% 3.46 5.57x ok
C++ ijk loop, clang -O2 512 429.951 424.304 1% 0.62 1.01x ok
C++ ikj loop, -O3 native 512 36.792 35.454 4% 7.44 12.00x ok
Reading the numbers¶
Each statement below is about this table, and is followed by what the evidence does and does not show.
1. Turning on the C compiler's optimizer matters a lot. -O2 is between about 2× (at N = 512) and 6× (at N = 64) faster than the -O0 that every earlier chapter used. Nothing in Mountain Goat changed; only the flag. (At N = 64 each call takes about a tenth of a millisecond, so that figure is the least reliable.)
2. Mountain Goat's generated matmul is as fast as the same loop written in C++. At -O2, mg_O2 and C++ ijk loop, clang -O2 are within the noise of each other at every size (the ratio column is 0.97 to 1.21; at N = 128 and above the two passes of each disagree by at most 10%, at N = 64 by up to 30%). That is what you would expect: the compiler lowers a @ b to exactly the textbook i, j, k loop. It is not a claim that Mountain Goat is fast; it is a claim that it is no slower than the algorithm it implements.
3. Tiling helps, and helps more as the matrices get bigger. Tiling by 32 at -O2 is 1.1× at N = 64 (within noise), 2.3× at N = 128, 2.6× at N = 256 and 5.2× at N = 512, relative to untiled -O2. The trend is consistent with the cache explanation in the primer: the untiled loop's column walk costs more as the matrices outgrow the cache. This chapter did not measure cache misses (no hardware counters were used), so the explanation is a consistent story, not a proven mechanism.
4. -O3 -march=native alone did nothing. Without tiling, mg_O3_native is 0.87× to 1.07× of mg_O2: no gain. The machine code shows why (next section): the compiled loop is scalar, with no vector instructions at all, despite the CPU having wide ones.
5. One combination is very fast: tiled, fixed shape, all instructions. mg_O3_native_tile32 (static 256) reaches 9.65 GFLOP/s, 5.2× the plain -O2 build and equal to the hand-written ikj loop at the same size (9.60 GFLOP/s). The same transform on the dynamic-size function reaches only 3.95 GFLOP/s (2.1×). So there is a gap between "the compiler knew the sizes" and "it did not".
6. At N = 512 nothing from Mountain Goat gets close to the hand-written loop. The best Mountain Goat variant (tiled, -O3 -march=native, dynamic sizes) reaches 3.46 GFLOP/s; the hand-written ikj loop reaches 7.44, about 2.1× faster. There is no fixed-size 512 function in the experiment, so this does not say what a fixed-size 512 build would do. A better Mountain Goat matmul (the loop order, a tuned tile size, a micro-kernel) is not built here.
7. The numbers are noisy. The two passes of the same experiment differ by up to 44% (mg_O2_tile32 at N = 128), 36% (mg_O0 at N = 256) and 30% (mg_O2 at N = 64). Differences smaller than about this are not meaningful, which is why the statements above compare large effects (2× and up) and call 1.0× to 1.2× "within the noise".
Looking at the machine code¶
Result 4 says the code is scalar and result 5 says one build is different. inspect_asm.sh checks directly, by counting vector and fused multiply-add instructions in the assembly of each function:
#!/bin/sh
# Look at the machine code behind the benchmark: do the compiled matrix products use vector (packed/FMA) instructions?
# Counts vfmadd/vmulpd/vaddpd instructions in each function of an -O3 -march=native build. Output: inspect_asm_out.txt
HERE=$(cd "$(dirname "$0")" && pwd); W=$HERE/work/asm; mkdir -p $W
count() { # name label mgc-flags...
name=$1; label=$2; shift 2; mkdir -p $W/$name
MGC_KEEP=$W/$name MGC_CFLAGS=-march=native $HERE/mgc lib $HERE/bench/matmul.mg -o $W/$name "$@" >/dev/null
clang-18 -O3 -march=native -S $W/$name/matmul.ll -o $W/$name/matmul.s 2>/dev/null
for f in mm_dyn mm_256; do
n=$(awk "/^$f:/,/\\.cfi_endproc/" $W/$name/matmul.s | grep -c 'vfmadd\|vmulpd\|vaddpd')
echo "$label, $f: $n vector/FMA instructions"
done
}
count untiled "untiled, -O3 -march=native" -O3
count tiled32 "tiled (32), -O3 -march=native" -O3 --passes "--affine-loop-tile=tile-size=32"
untiled, -O3 -march=native, mm_dyn: 0 vector/FMA instructions
untiled, -O3 -march=native, mm_256: 0 vector/FMA instructions
tiled (32), -O3 -march=native, mm_dyn: 0 vector/FMA instructions
tiled (32), -O3 -march=native, mm_256: 64 vector/FMA instructions
Only the tiled, fixed-shape function (mm_256 in the tiled build) contains vector instructions (64 of them). The dynamic-size function has none in either build, and the untiled fixed-shape function has none. That matches the speed ranking in result 5. What it does not tell us is which of the two ingredients (the tiling, or the fixed shape) is the one that unlocks vectorization on its own: only the combination was tried. For comparison, the plain -O2 build's inner loop is a chain of scalar mulsd/addsd instructions, unrolled four times, with the running sum kept in a register (so the compiler did avoid reloading and storing the result on every step).
Tests¶
Three new test files in test/perf/ (the suite now has 93 tests). Note what is not tested: no test asserts that anything is faster. Timings depend on the machine and its load, and a test that fails when a shared machine is busy is worse than no test. Instead the tests check the things that must hold regardless of speed:
| Test | What it checks |
|---|---|
options-same-results |
the same 3×5 by 5×2 product (no dimension a multiple of the tile size) gives identical output at -O0, -O2, tiled by 2 and by 3 with dynamic shapes, and tiled by 2 with static shapes, and equals the hand-computed 12 15 / 32 35 / 52 55 |
tiling-structure |
--passes really reaches mg-opt: the plain build has 5 loops, the tiled one 10, with min bounds at the edges; and mgc build exits with status 0 |
flags-reach-clang |
-O2, -O3 and MGC_CFLAGS reach the final clang command, for both build and lib, and no -O appears when none was given |
The third test needs an explanation, because it came from a failure of the first two. Optimization flags never change a program's results, so no test of the output can tell whether -O2 was applied. I broke mgc so that -O was ignored, and both result-checking tests still passed. The fix is a small seam: MGC_CLANG names the clang to call, and the test sets it to echo, so mgc prints the command line it would have run and the test checks that line. Without that seam, "-O is ignored" would be an equivalent mutant (Chapter 22): a bug no test of results can see.
mgc_mutation.py breaks the driver five ways, one at a time, and runs the tests each time:
#!/usr/bin/env python3
# READ THIS FIRST: this script injects deliberate bugs into the mgc driver and re-runs the Chapter 23 tests (test/perf).
# "caught by <tests>" lines are the EXPECTED, wanted result: a test noticed the bug. "NOT CAUGHT" would be a test gap.
# mgc is restored afterwards. Output: mgc_mutation_out.txt
import os, subprocess, sys
HERE = os.path.dirname(os.path.abspath(__file__)); MGC = os.path.join(HERE, "mgc")
LIT = os.path.join(HERE, "..", "..", "part15", "code", "run_lit.sh")
print("NOTE: this script deliberately breaks mgc. 'caught by' lines are EXPECTED: they show the tests can detect the bug.")
def run(label, baseline=False):
r = subprocess.run(["sh", LIT, "--filter", ":: perf/"], capture_output=True, text=True,
env={**os.environ, "MG_OPT": os.path.join(HERE, "..", "..", "part22", "code", "build", "mg-opt"), "MG_TEST_TMP": os.path.join(HERE, "work", "perfmut")})
fails = [l.split("::")[1].strip().split(" (")[0] for l in r.stdout.splitlines() if l.startswith("FAIL")]
if baseline: print(f"{label}: " + ("all tests pass (expected)" if not fails else "UNEXPECTED FAILURES: " + ", ".join(fails)))
else: print(f"{label}: " + ("caught by " + ", ".join(fails) if fails else "NOT CAUGHT (a test gap)"))
orig = open(MGC).read()
base = "run baseline (no bug)"
run(base, baseline=True)
muts = [("old `[ ... ] && exec` bug (build exits 1 on success)", 'if [ "$cmd" = run ]; then exec "$exe"; fi # (Chapter 23: this used to be `[ ... ] && exec`, which made `mgc build` exit with status 1 on success)', '[ "$cmd" = run ] && exec "$exe"'),
("--passes ignored", '--convert-mg-to-affine $PASSES -o', '--convert-mg-to-affine -o'),
("-O ignored when building executables", '${MGC_CLANG:-clang-18} $OPT $MGC_CFLAGS "$W/$base.ll"', '${MGC_CLANG:-clang-18} $MGC_CFLAGS "$W/$base.ll"'),
("-O ignored when building libraries", '${MGC_CLANG:-clang-18} $OPT $MGC_CFLAGS -c', '${MGC_CLANG:-clang-18} $MGC_CFLAGS -c'),
("MGC_CFLAGS ignored", '$OPT $MGC_CFLAGS "$W/$base.ll"', '$OPT "$W/$base.ll"')]
try:
for label, a, b in muts:
if a not in orig: print(label, ": MUTATION DID NOT APPLY"); continue
open(MGC, "w").write(orig.replace(a, b, 1)); run(label)
finally:
open(MGC, "w").write(orig)
run("restored (baseline again)", baseline=True)
NOTE: this script deliberately breaks mgc. 'caught by' lines are EXPECTED: they show the tests can detect the bug.
run baseline (no bug): all tests pass (expected)
old `[ ... ] && exec` bug (build exits 1 on success): caught by perf/flags-reach-clang.mlir, perf/tiling-structure.mlir
--passes ignored: caught by perf/tiling-structure.mlir
-O ignored when building executables: caught by perf/flags-reach-clang.mlir
-O ignored when building libraries: caught by perf/flags-reach-clang.mlir
MGC_CFLAGS ignored: caught by perf/flags-reach-clang.mlir
restored (baseline again): all tests pass (expected)
Limits and what is not established¶
- One machine, one session. A shared cloud VM with four vCPUs, pinned to one core. Nothing here says how Mountain Goat behaves on other hardware, other compilers, or a quiet machine.
- One operation. Square
f64matrix products from 64 to 512. Nothing about elementwise operations, reductions, other shapes or sizes. - One tile size (32), not tuned. A better tile size would likely do better; none was searched for.
- No hardware counters. Explanations involving caches are consistent with the data but not demonstrated by measuring cache misses.
- No multithreading. Everything ran on one core. The machine has four.
- Which ingredient matters is not isolated for result 5 (tiling versus fixed shape); only the combination was measured.
- The GPU path is not measured at all. There is no GPU here.
- No test asserts speed, by design.
- Not a competitive matrix product. The best Mountain Goat variant is more than twice as slow as a simple hand-written loop at N = 512, and far below what a tuned library would achieve on this CPU.
Reproducing¶
cd docs/part23/code
../part22/code/build.sh # once
./machine_info.sh > machine_info_out.txt
./run_bench.sh > bench_out_1.txt && ./run_bench.sh > bench_out_2.txt
python3 summarize.py bench_out_1.txt bench_out_2.txt > summary.txt
./inspect_asm.sh > inspect_asm_out.txt
./mgc_mutation.py > mgc_mutation_out.txt
cd ../../part15/code && ./run_lit.sh # 93 tests
Chapter summary¶
mgcgained-O0to-O3,--passes,MGC_CFLAGSandMGC_CLANG; the old default (-O0) is unchanged.- Measured on one shared VM: clang's
-O2makes the generated matmul 2× to 6× faster than-O0; at-O2it matches the same loop written in C++, so Mountain Goat adds no overhead but also no cleverness. - Chapter 7's tiling pass gives 2.6× at N = 256 and 5.2× at N = 512 over untiled
-O2; with a fixed shape and all CPU instructions, it matches a hand-writtenikjloop at N = 256 and is the only build whose machine code uses vector instructions. - At N = 512 the best Mountain Goat variant is still about 2.1× slower than that hand-written loop.
- Repeated runs differ by up to 44%, so only large differences are claims.
- Testing the new options found a bug in
mgc build(exit status 1 on success) and an equivalent-mutant problem for-O, solved with a test seam.
Self-check questions¶
Each answer is collapsed; try the question first.
-
Why does this chapter report both the median and the minimum, and why does it run the whole experiment twice?
Answer
Timings on a real computer include interference (other processes, frequency changes, a cold cache), so one number is unreliable. The median ignores a few slow outliers and the minimum shows the least disturbed run. Running the whole experiment a second time shows how much the numbers move from run to run: here by up to 44%, which tells the reader which differences (large ones) can be trusted and which (1.0× to 1.2×) cannot.
-
What is a GFLOP/s, and why can it compare two implementations of the same product at the same size but not different sizes?
Answer
It is billions of floating-point operations per second; a product of N by N matrices costs 2·N³ operations, so dividing by the time gives the speed. At a fixed size the work is the same, so a higher number is simply faster. Across sizes the memory behavior changes (the matrices stop fitting in cache), so the same code runs at different speeds at different sizes, and the numbers do not measure the same thing.
-
The Mountain Goat matmul at
-O2matches the C++ijkloop. Does that mean Mountain Goat is fast?Answer
No. It means the compiler turned
a @ binto exactly the textbook loop, so it is no slower than that algorithm. The same table shows a hand-written loop with the middle loops swapped running about 5× faster at N = 256 and 12× faster at N = 512. "Matches the naive version" is a statement about overhead, not about speed. -
What does loop tiling do, and what would you expect to happen to its benefit as N grows?
Answer
It restructures the loops to work on small square blocks at a time so that the data a block needs stays in cache while it is reused. Its benefit should grow with N because the untiled loop's memory traffic gets worse as the matrices become larger than the cache. The measurements are consistent with that: 1.1× at N = 64, 2.3× at 128, 2.6× at 256, 5.2× at 512. Cache misses were not measured, so this is consistent with the data, not proven by it.
-
-O3 -march=nativemade the untiled matmul no faster. What did the machine code show, and what can you conclude?Answer
The assembly of the untiled functions contains zero vector or fused-multiply-add instructions: the loop is scalar, even though the CPU supports wide vectors. So "allow every instruction" cannot help if the compiler does not use them. What can be concluded is only that these builds are scalar; why the compiler declined to vectorize them was not investigated.
-
Result 5 says the tiled, fixed-shape build is fast and contains vector instructions. What does the chapter say it has not established?
Answer
Which ingredient matters. Only the combination (tiled and fixed shape) was built and measured. The dynamic-size tiled build is not vectorized, and the untiled fixed-shape build is not either, but a fixed-shape build tiled differently, or a dynamic build with a different tile size, was not tried. Claiming that "knowing the sizes" alone, or "tiling" alone, is the cause would go beyond the evidence.
-
Why is there no test saying "the tiled build is faster than the untiled one"?
Answer
Speed depends on the machine and how busy it is. A test like that would fail randomly on a loaded shared machine and pass on a quiet one, which makes it noise that teaches people to ignore failures. The tests instead check what must always hold: the results are identical across variants, the tiling pass really runs (loop counts), and the flags reach the compiler.
-
Ignoring the
-Oflag did not make any result-checking test fail. Why not, and how was it caught?Answer
An optimization level changes how fast the program runs, not what it computes, so no test of the output can see whether it was applied. The bug is an equivalent mutant with respect to results. It was caught by adding a seam (
MGC_CLANG) that lets a test substituteechofor clang, somgcprints the command line it would have run, and the test checks that-O2is on it. -
How did testing
mgc buildfind a bug that had existed since Chapter 20, and what was it?Answer
Earlier tests used
mgc runandmgc lib, which never reach the script's last line in the failing way. A new test usedmgc buildand checked it succeeded. The last line,[ "$cmd" = run ] && exec "$exe", evaluates to false when the command isbuild, and in a shell script the last command's status becomes the script's status, sobuildexited 1 on success. The fix is an explicitif. The lesson is that a new test exercised a path no earlier test used. -
What would you need to do to turn this chapter's results into a claim about Mountain Goat's performance in general?
Answer
Run on more machines (ideally quiet, fixed-frequency ones), more operations and shapes, tune the tile size, use hardware counters to check the cache explanation, isolate the tiling and fixed-shape effects, and compare against a tuned library. This chapter did none of that, so its results are statements about one operation on one shared virtual machine in one session.