Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failure to push when using multi-node context #177

Open
Johannestegner opened this issue Oct 24, 2019 · 44 comments
Open

Failure to push when using multi-node context #177

Johannestegner opened this issue Oct 24, 2019 · 44 comments

Comments

@Johannestegner
Copy link

I will try to describe my issue as good as I can... much of the setup is done by trail and error, so I could just be doing it wrong, but the documentation for multi-node buildx instances is quite sparse at the moment, so it's the best I could!

Scenario:
I have connected a ARM64 machines docker daemon to one of my AMD64 machines through buildx to be able to utilize the native ARM64 engine for ARM64 builds. While the engines seems to work great together while building, when they are about to push they stop after the AMD64 machine have pushed the first tag.

There are no errors in the build logs, so it looks like it was built and pushed successfully while no images are pushed to the registries.

I have tried both by connecting to the remote daemon over tcp and over ssh, while none of them seems to work for me.
Connection was done through docker buildx create --append --name <builder-name> tcp://ip:2375

It does though, seem like the registries do notice that something was being pushed as they say that the last update was "1 minute ago", while no images have been changed.

The last part of the build log looks like this when it fails to push successfully:

#11 exporting to image
#11 exporting layers
#11 exporting layers 15.1s done
#11 pushing layers
#11 exporting manifest sha256:e79069017c796a48ecd0122aa6bb4b5a71d5366dad15a22d8dae3cf3445ffe85 0.0s done
#11 exporting config sha256:7539d58986be67c54043cf7c10f759f17d9f2c27cf48baa904ce6601e915af89 0.0s done
#11 exporting manifest list sha256:c13816f3f05006682736fcba1eb7cc9e38fd972c31d3a26155d8a80a33de1539 0.0s done
#11 pushing layers 6.6s done
#11 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base
#11 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base 1.6s done
#11 pushing layers 5.0s done
#11 pushing manifest for docker.io/jitesoft/node-base
#11 pushing manifest for docker.io/jitesoft/node-base 0.8s done
#11 DONE 29.2s

#16 merging manifest list registry.gitlab.com/jitesoft/dockerfiles/node-base...
#16 DONE 4.4s

While a "real" successful one looks like the following (using only the AMD64 machine with Qemu):

#13 exporting to image
#13 exporting layers
#13 exporting layers 12.0s done
#13 exporting manifest sha256:120e8ce6e70745087f148f6991b9c072a331a42b15224d7b073382dbd7f8862f 0.0s done
#13 exporting config sha256:708ed343e10cf46f540039b355a21fa962be06dfb0be6adf88385e11974872fb 0.0s done
#13 exporting manifest sha256:0a495831b15cdf834d3d5fbd56acb2834a9161d42fac9fe8ec69c2435807a79f 0.0s done
#13 exporting config sha256:33d5f0ebafc4f4a6b33acd9726a2517e916713616c539f0c28c210976f84b424 0.0s done
#13 exporting manifest list sha256:c5a0e0562036da3573f03c609923266779df8dc4b2f3d5de6fa1d4b11aec108a 0.0s done
#13 pushing layers
#13 pushing layers 6.0s done
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:12.13.0-slim
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:12.13.0-slim 3.9s done
#13 pushing layers 4.9s done
#13 pushing manifest for docker.io/jitesoft/node-base:12.13.0-slim
#13 pushing manifest for docker.io/jitesoft/node-base:12.13.0-slim 1.5s done
#13 pushing layers 1.8s done
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:12-slim
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:12-slim 3.0s done
#13 pushing layers 1.4s done
#13 pushing manifest for docker.io/jitesoft/node-base:12-slim
#13 pushing manifest for docker.io/jitesoft/node-base:12-slim 1.1s done
#13 pushing layers 1.8s done
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:stable-slim
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:stable-slim 3.2s done
#13 pushing layers 1.0s done
#13 pushing manifest for docker.io/jitesoft/node-base:stable-slim
#13 pushing manifest for docker.io/jitesoft/node-base:stable-slim 1.4s done
#13 pushing layers 1.9s done
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:lts-slim
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:lts-slim 3.5s done
#13 pushing layers 1.1s done
#13 pushing manifest for docker.io/jitesoft/node-base:lts-slim
#13 pushing manifest for docker.io/jitesoft/node-base:lts-slim 1.1s done
#13 pushing layers 2.0s done
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:erbium-slim
#13 pushing layers
#13 pushing manifest for registry.gitlab.com/jitesoft/dockerfiles/node-base:erbium-slim 8.1s done
#13 pushing layers 1.0s done
#13 pushing manifest for docker.io/jitesoft/node-base:erbium-slim
#13 pushing manifest for docker.io/jitesoft/node-base:erbium-slim 1.0s done
#13 DONE 62.8s 

If there are any logs that I can't find that would help in debugging the issue or any more information that you could need, please let me know!

Docker version output:
AMD machine:

Client: Docker Engine - Community                                                                                                                                                                                                                                                                                                                                           Version:           19.03.4                                                                                                                                                                                                                                                                                                                                                 API version:       1.40                                                                                                                                                                                                                                                                                                                                                    Go version:        go1.12.10                                                                                                                                                                                                                                                                                                                                               Git commit:        9013bf583a                                                                                                                                                                                                                                                                                                                                              Built:             Fri Oct 18 15:54:09 2019                                                                                                                                                                                                                                                                                                                                OS/Arch:           linux/amd64                                                                                                                                                                                                                                                                                                                                             Experimental:      true                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              Server: Docker Engine - Community                                                                                                                                                                                                                                                                                                                                           Engine:                                                                                                                                                                                                                                                                                                                                                                     Version:          19.03.4                                                                                                                                                                                                                                                                                                                                                  API version:      1.40 (minimum version 1.12)                                                                                                                                                                                                                                                                                                                              Go version:       go1.12.10                                                                                                                                                                                                                                                                                                                                                Git commit:       9013bf583a                                                                                                                                                                                                                                                                                                                                               Built:            Fri Oct 18 15:52:40 2019                                                                                                                                                                                                                                                                                                                                 OS/Arch:          linux/amd64                                                                                                                                                                                                                                                                                                                                              Experimental:     true                                                                                                                                                                                                                                                                                                                                                    containerd:
  Version:          1.2.10
  GitCommit:        b34a5c8af56e510852c35414db4c1f4fa6172339
 runc:
  Version:          1.0.0-rc8+dev
  GitCommit:        3e425f80a8c931f88e6d94a8c831b9d5aa481657
 docker-init:
  Version:          0.18.0
  GitCommit:        fec3683

ARM machine:

Client: Docker Engine - Community
 Version:           19.03.4
 API version:       1.40
 Go version:        go1.12.10
 Git commit:        9013bf5
 Built:             Fri Oct 18 15:52:24 2019
 OS/Arch:           linux/arm64
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          19.03.4
  API version:      1.40 (minimum version 1.12)
  Go version:       go1.12.10
  Git commit:       9013bf5
  Built:            Fri Oct 18 15:50:53 2019
  OS/Arch:          linux/arm64
  Experimental:     true
 containerd:
  Version:          1.2.10
  GitCommit:        b34a5c8af56e510852c35414db4c1f4fa6172339
 runc:
  Version:          1.0.0-rc8+dev
  GitCommit:        3e425f80a8c931f88e6d94a8c831b9d5aa481657
 docker-init:
  Version:          0.18.0
  GitCommit:        fec3683

Buildx version:

AMD machine:

github.com/docker/buildx v0.3.1 6db68d029599c6710a32aa7adcba8e5a344795a7

ARM machine:

github.com/docker/buildx v0.3.1-tp-docker 6db68d029599c6710a32aa7adcba8e5a344795a7
@tonistiigi
Copy link
Member

I don't see any errors in the output you posted. The difference in output between multi-node and single-node builds is expected. You can get the logs by running docker logs on the buildkit container. buildx create --buildkitd-flag '--debug' to enable debug mode.

@Johannestegner
Copy link
Author

