bench: microsecond timing via tools/timeit, toybox oracle, words to 10M lines

This commit is contained in:
2026-09-09 05:23:54 -04:00
parent 7b3a535173
commit 3cde946a68
7 changed files with 186 additions and 138 deletions
+104 -123
View File
@@ -12,7 +12,7 @@
# checkfastwc() verify a release build of fastwc exists
# checkwc() locate the coreutils wc implementation
# createtxt() create (or reuse) a text file with N such lines
# time_ms() run a command once, print elapsed wall time in ms
# timeit() run a command once, print elapsed wall time in µs
# capture_count() print the first whitespace-separated field of output
# run_case() race fastwc against the reference on a file argument
# run_stdin_case() same, but feeding the file through standard input
@@ -36,9 +36,14 @@ export LC_CTYPE=C
FASTWC="$REPO_DIR/bin/release/fastwc"
DATA_DIR="$SCRIPT_DIR/.data"
GENFILE="$REPO_DIR/benchmarks/tools/genfile" # optional C helper, built by test-all.sh
TIMEIT="$REPO_DIR/benchmarks/tools/timeit" # µs exec timer, built by test-all.sh
BENCH_NAME="${BENCH_NAME:-wc}" # set by the caller: coreutils
BENCH_REPS="${BENCH_REPS:-3}" # interleaved runs per case; minimum is kept
# A reference wc that finishes under this many µs was really measuring
# startup, not throughput. Those cases are checked for correctness and
# reported, but excluded from the averages (see finish_race).
RACE_FLOOR_US="${RACE_FLOOR_US:-5000}"
RESULT_ROWS="" # accumulated results table
# Per-case speedup ratios accumulate here so the run can end with the
@@ -68,14 +73,16 @@ checkfastwc() {
}
# wc_impl <cmd...> — identify a wc implementation from its --version
# answer. coreutils and fastwc respond to --version; busybox does not
# have the option and names itself in the error it prints instead.
# answer. coreutils, fastwc and toybox respond to --version; busybox
# does not have the option and names itself in the error it prints
# instead.
wc_impl() {
local out
out=$("$@" --version 2>&1)
case "$out" in
*'GNU coreutils'*) printf 'coreutils\n' ;;
fastwc*) printf 'fastwc\n' ;;
toybox*) printf 'toybox\n' ;;
*BusyBox*) printf 'busybox\n' ;;
*) printf 'unknown\n' ;;
esac
@@ -85,15 +92,17 @@ wc_impl() {
# for every wc binary and identifies each by its --version answer. A wc
# that answers as fastwc is a symlink somebody made to our own binary —
# people do symlink wc to fastwc — and is skipped, because racing
# ourselves proves nothing. Busybox usually exists only as the
# multi-call binary, so that is probed too; it is back in the suite for
# shits and giggles, not because it is a challenge.
# Sets COREUTILS_CMD, BUSYBOX_CMD (empty if absent) and ORACLES, and
# points WC_CMD at coreutils. Exits if no coreutils wc is found.
# ourselves proves nothing. Busybox and toybox usually exist only as the
# multi-call binaries, so those are probed too; they are back in the
# suite for shits and giggles, not because they are a challenge.
# Sets COREUTILS_CMD, BUSYBOX_CMD, TOYBOX_CMD (empty if absent) and
# ORACLES, and points WC_CMD at coreutils. Exits if no coreutils wc is
# found.
checkwc() {
local dir impl
COREUTILS_CMD=()
BUSYBOX_CMD=()
TOYBOX_CMD=()
ORACLES=''
printf 'locating wc implementations... '
@@ -118,6 +127,12 @@ checkwc() {
printf 'busybox; '
fi
;;
toybox)
if [[ ${#TOYBOX_CMD[@]} -eq 0 ]]; then
TOYBOX_CMD=("$dir/wc")
printf 'toybox; '
fi
;;
*) ;;
esac
done
@@ -129,6 +144,13 @@ checkwc() {
printf 'busybox; '
fi
# same for toybox
if [[ ${#TOYBOX_CMD[@]} -eq 0 ]] && command -v toybox >/dev/null 2>&1 \
&& [[ "$(wc_impl toybox wc)" == 'toybox' ]]; then
TOYBOX_CMD=(toybox wc)
printf 'toybox; '
fi
if [[ ${#COREUTILS_CMD[@]} -eq 0 ]]; then
printf 'none\n'
printf 'configure: error: no coreutils wc found in PATH\n' >&2
@@ -140,14 +162,16 @@ checkwc() {
WC_CMD=("${COREUTILS_CMD[@]}")
ORACLES='coreutils'
[[ ${#BUSYBOX_CMD[@]} -gt 0 ]] && ORACLES="$ORACLES busybox"
[[ ${#TOYBOX_CMD[@]} -gt 0 ]] && ORACLES="$ORACLES toybox"
}
# select_oracle <coreutils|busybox> — point the racing functions at the
# chosen oracle by setting BENCH_NAME and WC_CMD.
# select_oracle <coreutils|busybox|toybox> — point the racing functions
# at the chosen oracle by setting BENCH_NAME and WC_CMD.
select_oracle() {
case "$1" in
coreutils) BENCH_NAME='coreutils'; WC_CMD=("${COREUTILS_CMD[@]}") ;;
busybox) BENCH_NAME='busybox'; WC_CMD=("${BUSYBOX_CMD[@]}") ;;
toybox) BENCH_NAME='toybox'; WC_CMD=("${TOYBOX_CMD[@]}") ;;
*) return 1 ;;
esac
return 0
@@ -199,24 +223,17 @@ createtxt() {
printf '%s\n' "$TEXT_FILE"
}
# time_ms <cmd...> — run a command once and print elapsed wall time in ms.
time_ms() {
local s e
s=$(date +%s%N)
"$@" >/dev/null 2>&1
e=$(date +%s%N)
printf '%s\n' "$(( (e - s) / 1000000 ))"
}
# time_us <cmd...> — run a command once and print elapsed wall time in µs.
# More precise than time_ms: sub-millisecond runs come out as e.g. 812,
# not 0. The benchmark keeps the µs reading for fastwc and derives the ms.
time_us() {
local s e
s=$(date +%s%N)
"$@" >/dev/null 2>&1
e=$(date +%s%N)
printf '%s\n' "$(( (e - s) / 1000 ))"
# timeit <cmd...> — run a command once and print elapsed wall time in µs
# on stdout, with the command's own output discarded. The clock starts in
# main(), after timeit's own loader has run, so every binary pays the same
# bookkeeping and the reading is the child's fork + exec + run + exit.
timeit() {
[[ -x "$TIMEIT" ]] || {
printf 'error: %s not built — run test-all.sh (or "make bench") first\n' \
"$TIMEIT" >&2
exit 1
}
"$TIMEIT" "$@"
}
# capture_count <cmd...> — print the first whitespace-separated field of a
@@ -225,10 +242,10 @@ capture_count() {
"$@" 2>/dev/null | awk 'NR == 1 { print $1 }'
}
# write_failed_report <label> <reason> <wc_ms> <fast_ms> — write the
# write_failed_report <label> <reason> <wc_us> <fast_us> — write the
# human readable failure report to FAILED-benchmark.txt next to the suite.
write_failed_report() {
local label="$1" reason="$2" wc_ms="$3" fast_ms="$4"
local label="$1" reason="$2" wc_us="$3" fast_us="$4"
local report="$SCRIPT_DIR/FAILED-benchmark.txt"
{
@@ -239,7 +256,7 @@ write_failed_report() {
printf 'failure : %s\n' "$reason"
printf '\nresults\n'
printf '%s\n' '-------'
printf '%-28s %10s %22s %8s %s\n' 'test' 'wc' 'fastwc (ms µs)' 'ratio' 'status'
printf '%-28s %16s %24s %8s %s\n' 'test' 'wc' 'fastwc (µs)' 'ratio' 'status'
printf '%s' "$RESULT_ROWS"
printf '\nfastwc must never be slower than %s wc — benchmark aborted.\n' "$BENCH_NAME"
} > "$report"
@@ -248,6 +265,45 @@ write_failed_report() {
printf 'full results written to %s\n' "$report" >&2
}
# finish_race <label> <wc_count> <fast_count> <wc_us> <fast_us> — turn the
# measured counts and times into a verdict. A count mismatch fails
# outright. A reference that finished under RACE_FLOOR_US was really
# measuring startup, not throughput: the case is reported as PASS
# (startup-bound) and left out of the averages. Raced cases pass when
# fastwc is not slower than the reference beyond a small dead-heat slack
# (200µs + 2%) that absorbs scheduler jitter on genuinely even races.
finish_race() {
local label="$1" wc_count="$2" fast_count="$3" wc_us="$4" fast_us="$5"
local ratio='-' verdict='PASS' reason='' row slack
if [[ "$fast_count" != "$wc_count" ]]; then
verdict='FAIL'
reason="output mismatch (fastwc: ${fast_count}, ${BENCH_NAME} wc: ${wc_count})"
elif (( wc_us < RACE_FLOOR_US )); then
verdict='PASS (startup-bound)'
else
ratio=$(awk -v f="$fast_us" -v w="$wc_us" 'BEGIN { printf "%.2fx", w / f }')
# feed the end-of-run average speedup (raced rows only)
printf '%s\t%s\n' "$BENCH_NAME" "${ratio%x}" >> "$RATIOS_FILE"
slack=$((200 + wc_us / 50))
if (( fast_us > wc_us + slack )); then
verdict='FAIL'
reason="fastwc was slower (fastwc: ${fast_us}µs vs ${BENCH_NAME} wc: ${wc_us}µs)"
fi
fi
row=$(printf '%-28s %16s %24s %8s %s\n' \
"$label" "wc: ${wc_us}µs" "fastwc: ${fast_us}µs" "$ratio" "$verdict")
RESULT_ROWS+="${row}"$'\n'
printf '%s\n' "$row"
if [[ "$verdict" == 'FAIL' ]]; then
write_failed_report "$label" "$reason" "$wc_us" "$fast_us"
return 1
fi
return 0
}
# run_case <words|lines> <n-lines> <-w|-l> — race the reference wc against
# fastwc on a file argument. Fails the benchmark the moment fastwc is
# slower or reports a different count.
@@ -255,7 +311,7 @@ run_case() {
local mode="$1" lines="$2" flag="$3"
local noun='lines'; [[ "$lines" -eq 1 ]] && noun='line'
local label="${mode} (${lines} ${noun})"
local file wc_count fast_count wc_ms fast_us fast_ms ratio verdict reason row
local file wc_count fast_count wc_us fast_us
local i d
file=$(createtxt "$lines") || return 1
@@ -264,58 +320,19 @@ run_case() {
wc_count=$(capture_count "${WC_CMD[@]}" "$flag" "$file")
fast_count=$(capture_count "$FASTWC" "$flag" "$file")
# speed: interleaved timing so both commands see identical cache warmth;
# keep the minimum of $BENCH_REPS runs each to reduce noise; fastwc is
# timed in µs so sub-millisecond wins are visible in the report
wc_ms=''
# speed: interleaved timing so both commands see identical cache
# warmth; keep the minimum of $BENCH_REPS runs each
wc_us=''
fast_us=''
for ((i = 0; i < BENCH_REPS; i++)); do
d=$(time_ms "${WC_CMD[@]}" "$flag" "$file")
[[ -z "$wc_ms" || "$d" -lt "$wc_ms" ]] && wc_ms="$d"
d=$(timeit "${WC_CMD[@]}" "$flag" "$file")
[[ -z "$wc_us" || "$d" -lt "$wc_us" ]] && wc_us="$d"
d=$(time_us "$FASTWC" "$flag" "$file")
d=$(timeit "$FASTWC" "$flag" "$file")
[[ -z "$fast_us" || "$d" -lt "$fast_us" ]] && fast_us="$d"
done
fast_ms=$(( fast_us / 1000 ))
# ratio: how many times faster fastwc is than the reference (wc / fastwc)
if [[ -n "$wc_ms" && "$wc_ms" -gt 0 ]]; then
if [[ "$fast_ms" -gt 0 ]]; then
ratio=$(awk -v f="$fast_ms" -v w="$wc_ms" 'BEGIN { printf "%.2fx", w / f }')
else
ratio='infx'
fi
else
ratio='-'
fi
# feed the end-of-run average speedup (numeric ratios only)
if [[ "$ratio" == *x && "$ratio" != 'infx' ]]; then
printf '%s\t%s\n' "$BENCH_NAME" "${ratio%x}" >> "$RATIOS_FILE"
fi
verdict='PASS'
reason=''
if [[ "$fast_count" != "$wc_count" ]]; then
verdict='FAIL'
reason="output mismatch (fastwc: ${fast_count}, ${BENCH_NAME} wc: ${wc_count})"
elif (( wc_ms > 0 && fast_ms > wc_ms )); then
# a 0ms reference is below the benchmark's resolution: sub-millisecond
# runs (startup noise, mostly) cannot prove fastwc slower
verdict='FAIL'
reason="fastwc was slower (fastwc: ${fast_ms}ms vs ${BENCH_NAME} wc: ${wc_ms}ms)"
fi
row=$(printf '%-28s %10s %22s %8s %s\n' \
"$label" "wc: ${wc_ms}ms" "fastwc: ${fast_ms}ms (${fast_us}µs)" \
"$ratio" "$verdict")
RESULT_ROWS+="${row}"$'\n'
printf '%s\n' "$row"
if [[ "$verdict" == 'FAIL' ]]; then
write_failed_report "$label" "$reason" "$wc_ms" "$fast_ms"
return 1
fi
return 0
finish_race "$label" "$wc_count" "$fast_count" "$wc_us" "$fast_us"
}
# run_stdin_case <words|lines> <n-lines> <-w|-l|...> — same race, but the
@@ -325,7 +342,7 @@ run_stdin_case() {
local mode="$1" lines="$2" flag="$3"
local noun='lines'; [[ "$lines" -eq 1 ]] && noun='line'
local label="stdin ${mode} (${lines} ${noun})"
local file wc_count fast_count wc_ms fast_us fast_ms ratio verdict reason row
local file wc_count fast_count wc_us fast_us
local i d
file=$(createtxt "$lines") || return 1
@@ -333,55 +350,17 @@ run_stdin_case() {
wc_count=$(capture_count "${WC_CMD[@]}" "$flag" < "$file")
fast_count=$(capture_count "$FASTWC" "$flag" < "$file")
wc_ms=''
wc_us=''
fast_us=''
for ((i = 0; i < BENCH_REPS; i++)); do
d=$(time_ms "${WC_CMD[@]}" "$flag" < "$file")
[[ -z "$wc_ms" || "$d" -lt "$wc_ms" ]] && wc_ms="$d"
d=$(timeit "${WC_CMD[@]}" "$flag" < "$file")
[[ -z "$wc_us" || "$d" -lt "$wc_us" ]] && wc_us="$d"
d=$(time_us "$FASTWC" "$flag" < "$file")
d=$(timeit "$FASTWC" "$flag" < "$file")
[[ -z "$fast_us" || "$d" -lt "$fast_us" ]] && fast_us="$d"
done
fast_ms=$(( fast_us / 1000 ))
# ratio: how many times faster fastwc is than the reference (wc / fastwc)
if [[ -n "$wc_ms" && "$wc_ms" -gt 0 ]]; then
if [[ "$fast_ms" -gt 0 ]]; then
ratio=$(awk -v f="$fast_ms" -v w="$wc_ms" 'BEGIN { printf "%.2fx", w / f }')
else
ratio='infx'
fi
else
ratio='-'
fi
# feed the end-of-run average speedup (numeric ratios only)
if [[ "$ratio" == *x && "$ratio" != 'infx' ]]; then
printf '%s\t%s\n' "$BENCH_NAME" "${ratio%x}" >> "$RATIOS_FILE"
fi
verdict='PASS'
reason=''
if [[ "$fast_count" != "$wc_count" ]]; then
verdict='FAIL'
reason="output mismatch (fastwc: ${fast_count}, ${BENCH_NAME} wc: ${wc_count})"
elif (( wc_ms > 0 && fast_ms > wc_ms )); then
# a 0ms reference is below the benchmark's resolution: sub-millisecond
# runs (startup noise, mostly) cannot prove fastwc slower
verdict='FAIL'
reason="fastwc was slower (fastwc: ${fast_ms}ms vs ${BENCH_NAME} wc: ${wc_ms}ms)"
fi
row=$(printf '%-28s %10s %22s %8s %s\n' \
"$label" "wc: ${wc_ms}ms" "fastwc: ${fast_ms}ms (${fast_us}µs)" \
"$ratio" "$verdict")
RESULT_ROWS+="${row}"$'\n'
printf '%s\n' "$row"
if [[ "$verdict" == 'FAIL' ]]; then
write_failed_report "$label" "$reason" "$wc_ms" "$fast_ms"
return 1
fi
return 0
finish_race "$label" "$wc_count" "$fast_count" "$wc_us" "$fast_us"
}
# run_solo_case <n-lines> <-l|...> — time fastwc alone on <n-lines> of data,
@@ -399,7 +378,7 @@ run_solo_case() {
}
for ((i = 0; i < BENCH_REPS; i++)); do
d=$(time_us "$FASTWC" "$flag" "$file")
d=$(timeit "$FASTWC" "$flag" "$file")
[[ -z "$best_us" || "$d" -lt "$best_us" ]] && best_us="$d"
done
best_ms=$(( best_us / 1000 ))
@@ -455,5 +434,7 @@ print_averages() {
printf "coreutils\t%.2fx\t%d\n", sum["coreutils"] / n["coreutils"], n["coreutils"];
if (n["busybox"])
printf "busybox\t%.2fx\t%d\n", sum["busybox"] / n["busybox"], n["busybox"];
if (n["toybox"])
printf "toybox\t%.2fx\t%d\n", sum["toybox"] / n["toybox"], n["toybox"];
}' "$RATIOS_FILE")"
}