Timing a block¶

Level: 201 · working knowledge

One line: let start = Instant::now(); before and start.elapsed() after is the whole API — and the one Duration it hands back is a single sample of a noisy process: good enough for a log line, not a benchmark.

use std::time::Instant;

fn main() {
    let start = Instant::now();
    let total: u64 = (1..=1_000_000).sum();
    let took = start.elapsed();

    println!("{total}");                // 500000500000
    println!("summed in {took:?}");     // a different Duration every run
}

Two calls, and which clock¶

Instant::now() reads the monotonic clock; elapsed() reads it again and subtracts. The result is a Duration, so it cannot be negative — a stopwatch reading that went backwards would saturate to zero rather than go negative.

Never time with SystemTime. It is the clock NTP, the user or an administrator can set, and a step in the middle of your block makes the timing wrong by the size of the step, in either direction. Its API says so: SystemTime::elapsed returns a Result, and its docs put the advice in one line: "To measure elapsed time reliably, use Instant instead."

What you can safely say about the number¶

The example below prints no durations: a duration is different on every run, and would break its own answer key. It prints the one verdict std actually promises. thread::sleep ↗ "may sleep longer than the duration specified due to scheduling specifics or platform-dependent functionality. It will never sleep less." So after sleeping 20 ms, took >= 20ms is true on every machine. took < 21ms is not: nothing promises a ceiling, and on a busy machine the scheduler may hand the thread back much later.

That asymmetry is the general shape. A timing is the time your code took plus everything else that happened in the same interval, and only the plus has a floor.

A helper that returns the time¶

Time a closure, and hand the Duration back instead of printing it:

use std::time::{Duration, Instant};

fn timed<T>(f: impl FnOnce() -> T) -> (T, Duration) {
    let start = Instant::now();
    let value = f();
    (value, start.elapsed())
}

fn main() {
    let (total, took) = timed(|| (1..=1_000_000u64).sum::<u64>());
    println!("{total}");                // 500000500000
    println!("{took:?}");               // a different Duration every run
}

The caller decides whether to log it, compare it with a budget, or drop it — and the value comes back as well, so wrapping a call in timed changes nothing else about the code.

What one timing cannot tell you¶

A single elapsed() is one sample, and it cannot separate the code you meant to measure from:

The build. cargo run builds without optimization, and an unoptimized build runs different machine code from the release build of the same source — see what the optimizer does. Time --release, or you are timing the debug build.
The first run. The first call pays for page faults and cold caches that later calls do not.
The optimizer. In a release build, work whose result nobody uses can be deleted, and the timing then measures an empty block. black_box is a hint is about that, and about how little it promises.
The spread. Two runs of the same code give two numbers. One number cannot tell you whether a 5% difference is the code or the noise; many runs and their distribution can.

That last point is what separates timing from benchmarking, and it is the part std leaves to crates. The Rust Performance Book's benchmarking chapter ↗ is the method; Criterion ↗ is the tool most Rust projects reach for. And the clock itself has a cost — asking the time takes time — which the C++ chapter ↗ takes apart.

The verified output¶

Verified output of timing_a_block.rs — regenerated by tools/run_examples.py, never hand-typed.

1. The whole API is two calls
   slept 20ms; took >= 20ms        true

2. Hand the Duration back; let the caller decide what to do with it
   the value comes back too        500000500000
   a 20ms sleep, timed through it  took >= 20ms: true

If you are coming from another language¶

C++. auto start = std::chrono::steady_clock::now(); and then steady_clock::now() - start — the same two calls, plus a duration_cast to get a unit out. Two differences. C++ offers high_resolution_clock, which libstdc++ makes an alias of system_clock — exactly the clock not to time with (two clocks has the measurement). And C++ lets system_clock::now() - start compile when start came from the same clock. The C++ side of this page is Timing a block ↗.
Python. start = time.perf_counter() … time.perf_counter() - start is this page in floats. For the many-runs half Python ships timeit ↗ in its standard library; Rust's std has nothing like it, which is why this page ends at a crate. Two habits transfer unchanged: never time.time() for this, and never trust the first run.
ABAP. (Not machine-checked — CI cannot run ABAP; this is from the ABAP keyword documentation.) GET RUN TIME FIELD t1. … GET RUN TIME FIELD t2. and t2 - t1 microseconds is this page — the documentation calls the code between the two a measuring section. It adds a ceiling a Duration does not have: the field is an i, and the documentation says to keep measuring sections under 1,000 seconds so the value range is not exceeded. For the many-runs half it points to the class CL_ABAP_RUNTIME and to the runtime analysis tool.

Po polsku¶

Pomiar czasu (timing) fragmentu kodu to w Ruscie dwa wywołania: Instant::now() przed i elapsed() po. Wynik to Duration, który nie może być ujemny. Do tego celu nigdy nie używa się SystemTime — zegar systemowy może zostać przestawiony w trakcie pomiaru, a dokumentacja mówi wprost, że do rzetelnego mierzenia upływu czasu służy Instant.

Jeden pomiar to jednak jedna próbka (sample), a nie benchmark. Czas, który zwraca elapsed(), to czas twojego kodu plus wszystko inne, co zdarzyło się w tym samym przedziale — planista (scheduler) systemu, zimne pamięci podręczne (cache), pierwsze wywołanie. Z gwarancji zostaje tylko dolna granica: thread::sleep nigdy nie śpi krócej, niż mu kazano, ale może dłużej — i dlatego przykład na tej stronie drukuje wyłącznie werdykt took >= 20ms, a nie samą liczbę.

Pojedynczy pomiar nie odróżni też buildu bez optymalizacji (cargo run) od --release, pierwszego uruchomienia od kolejnych ani pracy, którą optymalizator po cichu usunął. Rozrzut wyników — statystyka wielu przebiegów — to już mikrobenchmark i w Ruscie zajmują się nim crate'y, najczęściej Criterion; w bibliotece standardowej nie ma odpowiednika pythonowego timeit.

Szukaj po polsku: pomiar czasu wykonania w Ruscie · mikrobenchmark · rust Instant elapsed · rust criterion benchmark · rust perf book benchmarking