Right, I cant see any either, hehe. I will take a look at the buildkit logs with the debug flag asap and update the issue when I have them.

Is buildkit supposed to connect docker daemons in the way I said before, or have I missed something which might be vital?

@Johannestegner
Copy link
Author

Small update, checked the buildkit container logs and found the following over and over through the logs:

time="2019-10-23T21:06:23Z" level=error msg="/moby.buildkit.v1.Control/Solve returned error: registry.gitlab.com/jitesoft/dockerfiles/node-base:12.13.0-slim not found\ngithub.com/containerd/containerd/remotes/docker.(*dockerResolver).Resolve\n\t/src/vendor/github.com/containerd/containerd/remotes/docker/resolver.go:307\ngithub.com/moby/buildkit/util/pull.(*cachedResolver).Resolve\n\t/src/util/pull/resolver.go:145\ngithub.com/moby/buildkit/util/pull.(*Puller).Resolve.func1\n\t/src/util/pull/pull.go:75\nsync.(*Once).Do\n\t/usr/local/go/src/sync/once.go:44\ngithub.com/moby/buildkit/util/pull.(*Puller).Resolve\n\t/src/util/pull/pull.go:51\ngithub.com/moby/buildkit/source/containerimage.(*puller).CacheKey\n\t/src/source/containerimage/pull.go:144\ngithub.com/moby/buildkit/solver/llbsolver/ops.(*sourceOp).CacheMap\n\t/src/solver/llbsolver/ops/source.go:65\ngithub.com/moby/buildkit/solver.(*sharedOp).CacheMap.func1\n\t/src/solver/jobs.go:635\ngithub.com/moby/buildkit/util/flightcontrol.(*call).run\n\t/src/util/flightcontrol/flightcontrol.go:119\nsync.(*Once).Do\n\t/usr/local/go/src/sync/once.go:44\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_arm64.s:1128\nfailed to load cache key\ngithub.com/moby/buildkit/solver.(*edge).unpark.func1\n\t/src/solver/edge.go:338\ngithub.com/moby/buildkit/solver/internal/pipe.NewWithFunction.func2\n\t/src/solver/internal/pipe/pipe.go:82\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_arm64.s:1128\nfailed to build LLB\ngithub.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve\n\t/src/solver/llbsolver/bridge.go:116\ngithub.com/moby/buildkit/frontend/gateway/forwarder.(*bridgeClient).Solve\n\t/src/frontend/gateway/forwarder/forward.go:44\ngithub.com/moby/buildkit/frontend/dockerfile/builder.Build.func3.1\n\t/src/frontend/dockerfile/builder/build.go:382\ngolang.org/x/sync/errgroup.(*Group).Go.func1\n\t/src/vendor/golang.org/x/sync/errgroup/errgroup.go:58\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_arm64.s:1128\nfailed to solve with frontend dockerfile.v0\ngithub.com/moby/buildkit/solver/llbsolver.(*llbBridge).Solve\n\t/src/solver/llbsolver/bridge.go:127\ngithub.com/moby/buildkit/solver/llbsolver.(*Solver).Solve\n\t/src/solver/llbsolver/solver.go:136\ngithub.com/moby/buildkit/control.(*Controller).Solve\n\t/src/control/control.go:276\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler.func1\n\t/src/api/services/control/control.pb.go:1364\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/src/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/server.go:57\nmain.unaryInterceptor.func1\n\t/src/cmd/buildkitd/main.go:526\ngithub.com/moby/buildkit/api/services/control._Control_Solve_Handler\n\t/src/api/services/control/control.pb.go:1366\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/src/vendor/google.golang.org/grpc/server.go:972\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/src/vendor/google.golang.org/grpc/server.go:1252\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/src/vendor/google.golang.org/grpc/server.go:691\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_arm64.s:1128"
time="2019-10-24T04:13:47Z" level=warning msg="reference for unknown type: application/vnd.buildkit.cacheconfig.v0"
2019/10/24 14:20:02 Unsolicited response received on idle HTTP channel starting with "HTTP/1.0 400 Bad Request\nCache-Control: no-cache\nConnection: close\nContent-Type: text/html\n\n<!DOCTYPE html>\n<html>\n<head>\n  <meta content=\"width=device-width, initial-scale=1, maximum-scale=1\" name=\"viewport\">\n  <title>400 Bad Request</title>\n  <style>\n    body {\n      color: #666;\n      text-align: center;\n      font-family: \"Helvetica Neue\", Helvetica, Arial, sans-serif;\n      margin: auto;\n      font-size: 14px;\n    }\n\n    h1 {\n      font-size: 56px;\n      line-height: 100px;\n      font-weight: normal;\n      color: #456;\n    }\n\n    h2 {\n      font-size: 24px;\n      color: #666;\n      line-height: 1.5em;\n    }\n\n    h3 {\n      color: #456;\n      font-size: 20px;\n      font-weight: normal;\n      line-height: 28px;\n    }\n\n    hr {\n      max-width: 800px;\n      margin: 18px auto;\n      border: 0;\n      border-top: 1px solid #EEE;\n      border-bottom: 1px solid white;\n    }\n\n    img {\n      max-width: 40vw;\n    }\n\n    .container {\n      margin: auto 20px;\n    }\n  </style>\n</head>\n\n<body>\n  <h1>\n    <img src=\"data:image/svg+xml;base64,PHN2ZyB3aWR0aD0iMjEwIiBoZWlnaHQ9IjIxMCIgdmlld0JveD0iMCAwIDIxMCAyMTAiIHhtbG5zPSJodHRwOi8vd3d3LnczLm9yZy8yMDAwL3N2ZyI+CiAgPHBhdGggZD0iTTEwNS4wNjE0IDIwMy42NTVsMzguNjQtMTE4LjkyMWgtNzcuMjhsMzguNjQgMTE4LjkyMXoiIGZpbGw9IiNlMjQzMjkiLz4KICA8cGF0aCBkPSJNMTA1LjA2MTQgMjAzLjY1NDhsLTM4LjY0LTExOC45MjFoLTU0LjE1M2w5Mi43OTMgMTE4LjkyMXoiIGZpbGw9IiNmYzZkMjYiLz4KICA8cGF0aCBkPSJNMTIuMjY4NSA4NC43MzQxbC0xMS43NDIgMzYuMTM5Yy0xLjA3MSAzLjI5Ni4xMDIgNi45MDcgMi45MDYgOC45NDRsMTAxLjYyOSA3My44MzgtOTIuNzkzLTExOC45MjF6IiBmaWxsPSIjZmNhMzI2Ii8+CiAgPHBhdGggZD0iTTEyLjI2ODUgODQuNzM0Mmg1NC4xNTNsLTIzLjI3My03MS42MjVjLTEuMTk3LTMuNjg2LTYuNDExLTMuNjg1LTcuNjA4IDBsLTIzLjI3MiA3MS42MjV6IiBmaWxsPSIjZTI0MzI5Ii8+CiAgPHBhdGggZD0iTTEwNS4wNjE0IDIwMy42NTQ4bDM4LjY0LTExOC45MjFoNTQuMTUzbC05Mi43OTMgMTE4LjkyMXoiIGZpbGw9IiNmYzZkMjYiLz4KICA8cGF0aCBkPSJNMTk3Ljg1NDQgODQuNzM0MWwxMS43NDIgMzYuMTM5YzEuMDcxIDMuMjk2LS4xMDIgNi45MDctMi45MDYgOC45NDRsLTEwMS42MjkgNzMuODM4IDkyLjc5My0xMTguOTIxeiIgZmlsbD0iI2ZjYTMyNiIvPgogIDxwYXRoIGQ9Ik0xOTcuODU0NCA4NC43MzQyaC01NC4xNTNsMjMuMjczLTcxLjYyNWMxLjE5Ny0zLjY4NiA2LjQxMS0zLjY4NSA3LjYwOCAwbDIzLjI3MiA3MS42MjV6IiBmaWxsPSIjZTI0MzI5Ii8+Cjwvc3ZnPgo=\" alt=\"GitLab Logo\" /><br />\n    400\n  </h1>\n  <div class=\"container\">\n    <h3>Your browser sent an invalid request.</h3>\n    <hr />\n    <p>Please contact your GitLab administrator if you think this is a mistake.</p>\n  </div>\n</body>\n</html>\n<html>\n"; err=<nil>

