See initial notes here, here & here
High level summary so far:
Basically something's broken between rules_docker & RBE causing erroneous cache hits in Linux while the Mac CI fails. Need to figure out:
What's the missing dependency causing us to get erroneous remote cache hits?
What changed to cause the change in image digest?
Example failing build: https://buildkite.com/bazel/rules-docker-docker/builds/4442#94c0c6a8-6ac4-449a-81c8-337798a0a285
Bazel invocation: 0c549f01-e1e1-43ea-91cf-4553c9843bf0
I'm going to see if I can temporarily disable remote caching in the CI and update the digests to fix the CI at head. Note this doesn't fix the underlying "what missing input dependency is causing the erroneous remote cache hit" issue but it brings the CI back to a state where it can verify _some_ functionality while we investigate the issue
I started digging into this by diffing the Darwin invocation logs from Build #4426 and #4427 with:
$ curl https://buildkite.com/organizations/bazel/pipelines/rules-docker-docker/builds/4426/jobs/32c8e694-7cc0-4e0a-8b95-8a06da09bf08/download.txt > rules-docker-docker_build_4426_darwin-openjdk-8.log
$ curl https://buildkite.com/organizations/bazel/pipelines/rules-docker-docker/builds/4427/jobs/e5436c71-269b-4eee-99a4-fd69751fbe84/download.txt > rules-docker-docker_build_4427_darwin-openjdk-8.log
$ git diff --no-index rules-docker-docker_build_4426_darwin-openjdk-8.log rules-docker-docker_build_4427_darwin-openjdk-8.log
Here are a few interesting-looking diffs:
-workspace: /Users/buildkite/builds/bk-imacpro-5/bazel/rules-docker-docker
+workspace: /Users/buildkite/builds/bk-imacpro-4/bazel/rules-docker-docker
-BUILDKITE_AGENT_META_DATA_OS_VERSION=(10.15.5)
+BUILDKITE_AGENT_META_DATA_OS_VERSION=(10.15.6)
-BUILDKITE_SCRIPT_PATH=(curl -sS https://raw.githubusercontent.com/bazelbuild/continuous-integration/master/buildkite/bazelci.py?1597968169 -o bazelci.py python3.7 bazelci.py runner --task=macos)
+BUILDKITE_SCRIPT_PATH=(curl -sS https://raw.githubusercontent.com/bazelbuild/continuous-integration/master/buildkite/bazelci.py?1598054899 -o bazelci.py python3.7 bazelci.py runner --task=macos)
The diff is from the milliseconds since epoch query param changing, however the interesting part is that this pulls content from the master branch of bazelbuild/continuous-integration. Looks like there were a number of commits to files in the buildkite directory on August 21th, the day of the first failure: https://github.com/bazelbuild/continuous-integration/commits/master/buildkite. @philwo
-PWD=(/Users/buildkite/builds/bk-imacpro-5/bazel/rules-docker-docker)
+PWD=(/Users/buildkite/builds/bk-imacpro-4/bazel/rules-docker-docker)
The os-version component of the BUILDKITE_AGENT_TAGS environment variable changed:
-SUDO_COMMAND=(/usr/bin/env GOOGLE_APPLICATION_CREDENTIALS=/usr/local/etc/buildkite-agent/bazel.json PATH=/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin BUILDKITE_AGENT_DISCONNECT_AFTER_JOB=true BUILDKITE_AGENT_EXPERIMENT=git-mirrors BUILDKITE_AGENT_NAME=%hostname BUILDKITE_AGENT_TAGS=queue=macos,kind=worker,os=macos,java=8,os-version=10.15.5,machine-type=imacpro BUILDKITE_BUILD_PATH=/Users/buildkite/builds BUILDKITE_CONFIG_PATH=/usr/local/etc/buildkite-agent/buildkite-agent.cfg BUILDKITE_GIT_MIRRORS_PATH=/usr/local/var/bazelbuild BUILDKITE_GIT_CLONE_MIRROR_FLAGS=-v --bare /usr/local/bin/buildkite-agent start)
+SUDO_COMMAND=(/usr/bin/env GOOGLE_APPLICATION_CREDENTIALS=/usr/local/etc/buildkite-agent/bazel.json PATH=/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin BUILDKITE_AGENT_DISCONNECT_AFTER_JOB=true BUILDKITE_AGENT_EXPERIMENT=git-mirrors BUILDKITE_AGENT_NAME=%hostname BUILDKITE_AGENT_TAGS=queue=macos,kind=worker,os=macos,java=8,os-version=10.15.6,machine-type=imacpro BUILDKITE_BUILD_PATH=/Users/buildkite/builds BUILDKITE_CONFIG_PATH=/usr/local/etc/buildkite-agent/buildkite-agent.cfg BUILDKITE_GIT_MIRRORS_PATH=/usr/local/var/bazelbuild BUILDKITE_GIT_CLONE_MIRROR_FLAGS=-v --bare /usr/local/bin/buildkite-agent start)
-BUILDKITE_BUILD_CHECKOUT_PATH=(/Users/buildkite/builds/bk-imacpro-5/bazel/rules-docker-docker)
-BUILDKITE_AGENT_NAME=(bk-imacpro-5)
+BUILDKITE_BUILD_CHECKOUT_PATH=(/Users/buildkite/builds/bk-imacpro-4/bazel/rules-docker-docker)
+BUILDKITE_AGENT_NAME=(bk-imacpro-4)
-__PYVENV_LAUNCHER__=(/usr/local/bin/python3.7)
-Adding to platform cache key: b'10.15.5\n'
+Adding to platform cache key: b'10.15.6\n'
The cache-silo-key component of the --remote_default_platform_properties bazel argument changed:
-bazel build --show_progress_rate_limit=5 --curses=yes --color=yes --terminal_columns=143 --show_timestamps --verbose_failures --jobs=36 --announce_rc --experimental_repository_cache_hardlinks --disk_cache= --sandbox_writable_path=/var/tmp/_bazel_buildkite/cache/repos/v1 --test_env=REPOSITORY_CACHE=/var/tmp/_bazel_buildkite/cache/repos/v1 --remote_cache=http://100.107.73.148 --remote_timeout=60 --remote_max_connections=200 --remote_default_platform_properties=properties:{name:"cache-silo-key" value:"8ac85e8169cd9f0eb7011928d48c03b3f7401b9a29958ef657294e8394986caa"} --action_env=PATH --define=ENV_KEY=my_key --define=ENV_VALUE=my_value --extra_execution_platforms=@local_config_platform//:host,@io_bazel_rules_docker//platforms:local_container_platform --test_env=HOME -- //tests/container/... -//testing/new_pusher_tests/...
+bazel build --show_progress_rate_limit=5 --curses=yes --color=yes --terminal_columns=143 --show_timestamps --verbose_failures --jobs=36 --announce_rc --experimental_repository_cache_hardlinks --disk_cache= --sandbox_writable_path=/var/tmp/_bazel_buildkite/cache/repos/v1 --test_env=REPOSITORY_CACHE=/var/tmp/_bazel_buildkite/cache/repos/v1 --remote_cache=http://100.107.73.148 --remote_timeout=60 --remote_max_connections=200 --remote_default_platform_properties=properties:{name:"cache-silo-key" value:"b1beb1ad554d6e9eb9bf350ecd4e66daba5531135bfb14164e8b2f3821ba8b31"} --action_env=PATH --define=ENV_KEY=my_key --define=ENV_VALUE=my_value --extra_execution_platforms=@local_config_platform//:host,@io_bazel_rules_docker//platforms:local_container_platform --test_env=HOME -- //tests/container/... -//testing/new_pusher_tests/...
Interestingly, the cache-silo-key did not change for the Ubuntu invocations.
@cgdolan Indeed, last Friday I performed system maintenance on our macOS CI workers and essentially did the following:
# Reinstall the Android SDK with some additional versions build-tools.
tools/bin/sdkmanager [...]
# Upgrade macOS 10.15.5 to 10.15.6.
sudo softwareupdate -i -a -R
# Wait for reboot...
# Upgrade all packages from Homebrew
brew update && brew updates && brew cleanup -s
# Oh-oh, Homebrew upgraded the `python` version from 3.7 to 3.8.
# This will break our CI scripts. Let's reinstall Python 3.7 side-by-side:
brew install [email protected]
ln -s /usr/local/opt/[email protected]/bin/python3 /usr/local/bin/python3.7
ln -s /usr/local/opt/[email protected]/bin/pip3 /usr/local/bin/pip3.7
# Also let's install the usual pip3 packages in the new default Python 3.8:
pip3 install --upgrade pip setuptools wheel
pip3 install --upgrade requests uritemplate pyyaml github3.py macholib
pip3 install --upgrade urllib3
The macOS version goes into the cache-silo-key, which is the reason why it changed.
While I updated our Ubuntu CI VMs and containers, too, their cache-silo-key does not change in that case. We only bump it manually when we notice cache poisoning (which has happened only ~3 times since Bazel CI was created, AFAIR).
@cgdolan Thanks for the info! This might turn out to be very helpful.
Also from build after commit in your PR I see the Linux builds still get the old digest even when the remote actions are rerun. So it appears the Linux platform and Mac platforms actually produce different digests in a reproducible fashion. This makes me panic far less and I no longer think rules_docker is fundamentally broken.
No idea what this cache-silo-key is about. Need to dig into Bazel/Remote execution to see what that controls. @philwo any idea why cache-silo-key changed in --remote_default_platform_properties but not for the Linux platform as observed by @cgdolan in the previous post? Do you know what it's supposed to do?
Oops I didn't see @philwo's update because I didn't refresh the page before posting...
@philwo can you point me to what toolchain container the Buildkite Linux RBE builds are using? I couldn't quite tell from the command options in the logs.
I'm going to try to reproduce the older image digests by using Bazel's docker sandbox feature locally to try and narrow down the source of the difference
@philwo - Thanks so much for all the details, really appreciate it.
@smukherj1 - Ack that CI is still failing even with remote actions re-running. I agree with your assessment that Linux and Darwin are deterministically producing different digests.
I think I've ruled out changes to the master branch of bazelbuild/continuous-integration picked up by BUILDKITE_SCRIPT_PATH as a possible source of the breakage since bazelci.py is unchanged between the last commit on Aug 20 and the last commit on Aug 21:
$ curl -sS https://raw.githubusercontent.com/bazelbuild/continuous-integration/7773d887875b8a089f0461339370bca451b05d97/buildkite/bazelci.py > bazelci.py.20
$ curl -sS https://raw.githubusercontent.com/bazelbuild/continuous-integration/a7c9a468efaf2336001ea54855a4d1b9b35918cd/buildkite/bazelci.py > bazelci.py.21
$ sha256sum bazelci.py.20
1cc49ba19ace7e5f097496405010e9822ee21528b36caec63ddf6cc77274aa80 bazelci.py.20
$ sha256sum bazelci.py.21
1cc49ba19ace7e5f097496405010e9822ee21528b36caec63ddf6cc77274aa80 bazelci.py.21
My current thinking is:
os-version and cache-silo-key diffs have been explainedagent-name diff is likely not relevant as it's just a hostname__PYVENV_LAUCHER__ removal has yet to be explainedAccording to StackOverflow: "[__PYVENV_LAUNCHER__] seems to affect the behavior of pip" and "__PYVENV_LAUNCHER__ is an implementation detail of the way a Python framework build on Mac works".
Perhaps pip installs have changed on Darwin?
Ok it appears build switched to local execution without remote caching instead of remote execution without remote caching when --noremote_accept_cached was added which is interesting.
I'm going to try some old Ubuntu containers to see if I can reproduce the old digests
Ok I could reproduce the test //tests/container:alpine_custom_attr_digest_test passing locally when I ran it inside the docker container l.gcr.io/google/bazel@sha256:cecc8b1de6830fada11d3a9111e54a9a5ec38fee4ba589812c6f4ae6c602ab3d
Now to inspect the generated image manifest and compare it with the changed manifest to narrow down the source of the diff...
Old manifest:
{2 application/vnd.docker.distribution.manifest.v2+json {application/vnd.docker.container.image.v1+json 1470 sha256:c3a03330e420c3b68c356cf2fcc087c00c7b0975f4cfe6a34bebc74a6e4a2924 [] map[] <nil>} [{application/vnd.docker.image.rootfs.diff.tar.gzip 2207101 sha256:486039affc0ad0f17f473efe8fb25c947515a8929198879d1e64210ef142372f [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 45 sha256:85cea451eec057fa7e734548ca3ba6d779ed5836a3f9de14b8394575ef0d7d8e [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 162 sha256:8370b9623386466f7a7f582dfff0a5029260ac79f64dd2fe28b6162e8d435dc8 [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 131 sha256:16636da27233ea306a10cb2caed92d511d0c20fa8f72628197d2a79fcfb1fa94 [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 151 sha256:5e09d85f75f9c2b7678e44d2558a8f14a529a7f3bc76671dd97c038a9c6cba5d [] map[] <nil>}] map[]}
New manifest:
{2 application/vnd.docker.distribution.manifest.v2+json {application/vnd.docker.container.image.v1+json 1470 sha256:44a8165dbe6845f5ef71a67e22952ccf848aa6df1c5af75ec6dda54f0dd67014 [] map[] <nil>} [{application/vnd.docker.image.rootfs.diff.tar.gzip 2207101 sha256:486039affc0ad0f17f473efe8fb25c947515a8929198879d1e64210ef142372f [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 45 sha256:85cea451eec057fa7e734548ca3ba6d779ed5836a3f9de14b8394575ef0d7d8e [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 162 sha256:caf1256a043d9199caf3b21bc6d297dea8936bd22d9ce3dc859fa30a8d6309cf [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 135 sha256:184e44f4cccd4de4956568168f4f82a33f43773395bb5b308f4b944c11f8863d [] map[] <nil>} {application/vnd.docker.image.rootfs.diff.tar.gzip 150 sha256:687a338bf97839f7e99c48a22a7f8231de79614fc1f23341405da05bee6b4529 [] map[] <nil>}] map[]}
So the image config and the bottom three layers have changed. I can't recall the layer order off the top of my head, i.e., do the base image layers go to the top or the bottom.
Perhaps pip installs have changed on Darwin?
In case the Python version or pip packages play a role for rules_docker, then the brew upgrade on the Mac machines which upgraded the python3 binary from Python 3.7 to Python 3.8 (and all pip packages that were installed for Python 3.7 have been upgraded to their latest available version as well) might matter:
bk-imacpro-1:~ ci$ pip3.7 list bk-imacpro-1:~ ci$ pip3.8 list
Package Version Package Version
--------------- -------- --------------- ---------
altgraph 0.16.1 altgraph 0.17
asn1crypto 0.24.0
certifi 2019.3.9 certifi 2020.6.20
cffi 1.12.3 cffi 1.14.2
chardet 3.0.4 chardet 3.0.4
cryptography 2.6.1 cryptography 3.0
github3.py 1.3.0 github3.py 1.3.0
idna 2.8 idna 2.10
jwcrypto 0.6.0 jwcrypto 0.8
macholib 1.14 macholib 1.14
pip 20.0.2 pip 20.2.2
pycparser 2.19 pycparser 2.20
python-dateutil 2.8.0 python-dateutil 2.8.1
PyYAML 5.3 PyYAML 5.3.1
requests 2.22.0 requests 2.24.0
setuptools 46.0.0 setuptools 49.6.0
six 1.12.0 six 1.15.0
uritemplate 3.0.1 uritemplate 3.0.1
urllib3 1.25.8 urllib3 1.25.10
wheel 0.34.2 wheel 0.35.1
Ok I narrowed down one of the changed images to //tests/container:alpine_with_custom_attr.
Specifically, I see the layer tarball containing the files //testdata:bar and //testdata:foo has a binary diff but the source files should be unchanged. I believe the layer tarball is built by build_tar.py so it's looking quite likely it's a pip package upgrade. I just don't know which one yet...
@smukherj1 Maybe Python 3.8 changed something in the bundled “tarfile” library?
https://docs.python.org/3.8/library/tarfile.html#tarfile.DEFAULT_FORMAT:
"Changed in version 3.8: The default format for new archives was changed to PAX_FORMAT from GNU_FORMAT."
I bet it’s this one: https://github.com/python/cpython/commit/e680c3db80efc4a1d637dd871af21276db45ae03#diff-ef64d8b610dda67977a63a9837f46349
@smukherj1 Maybe Python 3.8 changed something in the bundled “tarfile” library?
Quite possibly. I just checked my local env. Env where I see no diff I have python 3.5.2, env where I see diff, I see 3.8.5
@philwo any idea if we could update the Python version in Linux buildkite to match Mac? This should unblock https://github.com/bazelbuild/rules_docker/pull/1596 (after the buildkite flags are reverted)
Another possibility is to see if we could always force the new format in the python code...
Another possibility is to see if we could always force the new format in the python code...
@cgdolan Added suggestion on how to try this here
Sure thing, done.
A bit strange that the digests used by the tests here haven't changed 🤔
After updating the tarfile format, RBE passes and Ubuntu fails due to the image_test shas you mentioned changing. I'll update those too.
@philwo any idea if we could update the Python version in Linux buildkite to match Mac? This should unblock #1596 (after the buildkite flags are reverted)
Unfortunately we can't upgrade Python in the Linux containers, because we want to test against the default versions that the distributions ship to ensure that Bazel works and we don't accidentally depend on later non-default versions.
I think explicitly setting the tarfile format is a good fix, as it restores determinism across Python versions!
Most helpful comment
https://docs.python.org/3.8/library/tarfile.html#tarfile.DEFAULT_FORMAT:
"Changed in version 3.8: The default format for new archives was changed to PAX_FORMAT from GNU_FORMAT."