Bug 1413987

Summary: docker pull with private registry (Artifactory) fails to request bearer token
Product: [Fedora] Fedora Reporter: Mark Mielke <mark>
Component: dockerAssignee: Antonio Murdaca <amurdaca>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: 25CC: adimania, admiller, amurdaca, dwalsh, ichavero, jcajka, jchaloup, lsm5, marianne, mattias.hofvander, miminar, nalin, obockows, riek, sara.c, vbatts
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: docker-1.12.6-6.gitae7d637.fc25 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1418939 (view as bug list) Environment:
Last Closed: 2017-02-08 01:51:26 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1418939    

Description Mark Mielke 2017-01-17 13:49:51 UTC
Description of problem:

This issue is new to Fedora 25 and Docker 1.12. It did not happen on Fedora 24 (1.10.3-55) or RHEL 7 (1.10.3, 1.9.1, others).

Testing with 1.12.6-4.gitf499e8b.fc25.x86_64 to try to "docker pull" from a private repository running Artifactory, I am seeing this output:

    unauthorized: The client does not have permission for manifest

This issue may be related to 1403908. I am opening this as a separate issue to track my particular symptoms to closure. I am re-summarizing the findings that I listed in 1403908.

The Artifactory instance is hosted behind an Nginx transparent reverse proxy. I was able to adjust the Nginx configuration to capture additional information including the request "Authentication" headers, and the response "WWW-Authenticate" headers (if any).

Here is the "fail" case, which is running on Fedora 25 / Docker 1.12.6-4:

