Mise task to probe go build cache behavior

cache-probe.sh

#!/usr/bin/env bash
#MISE description="Test harness to probe Go build-cache behaviour for the prebuild tasks"
#
# Why this exists
# ---------------
# The `prebuild` task warms the Go build cache so that CI's `gotest` and `dist`
# steps reuse compiled dependencies instead of rebuilding them.  Two phases were
# still slow despite the prebuild (first `go test` ~60s, darwin `dist` ~40s).
# The normal tasks rebuild everything and only print wall-clock totals, which is
# far too coarse to see *which* packages miss the cache and *why*.
#
# This harness gives fine-grained, repeatable visibility:
#   * each phase is wall-clock timed, and
#   * the number of real toolchain invocations (compile/asm/cgo/link/cc) is
#     counted by parsing `go ... -x` output.  A cached package emits no
#     `compile` line, so the compile count is an exact, machine-independent
#     measure of cache misses -- much more reliable than timing alone.
#
# Usage
# -----
#   mise run cache-probe <scenario> [args...]
#
# Scenarios (high level, run the full clean->precache->target flow):
#   gotest [precache-flags...]   Probe issue #1: warm deps then `go test`.
#                                Default precache flags: -race -cover
#   dist <goos> <goarch>         Probe issue #2: warm deps then a dist-style
#                                cross build (default darwin amd64).
#   matrix                       Build every target after one shared precache
#                                and report per-target compile/link counts.
#
# Low-level building blocks (compose your own experiments):
#   clean                        go clean -cache  (module cache untouched)
#   precache [flags...]          warm std+deps for $GOOS/$GOARCH (env-driven)
#   count -- <go command...>     run a go command with -x and report
#                                timing + tool-invocation counts
#
# Examples:
#   mise run cache-probe gotest                 # current prebuild flags
#   mise run cache-probe gotest -race           # drop -cover, compare
#   GOOS=darwin GOARCH=arm64 mise run cache-probe precache
#   mise run cache-probe dist darwin arm64
#   mise run cache-probe count -- go test -race -cover ./...
set -euo pipefail
# shellcheck source=/dev/null
source "$MISE_PROJECT_ROOT/.config/mise/lib.sh"
cd "$ROOT"

TOOLDIR="$(go env GOTOOLDIR)"

# ---------------------------------------------------------------------------
# run_counted LABEL -- CMD...
#
# Run a go command with `-x` appended, stream a live spinner-free copy of the
# build log to a temp file, and report:
#   * wall-clock seconds
#   * count of each toolchain program actually executed
#
# Cache hits skip the compiler entirely, so `compile=` is the cache-miss count.
# `-x` writes the executed commands to stderr; we capture that, not stdout. We
# inject -x via GOFLAGS rather than appending it, so it applies no matter how
# the command is shaped (env prefixes, `bash -c`, package args) -- `go build`
# rejects flags placed after the package path.
# ---------------------------------------------------------------------------
run_counted() {
	local label="$1"; shift
	[ "$1" = "--" ] && shift

	local log start end secs
	log="$(mktemp)"

	printf '\n=== %s ===\n' "$label"
	printf '    $ GOFLAGS=-x %s\n' "$*"

	start=$(date +%s.%N)
	# GOFLAGS=-x makes the toolchain print each sub-process it runs. Keep going
	# on failure so we still print the diagnostics that explain the failure.
	if ! GOFLAGS=-x "$@" >/dev/null 2>"$log"; then
		printf '    !! command failed (see counts below)\n'
	fi
	end=$(date +%s.%N)
	secs=$(awk -v a="$start" -v b="$end" 'BEGIN{printf "%.1f", b-a}')

	# Count toolchain invocations by matching the absolute tool path. Each line
	# in -x output that starts the tool path is exactly one invocation.
	local compile asm cgo link cc
	compile=$(grep -c "${TOOLDIR}/compile" "$log" || true)
	asm=$(grep -c "${TOOLDIR}/asm" "$log" || true)
	cgo=$(grep -c "${TOOLDIR}/cgo" "$log" || true)
	link=$(grep -c "${TOOLDIR}/link" "$log" || true)
	# External C compiler invocations (cgo / external linking). Matches the
	# common driver names regardless of absolute path.
	cc=$(grep -cE '(^|/)(cc|gcc|clang|g\+\+|clang\+\+) ' "$log" || true)

	printf '    time=%ss  compile=%s  asm=%s  cgo=%s  cc=%s  link=%s\n' \
		"$secs" "$compile" "$asm" "$cgo" "$link" "$cc"

	# When PROBE_NAMES=1, list the import paths that actually recompiled. Each
	# compile invocation carries `-p <importpath>`, so this is the exact set of
	# cache misses -- the single most useful signal for diagnosing why a warmed
	# cache wasn't reused. std packages show as e.g. `runtime`, deps as full
	# module paths.
	if [ "${PROBE_NAMES:-0}" = 1 ] && [ "$compile" -gt 0 ]; then
		printf '    recompiled packages (-p):\n'
		grep -oE "${TOOLDIR}/compile .* -p [^ ]+" "$log" |
			grep -oE -- '-p [^ ]+' | awk '{print $2}' | sort -u | sed 's/^/      /'
	fi

	# Leave the raw -x log on disk for ad-hoc digging (e.g. diffing compile
	# command lines between two phases to find a flag mismatch).
	printf '    (raw -x log: %s)\n' "$log"
}

