diff --git a/RUNBOOK.md b/RUNBOOK.md index 0f44c8d..76f4f75 100644 --- a/RUNBOOK.md +++ b/RUNBOOK.md @@ -506,8 +506,8 @@ sit still while the controller is fine. It is evidence only when paired with a reading this section. **One metric answers it, and only one.** The controller observes -`argocd_app_reconcile_count` once per completed app reconciliation, so with a 2-minute -comparison expiry it climbs continuously and forever. Flat means stopped: +`argocd_app_reconcile_count` once per completed app reconciliation. Flat means it is doing +nothing: ```bash kubectl -n monitoring exec prometheus-kube-prometheus-stack-prometheus-0 -c prometheus -- \ @@ -516,18 +516,18 @@ kubectl -n monitoring exec prometheus-kube-prometheus-stack-prometheus-0 -c prom ``` **Two metrics that look like they answer it and do not.** Both were tried on 2026-07-22 -against a controller that had been wedged for 82 minutes and had reconciled exactly zero -apps, and both read healthy: +against a controller that had reconciled nothing for 82 minutes, and both read healthy: -| metric | reading during the wedge | why it lies | +| metric | reading at the time | why it lies | |---|---|---| -| `argocd_redis_request_total` | 45 reads / 15m, climbing | something in the process still touches the cache when the reconcile loop is dead — it measures "the pod is running", which `up` already covers | -| `workqueue_unfinished_work_seconds{name="app_reconciliation_queue"}` | 0 | the wedge blocks goroutines *outside* the queue, so nothing is in flight to count and nothing is being enqueued either | +| `argocd_redis_request_total` | 45 reads / 15m, climbing | something in the process still touches the cache when nothing is reconciling — it measures "the pod is running", which `up` already covers | +| `workqueue_unfinished_work_seconds{name="app_reconciliation_queue"}` | 0 | it only counts work already *in* the queue, and the queue is empty. Nothing is stuck; nothing is being enqueued | Keep the second one anyway — it catches a genuinely stuck queue item, which is a different failure. Just never read a zero from it as "healthy". -**What the wedge actually is.** Read the controller's own metrics during one: +**What is actually wrong: the periodic git poll does not run.** Read the controller's own +metrics on an idle cluster: ```bash kubectl -n monitoring exec prometheus-kube-prometheus-stack-prometheus-0 -c prometheus -- \ @@ -535,32 +535,45 @@ kubectl -n monitoring exec prometheus-kube-prometheus-stack-prometheus-0 -c prom | grep -E '^workqueue_(depth|adds_total|longest_running_processor_seconds)\{controller="app_reconciliation_queue"' ``` -Measured 2026-07-22 on a controller that had reconciled nothing for 15 minutes: +Measured 2026-07-22, across two separate controller pods, on a fully healthy API server: ``` -workqueue_depth 0 -workqueue_longest_running_processor_seconds 0 -workqueue_adds_total 68 <- frozen +03:37:03 controller starts, refreshes all 3 apps adds_total = 3 +03:38:31 adds_total = 3 +03:41:33 adds_total = 3 +03:44:34 adds_total = 3 +03:47:35 adds_total = 3 <- expiry is 2m0s, jitter 60s ``` -Empty queue, idle processors, and no new adds. Nothing is *blocked* — nothing is being -**enqueued**. The periodic app-resync timer (`appResyncPeriod=2m0s, appResyncJitter=1m0s`, -logged at controller startup) has stopped firing, so no Application is ever queued for -refresh again. +`workqueue_depth 0`, `longest_running_processor_seconds 0`, `adds_total` frozen. Nothing is +*blocked* — nothing is being **enqueued**. The controller logs its own schedule at startup +(`appResyncPeriod=2m0s, appResyncJitter=1m0s`) and `argocd-cm` carries the matching +`timeout.reconciliation: 120s`, so the setting is read and then never acted on. -The trigger is an Application-informer watch break. Every occurrence followed an API server -disruption, and the logs carry the matching line: +Refreshes still happen from two other paths, which is what makes this so easy to +misread as working: +| path | fires when | observed | +|---|---|---| +| startup | controller (re)starts | 3 apps refreshed within ~2s of ready | +| cluster events | a watched resource changes | 68 adds during one svcforge rollout, then flat the moment the cluster went quiet | +| periodic poll | every 2m ± 60s | **never** | + +**The consequence is the thing to take away: a commit that changes only the repo is never +noticed.** Every "auto-sync" observed on 2026-07-22 happened within seconds of a controller +restart, i.e. it was the startup refresh, not the poll. Do not read a successful deploy +straight after a restart as evidence that polling works. + +There is also **no Gitea webhook configured** (`GET /api/v1/repos/gitea_admin/svcforge/hooks` +returns `[]`, and `argocd-secret` has no `webhook.gitea.secret`), so nothing covers for the +broken poll. Wiring one is the fix worth making regardless — it turns a 2-3 minute poll into +an instant push, and it does not depend on the behaviour above being repaired. + +Until then, a deploy needs a nudge: + +```bash +kubectl -n argocd annotate application svcforge argocd.argoproj.io/refresh=normal --overwrite ``` -Warning: watch ended with error ... reflector=...reflector.go:290 type=*v1alpha1.Application - err="unable to decode an event from the watch stream: http2: client connection lost" -``` - -The informer re-lists, but the resync does not resume. That is why the controller looks -alive from every angle except the one that matters, and why nothing short of a restart -clears it. Anything that kills kube-apiserver — on a single-control-plane cluster, that -includes memory reclaim stalling `/livez` past its 80s threshold — can silently stop all -GitOps until someone notices. Without Prometheus, fall back to the logs — this works and is what found the 2026-07-22 wedge before the metrics were checked: