search

bazelbuild / bazel

a fast, scalable, multi-language and extensible build system
https://bazel.build
Apache License 2.0
22.69k stars 3.98k forks source link

Bazel `info` -> `cquery` invalidate part of cache #22360

Open SinimaWath opened 1 month ago

SinimaWath commented 1 month ago

Description of the bug:

Running: 1 - bazel info 2 - bazel cquery target 3 - bazel run/build target

Invalidate part of cache (for example, suddenly npm modules start extracting, but must be taken from cache). For more info see reproduction steps

Which category does this issue belong to?

Core

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

Add to ~/.bazelrc:

common --experimental_check_output_files=false
common --noexperimental_check_external_repository_files

1 - git clone https://github.com/bazelbuild/examples.git - Clone examples repo 2 - cd frontend - go to frontend example. 3 - bazel build //next.js:next - build application 4 - bazel build //next.js:next - check build is from cache 5 - bazel info && bazel cquery //next.js:next && bazel build //next.js:next

After step 5, in logs (bazel info server_log) we see there were Extracting npm package (building without info and cquery doesn't have extracting npm package):

240514 09:51:17.209:I 6609 [com.google.devtools.build.lib.runtime.BuildSummaryStatsModule.buildComplete] Critical Path: 0.08s, Remote (0.00% of the time): [parse: 0.00%, queue: 0.00%, network: 0.00%, upload: 0.00%, setup: 0.00%, process: 0.00%, fetch: 0.00%, retry: 0.00%, processOutputs: 0.00%, other: 0.00%, input files: 0, input bytes: 0, memory bytes: 0]
  0.00s action 'JsRunBinary next.js/.next'
  0.00s action 'Transpiling & type-checking TypeScript project @@//next.js/pages:pages [tsc -p next.js/tsconfig.json]'
  0.00s action 'Transpiling & type-checking TypeScript project @@//next.js/pages/api:api [tsc -p next.js/tsconfig.json]'
  0.08s action 'Extracting npm package next@13.0.5_-1955910335'
240514 09:51:17.209:I 6609 [com.google.devtools.build.lib.runtime.BuildSummaryStatsModule.buildComplete] Slowest actions:
  0.08s action 'Extracting npm package next@13.0.5_-1955910335'
  0.04s action 'Extracting npm package next@13.0.5_-1955910335 [for tool]'
  0.04s action 'Copying directory packages/one/one'
  0.04s action 'Extracting npm package @babel/generator@7.23.5 [for tool]'
  0.02s action 'Extracting npm package scheduler@0.23.0 [for tool]'
  0.02s action 'Extracting npm package @babel/types@7.23.5 [for tool]'
  0.02s action 'Extracting npm package react-dom@18.2.0_react_18.2.0'
  0.02s action 'Extracting npm package styled-jsx@5.1.0_986221465 [for tool]'
  0.02s action 'Extracting npm package kind-of@3.2.2'
  0.02s action 'Extracting npm package @babel/helper-hoist-variables@7.22.5 [for tool]'
  0.02s action 'Extracting npm package @babel/helper-module-transforms@7.23.3_at_babel_core_7.23.5 [for tool]'
  0.02s action 'Extracting npm package supports-color@5.5.0 [for tool]'
  0.02s action 'Extracting npm package is-number@6.0.0'
  0.01s action 'Extracting npm package @babel/helper-validator-option@7.23.5 [for tool]'
  0.01s action 'Extracting npm package caniuse-lite@1.0.30001542'
  0.01s action 'Extracting npm package @babel/helper-environment-visitor@7.22.20 [for tool]'
  0.01s action 'Extracting npm package @babel/parser@7.23.5 [for tool]'
  0.01s action 'Extracting npm package @babel/generator@7.23.5'
  0.01s action 'Extracting npm package @babel/traverse@7.23.5 [for tool]'
  0.01s action 'Extracting npm package @jridgewell/trace-mapping@0.3.19 [for tool]'
  0.01s action 'Extracting npm package @babel/parser@7.23.5'
  0.01s action 'BazelWorkspaceStatusAction stable-status.txt'
  0.01s action 'Extracting npm package typescript@4.9.3'
  0.01s action 'Extracting npm package @babel/template@7.22.15'
  0.01s action 'Extracting npm package @babel/helper-function-name@7.23.0 [for tool]'
  0.01s action 'Extracting npm package @babel/core@7.23.5 [for tool]'
  0.01s action 'Extracting npm package @babel/template@7.22.15 [for tool]'
  0.01s action 'Extracting npm package postcss@8.4.14'
  0.01s action 'Extracting npm package @babel/helper-compilation-targets@7.22.15'
  0.01s action 'Extracting npm package semver@6.3.1 [for tool]'
240514 09:51:17.212:I 6609 [com.google.devtools.build.lib.sandbox.AsynchronousTreeDeleter.setThreads] Resizing async tree deletion pool to 4 threads
240514 09:51:17.212:I 6609 [com.google.devtools.build.lib.runtime.CacheFileDigestsModule.logStats] Accumulated cache stats after command: hit count=63355, miss count=17619, hit rate=0.782412, eviction count=0
240514 09:51:17.212:I 6609 [com.google.devtools.build.lib.runtime.CacheFileDigestsModule.logStats] Cache stats for finished command: hit count=12671, miss count=1, hit rate=0.999921, eviction count=0

Which operating system are you running Bazel on?

macos

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.

No response

Have you found anything relevant by searching the web?

https://github.com/bazelbuild/bazel/issues/17914

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

GrpcServerImpl.executeCommand logs, without --client-env (removed it)


240515 12:10:24.009:I 8721 [com.google.devtools.build.lib.server.GrpcServerImpl.executeCommand] [info, --startup_time=32, --command_wait_time=0, --extract_data_time=0, --binary_path=/Users/user_name/Library/Caches/bazelisk/downloads/sha256/fb5e7bc62fc3c8f2511e3b64d795296444129b26f13d8dece4d4cee1845b758f/bin/bazel, --rc_source=client, --default_override=0:common=--isatty=1, --default_override=0:common=--terminal_columns=156, --rc_source=/Users/user_name/trash/examples/frontend/.bazelrc, --rc_source=/Users/user_name/.bazelrc, --default_override=1:common=--@aspect_rules_ts//ts:skipLibCheck=always]
240515 12:10:24.097:I 8721 [com.google.devtools.build.lib.server.GrpcServerImpl.executeCommand] [cquery, --startup_time=21, --command_wait_time=0, --extract_data_time=0, --binary_path=/Users/user_name/Library/Caches/bazelisk/downloads/sha256/fb5e7bc62fc3c8f2511e3b64d795296444129b26f13d8dece4d4cee1845b758f/bin/bazel, --rc_source=client, --default_override=0:common=--isatty=1, --default_override=0:common=--terminal_columns=156, --rc_source=/Users/user_name/trash/examples/frontend/.bazelrc, --rc_source=/Users/user_name/.bazelrc, --default_override=1:common=--@aspect_rules_ts//ts:skipLibCheck=always, //next.js:next]
240515 12:10:24.223:I 8721 [com.google.devtools.build.lib.server.GrpcServerImpl.executeCommand] [build, --startup_time=21, --command_wait_time=0, --extract_data_time=0, --binary_path=/Users/user_name/Library/Caches/bazelisk/downloads/sha256/fb5e7bc62fc3c8f2511e3b64d795296444129b26f13d8dece4d4cee1845b758f/bin/bazel, --rc_source=client, --default_override=0:common=--isatty=1, --default_override=0:common=--terminal_columns=156, --rc_source=/Users/user_name/trash/examples/frontend/.bazelrc, --rc_source=/Users/user_name/.bazelrc, --default_override=1:common=--@aspect_rules_ts//ts:skipLibCheck=always, //next.js:next]
tpasternak commented 1 month ago

I'm not sure if this is related, but I also noticed that commands such as bazel info or bazel mod cause invalidaiton of large portions of skyframe. It can be easily verified with bazel build && bazel dump --skyframe=summary && bazel info && bazel dump --skyframe=summary

SinimaWath commented 1 month ago

@tpasternak You are right.

Checked and even just bazel info invalidate part of cache, thanks!

fmeum commented 1 month ago

@tpasternak Are you using --disk_cache or --remote_cache when you reproduce this?

I'm seeing some weird Skyframe invalidation when using these flags, but not without them.

Changed keys without new values: [ActionLookupData0{actionLookupKey=ConfiguredTargetKey{label=@@rules_java~//toolchains:platformclasspath, config=BuildConfigurationKey[b85621dae172f731976165fe86631f99030f401e70ed2b02d58c69595e5ea36d]}, actionIndex=0}]
fmeum commented 1 month ago

Possibly related: https://github.com/bazelbuild/bazel/issues/22367

@tpasternak Could you build Bazel with the patch I added to that issue and rerun on your reproducer?

tjgq commented 1 month ago

Does this repro with --noexperimental_merged_skyframe_analysis_execution? I'm wondering if it's the limitation described in this commit description (and afaik not yet lifted since then): https://github.com/bazelbuild/bazel/commit/d94816a68980628e43f509bcd6a49e98984658b5 (although I would concur that bazel info at least ought not to invalidate anything).

tpasternak commented 1 month ago

@fmeum with your help I figured out what's wrong - I was using --override_repository when running build, but not when running bazel info. When I tried bazel info --override_repository it didn't trigger skyframe eviction

tpasternak commented 1 month ago

Probably my comments are unrelated to the original issue, sorry for messing

SinimaWath commented 1 month ago

Does this repro with --noexperimental_merged_skyframe_analysis_execution? I'm wondering if it's the limitation described in this commit description (and afaik not yet lifted since then): d94816a (although I would concur that bazel info at least ought not to invalidate anything).

@tjgq

Repro without --noexperimental_merged_skyframe_analysis_execution