registry auth failed randomly on docker push with 'unauthorized: authentication required' message

I have an external registry 1.4.1 reversed proxyed by nginx 1.10.1, and gitlab 8.10.3 configured for token authentication. Both services are running on CoreOS 1068.8.0 which has docker 1.10.3 installed.

I didn't have the bug when I had a simple silly auth configured as a htpasswd auth on nginx itself.

Now pushes are usually stopping in the middle of the process, not necessarily after a long time (i configured a token validity for more than 30min anyway), with the message unauthorized: authentication required.

On the registry side, this is the relevant part of the log (after the 2nd PUT), complaining suddenly about an insufficient scope:

Aug 02 15:05:50 coreos1 docker[975]: @ - - [02/Aug/2016:14:05:50 +0000] "HEAD /v2/docker/mattermost-gitlab/blobs/sha256:5ce7af39396d47482ed14588ede3d6d2a91ad2fc414ae4dfb0192b415b70b029 HTTP/1.0" 200 0 "" "docker/1.10.3 go/go1.6.1 git-commit/20f81dd kernel
Aug 02 15:05:50 coreos1 docker[975]: time="2016-08-02T14:05:50Z" level=info msg="response completed" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=e86af444-2889-4c6c-9fe4-2eec65e61bb0 http.request.method=PUT http.request.remotead
Aug 02 15:05:50 coreos1 docker[975]: @ - - [02/Aug/2016:14:05:50 +0000] "PUT /v2/docker/mattermost-gitlab/blobs/uploads/86429402-fa75-48e6-8d5e-ebe99b22a101?_state=1S4vlDcUMd8Zi17rIE6mfc_hf4cIZRmaI9rtsllpnNR7Ik5hbWUiOiJkb2NrZXIvbWF0dGVybW9zdC1naXRsYWIiLCJ
Aug 02 15:05:50 coreos1 docker[975]: time="2016-08-02T14:05:50Z" level=info msg="response completed" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=3be245a8-76e2-42b1-b192-9f23c04e041a http.request.method=POST http.request.remotea
Aug 02 15:05:50 coreos1 docker[975]: @ - - [02/Aug/2016:14:05:50 +0000] "POST /v2/docker/mattermost-gitlab/blobs/uploads/ HTTP/1.0" 202 0 "" "docker/1.10.3 go/go1.6.1 git-commit/20f81dd kernel/4.4.0-31-generic os/linux arch/amd64"
Aug 02 15:05:50 coreos1 docker[975]: time="2016-08-02T14:05:50Z" level=info msg="response completed" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=29ad7290-9942-415b-ba92-4659d18c5cd8 http.request.method=HEAD http.request.remotea
Aug 02 15:05:50 coreos1 docker[975]: @ - - [02/Aug/2016:14:05:50 +0000] "HEAD /v2/docker/mattermost-gitlab/blobs/sha256:29d02472b0432ffab194bd486cac13de5738866c4b2c6b388cbdcd79e11d4b8b HTTP/1.0" 200 0 "" "docker/1.10.3 go/go1.6.1 git-commit/20f81dd kernel
Aug 02 15:05:56 coreos1 docker[975]: time="2016-08-02T14:05:56Z" level=info msg="response completed" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=e6e32666-673d-4e11-bc15-ff8bec4726ce http.request.method=POST http.request.remotea
Aug 02 15:05:56 coreos1 docker[975]: @ - - [02/Aug/2016:14:05:56 +0000] "POST /v2/docker/mattermost-gitlab/blobs/uploads/ HTTP/1.0" 202 0 "" "docker/1.10.3 go/go1.6.1 git-commit/20f81dd kernel/4.4.0-31-generic os/linux arch/amd64"
Aug 02 15:06:05 coreos1 docker[975]: time="2016-08-02T14:06:05Z" level=info msg="response completed" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=93a83a6d-1f58-4fed-9807-6a9380c40512 http.request.method=PATCH http.request.remote
Aug 02 15:06:05 coreos1 docker[975]: @ - - [02/Aug/2016:14:06:05 +0000] "PATCH /v2/docker/mattermost-gitlab/blobs/uploads/54db28c6-f6c6-4940-bbbf-3d4d62eb6a6b?_state=JXRlBtFTNQE269d293S5UXtdyc2PIwK7qJbMCciekXp7Ik5hbWUiOiJkb2NrZXIvbWF0dGVybW9zdC1naXRsYWIiL
Aug 02 15:06:05 coreos1 docker[975]: time="2016-08-02T14:06:05Z" level=info msg="response completed" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=63725f69-9cca-48cc-a06c-56af9ecd5f94 http.request.method=PUT http.request.remotead
Aug 02 15:06:05 coreos1 docker[975]: @ - - [02/Aug/2016:14:06:05 +0000] "PUT /v2/docker/mattermost-gitlab/blobs/uploads/54db28c6-f6c6-4940-bbbf-3d4d62eb6a6b?_state=KrctV9P5eNl1RQMuZGyTynBCzY5AKZvlbyQ8iIb6Bft7Ik5hbWUiOiJkb2NrZXIvbWF0dGVybW9zdC1naXRsYWIiLCJ
Aug 02 15:06:06 coreos1 docker[975]: time="2016-08-02T14:06:06Z" level=info msg="response completed" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=694f062c-27dc-45b1-808d-5976ac0b79e6 http.request.method=HEAD http.request.remotea
Aug 02 15:06:06 coreos1 docker[975]: @ - - [02/Aug/2016:14:06:06 +0000] "HEAD /v2/docker/mattermost-gitlab/blobs/sha256:834ee5c94396a7246dee194ca3f4464bdc6e64eba4d8bacbef3aeb3d292bc381 HTTP/1.0" 200 0 "" "docker/1.10.3 go/go1.6.1 git-commit/20f81dd kernel
Aug 02 15:06:08 coreos1 docker[975]: time="2016-08-02T14:06:08Z" level=warning msg="error authorizing context: insufficient scope" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=66f304ec-2aa5-45e3-98c7-ad0e96341dfc http.request.me
Aug 02 15:06:08 coreos1 docker[975]: @ - - [02/Aug/2016:14:06:08 +0000] "POST /v2/docker/mattermost-gitlab/blobs/uploads/?from=docker%2Fregistry&mount=sha256%3Aa2de530e53f7ba75dfe24749ca371601690a442af9fe00d7c63099b4d23b173a HTTP/1.0" 401 291 "" "docker/1
Aug 02 15:06:08 coreos1 docker[975]: time="2016-08-02T14:06:08Z" level=warning msg="error authorizing context: insufficient scope" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=e8f79cde-9921-41ed-a0d0-4b258ad52e35 http.request.me
Aug 02 15:06:08 coreos1 docker[975]: @ - - [02/Aug/2016:14:06:08 +0000] "POST /v2/docker/mattermost-gitlab/blobs/uploads/ HTTP/1.0" 401 228 "" "docker/1.10.3 go/go1.6.1 git-commit/20f81dd kernel/4.4.0-31-generic os/linux arch/amd64"
Aug 02 15:06:09 coreos1 docker[975]: time="2016-08-02T14:06:09Z" level=warning msg="error authorizing context: insufficient scope" go.version=go1.5.4 http.request.host=dkr.local.lan http.request.id=bbc5bb2d-49ba-4a80-8d56-580081fad6de http.request.me

Anyone experiencing this is issue ? (I just try the registry auth since 8.10.x so don't known if it fails for another version).

Edited by 🤖 GitLab Bot 🤖