Birdoggydog's Builds

Tracing a false alarm from two test suites sharing a folder

A guard reported one write outside the workspace that never happened. A second run had deleted the first run's logs, and an exit code was taken for a count.

My test suite has a guard that checks the game’s tests haven’t written anything to Godot’s real folders, which are the engine’s settings, saves and cache. After one merge it reported “1 entries outside the workspace were written” and didn’t list any. Nothing had been written. The guard had crashed, and the suite had taken the crash for a count of one.

What did the failed run say?

I’d run 35 tests by name from the main checkout. 34 passed and the guard failed. The evidence file had been overwritten by a later run, so I couldn’t see which entry or which test it was.

I had a lot of agents running at the time, and my first thought was that it was competition for resources. I didn’t want to fix anything on a guess that it was load, so I had the failure traced first.

The failed run’s output was still on disk. It said a note file was missing, then showed a Python traceback with a FileNotFoundError on the guard’s “before” listing, and then “1 entries” with an empty list. Godot’s three real folders had nothing written after the last time I’d played that day, and the folders’ timestamps matched that.

Why was the listing missing?

There were two suites running in one checkout. The first started at 22:08. A second one, started by another session at 22:19, used the same log folder.

The suite script used one folder per checkout and started by deleting it:

rm -rf "<tmp>/suite/<checkout name>/"

The guard runs twice. At the start it writes a listing of the real folders into that folder, and at the end it compares against it. So the second run’s start deleted the first run’s results and its “before” listing just as the first run was finishing. The guard had nothing to compare against and crashed. Python exits with code 1 for a traceback, and the suite printed “N entries outside the workspace were written” using the guard’s exit code as N.

A worktree’s suite has its own folder, because the folder is named for the checkout. Only two suites on the same checkout could collide.

The old layout could also hide a real write. If the second run had started a few seconds earlier, the first would have compared against the second run’s listing and passed anything written in its ten minutes.

Fixing the folder, the exit code and the evidence

I didn’t loosen the guard or add an exception to it. The fix has three parts.

Each run gets its own folder, named <day_time_pid> under the checkout’s folder, and a latest.txt there names the newest run. A new run never removes anything of another run’s. Each run’s folder also has a times.txt with every test’s start and end time.

A comparison that can’t be made is its own failure and not an entry. If the “before” listing is missing or unreadable, the guard prints a line starting USER FOLDER GUARD and exits with 250, and the suite reports user_folder_guard NO COMPARISON WAS MADE.

The suite doesn’t trust the exit code for the count anymore. It counts the entry lines the guard prints. The exit code for “entries found” is also capped at 200, because a count of 256 would have wrapped to 0 in a process exit code and looked clean. Each printed entry says when it was written, so I can match it against times.txt and see which test was running.

The newest six finished runs are kept and older ones are pruned. A run where the guard failed gets a file named KEEP and is never pruned, so the evidence is still there after the next run.

Checking the fix without touching the real folders

The trace was done by reading the failed run’s output, the second run’s transcript and the folders’ timestamps. I didn’t reproduce the original failure.

To check the fixes I used a stand-in for the real folders. The guard’s location for them can be overridden with an environment variable for exactly this. An entry written mid-run was reported as 2 entries with times, and the run was marked KEEP. Removing the listing mid-run gave NO COMPARISON WAS MADE, exit 250 and KEEP. Two suites started at once on one checkout both finished clean with a folder each. The guard’s self-test covers these cases and passes.

What’s left?

Two suites on one checkout still share that checkout’s Godot cache and one Godot home folder. Inside one suite, the tests that start an editor are held back to run alone, but nothing holds them apart across two suites. I haven’t seen it fail. If an editor test fails only when another suite was running, the two times.txt files will show it, and a lock per checkout would close it.