bazel icon indicating copy to clipboard operation
bazel copied to clipboard

"dangling symbolic link" flakes when switching from --noenable_bzlmod -> --enable_bzlmod

Open quic-sbjorkle opened this issue 1 year ago • 10 comments

Description of the bug:

Switching from --noenable_bzlmod to the default --enable_bzlmod occasionally causes builds to flake, resulting in "dangling symbolic link" errors. Although this issue was reported in #20886 and supposedly fixed in commit 52adf0b, the problem persists.

Error message from build:

13:34:43 ERROR: /Top-bazel/478b2cbff2254079381e27d1a245fab2/external/FOO/BUILD.bazel:99:11: output '_solib_k8/_U@@FOO_Ulibrary___Uexternal_FOO_Sexternal_FOO_Slib_Smodified_Urunpath/libBar.so.5' is a dangling symbolic link
13:34:44 ERROR: /Top-bazel/478b2cbff2254079381e27d1a245fab2/external/FOO/BUILD.bazel:99:11: SolibSymlink _solib_k8/_U@@FOO_S_S_FOO_Ulibrary___Uexternal_SFOO_Sexternal_SFOO_Slib_Smodified_Urunpath/libBar.so.5 failed: not all outputs were created or valid
13:34:44 [207,396 / 262,586] 645 / 1863 tests, 1 failed; checking cached actions

This error occurs quite often when running in CI, though it happens less so on local development machines. It appears to be linked to the local action cache becoming corrupted somehow when toggling bzlmod_enabled. Once the error manifests on a node, it persists on that node until the action cache is cleared or a ./bazel clean is executed.

Below are extracted parts from a decoded action cache:

In index: bazel-out/ubuntu22-fastbuild/bin/_solib_k8/_U@@FOOcc_Ulibrary___Uexternal_SFOO_Sexternal_SFOO_Slib_Smodified_Urunpath/libBar.so.5 <==> 333425 <-- Missing entry

ls -alh bazel-out/ubuntu22-fastbuild/bin/_solib_k8/_U@@FOOcc_Ulibrary___Uexternal_SCLibs_UFOO_Sexternal_SFOO_Slib_Smodified_Urunpath/libBar.so.5 <--- File exist but dangling symlink
lrwxrwxrwx 1 user 1002 182 May 23 11:34 bazel-out/ubuntu22-fastbuild/bin/_solib_k8/_U@@FOO_S_S_FOO_Ucc_Ulibrary___Uexternal_SFOO_Sexternal_SFOO_Slib_Smodified_Urunpath/libBar.so.5 -> /Top-bazel/478b2cbff2254079381e27d1a245fab2/execroot/_main/bazel-out/ubuntu22-fastbuild/bin/external/FOO/external/FOO/lib/modified_runpath/libBar.so.5
333424, bazel-out/ubuntu22-fastbuild/bin/external/FOO/external/FOO/lib/modified_runpath/libBar.so.5:
      actionKey = efa037ea581a671c7388fa04511f5002423d8f58bf4942ba7e4bbaba04eeeea2
      usedClientEnvKey = 3ef42779f2af10825fa190221bb26ed61875ae41b887cc046b95040348911d16
      digestKey = b4ab98ca955cd21c9533086be59710a64be28843af7bed2436b88f07b58000ae
      bazel-out/ubuntu22-fastbuild/bin/external/FOO/external/FOO/lib/modified_runpath/libBar.so.5 = RemoteFileArtifactValueWithExpiration{digest=0x91949D49AED5522D6D40827CB94D192037457E6DC5036D0482D771E4F389D831, size=5976097, locationIndex=1, materializationExecPath=null, expireAtEpochMilli=1715950679390}
      packed_len = 186

A known workaround is to use the flag --nouse_action_cache.

Which category does this issue belong to?

Local Execution

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

It's not clear how to reproduce this issue with ease. Attempts to manually induce this state on a local machine in a controlled manner have been unsuccessful.

Which operating system are you running Bazel on?

Linux

What is the output of bazel info release?

release 7.2.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

If this is a regression, please try to identify the Bazel commit where the bug was introduced with bazelisk --bisect.

No response

Have you found anything relevant by searching the web?

No response

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

No response

quic-sbjorkle avatar Jun 24 '24 07:06 quic-sbjorkle

What does FOO look like here? In particular, does it contain any ~ characters?

bazel-out/ubuntu22-fastbuild/bin/external/FOO/external/FOO/lib/modified_runpath/libBar.so.5 also looks very weird as it has two external segments. Is that what you see in the cache entry or is it a result of redacting information?

fmeum avatar Jun 24 '24 12:06 fmeum