10.179.128.4 - - [17/Jan/2017:08:06:20 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: Bearer realm=\x22https://prism.ciena.com/v2/token\x22,service=\x22prism.ciena.com\x22,scope=\x22repository:docker-prism.ciena.com-v2-local:pull,push\x22" 0.001s "GET /v2/ HTTP/1.1" 401 512 "-" "docker/1.12.6 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.6 \x5C(linux\x5C))"
10.179.128.4 - - [17/Jan/2017:08:06:20 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: Bearer realm=\x22https://prism.ciena.com/v2/token\x22,service=\x22prism.ciena.com\x22,scope=\x22repository:docker-prism.ciena.com-v2-local:pull,push\x22" 0.001s "GET /v2/ HTTP/1.1" 401 512 "-" "docker/1.12.6 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.6 \x5C(linux\x5C))"
10.179.128.4 - - [17/Jan/2017:08:06:20 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: -" 0.003s "GET /v2/nginx/manifests/nginx-1.11.8-20161229 HTTP/1.1" 403 483 "-" "docker/1.12.6 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.6 \x5C(linux\x5C))"
10.179.128.4 - - [17/Jan/2017:08:06:20 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: -" 0.001s "GET /v2/nginx/manifests/nginx-1.11.8-20161229 HTTP/1.1" 403 483 "-" "docker/1.12.6 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.6 \x5C(linux\x5C))"

This shows that Docker 1.12.6 is sending HTTP GET on /v2/ and getting 401. It is re-issuing the *same* HTTP GET on /v2/ without any "Authorization" credentials. Artifactory gives the same 401 response. Docker than proceeds to fetch the manifests file which fail with 403 as Artifactory does not consider the request to be properly authorized.

Here is the "success" case, which is running on on Fedora 24 / Docker 1.10.3-55 (with password and bearer token masked):

10.179.128.11 - - [17/Jan/2017:08:06:57 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: Bearer realm=\x22https://prism.ciena.com/v2/token\x22,service=\x22prism.ciena.com\x22,scope=\x22repository:docker-prism.ciena.com-v2-local:pull,push\x22" 0.001s "GET /v2/ HTTP/1.1" 401 512 "-" "docker/1.10.3 go/go1.6.3 kernel/4.8.16-200.fc24.x86_64 os/linux arch/amd64"
10.179.128.11 - mmielke [17/Jan/2017:08:06:59 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: Basic XXXXXXXX" "WWW-Authenticate: -" 1.636s "GET /v2/token?account=mmielke&scope=repository%3Anginx%3Apull&service=prism.ciena.com HTTP/1.1" 200 409 "-" "docker/1.10.3 go/go1.6.3 kernel/4.8.16-200.fc24.x86_64 os/linux arch/amd64"
10.179.128.11 - - [17/Jan/2017:08:06:59 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: Bearer XXXXXXXX" "WWW-Authenticate: -" 0.012s "GET /v2/nginx/manifests/nginx-1.11.8-20161229 HTTP/1.1" 200 1894 "-" "docker/1.10.3 go/go1.6.3 kernel/4.8.16-200.fc24.x86_64 os/linux arch/amd64"

This shows that Docker 1.10.3 is sending HTTP GET on /v2/ and getting 401. It then sending basic auth credentials to the /v2/token service to obtain the bearer token. It then provides the bearer token when request the manifest file. This all works as expected. Artifactory considers the requests properly authorized.

Given that I don't see anything particular about Artifactory above, I am tentatively marking this issue as "High" priority. If, however, there is something particular about Artifactory, and there is a limited user base affected, then please reduce the priority.

Comment 1 Antonio Murdaca 2017-01-17 13:51:41 UTC
For reference we were discussing this here https://bugzilla.redhat.com/show_bug.cgi?id=1403908

Comment 2 Mark Mielke 2017-01-17 14:08:37 UTC
Antonio requested:

    Also, any chance you can test this (now-old) update in your F25 box and tell me if that works? https://bodhi.fedoraproject.org/updates/FEDORA-2016-2f28826f76

I tried this update, and the "docker pull" works. I was able to "rpm -Uvh --oldpackage" downgrade to the 1.12.5-3 version and it worked, and "dnf upgrade" to 1.12.6-4 and see it repeatedly toggle between working and failing.

The trace from Nginx is a little different than 1.10:

10.179.128.18 - - [17/Jan/2017:09:00:01 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: Bearer realm=\x22https://prism.ciena.com/v2/token\x22,service=\x22prism.ciena.com\x22,scope=\x22repository:docker-prism.ciena.com-v2-local:pull,push\x22" 0.001s "GET /v2/ HTTP/1.1" 401 512 "-" "docker/1.12.5 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.5 \x5C(linux\x5C))"
10.179.128.18 - - [17/Jan/2017:09:00:01 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: Bearer realm=\x22https://prism.ciena.com/v2/token\x22,service=\x22prism.ciena.com\x22,scope=\x22repository:docker-prism.ciena.com-v2-local:pull,push\x22" 0.001s "GET /v2/ HTTP/1.1" 401 512 "-" "docker/1.12.5 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.5 \x5C(linux\x5C))"
10.179.128.18 - - [17/Jan/2017:09:00:01 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: -" "WWW-Authenticate: -" 0.001s "GET /v2/nginx/manifests/nginx-1.11.8-20161229 HTTP/1.1" 403 483 "-" "docker/1.12.5 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.5 \x5C(linux\x5C))"
10.179.128.18 - mmielke [17/Jan/2017:09:00:03 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: Basic XXXXXXXX" "WWW-Authenticate: -" 1.977s "GET /v2/nginx/manifests/nginx-1.11.8-20161229 HTTP/1.1" 200 1894 "-" "docker/1.12.5 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.5 \x5C(linux\x5C))"
10.179.128.18 - mmielke [17/Jan/2017:09:00:05 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: Basic XXXXXXXX" "WWW-Authenticate: -" 1.520s "GET /v2/nginx/manifests/nginx-1.11.8-20161229 HTTP/1.1" 200 1894 "-" "docker/1.12.5 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.5 \x5C(linux\x5C))"
10.179.128.18 - mmielke [17/Jan/2017:09:00:05 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: Basic XXXXXXXX" "WWW-Authenticate: -" 0.001s "GET /v2/token?account=mmielke&scope=repository%3Anginx%3Apull&service=prism.ciena.com HTTP/1.1" 200 409 "-" "docker/1.12.5 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.5 \x5C(linux\x5C))"
10.179.128.18 - - [17/Jan/2017:09:00:05 -0500] TLSv1.2/ECDHE-RSA-AES128-GCM-SHA256 "Authorization: Bearer XXXXXXXX" "WWW-Authenticate: -" 0.009s "GET /v2/nginx/manifests/sha256:114dec9d608249f96a4a8a2567ed3fd9a2d1061160b9b3a41fc07091f0bd6b1c HTTP/1.1" 200 1894 "-" "docker/1.12.5 go/go1.7.4 kernel/4.9.3-200.fc25.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/1.12.5 \x5C(linux\x5C))"

It looks like it still does the HTTP GET on /v2/ without authentication credentials, even though it received 401 on the first request. In Docker 1.10, it used to respond to this 401 immediately with credentials.

When it does fetch the manifests, it fails with 403, but then it tries basic auth twice (the same request twice?) which seems like this might be a mistake? 

Then, when it does fetch the image layer, it finally provides the bearer token which also succeeds?

I think I prefer the 1.10 behaviour. :-)

Comment 3 Fedora Update System 2017-01-30 16:37:02 UTC
docker-1.12.6-6.gitae7d637.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-1f25542810

Comment 4 Antonio Murdaca 2017-01-30 16:38:18 UTC
Mark could you try out the update in fedora updates-testing? That fixes this bugzilla for me

Comment 5 Fedora Update System 2017-01-31 03:52:17 UTC
docker-1.12.6-6.gitae7d637.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-1f25542810

Comment 6 Mark Mielke 2017-02-02 03:30:11 UTC
Thanks, Antonio. I am seeing success with this update so far.

Comment 10 Fedora Update System 2017-02-08 01:51:26 UTC
docker-1.12.6-6.gitae7d637.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.