From 0d2335e6a7989dc102ad38109ded8eebfd1e9a74 Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 13 Aug 2026 18:05:40 +0000 Subject: [PATCH] Show the difference in the README, and measure it The README said chains are faster without ever showing by how much. Two gantt charts now draw the same build in order and in chains, one for a build that passes and one for a build whose lint fails, and a benchmark suite puts numbers under them. bench/bench.sh describes four builds as the chains they are made of, with every step a sleep as long as that step usually takes, and runs each one twice: in declaration order, the way a set -e script runs it, and as chains. Sleeps because the shape of a build is what changes here, not the work in it, and the report says so. Four scenarios, because the gain depends entirely on the shape: two independent chains, four independent checks, a failure found early, and one step long enough that nothing can be done about it. The only assertion is that a scenario was faster in chains than in order. The times are a report, and a hosted runner is far too noisy to hold a particular number against a build. CI runs it on every push and puts the table in the run summary. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01Bn7kapsRo75cCUfU6nfNpS --- .github/workflows/ci.yml | 22 ++++ Makefile | 12 +- README.md | 91 +++++++++++++++ bench/bench.sh | 246 +++++++++++++++++++++++++++++++++++++++ 4 files changed, 368 insertions(+), 3 deletions(-) create mode 100755 bench/bench.sh diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 880f465..342eb34 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -72,6 +72,28 @@ jobs: - run: make install-dev - run: make test SHELLSPEC_FLAGS="--shell ${{ matrix.shell }}" + # The benchmarks are a report, and a hosted runner is a noisy place to + # take timings on, so the job only fails when a scenario was not faster in + # chains than in order at all. That is a claim no amount of a busy runner + # should be able to break, and the table lands in the run summary either + # way. + bench: + runs-on: ubuntu-latest + timeout-minutes: 15 + steps: + - uses: actions/checkout@v7 + - name: Benchmark + run: make bench 2>&1 | tee bench.txt + - name: Publish the table + if: always() + run: | + [ -f bench.txt ] || exit 0 + { + echo '```' + cat bench.txt + echo '```' + } >>"$GITHUB_STEP_SUMMARY" + freebsd: runs-on: ubuntu-latest timeout-minutes: 30 diff --git a/Makefile b/Makefile index dd03f56..7b48b7b 100644 --- a/Makefile +++ b/Makefile @@ -7,15 +7,16 @@ SHELLSPEC = .tools/bin/shellspec # Extra flags for the suite, e.g. `make test SHELLSPEC_FLAGS="--shell dash"`. SHELLSPEC_FLAGS = -# The library and the example: POSIX sh, formatted, no bashisms. -SCRIPTS = parallel.sh examples/build.sh +# The library, the example and the benchmarks: POSIX sh, formatted, no +# bashisms. +SCRIPTS = parallel.sh examples/build.sh bench/bench.sh # The spec files are POSIX sh as well and get checked, but not formatted: # shellspec's Describe, It and End are ordinary commands, so shfmt sees no # nesting to keep and flattens the whole file to one column. SPECS = spec/parallel_spec.sh spec/spec_helper.sh -.PHONY: check lint test install-dev +.PHONY: check lint test bench install-dev check: lint test @@ -28,6 +29,11 @@ test: @[ -x $(SHELLSPEC) ] || { echo "$(SHELLSPEC) is missing: make install-dev" >&2; exit 1; } $(SHELLSPEC) $(SHELLSPEC_FLAGS) +# Not part of `check`: it is minutes of sleeping, and it reports rather than +# asserts. Takes REPS, SCALE and SHELL_UNDER_TEST from the environment. +bench: + ./bench/bench.sh + # Into .tools, which is gitignored. install-dev: curl -fsSL https://raw.githubusercontent.com/shellspec/shellspec/$(SHELLSPEC_VERSION)/install.sh \ diff --git a/README.md b/README.md index ab4f7a8..068317a 100644 --- a/README.md +++ b/README.md @@ -30,6 +30,45 @@ chain "npm ci --audit false" "npm run build" run ``` +Drawn out, with the times off a middling Laravel app. The second one +finishes when its longest chain does rather than when its last command +does: + +```mermaid +gantt + title The build above, in order and in chains + dateFormat HH:mm:ss + axisFormat %M:%S + todayMarker off + section In order + composer install :done, 00:00:00, 00:00:40 + npm ci :done, 00:00:40, 00:01:30 + npm run build :done, 00:01:30, 00:01:50 + section In chains + composer install :active, 00:00:00, 00:00:40 + npm ci :active, 00:00:00, 00:00:50 + npm run build :active, 00:00:50, 00:01:10 +``` + +A failure arrives sooner for the same reason. The step that fails is not +waiting on the steps that would have run before it, so the build stops +about when the failure happens instead of once everything ahead of it is +done: + +```mermaid +gantt + title A lint that fails, at the end of a script and in a chain + dateFormat HH:mm:ss + axisFormat %M:%S + todayMarker off + section In order + phpunit :done, 00:00:00, 00:00:50 + lint, exits 1 :crit, 00:00:50, 00:01:00 + section In chains + phpunit, cancelled :active, 00:00:00, 00:00:10 + lint, exits 1 :crit, 00:00:00, 00:00:10 +``` + When something fails, the failure is at the bottom and the rest is grouped above it: @@ -92,6 +131,58 @@ a different interval and `POLL_WHOLE` for a different fallback: POLL=0.5 . ./parallel.sh ``` +## Benchmarks + +`bench/bench.sh` runs four builds twice each, once in declaration order the +way a `set -e` script runs them and once as chains. Every step in them is a +`sleep`, at a tenth of the length the step it stands for would take, so the +suite is minutes rather than hours. On a four-core Linux box, under dash, +best of three runs: + +| Scenario | In order | In chains | Speedup | +| --- | ---: | ---: | ---: | +| PHP app with a front end | 11.01s | 7.09s | 1.6x | +| CI checks, four of them | 12.01s | 5.03s | 2.4x | +| A failing lint | 6.01s | 1.03s | 5.8x | +| One dominant step | 10.01s | 6.04s | 1.7x | + +- **PHP app with a front end** — `composer install` (4s) in one chain, + `npm ci` (5s) then `npm run build` (2s) in the other. The build at the top + of this file. +- **CI checks, four of them** — lint (1s), typecheck (3s), unit tests (5s) + and a build (3s), none of them waiting on any other. The shape chains are + best at: the job takes as long as its slowest check instead of as long as + all of them. +- **A failing lint** — unit tests (5s) alongside a lint that exits 1 after + 1s. In order the failure turns up last because that is where the step is, + and a lint at the top of the script would be found just as early. That is + the point: in chains it does not matter where it is. +- **One dominant step** — `npm run build` (6s) alongside `composer install` + (3s) and `php artisan migrate` (1s). The ceiling on all of this: a build + cannot finish before its longest chain does, so the most chains can do is + hide the rest behind it. + +Eight chains that do nothing at all finish in 0.15s: one `mktemp`, eight +forks, and a poll or two. That is about what the library costs a build with +nothing to gain. + +The table is a report on shapes, not a measurement of any real build. A +`sleep` waits without competing for a core, a disk or a link, so these are +the times a build gets when its steps are mostly waiting on something other +than each other. Steps that each saturate the machine will not see them. + +`make bench` runs it. `REPS` is how many runs each scenario gets, `SCALE` +multiplies every duration, and `SHELL_UNDER_TEST` picks the shell: + +```sh +REPS=1 SCALE=0.25 SHELL_UNDER_TEST=/bin/bash make bench +``` + +CI runs it on every push and puts the table in the run summary. It fails the +job only when a scenario was not faster in chains than in order at all: +anything tighter is a number to hold against a hosted runner, and they are +too noisy to be held to one. + ## Caveats `kill` stops a cancelled chain's shell, not its grandchildren. A command diff --git a/bench/bench.sh b/bench/bench.sh new file mode 100755 index 0000000..53fae29 --- /dev/null +++ b/bench/bench.sh @@ -0,0 +1,246 @@ +#!/bin/sh +# shellcheck shell=sh +# Benchmarks for parallel.sh. POSIX sh, like the library it measures. +# +# A scenario is a build, described as the chains it is made of, and every +# step in it is a `sleep` as long as that step usually takes. The same steps +# then run twice: once in declaration order, the way a `set -e` script runs +# them, and once as chains. The difference between the two is the whole of +# what this measures. +# +# Sleeps stand in for the work because the shape of a build is what changes +# here, not the work in it: `sleep` waits without competing for a core, a +# disk or a network link, so these numbers are the ones a build gets when +# its steps are mostly waiting on something other than each other. Steps +# that each saturate the machine will not see them. +# +# ./bench/bench.sh every scenario, three runs each +# REPS=1 ./bench/bench.sh one run each +# SCALE=0.25 ./bench/bench.sh a quarter of every duration +# SHELL_UNDER_TEST=/bin/bash ./bench/bench.sh +# +# It exits non-zero if a scenario was not faster in chains than in order, +# which is the only assertion here: the times themselves are a report, and +# a machine slow enough to change them by a few percent should not fail a +# build over it. + +set -u + +REPS=${REPS:-3} +SCALE=${SCALE:-1} +SHELL_UNDER_TEST=${SHELL_UNDER_TEST:-/bin/sh} + +_here=$(dirname "$0") +LIB=${LIB:-$_here/../parallel.sh} +if [ ! -f "$LIB" ]; then + printf 'no parallel.sh at %s\n' "$LIB" >&2 + exit 1 +fi +# The generated scripts are run from elsewhere, so the library needs a path +# that does not depend on where they run from. +LIB=$(cd "$(dirname "$LIB")" && pwd)/$(basename "$LIB") + +_work=$(mktemp -d "${TMPDIR:-/tmp}/parallel-bench.XXXXXX") +trap 'rm -rf "$_work"' EXIT +trap 'rm -rf "$_work"; exit 130' INT +trap 'rm -rf "$_work"; exit 143' TERM + +_slower='' # scenarios that chains did not help, filled in as they run + +# Milliseconds since the epoch, from whatever this machine happens to have. +# GNU date takes %3N and BSD date does not, so the clock is chosen once, by +# trying each candidate and keeping the first that answers with a plausible +# number of digits. Whole seconds are the last resort: the report says which +# clock it used, because a scenario timed to the second is worth less than +# one timed to the millisecond. +_clock=seconds +_now() { + case $_clock in + date) date +%s%3N ;; + perl) perl -MTime::HiRes -e 'printf "%.0f", Time::HiRes::time() * 1000' ;; + python) python3 -c 'import time; print(int(time.time() * 1000))' ;; + *) printf '%s000' "$(date +%s)" ;; + esac +} + +_pick_clock() { + for _c in date perl python; do + _clock=$_c + _t=$(_now 2>/dev/null) || _t='' + case $_t in + '' | *[!0-9]*) continue ;; + esac + [ "${#_t}" -ge 13 ] && return 0 + done + _clock=seconds +} + +# A chain is written "label:seconds|label:seconds": steps in order, each one +# the length it takes. A duration ending in ! is a step that fails when it +# is done, which is how a scenario says where the failure is. +_steps() { printf '%s\n' "$1" | tr '|' '\n'; } + +_label() { + _first=${1%%|*} + printf '%s' "${_first%:*}" +} + +_seconds() { + _d=${1##*:} + _d=${_d%!} + awk -v d="$_d" -v s="$SCALE" 'BEGIN { printf "%g", d * s }' +} + +_command() { + case ${1##*:} in + *!) printf 'sleep %s; exit 1' "$(_seconds "$1")" ;; + *) printf 'sleep %s' "$(_seconds "$1")" ;; + esac +} + +# The build as a script that runs its steps in order and stops at the first +# failure, which is what it looked like before. +_write_ordered() { + { + printf '#!/bin/sh\nset -e\n' + for _chain in "$@"; do + _steps "$_chain" | while IFS= read -r _step; do + printf '%s\n' "$(_command "$_step")" + done + done + } >"$_work/ordered.sh" +} + +# The same build as chains. +_write_chained() { + { + printf '#!/bin/sh\n. "%s"\n' "$LIB" + for _chain in "$@"; do + printf 'chain "%s"' "$(_label "$_chain")" + _steps "$_chain" | while IFS= read -r _step; do + printf ' "%s"' "$(_command "$_step")" + done + printf '\n' + done + printf 'run\n' + } >"$_work/chained.sh" +} + +# One run, in milliseconds. A scenario that ends in a failure exits +# non-zero by design, so the status is not the point and is thrown away. +_time() { + _start=$(_now) + "$SHELL_UNDER_TEST" "$1" >/dev/null 2>&1 || : + _end=$(_now) + printf '%s' "$((_end - _start))" +} + +# The best of REPS runs, not the mean: a run can only be made slower by +# whatever else the machine was doing, so the fastest one is the closest to +# what was actually being measured. +_best() { + _min='' + _i=1 + while [ "$_i" -le "$REPS" ]; do + _ms=$(_time "$1") + if [ -z "$_min" ] || [ "$_ms" -lt "$_min" ]; then + _min=$_ms + fi + _i=$((_i + 1)) + done + printf '%s' "$_min" +} + +_secs() { awk -v ms="$1" 'BEGIN { printf "%.2fs", ms / 1000 }'; } + +_ratio() { + if [ "$2" -le 0 ]; then + printf '-' + return 0 + fi + awk -v a="$1" -v b="$2" 'BEGIN { printf "%.1fx", a / b }' +} + +_row() { printf '%-32s %11s %11s %9s\n' "$1" "$2" "$3" "$4"; } + +scenario() { + _name=$1 + shift + _write_ordered "$@" + _write_chained "$@" + _ordered=$(_best "$_work/ordered.sh") + _chained=$(_best "$_work/chained.sh") + _row "$_name" "$(_secs "$_ordered")" "$(_secs "$_chained")" \ + "$(_ratio "$_ordered" "$_chained")" + [ "$_chained" -lt "$_ordered" ] || _slower="$_slower + $_name" +} + +# What the library costs when there is nothing to gain: eight chains that do +# nothing at all, so the time is one mktemp, eight forks and a poll or two. +# Any scenario above is that much slower than the build it describes. +_overhead() { + { + printf '#!/bin/sh\n. "%s"\n' "$LIB" + _i=1 + while [ "$_i" -le 8 ]; do + printf 'chain "chain %s" ":"\n' "$_i" + _i=$((_i + 1)) + done + printf 'run\n' + } >"$_work/overhead.sh" + _best "$_work/overhead.sh" +} + +_pick_clock + +printf 'parallel.sh benchmarks\n' +printf 'shell %s, clock %s, poll %s, best of %s, scale %s\n\n' \ + "$SHELL_UNDER_TEST" "$_clock" "${POLL:-0.1}" "$REPS" "$SCALE" + +_row 'scenario' 'in order' 'in chains' 'speedup' +_row '--------' '--------' '---------' '-------' + +# A PHP app with a front end: composer waits on nothing npm does, and npm +# waits on nothing composer does, but a script runs them one after the other +# anyway. The npm steps are a chain because the build needs its own +# dependencies first. +scenario 'PHP app with a front end' \ + 'composer install:4' \ + 'npm ci:5|npm run build:2' + +# The checks a CI job runs over a monorepo, all four independent of each +# other. This is the shape chains are best at: the build takes as long as +# its longest check instead of as long as all of them. +scenario 'CI checks, four of them' \ + 'lint:1' \ + 'typecheck:3' \ + 'unit tests:5' \ + 'build:3' + +# The same checks, with the lint failing. In order, the failure is found +# only once everything ahead of it has run, and where that is depends on +# where the failing step sits in the script; in chains it is found as soon +# as it happens, whatever else is still going. +scenario 'A failing lint' \ + 'unit tests:5' \ + 'lint:1!' + +# One step much longer than the rest, which is where the gain runs out: the +# build can never finish before its longest chain does, so the most chains +# can do is hide everything else behind it. +scenario 'One dominant step' \ + 'npm run build:6' \ + 'composer install:3' \ + 'php artisan migrate:1' + +_row '--------' '--------' '---------' '-------' +printf '\neight empty chains: %s\n' "$(_secs "$(_overhead)")" + +case $_slower in +'') ;; +*) + printf '\nnot faster in chains than in order:%s\n' "$_slower" >&2 + exit 1 + ;; +esac