From the looks of it, it seems like the specific daemon have issues with both pulling and pushing to the specific repositories, could this be the issue? The client SHOULD be logged in, as it is able to push with a single daemon... and I'm guessing that it is only the client that needs to "log in", right?

@Johannestegner
Copy link
Author

Oh and a note: I push to my gitlab registry first then docker hub.

@Johannestegner
Copy link
Author

Thought I'd update this issue with a bit more information.
It does seem like I got it to work partially, unsure if it worked like this the last time I messed with it too:

When I push my image, it pushes the first tag only.
I'm checking the code to see if I can find any issues there, but my go skills are kind of... un-sharpened, so not finding anything usefully there (yet, hehe). Will activate the debug flag again and see if I can find any more information there since last time.

@Johannestegner
Copy link
Author

Johannestegner commented Nov 13, 2019

So, the debug logs did give me quite a bit of information.

The first thing that I saw was the following:

time="2019-11-13T09:04:30Z" level=debug msg=push digest="sha256:1b43e69507299c7f03b024fd9219c12557edff878295e63a464bce8b3226286e" mediatype=application/vnd.docker.distribution.manifest.v2+json size=1786
time="2019-11-13T09:04:30Z" level=debug msg="do request" digest="sha256:1b43e69507299c7f03b024fd9219c12557edff878295e63a464bce8b3226286e" mediatype=application/vnd.docker.distribution.manifest.v2+json request.headers="map[Accept:[application/vnd.docker.distribution.manifest.v2+json, *]]" request.method=HEAD size=1786 url="https://registry-1.docker.io/v2/jitesoft/paclair/manifests/sha256:1b43e69507299c7f03b024fd9219c12557edff878295e63a464bce8b3226286e"
time="2019-11-13T09:04:30Z" level=debug msg="fetch response received" digest="sha256:1b43e69507299c7f03b024fd9219c12557edff878295e63a464bce8b3226286e" mediatype=application/vnd.docker.distribution.manifest.v2+json response.headers="map[Content-Length:[192] Content-Type:[application/json] Date:[Wed, 13 Nov 2019 09:04:30 GMT] Docker-Distribution-Api-Version:[registry/2.0] Strict-Transport-Security:[max-age=31536000]]" size=1786 status="404 Not Found" url="https://registry-1.docker.io/v2/jitesoft/paclair/manifests/sha256:1b43e69507299c7f03b024fd9219c12557edff878295e63a464bce8b3226286e"

Something that I would personally thing should produce a warning :)

The second thing that I noticed, which is probably the actual error was the following:

time="2019-11-13T09:04:27Z" level=debug msg=Unauthorized digest="sha256:8bfa913040406727f36faa9b69d0b96e071b13792a83ad69c19389031a9f3797" header="Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:jitesoft/paclair:pull\"" mediatype=application/vnd.docker.image.rootfs.diff.tar.gzip size=2717778

It seems that when using multiple nodes, they have lost their auth token and get a Unauthorized response!

This is really odd, as it works perfectly fine if I remove the secondary node...
The client on the primary node (the one I create the build contexts in) is authenticated fine, I can pull from private registries and all and I can see it fetch the authentication token from dockerhub, but when it pushes from the secondary node, it's no longer authenticated (does it not send over the authentication token to the secondary node?)!

This should probably not just be a warning, but rather an error. If the builder is not authed it won't be able to do anything, hence it should just crash imho.

@Johannestegner
Copy link
Author

@tonistiigi I will gladly hand out some more debug logs if that would help more, but I would prefer to do that private as it might contain keys and stuff that I would rather not share openly ;P

@Johannestegner
Copy link
Author

Hi there!
I'm still having this issue? Is anyone else experiencing this or am I doing something wrong? I've tried multiple times with multiple machines, still no go. As of right now, I have to use qemu instead of my ARM64 machine, which makes my arm builds extremely slow.

@StarGate01
Copy link

StarGate01 commented Feb 14, 2020

I am experiencing the same issue, any updates on this?

Edit: I fixed my problem by not using a custom registry port. Apparently the port does not get propagated to the builder correctly.

@Johannestegner
Copy link
Author

Still issues here. Using public registries, so no specific ports set here :/
Have been trying to fix it in different ways, multiple machines, multiple versions of both buildx and docker, no fix.

If anyone who have insight wish more logs or anything, let me know and I'll gladly send them over!

@StarGate01
Copy link

I found something that might help you in your investigation. On my systems, buildx does not send any username information when pushing (or pulling from cache) multi-arch images. I do not know how it is nontheless authentificated, I guess the builder caches only the digest auth token and not the username string.

Theory: Some registries reguire the username string (actor.name field in the registry metadata / notifications) but it is not set.

@StarGate01
Copy link

StarGate01 commented Feb 18, 2020

To further support my argument, I pulled the access logs for a push from buildx from my nginx gateway:


[redacted-ip] - chonal [18/Feb/2020:14:49:31 +0000] "GET /v2/token?scope=repository%3Apublic%2Fhello-ci%3Apull&scope=repository%3Apublic%2Fhello-ci%3Apull%2Cpush&service=[redacted-registry-fqdn] HTTP/1.1" 200 710 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3 HTTP/1.1" 401 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc HTTP/1.1" 401 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db HTTP/1.1" 401 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be HTTP/1.1" 401 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9 HTTP/1.1" 401 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f HTTP/1.1" 401 0 "-" "Go-http-client/1.1",
[redacted-ip] - chonal [18/Feb/2020:14:55:02 +0000] "GET /v2/token?scope=repository%3Apublic%2Fhello-ci%3Apull&scope=repository%3Apublic%2Fhello-ci%3Apull%2Cpush&service=[redacted-registry-fqdn] HTTP/1.1" 200 709 "-" "Go-http-client/1.1",
[redacted-ip] - chonal [18/Feb/2020:14:55:02 +0000] "GET /v2/token?scope=repository%3Apublic%2Fhello-ci%3Apull&scope=repository%3Apublic%2Fhello-ci%3Apull%2Cpush&service=[redacted-registry-fqdn] HTTP/1.1" 200 702 "-" "Go-http-client/1.1",
[redacted-ip] - chonal [18/Feb/2020:14:55:02 +0000] "GET /v2/token?scope=repository%3Apublic%2Fhello-ci%3Apull&scope=repository%3Apublic%2Fhello-ci%3Apull%2Cpush&service=[redacted-registry-fqdn] HTTP/1.1" 200 706 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
[redacted-ip] - chonal [18/Feb/2020:14:55:02 +0000] "GET /v2/token?scope=repository%3Apublic%2Fhello-ci%3Apull&scope=repository%3Apublic%2Fhello-ci%3Apull%2Cpush&service=[redacted-registry-fqdn] HTTP/1.1" 200 704 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9 HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3 HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/manifests/latest HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "PUT /v2/public/hello-ci/manifests/latest HTTP/1.1" 201 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:03 +0000] "HEAD /v2/public/hello-ci/manifests/latest HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:03 +0000] "PUT /v2/public/hello-ci/manifests/latest HTTP/1.1" 201 0 "-" "Go-http-client/1.1",
[redacted-ip] - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f HTTP/1.1" 200 0 "-" "Go-http-client/1.1",
192.168.1.1 - portus [18/Feb/2020:14:55:04 +0000] "GET /v2/token?account=portus&scope=repository%3Apublic%2Fhello-ci%3Apull&service=[redacted-registry-fqdn] HTTP/1.1" 200 703 "-" "Ruby"