@fmeum, no.. Just [A-Z0-9_] bazel-out/ubuntu22-fastbuild/bin/_solib_k8/_U@@CLibs_UGt_Ulinux_U64_S_S_CCLibs_UGt_Ucc_Ulibrary___Uexternal_SCLibs_UGt_Ulinux_U64_Sexternal_SCLibs_UGt_Ulinux_U64_Slib_Smodified_Urunpath/libBar.so.5

You are correct with the observation of 2 external/ directories: 333424, bazel-out/ubuntu22-fastbuild/bin/external/CLibs_Gt_linux_64/external/CLibs_Gt_linux_64/lib/modified_runpath/libBar.so.5

quic-sbjorkle avatar Jun 24 '24 12:06 quic-sbjorkle

@justinhorvitz Not sure who to ask about this, but do you happen to have an idea how such corrupted paths could end up in the action cache?

fmeum avatar Jun 24 '24 12:06 fmeum

@bazel-io flag

fmeum avatar Jun 24 '24 12:06 fmeum

@bazel-io fork 7.3.0

iancha1992 avatar Jun 24 '24 18:06 iancha1992

The action cache indexes the path strings of outputs' exec paths. I'm not sure why you've concluded that there is action cache corruption? Is the correct output path bin/external/CLibs_Gt_linux_64/lib/modified_runpath/libBar.so.5 and not bin/external/CLibs_Gt_linux_64/external/CLibs_Gt_linux_64/lib/modified_runpath/libBar.so.5?

justinhorvitz avatar Jun 24 '24 18:06 justinhorvitz

The action cache indexes the path strings of outputs' exec paths. I'm not sure why you've concluded that there is action cache corruption? Is the correct output path bin/external/CLibs_Gt_linux_64/lib/modified_runpath/libBar.so.5 and not bin/external/CLibs_Gt_linux_64/external/CLibs_Gt_linux_64/lib/modified_runpath/libBar.so.5?

Yes, I don't know of any source of the latter type of path that wouldn't be a bug. I don't know whether this comes from action cache logic though.

fmeum avatar Jun 24 '24 18:06 fmeum

I'm afraid I can't be of too much help here. Is it at all possible that multiple concurrent builds are writing to the same action cache (wild guess)?

If it could be reproduced, I would try to see if I could hit a breakpoint where the questionable path string is being written to the action cache. It would be in PersistentStringIndexer#getOrCreate, or perhaps it's being loaded from disk incorrectly, which would be when instantiating the PersistentIndexMap.

justinhorvitz avatar Jun 24 '24 18:06 justinhorvitz

We don’t have concurrent builds on these machines so multiple simultaneous writes to the action cache is not possible. It also happens fairly frequently on multiple machines in the cluster. Maybe 1 in 50 builds will end up in this corrupt state when —enable_bzlmod is toggled. But will be tricky to catch with a debugger.

quic-sbjorkle avatar Jun 24 '24 21:06 quic-sbjorkle

@Wyverald since this seems related to bzlmod. I do not have any further ideas beyond adding more verbose logging to try and gather data.

justinhorvitz avatar Jun 24 '24 22:06 justinhorvitz

cc @tjgq in case you have any observations.

I have no idea how enabling Bzlmod could make a difference here, except for maybe the presence of the ~ character in paths.

@quic-sbjorkle, if you're able to specify a custom Bazel version on your CI (using Bazelisk for example), I could create a custom build of Bazel that includes extra logging. (That is, if anyone has idea what sort of extra logging would help here.)

Wyverald avatar Jul 08 '24 18:07 Wyverald

@Wyverald Yes we can specify a custom bazel to be used in CI so if you have some logging points we can add that as a patch. However @quic-sbjorkle is on vacation until beginning of August so we can't do it until he's back.

Gormo avatar Jul 09 '24 08:07 Gormo

We are also seeing the bazel flakiness since upgrading to bazel 7.2.1 from bazel 6 on our Linux agents. We haven't bzlmod yet.

Go builds would fail with the below error:

ERROR: /....: output ..../_virtual_imports/docker_proto.withgogoimport/.../docker.proto' is a dangling symbolic link
ERROR: ....: Symlinking virtual .proto sources for .... failed: not all outputs were created or valid
Use --verbose_failures to see the command lines of failed build steps.
ERROR: .... ~testmain.a failed: not all outputs were created or valid

Javascript builds would fail with the below error:

