Log based on registry known-support - reduce noise on notifications #716

tkalus · 2020-12-21T16:41:04Z

Some private registries do not support HEAD (E.G. GitLab Container Registry).
With the current config, this log message is causing a notification to be
sent for each container hosted in a registry lacking HEAD support.

Attempt to log.Debug or log.Warning for failed HTTP HEAD-check based on
registry hostname. For Docker Hub, a failed HEAD may count against a
user's call-quota whereas other registry implementations do not support HEAD.

Fixes #715

tkalus · 2020-12-21T16:47:16Z

In my case, I'm getting 48 noop notifications per hour:

three containers in GitLab Container Registry
two identical VMs behind a LB for HA
15 minute checks
email and Slack notifications

I'm hoping this is in time for the next tagged release -- and that it's soon.

simskij · 2020-12-21T17:15:18Z

Hi,

Thank you for your contribution! We'll definitely consider this in case we're unable to get HEAD to work consistently. However, I'd like to wait for v1.1.1 to be rolled out first to see how many false positives we actually get post that.

In the best of worlds, we'll be able to keep logs of failing head requests as a warning for when DockerHub users are consuming their rate limit - without spamming you in the progress.

If it's still too noisy post that, and we come to the conclusion that we're out of options, we'll make a fast patch release with your changes.

Best,
Simme

tkalus · 2020-12-21T17:32:27Z

Hey @simskij, thanks for the consideration.

Totally agree with the need for visibility when it comes to Docker Hub API consumption -- and I half-agree with the idea of checking HEAD only on dockerhub.

I'll bring it up in issue 715 too, but one idea might be keep the check for all containers/registries but selectively log.Debug() or log.Warning() based on the registry hostname?

tkalus · 2020-12-22T00:43:20Z

Updated with one possible way. Golang isn't my one of my primary languages, so I'm not going to feel bad at all if this isn't up to y'alls standards or deviates too far from the established patterns.

I managed to confirm it works by dint of live testing.

Here are the relevant log files with some light redaction:

