Bake: Cache of child target gets invalidated by COPY in parent

[flozzone]

Contributing guidelines

• I've read the contributing guidelines and wholeheartedly agree

I've found a bug and checked that ...

• ... the documentation does not mention anything about my problem
• ... there are no open or closed issues that are related to my problem

Description

Building cached chained image with bake invalidates child layer caches if parent contains a COPY command. Running the example bake build a second time results in different image Ids for image2 images (A vs B), even though first run cached layers for image2.

• When removing the COPY line in 1.Dockerfile both image2 (A and B) are the same.
• All preceding layers from image1 are always the same
• Setting SOURCE_DATE_EPOCH=1 has no impact
• Setting BUILDX_NO_DEFAULT_ATTESTATIONS=1 has no impact
• Setting BUILDX_GIT_INFO=0 has no impact
• Using different cache mode flags mode=min or mode=max has no impact

Possibly related to:

• cache of child imgs gets busted w/o change in COPYd file in parent image #1244
• Unable to produce consistent digest id even with cache provided #1219
• bake cache misses with multiple targets #414

Minimal reproducer

Reproducer: https://github.com/flozzone/docker-bake-invalidate-child-cache builds the above bake file twice using a common cache between runs A and B:

prune_cache
recreate_builder
build "${RUN_ID}-A"
recreate_builder
build "${RUN_ID}-B"

compare_image "image1"
compare_image "image2"

Usage: ./test.sh RUN_ID

• RUN_ID: ID of the run. Should be changed when running multiple times. Used to organize debug output.

A refers to the images built from first run
B refers to the images built from second run

Usage example:

$ ./test.sh 4

...
/tmp/docker-test-run/4-A-bake.json
/tmp/docker-test-run/4-A-buildkitd.log
/tmp/docker-test-run/4-A.json
/tmp/docker-test-run/4-B-bake.json
/tmp/docker-test-run/4-B-buildkitd.log
/tmp/docker-test-run/4-B.json
✅  image1:4-A and docker-test1:4-B images are the same
❌  image2:4-A and docker-test2:4-B images are not the same

Expected behaviour

The second build should output the same image2 image Id as the first run.

✅  image1:1-A and image1:1-B images are the same
✅  image2:1-A and image2:1-B images are the same

Actual behaviour

The second build outputs a different image2 image Id than the previous run and layers for image2 are not re-used.

✅  image1:1-A and image1:1-B images are the same
❌  image2:1-A and image2:1-B images are not the same

Buildx version

github.com/docker/buildx v0.12.0 542e5d810e4a1a155684f5f3c5bd7e797632a12f

Other versions

• docker version: Docker version 24.0.7, build afdd53b
• docker buildx version: github.com/docker/buildx v0.12.0 542e5d810e4a1a155684f5f3c5bd7e797632a12f
• buildkitd image: moby/buildkit:v0.12.3
• driver: docker-container
• buildkitd-flags: --debug
• cache type: local, no additional cache options

Docker info

Client: Docker Engine - Community
 Version:    24.0.7
 Context:    default
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc.)
    Version:  v0.12.0
    Path:     /usr/libexec/docker/cli-plugins/docker-buildx
  compose: Docker Compose (Docker Inc.)
    Version:  v2.21.0
    Path:     /usr/libexec/docker/cli-plugins/docker-compose
WARNING: Plugin "/usr/libexec/docker/cli-plugins/docker-buildx.bak" is not valid: plugin candidate "buildx.bak" did not match "^[a-z][a-z0-9]*$"

Server:
 Containers: 3
  Running: 3
  Paused: 0
  Stopped: 0
 Images: 6
 Server Version: 24.0.7
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: systemd
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
 runc version: v1.1.10-0-g18a0cb0
 init version: de40ad0
 Security Options:
  apparmor
  seccomp
   Profile: builtin
  cgroupns
 Kernel Version: 6.5.0-13-generic
 Operating System: Ubuntu 23.10
 OSType: linux
 Architecture: x86_64
 CPUs: 16
 Total Memory: 27.22GiB
 Name: [ANONYMIZED]
 ID: [ANONYMIZED]
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

Builders list