As you can see, only the GET requests for auth tokens are properly authenticated using HTTP auth, the subsequent PUT requests actually uploading data are not, which is perfectly ok since auth is achieved with the token. However, the registry pulls the actor name from the HTTP auth user (I suppose) See below. The registry sends this notification:

Handling 'push' event:
{
  "id": "621b40f2-dc93-4fb7-b721-8fe140fb2a44",
  "timestamp": "2020-02-18T14:55:03.181921156Z",
  "action": "push",
  "target": {
    "mediaType": "application/vnd.docker.distribution.manifest.list.v2+json",
    "size": 1076,
    "digest": "sha256:9ea58c192d477295f85fa5d85856768296da8ab98549445cc6818d733539779e",
    "length": 1076,
    "repository": "public/hello-ci",
    "url": "https://[redacted-registry-fqdn]/v2/public/hello-ci/manifests/sha256:9ea58c192d477295f85fa5d85856768296da8ab98549445cc6818d733539779e",
    "tag": "latest"
  },
  "request": {
    "id": "485bc065-c1df-4250-9ddf-5972b879542b",
    "addr": "[redacted-ip]",
    "host": "[redacted-registry-fqdn]",
    "method": "PUT",
    "useragent": "Go-http-client/1.1"
  },

�
  "actor": {
  },
  "source": {
    "addr": "ce2d2570cb42:5000",
    "instanceID": "0b6d7d0e-35f9-4ac6-8c37-9ca00c2fbbb6"
  }
}

Edit: Strange thing, regular docker push uses the same pattern:


[redacted-ip] - chonal [18/Feb/2020:15:09:52 +0000] "GET /v2/token?account=chonal&scope=repository%3Apublic%2Fhello-ci%3Apush%2Cpull&service=[redacted-regsitry-fqdn] HTTP/1.1" 200 710 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))"
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "PUT /v2/public/hello-ci/manifests/test2 HTTP/1.1" 201 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:f16790039ef1d40f0b01b9807317809ad04e528cd631fdbfd40cd783d3078e4f HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:5c939e3a4d1097af8d3292ad3a41d3caa846f6333b91f2dd22b972bc2d19c5b5 HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:c63719cdbe7ae254b453dba06fb446f583b503f2a2c15becc83f8c5bc7a705e0 HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:19a861ea6baff71b05cd577478984c3e62cf0177bf74468d0aca551f5fcb891c HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:3976a685910e7b9752b1fb64e0db6c6af19115394e4bcc0ffbcf450363b7b4bb HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:651c9d2d6c4f37c56a221259e033e7e2353b698139c2ff950623ca28d64a9837 HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:f35234890e641ef10024b968edf6a8ef7221920f0f2492f4e7bc4a9c7d5aa0df HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
[redacted-ip] - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:f075fb918eb3e716dff06c93d6c6b9ea13b9fa6638ad1c17675e440341ebf811 HTTP/1.1" 200 0 "-" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \x5C(linux\x5C))",
192.168.1.1 - portus [18/Feb/2020:15:09:55 +0000] "GET /v2/token?account=portus&scope=repository%3Apublic%2Fhello-ci%3Apull&service=[redacted-regsitry-fqdn] HTTP/1.1" 200 703 "-" "Ruby",

But this time the notification sent by the registry contains the actor:

Handling 'push' event:
{
  "id": "b5b4064b-9703-4f2e-81b7-5056d77ef55d",
  "timestamp": "2020-02-18T15:09:53.6760806Z",
  "action": "push",
  "target": {
    "mediaType": "application/vnd.docker.distribution.manifest.v2+json",
    "size": 1984,
    "digest": "sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6",
    "length": 1984,
    "repository": "public/hello-ci",
    "url": "https://[redacted-registry-fqdn]/v2/public/hello-ci/manifests/sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6",
    "tag": "test2"
  },
  "request": {
    "id": "73907ff4-bba0-4744-bbba-f6ad03c210d4",
    "addr": "[redacted-ip]",
    "host": "[redacted-registry-fqdn]",
    "method": "PUT",
    "useragent": "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
  },

�
  "actor": {
    "name": "chonal"
  },
  "source": {
    "addr": "ce2d2570cb42:5000",
    "instanceID": "0b6d7d0e-35f9-4ac6-8c37-9ca00c2fbbb6"
  }
}

So maybe it is an issue with the registry itself? Does anyone have a clue?

Here are the logs of the registry. For Buildx push:

time="2020-02-18T14:55:02.179798053Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=345ef571-0d91-4894-8a1b-a4cf3d0f2bd5 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc" vars.name="public/hello-ci" 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc HTTP/1.1" 401 158 "" "Go-http-client/1.1"
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db HTTP/1.1" 401 158 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.190803592Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=3242de1a-3fbd-4140-b248-5ec61acf5deb http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db" vars.name="public/hello-ci" 
time="2020-02-18T14:55:02.193644246Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=71fe33c1-362e-4df2-b2ae-f4797c32588b http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9" vars.name="public/hello-ci" 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9 HTTP/1.1" 401 158 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.205166998Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=478d7154-455e-4181-81b6-5c4d73db730d http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be" vars.name="public/hello-ci" 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be HTTP/1.1" 401 158 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.210777842Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=4ad05b89-b509-47ff-80f4-8227df48203f http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f" vars.name="public/hello-ci" 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f HTTP/1.1" 401 158 "" "Go-http-client/1.1"
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3 HTTP/1.1" 401 158 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.215028675Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=e24c24ac-c0a2-492b-af61-dcc73de54ef3 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3" vars.name="public/hello-ci" 
time="2020-02-18T14:55:02.612831903Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=b5b27514-a4b7-418e-85cd-2a1b1c168aab http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc" vars.name="public/hello-ci" 
time="2020-02-18T14:55:02.613936381Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=b5b27514-a4b7-418e-85cd-2a1b1c168aab http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/octet-stream" http.response.duration=3.288499ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4b43bc1432667384cc7804a344d7f09ecda21e64cd74557d36d4df9d670676bc HTTP/1.1" 200 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.642570742Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=2f969494-747a-4f28-a9bb-ab00ddc95c82 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db" vars.name="public/hello-ci" 
time="2020-02-18T14:55:02.643644999Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=2f969494-747a-4f28-a9bb-ab00ddc95c82 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/octet-stream" http.response.duration=4.884003ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:a500ce965033a66dfc4f42b7075d36fb523d7f1c188dc4f45eeeafdd773967db HTTP/1.1" 200 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.65861904Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=f4d0077c-f9eb-41a9-9b59-505a07e70cf0 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be" vars.name="public/hello-ci" 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be HTTP/1.1" 200 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.66335199Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=f4d0077c-f9eb-41a9-9b59-505a07e70cf0 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:c2e531a682bf960449368b943a3a2646b979256a9412712822bd3759600881be" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/octet-stream" http.response.duration=8.220233ms http.response.status=200 http.response.written=0 
time="2020-02-18T14:55:02.696087438Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=85baa728-9812-4905-9a72-60f0e7e2599c http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9" vars.name="public/hello-ci" 
time="2020-02-18T14:55:02.703428475Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=85baa728-9812-4905-9a72-60f0e7e2599c http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/octet-stream" http.response.duration=19.645656ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b6f32fe9e99eb867b3ee67d62c01ed4d811bfb6f341c6f6500dd21d54ab720e9 HTTP/1.1" 200 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.717278163Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=0bfa1d79-979e-4dff-9730-836364fde6a5 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3" vars.name="public/hello-ci" 
time="2020-02-18T14:55:02.717958958Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=0bfa1d79-979e-4dff-9730-836364fde6a5 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/octet-stream" http.response.duration=2.587956ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:4dbc2ebf6782e665546eef55b84c4a93b578f829cbe55ed1b38579e4a3257dc3 HTTP/1.1" 200 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.751755046Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=8df45743-fe59-4bf9-bb5a-7f4042bf1c3b http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f" http.request.useragent="Go-http-client/1.1" vars.digest="sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f" vars.name="public/hello-ci" 
time="2020-02-18T14:55:02.752130286Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=8df45743-fe59-4bf9-bb5a-7f4042bf1c3b http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/octet-stream" http.response.duration=1.865483ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:b02a8f490bc868eb3f484717ff2deae91bf8df998a83cea8655c6adf0c22180f HTTP/1.1" 200 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.793796052Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=121773b6-164b-45bd-abe9-4ef69b1c7c57 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
time="2020-02-18T14:55:02.795594755Z" level=info msg="rewriting manifest list sha256:9ea58c192d477295f85fa5d85856768296da8ab98549445cc6818d733539779e in schema1 format to support old client" auth.user.name= go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=121773b6-164b-45bd-abe9-4ef69b1c7c57 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/manifests/latest HTTP/1.1" 200 528 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.796219551Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=121773b6-164b-45bd-abe9-4ef69b1c7c57 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=5.536113ms http.response.status=200 http.response.written=528 
time="2020-02-18T14:55:02.842040361Z" level=info msg="authorized request" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=7ab238eb-f39c-4ca2-b706-3e03b1152587 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "PUT /v2/public/hello-ci/manifests/latest HTTP/1.1" 201 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.877043685Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=7ab238eb-f39c-4ca2-b706-3e03b1152587 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.duration=37.186966ms http.response.status=201 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "HEAD /v2/public/hello-ci/manifests/latest HTTP/1.1" 200 528 "" "Go-http-client/1.1"
time="2020-02-18T14:55:02.920270863Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=c03dfda1-b005-43ad-a676-861b99cb6708 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
time="2020-02-18T14:55:02.92137006Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=c03dfda1-b005-43ad-a676-861b99cb6708 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=10.568877ms http.response.status=200 http.response.written=528 
time="2020-02-18T14:55:02.964788728Z" level=info msg="authorized request" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=883732db-774b-49fd-a61e-8b8b700870d3 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
time="2020-02-18T14:55:02.979119762Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=883732db-774b-49fd-a61e-8b8b700870d3 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.duration=17.181858ms http.response.status=201 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:02 +0000] "PUT /v2/public/hello-ci/manifests/latest HTTP/1.1" 201 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:03.019278722Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=59ddded9-d745-4939-b2f8-aac79a1ce524 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
192.168.1.6 - - [18/Feb/2020:14:55:03 +0000] "HEAD /v2/public/hello-ci/manifests/latest HTTP/1.1" 200 528 "" "Go-http-client/1.1"
time="2020-02-18T14:55:03.020641218Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=59ddded9-d745-4939-b2f8-aac79a1ce524 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=4.567566ms http.response.status=200 http.response.written=528 
time="2020-02-18T14:55:03.058573061Z" level=info msg="authorized request" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=f642b72a-3740-44e2-8bc4-47590a0b6022 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
time="2020-02-18T14:55:03.095574793Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=f642b72a-3740-44e2-8bc4-47590a0b6022 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.duration=39.107148ms http.response.status=201 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:14:55:03 +0000] "PUT /v2/public/hello-ci/manifests/latest HTTP/1.1" 201 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:03.133811445Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=394902e0-ad84-40fe-a604-17c325434ee0 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
time="2020-02-18T14:55:03.136046402Z" level=info msg="rewriting manifest sha256:f623e417f232c240a4e7daf305789840c7b9197b91e1c396e07c995789e8b61b in schema1 format to support old client" auth.user.name= go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=394902e0-ad84-40fe-a604-17c325434ee0 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
192.168.1.6 - - [18/Feb/2020:14:55:03 +0000] "HEAD /v2/public/hello-ci/manifests/latest HTTP/1.1" 200 1262 "" "Go-http-client/1.1"
time="2020-02-18T14:55:03.137389934Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=394902e0-ad84-40fe-a604-17c325434ee0 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.contenttype="application/vnd.docker.distribution.manifest.v1+prettyjws" http.response.duration=6.319593ms http.response.status=200 http.response.written=1262 
time="2020-02-18T14:55:03.17776804Z" level=info msg="authorized request" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.list.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=485bc065-c1df-4250-9ddf-5972b879542b http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" vars.name="public/hello-ci" vars.reference=latest 
192.168.1.6 - - [18/Feb/2020:14:55:03 +0000] "PUT /v2/public/hello-ci/manifests/latest HTTP/1.1" 201 0 "" "Go-http-client/1.1"
time="2020-02-18T14:55:03.189751486Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.list.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=485bc065-c1df-4250-9ddf-5972b879542b http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/latest" http.request.useragent="Go-http-client/1.1" http.response.duration=14.035456ms http.response.status=201 http.response.written=0 
192.168.1.2 - - [18/Feb/2020:14:55:04 +0000] "GET /v2/public/hello-ci/tags/list?n=100 HTTP/1.1" 401 158 "" "Ruby"
time="2020-02-18T14:55:04.528732579Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=104576ee-5a86-4ba4-a887-f9cb6a4d9e14 http.request.method=GET http.request.remoteaddr="192.168.1.2:47984" http.request.uri="/v2/public/hello-ci/tags/list?n=100" http.request.useragent=Ruby vars.name="public/hello-ci" 
time="2020-02-18T14:55:04.696586348Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=95dc099f-a60d-46ed-88bb-7653d2a847dd http.request.method=GET http.request.remoteaddr="192.168.1.2:47992" http.request.uri="/v2/public/hello-ci/tags/list?n=100" http.request.useragent=Ruby vars.name="public/hello-ci" 
192.168.1.2 - - [18/Feb/2020:14:55:04 +0000] "GET /v2/public/hello-ci/tags/list?n=100 HTTP/1.1" 200 60 "" "Ruby"
time="2020-02-18T14:55:04.696931437Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=95dc099f-a60d-46ed-88bb-7653d2a847dd http.request.method=GET http.request.remoteaddr="192.168.1.2:47992" http.request.uri="/v2/public/hello-ci/tags/list?n=100" http.request.useragent=Ruby http.response.contenttype="application/json; charset=utf-8" http.response.duration=2.425003ms http.response.status=200 http.response.written=60 

And for regular docker push (which generated correct notifications):