watchtower    | time="2020-12-22T00:28:35Z" level=debug msg="Doing a HEAD request to fetch a digest" url="https://index.docker.io/v2/tkalus-forks/watchtower/manifests/latest"
watchtower    | time="2020-12-22T00:28:35Z" level=warning msg="Could not do a head request, falling back to regular pull." container=/watchtower image="tkalus-forks/watchtower:latest"
watchtower    | time="2020-12-22T00:28:35Z" level=debug msg="Reason: registry responded to head request with &{401 Unauthorized 401 HTTP/1.1 1 1 map[Content-Length:[166] Content-Type:[application/json] Date:[Tue, 22 Dec 2020 00:28:35 GMT] Docker-Distribution-Api-Version:[registry/2.0] Strict-Transport-Security:[max-age=31536000] Www-Authenticate:[Bearer realm=\"https://auth.docker.io/token\",service=\"registry.docker.io\",scope=\"repository:tkalus-forks/watchtower:pull\",error=\"insufficient_scope\"]] {} 166 [] false false map[] 0xc000432c00 0xc00044c4d0}"
watchtower    | time="2020-12-22T00:28:35Z" level=debug msg="Pulling image" container=/watchtower image="tkalus-forks/watchtower:latest"
watchtower    | time="2020-12-22T00:28:36Z" level=debug msg="Error pulling image tkalus-forks/watchtower:latest, Error response from daemon: pull access denied for tkalus-forks/watchtower, repository does not exist or may require 'docker login': denied: requested access to the resource is denied"
watchtower    | time="2020-12-22T00:28:36Z" level=info msg="Unable to update container \"/watchtower\": Error response from daemon: pull access denied for tkalus-forks/watchtower, repository does not exist or may require 'docker login': denied: requested access to the resource is denied. Proceeding to next."
...
watchtower    | time="2020-12-22T00:28:37Z" level=debug msg="Doing a HEAD request to fetch a digest" url="https://registry.gitlab.com/v2/<snip:gitlab_org>/<snip:gitlab_repo>/manifests/latest"
watchtower    | time="2020-12-22T00:28:37Z" level=debug msg="Could not do a head request, falling back to regular pull."
watchtower    | time="2020-12-22T00:28:37Z" level=debug msg="Reason: registry responded to head request with &{401 Unauthorized 401 HTTP/1.1 1 1 map[Content-Length:[160] Content-Type:[application/json] Date:[Tue, 22 Dec 2020 00:28:37 GMT] Docker-Distribution-Api-Version:[registry/2.0] Www-Authenticate:[Bearer realm=\"https://gitlab.com/jwt/auth\",service=\"container_registry\",scope=\"repository:<snip:gitlab_org>/<snip:gitlab_repo>:pull\",error=\"insufficient_scope\"] X-Content-Type-Options:[nosniff]] {} 160 [] false false map[] 0xc000433e00 0xc00044cf20}"
watchtower    | time="2020-12-22T00:28:37Z" level=debug msg="Pulling image" container=/<snip:gitlab_repo> image="registry.gitlab.com/<snip:gitlab_org>/<snip:gitlab_repo>:latest"
watchtower    | time="2020-12-22T00:28:38Z" level=debug msg="No new images found for /<snip:gitlab_repo>"
...
watchtower    | time="2020-12-22T00:28:39Z" level=debug msg="Doing a HEAD request to fetch a digest" url="https://index.docker.io/v2/library/traefik/manifests/v2.1"
watchtower    | time="2020-12-22T00:28:39Z" level=debug msg="Found a remote digest to compare with" remote="sha256:ab83baa3d198ee5a2fd685bed96417055a2bdd271efe11a0b831d6c02436aabd"
watchtower    | time="2020-12-22T00:28:39Z" level=debug msg=Comparing local="sha256:2c17c789b4913f29d1f64199cc3d9110f77fc3f7d6bafb306520d9e377efff96" remote="sha256:ab83baa3d198ee5a2fd685bed96417055a2bdd271efe11a0b831d6c02436aabd"
watchtower    | time="2020-12-22T00:28:39Z" level=debug msg=Comparing local="sha256:ab83baa3d198ee5a2fd685bed96417055a2bdd271efe11a0b831d6c02436aabd" remote="sha256:ab83baa3d198ee5a2fd685bed96417055a2bdd271efe11a0b831d6c02436aabd"
watchtower    | time="2020-12-22T00:28:39Z" level=debug msg="Found a match"
watchtower    | time="2020-12-22T00:28:39Z" level=debug msg="No pull needed. Skipping image."

The error on the 'full-pull' for tkalus-forks/watchtower is expected -- and demonstrates the reduced noise v. desired alerting nicely.

simskij

Looks really good! Some minor nitpicks, but other than that I think we're ready to roll 👍 🎉 Thanks for helping out! 🙏

pkg/registry/registry.go

pkg/container/client.go

pkg/registry/registry.go

tkalus · 2020-12-22T17:48:44Z

@simskij Based on the comments in Issue 715, it seems as though GitLab Registry are the only ones still suffering heartburn. It appears they have a URL pathname pattern for the manifests that's different from DockerHub, GitHub, GCR, and others.

Any objection to flipping the logic so it Warns on everything but registry.gitlab.com?

Strange thing is that GitLab Registry does respond appropriately to the command docker manifest inspect, so it is able to pull the manifest -- somehow. I might see about running docker manifest inspect through mitmproxy to see what pathnames are being pulled if I find some time over my holiday downtime.

simskij · 2020-12-22T21:17:30Z

I think the previous approach with only making them info-level for DockerHub probably will work better, as that's the only case (right now) where it actually makes any real difference for the user. In the other cases, if it works then good, otherwise no harm, right?

My thinking is that we already know of two or three cases where it won't work, GitLab, GitHub Packages, and some local registries. For local registries, I assume the varying success rate mostly has to do with versions and such as it works for me with registry:2.7.

