test: the execution_plan artifact-identity tests are racy on fast filesystems

[jamesbrink]

Summary

A cluster of ~5 tests in crates/mold-server/src/execution_plan.rs fails non-deterministically on a fast local machine while passing in CI. The failing subset varies run to run — I have observed 2, 3, 4, and 5 failures from the same cluster within a single session, with no source change between runs:

• cache_miss_identity_changes_when_artifact_metadata_changes
• same_size_in_place_overwrite_changes_equivalence_content_identity
• same_size_in_place_overwrite_with_restored_mtime_changes_content_identity
• frozen_chain_model_uses_canonical_companions_and_ignores_changed_config

Root cause

artifact_metadata_identity derives identity from path + size + mtime. The fixtures overwrite a file with different content of identical size:

std::fs::write(&path, b"aaaa").unwrap();
let first_metadata = artifact_metadata_identity(&path, &path.metadata().unwrap());
// ...
std::fs::write(&path, b"bbbb").unwrap();
let second_metadata = artifact_metadata_identity(&path, &path.metadata().unwrap());
assert_ne!(
    first_metadata, second_metadata,
    "fixture must observe a new metadata identity"
);

Size is unchanged by construction, so the assertion rests entirely on the two writes landing in different filesystem mtime ticks. When they land in the same tick the identities are equal and the fixture's own precondition fails — before the test reaches the behaviour it means to check.

This is why it fails more on a fast machine: the two writes complete closer together. CI's slower runners and filesystem separate them, which is why main is green.

Why it matters beyond flakiness

The failing set drifts with machine load, so a local cargo test --workspace cannot distinguish "my change broke something" from "the box was busy". Every contributor running the documented CI-equivalent gate has to hold a mental list of which failures to ignore, and that list is not even stable. During recent LTX-2 milestone work this cost real time on several PRs, each time re-deriving that the failures were unrelated.

Suggested fix

Make the fixture control the clock instead of racing it — force a distinct mtime rather than hoping for one:

filetime::set_file_mtime(&path, FileTime::from_unix_time(t + 1, 0))?;

filetime is already in the dependency graph. Alternatively, assert on the content identity these tests actually care about and drop the metadata-identity precondition, which is an implementation detail of the cache rather than the property under test.

Either way the tests then verify the intended invariant deterministically, on any filesystem.

Reproduction

unshare -Urm --map-root-user sh -c 'mount -t tmpfs none /mnt; \
  env -u MOLD_HOME -u MOLD_MODELS_DIR cargo test -p mold-ai-server --lib execution_plan:: 2>&1' \
  | grep -E "^test .*FAILED|^test result"

Run it a few times under varying load; the failing subset changes.

[jamesbrink]

The cluster is wider than the four execution_plan tests named above. Two more fail under parallel load on this machine and pass cleanly in isolation:

• batch_transaction::tests::deleting_one_of_ten_thousand_authority_entries_hashes_no_unrelated_media
• scheduler::tests::rejected_v2_post_upscale_preserves_f0_and_ignores_late_completion

These look like a different root cause from the mtime race, and probably from each other:

deleting_one_of_ten_thousand... takes 36.4 s on its own on an i9-13900K. That is slow enough that it is plausibly tripping a duration budget rather than a correctness assertion once the machine is busy — worth checking whether it asserts on elapsed time or on a work-avoidance counter that a loaded scheduler perturbs. If it is a wall-clock bound, ten thousand entries is buying very little that a hundred would not, and the runtime is itself a cost on every CI run.

rejected_v2_post_upscale_preserves_f0_and_ignores_late_completion runs in 0.20 s alone, so it is not slow — it is a "late completion" ordering test, and its name suggests it depends on a particular interleaving that heavy load reorders.

Reproduced today while running four concurrent cargo builds on the same box. The whole set is what makes a local cargo test --workspace unusable as a signal: the failing subset moved between 2, 3, 4, and 5 across runs of unmodified code.

Whoever picks this up: please treat the mtime race as the primary fix and triage these two separately rather than folding them into the same change — they almost certainly need different remedies, and pinning the clock will not help either one.

[jamesbrink]

Correcting my own diagnosis above, since it would send the next person down a dead end.

I wrote that identity is "path + size + mtime" and proposed filetime::set_file_mtime. That is wrong. artifact_metadata_identity does not consult mtime at all:

platform_identity: vec![
    metadata.dev(),
    metadata.ino(),
    metadata.ctime() as u64,
    metadata.ctime_nsec() as u64,
],

A same-size in-place rewrite preserves len, dev, and ino, so the only varying signal is ctime — and set_file_mtime bumps ctime to "now", which is precisely the value that collides. The suggested fix could not have worked.

#682 has the correct mechanism, measured rather than assumed: ~98 ms ctime granularity on ext4 here, and 1635/2000 collisions running the fixtures' exact write cycle. It also found a fifth site I missed (scheduler::config_artifact_change_after_plan_transports_only_the_replanned_fingerprint) and established that batch_transaction was a false positive with a different root cause entirely — a process-wide AUTHORITY_HASH_COUNT atomic being read across cargo test's shared-process threads.

Leaving my original comment in place rather than editing it, so the correction is legible.

[jamesbrink]

Independently verified on merged main (530622d2), not on the PR branch — a probabilistic failure is the one case where the author's own evidence is least sufficient.

Three consecutive full mold-ai-server runs:

Run	Result
1	ok. 1248 passed; 0 failed (91.33s)
2	ok. 1248 passed; 0 failed (80.91s)
3	ok. 1248 passed; 0 failed (77.73s)

Run under load average 106 on a 32-thread box — four concurrent agents plus builds. That matters: heavy load is precisely the condition that used to produce the 2/3/4/5 failure drift, so this is a test under the adverse case rather than a quiet one.

Also confirming the two extra tests I flagged earlier in this thread are clean here: batch_transaction::deleting_one_of_ten_thousand_authority_entries_hashes_no_unrelated_media and scheduler::rejected_v2_post_upscale_preserves_f0_and_ignores_late_completion both passed in all three runs. #682's thread-local AUTHORITY_HASH_COUNT change covers the first; the second appears to have been collateral from the same contention.

Net effect for contributors: cargo test --workspace is a trustworthy signal again. Until now a clean run and a four-failure run carried the same information, which is how the #672 hang stayed hidden — a suite nobody trusted was a suite nobody read.