Error context cancellation when docker pull image

r.loginov commented

2024-08-06 12:28:38 +00:00

Member

During the operation of the docker full command, an error appears in the distribution logs:

ERRO[0137] error resolving descriptor in ServeBlob listener: frostfs: couldn't get object from tree: failed to get node by path: rpc error: code = Canceled desc = context canceled  environment=development go.version=go1.22.4 http.request.host="localhost:5000" http.request.id=d66d4248-74dc-4caf-8cb9-bdcfc62ca53c http.request.method=GET http.request.remoteaddr="127.0.0.1:46946" http.request.uri="/v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" http.request.useragent="docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \\(linux\\))" instance.id=a523fc39-f7f4-4285-857d-9e9a2cbccb6c service=registry vars.digest="sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" vars.name=redis version=v3.0.0-beta.1.m+unknown

At the same time, the request itself is completed successfully and there is no negative effect on the result of the work:

ERRO[0137] error resolving descriptor in ServeBlob listener: frostfs: couldn't get object from tree: failed to get node by path: rpc error: code = Canceled desc = context canceled  environment=development go.version=go1.22.4 http.request.host="localhost:5000" http.request.id=d66d4248-74dc-4caf-8cb9-bdcfc62ca53c http.request.method=GET http.request.remoteaddr="127.0.0.1:46946" http.request.uri="/v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" http.request.useragent="docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \\(linux\\))" instance.id=a523fc39-f7f4-4285-857d-9e9a2cbccb6c service=registry vars.digest="sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" vars.name=redis version=v3.0.0-beta.1.m+unknown
INFO[0137] response completed                            environment=development go.version=go1.22.4 http.request.host="localhost:5000" http.request.id=d66d4248-74dc-4caf-8cb9-bdcfc62ca53c http.request.method=GET http.request.remoteaddr="127.0.0.1:46946" http.request.uri="/v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" http.request.useragent="docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \\(linux\\))" http.response.contenttype=application/octet-stream http.response.duration=18.748313166s http.response.status=200 http.response.written=29126287 instance.id=a523fc39-f7f4-4285-857d-9e9a2cbccb6c service=registry vars.digest="sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" vars.name=redis version=v3.0.0-beta.1.m+unknown
127.0.0.1 - - [06/Aug/2024:11:14:25 +0300] "GET /v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559 HTTP/1.1" 200 29126287 "" "docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \\(linux\\))"

The error itself occurs due to the fact that the context is canceled from outside the frostfs driver code.

Steps to Reproduce (for bugs)

Pull an image from the Docker Pub (not necessarily this one, you can use any one)

$ docker pull redis:latest

We do all the actions to launch distribution:

2.1 Raising frostfs-aio

2.2 Creating a container

2.3 Add its id and the path to the wallet to the config file distribution: ./cmd/registry/config-dev-frostfs.yml

2.4 We are building distribution from the root of the project and launching

$ make binaries

$ ./bin/registry serve cmd/registry/config-dev-frostfs.yml

We put a tag on the image so that we can upload it to our registry

$ docker tag redis:latest localhost:5000/redis:latest

Push the image

$ docker push localhost:5000/redis:latest

Deleting the image from your computer (so that the pull is complete)

$ docker rmi redis:latest

$ docker rmi localhost:5000/redis:latest

We pool the image and observe an error in the logs

$ docker pull localhost:5000/redis:latest

Your Environment

Distribution commit version: 8ceca80274

