search

moby / buildkit

concurrent, cache-efficient, and Dockerfile-agnostic builder toolkit
https://github.com/moby/moby/issues/34227
Apache License 2.0
7.85k stars 1.09k forks source link

error: failed to solve: rpc error: code = Unknown #1937

Open AhmadMasry opened 3 years ago

AhmadMasry commented 3 years ago

Hi; I am using buildkit 0.8.1 alongside with buildkit:master-rootless. I got the following error intermittently and randomly, error: failed to solve: rpc error: code = Unknown desc = failed to get record sfx1jm9owmoa8mzgmae6likt2 by blobchainid: failed to remove sfx1jm9owmoa8mzgmae6likt2: lease "sfx1jm9owmoa8mzgmae6likt2": not found We are using registry caching for both export and import cache. I also want to mention that both export an import caches are using the same tag: --export-cache type=registry,ref={image_base_url}:build-cache --import-cache type=registry,ref={image_base_url}:build-cache I am doing anything wrong, and if now, why this error is happening. Best

tonistiigi commented 3 years ago

Never seen this error. We need a reproducer (even if it is run in a loop to hit the issue) to look into it.

AhmadMasry commented 3 years ago

The following are the logs of another 1failing job, but these are the contain logs.

time="2021-01-08T02:18:52Z" level=info msg="auto snapshotter: using overlayfs"
time="2021-01-08T02:18:52Z" level=warning msg="NoProcessSandbox is enabled. Note that NoProcessSandbox allows build containers to kill (and potentially ptrace) an arbitrary process in the BuildKit host namespace. NoProcessSandbox should be enabled only when the BuildKit is running in a container as an unprivileged user."
time="2021-01-08T02:18:52Z" level=info msg="found worker \"tr4iz83mtbu8tcfzmp3sey0cd\", labels=map[org.mobyproject.buildkit.worker.executor:oci org.mobyproject.buildkit.worker.hostname:carta-bitbucket-organization-folder-carta-dev-120-v0hpj-f-lpfsp org.mobyproject.buildkit.worker.snapshotter:overlayfs], platforms=[linux/amd64 linux/386]"
time="2021-01-08T02:18:52Z" level=warning msg="rootless mode is not supported for containerd workers. disabling containerd worker."
time="2021-01-08T02:18:52Z" level=info msg="found 1 workers, default=\"tr4iz83mtbu8tcfzmp3sey0cd\""
time="2021-01-08T02:18:52Z" level=warning msg="currently, only the default worker can be used."
time="2021-01-08T02:18:52Z" level=warning msg="TLS is not enabled for tcp://0.0.0.0:1234. enabling mutual TLS authentication is highly recommended"
time="2021-01-08T02:18:52Z" level=info msg="running server on [::]:1234"
time="2021-01-08T02:35:39Z" level=warning msg="reference for unknown type: application/vnd.buildkit.cacheconfig.v0"
time="2021-01-08T03:41:30Z" level=warning msg="reference for unknown type: application/vnd.buildkit.cacheconfig.v0"
time="2021-01-08T03:49:13Z" level=warning msg="reference for unknown type: application/vnd.buildkit.cacheconfig.v0"
time="2021-01-08T03:49:16Z" level=error msg="/moby.buildkit.v1.Control/Solve returned error: rpc error: code = Unknown desc = failed to get record r70cxzzj1rsk6bx9edp8jebnb by blobchainid: failed to remove r70cxzzj1rsk6bx9edp8jebnb: lease \"r70cxzzj1rsk6bx9edp8jebnb\": not found\n"

The executed command was buildctl build --frontend dockerfile.v0 --output type=image,name=****.azurecr.io/carta/{image_name}:dev,push=true --export-cache type=registry,ref=****.azurecr.io/carta/{image_name}:build-cache --import-cache type=registry,ref=****.azurecr.io/carta/{image_name}:build-cache --opt target={image_name} --opt build-arg:CARTA_PLATFORM_VERSION=1.0.16 --local context=. --local dockerfile=. --opt filename=Dockerfile.ubuntu The last lines of the build output that contains the error are:

#5 [platform 1/1] FROM ****.azurecr.io/carta/platform:1.0.16@sha256:7d0165605125521105a2120f8a5a200ea32cceeacd6880eebe33a5b58f75e046

#5 sha256:3b12f6941eb3cf973b186cdd5b7e7704e6aeded9d2b5e42a5dd539f0fd6c4c52