time="2020-02-18T15:09:52.682213286Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=f8b022e5-0bf1-466b-93e0-5ab5857b7677 http.request.method=GET http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" 
192.168.1.6 - - [18/Feb/2020:15:09:52 +0000] "GET /v2/ HTTP/1.1" 401 87 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.222645883Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=91035cfd-263b-411f-8308-211d4501396e http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:f075fb918eb3e716dff06c93d6c6b9ea13b9fa6638ad1c17675e440341ebf811" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:f075fb918eb3e716dff06c93d6c6b9ea13b9fa6638ad1c17675e440341ebf811" vars.name="public/hello-ci" 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:f075fb918eb3e716dff06c93d6c6b9ea13b9fa6638ad1c17675e440341ebf811 HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.223275571Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=91035cfd-263b-411f-8308-211d4501396e http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:f075fb918eb3e716dff06c93d6c6b9ea13b9fa6638ad1c17675e440341ebf811" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=2.989498ms http.response.status=200 http.response.written=0 
time="2020-02-18T15:09:53.229190193Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=610bbd51-5320-4648-a2d8-4be592931a9f http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:f35234890e641ef10024b968edf6a8ef7221920f0f2492f4e7bc4a9c7d5aa0df" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:f35234890e641ef10024b968edf6a8ef7221920f0f2492f4e7bc4a9c7d5aa0df" vars.name="public/hello-ci" 
time="2020-02-18T15:09:53.229522242Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=610bbd51-5320-4648-a2d8-4be592931a9f http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:f35234890e641ef10024b968edf6a8ef7221920f0f2492f4e7bc4a9c7d5aa0df" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=2.789449ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:f35234890e641ef10024b968edf6a8ef7221920f0f2492f4e7bc4a9c7d5aa0df HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.250579411Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=c957c5cb-abab-46a8-9431-0ddb0996cc12 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:3976a685910e7b9752b1fb64e0db6c6af19115394e4bcc0ffbcf450363b7b4bb" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:3976a685910e7b9752b1fb64e0db6c6af19115394e4bcc0ffbcf450363b7b4bb" vars.name="public/hello-ci" 
time="2020-02-18T15:09:53.250718841Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=6793b385-f071-43ca-b2a2-ad5d5fd7e82b http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:651c9d2d6c4f37c56a221259e033e7e2353b698139c2ff950623ca28d64a9837" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:651c9d2d6c4f37c56a221259e033e7e2353b698139c2ff950623ca28d64a9837" vars.name="public/hello-ci" 
time="2020-02-18T15:09:53.251069885Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=6793b385-f071-43ca-b2a2-ad5d5fd7e82b http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:651c9d2d6c4f37c56a221259e033e7e2353b698139c2ff950623ca28d64a9837" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=2.127827ms http.response.status=200 http.response.written=0 
time="2020-02-18T15:09:53.251214783Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=c957c5cb-abab-46a8-9431-0ddb0996cc12 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:3976a685910e7b9752b1fb64e0db6c6af19115394e4bcc0ffbcf450363b7b4bb" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=2.280981ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:651c9d2d6c4f37c56a221259e033e7e2353b698139c2ff950623ca28d64a9837 HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:3976a685910e7b9752b1fb64e0db6c6af19115394e4bcc0ffbcf450363b7b4bb HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.256909131Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=4664a638-8ad9-4655-9d0f-61cd5f67cfcf http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:19a861ea6baff71b05cd577478984c3e62cf0177bf74468d0aca551f5fcb891c" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:19a861ea6baff71b05cd577478984c3e62cf0177bf74468d0aca551f5fcb891c" vars.name="public/hello-ci" 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:19a861ea6baff71b05cd577478984c3e62cf0177bf74468d0aca551f5fcb891c HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.257333517Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=4664a638-8ad9-4655-9d0f-61cd5f67cfcf http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:19a861ea6baff71b05cd577478984c3e62cf0177bf74468d0aca551f5fcb891c" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=3.174941ms http.response.status=200 http.response.written=0 
time="2020-02-18T15:09:53.355907185Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=97b70d20-02f2-4055-9691-85f4934ff946 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:c63719cdbe7ae254b453dba06fb446f583b503f2a2c15becc83f8c5bc7a705e0" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:c63719cdbe7ae254b453dba06fb446f583b503f2a2c15becc83f8c5bc7a705e0" vars.name="public/hello-ci" 
time="2020-02-18T15:09:53.356252408Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=97b70d20-02f2-4055-9691-85f4934ff946 http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:c63719cdbe7ae254b453dba06fb446f583b503f2a2c15becc83f8c5bc7a705e0" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=1.920595ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:c63719cdbe7ae254b453dba06fb446f583b503f2a2c15becc83f8c5bc7a705e0 HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.365684892Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=dc059c62-ff99-4d94-a14a-7b71e070294a http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:5c939e3a4d1097af8d3292ad3a41d3caa846f6333b91f2dd22b972bc2d19c5b5" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:5c939e3a4d1097af8d3292ad3a41d3caa846f6333b91f2dd22b972bc2d19c5b5" vars.name="public/hello-ci" 
time="2020-02-18T15:09:53.36626949Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=dc059c62-ff99-4d94-a14a-7b71e070294a http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:5c939e3a4d1097af8d3292ad3a41d3caa846f6333b91f2dd22b972bc2d19c5b5" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=2.676085ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:5c939e3a4d1097af8d3292ad3a41d3caa846f6333b91f2dd22b972bc2d19c5b5 HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.512738836Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=48ac4a43-0c42-4d25-853c-c9ac443b118c http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:f16790039ef1d40f0b01b9807317809ad04e528cd631fdbfd40cd783d3078e4f" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.digest="sha256:f16790039ef1d40f0b01b9807317809ad04e528cd631fdbfd40cd783d3078e4f" vars.name="public/hello-ci" 
time="2020-02-18T15:09:53.51322823Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=[redacted-registry-fqdn] http.request.id=48ac4a43-0c42-4d25-853c-c9ac443b118c http.request.method=HEAD http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/blobs/sha256:f16790039ef1d40f0b01b9807317809ad04e528cd631fdbfd40cd783d3078e4f" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.contenttype="application/octet-stream" http.response.duration=2.602999ms http.response.status=200 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "HEAD /v2/public/hello-ci/blobs/sha256:f16790039ef1d40f0b01b9807317809ad04e528cd631fdbfd40cd783d3078e4f HTTP/1.1" 200 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:53.670882224Z" level=info msg="authorized request" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=73907ff4-bba0-4744-bbba-f6ad03c210d4 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/test2" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" vars.name="public/hello-ci" vars.reference=test2 
time="2020-02-18T15:09:53.681112232Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.request.host=[redacted-registry-fqdn] http.request.id=73907ff4-bba0-4744-bbba-f6ad03c210d4 http.request.method=PUT http.request.remoteaddr=[redacted-ip] http.request.uri="/v2/public/hello-ci/manifests/test2" http.request.useragent="docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \(linux\))" http.response.duration=13.72949ms http.response.status=201 http.response.written=0 
192.168.1.6 - - [18/Feb/2020:15:09:53 +0000] "PUT /v2/public/hello-ci/manifests/test2 HTTP/1.1" 201 0 "" "docker/19.03.5 go/go1.12.12 git-commit/633a0ea kernel/4.19.76-linuxkit os/linux arch/amd64 UpstreamClient(Docker-Client/19.03.5 \\(linux\\))"
time="2020-02-18T15:09:55.096296498Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=00c30124-384e-43c6-a0fd-d487913daeee http.request.method=GET http.request.remoteaddr="192.168.1.2:51164" http.request.uri="/v2/public/hello-ci/manifests/sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6" http.request.useragent=Ruby vars.name="public/hello-ci" vars.reference="sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6" 
192.168.1.2 - - [18/Feb/2020:15:09:55 +0000] "GET /v2/public/hello-ci/manifests/sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6 HTTP/1.1" 401 158 "" "Ruby"
time="2020-02-18T15:09:55.251478197Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=c8212702-df9a-4726-9fa8-465f1be139d8 http.request.method=GET http.request.remoteaddr="192.168.1.2:51172" http.request.uri="/v2/public/hello-ci/manifests/sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6" http.request.useragent=Ruby vars.name="public/hello-ci" vars.reference="sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6" 
time="2020-02-18T15:09:55.260861525Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=c8212702-df9a-4726-9fa8-465f1be139d8 http.request.method=GET http.request.remoteaddr="192.168.1.2:51172" http.request.uri="/v2/public/hello-ci/manifests/sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6" http.request.useragent=Ruby http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=14.100453ms http.response.status=200 http.response.written=1984 
192.168.1.2 - - [18/Feb/2020:15:09:55 +0000] "GET /v2/public/hello-ci/manifests/sha256:48613f5687e841d1877c95dbb76a78d16a3d29c2e86b2308a5e4d4ca11f12de6 HTTP/1.1" 200 1984 "" "Ruby"
192.168.1.2 - - [18/Feb/2020:15:09:57 +0000] "GET /v2/public/hello-ci/tags/list?n=100 HTTP/1.1" 401 158 "" "Ruby"
time="2020-02-18T15:09:57.326236742Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=b90358ef-3550-4905-be08-faca0a2ac714 http.request.method=GET http.request.remoteaddr="192.168.1.2:51184" http.request.uri="/v2/public/hello-ci/tags/list?n=100" http.request.useragent=Ruby vars.name="public/hello-ci" 
time="2020-02-18T15:09:57.482531814Z" level=info msg="authorized request" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=bdcd800d-9b27-4ff7-a4f7-74a08cd12592 http.request.method=GET http.request.remoteaddr="192.168.1.2:51196" http.request.uri="/v2/public/hello-ci/tags/list?n=100" http.request.useragent=Ruby vars.name="public/hello-ci" 
time="2020-02-18T15:09:57.482794819Z" level=info msg="response completed" go.version=go1.11.2 http.request.host="registry:5000" http.request.id=bdcd800d-9b27-4ff7-a4f7-74a08cd12592 http.request.method=GET http.request.remoteaddr="192.168.1.2:51196" http.request.uri="/v2/public/hello-ci/tags/list?n=100" http.request.useragent=Ruby http.response.contenttype="application/json; charset=utf-8" http.response.duration=1.678623ms http.response.status=200 http.response.written=60 
192.168.1.2 - - [18/Feb/2020:15:09:57 +0000] "GET /v2/public/hello-ci/tags/list?n=100 HTTP/1.1" 200 60 "" "Ruby"

