gitdan-actions/scripts/restore-mtimes-selftest.sh

#!/usr/bin/env bash
# Regression test for restore-mtimes.sh's per-target-dir watermark (issue
# The merge hazard: a branch that merges an older commit could silently reuse a stale
# build artifact and fail with an "impossible" compile error). Builds a
# minimal, throwaway two-crate cargo workspace in a scratch git repo whose
# history is shaped exactly like the real incident, then runs the ACTUAL
# `restore-mtimes.sh` sitting next to this file against it under real
# `cargo build` — not a simulation of the logic, the real script and a real
# compiler. Every scenario ends in a hard assertion; the first failure dumps
# the relevant log and exits non-zero, so a future change to restore-mtimes.sh
# or the actions' step order that reopens this hazard fails loudly here
# instead of surfacing weeks later as a confusing CI compile error.
#
# Run by hand:
#   bash .gitea/scripts/restore-mtimes-selftest.sh
#
# Slow by design — this builds a throwaway cargo workspace
# and runs several real compiler invocations (~1-2 minutes), which is too
# slow to pay on every ordinary push. Re-run it by hand whenever
# restore-mtimes.sh's timestamp logic or the actions' cache/seed/watermark step
# order changes.
#
# Needs a working `cargo`/`rustc` on PATH. Does not touch this repo or its
# own target dir — everything happens under a `mktemp -d` scratch tree,
# removed on exit via the trap below regardless of outcome.
#
# What each scenario demonstrates, and why the "control" runs matter as much
# as the "fixed" ones (a scenario that always passes proves nothing):
#
#   1. NO WATERMARK, same-branch merge (control) — a feature branch builds
#      once, then merges a commit that changed a dependency crate but was
#      authored earlier in real time than that build. With no watermark to
#      consult, restore-mtimes.sh falls back to its pre-watermark behaviour
#      (git-log-only timestamps): asserts this reproduces the exact bug —
#      the dependency crate is judged Fresh and reused stale, and the
#      dependent crate fails to compile against it.
#   2. WATERMARK PRESENT, same state (fix) — identical setup, but this
#      target dir's watermark names the pre-merge build. Asserts the
#      dependency crate is correctly identified as changed and recompiles,
#      and the build succeeds.
#   3. WATERMARK PRESENT, no further change (warm-path) — re-runs scenario
#      2's state with an up-to-date watermark and no new commits. Asserts
#      NOTHING recompiles — the ordinary no-merge case restore-mtimes.sh
#      exists for is unaffected by the watermark machinery.
#   4. SEEDED NAMESPACE, watermark stripped (control) — a brand-new branch
#      namespace, seeded from scenario
#      2/3's now-warm target dir, then merges a THIRD lineage's older commit.
#      With the inherited watermark file deliberately removed, asserts the
#      same staleness bug reproduces on a namespace that has never itself
#      run a build — proving the seed-snapshot path shares the hazard, not
#      just long-lived branches.
#   5. SEEDED NAMESPACE, watermark inherited (fix) — identical to 4, but the
#      watermark file rides along with the `cp -a` seed copy exactly as
#      the cargo-cache action's seed step really does it.
#      Asserts the dependency crate correctly recompiles on this namespace's
#      very first run.
#   6. TWO CONSUMERS, ONE SHARED WATERMARK FILE, sequential jobs (control) —
#      two jobs in one workflow can share a single per-ref
#      $CARGO_TARGET_DIR, so one cache holds two independent cargo profile
#      directories (say `debug/` built by a test job and `release/` built by a
#      wasm build job). Modelling this as "both jobs read before either
#      writes" is the wrong ordering: on a serial runner with no `needs:`
#      between the two jobs, one job's watermark WRITE lands before the other
#      job's own READ, within the same trigger. This scenario now runs restore-mtimes.sh TWICE IN
#      SEQUENCE against ONE shared watermark file, with a real watermark
#      write in between (job A builds debug/, succeeds, advances the shared
#      watermark to HEAD; job B then reads that JUST-ADVANCED watermark).
#      Asserts job A succeeds and job B reproduces the original bug —
#      an empty HEAD..HEAD diff, full fallback to git-log timestamps, stale
#      reuse in release/.
#   7. TWO CONSUMERS, TWO WATERMARK FILES, sequential jobs (fix) — identical
#      ordering, but each job reads and writes its OWN watermark file
#      (`CI_WATERMARK_FILE`), exactly as the cargo-cache action does. Job B's read is
#      unaffected by job A's write because they touch different files.
#      Asserts BOTH jobs correctly recompile the dependency and succeed.
set -euo pipefail

# Every assertion below reads cargo's own words out of a build log
# (`Compiling libdep`, `Fresh probe`). A CI image that forces colour splices an
# ANSI reset between the status word and the crate name, at which point every
# one of those greps silently stops matching and the suite reports the
# opposite of what happened — observed on gitdan-ci's runner image, where
# scenario 2 failed while the log it printed plainly showed `Compiling libdep`.
# Pin the format the assertions are written against.
export CARGO_TERM_COLOR=never

script_dir=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)
restore_mtimes="$script_dir/restore-mtimes.sh"

if [ ! -x "$restore_mtimes" ] && [ ! -f "$restore_mtimes" ]; then
  echo "restore-mtimes-selftest: expected to find restore-mtimes.sh at $restore_mtimes" >&2
  exit 1
fi

scratch=$(mktemp -d)
trap 'rm -rf "$scratch"' EXIT
repo="$scratch/wk"
target_feature="$scratch/target-feature"
target_newbranch="$scratch/target-newbranch"
target_multiprofile="$scratch/target-multiprofile"

pass_count=0

assert_log_has() {
  local file="$1" pattern="$2" desc="$3"
  if ! grep -q -- "$pattern" "$file"; then
    echo "ASSERTION FAILED: $desc" >&2
    echo "  expected to find: $pattern" >&2
    echo "  --- full log ($file) ---" >&2
    cat "$file" >&2
    exit 1
  fi
  pass_count=$((pass_count + 1))
  echo "PASS: $desc"
}

assert_log_lacks() {
  local file="$1" pattern="$2" desc="$3"
  if grep -q -- "$pattern" "$file"; then
    echo "ASSERTION FAILED: $desc" >&2
    echo "  expected NOT to find: $pattern" >&2
    echo "  --- full log ($file) ---" >&2
    cat "$file" >&2
    exit 1
  fi
  pass_count=$((pass_count + 1))
  echo "PASS: $desc"
}

# `actions/checkout` stamps every tracked file with wall-clock "now" on
# every run — simulate that before each restore-mtimes.sh pass, exactly as
# CI would see it, so this test exercises the script the same way CI does.
stamp_checkout_now() {
  find . -path ./.git -prune -o -type f -print0 | xargs -0 touch
}

echo "=== building scratch workspace ==="
mkdir -p "$repo/crates/libdep/src" "$repo/crates/libuser/src"
cd "$repo"
git init -q
git config user.email test@example.com
git config user.name "restore-mtimes-selftest"

cat > Cargo.toml <<'EOF'
[workspace]
resolver = "2"
members = ["crates/libdep", "crates/libuser"]
EOF
cat > crates/libdep/Cargo.toml <<'EOF'
[package]
name = "libdep"
version = "0.1.0"
edition = "2021"
EOF
cat > crates/libdep/src/lib.rs <<'EOF'
pub struct CheckIn;

impl CheckIn {
    pub fn new() -> Self {
        CheckIn
    }
}
EOF
cat > crates/libuser/Cargo.toml <<'EOF'
[package]
name = "libuser"
version = "0.1.0"
edition = "2021"

[dependencies]
libdep = { path = "../libdep" }
EOF
cat > crates/libuser/src/lib.rs <<'EOF'
pub fn make() -> libdep::CheckIn {
    libdep::CheckIn::new()
}
EOF
git add -A
GIT_AUTHOR_DATE="2023-01-01T00:00:00" GIT_COMMITTER_DATE="2023-01-01T00:00:00" \
  git commit -q -m "base: CheckIn::new only"
base_sha=$(git rev-parse HEAD)

# dev's own future: adds with_intensity_opt, with an OLD committer date —
# analogous to a PR merged into dev before this branch's own build.
git switch -q -c dev
cat > crates/libdep/src/lib.rs <<'EOF'
pub struct CheckIn;

impl CheckIn {
    pub fn new() -> Self {
        CheckIn
    }

    pub fn with_intensity_opt(&self) -> Self {
        CheckIn
    }
}
EOF
git add -A
GIT_AUTHOR_DATE="2023-06-01T01:02:51" GIT_COMMITTER_DATE="2023-06-01T01:02:51" \
  git commit -q -m "journal: add CheckIn::with_intensity_opt"
dev2_sha=$(git rev-parse HEAD)

# feature branch, forked BEFORE dev2 exists — does its own unrelated work,
# and gets its own real build (real wall-clock dep-info mtimes) before dev2
# is ever merged in.
git switch -q -c feature "$base_sha"
cat > crates/libuser/src/lib.rs <<'EOF'
pub fn make() -> libdep::CheckIn {
    libdep::CheckIn::new()
}

pub fn unrelated_feature_work() -> u32 {
    42
}
EOF
git add -A
git commit -q -m "feature: unrelated libuser work"
feat1_sha=$(git rev-parse HEAD)

echo "=== feature branch's own real build (real wall-clock artifact mtimes) ==="
CARGO_TARGET_DIR="$target_feature" cargo build --workspace --quiet
# Two pristine snapshots taken right after this one real build, before
# scenario 1's failed build attempt below partially rewrites fingerprints
# against it: one WITHOUT a watermark file (scenario 1's starting state) and
# one WITH (scenario 2's) — both need to restart from this same pre-merge
# baseline, not from whatever a failed build left behind, and scenario 1
# must never see a watermark or it isn't testing the control it claims to.
cp -a "$target_feature" "$target_feature.pristine-no-watermark"
echo "$feat1_sha" > "$target_feature/.ci-watermark-sha"
cp -a "$target_feature" "$target_feature.pristine-with-watermark"

# The commit below ("feature: use with_intensity_opt") gets a real "now"
# date — scenario 1 needs it to be unambiguously newer than the dep-info
# artifact just built above, in whole-second terms git commit timestamps
# use. This harness runs fast enough that, without a gap, the two could
# otherwise land in the same wall-clock second and make scenario 1 flaky.
# Real CI never runs this close together; this is purely a test-harness
# margin, matching the one before scenarios 4/5 below.
sleep 2

git merge -q dev -m "merge dev into feature"
cat > crates/libuser/src/lib.rs <<'EOF'
pub fn make() -> libdep::CheckIn {
    libdep::CheckIn::new().with_intensity_opt()
}

pub fn unrelated_feature_work() -> u32 {
    42
}
EOF
git add -A
git commit -q -m "feature: use with_intensity_opt"
feat2_sha=$(git rev-parse HEAD)

echo
echo "=== 1: NO WATERMARK, same-branch merge (control — expect the bug) ==="
rm -rf "$target_feature"
cp -a "$target_feature.pristine-no-watermark" "$target_feature"
stamp_checkout_now
CARGO_TARGET_DIR="$target_feature" bash "$restore_mtimes"
set +e
CARGO_TARGET_DIR="$target_feature" cargo build --workspace -v > "$scratch/run1.log" 2>&1
set -e
assert_log_has "$scratch/run1.log" "no method named .with_intensity_opt." \
  "scenario 1: absent watermark reproduces the stale-reuse compile error"

