Performance: measure, then change
Performance work is mostly measuring. This page runs the measurements in the course’s image (Linux on ARM64, Rust 1.99.1) and keeps to two rules. A time is printed only to show a direction, and it is labelled as one run. The rest are counts (allocator calls, instructions), which came out the same in the runs here, and sizes in bytes, which belong to this path and target. Steps whose output changes say so.
RememberMeasure a release build. Count what you can count. Let a time tell you which of two things is smaller, never a number to quote.
perf-lab/ ├── src/ │ ├── bin/ │ │ ├── allocs.rs a counting allocator │ │ ├── fold.rs loops the compiler can answer without running │ │ ├── overflow.rs what release changes besides speed │ │ ├── unwind.rs panic = abort │ │ └── work.rs debug against release │ ├── lib.rs three functions the page compiles to assembly │ └── main.rs ├── asm.sh prints one function from the assembly ├── Cargo.lock created by Cargo └── Cargo.toml the profiles
[package]name = "perf-lab"version = "0.1.0"edition = "2024"default-run = "app"
[[bin]]name = "app"path = "src/main.rs"
# Named profiles built on top of `release`: one setting changed each (and `tiny`, all of# them together). `cargo build --profile small` builds into target/small/.[profile.small]inherits = "release"opt-level = "z"
[profile.lto]inherits = "release"lto = true
[profile.one-unit]inherits = "release"codegen-units = 1
[profile.abort]inherits = "release"panic = "abort"
[profile.stripped]inherits = "release"strip = true
[profile.tiny]inherits = "release"opt-level = "z"lto = truecodegen-units = 1panic = "abort"strip = trueDebug and release are two programs
Section titled “Debug and release are two programs”cargo run builds the dev profile and cargo run --release builds the release profile (Cargo’s profile table). The same source gives the same answer, and the program asserts that its loop and its iterator chain agree:
use std::time::Instant;
// How many steps the Collatz process takes to get from n to 1.fn collatz_steps(mut n: u64) -> u64 { let mut steps = 0; while n != 1 { n = if n % 2 == 0 { n / 2 } else { 3 * n + 1 }; steps += 1; } steps}
fn main() { let limit = 300_000; println!("debug assertions on: {}", cfg!(debug_assertions));
let start = Instant::now(); let mut with_loop = 0; for n in 1..=limit { with_loop += collatz_steps(n); } let loop_time = start.elapsed();
let start = Instant::now(); let with_iter: u64 = (1..=limit).map(collatz_steps).sum(); let iter_time = start.elapsed();
// The two versions are the same computation, so the answers must match. assert_eq!(with_loop, with_iter); println!("total steps for 1..={limit}: {with_iter}"); println!("for loop: {loop_time:?}"); println!("iterator chain: {iter_time:?}");}debug assertions on: true total steps for 1..=300000: 35669725 for loop: 133.072524ms iterator chain: 135.173913ms$ cargo run --release --bin work # one run on this VM, 8 cores (colima), varies
debug assertions on: false total steps for 1..=300000: 35669725 for loop: 26.300602ms iterator chain: 26.242352ms
This output changes from run to run. This is one real run.
In this run the debug build printed the larger time for both versions. The code explains it better than a ratio. Three functions compiled for release and for debug (sum_to is (0..n).sum() and sum_loop is a for loop):
$ cargo rustc -q --release --lib -- --emit asm $ sh asm.sh release sum_const _RNvCs1sbkSINsBSH_8perf_lab9sum_const: mov w0, #40748 movk w0, #7, lsl #16 ret $ sh asm.sh release sum_to _RNvCs1sbkSINsBSH_8perf_lab6sum_to: cbz x0, .LBB0_2 sub x8, x0, #1 sub x9, x0, #2 mul x10, x8, x9 umulh x9, x8, x9 extr x9, x9, x10, #1 add x0, x8, x9 ret $ sh asm.sh release sum_loop _RNvCs1sbkSINsBSH_8perf_lab8sum_loop: cbz x0, .LBB1_2 sub x8, x0, #1 sub x9, x0, #2 mul x10, x8, x9 umulh x9, x8, x9 extr x9, x9, x10, #1 add x0, x8, x9 ret $ cargo rustc --lib -- --emit asm # the debug build $ sh asm.sh debug sum_to _RNvCs6D0RQGRaSru_8perf_lab6sum_to: sub sp, sp, #32 stp x29, x30, [sp, #16] add x29, sp, #16 mov x1, x0 str x1, [sp, #8] mov x0, xzr bl _RINvYINtNtNtCsaWcbhsS8OaW_4core3ops5range5RangeyENtNtNtNtBa_4iter6traits8iterator8Iterator3sumyECs6D0RQGRaSru_8perf_lab ldp x29, x30, [sp, #16] add sp, sp, #32 ret $ sh asm.sh debug sum_loop _RNvCs6D0RQGRaSru_8perf_lab8sum_loop: sub sp, sp, #80 stp x29, x30, [sp, #64] add x29, sp, #64 mov x1, x0 stur x1, [x29, #-16] mov x0, xzr str xzr, [sp, #8] bl _RNvXNtNtNtCsaWcbhsS8OaW_4core4iter6traits7collectINtNtNtB8_3ops5range5RangeyENtB2_12IntoIterator9into_iterCs6D0RQGRaSru_8perf_lab str x0, [sp, #16] str x1, [sp, #24] b .LBB5_1 add x0, sp, #16 bl _RNvXs4_NtNtCsaWcbhsS8OaW_4core4iter5rangeINtNtNtB9_3ops5range5RangeyENtNtNtB7_6traits8iterator8Iterator4nextCs6D0RQGRaSru_8perf_lab str x0, [sp, #32] str x1, [sp, #40] ldr x8, [sp, #32] tbnz w8, #0, .LBB5_2 b .LBB5_3 ldr x8, [sp, #40] stur x8, [x29, #-8] ldr x9, [sp, #8] add x8, x9, x8 str x8, [sp] subs x8, x8, x9 b.lo .LBB5_5 b .LBB5_4 ldr x0, [sp, #8] ldp x29, x30, [sp, #64] add sp, sp, #80 ret ldr x8, [sp] str x8, [sp, #8] b .LBB5_1 adrp x0, .Lanon.fff5426ee47afe1ffe0adc2e8d0daeb7.3 add x0, x0, :lo12:.Lanon.fff5426ee47afe1ffe0adc2e8d0daeb7.3 bl _RNvNtNtCsaWcbhsS8OaW_4core9panicking11panic_const24panic_const_add_overflow $ for each function: count the call instructions (bl) in sh asm.sh debug|release <function> sum_const: calls in debug 1, in release 0 sum_to: calls in debug 1, in release 0 sum_loop: calls in debug 3, in release 0 $ diff the instructions of sum_to and sum_loop in the release build (label numbers aside) sum_to and sum_loop: same instructions
- In release,
sum_constis a constant andsum_tohas no loop at all: the compiler worked out a formula (mul,umulh). - In release,
sum_toandsum_loopcame out as the same instructions. That is one case, not a law about iterators. - In debug,
sum_tomakes one call (toIterator::sum, not inlined) andsum_loopmakes three, where release makes none. The debugsum_loopalso loads and storestotalin memory on each pass.
The second difference is behaviour. The Cargo docs say that when overflow-checks is enabled, “a panic will occur on overflow”. It was on in debug, off in release, and is a setting of its own:
$ cargo build --bin overflow && ./target/debug/overflow # the thread id in the panic line is replaced by N debug assertions on: true wrapping_add: 0 checked_add: None thread 'main' (N) panicked at src/bin/overflow.rs:9:34: attempt to add with overflow note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace $ cargo build -q --release --bin overflow && ./target/release/overflow debug assertions on: false wrapping_add: 0 checked_add: None x + 1: 0 $ cargo build --release --bin overflow --config profile.release.overflow-checks=true && ./target/release/overflow # thread id replaced by N debug assertions on: false wrapping_add: 0 checked_add: None thread 'main' (N) panicked at src/bin/overflow.rs:9:34: attempt to add with overflow note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
So “release is the same program, faster” is not quite true: an overflow that panics in debug wraps in release unless you turn the check on. Integer overflow is covered earlier in the course.
Profile settings, and sizes
Section titled “Profile settings, and sizes”Each profile in Cargo.toml changes one setting from release (tiny changes all of them). The listing is the size of the same small program (a word counter in src/main.rs) under each, on this target. Another program or target gives other sizes:
$ cargo build --bin app $ for p in release small lto one-unit abort stripped tiny; do cargo build --profile $p --bin app; done $ stat -c '%s bytes %n' target/*/app # this path, Linux ARM64, rustc 1.99.1; the debug size changed with the build directory, varies 542504 bytes target/abort/app 5199912 bytes target/debug/app 444224 bytes target/lto/app 542824 bytes target/one-unit/app 543912 bytes target/release/app 547984 bytes target/small/app 398168 bytes target/stripped/app 332528 bytes target/tiny/app $ cargo run -q --profile tiny the: 4 a: 1 and: 1 20 distinct words
This output changes from run to run. This is one real run.
What the listing shows for this program:
- The debug build is the largest by far. Debug information (the
debugsetting) makes up most of the difference: release withdebug = truecame out about as large as the debug build (second task below). The debug size also changed with the build directory. stripandltoeach made the release binary smaller, andtiny(all five settings) is the smallest.opt-level = "z"alone did not make it smaller. The Cargo docs warn of surprising results, such as ‘the “s” and “z” levels not being necessarily smaller’ (profiles). min-sized-rust notes that “The prebuiltlibstdis optimized for speed, not size”, a likely reason here: a small program’sopt-levelreaches only its own code.- The Performance Book describes
ltoandcodegen-units = 1as run-time options too. This page times neither.
panic = "abort" changes behaviour, not only size. With the default, catch_unwind caught the panic and the guard’s Drop ran. With abort the process was killed by a signal and neither line printed (catch_unwind says it catches only unwinding panics):
use std::panic;
struct Noisy;
impl Drop for Noisy { fn drop(&mut self) { println!("Noisy dropped"); }}
fn main() { panic::set_hook(Box::new(|_| {})); // keep the output about the setting, not the message let result = panic::catch_unwind(|| { let _guard = Noisy; panic!("boom"); }); println!("caught: {}", result.is_err());}Noisy dropped caught: true$ cargo run --profile abort --bin unwind; echo "exit code: $?" # the process id is replaced by N; "core dumped" depends on the system, varies
bash: line N: N Aborted (core dumped) cargo run --profile abort --bin unwind exit code: 134
This output changes from run to run. This is one real run.
Count first
Section titled “Count first”Time is noisy. The number of calls to the allocator did not change between runs. A global allocator that wraps the system one and counts its calls takes a dozen lines (the formatting lesson uses the same pattern). unsafe impl is boilerplate here (GlobalAlloc). It counts calls, not bytes, and a realloc is a call:
use std::alloc::{GlobalAlloc, Layout, System};use std::fmt::Write as _;use std::hint::black_box;use std::rc::Rc;use std::sync::atomic::{AtomicUsize, Ordering::Relaxed};
// Counts calls to the system allocator. (`unsafe impl` is boilerplate here: the// Unsafe lesson explains why it is needed.)struct Counting;static CALLS: AtomicUsize = AtomicUsize::new(0);
unsafe impl GlobalAlloc for Counting { unsafe fn alloc(&self, layout: Layout) -> *mut u8 { CALLS.fetch_add(1, Relaxed); unsafe { System.alloc(layout) } } unsafe fn dealloc(&self, ptr: *mut u8, layout: Layout) { unsafe { System.dealloc(ptr, layout) } } unsafe fn realloc(&self, ptr: *mut u8, layout: Layout, new_size: usize) -> *mut u8 { CALLS.fetch_add(1, Relaxed); // growing a buffer in place or by copying: one call unsafe { System.realloc(ptr, layout, new_size) } }}
#[global_allocator]static COUNTING: Counting = Counting;
// Runs `work` and returns how many times it asked the allocator for memory.fn count<T>(work: impl FnOnce() -> T) -> usize { let before = CALLS.load(Relaxed); black_box(work()); CALLS.load(Relaxed) - before}
fn main() { let line = String::from("alpha beta gamma delta epsilon zeta eta theta");
// Owned pieces versus borrowed pieces of the same line. println!("split into Vec<String>: {}", count(|| line.split(' ').map(String::from).collect::<Vec<_>>())); println!("split into Vec<&str>: {}", count(|| line.split(' ').collect::<Vec<_>>()));
// Cloning: a String copies its text; an Rc only bumps a counter. let shared = Rc::new(line.clone()); println!("String::clone: {}", count(|| line.clone())); println!("Rc::clone: {}", count(|| Rc::clone(&shared)));
// Growing a Vec one push at a time, or asking for the room first. println!("1000 pushes, no hint: {}", count(|| { let mut v = Vec::new(); for i in 0..1000u32 { v.push(i); } v })); println!("1000 pushes, capacity: {}", count(|| { let mut v = Vec::with_capacity(1000); for i in 0..1000u32 { v.push(i); } v }));
// Building 100 lines of text: a new String for each, or one buffer written into. println!("format! x100: {}", count(|| (0..100).map(|i| format!("item {i}")).collect::<Vec<_>>())); println!("write! into one String: {}", count(|| { let mut out = String::new(); for i in 0..100 { writeln!(out, "item {i}").unwrap(); } out }));}split into Vec<String>: 10 split into Vec<&str>: 2 String::clone: 1 Rc::clone: 0 1000 pushes, no hint: 9 1000 pushes, capacity: 1 format! x100: 101 write! into one String: 8$ cargo run --release --bin allocs
split into Vec<String>: 10 split into Vec<&str>: 2 String::clone: 1 Rc::clone: 0 1000 pushes, no hint: 9 1000 pushes, capacity: 1 format! x100: 101 write! into one String: 8
The counts were the same in debug and release. They show:
- Splitting into
Vec<&str>made fewer allocations than intoVec<String>: the&strpieces borrow the line (Strings). String::cloneallocated once andRc::clonenot at all (Smart pointers). A clone is not always a copy of the data.- A
Vecgrown bypushasked the allocator repeatedly;with_capacityasked once (Capacity and growth). Whether that matters is a question only a benchmark answers. format!per item allocated aStringper item;write!into oneStringonly grew it.
A timing the compiler can delete
Section titled “A timing the compiler can delete”A loop whose result is unused, or whose answer has a formula, may not run at all. std::hint::black_box hides a value from the optimiser, and its docs say it works on a “best-effort” basis. This is what that means in practice (release build, one run on this VM, 8 cores (colima), varies):
use std::hint::black_box;use std::time::Instant;
// A loop whose total has a short formula: the compiler can skip the looping.fn sum_squares(n: u64) -> u64 { (0..n).map(|i| i.wrapping_mul(i)).fold(0, u64::wrapping_add)}
// A loop that scrambles the bits each time round: no formula, so it has to run.fn mix(n: u64) -> u64 { let mut x = 88172645463325252u64; for _ in 0..n { x ^= x << 13; x ^= x >> 7; x ^= x << 17; } x}
fn time(label: &str, work: impl FnOnce() -> u64) { let start = Instant::now(); let result = work(); println!("{label:<36} result {result:>20}, took {:?}", start.elapsed());}
fn main() { time("sum_squares(100_000_000)", || sum_squares(100_000_000)); time("sum_squares(black_box(100_000_000))", || sum_squares(black_box(100_000_000))); time("mix(100)", || mix(100)); time("mix(black_box(100))", || mix(black_box(100))); time("mix(100_000_000)", || mix(100_000_000)); time("mix(black_box(100_000_000))", || mix(black_box(100_000_000)));}sum_squares(100_000_000) result 662921401752298880, took 42ns sum_squares(black_box(100_000_000)) result 662921401752298880, took 0ns mix(100) result 10653220568048883440, took 0ns mix(black_box(100)) result 10653220568048883440, took 167ns mix(100_000_000) result 13637911440367556603, took 139.737943ms mix(black_box(100_000_000)) result 13637911440367556603, took 140.87787ms$ cargo rustc --release --bin fold -- --emit asm; then count the umulh instructions in the .s file
1
This output changes from run to run. This is one real run.
sum_squares of a hundred million printed a time in nanoseconds, with or without black_box on the input: the compiler used a formula for the total, so the loop never ran. The assembly step backs that up: the release build contains a umulh instruction, the multiply-high the formula used in the asm session. black_box hid the number, and the formula still worked for any number. mix has no formula, so with a large count it ran for milliseconds either way. With a small count, mix(100) printed a smaller time without black_box than with it in this run. Three things help a benchmark: the input passed through black_box, the result passed through it too, and work the compiler cannot shortcut. Criterion passes the result through black_box for you; the input is yours to hide, as benches/mix.rs does. It also repeats the call and reports a range. The Performance Book lists it, with Divan, as a more sophisticated alternative to the built-in #[bench] tests, which need nightly Rust. It is a separate crate, so its first run compiles it (needs network):
use criterion::{Criterion, criterion_group, criterion_main};use mix_bench::mix;use std::hint::black_box;
fn bench_mix(c: &mut Criterion) { // The input and the result both go through black_box, so the compiler cannot // precompute the answer or drop the call. c.bench_function("mix 1000 rounds", |b| b.iter(|| black_box(mix(black_box(88172645463325252), 1000))));}
criterion_group!(benches, bench_mix);criterion_main!(benches);mix 1000 rounds time: [1.3309 µs 1.3371 µs 1.3432 µs]
This output changes from run to run. This is one real run.
Profilers
Section titled “Profilers”A profiler tells you where the time went, which a benchmark does not. The usual Linux tools, perf and cargo flamegraph (which relies on perf), and samply (which uses perf events on Linux), are named here but not run: perf installs with apt inside the session (needs network), but this VM’s setting refuses it.
$ apt-get install linux-perf # needs network perf version 6.12.113 $ cat /proc/sys/kernel/perf_event_paranoid 4 $ perf stat -e task-clock true 2>&1 | head -2 Error: Access to performance monitoring and observability operations is limited.
The same questions in your language
Section titled “The same questions in your language”Where the image has the tool, the cell is a run. The other cells name a tool and are marked not run.
| Language | Optimised or not | Count allocations | Benchmark tool |
|---|---|---|---|
| Rust | --release, [profile.*] |
counting allocator (above) | Criterion (run above) |
| Go | go tool compile has -N (no optimisation) and -l (no inlining), help text below; no build run |
testing.AllocsPerRun (run below) |
go test -bench, in the testing package, not run |
| Python | not run | sys.getallocatedblocks (run below) |
timeit, not run |
| TypeScript | not run | not run | node --cpu-prof for profiles (Node CLI), not run |
| Java, Kotlin | not run | not run | JMH, not run |
| C# | not run | not run | BenchmarkDotNet, not run |
| C, C++ | -O0 and -O2 (C run below; g++ not run) |
not run | not run |
$ go run allocs.go # Go, testing.AllocsPerRun strings.Split: 1 1000 appends, no hint: 9 1000 appends, capacity: 1 $ go tool compile -help # the two flags that switch optimisation and inlining off -N disable optimizations -l disable inlining $ python3 allocs.py # Python 3.13, sys.getallocatedblocks; the count can vary, varies blocks gained by list(range(1000)): 746 blocks gained by list(range(200)): 2 $ gcc -O0 -S sum.c # C, no optimisation sum_to: sub sp, sp, #32 str x0, [sp, 8] str xzr, [sp, 24] str xzr, [sp, 16] b .L2 ldr x1, [sp, 24] ldr x0, [sp, 16] add x0, x1, x0 str x0, [sp, 24] ldr x0, [sp, 16] add x0, x0, 1 str x0, [sp, 16] ldr x1, [sp, 16] ldr x0, [sp, 8] cmp x1, x0 bcc .L3 ldr x0, [sp, 24] add sp, sp, 32 ret $ gcc -O2 -S sum.c # C, optimised sum_to: mov x2, x0 cbz x0, .L4 mov x1, 0 mov x0, 0 add x0, x0, x1 add x1, x1, 1 cmp x2, x1 bne .L3 ret mov x0, 0 ret
This output changes from run to run. This is one real run.
- Go printed 1 for
strings.Splitwhere Rust’sVec<&str>split took 2; the two jobs are different code, so that is not a comparison of the languages. The appends matched: 9 for a thousand without a size hint and 1 withmake(..., 0, 1000), as Rust’s 9 and 1. Both grow a slice by reallocating. - Python gained 746 blocks for a list of a thousand integers and 2 for a list of two hundred. The Python 3.13 docs say CPython keeps one shared object for each integer from -5 to 256, so larger ones are objects of their own. The
sysdocs warn that this count can vary between calls. - C at
-O0kepttotalin memory on every pass, as the debug Rustsum_loopdid in theasmsession. At-O2it kept it in a register. The-O2listing still has the loop: GCC 14 did not turn this one into a formula, where rustc did. That is one loop and one compiler version, not a verdict on either.
Myths, each tested or dropped
Section titled “Myths, each tested or dropped”| Belief | What the run showed |
|---|---|
| “Release is the same program, only faster.” | An overflow panicked in debug and wrapped in release, until overflow-checks was set. |
| “Cloning copies the data.” | String::clone allocated once, Rc::clone not at all. |
| “A benchmark that takes nanoseconds shows a fast program.” | The formula loop took nanoseconds because it did not run. |
“opt-level = "z" gives a smaller binary.” |
Alone, it was bigger than plain release here (this program, this target). |
| “Iterator chains cost more than loops.” | In this release build sum_to and sum_loop were the same instructions. In debug, sum_to made 1 call and sum_loop 3. |
| “More threads make any loop faster.” | Rayon printed the parallel version slower for 10 items. |
Try it yourself
Section titled “Try it yourself”Each task is a step in the session below, run in the image.
- Give the debug profile
opt-level = 3from the command line:cargo run --bin work --config profile.dev.opt-level=3.debug assertions onstill printstrue, and the time printed is smaller than the plain debug run. Optimisation and checks are separate settings. - Build release with
--config profile.release.debug=trueand list the size. The binary is about as large as the debug one: the debug information is most of the difference. - Change
with_capacity(1000)towith_capacity(10)inallocs.rs. The pushes now take more than one allocation but fewer than with no hint, because the buffer still has to grow.
$ cargo run --bin work --config profile.dev.opt-level=3 # one run on this VM, varies debug assertions on: true total steps for 1..=300000: 35669725 for loop: 38.423315ms iterator chain: 37.779227ms $ cargo build --release --config profile.release.debug=true; stat -c '%s bytes %n' target/release/app # varies with the build directory 5009408 bytes target/release/app $ sed -i 's/with_capacity(1000)/with_capacity(10)/' src/bin/allocs.rs; cargo run --bin allocs | grep pushes 1000 pushes, no hint: 9 1000 pushes, capacity: 8
This output changes from run to run. This is one real run.
Read more
Section titled “Read more”- The Cargo Book: Profiles and the Rust Book on release profiles, for every setting used above.
- The Rust Performance Book: build configuration, heap allocations, benchmarking and profiling.
- min-sized-rust, on shrinking binaries.
- The Criterion.rs book (the crate here is
criterion0.8.2, as pinned inCargo.lock). - In this course: Formatting (the first counting allocator), Iterators, Rayon and Testing.
- Other languages: Go’s
testing, Python’stimeit, GCC’s optimisation options.
Learn Rust is an independent project, not affiliated with the Rust Project or the Rust Foundation. Code and text are under the MIT licence.Source on GitHub.