thought-machine / please

High-performance extensible build system for reproducible multi-language builds.
https://please.build
Apache License 2.0
2.48k stars 207 forks source link

Please often rebuilding when no change was made #3278

Closed rmillet-rs closed 1 month ago

rmillet-rs commented 1 month ago

Hello,

It seems that please detect changes when none visibly happened. For example, I build my app, it fetches go toolchain and build the whole thing. Then build the same app, it fetches again the toolchain (not always).

Way to reproduce:

false; while [ $? -eq 1 ]; do sleep 1; plz build //plugins:go; grep 'Need to rebuild.*' plz-out/log/build.log; done
11:52:47.564 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 50ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:52:47.571   DEBUG: Need to rebuild //plugins:_go#download, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.571   DEBUG: Need to rebuild //plugins:_shell#download, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.571   DEBUG: Need to rebuild //plugins:_proto#download, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.571   DEBUG: Need to rebuild //plugins:_go_proto#download, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.571   DEBUG: Need to rebuild //_please:arcat, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.572   DEBUG: Need to rebuild //plugins:_java#download, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.579   DEBUG: Need to rebuild //plugins:go_proto, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.579   DEBUG: Need to rebuild //plugins:proto, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.579   DEBUG: Need to rebuild //plugins:shell, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.579   DEBUG: Need to rebuild //plugins:java, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.579   DEBUG: Need to rebuild //plugins:go, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.589   DEBUG: Need to rebuild ///proto//build_defs:proto_languages, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)
11:52:47.608   DEBUG: Need to rebuild ///proto//build_defs:grpc_languages, config has changed (was iX483CjwkDTCohF3canxchyXd+o, need iGq7eE29gHhGG7bDW9tj/lLR1Tc)

# Launch again

false; while [ $? -eq 1 ]; do sleep 1; plz build //plugins:go; grep 'Need to rebuild.*' plz-out/log/build.log; done
11:52:53.670 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 30ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:52:54.707 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 30ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:52:55.747 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 30ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:52:56.783 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 20ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:52:57.823 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 20ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:52:58.860 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 30ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:52:59.896 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 30ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:53:00.944 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 20ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:53:01.983 WARNING: Downgrading to Please version 17.11.0 skipped (current version: 17.12.0)
Build finished; total time 50ms, incrementality 100.0%. Outputs:
//plugins:go:
  plz-out/subrepos/plugins/go
11:53:01.989   DEBUG: Need to rebuild //plugins:_go_proto#download, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.989   DEBUG: Need to rebuild //plugins:_java#download, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.989   DEBUG: Need to rebuild //_please:arcat, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.989   DEBUG: Need to rebuild //plugins:_proto#download, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.989   DEBUG: Need to rebuild //plugins:_shell#download, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.989   DEBUG: Need to rebuild //plugins:_go#download, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.996   DEBUG: Need to rebuild //plugins:go_proto, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.996   DEBUG: Need to rebuild //plugins:java, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.996   DEBUG: Need to rebuild //plugins:shell, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.996   DEBUG: Need to rebuild //plugins:proto, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:01.996   DEBUG: Need to rebuild //plugins:go, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:02.007   DEBUG: Need to rebuild ///proto//build_defs:proto_languages, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)
11:53:02.028   DEBUG: Need to rebuild ///proto//build_defs:grpc_languages, config has changed (was iGq7eE29gHhGG7bDW9tj/lLR1Tc, need iX483CjwkDTCohF3canxchyXd+o)

Its seems to switch between the same two config hashes (iX483CjwkDTCohF3canxchyXd+o and iGq7eE29gHhGG7bDW9tj/lLR1Tc).

How is this hash calculated, so I can check if something messes around my env?

Tested with:

Tatskaari commented 1 month ago

This is alarming. There are very little inputs into the config hash.

The inputs are a subset of the fields in the config file that change the way a build works without changing the rule hash. These are: 1) Secrets passed in via the build env 2) The rejected licences 3) The language config i.e. Lang under [BUILD], but this is mostly just some legacy left over from the old proto rules.

There's also build.nonce that you can set to explicitly invalidate the cache.

You can find the code here.

If you're able to, can you share your .plzconfig? Are you exposing a secret to the build that is changing between invocations?

peterebden commented 1 month ago

Think I've spotted this one, I assume that you have multiple entries in [buildenv] in your config? It seems that can incorrectly produce nondeterminism

rmillet-rs commented 1 month ago

I have effectively two variables in my [BuildEnv], and when I remove one of them, the issue doesn't appear anymore

toastwaffle commented 1 month ago

@rmillet-rs FYI we've released Please v17.12.1 today with the fix for this issue

rmillet-rs commented 1 month ago

thank you !