tkalus · 2020-12-22T21:24:02Z

Totally reasonable to me. 💯 agree: local, private-network registries will be hard to enumerate and probably shouldn't be notifying anyway.

Will revert and push in just a moment -- Warn on index.docker.io and ghcr.io and Debug on others.

Log based on registry known-poor support of HEAD in checking container manifest. Some private registries do not support HEAD (E.G. GitLab Container Registry). With the current config, this log message is causing a notification to be sent for each container hosted in a registry lacking HEAD support. log.Debug or log.Warning for failed HTTP HEAD-check based on registry hostname where HEAD-check is known to fail. For Docker Hub, a failed HEAD leading to a "regular pull" may count against a user's call-quota whereas other registry implementations do not support HEAD, or whose container manifest may be in a different location.

simskij · 2020-12-22T23:48:20Z

Awesome! Thanks a bunch for your help with this!

simskij · 2020-12-22T23:48:32Z

@all-contributors add @tkalus for code

allcontributors · 2020-12-22T23:48:42Z

@simskij

I've put up a pull request to add @tkalus! 🎉

tkalus requested a review from simskij as a code owner December 21, 2020 16:41

tkalus force-pushed the fix/reduce-notification-noise branch from 33fb59e to 3f762c1 Compare December 22, 2020 00:41

tkalus changed the title ~~reduce noise on notifications~~ Log based on registry known-support - reduce noise on notifications Dec 22, 2020

simskij requested changes Dec 22, 2020

View reviewed changes

pkg/registry/registry.go Outdated Show resolved Hide resolved

pkg/container/client.go Outdated Show resolved Hide resolved

pkg/registry/registry.go Outdated Show resolved Hide resolved

tkalus force-pushed the fix/reduce-notification-noise branch from f681b31 to bd3db60 Compare December 22, 2020 20:30

tkalus force-pushed the fix/reduce-notification-noise branch from bd3db60 to cf11156 Compare December 22, 2020 21:27

simskij merged commit 5983d58 into containrrr:master Dec 22, 2020

allcontributors bot mentioned this pull request Dec 22, 2020

docs: add tkalus as a contributor #721

Merged

tkalus deleted the fix/reduce-notification-noise branch December 22, 2020 23:50

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Log based on registry known-support - reduce noise on notifications #716

Log based on registry known-support - reduce noise on notifications #716

tkalus commented Dec 21, 2020 •

edited

Loading

tkalus commented Dec 21, 2020

simskij commented Dec 21, 2020

tkalus commented Dec 21, 2020 •

edited

Loading

tkalus commented Dec 22, 2020

simskij left a comment

tkalus commented Dec 22, 2020 •

edited

Loading

simskij commented Dec 22, 2020 •

edited

Loading

tkalus commented Dec 22, 2020

simskij commented Dec 22, 2020

simskij commented Dec 22, 2020

allcontributors bot commented Dec 22, 2020

Log based on registry known-support - reduce noise on notifications #716

Log based on registry known-support - reduce noise on notifications #716

Conversation

tkalus commented Dec 21, 2020 • edited Loading

tkalus commented Dec 21, 2020

simskij commented Dec 21, 2020

tkalus commented Dec 21, 2020 • edited Loading

tkalus commented Dec 22, 2020

simskij left a comment

Choose a reason for hiding this comment

tkalus commented Dec 22, 2020 • edited Loading

simskij commented Dec 22, 2020 • edited Loading

tkalus commented Dec 22, 2020

simskij commented Dec 22, 2020

simskij commented Dec 22, 2020

allcontributors bot commented Dec 22, 2020

tkalus commented Dec 21, 2020 •

edited

Loading

tkalus commented Dec 21, 2020 •

edited

Loading

tkalus commented Dec 22, 2020 •

edited

Loading

simskij commented Dec 22, 2020 •

edited

Loading