#5 ERROR: failed to get record r70cxzzj1rsk6bx9edp8jebnb by blobchainid: failed to remove r70cxzzj1rsk6bx9edp8jebnb: lease "r70cxzzj1rsk6bx9edp8jebnb": not found

Hope that this information are sufficient. Knowing that I rerun the build after that and it succeeded. Best

AhmadMasry commented 3 years ago

Hi @tonistiigi Are the provided logs sufficient or do you want something more? if more info is needed, can you provide me with how to provide the debug information? Thanks

Maubil commented 1 year ago

Hi there, seems like this is a corner case that happens sometimes (caching issues?). I saw this on rocky linux 9 - 5.14 kernel. The issue is not really reproducible, and a complete removal of all images/snapshot/blobs (+docker system prune) fixed it.

Here are the logs if someone is interested:

Apr 04 15:41:07 my-vm buildkitd[3822]: time="2023-04-04T15:41:07+02:00" level=debug msg="reusing ref for local: pwa1jngqw44z0tle825y2gfk4" span="[internal] load build definition from Dockerfile" spanID=4d3755bf0b2d3f1b traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:07 my-vm buildkitd[3822]: time="2023-04-04T15:41:07+02:00" level=debug msg="reusing ref for local: yn42dnmveaw0189778ii902wd" span="[internal] load .dockerignore" spanID=aeb832da95d11377 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:07 my-vm buildkitd[3822]: time="2023-04-04T15:41:07+02:00" level=debug msg="diffcopy took: 2.135479ms" span="[internal] load .dockerignore" spanID=92040cc5b0af406f traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:07 my-vm buildkitd[3822]: time="2023-04-04T15:41:07+02:00" level=debug msg="diffcopy took: 2.568971ms" span="[internal] load build definition from Dockerfile" spanID=fab50592cf022687 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:07 my-vm buildkitd[3822]: time="2023-04-04T15:41:07+02:00" level=debug msg=resolving host="redacted.registry.org:443" spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:07 my-vm buildkitd[3822]: time="2023-04-04T15:41:07+02:00" level=debug msg="do request" host="redacted.registry.org:443" 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.11 request.method=HEAD spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0 url="https://redacted.registry.org:443/v2/postgres/manifests/12.7"
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg="fetch response received" host="redacted.registry.org:443" response.header.alt-svc="h3=\":443\"; ma=86400, h3-29=\":443\"; ma=86400" response.header.cache-control="no-store, no-cache" response.header.cf-cache-status=DYNAMIC response.header.cf-ray=7b29f78f9a4fbaca-MXP response.header.connection=keep-alive response.header.content-length=1862 response.header.content-security-policy="sandbox allow-forms allow-modals allow-popups allow-presentation allow-scripts allow-top-navigation" response.header.content-type=application/vnd.docker.distribution.manifest.list.v2+json response.header.date="Tue, 04 Apr 2023 13:41:09 GMT" response.header.docker-content-digest="sha256:1ba4e7aa3db644e8f6faee085bb40c1e050baa9a28f79948daa98220b2dc0394" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:1ba4e7aa3db644e8f6faee085bb40c1e050baa9a28f79948daa98220b2dc0394\"" response.header.last-modified="Thu, 09 Mar 2023 14:13:48 GMT" response.header.pragma=no-cache response.header.server=cloudflare response.header.set-cookie="path=/; Httponly; Secure" response.header.strict-transport-security="max-age=31536000" response.header.x-content-type-options=nosniff response.header.x-xss-protection="1; mode=block" response.status="200 OK" spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0 url="https://redacted.registry.org:443/v2/postgres/manifests/12.7"
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=resolved desc.digest="sha256:1ba4e7aa3db644e8f6faee085bb40c1e050baa9a28f79948daa98220b2dc0394" host="redacted.registry.org:443" spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:1ba4e7aa3db644e8f6faee085bb40c1e050baa9a28f79948daa98220b2dc0394" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=1862 spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:8ccaddb60a6bcda7de4f19d5c15e442bb50836b34c9bf828e2a9ed2ded30779f" mediatype=application/vnd.docker.distribution.manifest.v2+json size=3038 spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:0a0f8f6f039211cab471c89d2e176ce1c6e76aa8039cfd9216df2cde7d3a3831" mediatype=application/vnd.docker.distribution.manifest.v2+json size=3038 spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:0f698a6badfa74ce8a84a7c5b593348578bb7d348447df63f91b0d0413353615" mediatype=application/vnd.docker.container.image.v1+json size=10230 spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:ed26d135f9f3ecfcc90c5b140922d49c3f7fd0931a469d19dded145142c7187f" mediatype=application/vnd.docker.container.image.v1+json size=10230 spanID=795ed75a5e510af4 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:1ba4e7aa3db644e8f6faee085bb40c1e050baa9a28f79948daa98220b2dc0394" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=1862 spanID=319bdeb92e56ffcb traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:0a0f8f6f039211cab471c89d2e176ce1c6e76aa8039cfd9216df2cde7d3a3831" mediatype=application/vnd.docker.distribution.manifest.v2+json size=3038 spanID=319bdeb92e56ffcb traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg=fetch digest="sha256:0f698a6badfa74ce8a84a7c5b593348578bb7d348447df63f91b0d0413353615" mediatype=application/vnd.docker.container.image.v1+json size=10230 spanID=319bdeb92e56ffcb traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg="new ref for local: q8grvv8s6ynjqlxxg3zn36jgw" span="[internal] load build context" spanID=02a0e7efb6051a38 traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg="diffcopy took: 255.53µs" span="[internal] load build context" spanID=e030c0a7c6ebb79c traceID=2e6eaa975409077bee9175b6686ffaf0
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=error msg="/moby.buildkit.v1.Control/Solve returned error: rpc error: code = Unknown desc = lease \"tuhb8pyuj9r7o2n1e7buzaz0t\": not found"
Apr 04 15:41:09 my-vm buildkitd[3822]: lease "tuhb8pyuj9r7o2n1e7buzaz0t": not found
Apr 04 15:41:09 my-vm buildkitd[3822]: 3822 v0.11.3 /usr/local/bin/buildkitd
Apr 04 15:41:09 my-vm buildkitd[3822]: github.com/moby/buildkit/solver.(*edge).execOp
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/solver/edge.go:906
Apr 04 15:41:09 my-vm buildkitd[3822]: github.com/moby/buildkit/solver/internal/pipe.NewWithFunction.func2
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/solver/internal/pipe/pipe.go:82
Apr 04 15:41:09 my-vm buildkitd[3822]: runtime.goexit
Apr 04 15:41:09 my-vm buildkitd[3822]:         /usr/local/go/src/runtime/asm_amd64.s:1594
Apr 04 15:41:09 my-vm buildkitd[3822]: 3822 v0.11.3 /usr/local/bin/buildkitd
Apr 04 15:41:09 my-vm buildkitd[3822]: main.unaryInterceptor.func1
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/cmd/buildkitd/main.go:576
Apr 04 15:41:09 my-vm buildkitd[3822]: github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/vendor/github.com/grpc-ecosystem/go-grpc-middleware/chain.go:25
Apr 04 15:41:09 my-vm buildkitd[3822]: github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/vendor/github.com/grpc-ecosystem/go-grpc-middleware/chain.go:34
Apr 04 15:41:09 my-vm buildkitd[3822]: github.com/moby/buildkit/api/services/control._Control_Solve_Handler
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/api/services/control/control.pb.go:2440
Apr 04 15:41:09 my-vm buildkitd[3822]: google.golang.org/grpc.(*Server).processUnaryRPC
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/vendor/google.golang.org/grpc/server.go:1340
Apr 04 15:41:09 my-vm buildkitd[3822]: google.golang.org/grpc.(*Server).handleStream
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/vendor/google.golang.org/grpc/server.go:1713
Apr 04 15:41:09 my-vm buildkitd[3822]: google.golang.org/grpc.(*Server).serveStreams.func1.2
Apr 04 15:41:09 my-vm buildkitd[3822]:         /src/vendor/google.golang.org/grpc/server.go:965
Apr 04 15:41:09 my-vm buildkitd[3822]: runtime.goexit
Apr 04 15:41:09 my-vm buildkitd[3822]:         /usr/local/go/src/runtime/asm_amd64.s:1594
Apr 04 15:41:09 my-vm buildkitd[3822]: time="2023-04-04T15:41:09+02:00" level=debug msg="session finished: <nil>" spanID=6690db09bae773b8 traceID=2e6eaa975409077bee9175b6686ffaf0

But I guess a docker system prune should do the trick if nothing else works.