[webpack-cli] Error: Cannot find module 'source-map'
     Require stack:
     - .cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-fastbuild/bin/node_modules/css-minimizer-webpack-plugin/dist/index.js
     - .cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-fastbuild/bin/tools/js/webpack.config.js
     - .cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-opt-exec-ST-a828a81199fe/bin/tools/js/webpack/webpack_js_binary.sh.runfiles/yext/node_modules/.aspect_rules_js/[email protected]_webpack_5.76.3/node_modules/webpack-cli/lib/webpack-cli.js
     - .cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-opt-exec-ST-a828a81199fe/bin/tools/js/webpack/webpack_js_binary.sh.runfiles/yext/node_modules/.aspect_rules_js/[email protected]_webpack_5.76.3/node_modules/webpack-cli/lib/bootstrap.js
     - .cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-opt-exec-ST-a828a81199fe/bin/tools/js/webpack/webpack_js_binary.sh.runfiles/yext/node_modules/.aspect_rules_js/[email protected]_webpack_5.76.3/node_modules/webpack-cli/bin/cli.js
     - .cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-opt-exec-ST-a828a81199fe/bin/tools/js/webpack/webpack_js_binary.sh.runfiles/yext/node_modules/.aspect_rules_js/[email protected]_webpack-cli_4.4.0/node_modules/webpack/bin/webpack.js
         at Module._resolveFilename (node:internal/modules/cjs/loader:1140:15)
         at Module._load (node:internal/modules/cjs/loader:981:27)
         at Module.require (node:internal/modules/cjs/loader:1231:19)
         at require (.cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-opt-exec-ST-a828a81199fe/bin/tools/js/webpack/webpack_js_binary.sh.runfiles/yext/node_modules/.aspect_rules_js/[email protected]/node_modules/v8-compile-cache/v8-compile-cache.js:159:20)
         at Object.<anonymous> (.cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-fastbuild/bin/node_modules/css-minimizer-webpack-plugin/dist/index.js:7:5)
         at Module._compile (.cache/bazel/.../523ecd3a78772af5fd843de01aa3ce97/sandbox/linux-sandbox/13411/execroot/yext/bazel-out/k8-opt-exec-ST-a828a81199fe/bin/tools/js/webpack/webpack_js_binary.sh.runfiles/yext/node_modules/.aspect_rules_js/[email protected]/node_modules/v8-compile-cache/v8-compile-cache.js:192:30)
         at Module._extensions..js (node:internal/modules/cjs/loader:1422:10)
         at Module.load (node:internal/modules/cjs/loader:1203:32)
         at Module._load (node:internal/modules/cjs/loader:1019:12)
         at Module.require (node:internal/modules/cjs/loader:1231:19) {
       code: 'MODULE_NOT_FOUND',
       requireStack: [
         ...
       ]
     }

Rerun of the builds typically fix the issue. If it is relevant, we also have --noallow_unresolved_symlinks and --experimental_inprocess_symlink_creation flags set in our .bazelrc.

amit-mittal avatar Jul 09 '24 21:07 amit-mittal

Ping @Wyverald

meteorcloudy avatar Jul 23 '24 15:07 meteorcloudy

@Wyverald, I'm back from vacation now so If you have any proposed log-points I can deploy a patched bazel and collect those logs in our environment.

quic-sbjorkle avatar Aug 05 '24 07:08 quic-sbjorkle

Sorry, but I'm really not familiar enough with local action execution to even know where to insert log statements.

@fmeum, @tjgq, @zhengwei143 -- any pointers here? Where could we add log statements to help debug this?

Wyverald avatar Aug 05 '24 21:08 Wyverald

Rerun of the builds typically fix the issue. If it is relevant, we also have --noallow_unresolved_symlinks and --experimental_inprocess_symlink_creation flags set in our .bazelrc.

@amit-mittal Just want to point out the Webpack one could be to do with https://github.com/aspect-build/rules_js/issues/1877 if you are using rules_js.

Best everyone checks --experimental_inprocess_symlink_creation is not enabled in order to disambiguate these issues. It is currently unclear if this flag negatively affects other rules when used with Bazel 7.

adamscybot avatar Aug 06 '24 01:08 adamscybot

@Wyverald Places to log could be (based on release-7.2.0 branch): https://github.com/bazelbuild/bazel/blob/5b546af3b9a22c8e280e3ba3fcdd5d0bc13215c5/src/main/java/com/google/devtools/build/lib/rules/cpp/SolibSymlinkAction.java#L103-L104 (both properties) https://github.com/bazelbuild/bazel/blob/49a9502312b6af391a10e1a5c3e05d245ad54899/src/main/java/com/google/devtools/build/lib/actions/cache/CompactPersistentActionCache.java#L359 (entry has toString implemented) https://github.com/bazelbuild/bazel/blob/49a9502312b6af391a10e1a5c3e05d245ad54899/src/main/java/com/google/devtools/build/lib/actions/cache/CompactPersistentActionCache.java#L349

@quic-sbjorkle Could you also provide the output of --announce_rc and the command-line flags for both CI runs, with and without Bzlmod enabled?

fmeum avatar Aug 06 '24 13:08 fmeum

@quic-sbjorkle Could you also share the definitions of the targets producing @CLibs_Gt_linux_U64//:CLibs_Gt_cc_library and @CLibs_Gt_linux_U64//lib/modified_runpath:libBar.so.5? Does that repo have any subdirectories called external?

fmeum avatar Aug 06 '24 14:08 fmeum