CNAME/NODE    DRIVER/ENDPOINT                                                                                    STATUS   BUILDKIT             PLATFORMS
builder *    docker-container                                                                                                                 
  builder0   unix:///var/run/docker.sock                                                                        running  v0.12.3              linux/amd64, linux/amd64/v2, linux/amd64/v3, linux/386                   
default      docker                                                                                                                           
  default    default                                                                                            running  v0.11.7+d3e6c1360f6e linux/amd64, linux/amd64/v2, linux/amd64/v3, linux/386

Configuration

1.Dockerfile

# syntax=docker/dockerfile:1
FROM quay.io/bashell/alpine-python:3
COPY test-copy.txt test-copy.txt

test-copy.txt

2.Dockerfile

# syntax=docker/dockerfile:1
FROM baseapp
RUN echo "test" > test

docker-bake.hcl

group "default" {
  targets = [ "image1", "image2"]
}

variable "TAG" {}

variable "CACHE_DIR" {
  default = "/tmp/docker-test-cache"
}

target "image1" {
  context    = "."
  dockerfile = "1.Dockerfile"
  cache-to   = ["type=local,dest=${CACHE_DIR}/cache1"]
  cache-from = ["type=local,src=${CACHE_DIR}/cache1"]
  tags       = ["image1:${TAG}"]
}

target "image2" {
  context    = "."
  dockerfile = "2.Dockerfile"
  contexts   = {
    baseapp = "target:image1"
  }
  cache-to   = ["type=local,dest=${CACHE_DIR}/cache2"]
  cache-from = ["type=local,src=${CACHE_DIR}/cache2"]
  tags       = ["image2:${TAG}"]
}

Build logs

time="2023-11-29T12:25:15Z" level=info msg="auto snapshotter: using overlayfs"
time="2023-11-29T12:25:15Z" level=warning msg="using host network as the default"
time="2023-11-29T12:25:15Z" level=info msg="found worker \"q8t4u75a02iah4g29l4f2i5i9\", labels=map[org.mobyproject.buildkit.worker.executor:oci org.mobyproject.buildkit.worker.hostname:7462f1f4096b org.mobyproject.buildkit.worker.network:host org.mobyproject.buildkit.worker.oci.process-mode:sandbox org.mobyproject.buildkit.worker.selinux.enabled:false org.mobyproject.buildkit.worker.snapshotter:overlayfs], platforms=[linux/amd64 linux/amd64/v2 linux/amd64/v3 linux/386]"
time="2023-11-29T12:25:15Z" level=warning msg="skipping containerd worker, as \"/run/containerd/containerd.sock\" does not exist"
time="2023-11-29T12:25:15Z" level=info msg="found 1 workers, default=\"q8t4u75a02iah4g29l4f2i5i9\""
time="2023-11-29T12:25:15Z" level=warning msg="currently, only the default worker can be used."
time="2023-11-29T12:25:15Z" level=info msg="running server on /run/buildkit/buildkitd.sock"
time="2023-11-29T12:25:15Z" level=debug msg="session started" spanID=808f2b0860d0b17a traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="session finished: <nil>" spanID=808f2b0860d0b17a traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="session started" spanID=5a8c51d53c0b9a04 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="skipping invalid cache export mode: " spanID=0b6fd5089b26248f traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="new ref for local: 7pejsy4f82gjt8dc05z2362j6" span="[internal] load build definition from 1.Dockerfile" spanID=20e61815d05e5bf3 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="diffcopy took: 1.956955ms" span="[internal] load build definition from 1.Dockerfile" spanID=ce5800c7117928fc traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="saved 7pejsy4f82gjt8dc05z2362j6 as dockerfile:dockerfile:docker-bake-invalidate-child-cache:626dcb2aac370ce5" span="[internal] load build definition from 1.Dockerfile" spanID=20e61815d05e5bf3 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg=resolving host=registry-1.docker.io spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="do request" host=registry-1.docker.io request.header.accept="application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=HEAD spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1"
time="2023-11-29T12:25:15Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=160 response.header.content-type=application/json response.header.date="Wed, 29 Nov 2023 12:25:15 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=62.178.188.41 response.header.strict-transport-security="max-age=31536000" response.header.www-authenticate="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:docker/dockerfile:pull\"" response.status="401 Unauthorized" spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1"
time="2023-11-29T12:25:15Z" level=debug msg=Unauthorized header="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:docker/dockerfile:pull\"" host=registry-1.docker.io spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:15Z" level=debug msg="do request" host=registry-1.docker.io request.header.accept="application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=HEAD spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1"
time="2023-11-29T12:25:16Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=8404 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Wed, 29 Nov 2023 12:25:16 GMT" response.header.docker-content-digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=62.178.188.41 response.header.etag="\"sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1"
time="2023-11-29T12:25:16Z" level=debug msg=resolved desc.digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" host=registry-1.docker.io spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg=fetch digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json size=8404 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg="do request" digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json request.header.accept="application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=GET size=8404 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021"
time="2023-11-29T12:25:16Z" level=debug msg="fetch response received" digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json response.header.content-length=8404 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Wed, 29 Nov 2023 12:25:16 GMT" response.header.docker-content-digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=62.178.188.41 response.header.etag="\"sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" size=8404 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021"
time="2023-11-29T12:25:16Z" level=debug msg=fetch digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json size=482 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg="do request" digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json request.header.accept="application/vnd.oci.image.manifest.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=GET size=482 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e"
time="2023-11-29T12:25:16Z" level=debug msg="fetch response received" digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json response.header.content-length=482 response.header.content-type=application/vnd.oci.image.manifest.v1+json response.header.date="Wed, 29 Nov 2023 12:25:16 GMT" response.header.docker-content-digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=62.178.188.41 response.header.etag="\"sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" size=482 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e"
time="2023-11-29T12:25:16Z" level=debug msg=fetch digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json size=1271 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg="do request" digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json request.header.accept="application/vnd.oci.image.config.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=GET size=1271 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/blobs/sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89"
time="2023-11-29T12:25:16Z" level=debug msg="fetch response received" digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json response.header.accept-ranges=bytes response.header.age=119440 response.header.cache-control="public, max-age=14400" response.header.cf-cache-status=HIT response.header.cf-ray=82dad51848d0c282-VIE response.header.connection=keep-alive response.header.content-length=1271 response.header.content-type=application/octet-stream response.header.date="Wed, 29 Nov 2023 12:25:16 GMT" response.header.etag="\"c672f7caa35401d1206dcc25158dabb0\"" response.header.expires="Wed, 29 Nov 2023 16:25:16 GMT" response.header.last-modified="Wed, 12 Jul 2023 22:22:37 GMT" response.header.server=cloudflare response.header.vary=Accept-Encoding response.header.x-amz-id-2="gc9J991urP+gxTR1KHhg5WXO8Sf6zQ5rSGDh8bVwT2R1d01hlyewR1PnMk8WaJ0jfuAil8ZXCSo=" response.header.x-amz-request-id=4QMG0HCMW1GT1V5T response.header.x-amz-server-side-encryption=AES256 response.header.x-amz-version-id=EhNMISiBv2LVkOSoeh1cNpabFCp6QxVB response.status="200 OK" size=1271 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/blobs/sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89"
time="2023-11-29T12:25:16Z" level=debug msg=fetch digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json size=8404 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg=fetch digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json size=482 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg=fetch digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json size=1271 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg=fetch digest="sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=11796420 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:16Z" level=debug msg="do request" digest="sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232" mediatype=application/vnd.oci.image.layer.v1.tar+gzip request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=containerd/1.7.2+unknown request.method=GET size=11796420 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/blobs/sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232"
time="2023-11-29T12:25:17Z" level=debug msg="fetch response received" digest="sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232" mediatype=application/vnd.oci.image.layer.v1.tar+gzip response.header.accept-ranges=bytes response.header.age=1837669 response.header.cache-control="public, max-age=14400" response.header.cf-cache-status=HIT response.header.cf-ray=82dad5198a4cc282-VIE response.header.connection=keep-alive response.header.content-length=11796420 response.header.content-type=application/octet-stream response.header.date="Wed, 29 Nov 2023 12:25:17 GMT" response.header.etag="\"7900e017752b00e0a6c9003273d20135\"" response.header.expires="Wed, 29 Nov 2023 16:25:17 GMT" response.header.last-modified="Wed, 12 Jul 2023 22:22:31 GMT" response.header.server=cloudflare response.header.vary=Accept-Encoding response.header.x-amz-id-2="QiW7XfAGAMQQRdQLfSLsX8AU2GFAJJVSAtGkXIwA0BzXyJeD4iECuugkfkG4KEhI0pnVSXUSYAU=" response.header.x-amz-request-id=MA34CM7R52425CF2 response.header.x-amz-server-side-encryption=AES256 response.header.x-amz-version-id=chJkGx1pzfDz_MnqTz_BpSJLzn61zGA2 response.status="200 OK" size=11796420 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/blobs/sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232"
time="2023-11-29T12:25:17Z" level=debug msg="using pigz for decompression"
time="2023-11-29T12:25:17Z" level=debug msg="diff applied" d=85.435642ms digest="sha256:9d9c93f4b00be908ab694a4df732570bced3b8a96b7515d70ff93402179ad232" media=application/vnd.oci.image.layer.v1.tar+gzip size=11796420 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:17Z" level=debug msg="serving grpc connection" spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:17Z" level=debug msg="> creating fimvqwiz9v2mcijfebt6sh3sp [/bin/dockerfile-frontend]" spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:17Z" level=debug msg=resolving host=quay.io spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:17Z" level=debug msg="do request" host=quay.io request.header.accept="application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=HEAD spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://quay.io/v2/bashell/alpine-python/manifests/3"
time="2023-11-29T12:25:18Z" level=debug msg="fetch response received" host=quay.io response.header.connection=keep-alive response.header.content-length=1157 response.header.content-type=application/vnd.docker.distribution.manifest.v2+json response.header.date="Wed, 29 Nov 2023 12:25:18 GMT" response.header.docker-content-digest="sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e" response.header.server=nginx/1.20.1 response.header.strict-transport-security="max-age=63072000; preload" response.header.vary=Cookie response.header.x-frame-options=DENY response.status="200 OK" spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://quay.io/v2/bashell/alpine-python/manifests/3"
time="2023-11-29T12:25:18Z" level=debug msg=resolved desc.digest="sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e" host=quay.io spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg=fetch digest="sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e" mediatype=application/vnd.docker.distribution.manifest.v2+json size=1157 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="do request" digest="sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e" mediatype=application/vnd.docker.distribution.manifest.v2+json request.header.accept="application/vnd.docker.distribution.manifest.v2+json, */*" request.header.user-agent=buildkit/v0.12 request.method=GET size=1157 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://quay.io/v2/bashell/alpine-python/manifests/sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e"
time="2023-11-29T12:25:18Z" level=debug msg="fetch response received" digest="sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e" mediatype=application/vnd.docker.distribution.manifest.v2+json response.header.connection=keep-alive response.header.content-length=1157 response.header.content-type=application/vnd.docker.distribution.manifest.v2+json response.header.date="Wed, 29 Nov 2023 12:25:18 GMT" response.header.docker-content-digest="sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e" response.header.server=nginx/1.20.1 response.header.strict-transport-security="max-age=63072000; preload" response.header.vary=Cookie response.header.x-frame-options=DENY response.status="200 OK" size=1157 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://quay.io/v2/bashell/alpine-python/manifests/sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e"
time="2023-11-29T12:25:18Z" level=debug msg=fetch digest="sha256:2f803c01d87d5f3f9f96290587bbd859dc0f610431ab6825081fd3c1497e0f3a" mediatype=application/vnd.docker.container.image.v1+json size=2698 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="do request" digest="sha256:2f803c01d87d5f3f9f96290587bbd859dc0f610431ab6825081fd3c1497e0f3a" mediatype=application/vnd.docker.container.image.v1+json request.header.accept="application/vnd.docker.container.image.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=GET size=2698 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://quay.io/v2/bashell/alpine-python/blobs/sha256:2f803c01d87d5f3f9f96290587bbd859dc0f610431ab6825081fd3c1497e0f3a"
time="2023-11-29T12:25:18Z" level=debug msg="fetch response received" digest="sha256:2f803c01d87d5f3f9f96290587bbd859dc0f610431ab6825081fd3c1497e0f3a" mediatype=application/vnd.docker.container.image.v1+json response.header.accept-ranges=bytes response.header.access-control-allow-methods="GET, POST, PUT, DELETE, OPTIONS" response.header.access-control-allow-origin="*" response.header.age=6849 response.header.cache-control="max-age=1500" response.header.cf-cache-status=HIT response.header.cf-ray=82dad523cd6e5aef-VIE response.header.connection=keep-alive response.header.content-length=2698 response.header.content-type=binary/octet-stream response.header.date="Wed, 29 Nov 2023 12:25:18 GMT" response.header.etag="\"3163d90e63d68d1278e6b2ebbd762fb6-1\"" response.header.expires="Wed, 29 Nov 2023 16:25:18 GMT" response.header.last-modified="Tue, 28 Apr 2020 10:01:16 GMT" response.header.server=cloudflare response.header.vary=Accept-Encoding response.header.x-amz-id-2="cbE96seR+2frXES5Nu0Xrxmkqqz34l0N00cbOY3KR8Ar9FMnuhpLxGRhrdHbJoT04zKzGTFZ4fU=" response.header.x-amz-replication-status=REPLICA response.header.x-amz-request-id=HDCX48F8G1EGFFQ0 response.header.x-amz-server-side-encryption=AES256 response.header.x-amz-storage-class=INTELLIGENT_TIERING response.header.x-amz-version-id=5Idkf6SNyu0CGHEUBuUwFhnOy1Cn4YvW response.status="200 OK" size=2698 spanID=2de48becf6dab694 traceID=a402701ede544afad1e165ab932fcf94 url="https://quay.io/v2/bashell/alpine-python/blobs/sha256:2f803c01d87d5f3f9f96290587bbd859dc0f610431ab6825081fd3c1497e0f3a"
time="2023-11-29T12:25:18Z" level=debug msg=fetch digest="sha256:d47b81ce7e566aa881b8a3064d3f55493fe6f782b31334dd7537c921c7b57f8e" mediatype=application/vnd.docker.distribution.manifest.v2+json size=1157 spanID=c670c989bef0b4d1 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg=fetch digest="sha256:2f803c01d87d5f3f9f96290587bbd859dc0f610431ab6825081fd3c1497e0f3a" mediatype=application/vnd.docker.container.image.v1+json size=2698 spanID=c670c989bef0b4d1 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="new ref for local: dco7z2jpefrvfwqe3f0vawb5m" span="[internal] load build context" spanID=fca6e46a9da251f6 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="diffcopy took: 1.456875ms" span="[internal] load build context" spanID=5a0cdc41c31e7454 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="saved dco7z2jpefrvfwqe3f0vawb5m as context:context:docker-bake-invalidate-child-cache:626dcb2aac370ce5" span="[internal] load build context" spanID=fca6e46a9da251f6 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="load cache for [2/2] COPY test-copy.txt test-copy.txt with sha256:508d74f7cec7d37ed93a0542cfca5637e03c561b4ad2ad1fd40e9b66cd33190f"
time="2023-11-29T12:25:18Z" level=debug msg="session started" spanID=9796b311ed7d9d49 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="skipping invalid cache export mode: " spanID=1116c73747b93a96 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg=fetch span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="diff applied" d=48.08545ms digest="sha256:395d873e3f39aca0f296f8502629c6ece454de1c483033a3fbed63f1ed9cb719" media=application/vnd.oci.image.layer.v1.tar+gzip size=2886668 span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg=fetch span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="diff applied" d=17.445778ms digest="sha256:ae90af469fbdda9e80320535dbe97f45e19f967de9615fa358fd4fe756ea295c" media=application/vnd.oci.image.layer.v1.tar+gzip size=779177 span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="not reusing ref 7pejsy4f82gjt8dc05z2362j6 for local: 7pejsy4f82gjt8dc05z2362j6 is locked: locked" span="[internal] load build definition from 2.Dockerfile" spanID=108563c02a334949 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg=fetch span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="diff applied" d=1.173303ms digest="sha256:543b46ef632ebc35f5fbeafad2f8f255962d9f69c1e7671e949c05d5e41fcfb6" media=application/vnd.oci.image.layer.v1.tar+gzip size=568 span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="new ref for local: ot2kaiauct1cqhqqxrkd1hmx3" span="[internal] load build definition from 2.Dockerfile" spanID=108563c02a334949 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="diffcopy took: 1.573555ms" span="[internal] load build definition from 2.Dockerfile" spanID=fcbb2a8be27ba5ba traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg="saved ot2kaiauct1cqhqqxrkd1hmx3 as dockerfile:dockerfile:docker-bake-invalidate-child-cache:626dcb2aac370ce5" span="[internal] load build definition from 2.Dockerfile" spanID=108563c02a334949 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:18Z" level=debug msg=fetch span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg="diff applied" d=551.039073ms digest="sha256:32152f8dd49674ba3a5f84cab173f33c7f9eba663c3e705e96ccf3bcf87a52e6" media=application/vnd.oci.image.layer.v1.tar+gzip size=16849448 span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg=resolving host=registry-1.docker.io spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg="do request" host=registry-1.docker.io request.header.accept="application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.12 request.method=HEAD spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1"
time="2023-11-29T12:25:19Z" level=debug msg=fetch span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg="diff applied" d=1.200795ms digest="sha256:03cfbfe433f3c1536f28892c754533a8f2d425c25ea7b79e13d54e3d59f2c348" media=application/vnd.oci.image.layer.v1.tar+gzip size=135 span="load cache: [2/2] COPY test-copy.txt test-copy.txt" spanID=985cdc47c352cee4 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=8404 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Wed, 29 Nov 2023 12:25:19 GMT" response.header.docker-content-digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=62.178.188.41 response.header.etag="\"sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94 url="https://registry-1.docker.io/v2/docker/dockerfile/manifests/1"
time="2023-11-29T12:25:19Z" level=debug msg=resolved desc.digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" host=registry-1.docker.io spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg=fetch digest="sha256:ac85f380a63b13dfcefa89046420e1781752bab202122f8f50032edf31be0021" mediatype=application/vnd.oci.image.index.v1+json size=8404 spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg=fetch digest="sha256:657fcc512c7369f4cb3d94ea329150f8daf626bc838b1a1e81f1834c73ecc77e" mediatype=application/vnd.oci.image.manifest.v1+json size=482 spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg=fetch digest="sha256:a17ee7fff8f5e97b974f5b48f51647d2cf28d543f2aa6c11aaa0ea431b44bb89" mediatype=application/vnd.oci.image.config.v1+json size=1271 spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg="serving grpc connection" spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:19Z" level=debug msg="> creating jcbhq0n09pgt68m068o39j6l0 [/bin/dockerfile-frontend]" spanID=43fa21f54c8395b2 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg="> creating 216y6cl1icy8vpyplu63gzf23 [/bin/sh -c echo \"test\" > test]" span="[1/2] RUN echo \"test\" > test" spanID=fa831eec49e5555f traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:03cfbfe433f3c1536f28892c754533a8f2d425c25ea7b79e13d54e3d59f2c348" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=135 spanID=0b6fd5089b26248f traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:32152f8dd49674ba3a5f84cab173f33c7f9eba663c3e705e96ccf3bcf87a52e6" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=16849448 spanID=0b6fd5089b26248f traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:395d873e3f39aca0f296f8502629c6ece454de1c483033a3fbed63f1ed9cb719" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=2886668 spanID=0b6fd5089b26248f traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:543b46ef632ebc35f5fbeafad2f8f255962d9f69c1e7671e949c05d5e41fcfb6" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=568 spanID=0b6fd5089b26248f traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:ae90af469fbdda9e80320535dbe97f45e19f967de9615fa358fd4fe756ea295c" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=779177 spanID=0b6fd5089b26248f traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg="session finished: <nil>" spanID=5a8c51d53c0b9a04 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:03cfbfe433f3c1536f28892c754533a8f2d425c25ea7b79e13d54e3d59f2c348" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=135 spanID=1116c73747b93a96 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:27e6360a30e8ba00a1693a828a7b687ebaa93ee3f4026a8ab09e038324c86b29" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=131 spanID=1116c73747b93a96 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:32152f8dd49674ba3a5f84cab173f33c7f9eba663c3e705e96ccf3bcf87a52e6" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=16849448 spanID=1116c73747b93a96 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:395d873e3f39aca0f296f8502629c6ece454de1c483033a3fbed63f1ed9cb719" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=2886668 spanID=1116c73747b93a96 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:543b46ef632ebc35f5fbeafad2f8f255962d9f69c1e7671e949c05d5e41fcfb6" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=568 spanID=1116c73747b93a96 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg=fetch digest="sha256:ae90af469fbdda9e80320535dbe97f45e19f967de9615fa358fd4fe756ea295c" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=779177 spanID=1116c73747b93a96 traceID=a402701ede544afad1e165ab932fcf94
time="2023-11-29T12:25:20Z" level=debug msg="session finished: <nil>" spanID=9796b311ed7d9d49 traceID=a402701ede544afad1e165ab932fcf94

[tonistiigi]

I've confirmed this. Not so clear what might cause this. The issue is likely on buildkit side but let's keep it here for now, as the reproducer is with bake.

[tonistiigi]

A data point that if COPY test-copy.txt test-copy.txt is replaced with RUN apk add git in first Dockerfile then it doesn't seem to reproduce anymore.

[flozzone]

And in any case both the parent image1 always have the same ID between both runs A and B. Even if image1 has a COPY command. So image1 doesn't change at all, still a COPY in it causes the image2 target to not use the cache.

I've now tried with older versions of buildkit down to v0.7.2, but the problem stays. (Could not test with v0.5.1 anymore, because of a change in how cache files are stored)

[flozzone]

Passing a static image target to image2 baseapp context docker-image://alpine causes the image IDs of both runs to match again.

[flozzone]

@tonistiigi how can I further debug this? If you say that its caused by buildkit, then I should be able to reproduce it with buildkit too. Do you have any hints on how to implement a minimal reproducer based on buildkit only?

[jedevc]

@flozzone the right way to reproduce in buildkit would probably be in an integration test. See https://github.com/moby/buildkit/blob/master/client/client_test.go, for the other tests, and https://github.com/moby/buildkit/blob/master/.github/CONTRIBUTING.md#run-the-unit--and-integration-tests for instructions on running them.

To test if a layer is cached, the general way we do this is to read from /dev/random:
https://github.com/moby/buildkit/blob/4ab32be0cc61c46875054bfbc4d819e1135f1f5a/client/client_test.go#L5036-L5037.

Capturing the exact circumstances the bug happens under might be a bit tricky - you might need to read through buildx's bake code to make sure to do the same number of SolveOpts that bake does.

[kmontg]

I'm also facing this exact issue. The COPY instruction in the parent image seems to invalidate the cache (after a prune) for child images, even when using a separate cache backend.

I've added my own steps to reproduce in https://github.com/kmontg/bake-cache-issue.

This only seems to be a problem on the first build after a cache purge (even with a specified alternative cache backend).

[flozzone]

That seems to be really minimal @kmontg 👍

@jedevc I completely agree with you that a integration test would be the way to go for this issue here. But as you already described this can be bit tricky and I don't have the possibilities to dive into the codebase. I don't even know where to start with a buildkit based reproducer, since this issue involves chained builds and it's not really clear to me how to realize this in buildkit.

I don't know why this issue has not yet attracted more attention, because buildkit advertises caching as an important feature "concurrent, cache-efficient, and Dockerfile-agnostic builder toolkit".

@jedevc , @tonistiigi do you have any suggestions on how to progress here? I will probably not be able to come up with an integration test, but @tonistiigi was able to reproduce this bug and confirmed it.

Should we move this issue to buildkit repo, but still keep the bake based reproducer, preferably the one from @kmontg https://github.com/kmontg/bake-cache-issue

[tonistiigi]

This specific issue should be fixed with #2265 , but there is a more general issue that is causing it, tracked in moby/buildkit#4674 .