During the operation of the docker full <image> command, an error appears in the distribution logs: ``` ERRO[0137] error resolving descriptor in ServeBlob listener: frostfs: couldn't get object from tree: failed to get node by path: rpc error: code = Canceled desc = context canceled environment=development go.version=go1.22.4 http.request.host="localhost:5000" http.request.id=d66d4248-74dc-4caf-8cb9-bdcfc62ca53c http.request.method=GET http.request.remoteaddr="127.0.0.1:46946" http.request.uri="/v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" http.request.useragent="docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \$linux\$)" instance.id=a523fc39-f7f4-4285-857d-9e9a2cbccb6c service=registry vars.digest="sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" vars.name=redis version=v3.0.0-beta.1.m+unknown ``` At the same time, the request itself is completed successfully and there is no negative effect on the result of the work: ``` ERRO[0137] error resolving descriptor in ServeBlob listener: frostfs: couldn't get object from tree: failed to get node by path: rpc error: code = Canceled desc = context canceled environment=development go.version=go1.22.4 http.request.host="localhost:5000" http.request.id=d66d4248-74dc-4caf-8cb9-bdcfc62ca53c http.request.method=GET http.request.remoteaddr="127.0.0.1:46946" http.request.uri="/v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" http.request.useragent="docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \$linux\$)" instance.id=a523fc39-f7f4-4285-857d-9e9a2cbccb6c service=registry vars.digest="sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" vars.name=redis version=v3.0.0-beta.1.m+unknown INFO[0137] response completed environment=development go.version=go1.22.4 http.request.host="localhost:5000" http.request.id=d66d4248-74dc-4caf-8cb9-bdcfc62ca53c http.request.method=GET http.request.remoteaddr="127.0.0.1:46946" http.request.uri="/v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" http.request.useragent="docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \$linux\$)" http.response.contenttype=application/octet-stream http.response.duration=18.748313166s http.response.status=200 http.response.written=29126287 instance.id=a523fc39-f7f4-4285-857d-9e9a2cbccb6c service=registry vars.digest="sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559" vars.name=redis version=v3.0.0-beta.1.m+unknown 127.0.0.1 - - [06/Aug/2024:11:14:25 +0300] "GET /v2/redis/blobs/sha256:efc2b5ad9eec05befa54239d53feeae3569ccbef689aa5e5dbfc25da6c4df559 HTTP/1.1" 200 29126287 "" "docker/26.0.0 go/go1.21.8 git-commit/8b79278 kernel/6.5.0-44-generic os/linux arch/amd64 UpstreamClient(Docker-Client/26.0.0 \$linux\$)" ``` The error itself occurs due to the fact that the context is canceled from outside the frostfs driver code. ## Steps to Reproduce (for bugs) 1. Pull an image from the Docker Pub (not necessarily this one, you can use any one) ``` $ docker pull redis:latest ``` 2. We do all the actions to launch distribution: 2.1 Raising frostfs-aio 2.2 Creating a container 2.3 Add its id and the path to the wallet to the config file distribution: `./cmd/registry/config-dev-frostfs.yml` 2.4 We are building distribution from the root of the project and launching ``` $ make binaries $ ./bin/registry serve cmd/registry/config-dev-frostfs.yml ``` 3. We put a tag on the image so that we can upload it to our registry ``` $ docker tag redis:latest localhost:5000/redis:latest ``` 4. Push the image ``` $ docker push localhost:5000/redis:latest ``` 5. Deleting the image from your computer (so that the pull is complete) ``` $ docker rmi redis:latest $ docker rmi localhost:5000/redis:latest ``` 6. We pool the image and observe an error in the logs ``` $ docker pull localhost:5000/redis:latest ``` ## Your Environment Distribution commit version: 8ceca80274c527fe76cc9f55b52c29d6f094e3e3

r.loginov added the

bug

label 2024-08-06 12:28:38 +00:00

r.loginov added the

discussion

label 2024-08-14 09:55:58 +00:00

r.loginov commented

2024-08-20 12:41:48 +00:00

Author

Member

Additional details:
This error is reproduced as on the release v3.0.0-alpha.1 with FrostFS support so it is on the release v3.0.0-beta.1 with FrostFS support

The error was reproduced on the following environments:

frostfs-dev-env (frostfs-node=0.38.5)
frostfs-dev-env (frostfs-node=0.37.0) - this version was used when testing the release v3.0.0-alpha.1 with FrostFS support
frostfs-aio (frostfs-node=0.38.6)

Important detail: the error is reproduced only if caching is disabled. Caching is disabled by default, details here

Additional details: This error is reproduced as on the release [v3.0.0-alpha.1 with FrostFS support](https://git.frostfs.info/TrueCloudLab/distribution/releases/tag/v3.0.0-alpha.1-tcl.1) so it is on the release [v3.0.0-beta.1 with FrostFS support](https://git.frostfs.info/TrueCloudLab/distribution/releases/tag/v3.0.0-beta.1-tcl.1) The error was reproduced on the following environments: - [frostfs-dev-env](https://git.frostfs.info/TrueCloudLab/frostfs-dev-env/src/commit/d03be14312da6b1bd2f5bcbb113c4594eeaff258) (frostfs-node=0.38.5) - [frostfs-dev-env](https://git.frostfs.info/TrueCloudLab/frostfs-dev-env/src/commit/0f6f2722c2fe672a1246c6f6732c50711d1af271) (frostfs-node=0.37.0) - this version was used when testing the release [v3.0.0-alpha.1 with FrostFS support](https://git.frostfs.info/TrueCloudLab/distribution/releases/tag/v3.0.0-alpha.1-tcl.1) - [frostfs-aio](https://git.process.info/TrueCloudLab/frostfs-aio/src/commit/f0c20be1b9c1918bd753bd5d477d97ff4fec5e2d) (frostfs-node=0.38.6) Important detail: the error is reproduced only if caching is disabled. Caching is disabled by default, details [here](https://git.frostfs.info/TrueCloudLab/distribution/issues/7#issuecomment-36876)

dkirillov commented

2025-01-13 12:59:58 +00:00

Member

It seems this is valid behavior (I mean current distribution code leads to this error). We try do additional things using request context but we already send all data to client and it consider connection done and close it.

See example server:

	http.HandleFunc("/eof", func(w http.ResponseWriter, r *http.Request) {
		content := "some content"
		d := strings.NewReader(content)

		w.Header().Set("Content-Length", strconv.Itoa(len(content)))
		fmt.Println(io.Copy(w, d))
		w.(http.Flusher).Flush()

		time.Sleep(3 * time.Second)
		fmt.Println("eof:", r.Context().Err())
	})

	http.HandleFunc("/noeof", func(w http.ResponseWriter, r *http.Request) {
		content := "some content"
		d := strings.NewReader(content)
		content2 := "some other content"
		d2 := strings.NewReader(content2)

		w.Header().Set("Content-Length", strconv.Itoa(len(content)+len(content2)))
		fmt.Println(io.Copy(w, d))
		w.(http.Flusher).Flush()

		time.Sleep(3 * time.Second)
		fmt.Println(io.Copy(w, d2))
		fmt.Println("no eof:", r.Context().Err())
	})

	http.ListenAndServe(":5001", nil)

run client (it can be golang http client or curl (we will use curl))

$ curl http://localhost:5001/eof
some content

$curl http://localhost:5001/noeof
some contentsome other content

it server we will see:

12 <nil>
eof: context canceled

12 <nil>
18 <nil>
no eof: <nil>

It seems this is valid behavior (I mean current distribution code leads to this error). We try do additional things using request context but we already send all data to client and it consider connection done and close it. See example server: ```golang http.HandleFunc("/eof", func(w http.ResponseWriter, r *http.Request) { content := "some content" d := strings.NewReader(content) w.Header().Set("Content-Length", strconv.Itoa(len(content))) fmt.Println(io.Copy(w, d)) w.(http.Flusher).Flush() time.Sleep(3 * time.Second) fmt.Println("eof:", r.Context().Err()) }) http.HandleFunc("/noeof", func(w http.ResponseWriter, r *http.Request) { content := "some content" d := strings.NewReader(content) content2 := "some other content" d2 := strings.NewReader(content2) w.Header().Set("Content-Length", strconv.Itoa(len(content)+len(content2))) fmt.Println(io.Copy(w, d)) w.(http.Flusher).Flush() time.Sleep(3 * time.Second) fmt.Println(io.Copy(w, d2)) fmt.Println("no eof:", r.Context().Err()) }) http.ListenAndServe(":5001", nil) ``` run client (it can be golang http client or `curl` (we will use `curl`)) ``` $ curl http://localhost:5001/eof some content $curl http://localhost:5001/noeof some contentsome other content ``` it server we will see: ``` 12 <nil> eof: context canceled 12 <nil> 18 <nil> no eof: <nil> ```

👍 1

r.loginov commented

2025-01-20 07:40:01 +00:00

Author

Member

It seems like this is indeed the expected behavior. We can close this bug.