buildkit: COPY --from consistently fails with ZFS storage driver

Ok, so I have built docker with this commit https://github.com/jaen/moby/commit/a4ab9f592a802215be69a5463f48d763c7fd8705: and it seems to fix the issue, I can’t reproduce it using the script I posted above anymore.

Made a PR with it, @saiarcot895 thanks a lot for pointing me in the right direction!

Yup, let’s go ahead and close this one 👍

@oramirite I’ve since moved to NixOS so can’t easily test this works for sure, but I think you would just want to use docker-git’s PKGBUILD(see: https://aur.archlinux.org/cgit/aur.git/tree/PKGBUILD?h=docker-git) and change the moby repository (first entry of sources array) to point to my fork (and branch, apparently it would be adding #branch=zfs-driver-fix to the end, cf. https://wiki.archlinux.org/title/VCS_package_guidelines#VCS_sources).

@tonistiigi I see locks on the complete Get(), Put(), and Remove() methods for the overlay, aufs, and devmapper drivers, added in moby/moby@fc1cf19. The critical thing here is that the entire method has a lock (for each ID), so that the above case where one thread is going through Put() and another thread is going through Get() concurrently doesn’t happen.

@saiarcot895 If you compare this with overlay/aufs then afaics there the reference counter logic is always behind an id-based locker.

I have never used buildkit and don’t know anything about its architecture but does it somehow calls Get() and Put() from different processes? Otherwise I cannot explain how it would delete the mountpoint before mounting a different one.

With BuildKit, it is possible for Get() and Put() to be called from different threads within the dockerd process. Additionally, they may be called multiple times in succession with the same ID (i.e. Get() can be called with the same ID 3 times in a row for some cache mount).

Briefly looking at the zfs code, I could maybe see how there can be a race condition related to the mount directory being missing.

Assume that there are two threads, and some layer with ID 824f183 has been mounted once by thread 1. Now, thread 1 wants to unmount it, and thread 2 wants to mount that same layer. Here’s a possible execution sequence which will result in the above error:

1. Thread 2 decrements the refcount for 824f183’s mountpoint from 1 to 0. (When this counter reaches 0, it’ll unmount and remove that directory)
2. Thread 1 increments the refcount for 824f183’s mountpoint from 0 to 1.
3. Thread 2 unmounts 824f183’s mountpoint.
4. Thread 1 creates the mountpoint directory if it doesn’t already exist. (In this case, the directory still exists, so nothing really happens here)
5. Thread 2 removes the mountpoint directory.
6. Thread 1 tries to mount 824f183, but fails, because that directory no longer exists.

In this sequence, the only mutex/lock that is present is in the refcount increment/decrement (this is from code outside of the ZFS file); the rest don’t have any mutexes.

@tonistiigi I think I have a fairly minimal reproduction, a script follows:

#!/usr/bin/env bash

CONTEXT_TAR_PATH="${PWD}/context.tar"

if [ ! -f $CONTEXT_TAR_PATH ]; then
  CONTEXT_TEMP=`mktemp -d`

  echo "test-1" > ${CONTEXT_TEMP}/test-1
  echo "test-2" > ${CONTEXT_TEMP}/test-2

  cat > ${CONTEXT_TEMP}/Dockerfile <<-EODOCKERFILE
    FROM alpine as builder1

    COPY test-1 /test-1

    FROM alpine as builder2

    COPY test-2 /test-2

    FROM alpine

    COPY --from=builder1 /test-1 /stuff/test-1
    COPY --from=builder2 /test-2 /stuff/test-2
EODOCKERFILE

  (
    cd ${CONTEXT_TEMP}
    tar -cf ${CONTEXT_TAR_PATH} .
  )
fi

cat ${CONTEXT_TAR_PATH} | env DOCKER_BUILDKIT=1 docker build -t zfs-issue -

This fails fairly reliably for me if I run docker system prune -a first – sometimes it will just complain about the cachekey thing, sometimes it will also complain about the Dockerfilemissing, but not always, output follows:

╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ docker system prune -a
WARNING! This will remove:
  - all stopped containers
  - all networks not used by at least one container
  - all images without at least one container associated to them
  - all build cache

Are you sure you want to continue? [y/N] y
Deleted Images:
untagged: zfs-issue:latest
deleted: sha256:76dd7cf63e3a55b8b17656fe6d324d837c5a476500143bba7adbd98ae164987d

Deleted build cache objects:
p1hpzx6t74r6cixg2hjgn2xtq
hwa0qgf36d5b3u284cok6gtig
o2fziihelkrw9x72n4ht9ttg7
p1vvnu475t3mzo5beoka6p3tr
f8u5y0dyg1fmy21lcmc40ue0o
7jbwmrynfa00h0s7mqa4tzr3g
8x5ysndfquqd0cfui4ey0adyk
sha256:777b2c648970480f50f5b4d0af8f9a8ea798eea43dbcf40ce4a8c7118736bdcf

Total reclaimed space: 6.435MB
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh
[+] Building 1.8s (5/8)
 => [internal] load remote build context                                                                                                                                                  0.0s
 => copy /context /                                                                                                                                                                       0.1s
 => [internal] load metadata for docker.io/library/alpine:latest                                                                                                                          1.6s
 => CANCELED [builder2 1/2] FROM docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                         0.0s
 => => resolve docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                           0.0s
 => => sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436 1.64kB / 1.64kB                                                                                            0.0s
 => => sha256:074d3636ebda6dd446d0d00304c4454f468237fdacf08fb0eeac90bdbfa1bac7 528B / 528B                                                                                                0.0s
 => => sha256:389fef7118515c70fd6c0e0d50bb75669942ea722ccb976507d7b087e54d5a23 1.47kB / 1.47kB                                                                                            0.0s
 => ERROR [builder2 2/2] COPY test-2 /test-2                                                                                                                                              0.0s
------
 > [builder2 2/2] COPY test-2 /test-2:
------
failed to solve with frontend dockerfile.v0: failed to build LLB: failed to compute cache key: error creating zfs mount: mount airi-storage/local/docker/l1hf17ipwe0d2qrb3ztokt2d1:/var/lib/docker/zfs/graph/l1hf17ipwe0d2qrb3ztokt2d1: no such file or directory
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh                                                                                                                                                                              ↵ 1
[+] Building 0.0s (2/2) FINISHED
 => CACHED [internal] load remote build context                                                                                                                                           0.0s
 => CACHED copy /context /                                                                                                                                                                0.0s
failed to solve with frontend dockerfile.v0: failed to read dockerfile: open /var/lib/docker/tmp/buildkit-mount871595872/Dockerfile: no such file or directory
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh                                                                                                                                                                              ↵ 1
[+] Building 2.5s (9/9) FINISHED
 => CACHED [internal] load remote build context                                                                                                                                           0.0s
 => CACHED copy /context /                                                                                                                                                                0.0s
 => [internal] load metadata for docker.io/library/alpine:latest                                                                                                                          1.5s
 => [builder1 1/2] FROM docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                  0.3s
 => => resolve docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                           0.0s
 => => sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436 1.64kB / 1.64kB                                                                                            0.0s
 => => sha256:074d3636ebda6dd446d0d00304c4454f468237fdacf08fb0eeac90bdbfa1bac7 528B / 528B                                                                                                0.0s
 => => sha256:389fef7118515c70fd6c0e0d50bb75669942ea722ccb976507d7b087e54d5a23 1.47kB / 1.47kB                                                                                            0.0s
 => => sha256:801bfaa63ef2094d770c809815b9e2b9c1194728e5e754ef7bc764030e140cea 2.80MB / 2.80MB                                                                                            0.1s
 => => extracting sha256:801bfaa63ef2094d770c809815b9e2b9c1194728e5e754ef7bc764030e140cea                                                                                                 0.2s
 => [builder1 2/2] COPY test-1 /test-1                                                                                                                                                    0.1s
 => [builder2 2/2] COPY test-2 /test-2                                                                                                                                                    0.1s
 => [stage-2 2/3] COPY --from=builder1 /test-1 /stuff/test-1                                                                                                                              0.1s
 => [stage-2 3/3] COPY --from=builder2 /test-2 /stuff/test-2                                                                                                                              0.1s
 => exporting to image                                                                                                                                                                    0.3s
 => => exporting layers                                                                                                                                                                   0.3s
 => => writing image sha256:87db0be86903b3f1e492adabdfeca3500e210076e7571f43d5ca1cc888f927a5                                                                                              0.0s
 => => naming to docker.io/library/zfs-issue                                                                                                                                              0.0s
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ docker system prune -a
WARNING! This will remove:
  - all stopped containers
  - all networks not used by at least one container
  - all images without at least one container associated to them
  - all build cache

Are you sure you want to continue? [y/N] y
Deleted Images:
untagged: zfs-issue:latest
deleted: sha256:87db0be86903b3f1e492adabdfeca3500e210076e7571f43d5ca1cc888f927a5

Deleted build cache objects:
d3mymyhmxy9z4vteoyeo45h6h
unk5g02w5s9mh0hft9mg7bzw7
me58b0an7ofktojhnblhaeg64
lwb1g48q0sjrhd02as2lqpfd2
rz31uqdv7xnu5m3vd547lxh10
vmwj43sf9e6958y1oory3hzrh
l1hf17ipwe0d2qrb3ztokt2d1
jz6hwy3ytqwkyrd4tsufxxywu
sha256:777b2c648970480f50f5b4d0af8f9a8ea798eea43dbcf40ce4a8c7118736bdcf

Total reclaimed space: 6.445MB
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh
[+] Building 1.6s (5/8)
 => [internal] load remote build context                                                                                                                                                  0.0s
 => copy /context /                                                                                                                                                                       0.1s
 => [internal] load metadata for docker.io/library/alpine:latest                                                                                                                          1.5s
 => CANCELED [builder2 1/2] FROM docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                         0.0s
 => => resolve docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                           0.0s
 => => sha256:389fef7118515c70fd6c0e0d50bb75669942ea722ccb976507d7b087e54d5a23 1.47kB / 1.47kB                                                                                            0.0s
 => => sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436 1.64kB / 1.64kB                                                                                            0.0s
 => => sha256:074d3636ebda6dd446d0d00304c4454f468237fdacf08fb0eeac90bdbfa1bac7 528B / 528B                                                                                                0.0s
 => ERROR [builder2 2/2] COPY test-2 /test-2                                                                                                                                              0.0s
------
 > [builder2 2/2] COPY test-2 /test-2:
------
failed to solve with frontend dockerfile.v0: failed to build LLB: failed to compute cache key: error creating zfs mount: mount airi-storage/local/docker/e5ql1gcedsvzrojshdpxnnztq:/var/lib/docker/zfs/graph/e5ql1gcedsvzrojshdpxnnztq: no such file or directory
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh                                                                                                                                                                              ↵ 1
[+] Building 1.9s (9/9) FINISHED
 => CACHED [internal] load remote build context                                                                                                                                           0.0s
 => CACHED copy /context /                                                                                                                                                                0.0s
 => [internal] load metadata for docker.io/library/alpine:latest                                                                                                                          0.4s
 => [builder2 1/2] FROM docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                  0.3s
 => => resolve docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                           0.0s
 => => sha256:074d3636ebda6dd446d0d00304c4454f468237fdacf08fb0eeac90bdbfa1bac7 528B / 528B                                                                                                0.0s
 => => sha256:389fef7118515c70fd6c0e0d50bb75669942ea722ccb976507d7b087e54d5a23 1.47kB / 1.47kB                                                                                            0.0s
 => => sha256:801bfaa63ef2094d770c809815b9e2b9c1194728e5e754ef7bc764030e140cea 2.80MB / 2.80MB                                                                                            0.1s
 => => sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436 1.64kB / 1.64kB                                                                                            0.0s
 => => extracting sha256:801bfaa63ef2094d770c809815b9e2b9c1194728e5e754ef7bc764030e140cea                                                                                                 0.2s
 => [builder1 2/2] COPY test-1 /test-1                                                                                                                                                    0.1s
 => [builder2 2/2] COPY test-2 /test-2                                                                                                                                                    0.1s
 => [stage-2 2/3] COPY --from=builder1 /test-1 /stuff/test-1                                                                                                                              0.1s
 => [stage-2 3/3] COPY --from=builder2 /test-2 /stuff/test-2                                                                                                                              0.1s
 => exporting to image                                                                                                                                                                    0.9s
 => => exporting layers                                                                                                                                                                   0.9s
 => => writing image sha256:03d3e39c058c783a76e9e6d1f2569721de55cef8fb04fc2c54fc7b5ffe1bda02                                                                                              0.0s
 => => naming to docker.io/library/zfs-issue                                                                                                                                              0.0s
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh
[+] Building 2.0s (9/9) FINISHED
 => CACHED [internal] load remote build context                                                                                                                                           0.0s
 => CACHED copy /context /                                                                                                                                                                0.0s
 => [internal] load metadata for docker.io/library/alpine:latest                                                                                                                          2.0s
 => [builder2 1/2] FROM docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                  0.0s
 => CACHED [builder1 2/2] COPY test-1 /test-1                                                                                                                                             0.0s
 => CACHED [stage-2 2/3] COPY --from=builder1 /test-1 /stuff/test-1                                                                                                                       0.0s
 => CACHED [builder2 2/2] COPY test-2 /test-2                                                                                                                                             0.0s
 => CACHED [stage-2 3/3] COPY --from=builder2 /test-2 /stuff/test-2                                                                                                                       0.0s
 => exporting to image                                                                                                                                                                    0.0s
 => => exporting layers                                                                                                                                                                   0.0s
 => => writing image sha256:03d3e39c058c783a76e9e6d1f2569721de55cef8fb04fc2c54fc7b5ffe1bda02                                                                                              0.0s
 => => naming to docker.io/library/zfs-issue                                                                                                                                              0.0s
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ docker system prune -a
WARNING! This will remove:
  - all stopped containers
  - all networks not used by at least one container
  - all images without at least one container associated to them
  - all build cache

Are you sure you want to continue? [y/N] y
Deleted Images:
untagged: zfs-issue:latest
deleted: sha256:03d3e39c058c783a76e9e6d1f2569721de55cef8fb04fc2c54fc7b5ffe1bda02

Deleted build cache objects:
rto19x1hf0pki9eio1kacywv5
6rsyu03778egdzbbra4vhy4eh
jk2zpsl1veiputkq87a0axurg
xxbqejwh5ap5vzcs8t36iwelj
6ngc4b57grwplbkmfh37w1a2o
e5ql1gcedsvzrojshdpxnnztq
o8o5rr0ty3sgj4e87ei0j3xls
khpp8iekxfzdozyy1tjws3xi8
sha256:777b2c648970480f50f5b4d0af8f9a8ea798eea43dbcf40ce4a8c7118736bdcf

Total reclaimed space: 6.445MB
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh
[+] Building 1.6s (5/8)
 => [internal] load remote build context                                                                                                                                                  0.0s
 => copy /context /                                                                                                                                                                       0.1s
 => [internal] load metadata for docker.io/library/alpine:latest                                                                                                                          1.4s
 => CANCELED [builder2 1/2] FROM docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                         0.0s
 => => resolve docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                           0.0s
 => => sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436 1.64kB / 1.64kB                                                                                            0.0s
 => => sha256:074d3636ebda6dd446d0d00304c4454f468237fdacf08fb0eeac90bdbfa1bac7 528B / 528B                                                                                                0.0s
 => => sha256:389fef7118515c70fd6c0e0d50bb75669942ea722ccb976507d7b087e54d5a23 1.47kB / 1.47kB                                                                                            0.0s
 => ERROR [builder2 2/2] COPY test-2 /test-2                                                                                                                                              0.0s
------
 > [builder2 2/2] COPY test-2 /test-2:
------
failed to solve with frontend dockerfile.v0: failed to build LLB: failed to compute cache key: error creating zfs mount: mount airi-storage/local/docker/5le21f5z98do0po1ubji8a6pq:/var/lib/docker/zfs/graph/5le21f5z98do0po1ubji8a6pq: no such file or directory
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh                                                                                                                                                                              ↵ 1
[+] Building 0.0s (2/2) FINISHED
 => CACHED [internal] load remote build context                                                                                                                                           0.0s
 => CACHED copy /context /                                                                                                                                                                0.0s
failed to solve with frontend dockerfile.v0: failed to read dockerfile: open /var/lib/docker/tmp/buildkit-mount536567859/Dockerfile: no such file or directory
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$ ./repro.sh                                                                                                                                                                              ↵ 1
[+] Building 1.9s (9/9) FINISHED
 => CACHED [internal] load remote build context                                                                                                                                           0.0s
 => CACHED copy /context /                                                                                                                                                                0.0s
 => [internal] load metadata for docker.io/library/alpine:latest                                                                                                                          0.4s
 => [builder2 1/2] FROM docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                  0.4s
 => => resolve docker.io/library/alpine@sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436                                                                           0.0s
 => => sha256:3c7497bf0c7af93428242d6176e8f7905f2201d8fc5861f45be7a346b5f23436 1.64kB / 1.64kB                                                                                            0.0s
 => => sha256:074d3636ebda6dd446d0d00304c4454f468237fdacf08fb0eeac90bdbfa1bac7 528B / 528B                                                                                                0.0s
 => => sha256:389fef7118515c70fd6c0e0d50bb75669942ea722ccb976507d7b087e54d5a23 1.47kB / 1.47kB                                                                                            0.0s
 => => sha256:801bfaa63ef2094d770c809815b9e2b9c1194728e5e754ef7bc764030e140cea 2.80MB / 2.80MB                                                                                            0.1s
 => => extracting sha256:801bfaa63ef2094d770c809815b9e2b9c1194728e5e754ef7bc764030e140cea                                                                                                 0.2s
 => [builder2 2/2] COPY test-2 /test-2                                                                                                                                                    0.1s
 => [builder1 2/2] COPY test-1 /test-1                                                                                                                                                    0.1s
 => [stage-2 2/3] COPY --from=builder1 /test-1 /stuff/test-1                                                                                                                              0.1s
 => [stage-2 3/3] COPY --from=builder2 /test-2 /stuff/test-2                                                                                                                              0.1s
 => exporting to image                                                                                                                                                                    0.8s
 => => exporting layers                                                                                                                                                                   0.8s
 => => writing image sha256:5f9c5af7e4ad6219bf80b9a9e8d9c69b920560081bb95eeb8bf4c15f537d6e32                                                                                              0.0s
 => => naming to docker.io/library/zfs-issue                                                                                                                                              0.0s
╭─jaen@airi /home/jaen/Projects/work/zfs-issue  ‹system›
╰─$

Any idea how hard this could be to fix? I’m using ZFS and I need to use buildkit with it, so it’s a fairly blocking issue for me.

Please provide a reproducible testcase.