From fe677bae9415f379541dea69354a335b3efaa3b1 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Wed, 28 Oct 2026 12:43:38 +0100 Subject: [PATCH] security watch: Docker Hub requests spaced, a 429 retried (NOT CHECKED only after the last try), tag lists cached 24 h per registry path on the runner (R-1334); W14 --- documentation/architecture/08-alarm-ladder.md | 8 ++ scripts/CHANGELOG.md | 10 +++ scripts/security_watch.py | 84 ++++++++++++++++--- scripts/test_security_watch.py | 69 ++++++++++++++- 4 files changed, 158 insertions(+), 13 deletions(-) diff --git a/documentation/architecture/08-alarm-ladder.md b/documentation/architecture/08-alarm-ladder.md index dd2daef9..383a81a1 100644 --- a/documentation/architecture/08-alarm-ladder.md +++ b/documentation/architecture/08-alarm-ladder.md @@ -700,3 +700,11 @@ new image is read on the night its tag first appears; the log's `RUNTIME read= was read and how long it took. The DooPlex group (`documentation/security-watch/dooplex-workloads.txt`, from homelab-manifests) is read the same way and mailed in its own block; Felhom changes nothing on DooPlex. +**Docker Hub's tag API is asked gently (2026-10-28, R-1334).** The 2026-10-28 night run was refused 15 times (HTTP 429) +when it sent 211 tag-list requests to `hub.docker.com` in about 2 minutes from six workers; a 3.5-minute dry run that +morning sent 224 and was refused none. So: the requests to Docker Hub are spaced (one per second across the workers); +a 429 waits (its `Retry-After`, else 10/30/60 s) and tries again, and the image is NOT CHECKED only after the fourth +try; a tag list is kept for 24 hours per registry path in the CI runner's cache (`~/.cache/felhom-watch-tags.json`, not +committed), so two names of one path (`lscr.io/linuxserver/x`, `linuxserver/x`) and a same-day re-run fetch nothing. +The log's `TAGS fetched=… from-cache=… retried-429=…` line counts it. No Docker Hub login is used. + diff --git a/scripts/CHANGELOG.md b/scripts/CHANGELOG.md index 9dec4ee9..b5dca2f1 100644 --- a/scripts/CHANGELOG.md +++ b/scripts/CHANGELOG.md @@ -1,3 +1,13 @@ +## 2026-10-28 (midday) — the watch asks Docker Hub gently: spaced, retried on 429, tag lists cached 24 h (R-1334) + +- **`security_watch.py`:** Docker Hub requests (`hub.docker.com`, `registry-1.docker.io`, `auth.docker.io`) go through + `Sources.hub_get`: one per `HUB_GAP_S` (1 s) across the six workers; a 429 waits (`Retry-After`, capped at 120 s, else + 10/30/60 s) and is retried — NOT CHECKED only after `HUB_TRIES` (4). Tag lists are keyed by registry path (two names + of one path fetch once) and kept `TAG_CACHE_S` (24 h) in the runner's cache file `felhom-watch-tags.json` beside the + wheel cache (`--tag-cache=` overrides). The log gains `TAGS fetched=… from-cache=… retried-429=…`. +- Measured before: night job 2446, 211 Docker Hub requests in ~2 min, 15 refused; dry job 2450, 224 in ~3.5 min, 0 refused. +- Tests: W14 (7 checks; the 429 retry seen failing on the old code — the first 429 ended the image) — 71 checks. + ## 2026-10-28 — the watch remembers a notice per GROUP: a catalog pin and a DooPlex pin of one image are two entries - **`security_watch.py`:** the memory key is `dooplex:|` for a DooPlex pin (`mem_image`), `|` as diff --git a/scripts/security_watch.py b/scripts/security_watch.py index 4bbb8c73..e07d1d9f 100644 --- a/scripts/security_watch.py +++ b/scripts/security_watch.py @@ -52,6 +52,8 @@ import json import os import re import sys +import threading +import time import urllib.error import urllib.request import zlib @@ -313,11 +315,44 @@ def cached_runtime_reader(cache, resolve=None, read=None): return reader +# Docker Hub (R-1334): its tag API refused the 2026-10-28 night run (15 x HTTP 429) when 211 requests went out in about +# 2 minutes from six workers; the 07:03 dry run sent 224 in 3.5 minutes and got none. So the requests to Docker Hub are +# SPACED (one per HUB_GAP_S, across the workers), a 429 is RETRIED (its Retry-After, capped) and is NOT CHECKED only after +# the last try, and a tag list is kept for TAG_CACHE_S per registry path (two names of one path fetch once). +HUB_HOSTS = ("hub.docker.com", "registry-1.docker.io", "auth.docker.io") +HUB_TRIES = 4 +HUB_GAP_S = 1.0 +HUB_BACKOFF_S = (10, 30, 60) +TAG_CACHE_S = 24 * 3600 + + class Sources: - def __init__(self, net, today, rotate): + def __init__(self, net, today, rotate, tag_cache=None, now=None, sleep=None, clock=None): self.net, self.today, self.rotate = net, today, rotate self._adv, self._rel, self._feed, self._notes, self._osv, self._tags = {}, {}, {}, {}, {}, {} self.rate_limited = False + self.tag_cache = tag_cache if tag_cache is not None else {} + self.now = time.time() if now is None else now + self.sleep, self.clock = sleep or time.sleep, clock or time.monotonic + self._hub_lock, self._hub_last = threading.Lock(), None + self.tag_stats = {"from_cache": 0, "fetched": 0, "retried_429": 0} + + def hub_get(self, url, headers=None): + """A GET to Docker Hub: spaced across the workers, a 429 retried. Returns the last answer.""" + for i in range(HUB_TRIES): + with self._hub_lock: + if self._hub_last is not None: + wait = HUB_GAP_S - (self.clock() - self._hub_last) + if wait > 0: + self.sleep(wait) + self._hub_last = self.clock() + st, h, body = self.net.get(url, headers) + if st != 429 or i == HUB_TRIES - 1: + return st, h, body + self.tag_stats["retried_429"] += 1 + ra = str((h or {}).get("Retry-After", (h or {}).get("retry-after", ""))) + self.sleep(min(int(ra), 120) if ra.isdigit() else HUB_BACKOFF_S[min(i, len(HUB_BACKOFF_S) - 1)]) + return st, h, body def gh_advisories(self, repo): if repo in self._adv: @@ -408,30 +443,37 @@ class Sources: return self._osv[key] def _registry_tags(self, path): - st, _h, body = self.net.get("https://auth.docker.io/token?service=registry.docker.io&scope=repository:%s:pull" % path) + st, _h, body = self.hub_get("https://auth.docker.io/token?service=registry.docker.io&scope=repository:%s:pull" % path) if st != 200: raise SourceError("Docker registry token for %s: HTTP %s" % (path, st)) tok = json.loads(body).get("token", "") - st, _h, body = self.net.get("https://registry-1.docker.io/v2/%s/tags/list?n=10000" % path, + st, _h, body = self.hub_get("https://registry-1.docker.io/v2/%s/tags/list?n=10000" % path, {"Authorization": "Bearer %s" % tok}) if st != 200: raise SourceError("Docker registry tags of %s: HTTP %s" % (path, st)) return json.loads(body).get("tags") or [] def tags(self, image): - if image in self._tags: - return self._tags[image] reg, path = registry_of(image) + key = "%s/%s" % (reg, path) + if key in self._tags: + return self._tags[key] + hit = self.tag_cache.get(key) + if hit and self.now - hit.get("at", 0) < TAG_CACHE_S and isinstance(hit.get("tags"), list): + self.tag_stats["from_cache"] += 1 + self._tags[key] = hit["tags"] + return hit["tags"] names = [] if reg == "docker.io": url = "https://hub.docker.com/v2/repositories/%s/tags?page_size=100&ordering=last_updated" % path for _ in range(3): - st, _h, body = self.net.get(url) + st, h, body = self.hub_get(url) if st == 404 and not names: names = self._registry_tags(path) # the web API misses some repos the registry serves (plant-it) break if st != 200: - raise SourceError("Docker Hub tags of %s: HTTP %s" % (path, st)) + raise SourceError("Docker Hub tags of %s: HTTP %s%s" % ( + path, st, " after %d tries" % HUB_TRIES if st == 429 else "")) d = json.loads(body) names += [t["name"] for t in d.get("results", [])] url = d.get("next") @@ -454,7 +496,10 @@ class Sources: url = "https://ghcr.io" + nxt.group(1) if nxt.group(1).startswith("/") else nxt.group(1) else: names = None # a registry the watch does not read (our own Gitea, GitLab): stated, not a failure - self._tags[image] = names + self._tags[key] = names + if names is not None: + self.tag_stats["fetched"] += 1 + self.tag_cache[key] = {"at": self.now, "tags": names} return names @@ -822,11 +867,12 @@ def send(mail, key, test=False): # ── the run ────────────────────────────────────────────────────────────────────────────────────────────────────────── -def run(items, net, today, rotate, runtime=None): +def run(items, net, today, rotate, runtime=None, tag_cache=None): """`runtime`: a reader (cached_runtime_reader) for the images' own runtime parts; None = not looked at (the tests - of W1–W9). main() always hands one.""" - src = Sources(net, today, rotate) + of W1–W9). main() always hands one. `tag_cache`: {registry/path: {"at", "tags"}}, read and updated (R-1334).""" + src = Sources(net, today, rotate, tag_cache=tag_cache) src.runtime = runtime + run.sources = src # Box programs first, one by one (they share sources with nothing); apps in a small pool. box = [it for it in items if _grp(it) == 0] apps = [it for it in items if _grp(it) != 0] # catalog apps and the DooPlex list share the pool @@ -886,7 +932,19 @@ def main(argv): prior = json.load(open(state_path, encoding="utf-8")) rcache = {k: dict(v, _seen=False) for k, v in (prior.get("runtime_cache") or {}).items()} rreader = None if "no-runtime" in opts else cached_runtime_reader(rcache) - run(items, net, today, rotate=not token, runtime=rreader) + # the tag lists' 24-hour cache lives on the CI runner (beside the wheel cache), not in the committed state (R-1334) + tpath = opts.get("tag-cache") or os.path.join(os.path.dirname(image_runtime._wheel_cache()), "felhom-watch-tags.json") + try: + tcache = json.load(open(tpath, encoding="utf-8")) + except (OSError, ValueError): + tcache = {} + run(items, net, today, rotate=not token, runtime=rreader, tag_cache=tcache) + try: + os.makedirs(os.path.dirname(tpath), exist_ok=True) + cut = time.time() - TAG_CACHE_S + json.dump({k: v for k, v in tcache.items() if v.get("at", 0) > cut}, open(tpath, "w", encoding="utf-8")) + except OSError as e: + print("TAG CACHE not saved (%s): %s" % (tpath, e)) for line in table(items): print(line) counts = {} @@ -898,6 +956,8 @@ def main(argv): print("RUNTIME read=%d (%.0f s) from-cache=%d not-checked=%d zstd-decoder=%s" % ( st["read"], st["read_s"], st["cached"], st["not_checked"], image_runtime.zstd_decoder_how() if st["read"] else "not needed")) + ts = run.sources.tag_stats + print("TAGS fetched=%d from-cache=%d retried-429=%d (cache %s)" % (ts["fetched"], ts["from_cache"], ts["retried_429"], tpath)) print("REQUESTS " + " ".join("%s=%d" % kv for kv in sorted(net.requests.items()))) state_path = opts.get("state") state, missing = {}, True diff --git a/scripts/test_security_watch.py b/scripts/test_security_watch.py index 9d770c5d..92fb5f8c 100644 --- a/scripts/test_security_watch.py +++ b/scripts/test_security_watch.py @@ -22,6 +22,8 @@ What is pinned, each by its consequence (the mail or the class), not by its mech the catalog's lane; a DooPlex image in a private registry is NOT CHECKED with the reason; its own weekly block W13 one image in the catalog AND on DooPlex (R-1333): a new notice is mailed for both pins; the memory keeps one entry per group; an old shared key is copied, so nothing is mailed twice; a clean DooPlex pin forgets only its own + W14 Docker Hub (R-1334): a 429 is retried (Retry-After honoured) and is NOT CHECKED only after the last try; a tag list + cached under 24 h is not fetched, an older one is; two names of one path fetch once; requests are spaced W11 ghcr.io tag lists are PAGED (Link: rel="next"): every page is read, so a newer tag on page 2 is seen Red-proofs (2026-10-26): W5 with the `k not in known` test removed (every night mails) -> W5 fails; W6 with the streak threshold at 1 -> W6 fails; W2 with FEED_DAYS check removed -> W2's old-item case fails; W4 with SourceError swallowed @@ -393,7 +395,7 @@ def t_runtime(): src = open(os.path.join(HERE, "security_watch.py"), encoding="utf-8").read() check("W10 main() hands the reader to run() (off only with --no-runtime)", "rreader = None if \"no-runtime\" in opts else cached_runtime_reader(rcache)" in src - and "runtime=rreader)" in src) + and "runtime=rreader, tag_cache=tcache)" in src) check("W10 the reader counts what it read and from the cache (the log's RUNTIME line)", r.stats["read"] == 2 and r.stats["cached"] == 1 and r.stats["not_checked"] == 1 and "RUNTIME read=" in src, r.stats) @@ -470,11 +472,76 @@ def t_two_groups(): ["rommapp/romm|CVE-2026-111497"], sorted(st4["advisories"])) +class SeqNet(FakeNet): + """FakeNet whose route may be a LIST of answers, served in order (the last one repeats).""" + def get(self, url, headers=None, timeout=30): + for pfx, ans in self.routes.items(): + if url.startswith(pfx) and isinstance(ans, list): + self.seen.append(url) + st, h, body = ans.pop(0) if len(ans) > 1 else ans[0] + return st, h, body if isinstance(body, bytes) else json.dumps(body).encode() + return FakeNet.get(self, url, headers, timeout) + + +def t_dockerhub(): + print("-- W14: Docker Hub — retry a 429, cache a tag list for 24 h, one fetch per path, paced (R-1334)") + hub = "https://hub.docker.com/v2/repositories/library/redis/tags" + ok = (200, {}, {"results": [{"name": "7.4.1"}, {"name": "7.4.0"}], "next": None}) + r429 = (429, {"Retry-After": "7"}, b"") + slept = [] + clock = [1000.0] + + def sleep(s): + slept.append(s) + clock[0] += s + + def mk(net, cache=None, now=1000.0): + return w.Sources(net, TODAY, False, tag_cache=cache, now=now, sleep=sleep, clock=lambda: clock[0]) + net = SeqNet({hub: [r429, ok]}) + names = mk(net).tags("redis") + check("W14 a 429 is retried after its Retry-After, and the retry's tags are used", + names == ["7.4.1", "7.4.0"] and len(net.seen) == 2 and 7 in slept, (names, net.seen, slept)) + net = SeqNet({hub: [r429]}) + try: + mk(net).tags("redis") + res = "no error" + except w.SourceError as e: + res = str(e) + check("W14 a 429 on every try -> NOT CHECKED only after the last try (%d tries)" % w.HUB_TRIES, + "429" in res and len(net.seen) == w.HUB_TRIES, (res, len(net.seen))) + cache = {"docker.io/library/redis": {"at": 1000.0 - 3600, "tags": ["7.4.1"]}} + net = SeqNet({hub: [ok]}) + names = mk(net, cache).tags("redis") + check("W14 a tag list cached an hour ago -> no request", names == ["7.4.1"] and net.seen == [], (names, net.seen)) + cache = {"docker.io/library/redis": {"at": 1000.0 - 25 * 3600, "tags": ["7.4.0"]}} + net = SeqNet({hub: [ok]}) + names = mk(net, cache).tags("redis") + check("W14 a tag list cached 25 h ago -> fetched again, and the cache holds the new list", + names == ["7.4.1", "7.4.0"] and len(net.seen) == 1 and cache["docker.io/library/redis"]["at"] == 1000.0, + (names, net.seen, cache)) + lsio = "https://hub.docker.com/v2/repositories/linuxserver/sonarr/tags" + net = SeqNet({lsio: [(200, {}, {"results": [{"name": "4.0.20"}], "next": None})]}) + src = mk(net) + a, b = src.tags("lscr.io/linuxserver/sonarr"), src.tags("linuxserver/sonarr") + check("W14 two names of one Docker Hub path -> one fetch", a == b == ["4.0.20"] and len(net.seen) == 1, net.seen) + slept.clear() + net = SeqNet({hub: [ok], lsio: [(200, {}, {"results": [{"name": "4.0.20"}], "next": None})]}) + src = mk(net) + src.tags("redis") + src.tags("linuxserver/sonarr") + check("W14 Docker Hub requests are spaced (>= %.1f s apart)" % w.HUB_GAP_S, + slept and abs(sum(slept) - w.HUB_GAP_S) < 0.01, slept) + src_text = open(os.path.join(HERE, "security_watch.py"), encoding="utf-8").read() + check("W14 main() loads the runner's tag cache, hands it to run() and prints the TAGS line", + "tag_cache=tcache)" in src_text and "felhom-watch-tags.json" in src_text and "TAGS fetched=" in src_text) + + def main(): t_ranges() t_classes() t_memory() t_two_groups() + t_dockerhub() t_inventory() for t in (t_runtime, t_ghcr_pages, t_dooplex): try: