for-win
for-win copied to clipboard
docker
Docker build log says "CACHED" even when what it means is SKIPPED
Description
I was having an issue where a docker build seemed to be caching layers even when I had gone to extensive lengths (like docker system prune -a, and even doing a clean install of docker) to ensure that I was building from a clean state. Even when I used --no-cache, it was saying layers were cached. This seemed very bizarre, and Google searches weren't being very helpful.
Eventually, I decided that there was no way it was possibly cached, and figured out that the issue was because Docker was using some sort of lookahead logic, realizing that a later part of the build was going to fail, and fast-failing early. I don't have any issue with this behavior, but it was 100% not clear this was what was happening.
In my case, since the part that was failing was later in the Dockerfile and I was expecting a failure there (and just hadn't gotten to updating that part yet), I was ignoring the fact the build was failing and focused on trying to figure out why earlier layers were being cached when there was no way they should have been cached.
Commenting out that other part that I knew was broken suddenly caused previous parts of the Dockerfile to no longer claim to be cached.
Ultimately, this is more of a design bug than a code bug. It should absolutely not say CACHED unless it means it's actually cached - in this case, it should say SKIPPED or ABORTING something like that. Or just omit the skipped layers from the log, and jump right to the detected problem later in the Dockerfile.
Reproduce
Here's a minimal example of what was triggering this behavior for me:
Dockerfile:
FROM node:18.14.1-alpine AS node-builder
WORKDIR /usr/src/app
# copy just the files needed for configuring dependencies
COPY ["package.json", "yarn.lock", "./"]
# logs were claiming this next line was cached, even though there was no way it was cached because I'd just added this and it had never been run!
RUN yarn run my-script-name
# packages folder doesn't exist, so build expected to fail here
COPY ["./packages", "./packages"]
Expected behavior
if a step/layer is skipped because Docker realizes a file it's supposed to copy doesn't exist, it should indicate it's skipping steps, aborting the build, or just fully omit that section from the log.
docker version
Client: Docker Engine - Community
Cloud integration: v1.0.35+desktop.5
Version: 24.0.7
API version: 1.43
Go version: go1.20.10
Git commit: afdd53b
Built: Thu Oct 26 09:08:17 2023
OS/Arch: linux/amd64
Context: default
Server: Docker Desktop
Engine:
Version: 24.0.7
API version: 1.43 (minimum version 1.12)
Go version: go1.20.10
Git commit: 311b9ff
Built: Thu Oct 26 09:08:02 2023
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.6.25
GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
runc:
Version: 1.1.10
GitCommit: v1.1.10-0-g18a0cb0
docker-init:
Version: 0.19.0
GitCommit: de40ad0
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-desktop.2
Path: /usr/local/lib/docker/cli-plugins/docker-buildx
compose: Docker Compose (Docker Inc.)
Version: v2.23.3-desktop.2
Path: /usr/local/lib/docker/cli-plugins/docker-compose
dev: Docker Dev Environments (Docker Inc.)
Version: v0.1.0
Path: /usr/local/lib/docker/cli-plugins/docker-dev
extension: Manages Docker extensions (Docker Inc.)
Version: v0.2.21
Path: /usr/local/lib/docker/cli-plugins/docker-extension
feedback: Provide feedback, right in your terminal! (Docker Inc.)
Version: 0.1
Path: /usr/local/lib/docker/cli-plugins/docker-feedback
init: Creates Docker-related starter files for your project (Docker Inc.)
Version: v0.1.0-beta.10
Path: /usr/local/lib/docker/cli-plugins/docker-init
sbom: View the packaged-based Software Bill Of Materials (SBOM) for an image (Anchore Inc.)
Version: 0.6.0
Path: /usr/local/lib/docker/cli-plugins/docker-sbom
scan: Docker Scan (Docker Inc.)
Version: v0.26.0
Path: /usr/local/lib/docker/cli-plugins/docker-scan
scout: Docker Scout (Docker Inc.)
Version: v1.2.0
Path: /usr/local/lib/docker/cli-plugins/docker-scout
Server:
Containers: 0
Running: 0
Paused: 0
Stopped: 0
Images: 0
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: cgroupfs
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:
seccomp
Profile: unconfined
cgroupns
Kernel Version: 5.15.133.1-microsoft-standard-WSL2
Operating System: Docker Desktop
OSType: linux
Architecture: x86_64
CPUs: 20
Total Memory: 15.47GiB
Name: docker-desktop
ID: 4e30e950-a999-4f1a-9ab7-20ed06642dbf
Docker Root Dir: /var/lib/docker
Debug Mode: false
HTTP Proxy: http.docker.internal:3128
HTTPS Proxy: http.docker.internal:3128
No Proxy: hubproxy.docker.internal
Experimental: false
Insecure Registries:
hubproxy.docker.internal:5555
127.0.0.0/8
Live Restore Enabled: false
WARNING: daemon is not using the default seccomp profile
Diagnostics ID
225DAB08-088F-4B5D-9122-FD010F1A0C06/20240125224854
Additional Info
Actual log:
#4 [node-builder 1/9] FROM docker.io/library/node:18.14.1-alpine@sha256:e0a779479fca9cf43cae2852291bee70e730ae3ad27fea1211060bd344b696b8
#4 DONE 0.0s
#5 [internal] load build context
#5 transferring context: 7.09kB 0.0s done
#5 DONE 0.0s
#6 [node-builder 2/9] WORKDIR /usr/src/app
#6 CACHED
#7 [node-builder 3/9] RUN apk --no-cache --update add rsync curl
#7 CACHED
#8 [node-builder 4/9] COPY [package.json, yarn.lock, ./]
#8 CACHED
#9 [node-builder 5/9] RUN yarn run my-script-name
#9 CACHED
#10 [node-builder 6/9] COPY [./packages, ./packages]
#10 ERROR: failed to calculate checksum of ref 4e30e950-a999-4f1a-9ab7-20ed06642dbf::p3ptgg363g15z8bsf2hq67apu: "/packages": not found
------
> [node-builder 6/9] COPY [./packages, ./packages]:
------
Dockerfile:58
--------------------
56 | COPY ["package.json", "yarn.lock", "./"]
57 | RUN yarn run my-script-name
58 | >>> COPY ["./packages", "./packages"]
59 |
60 | RUN --mount=type=cache,target=/usr/local/share/.cache/yarn,sharing=locked,id=fc_nodecache \
--------------------
ERROR: failed to solve: failed to compute cache key: failed to calculate checksum of ref 4e30e950-a999-4f1a-9ab7-20ed06642dbf::p3ptgg363g15z8bsf2hq67apu: "/packages": not found
make: *** [Makefile:15: build] Error 1
Example of desired log (partial):
#9 [node-builder 5/9] RUN yarn run my-script-name
#9 SKIPPED: build expected to fail due to missing file (see below)
#10 [node-builder 6/9] COPY [./packages, ./packages]
#10 ERROR: failed to calculate checksum of ref 4e30e950-a999-4f1a-9ab7-20ed06642dbf::p3ptgg363g15z8bsf2hq67apu: "/packages": not found
Alternatively:
#9 ABORTING: build expected to fail due to missing file (see below)
- looks related to https://github.com/moby/buildkit/issues/4535#issuecomment-1881657648
@tonistiigi do you know if there's a tracking issue for that in buildkit?
Just wasted a couple of hours on this one due to the misleading information. I was trying to diagnose a problem with an earlier line so wasn't concerned with the line that was reporting the failure ( I was going to fix that problem after I had sorted the problem in the earlier line).
So we definitely need a better error message to indicate what is going on.
I agree with @FFdhorkin suggestion of a message such as:
#9 SKIPPED: build expected to fail due to missing file (see below)
