http auth scope parsing fails with multiple scopes about image

[mtrmac]

Thanks for your report.

Yes, that would fail, and we need to look into whether/how that should be handled.

OTOH, we should already be asking for the right scope; this happens only on a secondary authentication path. I wonder why the primary path is failing in the first place. Is it possible that your credentials just don’t allow the push at all? Or maybe that your current credentials don’t allow pulling from repos/repo2 (but you did pull from that location with some other credentials previously, triggering a reuse attempt)?

---

And, those are logged errors on that secondary authentication path, but that path does not actually directly cause anything to fail. I’d expect an error message recording the actual reason to fail to exist (in this case, probably some permission denied with that the secondary authentication was trying to recover from).

Please collect a full podman --log-level=debug push … output.

[filippog]

Thanks for your report.

Yes, that would fail, and we need to look into whether/how that should be handled.

OTOH, we should already be asking for the right scope; this happens only on a secondary authentication path. I wonder why the primary path is failing in the first place. Is it possible that your credentials just don’t allow the push at all? Or maybe that your current credentials don’t allow pulling from repos/repo2 (but you did pull from that location with some other credentials previously, triggering a reuse attempt)?

Thank you for your insight here. After further investigation it turns out that the upgrade from gitlab 15 to 16 broke "podman push" in this deployment! We have noticed a gitlab 15 "podman push" to work as expected for the same container.

And, those are logged errors on that secondary authentication path

, but that path does not actually directly cause anything to fail. I’d expect an error message recording the actual reason to fail to exist (in this case, probably some permission denied with that the secondary authentication was trying to recover from).

Please collect a full podman --log-level=debug push … output.

Certainly, please find the log attached: podman-push-gitlab-16.log

[mtrmac]

time="2023-06-02T07:19:48Z" level=debug msg="Detected insufficient_scope error, will retry request with updated scope"
time="2023-06-02T07:19:48Z" level=debug msg="GET https://gitlab.foo.bar/jwt/auth?scope=repository%3Arepos%2Frepo1%3Apull%2Cpush&scope=repository%3Arepos%2Frepo1%3Apull%2Cpush&service=container_registry"

So we are getting an insufficient_scope error. In response for that we ask for two scopes: 1. the one we hard-code, and we already got a token for, and 2. the one the registry is complaining about. The URL above shows that — but the two are identical!

Assuming this isn’t an artifact of an inaccurate log redaction, that sounds like something that needs to be diagnosed server-side. Why is the registry reporting “insufficient scope” for a scope that has already been granted?

---

Error: writing blob: initiating layer upload to /v2/repos/repo1/blobs/uploads/ in registry.gitlab.foo.bar: requested access to the resource is denied

This is the actual upload-terminating failure.

And more details in the error log:

time="2023-06-02T07:19:48Z" level=debug msg="Error initiating layer upload, response http.Response{Status:\"401 Unauthorized\", StatusCode:401, Proto:\"HTTP/1.1\", ProtoMajor:1, ProtoMinor:1, Header:http.Header{\"Connection\":[]string{\"keep-alive\"}, \"Content-Length\":[]string{\"244\"}, \"Content-Type\":[]string{\"application/json\"}, \"Date\":[]string{\"Fri, 02 Jun 2023 07:19:55 GMT\"}, \"Docker-Distribution-Api-Version\":[]string{\"registry/2.0\"}, \"Server\":[]string{\"nginx\"}, \"Www-Authenticate\":[]string{\"Bearer realm=\\\"https://gitlab.foo.bar/jwt/auth\\\",service=\\\"container_registry\\\",scope=\\\"repository:repos/repo1:pull,push\\\",error=\\\"insufficient_scope\\\"\"}, \"X-Content-Type-Options\":[]string{\"nosniff\"}}, Body:(*http.bodyEOFSignal)(0xc000728b80), ContentLength:244, TransferEncoding:[]string(nil), Close:false, Uncompressed:false, Trailer:http.Header(nil), Request:(*http.Request)(0xc000820000), TLS:(*tls.ConnectionState)(0xc000656160)}"

And again it is complaining about a scope that was granted in every earlier /jwt/auth call; at least I can’t find anything to suggest a /jwt/auth call has ever failed.

[filippog]

time="2023-06-02T07:19:48Z" level=debug msg="Detected insufficient_scope error, will retry request with updated scope"
time="2023-06-02T07:19:48Z" level=debug msg="GET https://gitlab.foo.bar/jwt/auth?scope=repository%3Arepos%2Frepo1%3Apull%2Cpush&scope=repository%3Arepos%2Frepo1%3Apull%2Cpush&service=container_registry"

So we are getting an insufficient_scope error. In response for that we ask for two scopes: 1. the one we hard-code, and we already got a token for, and 2. the one the registry is complaining about. The URL above shows that — but the two are identical!

Assuming this isn’t an artifact of an inaccurate log redaction, that sounds like something that needs to be diagnosed server-side. Why is the registry reporting “insufficient scope” for a scope that has already been granted?

Thank you for your help, I have double checked the non-redacted log and the requested repos are indeed the same! I have opened an issue with gitlab registry upstream here: https://gitlab.com/gitlab-org/gitlab/-/issues/414402

[mtrmac]

@filippog reading https://gitlab.com/gitlab-org/gitlab/-/issues/414402 suggests that this was caused by a missing podman login; and in that case the non-debug-log

Error: writing blob: initiating layer upload to /v2/repos/repo1/blobs/uploads/ in registry.gitlab.foo.bar: requested access to the resource is denied

seems basically appropriate.

Is there anything that needs to be fixed in c/image?

[filippog]

Hello @mtrmac ! That's indeed the case, the root cause was a missing podman login. Thank you for your help here, I don't think there's anything else actionable here, closing!

[mtrmac]

Thanks for the confirmation.