From b6fe036ae5be4db56d971c66309fc2341b5b7cca Mon Sep 17 00:00:00 2001 From: Hao Hu Date: Thu, 5 Nov 2026 11:35:32 +0100 Subject: [PATCH 1/5] measure: Pin inscount backend (--pin) for deterministic instruction counts --- tools/measure.py | 229 +++++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 221 insertions(+), 8 deletions(-) diff --git a/tools/measure.py b/tools/measure.py index 135e461..35eea3c 100755 --- a/tools/measure.py +++ b/tools/measure.py @@ -1,5 +1,5 @@ #!/usr/bin/env python3 -"""Load-independent Callgrind performance measurement for Python snippets. +"""Load-independent performance measurement for Python snippets. Runs every src/**/*.py script against the shared test cases and records metrics under Valgrind Callgrind: @@ -10,11 +10,16 @@ * wall_s (wall time). * maxrss_kb (peak RSS in KB). +Plus (under the new flags) Pin instruction counts from an inscount +tool run: pin_instructions min/median/max per case. + Usage: python3 tools/measure.py --resources tests/resources \ [--repeat 1] [--jobs 2] [--timeout 300] [--only substring] \ [--output perf.json] [--bmf-output bencher.json] \ - [--summary-file "$GITHUB_STEP_SUMMARY"] [--shard K/N] + [--summary-file "$GITHUB_STEP_SUMMARY"] [--shard K/N] \ + [--pin] [--pin-bin BIN] [--pin-tool SO] [--pin-repeat N] \ + [--pin-timeout S] python3 tools/measure.py --merge shard-*.json --output merged.json \ [--bmf-output bencher.json] [--summary-file summary.md] @@ -40,9 +45,15 @@ sys.path.insert(0, os.path.join(ROOT, "tests")) import run_tests -TOOL_VERSION = 1 +TOOL_VERSION = 2 _CALLGRIND_TOTAL_RE = re.compile(r"^(?:totals|summary):\s*(\d+)", re.MULTILINE) +# Pin inscount defaults: two counts per case catch instrument +# flakiness without paying for more slow runs; the Pin budget is +# separate from --timeout since instrumentation runs ~10-100x slower. +PIN_REPEAT_DEFAULT = 2 +PIN_TIMEOUT_DEFAULT = 600 + def parse_callgrind_output(content): """Extract total instruction count from Callgrind output text.""" @@ -62,6 +73,66 @@ def parse_callgrind_output(content): return None +def parse_pin_count(content): + """Extract the total from inscount-style tool output (one "Count N" line). + + Later Count lines win so per-thread dumps still resolve to their + trailing total. Raises ValueError when no Count line parses. + """ + found = None + for line in content.splitlines(): + fields = line.split() + if len(fields) != 2 or fields[0] != "Count": + continue + digits = fields[1] + if not digits or any(c not in "0123456789" for c in digits): + raise ValueError("pin count unreadable: {!r}".format(line.strip())) + found = int(digits) + if found is None: + raise ValueError("pin count unreadable: no Count line") + return found + + +def pin_usable(pin_bin, tool): + """Whether Pin count runs can execute: launcher resolves, tool exists.""" + if not pin_bin or not tool: + return False + if not os.path.isfile(tool): + return False + if os.path.dirname(pin_bin): + return os.path.isfile(pin_bin) and os.access(pin_bin, os.X_OK) + return shutil.which(pin_bin) is not None + + +def pin_version(pin_bin): + """Probe `pin -version` for report provenance, or None when silent. + + Compared runs must share one Pin version: counts are only + comparable within a version. + """ + try: + proc = subprocess.run( + [pin_bin, "-version"], + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + timeout=30, + ) + except (OSError, subprocess.SubprocessError): + return None + if proc.returncode != 0: + return None + for line in proc.stdout.decode(errors="ignore").splitlines(): + if line.strip(): + return line.strip() + return None + + +def is_pin_timeout(run_err): + """Whether a Pin run error text is a deadline timeout (degrades to + a skip) rather than a crash (fails the case).""" + return "TIMEOUT" in run_err + + def parse_shard(text): """Parse K/N shard selector into (index, total), 0-based index.""" try: @@ -174,6 +245,97 @@ def measure_case_callgrind(has_valgrind, script, case_name, input_path, output_p return summary, None +def pin_once(pin_bin, pin_tool, exec_cmd, input_bytes, timeout): + """Run exec_cmd once under Pin with the inscount tool. + + Returns (stdout, count, run_err): run_err is "" on success, else a + short "TIMEOUT (>Ns)" / "exit N: ..." / "pin output unreadable" + text for the caller to classify. + """ + fd_temp, out_file = tempfile.mkstemp(prefix="snip-pin-", suffix=".out") + os.close(fd_temp) + try: + cmd = [pin_bin, "-t", pin_tool, "-o", out_file, "--"] + list(exec_cmd) + try: + proc = subprocess.run( + cmd, + input=input_bytes, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + timeout=timeout, + ) + except subprocess.TimeoutExpired: + return None, 0, "TIMEOUT (>{}s)".format(timeout) + if proc.returncode != 0: + err_text = proc.stderr.decode(errors="ignore").strip().splitlines() + return None, 0, "exit {}: {}".format( + proc.returncode, err_text[-1] if err_text else "no stderr") + try: + with open(out_file, "r", errors="ignore") as fd: + count = parse_pin_count(fd.read()) + except (OSError, ValueError) as exc: + return None, 0, "pin output unreadable: {}".format(exc) + return proc.stdout, count, "" + finally: + if os.path.exists(out_file): + try: + os.unlink(out_file) + except OSError: + pass + + +def measure_case_pin(exec_cmd, label, case_name, input_path, output_path, + pin_bin, pin_tool, pin_repeat, pin_timeout): + """Pin inscount phase for one case. + + Returns (pin_summary|None, pin_skipped|None, error|None): timeouts + degrade to pin_skipped (callgrind data stays valid), crashes and + output mismatches fail the case. + """ + with open(output_path, "rb") as fd: + expected = run_tests.normalize(fd.read()) + with open(input_path, "rb") as fd: + input_bytes = fd.read() + + counts = [] + for i in range(pin_repeat): + stdout, count, run_err = pin_once( + pin_bin, pin_tool, exec_cmd, input_bytes, pin_timeout) + if run_err: + if is_pin_timeout(run_err): + print("warning: {}/{}: pin skipped ({})".format( + label, case_name, run_err), file=sys.stderr) + return None, run_err, None + return None, None, "pin: {}".format(run_err) + if i == 0 and run_tests.normalize(stdout) != expected: + got = run_tests.normalize(stdout).decode(errors="ignore") + want = expected.decode(errors="ignore") + return None, None, "pin output mismatch: expected {!r} got {!r}".format( + want[:100], got[:100]) + counts.append(count) + return summarize_numbers(counts), None, None + + +def measure_case_full(has_valgrind, label, script, case_name, inp, outp, + repeat, timeout, pin_bin, pin_tool, pin_repeat, pin_timeout): + """Callgrind measure plus the optional Pin inscount phase. + + Returns (summary|None, pin_skipped|None, error|None). + """ + summary, err = measure_case_callgrind( + has_valgrind, script, case_name, inp, outp, repeat, timeout) + if err is not None or pin_repeat <= 0: + return summary, None, err + pin_summary, pin_skipped, pin_err = measure_case_pin( + [sys.executable, script], label, case_name, inp, outp, + pin_bin, pin_tool, pin_repeat, pin_timeout) + if pin_err is not None: + return None, None, pin_err + if pin_summary is not None: + summary["pin_instructions"] = pin_summary + return summary, pin_skipped, None + + def build_bmf(results): """Aggregate per-snippet summaries into Bencher Metric Format JSON.""" snippets = {} @@ -281,6 +443,22 @@ def self_test(): parsed = parse_callgrind_output(sample_cg) assert parsed == 987654321, f"Expected 987654321, got {parsed}" + assert parse_pin_count("Count 846018869\n") == 846018869 + assert parse_pin_count("Pin 3.31\nCount 1\nCount 42\n") == 42 + for bad in ("", "no counts here\n", "Count abc\n", "Count\n", "Count 1 2\n"): + try: + parse_pin_count(bad) + except ValueError: + pass + else: + raise AssertionError(f"parse_pin_count must reject {bad!r}") + assert not pin_usable("", "") + assert not pin_usable("/nonexistent/pin", "/nonexistent/tool.so") + assert is_pin_timeout("TIMEOUT (>900s)") + for other in ("", "exit 1: boom", "pin output unreadable: x", + "pin count unreadable: x"): + assert not is_pin_timeout(other), other + sample_tasks = [ ("sort/merge_sort", "solution", "s1", "tc0", "in", "out"), ("sort/merge_sort", "solution", "s1", "tc1", "in", "out"), @@ -335,8 +513,21 @@ def main(argv=None): parser.add_argument("--summary-file", default=None, help="Markdown summary output") parser.add_argument("--merge", nargs="*", default=None, help="merge shard JSON files") parser.add_argument("--self-test", action="store_true", help="run self-test") + parser.add_argument("--pin", action="store_true", + help="also count instructions under Intel Pin") + parser.add_argument("--pin-bin", default="", + help="Pin launcher binary (Intel kit, direct download)") + parser.add_argument("--pin-tool", default="", + help="inscount tool .so for Pin (-t)") + parser.add_argument("--pin-repeat", type=int, default=PIN_REPEAT_DEFAULT) + parser.add_argument("--pin-timeout", type=int, default=PIN_TIMEOUT_DEFAULT) args = parser.parse_args(argv) + if args.pin_repeat < 1: + parser.error("--pin-repeat must be >= 1") + if args.pin_timeout < 1: + parser.error("--pin-timeout must be >= 1") + if args.self_test: return self_test() @@ -357,6 +548,12 @@ def main(argv=None): if not has_valgrind: print("warning: valgrind not found in PATH; running Python directly without Callgrind simulation", file=sys.stderr) + use_pin = args.pin and pin_usable(args.pin_bin, args.pin_tool) + if args.pin and not use_pin: + print("warning: pin unavailable (need --pin-bin launcher and --pin-tool inscount .so); pin_instructions will be null", file=sys.stderr) + pin_ver = pin_version(args.pin_bin) if use_pin else None + effective_pin_repeat = args.pin_repeat if use_pin else 0 + tasks = [] missing = [] for area, problem, stem, script, cases in run_tests.discover(args.resources): @@ -384,32 +581,46 @@ def main(argv=None): with ThreadPoolExecutor(max_workers=args.jobs) as pool: futures = { pool.submit( - measure_case_callgrind, + measure_case_full, has_valgrind, + label, script, case_name, inp, outp, args.repeat, args.timeout, + args.pin_bin, + args.pin_tool, + effective_pin_repeat, + args.pin_timeout, ): (label, stem, script, case_name) for label, stem, script, case_name, inp, outp in tasks } for future in as_completed(futures): label, stem, script, case_name = futures[future] - summary, err = future.result() + summary, pin_skipped, err = future.result() done += 1 if err is None: insn = summary["instructions"]["median"] if summary.get("instructions") else None insn_s = f"{int(insn):,} Ir" if insn else "n/a" - print(f"[{done}/{total_tasks}] {label}/{case_name}: {insn_s}") - results.append({ + pin_info = "" + if summary.get("pin_instructions"): + pin_med = summary["pin_instructions"]["median"] + pin_info = f"; {int(pin_med):,} Pin" + elif pin_skipped: + pin_info = f" (pin skipped: {pin_skipped})" + print(f"[{done}/{total_tasks}] {label}/{case_name}: {insn_s}{pin_info}") + entry = { "label": label, "stem": stem, "case": case_name, "script": os.path.relpath(script, ROOT), "summary": summary, - }) + } + if pin_skipped: + entry["pin_skipped"] = pin_skipped + results.append(entry) else: print(f"[{done}/{total_tasks}] FAIL {label}/{case_name}: {err}") failures.append(f"{label}/{case_name}: {err}") @@ -419,6 +630,8 @@ def main(argv=None): "platform": platform.platform(), "date": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()), "has_valgrind": has_valgrind, + "pin_used": use_pin, + "pin_version": pin_ver, "results": results, "failures": failures, } From 9fd9d2df9cc37805992a65113bb46a5dfb717f71 Mon Sep 17 00:00:00 2001 From: Hao Hu Date: Thu, 5 Nov 2026 11:35:32 +0100 Subject: [PATCH 2/5] ci: rename perf-callgrind jobs to perf-instrumentation --- .github/workflows/test.yml | 8 ++++---- README.md | 2 +- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 7e7ec7c..90c6abf 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -60,7 +60,7 @@ jobs: run: | if [ "${{ needs.test-shard.result }}" = "success" ]; then exit 0; else exit 1; fi - perf-callgrind: + perf-instrumentation: needs: test runs-on: ubuntu-latest permissions: @@ -71,7 +71,7 @@ jobs: fail-fast: false matrix: shard: [0, 1, 2, 3] - name: perf-callgrind (shard ${{ matrix.shard }}/4) + name: perf-instrumentation (shard ${{ matrix.shard }}/4) steps: - uses: actions/checkout@v7 - uses: ./.github/actions/profile-runner @@ -163,8 +163,8 @@ jobs: perf-results.json bencher-bmf.json - report: - needs: perf-callgrind + report-instrumentation: + needs: perf-instrumentation runs-on: ubuntu-latest permissions: contents: read diff --git a/README.md b/README.md index 6aa0630..c77db76 100644 --- a/README.md +++ b/README.md @@ -65,4 +65,4 @@ python3 tools/measure.py --resources tests/resources --repeat 1 \ python3 tools/measure.py --self-test ``` -CI runs correctness across sharded runners in the `test-shard` jobs, aggregated by `test`. Then the `perf-callgrind` job measures instruction counts under Valgrind Callgrind across 4 shards, reporting to Bencher under testbed `ubuntu-latest-python` and measure `instructions` (gated by `BENCHER_API_KEY`). A fan-in `report` job merges all shard results, verifies equality against the plain BMF union (`jq -s 'add'`), and publishes a combined Markdown summary table to the GitHub Actions job summary. +CI runs correctness across sharded runners in the `test-shard` jobs, aggregated by `test`. Then the `perf-instrumentation` job measures instruction counts under Valgrind Callgrind across 4 shards, reporting to Bencher under testbed `ubuntu-latest-python` and measure `instructions` (gated by `BENCHER_API_KEY`). A fan-in `report-instrumentation` job merges all shard results, verifies equality against the plain BMF union (`jq -s 'add'`), and publishes a combined Markdown summary table to the GitHub Actions job summary. From 862d299d6e2732985555f37ecb3858a367049833 Mon Sep 17 00:00:00 2001 From: Hao Hu Date: Thu, 5 Nov 2026 11:57:47 +0100 Subject: [PATCH 3/5] ci: switch perf-instrumentation from valgrind to Pin 4.4 Replace the valgrind/callgrind backend with Intel Pin 4.4: provision the kit (sha256-pinned, cached) and build the new vendored inscount tool (scripts/ci/instrumentation), then sweep with --pin. The harness keeps its Callgrind code paths for local use but CI no longer installs valgrind, so the deterministic signal is now the pin_instructions BMF measure; cpu_time continues, callgrind 'instructions' history ends by design. --- .github/workflows/test.yml | 29 +++++--- README.md | 12 ++-- scripts/ci/instrumentation/inscount.cpp | 57 +++++++++++++++ scripts/ci/instrumentation/makefile | 11 +++ scripts/ci/instrumentation/makefile.rules | 1 + scripts/ci/setup-instrumentation.sh | 66 +++++++++++++++++ tools/measure.py | 88 +++++++++++++++++------ 7 files changed, 229 insertions(+), 35 deletions(-) create mode 100644 scripts/ci/instrumentation/inscount.cpp create mode 100644 scripts/ci/instrumentation/makefile create mode 100644 scripts/ci/instrumentation/makefile.rules create mode 100755 scripts/ci/setup-instrumentation.sh diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 90c6abf..4ff5fd1 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -96,20 +96,27 @@ jobs: --passphrase "$RESOURCES_PASSPHRASE" \ -d tests/resources.tar.xz.asc | tar -xJ -C tests/resources --strip-components=1 - - name: Install Valgrind - uses: awalsh128/cache-apt-pkgs-action@v1.6.3 + - name: Cache instrumentation kit + uses: actions/cache@v5 with: - packages: valgrind - version: 1.0 - - - name: Measure performance (Callgrind instructions) - # Timeout 600 (was 300): edit_distance/test_case_5 (~45B Ir) - # sits on the 300s wall-clock knife-edge under callgrind with - # --jobs 2, and shard rotation after #2 tipped it to - # usually-timeout. 2x headroom; genuine hangs still fail. + path: ~/instrumentation + key: instrumentation-pin-4.4-${{ hashFiles('scripts/ci/setup-instrumentation.sh', 'scripts/ci/instrumentation/inscount.cpp') }} + + - name: Provision instrumentation (Pin 4.4) + run: bash scripts/ci/setup-instrumentation.sh + + - name: Measure performance (Pin instructions) + # Pin budget 600/repeat: the heaviest cases (edit_distance) + # run minutes under instrumentation with --jobs 2; the + # native first phase stays on the same 600s ceiling. Pin + # timeouts degrade to pin-skipped (native data stays valid); + # genuine hangs still fail via the native phase. run: | python3 tools/measure.py --resources tests/resources \ --repeat 1 --jobs 2 --timeout 600 \ + --pin --pin-bin "$INSTRUMENTATION_BIN" \ + --pin-tool "$INSTRUMENTATION_TOOL" \ + --pin-repeat 2 --pin-timeout 600 \ --shard ${{ matrix.shard }}/4 \ --output perf-results.json --bmf-output bencher-bmf.json \ --summary-file "$GITHUB_STEP_SUMMARY" @@ -144,7 +151,7 @@ jobs: --key '${{ secrets.BENCHER_API_KEY }}' \ --branch "${{ github.ref_name }}" \ --testbed ubuntu-latest-python \ - --threshold-measure instructions \ + --threshold-measure pin_instructions \ --threshold-test percentage \ --threshold-min-sample-size 10 \ --threshold-max-sample-size 64 \ diff --git a/README.md b/README.md index c77db76..8e962fe 100644 --- a/README.md +++ b/README.md @@ -51,18 +51,22 @@ tools/build_bundle.sh [passphrase-file] See `tools/build_bundle.sh` for rotation instructions when using a fresh passphrase. -## Performance Tracking (Callgrind) +## Performance Tracking (Intel Pin) -`tools/measure.py` measures load-independent algorithmic complexity using Valgrind Callgrind: +`tools/measure.py` measures load-independent algorithmic complexity using Intel Pin with the vendored inscount tool (`scripts/ci/instrumentation/`): -- `instructions` (`Ir` — simulated instruction reads) — completely load-invariant and deterministic across runs and runners. +- `pin_instructions` (executed application instructions under Pin 4.4) — completely load-invariant and deterministic across runs and runners. - `cpu_time` (user + sys CPU time) - `wall_time` +When Valgrind happens to be installed locally, a Callgrind `instructions` (`Ir`) signal is recorded too; CI no longer installs Valgrind, so that measure is absent there. + ```sh +bash scripts/ci/setup-instrumentation.sh # one-time: fetch Pin 4.4 kit, build tool python3 tools/measure.py --resources tests/resources --repeat 1 \ + --pin --pin-bin "$INSTRUMENTATION_BIN" --pin-tool "$INSTRUMENTATION_TOOL" \ --output perf.json --bmf-output bencher.json python3 tools/measure.py --self-test ``` -CI runs correctness across sharded runners in the `test-shard` jobs, aggregated by `test`. Then the `perf-instrumentation` job measures instruction counts under Valgrind Callgrind across 4 shards, reporting to Bencher under testbed `ubuntu-latest-python` and measure `instructions` (gated by `BENCHER_API_KEY`). A fan-in `report-instrumentation` job merges all shard results, verifies equality against the plain BMF union (`jq -s 'add'`), and publishes a combined Markdown summary table to the GitHub Actions job summary. +CI runs correctness across sharded runners in the `test-shard` jobs, aggregated by `test`. Then the `perf-instrumentation` job provisions the cached Pin 4.4 kit and measures instruction counts under Pin across 4 shards, reporting to Bencher under testbed `ubuntu-latest-python` and measure `pin_instructions` (gated by `BENCHER_API_KEY`). A fan-in `report-instrumentation` job merges all shard results, verifies equality against the plain BMF union (`jq -s 'add'`), and publishes a combined Markdown summary table to the GitHub Actions job summary. diff --git a/scripts/ci/instrumentation/inscount.cpp b/scripts/ci/instrumentation/inscount.cpp new file mode 100644 index 0000000..83e0650 --- /dev/null +++ b/scripts/ci/instrumentation/inscount.cpp @@ -0,0 +1,57 @@ +// inscount: minimal Intel Pin tool counting executed application +// instructions for the python snippet perf sweep. +// +// Instruments at TRACE/BBL granularity: each basic block gets one +// analysis call adding the block's static instruction count to a +// process-wide total (all threads, all application images; the Pin +// VM itself is never instrumented). At shutdown the tool prints a +// single line: +// +// Count N +// +// to the file named by the -o knob (default inscount.out). +// tools/measure.py parses that line (parse_pin_count) and records +// it as pin_instructions. Build out of the kit with: +// +// make PIN_ROOT= -C +// +// which drops obj-intel64/inscount.so next to this file. +#include +#include "pin.H" + +static UINT64 g_total = 0; +static FILE *g_out = nullptr; +static KNOB KnobOut(KNOB_MODE_WRITEONCE, "pintool", "o", "inscount.out", + "output file for the Count line"); + +static VOID AddBlock(UINT32 n) { g_total += n; } + +static VOID Trace(TRACE trace, VOID *) { + for (BBL bbl = TRACE_BblHead(trace); BBL_Valid(bbl); bbl = BBL_Next(bbl)) { + BBL_InsertCall(bbl, IPOINT_BEFORE, (AFUNPTR)AddBlock, IARG_UINT32, BBL_NumIns(bbl), + IARG_END); + } +} + +static VOID Fini(INT32, VOID *) { + if (g_out != nullptr) { + fprintf(g_out, "Count %llu\n", (unsigned long long)g_total); + fclose(g_out); + g_out = nullptr; + } +} + +int main(int argc, char *argv[]) { + PIN_InitSymbols(); + if (PIN_Init(argc, argv)) { + return 1; + } + g_out = fopen(KnobOut.Value().c_str(), "w"); + if (g_out == nullptr) { + return 1; + } + TRACE_AddInstrumentFunction(Trace, nullptr); + PIN_AddFiniFunction(Fini, nullptr); + PIN_StartProgram(); + return 0; +} diff --git a/scripts/ci/instrumentation/makefile b/scripts/ci/instrumentation/makefile new file mode 100644 index 0000000..10c9e72 --- /dev/null +++ b/scripts/ci/instrumentation/makefile @@ -0,0 +1,11 @@ +# Out-of-kit build for the vendored inscount tool. The kit's own +# makefile does the heavy lifting; PIN_ROOT must point at the +# extracted kit root (the directory containing the `pin` launcher). +ifdef PIN_ROOT +CONFIG_ROOT := $(PIN_ROOT)/source/tools/Config +else +CONFIG_ROOT := ../Config +endif +include $(CONFIG_ROOT)/makefile.config +include makefile.rules +include $(TOOLS_ROOT)/Config/makefile.default.rules diff --git a/scripts/ci/instrumentation/makefile.rules b/scripts/ci/instrumentation/makefile.rules new file mode 100644 index 0000000..8f2119c --- /dev/null +++ b/scripts/ci/instrumentation/makefile.rules @@ -0,0 +1 @@ +TOOL_ROOTS := inscount diff --git a/scripts/ci/setup-instrumentation.sh b/scripts/ci/setup-instrumentation.sh new file mode 100755 index 0000000..8748ab9 --- /dev/null +++ b/scripts/ci/setup-instrumentation.sh @@ -0,0 +1,66 @@ +#!/bin/bash +# Provision the instrumentation backend (Intel Pin + the vendored +# inscount tool) for the perf-instrumentation CI job. +# +# Idempotent: when INSTRUMENTATION_DIR already holds a kit and a +# built tool (the workflow caches it across runs), it just +# re-exports the paths. Otherwise it downloads the kit from +# Intel, verifies its sha256, extracts it, and builds +# scripts/ci/instrumentation/inscount.cpp against it. +# +# Outputs (stdout for logs, $GITHUB_ENV when present): +# INSTRUMENTATION_BIN absolute path to the pin launcher +# INSTRUMENTATION_TOOL absolute path to obj-intel64/inscount.so +set -euo pipefail + +PIN_URL="${PIN_URL:-https://software.intel.com/sites/landingpage/pintool/downloads/pin-external-4.4-99977-g54fbb8814-gcc-linux.tar.gz}" +PIN_SHA256="${PIN_SHA256:-3138183a5d2b51ea5c8f29edd148b67ac9c249e2c510cc0e9e2a5880f523a34c}" +PIN_TOPDIR="pin-external-4.4-99977-g54fbb8814-gcc-linux" +INSTRUMENTATION_DIR="${INSTRUMENTATION_DIR:-$HOME/instrumentation}" +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +TOOL_SRC="$SCRIPT_DIR/instrumentation" + +KIT_DIR="$INSTRUMENTATION_DIR/$PIN_TOPDIR" +INSTRUMENTATION_BIN="$KIT_DIR/pin" +TOOL_BUILD="$INSTRUMENTATION_DIR/toolbuild" +INSTRUMENTATION_TOOL="$TOOL_BUILD/obj-intel64/inscount.so" + +need_tool() { + [ ! -x "$INSTRUMENTATION_BIN" ] || [ ! -f "$INSTRUMENTATION_TOOL" ] +} + +err() { echo "setup-instrumentation: $*" >&2; } + +if need_tool; then + command -v g++ >/dev/null || { err "g++ is required to build the inscount tool"; exit 1; } + command -v curl >/dev/null || { err "curl is required to fetch the Pin kit"; exit 1; } + [ -f "$TOOL_SRC/inscount.cpp" ] || { err "tool sources missing at $TOOL_SRC"; exit 1; } + mkdir -p "$INSTRUMENTATION_DIR" + if [ ! -x "$INSTRUMENTATION_BIN" ]; then + err "downloading Pin 4.4 kit..." + curl -sSfL --retry 3 --max-time 600 -o "$INSTRUMENTATION_DIR/pin-kit.tar.gz" "$PIN_URL" + echo "$PIN_SHA256 $INSTRUMENTATION_DIR/pin-kit.tar.gz" | sha256sum -c - || { + err "kit checksum mismatch"; exit 1 + } + tar xzf "$INSTRUMENTATION_DIR/pin-kit.tar.gz" -C "$INSTRUMENTATION_DIR" + rm -f "$INSTRUMENTATION_DIR/pin-kit.tar.gz" + fi + err "building inscount tool..." + rm -rf "$TOOL_BUILD" + mkdir -p "$TOOL_BUILD" + cp "$TOOL_SRC/inscount.cpp" "$TOOL_SRC/makefile" "$TOOL_SRC/makefile.rules" "$TOOL_BUILD/" + make -C "$TOOL_BUILD" PIN_ROOT="$KIT_DIR" >/tmp/instrumentation-tool-build.log 2>&1 || { + tail -n 20 /tmp/instrumentation-tool-build.log >&2; err "tool build failed"; exit 1 + } +fi + +[ -x "$INSTRUMENTATION_BIN" ] || { err "pin launcher missing at $INSTRUMENTATION_BIN"; exit 1; } +[ -f "$INSTRUMENTATION_TOOL" ] || { err "tool missing at $INSTRUMENTATION_TOOL"; exit 1; } +"$INSTRUMENTATION_BIN" -version >/dev/null 2>&1 || { err "pin launcher does not run"; exit 1; } + +echo "INSTRUMENTATION_BIN=$INSTRUMENTATION_BIN" +echo "INSTRUMENTATION_TOOL=$INSTRUMENTATION_TOOL" +if [ -n "${GITHUB_ENV:-}" ]; then + echo "INSTRUMENTATION_BIN=$INSTRUMENTATION_BIN" >>"$GITHUB_ENV" + echo "INSTRUMENTATION_TOOL=$INSTRUMENTATION_TOOL" >>"$GITHUB_ENV" +fi diff --git a/tools/measure.py b/tools/measure.py index 35eea3c..e29c97d 100755 --- a/tools/measure.py +++ b/tools/measure.py @@ -2,23 +2,25 @@ """Load-independent performance measurement for Python snippets. Runs every src/**/*.py script against the shared test cases and records -metrics under Valgrind Callgrind: +metrics under Intel Pin (inscount tool): - * instructions (simulated instruction reads 'Ir' from Callgrind) -- + * pin_instructions (executed application instructions under Pin) -- fully load-independent and deterministic across runs. * cpu_s (user + sys CPU time). * wall_s (wall time). * maxrss_kb (peak RSS in KB). -Plus (under the new flags) Pin instruction counts from an inscount -tool run: pin_instructions min/median/max per case. +Plus, when Valgrind is installed locally, Callgrind instruction reads +('Ir') as instructions min/median/max per case. CI no longer installs +Valgrind, so the Callgrind signal is absent there; the Callgrind code +paths stay for local use. Usage: python3 tools/measure.py --resources tests/resources \ [--repeat 1] [--jobs 2] [--timeout 300] [--only substring] \ [--output perf.json] [--bmf-output bencher.json] \ [--summary-file "$GITHUB_STEP_SUMMARY"] [--shard K/N] \ - [--pin] [--pin-bin BIN] [--pin-tool SO] [--pin-repeat N] \ + --pin --pin-bin BIN --pin-tool SO [--pin-repeat N] \ [--pin-timeout S] python3 tools/measure.py --merge shard-*.json --output merged.json \ @@ -45,7 +47,7 @@ sys.path.insert(0, os.path.join(ROOT, "tests")) import run_tests -TOOL_VERSION = 2 +TOOL_VERSION = 3 _CALLGRIND_TOTAL_RE = re.compile(r"^(?:totals|summary):\s*(\d+)", re.MULTILINE) # Pin inscount defaults: two counts per case catch instrument @@ -318,7 +320,11 @@ def measure_case_pin(exec_cmd, label, case_name, input_path, output_path, def measure_case_full(has_valgrind, label, script, case_name, inp, outp, repeat, timeout, pin_bin, pin_tool, pin_repeat, pin_timeout): - """Callgrind measure plus the optional Pin inscount phase. + """Direct/Callgrind measure plus the Pin inscount phase. + + The first phase runs the case natively (or under Callgrind when + valgrind is installed) for correctness and wall/cpu time; the Pin + phase provides the deterministic instruction count. Returns (summary|None, pin_skipped|None, error|None). """ @@ -348,6 +354,8 @@ def build_bmf(results): items = snippets[name] total_instructions = 0 has_instructions = False + total_pin = 0 + has_pin = False total_cpu = 0.0 for it in items: @@ -357,12 +365,17 @@ def build_bmf(results): if s.get("instructions") and s["instructions"]["median"] is not None: total_instructions += int(s["instructions"]["median"]) has_instructions = True + if s.get("pin_instructions") and s["pin_instructions"]["median"] is not None: + total_pin += int(s["pin_instructions"]["median"]) + has_pin = True if s.get("cpu_s") and s["cpu_s"]["median"] is not None: total_cpu += float(s["cpu_s"]["median"]) measures = {} if has_instructions: measures["instructions"] = {"value": total_instructions} + if has_pin: + measures["pin_instructions"] = {"value": total_pin} measures["cpu_time"] = {"value": total_cpu} bmf[name] = measures @@ -398,15 +411,17 @@ def append_summary(path, report, bmf): if not path: return lines = [ - "### Callgrind Performance Summary (Python)", + "### Instrumentation Performance Summary (Python)", "", - "| Benchmark | Cases | Instructions (Ir) | CPU Time (s) |", - "| :--- | :---: | :---: | :---: |", + "| Benchmark | Cases | Pin Instr | Callgrind Ir | CPU Time (s) |", + "| :--- | :---: | :---: | :---: | :---: |", ] total_insn = 0 + total_pin = 0 total_cpu = 0.0 has_insn = False + has_pin = False snippets = {} for r in report.get("results", []): @@ -415,6 +430,12 @@ def append_summary(path, report, bmf): for name in sorted(snippets): cases_count = len(snippets[name]) m = bmf.get(name, {}) + pin_str = "-" + if "pin_instructions" in m: + val = m["pin_instructions"]["value"] + pin_str = f"{val:,}" + total_pin += val + has_pin = True insn_str = "-" if "instructions" in m: val = m["instructions"]["value"] @@ -423,10 +444,11 @@ def append_summary(path, report, bmf): has_insn = True cpu_val = m.get("cpu_time", {}).get("value", 0.0) total_cpu += cpu_val - lines.append(f"| `{name}` | {cases_count} | {insn_str} | {cpu_val:.4f} |") + lines.append(f"| `{name}` | {cases_count} | {pin_str} | {insn_str} | {cpu_val:.4f} |") + tot_pin_str = f"{total_pin:,}" if has_pin else "-" tot_insn_str = f"{total_insn:,}" if has_insn else "-" - lines.append(f"| **Total ({len(snippets)} snippets)** | - | **{tot_insn_str}** | **{total_cpu:.4f}** |") + lines.append(f"| **Total ({len(snippets)} snippets)** | - | **{tot_pin_str}** | **{tot_insn_str}** | **{total_cpu:.4f}** |") lines.append("") with open(path, "a") as f: @@ -480,6 +502,7 @@ def self_test(): "case": "tc0", "summary": { "instructions": {"median": 1000}, + "pin_instructions": {"median": 4000}, "cpu_s": {"median": 0.05}, }, }, @@ -488,14 +511,33 @@ def self_test(): "case": "tc1", "summary": { "instructions": {"median": 2000}, + "pin_instructions": {"median": 8000}, "cpu_s": {"median": 0.05}, }, }, ] bmf = build_bmf(mock_results) assert bmf["sort/merge_sort"]["instructions"]["value"] == 3000 + assert bmf["sort/merge_sort"]["pin_instructions"]["value"] == 12000 assert abs(bmf["sort/merge_sort"]["cpu_time"]["value"] - 0.10) < 1e-6 + # Pin BMF without any Callgrind signal (the CI shape: no + # valgrind installed, so no "instructions" measure at all). + pin_only = [ + { + "label": "math/gcd", + "case": "tc0", + "summary": { + "instructions": None, + "pin_instructions": {"median": 9000}, + "cpu_s": {"median": 0.02}, + }, + }, + ] + bmf_pin = build_bmf(pin_only) + assert "instructions" not in bmf_pin["math/gcd"] + assert bmf_pin["math/gcd"]["pin_instructions"]["value"] == 9000 + print("self-test passed!") return 0 @@ -514,7 +556,7 @@ def main(argv=None): parser.add_argument("--merge", nargs="*", default=None, help="merge shard JSON files") parser.add_argument("--self-test", action="store_true", help="run self-test") parser.add_argument("--pin", action="store_true", - help="also count instructions under Intel Pin") + help="count instructions under Intel Pin (primary signal)") parser.add_argument("--pin-bin", default="", help="Pin launcher binary (Intel kit, direct download)") parser.add_argument("--pin-tool", default="", @@ -572,7 +614,13 @@ def main(argv=None): tasks = select_shard(tasks, index, total) total_tasks = len(tasks) - print(f"Measuring {total_tasks} cases ({len({t[0] for t in tasks})} benchmarks) with Callgrind...") + if use_pin: + backend = "Pin inscount" + elif has_valgrind: + backend = "Callgrind" + else: + backend = "direct run (no instrumentation)" + print(f"Measuring {total_tasks} cases ({len({t[0] for t in tasks})} benchmarks) with {backend}...") results = [] failures = [] @@ -602,15 +650,15 @@ def main(argv=None): summary, pin_skipped, err = future.result() done += 1 if err is None: - insn = summary["instructions"]["median"] if summary.get("instructions") else None - insn_s = f"{int(insn):,} Ir" if insn else "n/a" - pin_info = "" + parts = [] if summary.get("pin_instructions"): pin_med = summary["pin_instructions"]["median"] - pin_info = f"; {int(pin_med):,} Pin" + parts.append(f"{int(pin_med):,} Pin") elif pin_skipped: - pin_info = f" (pin skipped: {pin_skipped})" - print(f"[{done}/{total_tasks}] {label}/{case_name}: {insn_s}{pin_info}") + parts.append(f"pin skipped: {pin_skipped}") + insn = summary["instructions"]["median"] if summary.get("instructions") else None + parts.append(f"{int(insn):,} Ir" if insn else "n/a Ir") + print(f"[{done}/{total_tasks}] {label}/{case_name}: {'; '.join(parts)}") entry = { "label": label, "stem": stem, From 6eef1d26164b4edf10c5b8698a16ad7bf664c07b Mon Sep 17 00:00:00 2001 From: Hao Hu Date: Thu, 5 Nov 2026 12:09:38 +0100 Subject: [PATCH 4/5] measure: pin-only mode (--repeat 0) + alloc-shim allocated_bytes --repeat 0 skips the native timed phase (needs --pin), so each case is measured once under Pin; correctness still gates on the first instrumented run's stdout. The same Pin run now also preloads the LD_PRELOAD alloc shim (scripts/ci/instrumentation/allocshim.c, built on demand with cc, total parsed from the child's stderr), recording allocated_bytes alongside pin_instructions. Renderers print '-' / omit BMF rows instead of zeros when timed signals are absent; maxrss is never read from instrumented runs. TOOL_VERSION 3->4. Callgrind code paths untouched. --- README.md | 11 +- scripts/ci/instrumentation/allocshim.c | 231 +++++++++++++++++ tools/measure.py | 328 +++++++++++++++++++++---- 3 files changed, 523 insertions(+), 47 deletions(-) create mode 100644 scripts/ci/instrumentation/allocshim.c diff --git a/README.md b/README.md index 8e962fe..3c73888 100644 --- a/README.md +++ b/README.md @@ -53,20 +53,19 @@ See `tools/build_bundle.sh` for rotation instructions when using a fresh passphr ## Performance Tracking (Intel Pin) -`tools/measure.py` measures load-independent algorithmic complexity using Intel Pin with the vendored inscount tool (`scripts/ci/instrumentation/`): +`tools/measure.py` measures load-independent algorithmic complexity using Intel Pin with the vendored inscount tool (`scripts/ci/instrumentation/`), in pin-only mode (`--repeat 0`): each case runs once under Pin, with an `LD_PRELOAD` allocation-counting shim in the same run: - `pin_instructions` (executed application instructions under Pin 4.4) — completely load-invariant and deterministic across runs and runners. -- `cpu_time` (user + sys CPU time) -- `wall_time` +- `allocated_bytes` (cumulative libc allocation in the same Pin run) — the memory signal. It includes Pin's own JIT/VM allocations, so like `pin_instructions` it is only comparable within one Pin version. -When Valgrind happens to be installed locally, a Callgrind `instructions` (`Ir`) signal is recorded too; CI no longer installs Valgrind, so that measure is absent there. +Peak RSS is never read from instrumented runs — Pin's own footprint pollutes it — so timed signals (`cpu_time`, `wall_time`, `maxrss`) are absent from pin-only sweeps; the summary shows `-` and BMF omits those rows rather than emitting zeros. Locally, `--repeat N` (N ≥ 1) still runs a native timed phase first (plus a Callgrind `instructions` signal when Valgrind happens to be installed); CI no longer installs Valgrind, so that measure is absent there. ```sh bash scripts/ci/setup-instrumentation.sh # one-time: fetch Pin 4.4 kit, build tool -python3 tools/measure.py --resources tests/resources --repeat 1 \ +python3 tools/measure.py --resources tests/resources --repeat 0 \ --pin --pin-bin "$INSTRUMENTATION_BIN" --pin-tool "$INSTRUMENTATION_TOOL" \ --output perf.json --bmf-output bencher.json python3 tools/measure.py --self-test ``` -CI runs correctness across sharded runners in the `test-shard` jobs, aggregated by `test`. Then the `perf-instrumentation` job provisions the cached Pin 4.4 kit and measures instruction counts under Pin across 4 shards, reporting to Bencher under testbed `ubuntu-latest-python` and measure `pin_instructions` (gated by `BENCHER_API_KEY`). A fan-in `report-instrumentation` job merges all shard results, verifies equality against the plain BMF union (`jq -s 'add'`), and publishes a combined Markdown summary table to the GitHub Actions job summary. +CI runs correctness across sharded runners in the `test-shard` jobs, aggregated by `test`. Then the `perf-instrumentation` job provisions the cached Pin 4.4 kit and measures instruction counts plus allocated bytes under Pin across 4 shards, reporting to Bencher under testbed `ubuntu-latest-python` and measures `pin_instructions` / `allocated_bytes` (gated by `BENCHER_API_KEY`). A fan-in `report-instrumentation` job merges all shard results, verifies equality against the plain BMF union (`jq -s 'add'`), and publishes a combined Markdown summary table to the GitHub Actions job summary. diff --git a/scripts/ci/instrumentation/allocshim.c b/scripts/ci/instrumentation/allocshim.c new file mode 100644 index 0000000..8613e77 --- /dev/null +++ b/scripts/ci/instrumentation/allocshim.c @@ -0,0 +1,231 @@ +// allocshim: LD_PRELOAD allocation-counting shim (Linux/glibc +// only) for the python snippet perf sweep. +// +// Interposes the libc allocation entry points, sums requested +// bytes, and a destructor reports the total on fd 2 as: +// +// snip_alloc_total_bytes=N +// +// Freed bytes are never subtracted, so the total is the cumulative +// allocation for the whole process run. Deterministic programs +// yield deterministic totals; exit-path allocations after the +// destructor (if any) are missed identically every run, so they +// shift the total by a constant, never by noise. +// +// tools/measure.py builds this file on demand (cc -shared -fPIC) +// and preloads it in the SAME Pin run as the inscount tool +// (LD_PRELOAD shim + pin -t inscount -- python ...), so each +// instrumented run yields both pin_instructions and +// allocated_bytes. The total therefore includes Pin's own +// JIT/VM allocations: deterministic within a Pin version, but +// only comparable within that version (like pin_instructions). +// Peak RSS is never read from instrumented runs -- Pin's own +// footprint pollutes it -- so allocated_bytes is the memory +// signal and maxrss stays null in pin-only sweeps. +// +// Ported from the hhh-pa/clojure-code-snippet alloc shim +// (scripts/ci/go/internal/measure/allocshim.go, embedded C +// source -- that repo has no standalone allocshim.c file), +// as a standalone source so the Python harness keeps one +// obvious build input next to inscount.cpp. +#define _GNU_SOURCE +#include +#include +#include +#include +#include +#include +#include +#include + +static atomic_ullong total_bytes = 0; + +/* Bootstrap pool: dlsym(RTLD_NEXT, ...) itself allocates, so + * allocations arriving before init completes are served from here + * (uncounted) instead of recursing. 64KB dwarfs dlsym's needs. */ +#define POOL_SIZE (64u * 1024u) +_Alignas(64) static char bootstrap_pool[POOL_SIZE]; +static atomic_size_t pool_used = 0; +static volatile int resolving = 0; +static void *(*real_malloc)(size_t); +static void (*real_free)(void *); +static void *(*real_calloc)(size_t, size_t); +static void *(*real_realloc)(void *, size_t); +static void *(*real_reallocarray)(void *, size_t, size_t); +static int (*real_posix_memalign)(void **, size_t, size_t); +static void *(*real_aligned_alloc)(size_t, size_t); + +static void *pool_alloc(size_t size) { + if (size == 0) + size = 1; + size = (size + 15) & ~(size_t)15; + size_t off = atomic_fetch_add(&pool_used, size); + if (off + size > POOL_SIZE) + return NULL; + return bootstrap_pool + off; +} + +static int in_pool(const void *p) { + const char *c = (const char *)p; + return c >= bootstrap_pool && c < bootstrap_pool + POOL_SIZE; +} + +static size_t pool_tail(const void *p) { + return (size_t)(bootstrap_pool + POOL_SIZE - (const char *)p); +} + +static void resolve_all(void) { + real_malloc = dlsym(RTLD_NEXT, "malloc"); + real_free = dlsym(RTLD_NEXT, "free"); + real_calloc = dlsym(RTLD_NEXT, "calloc"); + real_realloc = dlsym(RTLD_NEXT, "realloc"); + real_reallocarray = dlsym(RTLD_NEXT, "reallocarray"); + real_posix_memalign = dlsym(RTLD_NEXT, "posix_memalign"); + real_aligned_alloc = dlsym(RTLD_NEXT, "aligned_alloc"); +} + +/* True once the real entry points are resolved. Reentrant calls + * during resolution (dlsym allocates) take the pool path. */ +static int ensure_init(void) { + if (real_malloc) + return 1; + if (resolving) + return 0; + resolving = 1; + resolve_all(); + resolving = 0; + return real_malloc != 0; +} + +__attribute__((constructor)) static void shim_init(void) { + resolving = 1; + resolve_all(); + resolving = 0; +} + +void *malloc(size_t size) { + if (!ensure_init()) + return pool_alloc(size); + void *p = real_malloc(size); + if (p) + atomic_fetch_add(&total_bytes, (unsigned long long)size); + return p; +} + +void free(void *p) { + if (!p || in_pool(p)) + return; + if (!ensure_init()) + return; + real_free(p); +} + +void *calloc(size_t n, size_t size) { + if (!ensure_init()) { + if (size != 0 && n > POOL_SIZE / size) + return NULL; + void *p = pool_alloc(n * size); + if (p) + memset(p, 0, n * size); + return p; + } + void *p = real_calloc(n, size); + if (p) + atomic_fetch_add(&total_bytes, (unsigned long long)n * (unsigned long long)size); + return p; +} + +void *realloc(void *ptr, size_t size) { + if (ptr && in_pool(ptr)) { + /* Bootstrap block outliving init: re-home it. The old + * size is unknown, so the copy clamps to the pool tail; + * glibc never reallocs its bootstrap blocks, so this + * path is unreachable in practice. */ + void *p = ensure_init() ? real_malloc(size ? size : 1) : pool_alloc(size); + if (p) { + size_t tail = pool_tail(ptr); + memcpy(p, ptr, size < tail ? size : tail); + if (real_malloc) + atomic_fetch_add(&total_bytes, (unsigned long long)size); + } + return p; + } + if (!ensure_init()) + return pool_alloc(size); + void *p = real_realloc(ptr, size); + if (p) + atomic_fetch_add(&total_bytes, (unsigned long long)size); + return p; +} + +void *reallocarray(void *ptr, size_t n, size_t size) { + if (size != 0 && n > (size_t)-1 / size) { + errno = ENOMEM; + return NULL; + } + if (real_reallocarray || ensure_init()) { + if (real_reallocarray && !(ptr && in_pool(ptr))) { + void *p = real_reallocarray(ptr, n, size); + if (p) + atomic_fetch_add(&total_bytes, (unsigned long long)n * (unsigned long long)size); + return p; + } + } + return realloc(ptr, n * size); +} + +int posix_memalign(void **memptr, size_t alignment, size_t size) { + if (!ensure_init() || !real_posix_memalign) { + if (alignment < sizeof(void *) || (alignment & (alignment - 1)) != 0) + return 22; /* EINVAL */ + if (size + alignment < size) + return 12; /* ENOMEM */ + void *raw = pool_alloc(size + alignment); + if (!raw) + return 12; /* ENOMEM */ + uintptr_t a = ((uintptr_t)raw + alignment - 1) & ~(uintptr_t)(alignment - 1); + *memptr = (void *)a; + return 0; + } + int r = real_posix_memalign(memptr, alignment, size); + if (r == 0) + atomic_fetch_add(&total_bytes, (unsigned long long)size); + return r; +} + +void *aligned_alloc(size_t alignment, size_t size) { + if (!ensure_init() || !real_aligned_alloc) { + void *p = NULL; + int r = posix_memalign(&p, alignment, size); + if (r != 0) { + errno = r; + return NULL; + } + return p; + } + void *p = real_aligned_alloc(alignment, size); + if (p) + atomic_fetch_add(&total_bytes, (unsigned long long)size); + return p; +} + +__attribute__((destructor)) static void shim_fini(void) { + static const char marker[] = "snip_alloc_total_bytes="; + char buf[64]; + unsigned long long v = atomic_load(&total_bytes); + size_t n = sizeof(marker) - 1; + memcpy(buf, marker, n); + char rev[24]; + int r = 0; + if (v == 0) + rev[r++] = '0'; + while (v > 0) { + rev[r++] = (char)('0' + (v % 10)); + v /= 10; + } + while (r > 0) + buf[n++] = rev[--r]; + buf[n++] = '\n'; + ssize_t w = write(2, buf, n); + (void)w; +} diff --git a/tools/measure.py b/tools/measure.py index e29c97d..3f10464 100755 --- a/tools/measure.py +++ b/tools/measure.py @@ -6,9 +6,19 @@ * pin_instructions (executed application instructions under Pin) -- fully load-independent and deterministic across runs. - * cpu_s (user + sys CPU time). - * wall_s (wall time). - * maxrss_kb (peak RSS in KB). + * allocated_bytes (cumulative libc allocation in the same Pin run, + via the LD_PRELOAD alloc shim) -- the memory signal. It includes + Pin's own JIT/VM allocations, so like pin_instructions it is only + comparable within one Pin version. + * cpu_s (user + sys CPU time, timed phase only). + * wall_s (wall time, timed phase only). + * maxrss_kb (peak RSS in KB, timed phase only). + +Pin-only mode (--repeat 0, needs --pin): skips the native timed phase +entirely, so each case is measured ONCE under Pin; correctness still +gates on the instrumented run's stdout. Timed signals stay null and +the renderers print "-" / omit BMF rows instead of zeros. Peak RSS is +never read from instrumented runs -- Pin's own footprint pollutes it. Plus, when Valgrind is installed locally, Callgrind instruction reads ('Ir') as instructions min/median/max per case. CI no longer installs @@ -17,7 +27,7 @@ Usage: python3 tools/measure.py --resources tests/resources \ - [--repeat 1] [--jobs 2] [--timeout 300] [--only substring] \ + [--repeat 0] [--jobs 2] [--only substring] \ [--output perf.json] [--bmf-output bencher.json] \ [--summary-file "$GITHUB_STEP_SUMMARY"] [--shard K/N] \ --pin --pin-bin BIN --pin-tool SO [--pin-repeat N] \ @@ -47,9 +57,15 @@ sys.path.insert(0, os.path.join(ROOT, "tests")) import run_tests -TOOL_VERSION = 3 +TOOL_VERSION = 4 _CALLGRIND_TOTAL_RE = re.compile(r"^(?:totals|summary):\s*(\d+)", re.MULTILINE) +# LD_PRELOAD alloc-shim channel: the shim's destructor prints exactly +# one "snip_alloc_total_bytes=N" line on the child's stderr. +ALLOC_MARKER = "snip_alloc_total_bytes=" +ALLOC_SHIM_SRC = os.path.join( + ROOT, "scripts", "ci", "instrumentation", "allocshim.c") + # Pin inscount defaults: two counts per case catch instrument # flakiness without paying for more slow runs; the Pin budget is # separate from --timeout since instrumentation runs ~10-100x slower. @@ -129,6 +145,61 @@ def pin_version(pin_bin): return None +def parse_alloc_total(content): + """Extract the alloc shim's total from child stderr text. + + The stderr channel is shared with the application, so malformed + marker lines are skipped (an app echoing the marker cannot break + the parse) and the last valid total wins. Raises ValueError when + no marker line parses. + """ + found = None + for line in content.splitlines(): + text = line.strip() + if not text.startswith(ALLOC_MARKER): + continue + digits = text[len(ALLOC_MARKER):] + if digits and all(c in "0123456789" for c in digits): + found = int(digits) + if found is None: + raise ValueError( + "alloc-shim total unreadable: no snip_alloc_total_bytes line") + return found + + +def ensure_alloc_shim(): + """Build the LD_PRELOAD allocation-counting shim on demand. + + Compiles scripts/ci/instrumentation/allocshim.c with cc into a + fresh temp dir and returns the .so path. Raises RuntimeError when + the platform has no LD_PRELOAD (non-Linux), no C compiler, or the + build fails. + """ + if not sys.platform.startswith("linux"): + raise RuntimeError("needs Linux (LD_PRELOAD)") + cc = shutil.which("cc") or shutil.which("gcc") + if cc is None: + raise RuntimeError("needs a C compiler (cc not found)") + if not os.path.isfile(ALLOC_SHIM_SRC): + raise RuntimeError("shim source missing at {}".format(ALLOC_SHIM_SRC)) + build_dir = tempfile.mkdtemp(prefix="snip-alloc-shim-") + out = os.path.join(build_dir, "alloc_shim.so") + try: + proc = subprocess.run( + [cc, "-shared", "-fPIC", "-O2", "-o", out, ALLOC_SHIM_SRC, "-ldl"], + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + timeout=120, + ) + except (OSError, subprocess.SubprocessError) as exc: + raise RuntimeError("build failed: {}".format(exc)) + if proc.returncode != 0: + tail = proc.stderr.decode(errors="ignore").strip().splitlines() + raise RuntimeError("build failed: {}".format( + tail[-1] if tail else "cc exit {}".format(proc.returncode))) + return out + + def is_pin_timeout(run_err): """Whether a Pin run error text is a deadline timeout (degrades to a skip) rather than a crash (fails the case).""" @@ -247,17 +318,29 @@ def measure_case_callgrind(has_valgrind, script, case_name, input_path, output_p return summary, None -def pin_once(pin_bin, pin_tool, exec_cmd, input_bytes, timeout): +def pin_once(pin_bin, pin_tool, exec_cmd, input_bytes, timeout, alloc_shim=None): """Run exec_cmd once under Pin with the inscount tool. - Returns (stdout, count, run_err): run_err is "" on success, else a - short "TIMEOUT (>Ns)" / "exit N: ..." / "pin output unreadable" - text for the caller to classify. + When alloc_shim names a built shim .so, it is LD_PRELOADed into + the same run, so the one instrumented execution yields both the + instruction count and the cumulative allocated bytes. + + Returns (stdout, count, alloc_bytes|None, run_err): run_err is "" + on success, else a short "TIMEOUT (>Ns)" / "exit N: ..." / + "pin output unreadable" / "pin alloc output unreadable" text for + the caller to classify. A missing shim total after a successful + exit fails the case: the harness is broken, not the snippet, and + silently dropping a tracked measure is worse than a red case. """ fd_temp, out_file = tempfile.mkstemp(prefix="snip-pin-", suffix=".out") os.close(fd_temp) try: cmd = [pin_bin, "-t", pin_tool, "-o", out_file, "--"] + list(exec_cmd) + env = None + if alloc_shim: + env = dict(os.environ) + prev = env.get("LD_PRELOAD") + env["LD_PRELOAD"] = alloc_shim if not prev else alloc_shim + ":" + prev try: proc = subprocess.run( cmd, @@ -265,19 +348,27 @@ def pin_once(pin_bin, pin_tool, exec_cmd, input_bytes, timeout): stdout=subprocess.PIPE, stderr=subprocess.PIPE, timeout=timeout, + env=env, ) except subprocess.TimeoutExpired: - return None, 0, "TIMEOUT (>{}s)".format(timeout) + return None, 0, None, "TIMEOUT (>{}s)".format(timeout) if proc.returncode != 0: err_text = proc.stderr.decode(errors="ignore").strip().splitlines() - return None, 0, "exit {}: {}".format( + return None, 0, None, "exit {}: {}".format( proc.returncode, err_text[-1] if err_text else "no stderr") try: with open(out_file, "r", errors="ignore") as fd: count = parse_pin_count(fd.read()) except (OSError, ValueError) as exc: - return None, 0, "pin output unreadable: {}".format(exc) - return proc.stdout, count, "" + return None, 0, None, "pin output unreadable: {}".format(exc) + alloc_bytes = None + if alloc_shim: + try: + alloc_bytes = parse_alloc_total( + proc.stderr.decode(errors="ignore")) + except ValueError as exc: + return None, 0, None, "pin alloc output unreadable: {}".format(exc) + return proc.stdout, count, alloc_bytes, "" finally: if os.path.exists(out_file): try: @@ -287,12 +378,14 @@ def pin_once(pin_bin, pin_tool, exec_cmd, input_bytes, timeout): def measure_case_pin(exec_cmd, label, case_name, input_path, output_path, - pin_bin, pin_tool, pin_repeat, pin_timeout): - """Pin inscount phase for one case. - - Returns (pin_summary|None, pin_skipped|None, error|None): timeouts - degrade to pin_skipped (callgrind data stays valid), crashes and - output mismatches fail the case. + pin_bin, pin_tool, pin_repeat, pin_timeout, alloc_shim=None): + """Pin inscount (+ alloc shim) phase for one case. + + Returns (signals|None, pin_skipped|None, error|None): signals maps + "pin_instructions" and, when the shim ran, "allocated_bytes" to + min/median/max summaries. Timeouts degrade to pin_skipped (timed + data, if any, stays valid); crashes and output mismatches fail + the case. """ with open(output_path, "rb") as fd: expected = run_tests.normalize(fd.read()) @@ -300,9 +393,10 @@ def measure_case_pin(exec_cmd, label, case_name, input_path, output_path, input_bytes = fd.read() counts = [] + allocs = [] for i in range(pin_repeat): - stdout, count, run_err = pin_once( - pin_bin, pin_tool, exec_cmd, input_bytes, pin_timeout) + stdout, count, alloc_bytes, run_err = pin_once( + pin_bin, pin_tool, exec_cmd, input_bytes, pin_timeout, alloc_shim) if run_err: if is_pin_timeout(run_err): print("warning: {}/{}: pin skipped ({})".format( @@ -315,30 +409,48 @@ def measure_case_pin(exec_cmd, label, case_name, input_path, output_path, return None, None, "pin output mismatch: expected {!r} got {!r}".format( want[:100], got[:100]) counts.append(count) - return summarize_numbers(counts), None, None + if alloc_bytes is not None: + allocs.append(alloc_bytes) + signals = {"pin_instructions": summarize_numbers(counts)} + if allocs: + signals["allocated_bytes"] = summarize_numbers(allocs) + return signals, None, None def measure_case_full(has_valgrind, label, script, case_name, inp, outp, - repeat, timeout, pin_bin, pin_tool, pin_repeat, pin_timeout): + repeat, timeout, pin_bin, pin_tool, pin_repeat, pin_timeout, + alloc_shim=None): """Direct/Callgrind measure plus the Pin inscount phase. The first phase runs the case natively (or under Callgrind when valgrind is installed) for correctness and wall/cpu time; the Pin - phase provides the deterministic instruction count. + phase provides the deterministic instruction count. With + --repeat 0 (pin-only) the first phase is skipped entirely -- no + native run, no valgrind -- correctness gates on the first Pin + run, and timed signals stay None. Returns (summary|None, pin_skipped|None, error|None). """ - summary, err = measure_case_callgrind( - has_valgrind, script, case_name, inp, outp, repeat, timeout) - if err is not None or pin_repeat <= 0: - return summary, None, err - pin_summary, pin_skipped, pin_err = measure_case_pin( + if repeat > 0: + summary, err = measure_case_callgrind( + has_valgrind, script, case_name, inp, outp, repeat, timeout) + if err is not None or pin_repeat <= 0: + return summary, None, err + else: + summary = { + "instructions": None, + "wall_s": None, + "cpu_s": None, + "maxrss_kb": None, + "runs": 0, + } + signals, pin_skipped, pin_err = measure_case_pin( [sys.executable, script], label, case_name, inp, outp, - pin_bin, pin_tool, pin_repeat, pin_timeout) + pin_bin, pin_tool, pin_repeat, pin_timeout, alloc_shim) if pin_err is not None: return None, None, pin_err - if pin_summary is not None: - summary["pin_instructions"] = pin_summary + if signals is not None: + summary.update(signals) return summary, pin_skipped, None @@ -356,7 +468,10 @@ def build_bmf(results): has_instructions = False total_pin = 0 has_pin = False + total_alloc = 0 + has_alloc = False total_cpu = 0.0 + has_cpu = False for it in items: s = it.get("summary") @@ -368,16 +483,29 @@ def build_bmf(results): if s.get("pin_instructions") and s["pin_instructions"]["median"] is not None: total_pin += int(s["pin_instructions"]["median"]) has_pin = True + if s.get("allocated_bytes") and s["allocated_bytes"]["median"] is not None: + total_alloc += int(s["allocated_bytes"]["median"]) + has_alloc = True if s.get("cpu_s") and s["cpu_s"]["median"] is not None: total_cpu += float(s["cpu_s"]["median"]) + has_cpu = True measures = {} if has_instructions: measures["instructions"] = {"value": total_instructions} if has_pin: measures["pin_instructions"] = {"value": total_pin} - measures["cpu_time"] = {"value": total_cpu} - + if has_alloc: + measures["allocated_bytes"] = {"value": total_alloc} + # Pin-only summaries have no timed phase: no cpu_time row at + # all, never a zero one. + if has_cpu: + measures["cpu_time"] = {"value": total_cpu} + + # A snippet whose cases all pin-skipped in pin-only mode has + # no signal to track; leaving it out beats an empty entry. + if not measures: + continue bmf[name] = measures return bmf @@ -413,15 +541,18 @@ def append_summary(path, report, bmf): lines = [ "### Instrumentation Performance Summary (Python)", "", - "| Benchmark | Cases | Pin Instr | Callgrind Ir | CPU Time (s) |", - "| :--- | :---: | :---: | :---: | :---: |", + "| Benchmark | Cases | Pin Instr | Allocated (B) | Callgrind Ir | CPU Time (s) |", + "| :--- | :---: | :---: | :---: | :---: | :---: |", ] total_insn = 0 total_pin = 0 + total_alloc = 0 total_cpu = 0.0 has_insn = False has_pin = False + has_alloc = False + has_cpu = False snippets = {} for r in report.get("results", []): @@ -436,19 +567,31 @@ def append_summary(path, report, bmf): pin_str = f"{val:,}" total_pin += val has_pin = True + alloc_str = "-" + if "allocated_bytes" in m: + val = m["allocated_bytes"]["value"] + alloc_str = f"{val:,}" + total_alloc += val + has_alloc = True insn_str = "-" if "instructions" in m: val = m["instructions"]["value"] insn_str = f"{val:,}" total_insn += val has_insn = True - cpu_val = m.get("cpu_time", {}).get("value", 0.0) - total_cpu += cpu_val - lines.append(f"| `{name}` | {cases_count} | {pin_str} | {insn_str} | {cpu_val:.4f} |") + cpu_str = "-" + if "cpu_time" in m: + cpu_val = m["cpu_time"]["value"] + cpu_str = f"{cpu_val:.4f}" + total_cpu += cpu_val + has_cpu = True + lines.append(f"| `{name}` | {cases_count} | {pin_str} | {alloc_str} | {insn_str} | {cpu_str} |") tot_pin_str = f"{total_pin:,}" if has_pin else "-" + tot_alloc_str = f"{total_alloc:,}" if has_alloc else "-" tot_insn_str = f"{total_insn:,}" if has_insn else "-" - lines.append(f"| **Total ({len(snippets)} snippets)** | - | **{tot_pin_str}** | **{tot_insn_str}** | **{total_cpu:.4f}** |") + tot_cpu_str = f"{total_cpu:.4f}" if has_cpu else "-" + lines.append(f"| **Total ({len(snippets)} snippets)** | - | **{tot_pin_str}** | **{tot_alloc_str}** | **{tot_insn_str}** | **{tot_cpu_str}** |") lines.append("") with open(path, "a") as f: @@ -476,6 +619,24 @@ def self_test(): raise AssertionError(f"parse_pin_count must reject {bad!r}") assert not pin_usable("", "") assert not pin_usable("/nonexistent/pin", "/nonexistent/tool.so") + + # Alloc-shim totals: last valid marker wins, malformed marker + # lines are skipped (stderr is shared with the app). + assert parse_alloc_total("hi\nsnip_alloc_total_bytes=123\n") == 123 + assert parse_alloc_total( + "snip_alloc_total_bytes=1\nsnip_alloc_total_bytes=42\n") == 42 + assert parse_alloc_total( + "snip_alloc_total_bytes=oops\nsnip_alloc_total_bytes=7\n") == 7 + for bad in ("", "no marker here\n", "snip_alloc_total_bytes=\n", + "snip_alloc_total_bytes=-1\n", "snip_alloc_total_bytes=1.5\n", + "snip_alloc_total_bytes=oops\n"): + try: + parse_alloc_total(bad) + except ValueError: + pass + else: + raise AssertionError(f"parse_alloc_total must reject {bad!r}") + assert is_pin_timeout("TIMEOUT (>900s)") for other in ("", "exit 1: boom", "pin output unreadable: x", "pin count unreadable: x"): @@ -538,6 +699,75 @@ def self_test(): assert "instructions" not in bmf_pin["math/gcd"] assert bmf_pin["math/gcd"]["pin_instructions"]["value"] == 9000 + # Pin-only shape (--repeat 0): no timed phase, so no cpu_time + # row at all (never a zero one); allocated_bytes sits next to + # pin_instructions; an all-skipped snippet stays out of BMF. + pin_only_nocpu = [ + { + "label": "math/gcd", + "case": "tc0", + "summary": { + "instructions": None, + "pin_instructions": {"median": 9000}, + "allocated_bytes": {"median": 4096}, + "cpu_s": None, + "runs": 0, + }, + }, + ] + bmf_nocpu = build_bmf(pin_only_nocpu) + assert "cpu_time" not in bmf_nocpu["math/gcd"] + assert "instructions" not in bmf_nocpu["math/gcd"] + assert bmf_nocpu["math/gcd"]["pin_instructions"]["value"] == 9000 + assert bmf_nocpu["math/gcd"]["allocated_bytes"]["value"] == 4096 + assert build_bmf([ + {"label": "math/gcd", "case": "tc0", + "summary": {"instructions": None, "cpu_s": None, "runs": 0}}, + ]) == {} + + # Summary render: pin-only rows show "-" for CPU and the + # Allocated column; timed rows still show the cpu value. + fd_temp, tmppath = tempfile.mkstemp(prefix="snip-sum-", suffix=".md") + os.close(fd_temp) + try: + append_summary(tmppath, {"results": pin_only_nocpu}, bmf_nocpu) + with open(tmppath) as fd: + pin_text = fd.read() + finally: + os.unlink(tmppath) + assert "Allocated (B)" in pin_text + assert "| `math/gcd` | 1 | 9,000 | 4,096 | - | - |" in pin_text, pin_text + fd_temp, tmppath = tempfile.mkstemp(prefix="snip-sum-", suffix=".md") + os.close(fd_temp) + try: + append_summary(tmppath, {"results": mock_results}, bmf) + with open(tmppath) as fd: + timed_text = fd.read() + finally: + os.unlink(tmppath) + assert "| `sort/merge_sort` | 2 | 12,000 | - | 3,000 | 0.1000 |" in timed_text, timed_text + + # Alloc-shim build + smoke (Linux only: LD_PRELOAD interposition + # has no macOS equivalent). + if sys.platform.startswith("linux"): + shim = ensure_alloc_shim() + assert os.path.isfile(shim), shim + env = dict(os.environ) + prev = env.get("LD_PRELOAD") + env["LD_PRELOAD"] = shim if not prev else shim + ":" + prev + proc = subprocess.run( + [sys.executable, "-c", "print('hi')"], + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + timeout=60, + env=env, + ) + assert proc.returncode == 0, proc.stderr.decode(errors="ignore") + total = parse_alloc_total(proc.stderr.decode(errors="ignore")) + assert total > 0, total + else: + print("(skipping alloc-shim build test: needs Linux)") + print("self-test passed!") return 0 @@ -569,6 +799,8 @@ def main(argv=None): parser.error("--pin-repeat must be >= 1") if args.pin_timeout < 1: parser.error("--pin-timeout must be >= 1") + if args.repeat < 0: + parser.error("--repeat must be >= 0") if args.self_test: return self_test() @@ -587,15 +819,24 @@ def main(argv=None): return 0 has_valgrind = shutil.which("valgrind") is not None - if not has_valgrind: + if not has_valgrind and args.repeat > 0: print("warning: valgrind not found in PATH; running Python directly without Callgrind simulation", file=sys.stderr) use_pin = args.pin and pin_usable(args.pin_bin, args.pin_tool) if args.pin and not use_pin: print("warning: pin unavailable (need --pin-bin launcher and --pin-tool inscount .so); pin_instructions will be null", file=sys.stderr) + if args.repeat == 0 and not use_pin: + parser.error("--repeat 0 skips the timed phase, so it needs --pin (pin-only mode)") pin_ver = pin_version(args.pin_bin) if use_pin else None effective_pin_repeat = args.pin_repeat if use_pin else 0 + alloc_shim = None + if use_pin: + try: + alloc_shim = ensure_alloc_shim() + except RuntimeError as exc: + print("warning: alloc shim unavailable ({}); allocated_bytes will be null".format(exc), file=sys.stderr) + tasks = [] missing = [] for area, problem, stem, script, cases in run_tests.discover(args.resources): @@ -642,6 +883,7 @@ def main(argv=None): args.pin_tool, effective_pin_repeat, args.pin_timeout, + alloc_shim, ): (label, stem, script, case_name) for label, stem, script, case_name, inp, outp in tasks } @@ -654,6 +896,9 @@ def main(argv=None): if summary.get("pin_instructions"): pin_med = summary["pin_instructions"]["median"] parts.append(f"{int(pin_med):,} Pin") + if summary.get("allocated_bytes"): + alloc_med = summary["allocated_bytes"]["median"] + parts.append(f"{int(alloc_med):,}B alloc") elif pin_skipped: parts.append(f"pin skipped: {pin_skipped}") insn = summary["instructions"]["median"] if summary.get("instructions") else None @@ -680,6 +925,7 @@ def main(argv=None): "has_valgrind": has_valgrind, "pin_used": use_pin, "pin_version": pin_ver, + "alloc_shim_used": alloc_shim is not None, "results": results, "failures": failures, } From 3bdc7a8d5be11b216e009bc871a909ac2e50f898 Mon Sep 17 00:00:00 2001 From: Hao Hu Date: Thu, 5 Nov 2026 12:09:38 +0100 Subject: [PATCH 5/5] ci: switch perf-instrumentation to the pin-only sweep Measure step runs --repeat 0 (no native timed phase, no --timeout); each case measured once under Pin with the alloc shim in the same run. setup-instrumentation.sh fails fast when allocshim.c is missing. --- .github/workflows/test.yml | 18 +++++++++++------- scripts/ci/setup-instrumentation.sh | 3 +++ 2 files changed, 14 insertions(+), 7 deletions(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 4ff5fd1..bb1ecd6 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -105,15 +105,19 @@ jobs: - name: Provision instrumentation (Pin 4.4) run: bash scripts/ci/setup-instrumentation.sh - - name: Measure performance (Pin instructions) - # Pin budget 600/repeat: the heaviest cases (edit_distance) - # run minutes under instrumentation with --jobs 2; the - # native first phase stays on the same 600s ceiling. Pin - # timeouts degrade to pin-skipped (native data stays valid); - # genuine hangs still fail via the native phase. + - name: Measure performance (Pin-only sweep) + # Pin-only sweep: --repeat 0 skips the native timed phase, so + # each case is measured ONCE under Pin (inscount) with the + # LD_PRELOAD alloc shim in the same run; correctness gates on + # the instrumented run's stdout. Pin budget 600/repeat: the + # heaviest cases (edit_distance) run minutes under + # instrumentation with --jobs 2. Pin timeouts degrade to + # pin-skipped (skipped cases contribute no BMF rows in this + # mode); genuine hangs still fail in the test-shard jobs, + # which run natively with --timeout 300. run: | python3 tools/measure.py --resources tests/resources \ - --repeat 1 --jobs 2 --timeout 600 \ + --repeat 0 --jobs 2 \ --pin --pin-bin "$INSTRUMENTATION_BIN" \ --pin-tool "$INSTRUMENTATION_TOOL" \ --pin-repeat 2 --pin-timeout 600 \ diff --git a/scripts/ci/setup-instrumentation.sh b/scripts/ci/setup-instrumentation.sh index 8748ab9..79042c3 100755 --- a/scripts/ci/setup-instrumentation.sh +++ b/scripts/ci/setup-instrumentation.sh @@ -7,6 +7,8 @@ # re-exports the paths. Otherwise it downloads the kit from # Intel, verifies its sha256, extracts it, and builds # scripts/ci/instrumentation/inscount.cpp against it. +# tools/measure.py builds scripts/ci/instrumentation/allocshim.c on +# demand with cc at sweep time (present on ubuntu-latest runners). # # Outputs (stdout for logs, $GITHUB_ENV when present): # INSTRUMENTATION_BIN absolute path to the pin launcher @@ -35,6 +37,7 @@ if need_tool; then command -v g++ >/dev/null || { err "g++ is required to build the inscount tool"; exit 1; } command -v curl >/dev/null || { err "curl is required to fetch the Pin kit"; exit 1; } [ -f "$TOOL_SRC/inscount.cpp" ] || { err "tool sources missing at $TOOL_SRC"; exit 1; } + [ -f "$TOOL_SRC/allocshim.c" ] || { err "alloc-shim source missing at $TOOL_SRC"; exit 1; } mkdir -p "$INSTRUMENTATION_DIR" if [ ! -x "$INSTRUMENTATION_BIN" ]; then err "downloading Pin 4.4 kit..."