echo
echo "=== 2: WATERMARK PRESENT, same state (fix — expect success) ==="
rm -rf "$target_feature"
cp -a "$target_feature.pristine-with-watermark" "$target_feature"
stamp_checkout_now
CARGO_TARGET_DIR="$target_feature" bash "$restore_mtimes"
CARGO_TARGET_DIR="$target_feature" cargo build --workspace -v > "$scratch/run2.log" 2>&1
assert_log_lacks "$scratch/run2.log" "no method named" \
  "scenario 2: watermark present — build succeeds, no stale reuse"
assert_log_has "$scratch/run2.log" "Compiling libdep" \
  "scenario 2: libdep actually recompiled (not just Fresh-passthrough)"

echo
echo "=== 3: WATERMARK PRESENT, no further change (warm-path preserved) ==="
echo "$feat2_sha" > "$target_feature/.ci-watermark-sha"
stamp_checkout_now
CARGO_TARGET_DIR="$target_feature" bash "$restore_mtimes"
CARGO_TARGET_DIR="$target_feature" cargo build --workspace -v > "$scratch/run3.log" 2>&1
assert_log_lacks "$scratch/run3.log" "Compiling" \
  "scenario 3: unchanged re-run stays warm — nothing recompiles"

# Scenarios 4/5: a brand-new namespace seeded from feature's own (now warm)
# target dir, then merging a THIRD lineage's older change. `sleep` keeps the
# THIRD lineage's own "now"-dated commits a full second clear of the
# artifact just built above — git commit timestamps are whole-second, dep-info
# mtimes are nanosecond, and this harness runs fast enough that the two could
# otherwise land in the same second and make scenario 4's control flaky. Real
# CI never runs this close together; this is purely a test-harness margin.
sleep 2

git switch -q -c parallel2 "$dev2_sha"
cat > crates/libdep/src/lib.rs <<'EOF'
pub struct CheckIn;

impl CheckIn {
    pub fn new() -> Self {
        CheckIn
    }

    pub fn with_intensity_opt(&self) -> Self {
        CheckIn
    }

    pub fn with_note(&self) -> Self {
        CheckIn
    }
}
EOF
git add -A
GIT_AUTHOR_DATE="2023-07-15T09:00:00" GIT_COMMITTER_DATE="2023-07-15T09:00:00" \
  git commit -q -m "journal: add CheckIn::with_note"

# newbranch forks from feature at feat2_sha (scenario 2/3's fixed, warm
# state) and merges parallel2. Clean merge: newbranch already has dev2's
# with_intensity_opt via feature's earlier merge, parallel2 only adds
# with_note on top of that same ancestor.
git switch -q -c newbranch "$feat2_sha"
git merge -q parallel2 -m "merge parallel2 into newbranch"
sed -i 's/CheckIn::new()\.with_intensity_opt()/CheckIn::new().with_intensity_opt().with_note()/' \
  crates/libuser/src/lib.rs
git add -A
git commit -q -m "newbranch: use with_note too"

echo
echo "=== 4: SEEDED NAMESPACE, watermark stripped (control — expect the bug) ==="
rm -rf "$target_newbranch"
cp -a "$target_feature" "$target_newbranch"
rm -f "$target_newbranch/.ci-watermark-sha"
stamp_checkout_now
CARGO_TARGET_DIR="$target_newbranch" bash "$restore_mtimes"
set +e
CARGO_TARGET_DIR="$target_newbranch" cargo build --workspace -v > "$scratch/run4.log" 2>&1
set -e
assert_log_has "$scratch/run4.log" "no method named .with_note." \
  "scenario 4: a seeded namespace with no inherited watermark reproduces the same bug"