# Clear only the build cache; leave the module download cache alone so we don't
# re-download the world between experiments (matches CI, where the module cache
# is part of the same restored bundle but rarely the bottleneck).
do_clean() {
	printf '=== clean build cache (GOCACHE=%s) ===\n' "$(go env GOCACHE)"
	go clean -cache
}

# Warm std + external deps for the current GOOS/GOARCH, forwarding any flags
# (e.g. -race -cover) to mirror exactly what prebuild does via xt_precache_deps.
do_precache() {
	local goos goarch
	goos="$(go env GOOS)"; goarch="$(go env GOARCH)"
	# shellcheck disable=SC2016  # $@/$pkgs must expand in the inner shell, not here
	run_counted "precache deps ${goos}/${goarch} [flags: $*]" -- \
		bash -c 'set -e
			go build "$@" std
			pkgs=$(go list -deps -f "{{if and .Module (not .Module.Main)}}{{.ImportPath}}{{end}}" ./... | grep . || true)
			echo "$pkgs" | xargs --no-run-if-empty go build "$@"' _ "$@"
}

# --- Scenario: issue #1, go test -------------------------------------------
scenario_gotest() {
	local flags=("$@")
	[ ${#flags[@]} -eq 0 ] && flags=(-race -cover)

	printf '########## SCENARIO gotest (precache flags: %s) ##########\n' "${flags[*]}"
	do_clean
	do_precache "${flags[@]}"

	# First real test run -- this is the one that was taking 60s+.
	run_counted "go test (1st run, the one CI pays for)" -- \
		go test -race -coverprofile="$DIST_DIR/cover.out" ./...

	# Second run should be fully cached; large compile counts on the *first*
	# run combined with ~0 here prove the precache simply built the wrong
	# variant rather than there being unavoidable work.
	run_counted "go test (2nd run, should be ~fully cached)" -- \
		go test -race -coverprofile="$DIST_DIR/cover.out" ./...
}

# --- Scenario: issue #2, dist cross build ----------------------------------
# Mirrors the real `dist` task: default buildmode (the fix), -ldflags -w.
# Set PROBE_BUILDMODE=exe to reproduce the original regression (forcing exe
# overrides darwin's pie default and busts the warmed cache).
scenario_dist() {
	local goos="${1:-darwin}" goarch="${2:-amd64}"
	local bm=(); [ -n "${PROBE_BUILDMODE:-}" ] && bm=(-buildmode "$PROBE_BUILDMODE")

	printf '########## SCENARIO dist %s/%s (buildmode: %s) ##########\n' \
		"$goos" "$goarch" "${PROBE_BUILDMODE:-default}"
	do_clean
	GOOS="$goos" GOARCH="$goarch" do_precache

	rm -rf "$DIST_DIR/probe-$goos-$goarch"
	mkdir -p "$DIST_DIR/probe-$goos-$goarch"
	run_counted "dist build ${goos}/${goarch} (1st, post-precache)" -- \
		env GOOS="$goos" GOARCH="$goarch" \
		go build -ldflags "-w" "${bm[@]}" \
		-o "$DIST_DIR/probe-$goos-$goarch/xtemplate" ./cmd

	run_counted "dist build ${goos}/${goarch} (2nd, should be cached)" -- \
		env GOOS="$goos" GOARCH="$goarch" \
		go build -ldflags "-w" "${bm[@]}" \
		-o "$DIST_DIR/probe-$goos-$goarch/xtemplate" ./cmd
}

# --- Scenario: full dist matrix after a single precache --------------------
scenario_matrix() {
	local bm=(); [ -n "${PROBE_BUILDMODE:-}" ] && bm=(-buildmode "$PROBE_BUILDMODE")

	printf '########## SCENARIO matrix (buildmode: %s) ##########\n' "${PROBE_BUILDMODE:-default}"
	do_clean
	for os in linux darwin windows; do
		for arch in amd64 arm64; do
			GOOS="$os" GOARCH="$arch" do_precache >/dev/null 2>&1 || true
		done
	done
	printf '\n--- precache done, now timing each dist build (deps warm) ---\n'
	local os arch out exe
	for os in linux darwin windows; do
		for arch in amd64 arm64; do
			out="$DIST_DIR/probe-$os-$arch"
			rm -rf "$out"; mkdir -p "$out"
			exe=xtemplate; [ "$os" = windows ] && exe=xtemplate.exe
			run_counted "dist ${os}/${arch}" -- \
				env GOOS="$os" GOARCH="$arch" \
				go build -ldflags "-w" "${bm[@]}" -o "$out/$exe" ./cmd
		done
	done
}

cmd="${1:-}"; shift || true
case "$cmd" in
	clean)    do_clean ;;
	precache) do_precache "$@" ;;
	count)    run_counted "count" "$@" ;;
	gotest)   scenario_gotest "$@" ;;
	dist)     scenario_dist "$@" ;;
	matrix)   scenario_matrix ;;
	*)
		echo "usage: mise run cache-probe <clean|precache|count|gotest|dist|matrix> [args...]" >&2
		echo "see the header of $0 for details" >&2
		exit 2 ;;
esac

Used to probe go module build caching behavior in https://github.com/infogulch/xtemplate