When using non-overlay filesystems, a socket file triggers "failed to solve: failed to prepare xxx as yyy"
Open
Nobody has claimed this yet.
- Dominant language
- Go
- Stars
- 10.3k
- Forks
- 1.5k
- Avg merge
- 1d 21h
- Merged PRs (30d)
- 50
Description
short description
Running a Docker build when using vfs, and when that image creates a UNIX socket file, the image build fails on the next instruction with "failed to solve: failed to prepare xxx as yyy"
long description
I'm running a Docker build using version 24.0.2 (so buildkit on by default) and with the storage driver set to "vfs". If I run an image build that contains an instruction that results in a socket file, then any subsequent command fails with the error "failed to solve: failed to prepare xxx as yyy".
For example, building with the Dockerfile below (which uses netcat to create a socket file /tmp/sock, using timeout to prevent us waiting for ever) ...
FROM ubuntu:latest
RUN apt update && apt install -y netcat && apt clean cache && timeout 1s nc -l -U /tmp/sock || true
RUN ls
... produces the following output to the terminal...
# docker build -f Dockerfile -t asme:sock .
[+] Building 12.7s (6/6) FINISHED
=> [internal] load build definition from Dockerfile 0.0s
=> => transferring dockerfile: 233B 0.0s
=> [internal] load .dockerignore 0.0s
=> => transferring context: 2B 0.0s
=> [internal] load metadata for docker.io/library/ubuntu:latest 1.3s
=> [1/3] FROM docker.io/library/ubuntu:latest@sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd 2.4s
=> => resolve docker.io/library/ubuntu:latest@sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd 0.0s
=> => sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44 29.53MB / 29.53MB 0.8s
=> => sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd 1.13kB / 1.13kB 0.0s
=> => sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0 424B / 424B 0.0s
=> => sha256:99284ca6cea039c7784d1414608c6e846dd56830c2a13e1341be681c3ffcc8ac 2.30kB / 2.30kB 0.0s
=> => extracting sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44 1.4s
=> [2/3] RUN apt update && apt install -y netcat && apt clean cache && timeout 1s nc -l -U /tmp/sock || true 8.9s
=> ERROR [3/3] RUN ls 0.0s
------
> [3/3] RUN ls:
------
Dockerfile:3
--------------------
1 | FROM ubuntu:latest
2 | RUN apt update && apt install -y netcat && apt clean cache && timeout 1s nc -l -U /tmp/sock || true
3 | >>> RUN ls
4 |
--------------------
ERROR: failed to solve: failed to prepare jz7yp2njzr8hqny6l1vkhvq5o as lo45o7wqrglvam5qubyqua4ai: invalid argument
The docker logs contain the following for the time the build is running, but there doesn't seem to be much that helps...
time="2023-06-21T15:48:14.088337440Z" level=debug msg="Calling HEAD /_ping"
time="2023-06-21T15:48:14.190290320Z" level=debug msg="Calling HEAD /_ping"
time="2023-06-21T15:48:14.190852544Z" level=debug msg="Calling POST /grpc"
time="2023-06-21T15:48:14.191885967Z" level=debug msg="Calling HEAD /_ping"
time="2023-06-21T15:48:14.192669556Z" level=debug msg="Calling HEAD /_ping"
time="2023-06-21T15:48:14.193014344Z" level=debug msg="Calling GET /v1.42/version"
time="2023-06-21T15:48:14.205850377Z" level=debug msg="Calling POST /grpc"
time="2023-06-21T15:48:14.232171026Z" level=debug msg="Calling POST /session"
time="2023-06-21T15:48:14.263999529Z" level=debug msg="Calling POST /session"
time="2023-06-21T15:48:14.268713468Z" level=debug msg="new ref for local: w5aovbtpeclxwgojvlr87t2at" span="[internal] load build definition from Dockerfile"
time="2023-06-21T15:48:14.269092325Z" level=debug msg="new ref for local: xn0iewuoq67iwr4ffmnex63wu" span="[internal] load .dockerignore"
time="2023-06-21T15:48:14.271881369Z" level=debug msg="diffcopy took: 2.59373ms" span="[internal] load .dockerignore"
time="2023-06-21T15:48:14.272244450Z" level=debug msg="saved xn0iewuoq67iwr4ffmnex63wu as context:context-.dockerignore:agent:3a402616dba27f73" span="[internal] load .dockerignore"
time="2023-06-21T15:48:14.272464053Z" level=debug msg="diffcopy took: 3.367575ms" span="[internal] load build definition from Dockerfile"
time="2023-06-21T15:48:14.273049884Z" level=debug msg="saved w5aovbtpeclxwgojvlr87t2at as dockerfile:dockerfile:agent:3a402616dba27f73" span="[internal] load build definition from Dockerfile"
time="2023-06-21T15:48:14.298140598Z" level=debug msg=resolving host=registry-1.docker.io
time="2023-06-21T15:48:14.298233220Z" 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.11-dev request.method=HEAD url="https://registry-1.docker.io/v2/library/ubuntu/manifests/latest"
time="2023-06-21T15:48:14.607621501Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=157 response.header.content-type=application/json response.header.date="Wed, 21 Jun 2023 15:48:14 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=129.41.86.1 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:library/ubuntu:pull\"" response.status="401 Unauthorized" url="https://registry-1.docker.io/v2/library/ubuntu/manifests/latest"
time="2023-06-21T15:48:14.607685402Z" level=debug msg=Unauthorized header="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:library/ubuntu:pull\"" host=registry-1.docker.io
time="2023-06-21T15:48:14.611591062Z" 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.11-dev request.method=HEAD url="https://registry-1.docker.io/v2/library/ubuntu/manifests/latest"
time="2023-06-21T15:48:15.045731984Z" level=debug msg="fetch response received" host=registry-1.docker.io response.header.content-length=1133 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Wed, 21 Jun 2023 15:48:15 GMT" response.header.docker-content-digest="sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=129.41.86.1 response.header.etag="\"sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" url="https://registry-1.docker.io/v2/library/ubuntu/manifests/latest"
time="2023-06-21T15:48:15.045805149Z" level=debug msg=resolved desc.digest="sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd" host=registry-1.docker.io
time="2023-06-21T15:48:15.046315991Z" level=debug msg=fetch digest="sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd" mediatype=application/vnd.oci.image.index.v1+json size=1133
time="2023-06-21T15:48:15.049836972Z" level=debug msg="do request" digest="sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd" mediatype=application/vnd.oci.image.index.v1+json request.header.accept="application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=buildkit/v0.11-dev request.method=GET size=1133 url="https://registry-1.docker.io/v2/library/ubuntu/manifests/sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd"
time="2023-06-21T15:48:15.171082908Z" level=debug msg="fetch response received" digest="sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd" mediatype=application/vnd.oci.image.index.v1+json response.header.content-length=1133 response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Wed, 21 Jun 2023 15:48:15 GMT" response.header.docker-content-digest="sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=129.41.86.1 response.header.etag="\"sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" size=1133 url="https://registry-1.docker.io/v2/library/ubuntu/manifests/sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd"
time="2023-06-21T15:48:15.172395071Z" level=debug msg=fetch digest="sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0" mediatype=application/vnd.oci.image.manifest.v1+json size=424
time="2023-06-21T15:48:15.174524776Z" level=debug msg="do request" digest="sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0" mediatype=application/vnd.oci.image.manifest.v1+json request.header.accept="application/vnd.oci.image.manifest.v1+json, */*" request.header.user-agent=buildkit/v0.11-dev request.method=GET size=424 url="https://registry-1.docker.io/v2/library/ubuntu/manifests/sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0"
time="2023-06-21T15:48:15.276859965Z" level=debug msg="fetch response received" digest="sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0" mediatype=application/vnd.oci.image.manifest.v1+json response.header.content-length=424 response.header.content-type=application/vnd.oci.image.manifest.v1+json response.header.date="Wed, 21 Jun 2023 15:48:15 GMT" response.header.docker-content-digest="sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-ratelimit-source=129.41.86.1 response.header.etag="\"sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0\"" response.header.strict-transport-security="max-age=31536000" response.status="200 OK" size=424 url="https://registry-1.docker.io/v2/library/ubuntu/manifests/sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0"
time="2023-06-21T15:48:15.277872997Z" level=debug msg=fetch digest="sha256:99284ca6cea039c7784d1414608c6e846dd56830c2a13e1341be681c3ffcc8ac" mediatype=application/vnd.oci.image.config.v1+json size=2297
time="2023-06-21T15:48:15.279967141Z" level=debug msg="do request" digest="sha256:99284ca6cea039c7784d1414608c6e846dd56830c2a13e1341be681c3ffcc8ac" mediatype=application/vnd.oci.image.config.v1+json request.header.accept="application/vnd.oci.image.config.v1+json, */*" request.header.user-agent=buildkit/v0.11-dev request.method=GET size=2297 url="https://registry-1.docker.io/v2/library/ubuntu/blobs/sha256:99284ca6cea039c7784d1414608c6e846dd56830c2a13e1341be681c3ffcc8ac"
time="2023-06-21T15:48:15.610469170Z" level=debug msg="fetch response received" digest="sha256:99284ca6cea039c7784d1414608c6e846dd56830c2a13e1341be681c3ffcc8ac" mediatype=application/vnd.oci.image.config.v1+json response.header.accept-ranges=bytes response.header.age=486589 response.header.cache-control="public, max-age=14400" response.header.cf-cache-status=HIT response.header.cf-ray=7dad650d4f1ee5b1-DFW response.header.connection=keep-alive response.header.content-length=2297 response.header.content-type=application/octet-stream response.header.date="Wed, 21 Jun 2023 15:48:15 GMT" response.header.etag="\"81cb9ca97e5b5cdcffe184661b97e063\"" response.header.expires="Wed, 21 Jun 2023 19:48:15 GMT" response.header.last-modified="Mon, 05 Jun 2023 17:20:28 GMT" response.header.server=cloudflare response.header.vary=Accept-Encoding response.header.x-amz-id-2="zaMX/xwAURfsByHPu3Ln6D1/snR6IsR4brrSYK2SCmGMhVyqsGy43rqQUXCttxWVgcBpQWnxFSA=" response.header.x-amz-request-id=6SR4ESWTD1621EQS response.header.x-amz-server-side-encryption=AES256 response.header.x-amz-version-id=X8VcjwXsmg8nIeCpUqKwmoW.c72KN1M9 response.status="200 OK" size=2297 url="https://registry-1.docker.io/v2/library/ubuntu/blobs/sha256:99284ca6cea039c7784d1414608c6e846dd56830c2a13e1341be681c3ffcc8ac"
time="2023-06-21T15:48:15.615659699Z" level=debug msg=fetch digest="sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd" mediatype=application/vnd.oci.image.index.v1+json size=1133
time="2023-06-21T15:48:15.616041040Z" level=debug msg=fetch digest="sha256:83f0c2a8d6f266d687d55b5cb1cb2201148eb7ac449e4202d9646b9083f1cee0" mediatype=application/vnd.oci.image.manifest.v1+json size=424
time="2023-06-21T15:48:15.616376348Z" level=debug msg=fetch digest="sha256:99284ca6cea039c7784d1414608c6e846dd56830c2a13e1341be681c3ffcc8ac" mediatype=application/vnd.oci.image.config.v1+json size=2297
time="2023-06-21T15:48:15.617650115Z" level=debug msg=fetch span="[1/3] FROM docker.io/library/ubuntu:latest@sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd"
time="2023-06-21T15:48:15.617926568Z" level=debug msg=fetch span="[1/3] FROM docker.io/library/ubuntu:latest@sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd"
time="2023-06-21T15:48:15.618160949Z" level=debug msg=fetch span="[1/3] FROM docker.io/library/ubuntu:latest@sha256:6120be6a2b7ce665d0cbddc3ce6eae60fe94637c6a66985312d1f02f63cc0bcd"
time="2023-06-21T15:48:15.620994356Z" level=debug msg="do request" digest="sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44" request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=buildkit/v0.11-dev request.method=GET url="https://registry-1.docker.io/v2/library/ubuntu/blobs/sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44"
time="2023-06-21T15:48:15.773699432Z" level=debug msg="fetch response received" digest="sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44" response.header.accept-ranges=bytes response.header.age=1325759 response.header.cache-control="public, max-age=14400" response.header.cf-cache-status=HIT response.header.cf-ray=7dad650e4875e5b1-DFW response.header.connection=keep-alive response.header.content-length=29533050 response.header.content-type=application/octet-stream response.header.date="Wed, 21 Jun 2023 15:48:15 GMT" response.header.etag="\"1fdbde0f4f3513b4cab149065788c2d7\"" response.header.expires="Wed, 21 Jun 2023 19:48:15 GMT" response.header.last-modified="Mon, 05 Jun 2023 17:20:26 GMT" response.header.server=cloudflare response.header.vary=Accept-Encoding response.header.x-amz-id-2="+bucpU4WP5eogcGnVmkbok0DUrJsWMrNFp6IZgSRSqQAWxFsWc3L9h8z0hXgi26BOqZRWF7AJIk=" response.header.x-amz-request-id=7B284A9S8VAN6X89 response.header.x-amz-server-side-encryption=AES256 response.header.x-amz-version-id=tLV9TBc4i5Pq0BFzmWi5HyMkOtjthEGf response.status="200 OK" url="https://registry-1.docker.io/v2/library/ubuntu/blobs/sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44"
time="2023-06-21T15:48:16.436648849Z" level=debug msg="Using /usr/bin/unpigz to decompress"
time="2023-06-21T15:48:16.437584488Z" level=debug msg="Start untar layer" id=0bb897c63f7410b83af4142d8b6721481359dd7fdafc9f04628dfe6b6ddb23c3
time="2023-06-21T15:48:17.992396410Z" level=debug msg="Untar time: 1.554791174s" id=0bb897c63f7410b83af4142d8b6721481359dd7fdafc9f04628dfe6b6ddb23c3
time="2023-06-21T15:48:17.992478821Z" level=debug msg="Applied tar sha256:cdd7c73923174e45ea648d66996665c288e1b17a0f45efdbeca860f6dafdf731 to 0bb897c63f7410b83af4142d8b6721481359dd7fdafc9f04628dfe6b6ddb23c3, size: 77807754"
time="2023-06-21T15:48:17.995104110Z" level=debug msg="remove content" key="sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44"
time="2023-06-21T15:48:17.995244958Z" level=debug msg="schedule content cleanup"
time="2023-06-21T15:48:17.999763795Z" level=debug msg="removed content" digest="sha256:6b851dcae6ca1461dde247915abc5048061f34332929ca8fb37d9dc18f2e2f44"
time="2023-06-21T15:48:17.999872605Z" level=debug msg="content garbage collected" d=4.598693ms
time="2023-06-21T15:48:18.872764455Z" level=debug msg="Assigning addresses for endpoint ntopusvlenbuc520a5s63wypx's interface on network bridge"
time="2023-06-21T15:48:18.872841799Z" level=debug msg="RequestAddress(LocalDefault/10.0.0.0/24, <nil>, map[])"
time="2023-06-21T15:48:18.872891334Z" level=debug msg="Request address PoolID:10.0.0.0/24 Bits: 256, Unselected: 253, Sequence: (0xc0000000, 1)->(0x0, 6)->(0x1, 1)->end Curr:2 Serial:false PrefAddress:invalid IP "
time="2023-06-21T15:48:18.884680026Z" level=debug msg="Assigning addresses for endpoint ntopusvlenbuc520a5s63wypx's interface on network bridge"
time="2023-06-21T15:48:18.884842198Z" level=debug msg="e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813 (12250ab).addSvcRecords(ntopusvlenbuc520a5s63wypx, 10.0.0.2, <nil>, true) updateSvcRecord sid:e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813"
time="2023-06-21T15:48:18.885985068Z" level=debug msg="e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813 (12250ab).addSvcRecords(ntopusvlenbuc520a5s63wypx, 10.0.0.2, <nil>, true) updateSvcRecord sid:e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813"
time="2023-06-21T15:48:18.889037740Z" level=debug msg="Programming external connectivity on endpoint ntopusvlenbuc520a5s63wypx (e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813)"
time="2023-06-21T15:48:18.908046625Z" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2023-06-21T15:48:18.908081205Z" level=debug msg="DeleteConntrackEntriesByPort for udp ports purged ipv4:0, ipv6:0"
time="2023-06-21T15:48:18.909477629Z" level=debug msg="> creating q4ayb53lbu6ylrx7cafkr9ef2 [/bin/sh -c apt update && apt install -y netcat && apt clean cache && timeout 1s nc -l -U /tmp/sock || true]" span="[2/3] RUN apt update && apt install -y netcat && apt clean cache && timeout 1s nc -l -U /tmp/sock || true"
time="2023-06-21T15:48:19.056755298Z" level=debug msg="sandbox set key processing took 31.699211ms for container ntopusvlenbuc520a5s63wypx"
time="2023-06-21T15:48:19.234336675Z" level=debug msg="2023/06/21 15:48:19 WARNING: [core] [Channel #11 SubChannel #12] grpc: addrConn.createTransport failed to connect to {" library=grpc
time="2023-06-21T15:48:19.234422185Z" level=debug msg=" \"Addr\": \"localhost\"," library=grpc
time="2023-06-21T15:48:19.234434028Z" level=debug msg=" \"ServerName\": \"localhost\"," library=grpc
time="2023-06-21T15:48:19.234443172Z" level=debug msg=" \"Attributes\": null," library=grpc
time="2023-06-21T15:48:19.234451152Z" level=debug msg=" \"BalancerAttributes\": null," library=grpc
time="2023-06-21T15:48:19.234459323Z" level=debug msg=" \"Type\": 0," library=grpc
time="2023-06-21T15:48:19.234474279Z" level=debug msg=" \"Metadata\": null" library=grpc
time="2023-06-21T15:48:19.234482821Z" level=debug msg="}. Err: connection error: desc = \"transport: Error while dialing only one connection allowed\"" library=grpc
time="2023-06-21T15:48:19.266191295Z" level=debug msg="healthcheck completed" actualDuration="933.475µs" timeout=30s
time="2023-06-21T15:48:24.270576113Z" level=debug msg="healthcheck completed" actualDuration=5.811044ms timeout=30s
time="2023-06-21T15:48:26.930116796Z" level=debug msg="Revoking external connectivity on endpoint ntopusvlenbuc520a5s63wypx (e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813)"
time="2023-06-21T15:48:26.949462125Z" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2023-06-21T15:48:26.949503460Z" level=debug msg="DeleteConntrackEntriesByPort for udp ports purged ipv4:0, ipv6:0"
time="2023-06-21T15:48:26.972956372Z" level=warning msg="no trace recorder found, skipping"
time="2023-06-21T15:48:26.998024617Z" level=debug msg="e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813 (12250ab).deleteSvcRecords(ntopusvlenbuc520a5s63wypx, 10.0.0.2, <nil>, true) updateSvcRecord sid:e5d3025d403b903950d6ae5e7d33b057e496a42ffdc4fac346e51f6475cdc813 "
time="2023-06-21T15:48:27.068149086Z" level=debug msg="Releasing addresses for endpoint ntopusvlenbuc520a5s63wypx's interface on network bridge"
time="2023-06-21T15:48:27.068211726Z" level=debug msg="ReleaseAddress(LocalDefault/10.0.0.0/24, 10.0.0.2)"
time="2023-06-21T15:48:27.068254071Z" level=debug msg="Released address Address:10.0.0.2 Sequence:Bits: 256, Unselected: 253, Sequence: (0xc0000000, 1)->(0x0, 6)->(0x1, 1)->end Curr:3"
Looking at the files laid down on the host machine shows the vfs directories exist and there appears to be a socket file in one of them...
# ls -lart /var/lib/docker/vfs/dir/
total 0
drwxr-xr-x. 2 root root 6 Jun 21 15:48 xn0iewuoq67iwr4ffmnex63wu
drwx--x---. 3 root root 42 Jun 21 15:48 ..
drwxr-xr-x. 2 root root 24 Jun 21 15:48 w5aovbtpeclxwgojvlr87t2at
drwxr-xr-x. 17 root root 251 Jun 21 15:48 qqojul4frduac2shk5m7o8nfb
drwxr-xr-x. 17 root root 251 Jun 21 15:48 0bb897c63f7410b83af4142d8b6721481359dd7fdafc9f04628dfe6b6ddb23c3
drwx--x---. 7 root root 210 Jun 21 15:48 .
drwxr-xr-x. 15 root root 229 Jun 21 15:48 lo45o7wqrglvam5qubyqua4ai
# find /var/lib/docker/vfs/dir/ -type s
/var/lib/docker/vfs/dir/qqojul4frduac2shk5m7o8nfb/tmp/sock
# ls -la /var/lib/docker/vfs/dir/qqojul4frduac2shk5m7o8nfb/tmp/sock
srwxr-xr-x. 1 root root 0 Jun 21 15:48 /var/lib/docker/vfs/dir/qqojul4frduac2shk5m7o8nfb/tmp/sock
I can hit this bug with any command that creates a socket file, but this is the smallest recreate I've got
I do not see this when running with an overlay storage driver. It may happen with other non-overlay storage drivers but I've only tested vfs
I see this with various versions of Docker with buildkit enabled
I can work around this by removing the socket file within the same instruction that created it
Another interesting thing I've notices is that if I have the "socket creating command" as the last command then the docker logs contain some errors about tar not supporting socket files. As an example from some other builds where I've hit this using a Red Hat base image, the logs contain this...
time="2023-06-13T16:24:06.515798568Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-appstream-rpms-8-ppc64le/gpgdir/S.gpg-agent to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.515896501Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-appstream-rpms-8-ppc64le/gpgdir/S.gpg-agent.browser to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.515925492Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-appstream-rpms-8-ppc64le/gpgdir/S.gpg-agent.extra to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.515952024Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-appstream-rpms-8-ppc64le/gpgdir/S.gpg-agent.ssh to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.533314698Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-baseos-rpms-8-ppc64le/gpgdir/S.gpg-agent to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.533430756Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-baseos-rpms-8-ppc64le/gpgdir/S.gpg-agent.browser to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.533477483Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-baseos-rpms-8-ppc64le/gpgdir/S.gpg-agent.extra to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.533515956Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-baseos-rpms-8-ppc64le/gpgdir/S.gpg-agent.ssh to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.539168979Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-codeready-builder-rpms-8-ppc64le/gpgdir/S.gpg-agent to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.539209876Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-codeready-builder-rpms-8-ppc64le/gpgdir/S.gpg-agent.browser to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.539240834Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-codeready-builder-rpms-8-ppc64le/gpgdir/S.gpg-agent.extra to tar: archive/tar: sockets not supported"
time="2023-06-13T16:24:06.539265823Z" level=debug msg="Can't add file /var/lib/docker/vfs/dir/jq7zglc27evuwxogj9qxyuu2t/var/cache/yum/metadata/ubi-8-codeready-builder-rpms-8-ppc64le/gpgdir/S.gpg-agent.ssh to tar: archive/tar: sockets not supported"
I don't think tar is the "cause" of the problem, but if it's not at all related then it's an interesting coincidence
I think the build is hitting this line during the build (as this is the only line that has this error message) - https://github.com/moby/buildkit/blob/d1ea4c572c114e9a15b29fd543757d43f275c63a/cache/manager.go#L622
I suspect, but have no proof, that when running on a vfs storage driver, the first thing that happens for the next build instruction is to copy the whole file system from the most recent directory to a new directory, and it uses tar to do this (maybe tar is used because there's the option of using a remote cache? I don't know, this is all speculation). That directory copy either fails due to tar not supporting sockets and triggers this error, or it succeeds but some other subsequent check notices that the socket file has gone, and then throws an error
I've not managed to track down what the invalid argument in the original error is actually referring to, though, so this is pure guesswork based on observed behaviour
Hopefully there's enough above for a recreate
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start by reproducing the failure with the provided Dockerfile, using the vfs storage driver and its socket-creating RUN instruction followed by RUN ls. Trace the BuildKit preparation step that reports "failed to prepare" and add coverage for this case; done means the subsequent instruction completes successfully without the invalid-argument error.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- docker, go
- Domain
- build-system
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100