diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 38d880d..ff22346 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -202,7 +202,11 @@ jobs: benchmark: name: Benchmark - runs-on: ubuntu-latest + # The ARM runners expose the CPU's performance counters; the x86 ones do + # not, being Azure VMs whose hypervisor hides the PMU. That is what decides + # the runner here, since it is the difference between reading the + # instruction count off the hardware and simulating the program to get it. + runs-on: ubuntu-24.04-arm permissions: contents: read steps: @@ -214,14 +218,6 @@ jobs: - name: Install Rust toolchain uses: dtolnay/rust-toolchain@stable - - name: Install WABT (WebAssembly Binary Toolkit) - run: | - WABT_VERSION=1.0.41 - WABT_PLATFORM="linux-x64" - wget https://github.com/WebAssembly/wabt/releases/download/${WABT_VERSION}/wabt-${WABT_VERSION}-${WABT_PLATFORM}.tar.gz - tar -xzf wabt-${WABT_VERSION}-${WABT_PLATFORM}.tar.gz - sudo cp wabt-${WABT_VERSION}/bin/* /usr/local/bin/ - - name: Cache Rust dependencies # Pinned commit resolved from the annotated Swatinem/rust-cache@v2 tag. uses: Swatinem/rust-cache@e18b497796c12c097a38f9edb9d0641fb99eee32 @@ -229,43 +225,165 @@ jobs: save-if: ${{ github.ref == 'refs/heads/main' }} cache-bin: false - - name: Run CoreMark benchmark - id: benchmark + - name: Build benchmark binaries run: | - # Build and run the benchmark from workspace root, capturing output - output=$(cargo bench -p spacewasm_std --bench coremark --no-fail-fast 2>&1) - echo "$output" - - # Extract the CoreMark score from the output - score=$(echo "$output" | grep "CoreMark Score:" | awk '{print $3}') - if [ -z "$score" ]; then - echo "Failed to extract CoreMark score" - exit 1 - fi + set -euo pipefail + + # Stage the bench binary next to the wasm it loads, so a side can be + # re-run later without checking its revision back out. + stage() { + local dest="$1" + local exe + exe=$(cargo bench -p spacewasm_std --bench coremark --no-run --message-format=json \ + | jq -r 'select(.reason == "compiler-artifact") + | select(.target.kind | index("bench")) + | select(.target.name == "coremark") + | .executable' \ + | tail -n 1) + if [ -z "$exe" ] || [ ! -x "$exe" ]; then + echo "Could not locate the CoreMark benchmark executable" + return 1 + fi + mkdir -p "$dest/benches" + cp "$exe" "$dest/coremark" + cp crates/spacewasm_std/benches/coremark-minimal.wasm "$dest/benches/" + } - echo "score=$score" >> $GITHUB_OUTPUT - echo "Benchmark score: $score" + # Keep the measurement harness and workload identical for both builds. + # The baseline must vary only the implementation under measurement; + # otherwise older main branches cannot pin the workload and the two + # instruction counts are not comparable. + harness="$RUNNER_TEMP/coremark-harness" + mkdir -p "$harness" + cp crates/spacewasm_std/benches/coremark.rs "$harness/" + cp crates/spacewasm_std/benches/coremark-minimal.wasm "$harness/" - - name: Download baseline benchmark - id: baseline - continue-on-error: true - run: | - # Try to get baseline from main branch + stage "$RUNNER_TEMP/pr" + + # The baseline stays best effort. A harness written against an + # interface main does not have yet will not build there, and a PR + # should still get a score of its own when that happens. if [ "${{ github.event_name }}" == "pull_request" ]; then - git fetch origin main:main - git checkout main - baseline_output=$(cargo bench -p spacewasm_std --bench coremark --no-fail-fast 2>&1) || true - baseline_score=$(echo "$baseline_output" | grep "CoreMark Score:" | awk '{print $3}') - git checkout - + head=$(git rev-parse HEAD) + if git fetch --no-tags origin main && git checkout --detach FETCH_HEAD; then + cp "$harness/coremark.rs" crates/spacewasm_std/benches/coremark.rs + cp "$harness/coremark-minimal.wasm" \ + crates/spacewasm_std/benches/coremark-minimal.wasm + stage "$RUNNER_TEMP/base" \ + || echo "::warning::could not build the baseline against this branch's harness" + git restore --source=HEAD -- \ + crates/spacewasm_std/benches/coremark.rs \ + crates/spacewasm_std/benches/coremark-minimal.wasm + git checkout --detach "$head" + else + echo "::warning::could not check out main to build a baseline" + fi + fi + + - name: Count instructions + id: instructions + run: | + set -euo pipefail + + # How many instructions each side executes, read off the CPU's own + # counter. Unlike the score below it does not move with the runner's + # CPU model or with whoever else is on the machine, so a difference in + # it is work this PR added or removed. + # + # The image ships perf_event_paranoid=4, which refuses even to count a + # process this job started itself. + sudo sysctl -w kernel.perf_event_paranoid=1 + + # If the counter ever goes away, say so and leave the timed + # comparison to stand rather than failing a PR over it. + probe=$(perf stat -e instructions:u true 2>&1 || true) + if ! grep -q 'instructions:u' <<< "$probe" || grep -q 'not supported' <<< "$probe"; then + echo "$probe" + echo "::warning::no hardware instruction counter on this runner; skipping instruction counts" + exit 0 + fi + + sides=(pr) + if [ -x "$RUNNER_TEMP/base/coremark" ]; then + sides+=(base) + fi + + for side in "${sides[@]}"; do + stats="$RUNNER_TEMP/$side.perf" + log="$RUNNER_TEMP/$side.count.log" + + # COREMARK_FIXED_CLOCK is what makes the two counts comparable: + # without it the module sizes its own workload from wall-clock time, + # in steps of nearly 2x, and the count would describe the runner + # rather than the build. A pinned run scores exactly 10.000, so the + # score doubles as a check that the count came from that workload. + # + # A pr side that cannot pin is this branch's own doing and fails the + # job. A baseline that cannot pin is not, so the counts are skipped + # and the timed comparison stands. + if ! ( + cd "$RUNNER_TEMP/$side" + COREMARK_FIXED_CLOCK=1 perf stat -x, -e instructions:u \ + -o "$stats" ./coremark + ) > "$log" 2>&1 || ! grep -q '^CoreMark Score: 10.000$' "$log"; then + cat "$log" + if [ "$side" = pr ]; then + echo "The pr benchmark did not produce the pinned workload" + exit 1 + fi + echo "::warning::the baseline did not produce a pinned run; skipping instruction counts" + exit 0 + fi + + # User space only, so kernel work done on the runner's behalf stays + # out of the figure. Everything the process itself does is in it, + # parsing and compiling the module as well as interpreting it. + ir=$(awk -F, '$3 == "instructions:u" { print $1 }' "$stats") + if ! [[ "$ir" =~ ^[0-9]+$ ]]; then + cat "$stats" + echo "No instruction count for $side" + exit 1 + fi - if [ -n "$baseline_score" ]; then - echo "baseline=$baseline_score" >> $GITHUB_OUTPUT - echo "Baseline score: $baseline_score" + if [ "$side" = pr ]; then + echo "instructions=$ir" >> "$GITHUB_OUTPUT" + echo "Instructions: $ir" else - echo "baseline=" >> $GITHUB_OUTPUT + echo "baseline_instructions=$ir" >> "$GITHUB_OUTPUT" + echo "Baseline instructions: $ir" + fi + done + + - name: Run CoreMark benchmark + id: benchmark + run: | + set -euo pipefail + + # One run each. The score is a figure in units people care about, but + # it is worth a few percent either way on a shared runner, so it is + # the count above that a regression is read out of. Timing it + # repeatedly would not change that. + run_once() { + local score + score=$( cd "$1" && ./coremark ) || return 1 + score=$(awk '/CoreMark Score:/ { print $3 }' <<< "$score") + if [ -z "$score" ]; then + echo "Failed to extract CoreMark score for $1" >&2 + return 1 fi + echo "$score" + } + + score=$(run_once "$RUNNER_TEMP/pr") + echo "score=$score" >> "$GITHUB_OUTPUT" + echo "Benchmark score: $score" + + if [ -x "$RUNNER_TEMP/base/coremark" ]; then + baseline=$(run_once "$RUNNER_TEMP/base") + echo "baseline=$baseline" >> "$GITHUB_OUTPUT" + echo "Baseline score: $baseline" else - echo "baseline=" >> $GITHUB_OUTPUT + echo "baseline=" >> "$GITHUB_OUTPUT" fi - name: Save benchmark results @@ -274,8 +392,10 @@ jobs: cat > benchmark-results.json <= 0 ? '+' : ''}` + + `${diff.toLocaleString('en-US')} (${percentChange.toFixed(2)}%)\n\n`; + + // The count is exact, so this is a reading aid rather than a + // threshold: it puts a large difference in front of a reviewer + // instead of leaving it to be picked out of the figures. + if (percentChange >= 1.0) { + comment += '**Note:** this PR executes more than 1% more instructions ' + + 'than the baseline.\n\n'; + } + } else { + comment += '\n_No baseline available for comparison_\n\n'; + } + + comment += '_Read off the CPU performance counter, with the same benchmark ' + + 'harness on both sides and a workload pinned by `COREMARK_FIXED_CLOCK`. ' + + 'This is a repeatable count of the work done, not a timing measurement; ' + + 'it says nothing about cache or branch behaviour._\n\n'; + } + comment += `**Current Score:** ${currentScore.toFixed(3)}\n`; if (baselineScore && !isNaN(baselineScore)) { - const diff = currentScore - baselineScore; - const percentChange = ((diff / baselineScore) * 100).toFixed(2); - comment += `**Baseline Score (main):** ${baselineScore.toFixed(3)}\n`; - comment += `**Difference:** ${diff >= 0 ? '+' : ''}${diff.toFixed(3)} (${percentChange}%)\n\n`; } else { comment += '\n_No baseline available for comparison_\n'; } + comment += currentInsns + ? '\n_One timed run each. On a shared runner the score is worth a few percent ' + + 'either way, which is why no difference is quoted for it: read the ' + + 'instruction count above instead._\n' + : '\n_One timed run each, and worth a few percent either way on a shared ' + + 'runner, so no difference is quoted for it._\n'; + comment += '\n_Scores are only comparable within a single run, which measures ' + + 'both sides on one runner._\n'; + await upsertComment( parseInt(benchmark.prNumber, 10), 'CoreMark Benchmark Results', diff --git a/crates/spacewasm_std/benches/coremark.rs b/crates/spacewasm_std/benches/coremark.rs index 371411f..d7f19eb 100644 --- a/crates/spacewasm_std/benches/coremark.rs +++ b/crates/spacewasm_std/benches/coremark.rs @@ -16,10 +16,43 @@ const MAX_CODE_PAGES: u32 = 32; const MAX_CONTROL_FRAMES: usize = 64; const MAX_STACK_DEPTH: usize = 256; +/// Timestamps handed to the wasm module, in order, when `COREMARK_FIXED_CLOCK=1`. +/// +/// CoreMark sizes its own workload from the clock: it times a run of ten +/// iterations, keeps multiplying by ten until that takes at least a second, +/// then settles on `iterations * (1 + 10 / floor(seconds))`. The divisor is an +/// integer, so a run that takes 1.9s and one that takes 2.1s end up doing +/// nearly twice as much work as each other. That is fine for a score, which +/// divides the work back out, but it makes the amount of code executed a +/// property of the machine rather than of the build, and so not worth counting. +/// +/// These four values are what the module reads instead: one timed calibration +/// round reporting exactly one second, which pins the workload at 110 +/// iterations, and a measured window of eleven seconds, which clears the ten +/// second minimum CoreMark requires for a valid result. The score is then a +/// constant 110 / 11, and [`FIXED_CLOCK_SCORE`] asserts it. +const FIXED_CLOCK_MS: [i64; 4] = [0, 1_000, 1_000, 12_000]; + +/// How far the fixed clock advances per call once [`FIXED_CLOCK_MS`] runs out, +/// so an unexpected extra timing round changes the score rather than seeing +/// time stand still. +const FIXED_CLOCK_STEP_MS: i64 = 12_000; + +/// The only score [`FIXED_CLOCK_MS`] can produce, if the module still times +/// itself the way it does today. +const FIXED_CLOCK_SCORE: f32 = 10.0; + fn main() { println!("\n=== CoreMark Benchmark ==="); println!("Reference: https://github.com/wasm3/wasm-coremark\n"); + // Fixed-clock runs are for counting instructions, not for timing: the + // workload is a fraction of a normal run and the score is a self-check. + let fixed_clock = std::env::var("COREMARK_FIXED_CLOCK").as_deref() == Ok("1"); + if fixed_clock { + println!("Fixed clock: workload pinned for instruction counting.\n"); + } + // According to the reference implementation, clock_ms should return current time in milliseconds // See: https://github.com/wasm3/wasm-coremark/blob/main/coremark-minimal.html // JavaScript: env: { clock_ms: () => BigInt(Date.now()) } @@ -35,11 +68,22 @@ fn main() { "clock_ms", "".into(), "I".into(), - |_, _| { - let ms = std::time::SystemTime::now() - .duration_since(std::time::UNIX_EPOCH) - .unwrap() - .as_millis() as i64; + move |_, _| { + let call = CLOCK_CALL_COUNT.fetch_add(1, Ordering::Relaxed); + + let ms = if fixed_clock { + let past_end = (call + 1).saturating_sub(FIXED_CLOCK_MS.len()) as i64; + FIXED_CLOCK_MS + .get(call) + .copied() + .unwrap_or(FIXED_CLOCK_MS[FIXED_CLOCK_MS.len() - 1]) + + FIXED_CLOCK_STEP_MS * past_end + } else { + std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .unwrap() + .as_millis() as i64 + }; ControlFlow::Continue(Some(Value::I64(ms))) }, @@ -147,6 +191,19 @@ fn main() { println!("Return value: {:.3}", coremark_score); println!(); + // CoreMark only returns a score at all once its own CRC checks + // pass, and under the fixed clock there is exactly one score it can + // return. Anything else means the workload is no longer the one + // FIXED_CLOCK_MS pins, so a count taken from it is not comparable + // to a count taken from another build. + if fixed_clock && (coremark_score - FIXED_CLOCK_SCORE).abs() > 0.001 { + eprintln!( + "Error: fixed-clock score is {coremark_score:.3}, expected {FIXED_CLOCK_SCORE:.3}" + ); + eprintln!("The module no longer times itself the way FIXED_CLOCK_MS assumes."); + std::process::exit(1); + } + if coremark_score > 1.0 { println!("=== CoreMark Results ==="); println!("CoreMark Score: {:.3}", coremark_score);