Apparently the registry never even receives any form of HTTP auth. Which makes sense, since Portus handles my digest auth using tokens. So maybe a registry bug?

Edit: The critical difference is that buildx does not append the account GET parameter to the HTTP token request: compare /v2/token?scope=repository to /v2/token?account=chonal&scope=repository in the logs above.

So probably a buildx/buildkit bug?

@Johannestegner
Copy link
Author

@StarGate01, awesome debugging/research, thank you for that! Hopefully fixable with all that info! :)

@StarGate01
Copy link

Thanks! I actually fixed it already, working on creating pull-requests, building forked images, deployment to my CI etc ...

It was a one-line-fix in containerd: StarGate01/containerd@2caabd9

@Johannestegner
Copy link
Author

Haha wow... Oh well, this will improve my build process a whole lot, I owe you one! :)

@StarGate01
Copy link

StarGate01 commented Feb 18, 2020

Alright, I provide the following to the community:

You can use the unmodified buildx command with the patched buildkit like this:
docker buildx create --driver-opt image=stargate01/buildkit ...

I tested it locally and on my CI, it works. I use https://github.com/SUSE/Portus and https://github.com/Quiq/docker-registry-ui and both tools now read the username correctly.

Lets hope this fixes your problem too! :)

@StarGate01
Copy link

StarGate01 commented Feb 19, 2020

So apparently, adding the account parameter is not per specification (containerd/containerd#4040 (comment)). So I opened a pull request in Portus (SUSE/Portus#2286).

However, now I dont really know how to fix your problem - maybe your registry auth controller has similar issues? What setup are you using?

@Johannestegner
Copy link
Author

Ah that sucks. Well my setup is quite basic:

1x AMD64 machine, 1x ARM64 machine, both set up as nodes/context in docker and added as nodes in the builder context when setting up buildx/buildkit on the primary node (amd64).

Both clients are logged in to the registries through the .docker/config.json file, both are set up to be experimental in daemon (and client), but I guess the client login should do no real difference really.

I will take a look at your patched image and see if it works with that though!

@pschmitt
Copy link

pschmitt commented Mar 9, 2020

Same issue with a similar setup here, an ARMv6/7 and an AMD64 builder. The registry I'm targeting is the Docker Hub.
I just gave your image a spin, @StarGate01 . Sadly it gave me the same results as the upstream buildkit.
Only one tag of the many tags I am trying to push appeared on the hub.

I'm trying to push to both zabbixmultiarch/zabbix-agent2 and zabbixmultiarch/zabbix-agent2-alpine:

@pschmitt
Copy link

pschmitt commented Mar 9, 2020

Is there a way to properly retag multiarch images?

Something like the following:

docker tag MY_IMAGE:TAG_THAT_GOT_PUSHED MY_IMAGE:OTHER_TAG
docker manifest inspect MY_IMAGE:TAG_THAT_GOT_PUSHED > manifest.json
docker manifest create MY_IMAGE:OTHER_TAG < manifest.json # fictive
docker push MY_IMAGE:OTHER_TAG
docker manifest push MY_IMAGE:OTHER_TAG

Edit:
This looks promising but would create several images/tags on the registry
https://community.arm.com/developer/tools-software/tools/b/tools-software-ides-blog/posts/deploying-multi-architecture-docker-registry

@StarGate01
Copy link

Does this problem only occur when you are using multiple physical builder nodes? When I build a multi-arch image using the official buildkit and QEMU/binfmt (architecture emulation one one physical machine), the pushed tags and images look good.

pschmitt added a commit to pschmitt/zabbix-docker-multiarch that referenced this issue Mar 9, 2020
- Make latest the first tag since there's a bug in buildx docker/buildx#177
- Tag with current git commit id
@Johannestegner
Copy link
Author

Johannestegner commented Mar 9, 2020

Does this problem only occur when you are using multiple physical builder nodes? When I build a multi-arch image using the official buildkit and QEMU/binfmt (architecture emulation one one physical machine), the pushed tags and images look good.

Can't speak for others, but in my case it works fine in none-multi-node builds, I can do it with qemu without any issues, but the build is a lot slower on emulated arch than on a native one.


Edit:

Guessing you mean with you image, missed that it was you who commented the other day, hehe.
Have not tried your image yet, so can't say, sorry! :)

@pschmitt
Copy link

pschmitt commented Mar 9, 2020

Does this problem only occur when you are using multiple physical builder nodes? When I build a multi-arch image using the official buildkit and QEMU/binfmt (architecture emulation one one physical machine), the pushed tags and images look good.

This only occurs when multiple nodes are building the images. I tested both extensively. When building with more than one node the first tag gets pushed and nothing else. When only one node is involved everything is fine ie all tag/images get pushed as expected.

Can't speak for others, but in my case it works fine in none-multi-node builds, I can do it with qemu without any issues, but the build is a lot slower on emulated arch than on a native one.

What I am trying to build (zabbix agent2) only builds fine when running on ARM. QEMU doesn't cut it.

Edit:
In my case this is reproducible easily from an amd64 host

# Buildx setup
docker context create --use --docker "host=ssh://pi@raspberrypi.local" raspberrypi
docker buildx create --use --name test rasbperrypi
docker buildx create --append --name test default
# Code
git clone https://github.com/pschmitt/zabbix-docker-multiarch /tmp/zabbix-docker-multiarch
/tmp/zabbix-docker-multiarch/build.sh agent2-alpine -p

@Silex
Copy link

Silex commented May 23, 2020

This only occurs when multiple nodes are building the images. I tested both extensively. When building with more than one node the first tag gets pushed and nothing else. W

I have the same issue. The output is different too! It looks like the merging of the manifests triggers an error.

With the bug (multihost):

#34 exporting to image
 #34 exporting layers 0.0s done
 #34 exporting manifest sha256:79f01e54594b73be6892dc1ed67419bfff0f4ed9d1f23a10e269a7c154ef4e35 0.0s done
 #34 exporting config sha256:cb839d93af1a9fe5d93a194428927f4428c61d76a352004c02ef874be98dddec 0.0s done
 #34 exporting manifest sha256:cd735b661dda81f309942965ec70eb6857be4b877cc622f84b0c8da84620f7b6 0.0s done
 #34 exporting config sha256:6721e984c0daef46939a82ac74d85e5406599d150eec8de6850e4ebf89f741ab
 #34 pushing layers
 #34 exporting config sha256:6721e984c0daef46939a82ac74d85e5406599d150eec8de6850e4ebf89f741ab 0.0s done
 #34 exporting manifest list sha256:d7df07c82308211ba7f789038aac953a710ade2a9f87482eefedcdcea633329f 0.0s done
 #34 pushing layers 0.4s done
 #34 pushing manifest for docker.io/silex/emacs
 #34 pushing manifest for docker.io/silex/emacs 0.3s done
 #34 DONE 0.9s
 #35 exporting cache
 #35 preparing build cache for export done
 #35 DONE 0.0s
 #36 merging manifest list silex/emacs:26.3,silex/emacs:26,silex/emacs:latest
 #36 DONE 0.5s

Without the bug (single host):

#8 exporting to image
#8 exporting layers 0.1s done
#8 exporting manifest sha256:4ec922c362ecb14126f965c0a00f801214de35b861be772f41ba0ebc137785d2 0.0s done
#8 exporting config sha256:2435e1e8b4b4c9e73a713bfec313cfbe9ced82fe2c798c2ce9b463c314e2473d
#8 exporting config sha256:2435e1e8b4b4c9e73a713bfec313cfbe9ced82fe2c798c2ce9b463c314e2473d 0.0s done
#8 exporting manifest sha256:e53569221407ad942560a9520df75b69c699c7c352fc97b073c7e095289c9877 0.0s done
#8 exporting config sha256:aaf38ba0b8c46406853a53359970ec84ef2dfcdd9b21d7b080c13adbc0d687bc 0.0s done
#8 exporting manifest list sha256:96480942d682e0ff9d7443d24e7cb310d39882592eacdb7060d4f1d420752457
#8 exporting manifest list sha256:96480942d682e0ff9d7443d24e7cb310d39882592eacdb7060d4f1d420752457 0.0s done
#8 pushing layers
#8 pushing layers 2.0s done
#8 pushing manifest for docker.io/silex/emacs:test
#8 pushing manifest for docker.io/silex/emacs:test 2.4s done
#8 pushing layers 1.8s done
#8 pushing manifest for docker.io/silex/emacs:test2
#8 pushing manifest for docker.io/silex/emacs:test2 2.9s done
#8 DONE 9.3s

EDIT: buildx master has the same issue

@Johannestegner
Copy link
Author

I still experience this issue...

As a work around I no longer do any heavy work in the docker images, but rather on each native machine and import the binaries into the image as a final step with a single node. It's annoying to have to do it like that, but it works...
Would love to see this issue fixed though, as I really prefer to use multi-node!

@Silex
Copy link

Silex commented May 23, 2020

Ok I tried to work around this issue several ways:

  1. Build one tag only, then do docker tag aliases and push that. That failed because it only tags the current architecture so you have the main image multiarch and the tag aliases for one arch only.
  2. Do a docker buildx build for each tag in a loop. That almost works but for some reasons only the images that run on the buildx host get a new digest (You can search docker buildx build in the following log https://bit.ly/3cZ3RHT). The images that were built on the other node keep their digest.

Here's how 2 was implemented:

for tag in $BUILD_TAGS; do
  docker buildx build --platform="$DOCKER_PLATFORMS" --pull --push --cache-from="$BUILD_TAG" --cache-to="type=inline" --tag="$tag" .
done

Here are the two resulting images: https://hub.docker.com/r/silex/emacs/tags?page=1&name=25-dev https://hub.docker.com/r/silex/emacs/tags?page=1&name=25.3-dev. We see that for arm the sha256 digests are the same but for amd64/i386 they changed.

How am I supposed to "docker tag" a multiarch image?

I'm now thinking of docker manifest inspect my way to copy a manifest to another tag, but I'm unsure how. Any pointers would be appreciated.

@Johannestegner
Copy link
Author

This is basically how I build my images now'a day:

https://github.com/jitesoft/docker-node-base/blob/master/.gitlab-ci.yml

(in the docker command I use a helper file I made myself which basically generates a tag list (-t image:tag -t image:tag) and it works fine (using qemu on the build machin which is single node). The actual building of the binaries I do on build machines which are using the arch they are intended to run on. So for my aarch64 images, I use aarc64 host, on amd64, amd64 host.

It works and works quite well, but i still would want this to work good too, as it would make a lot of things much more easy, hehe...

@Johannestegner
Copy link
Author

Sorry for close and reopen, using GitHub mobile and thought it was "close window", not issue!

@Silex
Copy link

Silex commented May 23, 2020

@Johannestegner: be careful, your images are not multiarch (because you also did the tag route I described above)

You can see the diff with docker manifest inspect quay.io/jitesoft/node-base and docker manifest inspect silex/emacs:26.3.

@Johannestegner
Copy link
Author

@Silex yes, quay does not have multi-arch support in their registry. My gitlab and docker hub images are though :)

But thanks! :)

@Silex
Copy link

Silex commented May 23, 2020

Ah ok so you push a single tag to gitlab/docker hub and multiple tags to quay.io.

@Johannestegner
Copy link
Author

Well, I push multiple tags to both, but in the gitlab/docker hub case I have all tags in the build command (you can use multiple -t image:tag with buildx build) and for quay I iterate through the tags and push them. :)
So the image built is multi-arch, while I only push the amd64 one to quay.

