archutil.check is being called too often
For a simple build of an image without any RUN steps, I'm seeing delays of 30 seconds, sometimes over a minute, before the build starts sending the context. During that time, I'm seeing multiple calls to the check command:
# while true; do ps auxw | grep check | grep libexec; sleep 0.5; done
root 1999873 0.0 0.0 224108 4536 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 1999881 8.0 0.0 222684 3736 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 1999892 0.0 0.0 223492 3604 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 1999898 10.0 0.0 223500 3832 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 1999898 61.0 0.0 223500 3832 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 1999908 49.0 0.0 4409656 4608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 1999940 0.0 0.0 224108 4536 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 1999947 0.0 0.0 222684 3740 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 1999953 0.0 0.0 223188 4268 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 1999959 21.0 0.0 222396 3444 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 1999959 72.0 0.0 222396 3444 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 1999970 33.0 0.0 223492 3604 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 1999976 0.0 0.0 223500 3832 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 1999976 60.0 0.0 223500 3832 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 1999986 0.0 0.0 4409656 4604 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 1999992 0.0 0.0 224108 4532 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000000 0.0 0.0 223188 4420 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000013 46.0 0.0 4409656 4604 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000019 0.0 0.0 224108 4532 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000025 0.0 0.0 222684 3736 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000031 0.0 0.0 223188 4412 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000037 0.0 0.0 222396 3444 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000044 0.0 0.0 223492 3776 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000050 0.0 0.0 223500 3664 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000056 0.0 0.0 4409656 4608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000062 0.0 0.0 224108 4532 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000070 0.0 0.0 223188 4420 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000070 60.0 0.0 223188 4420 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000083 0.0 0.0 222396 3788 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000102 0.0 0.0 222684 3736 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000111 0.0 0.0 222396 3880 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000118 0.0 0.0 223492 3608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000124 0.0 0.0 223500 3660 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000134 46.0 0.0 222684 3600 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000143 0.0 0.0 223188 4416 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000154 46.0 0.0 223500 3660 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000160 0.0 0.0 4409656 4608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000166 47.0 0.0 224108 4368 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000178 0.0 0.0 222684 3600 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000184 45.0 0.0 223188 4272 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000193 0.0 0.0 223492 3776 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000199 44.0 0.0 223500 3664 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000205 0.0 0.0 4409656 4604 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000213 0.0 0.0 222684 3740 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000219 0.0 0.0 223188 4272 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000225 36.0 0.0 222396 3788 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000232 0.0 0.0 223492 3608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000238 37.0 0.0 223500 3664 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000246 0.0 0.0 224108 4532 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000252 29.0 0.0 222684 3600 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000258 0.0 0.0 223188 4272 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000264 0.0 0.0 222396 3788 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000279 0.0 0.0 223492 3608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000287 0.0 0.0 4409656 4608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000422 0.0 0.0 223188 4272 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000428 32.0 0.0 222396 3444 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000435 0.0 0.0 223492 3776 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000441 27.0 0.0 223500 3836 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000447 0.0 0.0 4409656 4580 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000453 8.0 0.0 224108 4372 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000461 0.0 0.0 223188 4272 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000467 0.0 0.0 222396 3792 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000474 0.0 0.0 223492 3608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000480 44.0 0.0 223500 3664 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000488 0.0 0.0 224108 4372 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000494 32.0 0.0 222684 3604 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000502 0.0 0.0 222396 3788 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000515 45.0 0.0 224108 4536 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000521 0.0 0.0 222684 3604 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000527 47.0 0.0 223188 4268 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000540 0.0 0.0 222396 3444 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000549 0.0 0.0 223500 3660 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000555 0.0 0.0 4409656 4612 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000564 0.0 0.0 224108 4372 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000564 0.0 0.0 224108 4372 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000564 107 0.0 224108 4372 ? Rl 11:44 0:01 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000564 131 0.0 224108 4372 ? Dl 11:44 0:01 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000564 65.5 0.0 224108 4372 ? Dl 11:44 0:01 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000586 0.0 0.0 222684 3736 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000592 0.0 0.0 223188 4276 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000598 0.0 0.0 222396 3384 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000605 0.0 0.0 223492 3608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000618 0.0 0.0 4409656 4608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000624 0.0 0.0 224108 4532 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000631 0.0 0.0 222684 3600 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000639 0.0 0.0 222396 3788 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000648 0.0 0.0 223500 3660 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000654 48.0 0.0 4409656 4608 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000662 0.0 0.0 222684 3732 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000668 27.0 0.0 223188 4416 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000674 0.0 0.0 222396 3784 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000681 13.0 0.0 223492 3772 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000687 0.0 0.0 223500 3832 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000687 54.0 0.0 223500 3832 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000704 51.0 0.0 222684 3740 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000711 0.0 0.0 223188 4268 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000720 0.0 0.0 223492 3776 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000726 0.0 0.0 223500 3832 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
root 2000732 0.0 0.0 4409656 4612 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/arm-binfmt-P /check /check
root 2000826 42.0 0.0 224108 4368 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/aarch64-binfmt-P /check /check
root 2000836 0.0 0.0 222684 3596 ? Rl 11:44 0:00 /usr/libexec/qemu-binfmt/riscv64-binfmt-P /check /check
root 2000842 0.0 0.0 223188 4420 ? Rl 11:45 0:00 /usr/libexec/qemu-binfmt/ppc64le-binfmt-P /check /check
root 2000848 0.0 0.0 222396 3444 ? Rl 11:45 0:00 /usr/libexec/qemu-binfmt/s390x-binfmt-P /check /check
root 2000855 32.0 0.0 223492 3604 ? Rl 11:45 0:00 /usr/libexec/qemu-binfmt/mips64el-binfmt-P /check /check
root 2000861 0.0 0.0 223500 3832 ? Rl 11:45 0:00 /usr/libexec/qemu-binfmt/mips64-binfmt-P /check /check
The above was seen when building:
FROM scratch
COPY base-a.txt /base.txt
LABEL base=a
With buildx:
docker buildx build --platform "linux/amd64,linux/arm64,linux/arm/v7,linux/arm/v6" ...
With a docker-container driver:
$ docker buildx ls
NAME/NODE DRIVER/ENDPOINT STATUS PLATFORMS
container docker-container
container0 unix:///var/run/docker.sock inactive
localhost * docker-container
localhost0 unix:///var/run/docker.sock running linux/amd64, linux/arm64, linux/riscv64, linux/ppc64le, linux/s390x, linux/386, linux/mips64le, linux/mips64, linux/arm/v7, linux/arm/v6
default docker
default default running linux/amd64, linux/arm64, linux/riscv64, linux/ppc64le, linux/s390x, linux/386, linux/arm/v7, linux/arm/v6
Running on the 20.10.18 build of docker:
$ docker version
Client: Docker Engine - Community
Version: 20.10.18
API version: 1.41
Go version: go1.18.6
Git commit: b40c2f6
Built: Thu Sep 8 23:12:20 2022
OS/Arch: linux/amd64
Context: default
Experimental: true
Server: Docker Engine - Community
Engine:
Version: 20.10.18
API version: 1.41 (minimum version 1.12)
Go version: go1.18.6
Git commit: e42327a
Built: Thu Sep 8 23:10:02 2022
OS/Arch: linux/amd64
Experimental: true
containerd:
Version: 1.6.8
GitCommit: 9cd3357b7fd7218e4aec3eae239db1f68a5a6ec6
runc:
Version: 1.1.4
GitCommit: v1.1.4-0-g5fd4c4d
docker-init:
Version: 0.19.0
GitCommit: de40ad0
$ docker buildx version
github.com/docker/buildx v0.8.2
Since this involves creating a tempdir, writing a binary, and executing that binary with an interpreter, ideally this would only be called once, and only if needed for a user query or running a step that needs an interpreter (like a RUN step in a Dockerfile for a platform other than the local platform).
An example of a call that doesn't make sense to me is:
https://github.com/moby/buildkit/blob/61307b8f2e73d681721b51856c10cb8606e5ea70/cmd/buildkitd/main.go#L701
That gets run just after a cached call to w.Platforms. Either the Platforms call shouldn't be cached or we don't need the immediate follow up call to WarnIfUnsupported.
The line you linked only gets called once on daemon boot.
But there are other places where this gets called. It needs to be called every time you do workers ls (equivalent buildx inspect) and also when starting a build with unknown platform. This is because any changes to emulators should be picked up automatically without requiring buildkitd restart.
There seems to be something in your system as well as these invocations should be very fast as they are binaries with literally 2 assembly instructions.
The line you linked only gets called once on daemon boot.
Yup, but it did the same work on line 699 if it wasn't cached already (which it wouldn't be on startup), so it's 2x the calls.
There seems to be something in your system as well as these invocations should be very fast as they are binaries with literally 2 assembly instructions.
Entirely possible my system needs a replace/rebuild. I suspect it's more the fork/exec and qemu running the interpreter, than the assembly itself. An arm64 build takes 10x the time of the same amd64 build on my host, so there's definitely some qemu overhead on my system. The behavior also isn't consistent, sometimes it's only an extra second or two, other times it's hanging for 20 seconds, which I suspect has more to do with whether it's launching buildkitd or it was already running. But it's been noticeable since I tried out the 22.06 beta, and now with the 20.10.18 release.
What timings do you see when invoking this check command manually? Have you been able to reproduce long times or high CPU? Have you tried if using some other binfmt installation makes a difference?
Using the following check_test.go:
package archutil
import "testing"
func BenchmarkSupportedPlatforms(b *testing.B) {
for n := 0; n < b.N; n++ {
pl := SupportedPlatforms(true)
if len(pl) < 5 {
b.Errorf("not enough platforms: %v", pl)
}
}
}
And running the test as root (for the chroot), I'm getting:
BenchmarkSupportedPlatforms-8 1438 16034324 ns/op
So it's not taking the over 0.5 sec for some platforms that I'm seeing during the docker builds. The standalone binaries are similarly fast.
$ time for file in bin/*; do echo $file; ./$file; done
bin/386
bin/amd64
bin/arm
bin/arm64
bin/mips64
bin/mips64le
bin/ppc64le
bin/riscv64
bin/s390x
real 0m0.098s
user 0m0.026s
sys 0m0.073s
I'll keep digging to see if I can track down the long startup times.