bollard icon indicating copy to clipboard operation
bollard copied to clipboard

`bollard` doesn't throw an error when Docker image not found

Open DeLion13 opened this issue 2 years ago • 3 comments

Here we see a decode_json_from_slice method, where an error handling of the response is happening:

https://github.com/fussybeaver/bollard/blob/e1046a48499eb2068790b2679b2e068ea03f1920/src/read.rs#L107-L124

As I see, I'm getting a stream of Result<CreateImageInfo, Error> when call a create_image function, where CreateImageInfo contains a response details. I caught a strange bug, that was probably an issue with Docker Hub or something else, because the image I've tried to pull definitely existed before and still exists now (I'm talking about Localstack one). It was a message that decode_json_from_slice was trying to decode, but unsuccessfully, and just passed by with Ok(CreateImageInfo) and None fields in the CreateImageInfo structure.

The slice that decode_json_from_slice passed as Ok() looked like this:

{"errorDetail":{"message":"Get \"[https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819\](https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819/)": EOF"},"error":"Get \"[https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819\](https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819/)": EOF"}

As I understand this response actually supposed to be parsed into BuildInfo structure because that is the only one where I can find errorDetail field for deserialisation. Is that expected at all?

I think that errors like these must be handled here. In my case it looked like:

  1. I'm trying to pull image
  2. create_image exited with Ok
  3. I'm getting error that Docker container I'm trying to interact with doesn't exist

DeLion13 avatar Jul 12 '22 16:07 DeLion13

Thanks for the detailed report, I suspect that the docker server is returning an error message but not sending a status code that Bollard considers as an error. If you have any logs of the docker server, that would be helpful. I'll be able to take a closer look next week when I have access to a laptop.

fussybeaver avatar Jul 13 '22 16:07 fussybeaver

Unfortunately, I don't have any logs of the docker server :( This situation happens inconsistently and I'm unable to reproduce it...

[UPD] I have a few logs from bollard, maybe they will be useful for you, these are logs from the start of pulling until the last log after which I got an error:

2022-07-06T10:58:16.333843ZDEBUGbollard::read: Decoding JSON line from stream: {"status":"Pulling from localstack/localstack","id":"0.14.2"}

2022-07-06T10:58:21.633841ZDEBUGbollard::read: Decoding JSON line from stream: {"errorDetail":{"message":"Get \"[https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819\](https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819/)": EOF"},"error":"Get \"[https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819\](https://registry-1.docker.io/v2/localstack/localstack/manifests/sha256:d7aefdaae6712891f13795f538fd855fe4e5a8722249e9ca965e94b69b83b819/)": EOF"}

2022-07-06T10:58:21.634650ZDEBUGbollard::docker: {"Image":"localstack/localstack:0.14.2","HostConfig":{"PortBindings":{"4566/tcp":[{}]}}}

2022-07-06T10:58:21.634963ZDEBUGbollard::uri: Parsing uri: unix://2f7661722f72756e2f646f636b65722e736f636b/containers/create?name=catalog-local-dniicb, client_type: Unix, socket: /var/run/docker.sock

2022-07-06T10:58:21.635067ZDEBUGbollard::docker: unix://2f7661722f72756e2f646f636b65722e736f636b/containers/create?name=catalog-local-dniicb

2022-07-06T10:58:21.635161ZDEBUGbollard::docker: request: Request { method: POST, uri: unix://2f7661722f72756e2f646f636b65722e736f636b/containers/create?name=catalog-local-dniicb, version: HTTP/1.1, headers: {"content-type": "application/json"}, body: Body(Full(b"{\"Image\":\"localstack/localstack:0.14.2\",\"HostConfig\":{\"PortBindings\":{\"4566/tcp\":[{}]}}}")) }

[UPD2] If someone has the same problem, workaround might be easy. In our case, we decided to just retry <...>NotFound error because we know that docker image definitely exists and it might be just a network issue or smth like that.

DeLion13 avatar Jul 14 '22 10:07 DeLion13

Yes, that is useful. It looks like the Docker server starts the stream successfully, but fails midway.

fussybeaver avatar Jul 14 '22 15:07 fussybeaver

Some more info on this. I haven't been able to reproduce this, even by compiling the registry codebase with intentional errors. However, I think there are two things going on here -

  1. The upstream swagger documentation does not expose an errorDetail field in the CreateImageInfo instance. I've looked through the moby codebase, and you are correct in that this field looks like it is emitted on the createImage operation (see the linked ticket above for details). After some more testing, I think the same problem is on the PushImageInfo struct. Bollard does not have a JSON deserialization error, because additional fields on structs during deserialization are silently ignored by default in Serde.
  2. Bollard does not currently fail a stream if the Docker server returns an error JSON struct as part of a larger 200 status code response stream. I think that's something we can correct and implement for the endpoints that do have an error field, but it's a perhaps surprising behaviour change, so I'll fold this into the next new minor version.

fussybeaver avatar Sep 02 '22 12:09 fussybeaver