@Silex
Copy link

Silex commented May 23, 2020

Well, I push multiple tags to both, but in the gitlab/docker hub case I have all tags in the build command (you can use multiple -t image:tag with buildx build) and for quay I iterate through the tags and push them. :)

Yes but that does not work when you have multiple hosts, I mean this is what this issue is about no? I also have multiple -t, but only the first one gets pushed.

@Johannestegner
Copy link
Author

@Silex it's been a while since i tried it the last time, but I think only my manifest gets pushed, while the tags are not. If I use a single host to push, all the tags and the manifest works fine.

@Silex
Copy link

Silex commented May 23, 2020

My setup is 1 gitlab worker for amd64/i386 and 1 arm machine for the arm images. The gilab worker does the pushing:

docker buildx create --name $DOCKER_BUILDX_BUILDER
docker buildx create --append --name $DOCKER_BUILDX_BUILDER ssh://root@$DOCKER_ARM_HOST
docker buildx inspect --bootstrap $DOCKER_BUILDX_BUILDER
docker buildx use $DOCKER_BUILDX_BUILDER

Then I build using:

docker buildx build --platform="linux/amd64,linux/386,linux/arm/v7,linux/arm64/v8" --pull --push --cache-from="silex/emacs:26.3" --cache-to="type=inline" --tag="silex/emacs:26.3"  --tag="silex/emacs:26" --tag="silex/emacs:latest" .

Only the first tag gets pushed.

@Johannestegner
Copy link
Author

Does the tag really get pushed though? Looking at the logs, it looks like it pushes the manifest, then its done... :)

@Silex
Copy link

Silex commented May 23, 2020

@Johannestegner: I mean https://hub.docker.com/r/silex/emacs/tags?page=1&name=26.3 is multiarch so it had to be pushed at some point? But maybe you're right and it "works" randomly.

Also what does it mean that only the manifest is pushed? Maybe I need to brush up on manifests vs tags.

@Johannestegner
Copy link
Author

Each docker "image" consists of a manifest and a bunch of layers. The manifest references the layers and a tag references a manifest. When it comes to multi-arch, the manifest file is split up into the same image but with different architectures, so each tag points to a manifest, which have multiple architectures which each references a bunch of layers.

From my testing and research, the manifest is pushed fine, while that's it, the layers are not pushed and the tags are not (as they comes after pushing of the layers).

@Silex
Copy link

Silex commented May 23, 2020

Thanks for the explanations. What I observe is that silex/emacs:26.3 image works fine on both arm and amd64, so the layers were pushed. For the other tags, it looks like nothing was pushed but maybe you're right and only the manifest is pushed without the layers, resulting in incomplete image and thus from the hub perspective it's like if nothing was pushed.

@H01001000
Copy link

H01001000 commented Oct 27, 2021

So I try multi-node build and push on docker hub, although it said it pushed I can't find the image. Then later I try to push to harbor, this time I finally see the image, both arm and amd image was not tagged and both are separated into two oci image instead of one oci image. the image SHA is also different than the one it output.

What I think of is due to it building on two nodes, it treat it as two image build and once one node finishes building it will push on their own. Now I am trying to output to a file, then push the file, but the problem is output type oci is not supported on multi node build

@arikmaor
Copy link

Also experiencing this :(

@psalkowski
Copy link

For those who also struggling with this, there is an open issue on Gitlab: https://gitlab.com/gitlab-org/gitlab/-/issues/389577

The workaround is to add --provenance false to buildx build command.

@tonistiigi
Copy link
Member

@psalkowski If you are hitting a provenance-related issue, specifically with multi-node, then make sure you are using the latest buildx and if you still see the problem open a new issue with reproduction steps. This issue is for something different (likely registry related).

@Johannestegner
Copy link
Author

Haven't tried this since my last comment I think, so will try asap (will require some re-configuring of my build machines) and see if it's still an issue. Kind of old issue now, so would be nice to be able to close it ;)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants