Cache eviction hangs action evaluation with remote execution

[hoj-stripe]

Description of the bug:

Setup:

• Ten targets with one output file each (“prerequisite targets”).
• One target that takes each of the ten prerequisite targets as input (“final target”).
• Remote cache, and some value for --remote_executor flag.

Reproduction:

1. Build the prerequisite targets in output base A.
2. Delete all CAS entries from the remote cache.
   a. Do not delete any AC entries. These AC entries are now invalid.
   b. At this point, FindMissingBlobs will return all CAS entries as missing.
3. Build the final target in output base B.

In this scenario, we made all the AC entries invalid before the GetActionResult RPC returned them as found. However, in practice, the entry could become invalid immediately after the GetActionResult RPC returns. That’s just difficult to actually simulate.

Expected behavior:

Bazel crashes with exit code 39 since the AC entries for the prerequisite targets are invalid.
Expected logs, as shown when less than 8 input files were missing:

Starting local Bazel server and connecting to it...
INFO: Invocation ID: f64ad5ff-8ce6-4530-a346-3d034b8e3185
INFO: Analyzed target //:less_than_eight_files (5 packages loaded, 19 targets configured).
[1 / 1] checking cached actions
ERROR: /pay/src/cache-eviction-hang/BUILD:11:8: Executing genrule //:less_than_eight_files failed: (Exit 34): 6 errors during bulk transfer:
com.google.devtools.build.lib.remote.common.CacheNotFoundException: Missing digest: 1121cfccd5913f0a63fec40a6ffd44ea64f9dc135c66634ba001d10bcf4302a2/2 for bazel-out/k8-opt/bin/file_3
com.google.devtools.build.lib.remote.common.CacheNotFoundException: Missing digest: 7de1555df0c2700329e815b93b32c571c3ea54dc967b89e81ab73b9972b72d1d/2 for bazel-out/k8-opt/bin/file_4
com.google.devtools.build.lib.remote.common.CacheNotFoundException: Missing digest: 53c234e5e8472b6ac51c1ae1cab3fe06fad053beb8ebfd8977b010655bfdd3c3/2 for bazel-out/k8-opt/bin/file_2
com.google.devtools.build.lib.remote.common.CacheNotFoundException: Missing digest: f0b5c2c2211c8d67ed15e75e656c7862d086e9245420892a7de62cd9ec582a06/2 for bazel-out/k8-opt/bin/file_5
com.google.devtools.build.lib.remote.common.CacheNotFoundException: Missing digest: 9a271f2a916b0b6ee6cecb2426f0b3206ef074578be55d9bc94f6f3fe3ab86aa/2 for bazel-out/k8-opt/bin/file_0
com.google.devtools.build.lib.remote.common.CacheNotFoundException: Missing digest: 4355a46b19d348dc2f57c046f8ef63d4538ebb936000f3c9ee954a27460dd865/2 for bazel-out/k8-opt/bin/file_1
Target //:less_than_eight_files failed to build
Use --verbose_failures to see the command lines of failed build steps.
INFO: Elapsed time: 3.388s, Critical Path: 0.30s
INFO: 8 processes: 6 remote cache hit, 2 internal.
ERROR: Build did NOT complete successfully
Bazel exited with 39

Actual behavior:

Logs from step 3 indicate both hang, one on download which times out, another afterwards:

Starting local Bazel server and connecting to it...
INFO: Invocation ID: d1c93586-627e-48ed-a7d8-a20e46b5de11
INFO: Analyzed target //:all_files (5 packages loaded, 27 targets configured).
[1 / 1] checking cached actions
[11 / 12] Executing genrule //:all_files; Downloading file_5; 59s remote
ERROR: /pay/src/cache-eviction-hang/BUILD:3:8: Executing genrule //:all_files failed: (Exit 34): Timed out when waiting for uploads
Target //:all_files failed to build
Use --verbose_failures to see the command lines of failed build steps.
INFO: Elapsed time: 63.271s, Critical Path: 60.10s
INFO: 12 processes: 10 remote cache hit, 2 internal.
ERROR: Build did NOT complete successfully

<hangs indefinitely>

Investigation:

The second hang after the build failure looks very similar to #21626, and we were able to prevent the hang by disabling AsyncTaskCache. However, when Bazel exits with timeout we don’t get the exit code 39, and we also don’t think Bazel should be timing out on input uploads.

The download happens when uploadBlob() tries to set its input from a remote file. That contains a ByteStream/Read operation, in this case to a nonexistent blob, which eventually gets executed when the uploader tries to read from the Chunker. When ByteStream/Read returns an RPC error, Bazel doesn’t properly subscribe to that while trying to upload and it never gets the CacheNotFoundException because OnError() is never called.

We were able to get the CacheNotFoundException wrapped in ExecutionException when we forcefully executed the upload() call here by calling upload(committedSize).get(), but we could not yet find a place to properly subscribe to the Exception while maintaining parallelism.

We think this may not be just limited to BwoB issues. We suspect any multiple RPC failures from this path could hang the uploads, even if it’s not about missing cache entries, but we haven't yet tried reproducing it in other ways.

Which category does this issue belong to?

Remote Execution

What's the simplest, easiest way to reproduce this bug? Please provide a minimal example if possible.

Check out https://github.com/hoj-stripe/cache-eviction-hang, run ./repro_hanging.sh.

Which operating system are you running Bazel on?

Ubuntu 20.04.6 LTS

What is the output of bazel info release?

release 7.1.0

If bazel info release returns development version or (@non-git), tell us how you built Bazel.

No response

What's the output of git remote get-url origin; git rev-parse HEAD ?

No response

Is this a regression? If yes, please try to identify the Bazel commit where the bug was introduced.

It was introduced in aafe123 (for 6.1.0)

But haven't yet bisected the last time it was fixed, since it used to hang before as well.
5.4.0 doesn’t hang and
5.3.2 hangs on //:less_than_eight_files.

Have you found anything relevant by searching the web?

No response

Any other information, logs, or outputs that you want to share?

cc @clintharrison @sushain97 @coeuvre

[hoj-stripe]

@coeuvre Thanks for the fix, I could verify this works with the repro case! And could we also ask backporting this? Preferrably 7.0.3 since we haven't yet tried 7.1.1, but we can work with 7.1.2 if that's the only option since our upgrade to 7.1.1 failed due to something taking forever while checking cached actions.

[iancha1992]

A fix for this issue has been included in Bazel 7.1.2 RC1. Please test out the release candidate and report any issues as soon as possible.
If you're using Bazelisk, you can point to the latest RC by setting USE_BAZEL_VERSION=7.1.2rc1. Thanks!