Open scottatron opened 2 years ago
tonistiigi
commented
2 years ago Hmm, I thought this should show stack trace when debug is enabled.
The most logical way where this error happens in during pull, for example with a corrupted manifest that doesn't match the size of bytes given with HTTP requests. Don't see exactly where but it comes from containerd library that deals with reading layer/manifest blob data, either from registry or from local copies.
bglimepoint
commented
2 years ago Hi @tonistiigi,
Thanks for your time and help :-)
We've done some more diagnosing and have some more understanding of this issue.
We ascertained that with older versions of buildkit (<= 0.9.2) we get the following clearer error:
error: failed to solve: failed to compute cache key: failed commit on ref "layer-sha256:929d4d417adbdafe947076e47161e10f88afcb63716ff7ec3205bc8f62be085f": "layer-sha256:929d4d417adbdafe947076e47161e10f88afcb63716ff7ec3205bc8f62be085f" failed size validation: 894478743 != 894478744: failed preconditionWhich pointed us to https://github.com/containerd/containerd/commit/2458afeb131b8942907b1c62a9b1751387e2ed08 as the cause of the change of error message (as a side thought, the older message does seem clearer than the new error message that was introduced in that commit).
This pointed us towards the likely issue in the registry we're using (Trow):
root@image-registry-0:/# cat /data/blobs/sha256/5072fe67945c72d2d60ee06fb580c0ec7d3897ef20d48673a5c2f59bf6eadad8
{
"schemaVersion": 2,
"mediaType": "application/vnd.docker.distribution.manifest.v2+json",
"config": {
"mediaType": "application/vnd.docker.container.image.v1+json",
"size": 5692,
"digest": "sha256:ec31f68666cce6e0086f16f3f1aaacff0a7afac1898c3c3f0a760c73ad2c86fb"
},
"layers": [
{
"mediaType": "application/vnd.docker.image.rootfs.diff.tar.gzip",
"size": 894478744, <---------------------------------------------------------------- this size here
"digest": "sha256:929d4d417adbdafe947076e47161e10f88afcb63716ff7ec3205bc8f62be085f"
}
]
}
root@image-registry-0:/# du -b /data/blobs/sha256/929d4d417adbdafe947076e47161e10f88afcb63716ff7ec3205bc8f62be085f
894478743 /data/blobs/sha256/929d4d417adbdafe947076e47161e10f88afcb63716ff7ec3205bc8f62be085fNoting the difference in size aligning with the error.
Curiously, as a note, the image works correctly when using docker build with DOCKER_BUILDKIT=1 or DOCKER_BUILDKIT=0; but fails when using buildctl.
We're still poking around, but thought this might be of interest,
tonistiigi
commented
2 years ago Curiously, as a note, the image works correctly when using docker build with DOCKER_BUILDKIT=1 or DOCKER_BUILDKIT=0; but fails when using buildctl.
Yes, docker does not validate the size property.
If the data in your registry does not match the manifest then your image is corrupted and you need to look into how it was created or if it got corrupted when it was pushed. Eg. check if the sha256 of the blob with the missing byte is correct.
You can also look into https://github.com/docker/for-linux/issues/1296 for similar symptoms with misbehaving registry.
bglimepoint
commented
2 years ago Thanks for that @tonistiigi, that issue looks very plausibly like it could be the case here, will have a closer look :+1:
bglimepoint
commented
2 years ago Thanks @tonistiigi that's 100% it -> the registry we're using has that same off-by-one error (0-894478743 with it, vs 0-894478742 with the Docker registry image)
Just as an aside.... To my eye, the manifest is created by the client based on that range header - hence the server response sending the wrong range header value means that the manifest that the client PUTs is dependent on that value; hence the registry being able to introduce this bug. Is that right? Just curious :-) and would be interesting for tracking the issue in the registry we're using. (Also curious that the client doesn't keep track of the data payload size itself rather than the registry tracking it? :shrug: :-) )
tonistiigi
commented
2 years ago Depends on how you push the image. Eg. this kind of error where the size in the manifest changes depending on registry behavior can not happen when pushing with buildkit.
As I wrote in docker/for-linux#1296 , https://github.com/distribution/distribution could do a better validation of these cases, detect the wrong behavior and give a proper error to the user. Feel free to create issues for that. This is the library still used when you do docker push.
bglimepoint
commented
2 years ago Thank you for all your time @tonistiigi! That all makes sense :+1:
Happy to close this issue now - although did have one thought/question,
It seems that buildkit isn't removing the corrupt image/manifest - should it do so?
We tried using the upstream centos using the broken registry, which failed as expect. But then we tried using it from Docker hub (i.e. FROM centos) and still saw an error, for example error: failed to solve: failed to compute cache key: failed to copy: httpReadSeeker: failed open: unexpected status code https://registry-1.docker.io/v2/library/centos/blobs/sha256:a1d0c75327776413fa0db9ed3adcdbadedc95a662eb1d360dad82bb913f8a1d1: 416 Requested Range Not Satisfiable
Should the manifest be removed for the corrupt image to ensure that the image would work from the unbroken registry?
mbentley
commented
2 years ago I seem to hit failed to compute cache key: failed to read expected number of bytes: unexpected EOF errors once or twice a week. The common factor for me when this happens is that I use a v2 registry as a cache to Docker Hub. Running a garbage collection allows the next build of the image to succeed. The odd thing is that I have started to run gc right before I run my daily builds so my image builds should be the only thing that is pulling through the cache on my network at that time.
scottt732
commented
1 year ago @mbentley I stumbled on this issue while looking over something happening now/that I ran into 2 years ago. Out of curiosity, do you have any other signs of download failures or general connectivity issues from the containers and/or host when this happens? Do your containers run in NAT mode? Any control plane running or service mesh involved? On our end, I think this may have to do with a connectivity issue that occurs mid-download. I'm seeing different symptoms on Windows & Linux but it seems to be occurring on both.
mbentley
commented
1 year ago I can't say that I've seen the issue in a long time - not sure specifically what seemed to resolve it but back then, I was using docker daemons running with macvlan and then the buildkit config was to use host networking (of the docker engine in a container).
For the last good while, I have been running my buildkit containers with macvlan on a Docker engine.
mbentley
commented
2 months ago Sorry in advance because this is going to be a great wall of logs. I am starting to see these errors occur more frequently as of late. They're happening fairly randomly as to when an image cache appears to be broken or unusable. I am not sure when exactly they started becoming more frequent again but I am currently running buildkit v0.15.2. Previously I would try to run a garbage collection on my registry that is hosting the build cache, clear the builder's cache and it seems as if it would resolve the issue but lately, it seems like the way for me to resolve it is to rebuild the image, ignoring the cache. The thing that I find strange is that I actually build both amd64 and arm64 images but using separate commands. In this case, both the amd64 and arm64 look to be failing on the exact same layer with the ERROR: failed to read expected number of bytes: unexpected EOF error. The errors started at the same time for both architecture's images. Here is one image build (all of the logs will be from the amd64 build) that I have right now that is currently running into the issue:
docker buildx build \
--output type=registry,buildinfo=false \
--provenance=false \
--builder builder1 \
--pull \
--push \
--progress plain \
--no-cache=false \
--build-arg TSMUXER_VER=7f8667d1e6100a5b6407340d91ad80d57d976e58 \
--build-arg UMSVER=14.4.0 \
--platform linux/amd64 -t mbentley/ums:14-alpine-amd64 -f Dockerfile.14-alpine \
--cache-from=type=registry,ref=registry.casa.mbentley.net/mbentley/ums:14-alpine-amd64-cache \
--cache-to=image-manifest=true,oci-mediatypes=true,mode=max,type=registry,ref=registry.casa.mbentley.net/mbentley/ums:14-alpine-amd64-cache .I can pinpoint the last time the build was successful - in that case, I ran the exact same command but with --no-cache=true, which I normally do if I've detected a vulnerability in the image and I want to force a rebuild and this normally works fine. In my build logs, it looks like everything was good when it wrote the cache yesterday - at least no errors:
# build start - 8/28/2024 @ 03:15:18
# export start - 03:16:34
03:16:34 #16 exporting cache to registry
03:16:34 #16 preparing build cache for export
03:16:52 #16 writing layer sha256:09aad8643ce764299abdc032acbc9d605172ecc38887a9cb781f6faacbc7ac49
03:16:52 #16 writing layer sha256:09aad8643ce764299abdc032acbc9d605172ecc38887a9cb781f6faacbc7ac49 done
03:16:52 #16 writing layer sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e
03:16:52 #16 writing layer sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e 0.5s done
03:16:52 #16 writing layer sha256:2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694
03:16:52 #16 writing layer sha256:2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694 0.0s done
03:16:52 #16 writing layer sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 done
03:16:52 #16 writing layer sha256:4fcaa864118708c7ca4e47f71b4c535692201e3dcd8dbf9b670c60c178c9fc93 done
03:16:52 #16 writing layer sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550 done
03:16:52 #16 writing layer sha256:c26021674b9f76800c8cdb96b16234b9c7c90939c2d095f2ff0fb918f210dfdc 0.0s done
03:16:52 #16 writing layer sha256:e99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a
03:16:53 #16 writing layer sha256:e99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a 1.3s done
03:16:53 #16 preparing build cache for export 18.4s done
03:16:53 #16 writing config sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5 done
03:16:53 #16 writing cache image manifest sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df doneI do have jaeger traces from when that build occurred if that would at all be helpful but I honestly have no idea what I would be looking for myself in them to see what would be noteworthy.
And from the registry, the logs when it was pushing the cache layers:
2024-08-28T07:16:51.288807218Z time="2024-08-28T07:16:51.288659051Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=bd0cc1d7-9dd4-4211-892c-5ce6f274126e http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:09aad8643ce764299abdc032acbc9d605172ecc38887a9cb781f6faacbc7ac49" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/octet-stream http.response.duration="878.346µs" http.response.status=200 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:09aad8643ce764299abdc032acbc9d605172ecc38887a9cb781f6faacbc7ac49" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.288827184Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:09aad8643ce764299abdc032acbc9d605172ecc38887a9cb781f6faacbc7ac49 HTTP/1.1" 200 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.289453994Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e HTTP/1.1" 404 157 "" "buildkit/v0.15"
2024-08-28T07:16:51.289463203Z time="2024-08-28T07:16:51.289372863Z" level=error msg="response completed with error" err.code="blob unknown" err.detail="sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" err.message="blob unknown to registry" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=ac937706-7360-4258-9b43-c229dd649a92 http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/json http.response.duration="295.521µs" http.response.status=404 http.response.written=157 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.292102890Z time="2024-08-28T07:16:51.292050169Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=d02ea521-26c8-408d-8529-62212c9cd9d7 http.request.method=POST http.request.remoteaddr="192.168.2.168:54750" http.request.uri=/v2/mbentley/ums/blobs/uploads/ http.request.useragent=buildkit/v0.15 http.response.duration=2.336019ms http.response.status=202 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.292113626Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "POST /v2/mbentley/ums/blobs/uploads/ HTTP/1.1" 202 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.814190102Z time="2024-08-28T07:16:51.8140768Z" level=info msg="response completed" go.version=go1.22.4 http.request.contenttype=application/octet-stream http.request.host=registry.casa.mbentley.net http.request.id=f9ea21f6-edbc-44ac-9ce7-40b88dd9a036 http.request.method=PUT http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/uploads/bdaa60ad-5d63-4056-a4a7-629ef28a6cfa?_state=UU5SaIKWHL5Sa69P-2NZZ7AMRCY1-W7s4r1KeZgcgPF7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiYmRhYTYwYWQtNWQ2My00MDU2LWE0YTctNjI5ZWYyOGE2Y2ZhIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjI4OTc3MjE5MVoifQ%3D%3D&digest=sha256%3A237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" http.request.useragent=buildkit/v0.15 http.response.duration=521.622771ms http.response.status=201 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums vars.uuid=bdaa60ad-5d63-4056-a4a7-629ef28a6cfa version=3.0.0-beta.1
2024-08-28T07:16:51.814233495Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "PUT /v2/mbentley/ums/blobs/uploads/bdaa60ad-5d63-4056-a4a7-629ef28a6cfa?_state=UU5SaIKWHL5Sa69P-2NZZ7AMRCY1-W7s4r1KeZgcgPF7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiYmRhYTYwYWQtNWQ2My00MDU2LWE0YTctNjI5ZWYyOGE2Y2ZhIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjI4OTc3MjE5MVoifQ%3D%3D&digest=sha256%3A237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e HTTP/1.1" 201 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.814977692Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694 HTTP/1.1" 404 157 "" "buildkit/v0.15"
2024-08-28T07:16:51.814976903Z time="2024-08-28T07:16:51.814902734Z" level=error msg="response completed with error" err.code="blob unknown" err.detail="sha256:2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694" err.message="blob unknown to registry" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=f81a4a5c-ab23-4df1-a0c4-9b1eac9c758d http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/json http.response.duration="307.405µs" http.response.status=404 http.response.written=157 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.817385497Z time="2024-08-28T07:16:51.817321342Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=e6e581bc-4e72-4125-903c-6a4bb0dc03e2 http.request.method=POST http.request.remoteaddr="192.168.2.168:54750" http.request.uri=/v2/mbentley/ums/blobs/uploads/ http.request.useragent=buildkit/v0.15 http.response.duration=2.107143ms http.response.status=202 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.817399159Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "POST /v2/mbentley/ums/blobs/uploads/ HTTP/1.1" 202 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.828079444Z time="2024-08-28T07:16:51.827974153Z" level=info msg="response completed" go.version=go1.22.4 http.request.contenttype=application/octet-stream http.request.host=registry.casa.mbentley.net http.request.id=c482d8c6-afd1-4e2f-a500-81a8d1104856 http.request.method=PUT http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/uploads/15bc8eef-1c5c-4376-aa88-b09085bf9dcd?_state=1qJMlewEgzs1EVEJE-vGixP7AGrP69cwct21ZOLpvwZ7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiMTViYzhlZWYtMWM1Yy00Mzc2LWFhODgtYjA5MDg1YmY5ZGNkIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjgxNTI4MjM3OFoifQ%3D%3D&digest=sha256%3A2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694" http.request.useragent=buildkit/v0.15 http.response.duration=10.209037ms http.response.status=201 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums vars.uuid=15bc8eef-1c5c-4376-aa88-b09085bf9dcd version=3.0.0-beta.1
2024-08-28T07:16:51.828100435Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "PUT /v2/mbentley/ums/blobs/uploads/15bc8eef-1c5c-4376-aa88-b09085bf9dcd?_state=1qJMlewEgzs1EVEJE-vGixP7AGrP69cwct21ZOLpvwZ7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiMTViYzhlZWYtMWM1Yy00Mzc2LWFhODgtYjA5MDg1YmY5ZGNkIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjgxNTI4MjM3OFoifQ%3D%3D&digest=sha256%3A2fd46b66fe4dc1e873f58772c9f52879e0b60bbedc1417f6c29fd38ca4a9f694 HTTP/1.1" 201 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.829279035Z time="2024-08-28T07:16:51.829209232Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=9bcce410-ae95-4588-a8ed-cecf6d8cc53e http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/octet-stream http.response.duration="663.224µs" http.response.status=200 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.829291298Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 HTTP/1.1" 200 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.830789626Z time="2024-08-28T07:16:51.830719422Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=be72130a-36e3-4d8b-873d-a7b6d2c2c7d2 http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:4fcaa864118708c7ca4e47f71b4c535692201e3dcd8dbf9b670c60c178c9fc93" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/octet-stream http.response.duration=1.076617ms http.response.status=200 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:4fcaa864118708c7ca4e47f71b4c535692201e3dcd8dbf9b670c60c178c9fc93" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.830792842Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:4fcaa864118708c7ca4e47f71b4c535692201e3dcd8dbf9b670c60c178c9fc93 HTTP/1.1" 200 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.831820569Z time="2024-08-28T07:16:51.831765876Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=9f493dc8-dde9-46ad-98eb-a4e3b8fc6c12 http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/octet-stream http.response.duration="661.212µs" http.response.status=200 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.831839027Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550 HTTP/1.1" 200 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.832412963Z time="2024-08-28T07:16:51.832349664Z" level=error msg="response completed with error" err.code="blob unknown" err.detail="sha256:c26021674b9f76800c8cdb96b16234b9c7c90939c2d095f2ff0fb918f210dfdc" err.message="blob unknown to registry" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=a4b5571d-baf6-4074-bc81-af41a695841f http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:c26021674b9f76800c8cdb96b16234b9c7c90939c2d095f2ff0fb918f210dfdc" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/json http.response.duration="257.883µs" http.response.status=404 http.response.written=157 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:c26021674b9f76800c8cdb96b16234b9c7c90939c2d095f2ff0fb918f210dfdc" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.832423974Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:c26021674b9f76800c8cdb96b16234b9c7c90939c2d095f2ff0fb918f210dfdc HTTP/1.1" 404 157 "" "buildkit/v0.15"
2024-08-28T07:16:51.834890386Z time="2024-08-28T07:16:51.834842728Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=c3056abc-6e3a-42ce-95e1-26f180015b33 http.request.method=POST http.request.remoteaddr="192.168.2.168:54750" http.request.uri=/v2/mbentley/ums/blobs/uploads/ http.request.useragent=buildkit/v0.15 http.response.duration=2.19265ms http.response.status=202 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.834904161Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "POST /v2/mbentley/ums/blobs/uploads/ HTTP/1.1" 202 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.852639663Z time="2024-08-28T07:16:51.852531873Z" level=info msg="response completed" go.version=go1.22.4 http.request.contenttype=application/octet-stream http.request.host=registry.casa.mbentley.net http.request.id=4c2678ff-fcec-4f57-8735-b6668a424c3b http.request.method=PUT http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/uploads/8b99441f-91af-4bdb-a192-fa58744b466f?_state=99kZxZ92cAQ3RepyjVCnNl2aTLiu8dJHfHt1Ix8H70V7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiOGI5OTQ0MWYtOTFhZi00YmRiLWExOTItZmE1ODc0NGI0NjZmIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjgzMjcwNDY0OFoifQ%3D%3D&digest=sha256%3Ac26021674b9f76800c8cdb96b16234b9c7c90939c2d095f2ff0fb918f210dfdc" http.request.useragent=buildkit/v0.15 http.response.duration=17.312753ms http.response.status=201 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums vars.uuid=8b99441f-91af-4bdb-a192-fa58744b466f version=3.0.0-beta.1
2024-08-28T07:16:51.852655120Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "PUT /v2/mbentley/ums/blobs/uploads/8b99441f-91af-4bdb-a192-fa58744b466f?_state=99kZxZ92cAQ3RepyjVCnNl2aTLiu8dJHfHt1Ix8H70V7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiOGI5OTQ0MWYtOTFhZi00YmRiLWExOTItZmE1ODc0NGI0NjZmIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjgzMjcwNDY0OFoifQ%3D%3D&digest=sha256%3Ac26021674b9f76800c8cdb96b16234b9c7c90939c2d095f2ff0fb918f210dfdc HTTP/1.1" 201 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.853462090Z time="2024-08-28T07:16:51.853385297Z" level=error msg="response completed with error" err.code="blob unknown" err.detail="sha256:e99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a" err.message="blob unknown to registry" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=e9455ce1-4b88-42ff-a7e0-bc7ed42554a4 http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:e99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/json http.response.duration="332.381µs" http.response.status=404 http.response.written=157 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:e99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:51.853483475Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:e99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a HTTP/1.1" 404 157 "" "buildkit/v0.15"
2024-08-28T07:16:51.856184626Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "POST /v2/mbentley/ums/blobs/uploads/ HTTP/1.1" 202 0 "" "buildkit/v0.15"
2024-08-28T07:16:51.856216427Z time="2024-08-28T07:16:51.856061998Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=32f24517-f9f0-476a-8357-6f74fbd407be http.request.method=POST http.request.remoteaddr="192.168.2.168:54750" http.request.uri=/v2/mbentley/ums/blobs/uploads/ http.request.useragent=buildkit/v0.15 http.response.duration=2.313053ms http.response.status=202 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:53.156207946Z time="2024-08-28T07:16:53.15608577Z" level=info msg="response completed" go.version=go1.22.4 http.request.contenttype=application/octet-stream http.request.host=registry.casa.mbentley.net http.request.id=5ccc2de5-8342-4b0a-a166-919b64b807b9 http.request.method=PUT http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/uploads/3067c3f6-dcd6-4d4e-bed3-49115b736c97?_state=Oo189bGM3PxHD5q-32xV-3mIaStn7N6vwcqC6MR_B097Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiMzA2N2MzZjYtZGNkNi00ZDRlLWJlZDMtNDkxMTViNzM2Yzk3IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjg1Mzg0ODk2OFoifQ%3D%3D&digest=sha256%3Ae99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a" http.request.useragent=buildkit/v0.15 http.response.duration=1.299563939s http.response.status=201 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums vars.uuid=3067c3f6-dcd6-4d4e-bed3-49115b736c97 version=3.0.0-beta.1
2024-08-28T07:16:53.156245861Z 192.168.2.168 - - [28/Aug/2024:07:16:51 +0000] "PUT /v2/mbentley/ums/blobs/uploads/3067c3f6-dcd6-4d4e-bed3-49115b736c97?_state=Oo189bGM3PxHD5q-32xV-3mIaStn7N6vwcqC6MR_B097Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiMzA2N2MzZjYtZGNkNi00ZDRlLWJlZDMtNDkxMTViNzM2Yzk3IiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUxLjg1Mzg0ODk2OFoifQ%3D%3D&digest=sha256%3Ae99da39f1975059768b1b51f70a06c4c9da4505972fb93d689778b196e2ec04a HTTP/1.1" 201 0 "" "buildkit/v0.15"
2024-08-28T07:16:53.157223222Z time="2024-08-28T07:16:53.157144243Z" level=error msg="response completed with error" err.code="blob unknown" err.detail="sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5" err.message="blob unknown to registry" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=b64a0a53-0456-4b89-aa79-ffefee1d17c8 http.request.method=HEAD http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5" http.request.useragent=buildkit/v0.15 http.response.contenttype=application/json http.response.duration="339.174µs" http.response.status=404 http.response.written=157 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.digest="sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5" vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:53.157238190Z 192.168.2.168 - - [28/Aug/2024:07:16:53 +0000] "HEAD /v2/mbentley/ums/blobs/sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5 HTTP/1.1" 404 157 "" "buildkit/v0.15"
2024-08-28T07:16:53.160813120Z time="2024-08-28T07:16:53.160745336Z" level=info msg="response completed" go.version=go1.22.4 http.request.host=registry.casa.mbentley.net http.request.id=2ef377e6-a057-4d91-830e-9c567cdfcec4 http.request.method=POST http.request.remoteaddr="192.168.2.168:54750" http.request.uri=/v2/mbentley/ums/blobs/uploads/ http.request.useragent=buildkit/v0.15 http.response.duration=3.256092ms http.response.status=202 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums version=3.0.0-beta.1
2024-08-28T07:16:53.160840419Z 192.168.2.168 - - [28/Aug/2024:07:16:53 +0000] "POST /v2/mbentley/ums/blobs/uploads/ HTTP/1.1" 202 0 "" "buildkit/v0.15"
2024-08-28T07:16:53.165394336Z time="2024-08-28T07:16:53.165304591Z" level=info msg="response completed" go.version=go1.22.4 http.request.contenttype=application/octet-stream http.request.host=registry.casa.mbentley.net http.request.id=a194f40c-ddad-482a-8db4-a6c44b283b2d http.request.method=PUT http.request.remoteaddr="192.168.2.168:54750" http.request.uri="/v2/mbentley/ums/blobs/uploads/3faa5993-401d-4189-9986-e17f6ef4937a?_state=vh0RK3hMKchmLk3k9o8nvfVItC4oOrmwFh1KT6EbBaN7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiM2ZhYTU5OTMtNDAxZC00MTg5LTk5ODYtZTE3ZjZlZjQ5MzdhIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUzLjE1NzU1MjE3NFoifQ%3D%3D&digest=sha256%3A4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5" http.request.useragent=buildkit/v0.15 http.response.duration=4.100231ms http.response.status=201 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums vars.uuid=3faa5993-401d-4189-9986-e17f6ef4937a version=3.0.0-beta.1
2024-08-28T07:16:53.165418533Z 192.168.2.168 - - [28/Aug/2024:07:16:53 +0000] "PUT /v2/mbentley/ums/blobs/uploads/3faa5993-401d-4189-9986-e17f6ef4937a?_state=vh0RK3hMKchmLk3k9o8nvfVItC4oOrmwFh1KT6EbBaN7Ik5hbWUiOiJtYmVudGxleS91bXMiLCJVVUlEIjoiM2ZhYTU5OTMtNDAxZC00MTg5LTk5ODYtZTE3ZjZlZjQ5MzdhIiwiT2Zmc2V0IjowLCJTdGFydGVkQXQiOiIyMDI0LTA4LTI4VDA3OjE2OjUzLjE1NzU1MjE3NFoifQ%3D%3D&digest=sha256%3A4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5 HTTP/1.1" 201 0 "" "buildkit/v0.15"
2024-08-28T07:16:53.166546128Z 192.168.2.168 - - [28/Aug/2024:07:16:53 +0000] "HEAD /v2/mbentley/ums/manifests/14-alpine-amd64-cache HTTP/1.1" 200 0 "" "buildkit/v0.15"
2024-08-28T07:16:53.172997226Z time="2024-08-28T07:16:53.172911037Z" level=info msg="response completed" go.version=go1.22.4 http.request.contenttype=application/vnd.oci.image.manifest.v1+json http.request.host=registry.casa.mbentley.net http.request.id=8e5bf622-23fd-4ccf-8280-b7dee2ccbd0c http.request.method=PUT http.request.remoteaddr="192.168.2.168:54750" http.request.uri=/v2/mbentley/ums/manifests/14-alpine-amd64-cache http.request.useragent=buildkit/v0.15 http.response.duration=5.967603ms http.response.status=201 http.response.written=0 instance.id=72f6af09-7713-4b5b-9ea1-29df456a7ea3 service=registry vars.name=mbentley/ums vars.reference=14-alpine-amd64-cache version=3.0.0-beta.1
2024-08-28T07:16:53.173023862Z 192.168.2.168 - - [28/Aug/2024:07:16:53 +0000] "PUT /v2/mbentley/ums/manifests/14-alpine-amd64-cache HTTP/1.1" 201 0 "" "buildkit/v0.15"On the next build, which ran the next day, the build using the cache failed. Here are the buildkit debug logs:
time="2024-08-29T13:13:50Z" level=debug msg="session started"
time="2024-08-29T13:13:50Z" level=debug msg="session finished: <nil>"
time="2024-08-29T13:13:50Z" level=debug msg="resolve exporter image with map[buildinfo:false name:mbentley/ums:14-alpine-amd64 push:true]"
time="2024-08-29T13:13:50Z" level=debug msg="checked for cached auth handler namespace" cached=false key="2f5kfieaji1vm075bvd0o08fh::registry.casa.mbentley.net/mbentley/ums::push" name=registry.casa.mbentley.net/mbentley/ums scope=push
time="2024-08-29T13:13:50Z" level=debug msg="session started"
time="2024-08-29T13:13:50Z" level=debug msg="reusing ref for local: dyndbbd56age0pvf8nzrjcp2q" span="[internal] load build definition from Dockerfile.14-alpine"
time="2024-08-29T13:13:50Z" level=debug msg="diffcopy took: 2.852767ms" span="[internal] load build definition from Dockerfile.14-alpine"
time="2024-08-29T13:13:50Z" level=debug msg="checked for cached auth handler namespace" cached=true key="docker.io/mbentley/alpine::pull" name=docker.io/mbentley/alpine scope=pull
time="2024-08-29T13:13:50Z" level=debug msg=resolving host=registry-1.docker.io
time="2024-08-29T13:13:50Z" 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.15 request.method=HEAD url="https://registry-1.docker.io/v2/mbentley/alpine/manifests/latest"
time="2024-08-29T13:13:50Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=987 response.header.content-type=application/vnd.docker.distribution.manifest.list.v2+json response.header.date="Thu, 29 Aug 2024 13:13:50 GMT" response.header.docker-content-digest="sha256:0222a0e9245d184b3cacad9d6b8951a4c2b3c0b177cb12992d6153b86df7f88d" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=d00b51bc-74c0-11e4-bea4-0242ac11001b response.header.etag="\"sha256:0222a0e9245d184b3cacad9d6b8951a4c2b3c0b177cb12992d6153b86df7f88d\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" url="https://registry-1.docker.io/v2/mbentley/alpine/manifests/latest"
time="2024-08-29T13:13:50Z" level=debug msg=resolved desc.digest="sha256:0222a0e9245d184b3cacad9d6b8951a4c2b3c0b177cb12992d6153b86df7f88d" host=registry-1.docker.io
time="2024-08-29T13:13:50Z" level=debug msg=fetch digest="sha256:0222a0e9245d184b3cacad9d6b8951a4c2b3c0b177cb12992d6153b86df7f88d" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=987
time="2024-08-29T13:13:50Z" level=debug msg=fetch digest="sha256:eadc64333df4287fcb3cced9b8e2c179fe93a7d0acf6024871f67f768dd82659" mediatype=application/vnd.docker.distribution.manifest.v2+json size=502
time="2024-08-29T13:13:50Z" level=debug msg=fetch digest="sha256:67fc0ece0b99d21934ce9186b00e39650cc1a7d54c23a9fa58371c2925c9886b" mediatype=application/vnd.docker.container.image.v1+json size=845
time="2024-08-29T13:13:50Z" level=debug msg="reusing ref for local: q0ghyttrba1zcn6tjttw1ksdn" span="[internal] load .dockerignore"
time="2024-08-29T13:13:50Z" level=debug msg="diffcopy took: 2.508833ms" span="[internal] load .dockerignore"
time="2024-08-29T13:13:50Z" level=debug msg="checked for cached auth handler namespace" cached=true key="registry.casa.mbentley.net/mbentley/ums::pull" name=registry.casa.mbentley.net/mbentley/ums scope=pull
time="2024-08-29T13:13:50Z" level=debug msg=resolving host=registry.casa.mbentley.net
time="2024-08-29T13:13:50Z" level=debug msg="do request" host=registry.casa.mbentley.net 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.15 request.method=HEAD url="https://registry.casa.mbentley.net/v2/mbentley/ums/manifests/14-alpine-amd64-cache"
time="2024-08-29T13:13:50Z" level=debug msg="checked for cached auth handler namespace" cached=true key="docker.io/mbentley/alpine::pull" name=docker.io/mbentley/alpine scope=pull
time="2024-08-29T13:13:50Z" level=debug msg=fetch digest="sha256:0222a0e9245d184b3cacad9d6b8951a4c2b3c0b177cb12992d6153b86df7f88d" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=987
time="2024-08-29T13:13:50Z" level=debug msg="fetch response received" host=registry.casa.mbentley.net response.header.content-length=2887 response.header.content-type=application/vnd.oci.image.manifest.v1+json response.header.date="Thu, 29 Aug 2024 13:13:50 GMT" response.header.docker-content-digest="sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df\"" response.header.x-content-type-options=nosniff response.status="200 OK" url="https://registry.casa.mbentley.net/v2/mbentley/ums/manifests/14-alpine-amd64-cache"
time="2024-08-29T13:13:50Z" level=debug msg=resolved desc.digest="sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df" host=registry.casa.mbentley.net
time="2024-08-29T13:13:50Z" level=debug msg="do request" digest="sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df" request.header.accept="application/vnd.oci.image.manifest.v1+json, */*" request.header.user-agent=buildkit/v0.15 request.method=GET url="https://registry.casa.mbentley.net/v2/mbentley/ums/manifests/sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df"
time="2024-08-29T13:13:50Z" level=debug msg="fetch response received" digest="sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df" response.header.content-length=2887 response.header.content-type=application/vnd.oci.image.manifest.v1+json response.header.date="Thu, 29 Aug 2024 13:13:50 GMT" response.header.docker-content-digest="sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df\"" response.header.x-content-type-options=nosniff response.status="200 OK" url="https://registry.casa.mbentley.net/v2/mbentley/ums/manifests/sha256:1a731eb7db29643b6878d7a8805ae7ea86602e66dba283e5749c40408a7773df"
time="2024-08-29T13:13:50Z" level=debug msg=fetch digest="sha256:eadc64333df4287fcb3cced9b8e2c179fe93a7d0acf6024871f67f768dd82659" mediatype=application/vnd.docker.distribution.manifest.v2+json size=502
time="2024-08-29T13:13:50Z" level=debug msg="do request" digest="sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5" request.header.accept="application/vnd.buildkit.cacheconfig.v0, */*" request.header.user-agent=buildkit/v0.15 request.method=GET url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5"
time="2024-08-29T13:13:50Z" level=debug msg="fetch response received" digest="sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5" response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=3245 response.header.content-type=application/octet-stream response.header.date="Thu, 29 Aug 2024 13:13:50 GMT" response.header.docker-content-digest="sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5\"" response.header.x-content-type-options=nosniff response.status="200 OK" url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:4deeae67f5534d886ad8188739be4d557e08d0e1a493bcbc50baf73a1e5584b5"
time="2024-08-29T13:13:50Z" level=debug msg=fetch digest="sha256:67fc0ece0b99d21934ce9186b00e39650cc1a7d54c23a9fa58371c2925c9886b" mediatype=application/vnd.docker.container.image.v1+json size=845
time="2024-08-29T13:13:50Z" level=debug msg="load cache for [tsmuxer-build 1/4] FROM docker.io/mbentley/alpine:latest@sha256:0222a0e9245d184b3cacad9d6b8951a4c2b3c0b177cb12992d6153b86df7f88d with 91gq08czdomqb7b5l3g2s7ttb::9xrud0g7notn1x9basogya74v"
time="2024-08-29T13:13:50Z" level=debug msg="reusing ref for local: n5l59tdeflq8n0v30cg38pyb6" span="[internal] load build context"
time="2024-08-29T13:13:50Z" level=debug msg="diffcopy took: 1.912315ms" span="[internal] load build context"
time="2024-08-29T13:13:50Z" level=debug msg="load cache for [tsmuxer-build 4/4] RUN /build-tsmuxer.sh with sha256:168fbfb41024084f98c7b3d71a451c2535392b1b74ca8496a3ca119b2ac6d3cc"
time="2024-08-29T13:13:50Z" level=debug msg="diff applied" d=78.188577ms digest="sha256:4fcaa864118708c7ca4e47f71b4c535692201e3dcd8dbf9b670c60c178c9fc93" media=application/vnd.docker.image.rootfs.diff.tar.gzip size=3622936
time="2024-08-29T13:13:51Z" level=debug msg=fetch digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=437
time="2024-08-29T13:13:51Z" level=debug msg=fetch digest="sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" mediatype=application/vnd.oci.image.layer.v1.tar+gzip size=106336257
time="2024-08-29T13:13:51Z" level=debug msg="do request" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=buildkit/v0.15 request.method=GET size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="fetch response received" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=437 response.header.content-type=application/octet-stream response.header.date="Thu, 29 Aug 2024 13:13:51 GMT" response.header.docker-content-digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550\"" response.header.x-content-type-options=nosniff response.status="200 OK" size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="do request" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=buildkit/v0.15 request.method=GET size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="fetch response received" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=437 response.header.content-type=application/octet-stream response.header.date="Thu, 29 Aug 2024 13:13:51 GMT" response.header.docker-content-digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550\"" response.header.x-content-type-options=nosniff response.status="200 OK" size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="do request" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=buildkit/v0.15 request.method=GET size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="do request" digest="sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" mediatype=application/vnd.oci.image.layer.v1.tar+gzip request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=buildkit/v0.15 request.method=GET size=106336257 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e"
time="2024-08-29T13:13:51Z" level=debug msg="fetch response received" digest="sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" mediatype=application/vnd.oci.image.layer.v1.tar+gzip response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=106336257 response.header.content-type=application/octet-stream response.header.date="Thu, 29 Aug 2024 13:13:51 GMT" response.header.docker-content-digest="sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e\"" response.header.x-content-type-options=nosniff response.status="200 OK" size=106336257 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e"
time="2024-08-29T13:13:51Z" level=debug msg="fetch response received" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=437 response.header.content-type=application/octet-stream response.header.date="Thu, 29 Aug 2024 13:13:51 GMT" response.header.docker-content-digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550\"" response.header.x-content-type-options=nosniff response.status="200 OK" size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="do request" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=buildkit/v0.15 request.method=GET size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="fetch response received" digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" mediatype=application/vnd.oci.image.layer.v1.tar+gzip response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=437 response.header.content-type=application/octet-stream response.header.date="Thu, 29 Aug 2024 13:13:51 GMT" response.header.docker-content-digest="sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550\"" response.header.x-content-type-options=nosniff response.status="200 OK" size=437 url="https://registry.casa.mbentley.net/v2/mbentley/ums/blobs/sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="> creating qhgciymj14thhxdjsrxi04i9l [/bin/sh -c apk add --no-cache coreutils flac jq iputils mediainfo mplayer openjdk17-jre vlc && UMSVER=$(if [ -z \"${UMSVER}\" ]; then wget -q -O - https://api.github.com/repos/UniversalMediaServer/UniversalMediaServer/releases/latest | jq -r .name; else echo \"${UMSVER}\"; fi) && MYARCH=\"$(arch)\" && if [ \"${MYARCH}\" = \"x86_64\" ]; then UMSARCH=\"x86_64\"; elif [ \"${MYARCH}\" = \"arm64\" ] || [ \"${MYARCH}\" = \"aarch64\" ]; then UMSARCH=\"arm64\"; else echo \"unsupported archtecture\"; exit 1; fi && apk del --purge --no-cache jq && if [ \"$(echo $UMSVER | awk -F '.' '{print $1}')\" -ne \"14\" ]; then echo \"Latest version number is no longer 14\"; exit 1; fi && wget -nv \"https://github.com/UniversalMediaServer/UniversalMediaServer/releases/download/${UMSVER}/UMS-${UMSVER}-${UMSARCH}.tgz\" -O /opt/UMS-${UMSVER}.tgz && cd /opt && tar zxf UMS-${UMSVER}.tgz && rm UMS-${UMSVER}.tgz && mv ums-${UMSVER} ums && rm -rf /opt/ums/jre* && rm -f /opt/ums/linux/tsMuxeR* && mkdir /opt/ums/database /opt/ums/data /var/log/UMS && addgroup -g 500 ums && adduser -u 500 -G ums -h /opt/ums -D ums && chown -R ums:ums /opt/ums /var/log/UMS && rm -rf /media/*]" span="[stage-1 2/5] RUN apk add --no-cache coreutils flac jq iputils mediainfo mplayer openjdk17-jre vlc && UMSVER=$(if [ -z \"14.4.0\" ]; then wget -q -O - https://api.github.com/repos/UniversalMediaServer/UniversalMediaServer/releases/latest | jq -r .name; else echo \"14.4.0\"; fi) && MYARCH=\"$(arch)\" && if [ \"${MYARCH}\" = \"x86_64\" ]; then UMSARCH=\"x86_64\"; elif [ \"${MYARCH}\" = \"arm64\" ] || [ \"${MYARCH}\" = \"aarch64\" ]; then UMSARCH=\"arm64\"; else echo \"unsupported archtecture\"; exit 1; fi && apk del --purge --no-cache jq && if [ \"$(echo 14.4.0 | awk -F '.' '{print $1}')\" -ne \"14\" ]; then echo \"Latest version number is no longer 14\"; exit 1; fi && wget -nv \"https://github.com/UniversalMediaServer/UniversalMediaServer/releases/download/14.4.0/UMS-14.4.0-${UMSARCH}.tgz\" -O /opt/UMS-14.4.0.tgz && cd /opt && tar zxf UMS-14.4.0.tgz && rm UMS-14.4.0.tgz && mv ums-14.4.0 ums && rm -rf /opt/ums/jre* && rm -f /opt/ums/linux/tsMuxeR* && mkdir /opt/ums/database /opt/ums/data /var/log/UMS && addgroup -g 500 ums && adduser -u 500 -G ums -h /opt/ums -D ums && chown -R ums:ums /opt/ums /var/log/UMS && rm -rf /media/*"
time="2024-08-29T13:13:51Z" level=debug msg="sending sigkill to process in container qhgciymj14thhxdjsrxi04i9l"
time="2024-08-29T13:13:51Z" level=error msg="failed to kill process in container id qhgciymj14thhxdjsrxi04i9l: buildkit-runc did not terminate successfully: exit status 1: container does not exist\n"
time="2024-08-29T13:13:51Z" level=debug msg="sending sigkill to process in container qhgciymj14thhxdjsrxi04i9l"
time="2024-08-29T13:13:51Z" level=debug msg="remove snapshot" key=pu4oqgnz7rx2qmy5s2g5hbttj snapshotter=overlayfs
time="2024-08-29T13:13:51Z" level=debug msg="remove ingest" ref="layer-sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e"
time="2024-08-29T13:13:51Z" level=debug msg="remove ingest" ref="layer-sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="schedule snapshotter cleanup" snapshotter=overlayfs
time="2024-08-29T13:13:51Z" level=debug msg="schedule content cleanup"
time="2024-08-29T13:13:51Z" level=debug msg="removed snapshot" key=buildkit/196993/pu4oqgnz7rx2qmy5s2g5hbttj snapshotter=overlayfs
time="2024-08-29T13:13:51Z" level=debug msg="cleanup aborting ingest" ref="buildkit/1/layer-sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550"
time="2024-08-29T13:13:51Z" level=debug msg="cleanup aborting ingest" ref="buildkit/1/layer-sha256:237bf871eef09f8f53f9d9ed1ad9418dd359e1525a40fe8da7070cfe5df4957e"
time="2024-08-29T13:13:51Z" level=error msg="/moby.buildkit.v1.Control/Solve returned error: rpc error: code = Unknown desc = failed to compute cache key: failed to read expected number of bytes: unexpected EOF"
failed to compute cache key: failed to read expected number of bytes: unexpected EOF
1 v0.15.2 buildkitd
github.com/moby/buildkit/solver.(*edge).createInputRequests.(*edge).createInputRequests.func1.func2
/src/solver/edge.go:912
github.com/moby/buildkit/solver/internal/pipe.NewWithFunction.func2
/src/solver/internal/pipe/pipe.go:82
runtime.goexit
/usr/local/go/src/runtime/asm_amd64.s:1695
1 v0.15.2 buildkitd
main.unaryInterceptor
/src/cmd/buildkitd/main.go:713
google.golang.org/grpc.NewServer.chainUnaryServerInterceptors.chainUnaryInterceptors.func1
/src/vendor/google.golang.org/grpc/server.go:1154
github.com/moby/buildkit/api/services/control._Control_Solve_Handler
/src/api/services/control/control.pb.go:2484
google.golang.org/grpc.(*Server).processUnaryRPC
/src/vendor/google.golang.org/grpc/server.go:1343
google.golang.org/grpc.(*Server).handleStream
/src/vendor/google.golang.org/grpc/server.go:1737
google.golang.org/grpc.(*Server).serveStreams.func1.1
/src/vendor/google.golang.org/grpc/server.go:986
runtime.goexit
/usr/local/go/src/runtime/asm_amd64.s:1695
time="2024-08-29T13:13:51Z" level=debug msg="session finished: <nil>"I also have jaeger traces from this as well - again, not sure if that's useful or not but I can share those if it might be.
koooge
commented
2 months ago Hi there, I had unexpected EOFs in the past, but it appears to have been resolved. In my case, it was caused by docker local registry blobdescriptor: inmemory. https://github.com/distribution/distribution/issues/2367#issuecomment-1874449361 I hope you find this useful.
mbentley
commented
2 months ago Ah, I think I've actually come across those findings on that before as I am subscribed to that issue & had previously disabled the blobdescriptor for my pull through registry however I still have the it enabled for my actual registry where my cache contents are being stored.
Having just now disabled it and restarted, I do now get a new error but I can only imagine that it has something to do with the blobdescriptor cache wasn't holding the same information as what was actually stored on disk or something like that:
ERROR: failed to solve: failed to compute cache key: failed to copy: httpReadSeeker: failed open: could not fetch content descriptor sha256:ba2c8c93b74b0a2061a72a0a2ba2207e109df4b9727e63f58efa59b894d0b550 (application/vnd.oci.image.layer.v1.tar+gzip) from remote: not foundI executed a build of all of my images, which I normally run daily, and of the 200+ images I build, a few others which were previously cached fine were throwing the same errors. I'm going to re-build those without cache and see how that goes for a while. Hopefully I'll see more consistent caching success.
*edit: just returning to this issue to say that I have not come across any build failures due to unexpected EOF errors since disabling the blob descriptor cache on my registry storing the cache images about two weeks ago.
We are currently trialling moby/buildkit:master-rootless running in Kubernetes using the deployment+service example as a reference.
We have a Trow registry running within the cluster, and buildctl is being called from another pod to perform builds.
The builds we're attempting are currently failing with
error: failed to solve: failed to compute cache key: failed to read expected number of bytes: unexpected EOF.The logs suggest that the
FROMstep is completing successfully and then failing on the next step which is anADDdirective.The failing builds only appear to be occurring with some base images and not with others. We have tried a simple build based on
centos:8with a singleADDstep and it successfully completes. The builds based on our base image (which is quite large at around 4GB) consistently fail on mutliple developer environments.Troubleshooting
So far we've tried:
--debugflag on buildkitdThere doesn't appear to be anything obvious in logs or traces that indicate what this failure means, but I have included a section of the logs for a build below.
Environment
Our developer environments are a mix of Docker Desktop on macOS and K3s on Linux.
My versions are:
Logs