Intermittent bot failures due EM_CACHE_IS_LOCKED building ports with libsdl2-ttf

[sbc100]

These failures seem to occur when building libsdl2-ttf, and have been seen on both mac and windows builders:

For example:

https://ci.chromium.org/ui/p/emscripten-releases/builders/try/win/b8678860304918941313/overview

The common pattern seems to be the occurrence of cache:INFO: deleting cached file: ... libSDL2.a in the log file, which logically should never happen during test_other.py.

The cause looks to me some kind of race condition that occurs when multiple tests all try to build libSDL2. In this case it seems like we end up calling Post.clear_project_build .. which causes the library built by another process to be deleted.

Our locking mechanism for the cache is not designed to be robust gainst library being deleted by an out side process, and this can break the assertion in the ports build that all deps have been built before we build a given port.

[sbc100]

I think the fix we need to make here is to add / wider our locking such as that so matter many many concurrent processes try to build a given library only one will end up building it and none of them will call Post.clear_project_build.

[sbc100]

AI generated root analysis:

Summary of the Root Cause

The bug is indeed caused by Ports.fetch_port_artifact returning False in one of the parallel processes, which triggers clear_project_build
and deletes the library ( libSDL2.a ) that another process has just built.

Here is the high-level sequence that leads to the failure:

1. Process A starts building sdl2_ttf . It successfully unpacks sdl2 (writing the .emscripten_url marker) and builds libSDL2.a .
2. Process A proceeds to build sdl2_ttf and holds the cache lock. It spawns a child emcc to compile SDL_ttf.c . This child inherits the
   EM_CACHE_IS_LOCKED=1 environment variable.
3. Process B (running in parallel) acquires the lock after Process A releases it momentarily. It checks if sdl2 is up-to-date.
4. The Race: If up_to_date('sdl2') in Process B returns False (which can happen due to filesystem latency in reflecting the marker file written
   by Process A, especially on macOS/Windows), Process B thinks the port is invalid.
5. The Destruction: Process B calls clear_project_build('sdl2') , which deletes libSDL2.a from the cache.
6. The Collision: Process A's child emcc (compiling SDL_ttf.c ) needs sdl2 . It sees libSDL2.a is missing and tries to rebuild it.
7. The Crash: The child emcc calls cache.get , which tries to lock the cache. Since it has EM_CACHE_IS_LOCKED=1 in its environment, it fails
   the assertion and exits with the EM_CACHE_IS_LOCKED error.

This explains why the bug is intermittent and why it has primarily been seen on macOS and Windows, where filesystem metadata updates can have more
latency than on Linux.

[sbc100]

This just showed up on the linux CI https://logs.chromium.org/logs/emscripten-releases/buildbucket/cr-buildbucket/8678253928542712369/+/u/Emscripten_testsuite__other_/stdout

cache:INFO: deleting cached file: /b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libharfbuzz.a
cache:INFO: generating port: sysroot/lib/wasm32-emscripten/libharfbuzz.a... (this will be cached in "/b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libharfbuzz.a" for subsequent builds)
wasm-ld: error: cannot open /b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libharfbuzz.a: No such file or directory
emcc: error: '/b/s/w/ir/x/w/install/bin/wasm-ld -o a.out.wasm /b/s/w/ir/x/t/emtest_t0uxqmot/tmpcdridmqqlibemscripten_js_symbols.so -Bstatic --strip-debug --export=emscripten_stack_get_end --export=emscripten_stack_get_free --export=emscripten_stack_get_base --export=emscripten_stack_get_current --export=emscripten_stack_init --export=_emscripten_stack_alloc --export=__wasm_call_ctors --export=_emscripten_stack_restore --export-if-defined=__start_em_asm --export-if-defined=__stop_em_asm --export-if-defined=__start_em_lib_deps --export-if-defined=__stop_em_lib_deps --export-if-defined=__start_em_js --export-if-defined=__stop_em_js --export-if-defined=main --export-if-defined=__main_argc_argv --export-if-defined=fflush --export-table -z stack-size=65536 --no-growable-memory --initial-heap=16777216 --no-entry --stack-first --table-base=1 /b/s/w/ir/x/t/emtest_t0uxqmot/emscripten_temp_k3hokhil/test_sdl2_ttf.o -L/b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten -L/b/s/w/ir/x/w/install/emscripten/src/lib /b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libSDL2_ttf.a /b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libharfbuzz.a /b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libSDL2.a /b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libfreetype.a /b/s/w/ir/x/w/install/emscripten/cache/sysroot/lib/wasm32-emscripten/libz.a -lGL-getprocaddr -lal -lhtml5 -lstubs-debug -lnoexit -lc-debug -ldlmalloc-debug -lclang_rt.builtins -lsockets -mllvm -combiner-global-alias-analysis=false -mllvm -enable-emscripten-sjlj -mllvm -disable-lsr' failed (returned 1)
None
None
[533/1647] test_sdl2_ttf (test_other.other.test_sdl2_ttf) ... FAIL

I think anther test is doing deleting cached file while test_sdl2_ttf` is running.

So we know it is reproducible on linux