echo
echo "=== 5: SEEDED NAMESPACE, watermark inherited via cp -a (fix — expect success) ==="
rm -rf "$target_newbranch"
cp -a "$target_feature" "$target_newbranch"
stamp_checkout_now
CARGO_TARGET_DIR="$target_newbranch" bash "$restore_mtimes"
CARGO_TARGET_DIR="$target_newbranch" cargo build --workspace -v > "$scratch/run5.log" 2>&1
assert_log_lacks "$scratch/run5.log" "no method named" \
  "scenario 5: inherited watermark — build succeeds on the namespace's first run"
assert_log_has "$scratch/run5.log" "Compiling libdep" \
  "scenario 5: libdep actually recompiled on the seeded namespace"

# Scenarios 6/7: a second job in the same workflow can share the
# `ci` job's per-branch $CARGO_TARGET_DIR namespace — `debug/` (the `ci`
# job's fmt/clippy/test steps) and `release/` (the `web` job's
# build-web-opt) sit side by side in one directory. The FIRST version of
# these scenarios ran restore-mtimes.sh ONCE, then built both profiles
# against its single output — modelling "both jobs read before either
# writes". Review caught that this is the wrong ordering: on a serial
# runner with no `needs:` between the two jobs, one job's watermark WRITE
# can land before the other job's own READ, on the very same trigger. These
# scenarios now run restore-mtimes.sh TWICE IN SEQUENCE, with a watermark
# write in between — the real ordering — and scenario 6 is required to
# reproduce the bug against a single shared watermark file before scenario 7
# demonstrates the fix (one watermark file per consumer). `target_feature`
# is already warm and consistent at feat2_sha from scenarios 2/3 (debug/
# built, watermark=feat2_sha); build release/ against the same namespace too
# so both profile dirs start warm, exactly as they would after both real
# jobs have run once against a branch.
echo
echo "=== building the release profile too, so both profile dirs start warm ==="
CARGO_TARGET_DIR="$target_feature" cargo build --workspace --release --quiet
cp -a "$target_feature" "$scratch/mp-pristine-shared-watermark"
cp -a "$target_feature" "$scratch/mp-pristine-split-watermarks"
cp "$scratch/mp-pristine-split-watermarks/.ci-watermark-sha" \
   "$scratch/mp-pristine-split-watermarks/.ci-watermark-sha-wasm32"

# A third lineage, forked from dev2_sha (same shape as parallel2 above),
# adding a further method with an OLD committer date — analogous to a second,
# later dev commit that both real jobs would need to see as a real change.
sleep 2
git switch -q -c parallel3 "$dev2_sha"
cat > crates/libdep/src/lib.rs <<'EOF'
pub struct CheckIn;

impl CheckIn {
    pub fn new() -> Self {
        CheckIn
    }

    pub fn with_intensity_opt(&self) -> Self {
        CheckIn
    }

    pub fn with_flag(&self) -> Self {
        CheckIn
    }
}
EOF
git add -A
GIT_AUTHOR_DATE="2023-08-01T09:00:00" GIT_COMMITTER_DATE="2023-08-01T09:00:00" \
  git commit -q -m "journal: add CheckIn::with_flag"

# multiprofile forks from feat2_sha (feature's own fixed, warm point) and
# merges parallel3 — clean merge, same shape as newbranch/parallel2 above.
git switch -q -c multiprofile "$feat2_sha"
git merge -q parallel3 -m "merge parallel3 into multiprofile"
cat > crates/libuser/src/lib.rs <<'EOF'
pub fn make() -> libdep::CheckIn {
    libdep::CheckIn::new().with_intensity_opt().with_flag()
}

pub fn unrelated_feature_work() -> u32 {
    42
}
EOF
git add -A
git commit -q -m "multiprofile: use with_flag too"
mp_sha=$(git rev-parse HEAD)

echo
echo "=== 6: TWO CONSUMERS, ONE SHARED WATERMARK FILE, sequential jobs (control — expect the bug) ==="
# "Job A" (ci-equivalent, debug/ consumer) runs FIRST: its own checkout,
# its own restore-mtimes call, its own build, then its own watermark write —
# exactly the actions' real step order, just inlined here instead of split
# across two jobs.
rm -rf "$target_multiprofile"
cp -a "$scratch/mp-pristine-shared-watermark" "$target_multiprofile"
stamp_checkout_now
CARGO_TARGET_DIR="$target_multiprofile" bash "$restore_mtimes"
CARGO_TARGET_DIR="$target_multiprofile" cargo build --workspace -v > "$scratch/run6-debug.log" 2>&1
assert_log_lacks "$scratch/run6-debug.log" "no method named" \
  "scenario 6: job A (debug/, running first) builds cleanly off the true prior watermark"
assert_log_has "$scratch/run6-debug.log" "Compiling libdep" \
  "scenario 6: job A actually recompiled libdep in debug/"
echo "$mp_sha" > "$target_multiprofile/.ci-watermark-sha"

# "Job B" (web-equivalent, release/ consumer) runs SECOND, same trigger, same
# HEAD, same $CARGO_TARGET_DIR, no `needs:` between them — the real ordering
# review caught. Its own checkout (stamp_checkout_now again, faithfully
# modelling a separate checkout), then its own restore-mtimes call, which
# reads the SAME watermark file job A just advanced to mp_sha: HEAD..mp_sha
# is an empty diff, so the override never fires and every path falls back to
# its plain git-log timestamp — including the backdated libdep change.
stamp_checkout_now
CARGO_TARGET_DIR="$target_multiprofile" bash "$restore_mtimes"
set +e
CARGO_TARGET_DIR="$target_multiprofile" cargo build --workspace --release -v > "$scratch/run6-release.log" 2>&1
set -e
assert_log_has "$scratch/run6-release.log" "no method named .with_flag." \
  "scenario 6: job B (release/, running second) reads the watermark job A just advanced, gets an empty diff, and reproduces the original stale-reuse bug"

echo
echo "=== 7: TWO CONSUMERS, TWO WATERMARK FILES, sequential jobs (fix — expect success) ==="
# Same sequential ordering as scenario 6, but each job reads and writes its
# OWN watermark file (CI_WATERMARK_FILE), exactly as the cargo-cache action does.
rm -rf "$target_multiprofile"
cp -a "$scratch/mp-pristine-split-watermarks" "$target_multiprofile"
stamp_checkout_now
CARGO_TARGET_DIR="$target_multiprofile" bash "$restore_mtimes"
CARGO_TARGET_DIR="$target_multiprofile" cargo build --workspace -v > "$scratch/run7-debug.log" 2>&1
assert_log_lacks "$scratch/run7-debug.log" "no method named" \
  "scenario 7: job A (debug/) builds cleanly off its own watermark"
assert_log_has "$scratch/run7-debug.log" "Compiling libdep" \
  "scenario 7: job A actually recompiled libdep in debug/"
echo "$mp_sha" > "$target_multiprofile/.ci-watermark-sha"

# Job B reads ITS OWN file (.ci-watermark-sha-wasm32), untouched by job A's
# write above — still feat2_sha, so the diff against mp_sha is exactly the
# real change set, not empty.
stamp_checkout_now
CARGO_TARGET_DIR="$target_multiprofile" CI_WATERMARK_FILE=.ci-watermark-sha-wasm32 \
  bash "$restore_mtimes"
CARGO_TARGET_DIR="$target_multiprofile" cargo build --workspace --release -v > "$scratch/run7-release.log" 2>&1
assert_log_lacks "$scratch/run7-release.log" "no method named" \
  "scenario 7: job B (release/) builds cleanly off its OWN watermark, unaffected by job A's write"
assert_log_has "$scratch/run7-release.log" "Compiling libdep" \
  "scenario 7: job B actually recompiled libdep in release/"

echo
echo "ALL ${pass_count} ASSERTIONS PASSED"