test failure

gistfile1.txt

=== CONT  TestIntegration/TestBasicRegistryCacheImportExport/worker=oci-rootless
    client_test.go:3540: 
        	Error Trace:	client_test.go:3540
        	            				client_test.go:2665
        	            				client_test.go:2704
        	            				run.go:176
        	Error:      	Should be true
        	Test:       	TestIntegration/TestBasicRegistryCacheImportExport/worker=oci-rootless
    sandbox.go:228: stdout: /usr/bin/sudo
    sandbox.go:228: stderr: /usr/bin/sudo
    sandbox.go:231: > startCmd 2021-08-25 00:19:35.487545861 +0000 UTC m=+40.284317413 [sudo -u #1000 -i -- exec rootlesskit buildkitd --oci-worker=true --containerd-worker=false --oci-worker-gc=false --oci-worker-labels=org.mobyproject.buildkit.worker.sandbox=true --config=/tmp/bktest_config1683980726/buildkitd.toml --root /tmp/bktest_buildkitd1525604206 --addr unix:///tmp/bktest_buildkitd1525604206/buildkitd.sock --debug]
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=info msg="auto snapshotter: using overlayfs"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="running in rootless mode"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="cannot mount overlay with \"userxattr\", probably the kernel does not support userxattr" error="invalid argument"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=info msg="found worker \"cowd6q8ujl3fagm6drhq5kzyb\", labels=map[org.mobyproject.buildkit.worker.executor:oci org.mobyproject.buildkit.worker.hostname:39a5dbea0b17 org.mobyproject.buildkit.worker.sandbox:true org.mobyproject.buildkit.worker.snapshotter:overlayfs], platforms=[linux/amd64 linux/arm64 linux/riscv64 linux/ppc64le linux/s390x linux/386 linux/mips64le linux/mips64 linux/arm/v7 linux/arm/v6]"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=warning msg="rootless mode is not supported for containerd workers. disabling containerd worker."
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=info msg="found 1 workers, default=\"cowd6q8ujl3fagm6drhq5kzyb\""
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=warning msg="currently, only the default worker can be used."
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=info msg="running server on /tmp/bktest_buildkitd1525604206/buildkitd.sock"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="skipping invalid cache export mode: "
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="session started"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg=resolving
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="do request" 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=containerd/1.5.5+unknown request.method=HEAD
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="fetch response received" response.header.content-length=527 response.header.content-type=application/vnd.docker.distribution.manifest.v2+json response.header.date="Wed, 25 Aug 2021 00:19:35 GMT" response.header.docker-content-digest="sha256:b862520da7361ea093806d292ce355188ae83f21e8e3b2a3ce4dbdba0a230f83" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:b862520da7361ea093806d292ce355188ae83f21e8e3b2a3ce4dbdba0a230f83\"" response.status="200 OK"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg=resolved desc.digest="sha256:b862520da7361ea093806d292ce355188ae83f21e8e3b2a3ce4dbdba0a230f83"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg=fetch
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="do request" request.header.accept="application/vnd.docker.distribution.manifest.v2+json, */*" request.header.user-agent=containerd/1.5.5+unknown request.method=GET
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="fetch response received" response.header.content-length=527 response.header.content-type=application/vnd.docker.distribution.manifest.v2+json response.header.date="Wed, 25 Aug 2021 00:19:35 GMT" response.header.docker-content-digest="sha256:b862520da7361ea093806d292ce355188ae83f21e8e3b2a3ce4dbdba0a230f83" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:b862520da7361ea093806d292ce355188ae83f21e8e3b2a3ce4dbdba0a230f83\"" response.status="200 OK"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg=fetch
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="do request" request.header.accept="application/vnd.docker.container.image.v1+json, */*" request.header.user-agent=containerd/1.5.5+unknown request.method=GET
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="fetch response received" response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=1456 response.header.content-type=application/octet-stream response.header.date="Wed, 25 Aug 2021 00:19:35 GMT" response.header.docker-content-digest="sha256:42b97d3c2ae95232263a04324aaf656dc80e7792dee6629a9eff276cdfb806c0" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:42b97d3c2ae95232263a04324aaf656dc80e7792dee6629a9eff276cdfb806c0\"" response.status="200 OK"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg=fetch
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="do request" request.header.accept="application/vnd.docker.image.rootfs.diff.tar.gzip, */*" request.header.user-agent=containerd/1.5.5+unknown request.method=GET
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="fetch response received" response.header.accept-ranges=bytes response.header.cache-control="max-age=31536000" response.header.content-length=766708 response.header.content-type=application/octet-stream response.header.date="Wed, 25 Aug 2021 00:19:35 GMT" response.header.docker-content-digest="sha256:8ec32b265e94aafb0d43ab71f1d8f786122c19afb37d25532aea169f414f8881" response.header.docker-distribution-api-version=registry/2.0 response.header.etag="\"sha256:8ec32b265e94aafb0d43ab71f1d8f786122c19afb37d25532aea169f414f8881\"" response.status="200 OK"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="unpigz not found, falling back to go gzip" error="exec: \"unpigz\": executable file not found in $PATH"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="diff applied" d=46.256284ms digest="sha256:8ec32b265e94aafb0d43ab71f1d8f786122c19afb37d25532aea169f414f8881" media=application/vnd.docker.image.rootfs.diff.tar.gzip size=766708
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="> creating xaa2fhihji36n9fiv3sqsdeba [sh -c echo -n foobar > const]" span="sh -c echo -n foobar > const"
    sandbox.go:231: time="2021-08-25T00:19:35Z" level=debug msg="> creating ipzxhai48b2lq6zeuf0zgww0b [sh -c cat /dev/urandom | head -c 100 | sha256sum > unique]" span="sh -c cat /dev/urandom | head -c 100 | sha256sum > unique"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="Using double walk diff for /run/user/1000/containerd-mount3405837205 from /run/user/1000/containerd-mount1117648457"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="Using double walk diff for /run/user/1000/containerd-mount1990571588 from /run/user/1000/containerd-mount3568883816"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg=fetch
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="checking and pushing to" url="http://localhost:34087/v2/buildkit/testexport/blobs/sha256:497f2e62aa051fbc044fee8becf2e46ccc325e46abf9fe36e1bf36f1f8187414"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=containerd/1.5.5+unknown request.method=HEAD
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=157 response.header.content-type="application/json; charset=utf-8" response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-distribution-api-version=registry/2.0 response.status="404 Not Found"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.user-agent=containerd/1.5.5+unknown request.method=POST
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=0 response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-upload-uuid=0c9ebda8-37a5-48fe-bad5-285b3186418a response.header.location="http://localhost:34087/v2/buildkit/testexport/blobs/uploads/0c9ebda8-37a5-48fe-bad5-285b3186418a?_state=_8aDm7cj0-wbvDEFuqZ6rk4G0bh53wLOTSSlpe3Laz17Ik5hbWUiOiJidWlsZGtpdC90ZXN0ZXhwb3J0IiwiVVVJRCI6IjBjOWViZGE4LTM3YTUtNDhmZS1iYWQ1LTI4NWIzMTg2NDE4YSIsIk9mZnNldCI6MCwiU3RhcnRlZEF0IjoiMjAyMS0wOC0yNVQwMDoxOTozNi4wODA0OTU1MDZaIn0%3D" response.header.range=0-0 response.status="202 Accepted"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.content-type=application/octet-stream request.header.user-agent=containerd/1.5.5+unknown request.method=PUT
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=0 response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-content-digest="sha256:497f2e62aa051fbc044fee8becf2e46ccc325e46abf9fe36e1bf36f1f8187414" response.header.docker-distribution-api-version=registry/2.0 response.header.location="http://localhost:34087/v2/buildkit/testexport/blobs/sha256:497f2e62aa051fbc044fee8becf2e46ccc325e46abf9fe36e1bf36f1f8187414" response.status="201 Created"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg=fetch
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="checking and pushing to" url="http://localhost:34087/v2/buildkit/testexport/blobs/sha256:a99b9ad2898fb0b6505adec2f32134367ac64aa8fee392c50d430b32e415370c"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.accept="application/vnd.oci.image.layer.v1.tar+gzip, */*" request.header.user-agent=containerd/1.5.5+unknown request.method=HEAD
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=157 response.header.content-type="application/json; charset=utf-8" response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-distribution-api-version=registry/2.0 response.status="404 Not Found"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.user-agent=containerd/1.5.5+unknown request.method=POST
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=0 response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-upload-uuid=8afd8aaa-9e3c-4e56-b2cc-6b695654b70b response.header.location="http://localhost:34087/v2/buildkit/testexport/blobs/uploads/8afd8aaa-9e3c-4e56-b2cc-6b695654b70b?_state=L_-cgoTabsxpFCmnZwNzDgWUILPGP-5MD5DaXywtjxN7Ik5hbWUiOiJidWlsZGtpdC90ZXN0ZXhwb3J0IiwiVVVJRCI6IjhhZmQ4YWFhLTllM2MtNGU1Ni1iMmNjLTZiNjk1NjU0YjcwYiIsIk9mZnNldCI6MCwiU3RhcnRlZEF0IjoiMjAyMS0wOC0yNVQwMDoxOTozNi4xMDE2MDM4MzZaIn0%3D" response.header.range=0-0 response.status="202 Accepted"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.content-type=application/octet-stream request.header.user-agent=containerd/1.5.5+unknown request.method=PUT
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=0 response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-content-digest="sha256:a99b9ad2898fb0b6505adec2f32134367ac64aa8fee392c50d430b32e415370c" response.header.docker-distribution-api-version=registry/2.0 response.header.location="http://localhost:34087/v2/buildkit/testexport/blobs/sha256:a99b9ad2898fb0b6505adec2f32134367ac64aa8fee392c50d430b32e415370c" response.status="201 Created"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=warning msg="reference for unknown type: application/vnd.buildkit.cacheconfig.v0"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="checking and pushing to" url="http://localhost:34087/v2/buildkit/testexport/blobs/sha256:e7891da0abd96e1c368b6bc2fbb339292bd64b29593705c183cff5a277c1e1c7"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.accept="application/vnd.buildkit.cacheconfig.v0, */*" request.header.user-agent=containerd/1.5.5+unknown request.method=HEAD
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=157 response.header.content-type="application/json; charset=utf-8" response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-distribution-api-version=registry/2.0 response.status="404 Not Found"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.user-agent=containerd/1.5.5+unknown request.method=POST
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=0 response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.docker-upload-uuid=00bbc9ca-6d2c-47b5-9ab3-82323116b1cf response.header.location="http://localhost:34087/v2/buildkit/testexport/blobs/uploads/00bbc9ca-6d2c-47b5-9ab3-82323116b1cf?_state=y24s7p8KrHXO8eGwG0aVxgqyNEmaLzgO1RYyOTwxd1Z7Ik5hbWUiOiJidWlsZGtpdC90ZXN0ZXhwb3J0IiwiVVVJRCI6IjAwYmJjOWNhLTZkMmMtNDdiNS05YWIzLTgyMzIzMTE2YjFjZiIsIk9mZnNldCI6MCwiU3RhcnRlZEF0IjoiMjAyMS0wOC0yNVQwMDoxOTozNi4xMTQwMzQ5MTJaIn0%3D" response.header.range=0-0 response.status="202 Accepted"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.content-type=application/octet-stream request.header.user-agent=containerd/1.5.5+unknown request.method=PUT
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=0 response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-content-digest="sha256:e7891da0abd96e1c368b6bc2fbb339292bd64b29593705c183cff5a277c1e1c7" response.header.docker-distribution-api-version=registry/2.0 response.header.location="http://localhost:34087/v2/buildkit/testexport/blobs/sha256:e7891da0abd96e1c368b6bc2fbb339292bd64b29593705c183cff5a277c1e1c7" response.status="201 Created"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="checking and pushing to" url="http://localhost:34087/v2/buildkit/testexport/manifests/latest"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.accept="application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=containerd/1.5.5+unknown request.method=HEAD
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=96 response.header.content-type="application/json; charset=utf-8" response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-distribution-api-version=registry/2.0 response.status="404 Not Found"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="do request" request.header.content-type=application/vnd.oci.image.index.v1+json request.header.user-agent=containerd/1.5.5+unknown request.method=PUT
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="fetch response received" response.header.content-length=0 response.header.date="Wed, 25 Aug 2021 00:19:36 GMT" response.header.docker-content-digest="sha256:1e9d1b591cd9c78ed7bf3053fce9f40b31477bf4d84fd6d6c8c43285655aa481" response.header.docker-distribution-api-version=registry/2.0 response.header.location="http://localhost:34087/v2/buildkit/testexport/manifests/sha256:1e9d1b591cd9c78ed7bf3053fce9f40b31477bf4d84fd6d6c8c43285655aa481" response.status="201 Created"
    sandbox.go:231: time="2021-08-25T00:19:36Z" level=debug msg="session finished: <nil>"
    sandbox.go:231: > sending sigterm 2021-08-25 00:19:46.169645647 +0000 UTC m=+50.966417199
    sandbox.go:231: time="2021-08-25T00:19:46Z" level=info msg="stopping server"
    sandbox.go:231: buildkitd: context canceled
    sandbox.go:231: [rootlesskit:child ] error: command [buildkitd --oci-worker=true --containerd-worker=false --oci-worker-gc=false --oci-worker-labels=org.mobyproject.buildkit.worker.sandbox=true --config=/tmp/bktest_config1683980726/buildkitd.toml --root /tmp/bktest_buildkitd1525604206 --addr unix:///tmp/bktest_buildkitd1525604206/buildkitd.sock --debug] exited: exit status 1
    sandbox.go:231: [rootlesskit:parent] error: child exited: exit status 1
    sandbox.go:231: > stopped 2021-08-25 00:19:46.174790879 +0000 UTC m=+50.971562431 exit status 1 1