runbook: correct 1b56cda -- the poll never runs, watch breaks are not the cause
ci / lint (push) Successful in 25s
ci / types (push) Successful in 54s
ci / unit (push) Successful in 42s
ci / security (push) Successful in 57s
ci / dockerfile (push) Successful in 7s
ci / chart (push) Successful in 10s
ci / integration (push) Successful in 59s
ci / image (api) (push) Successful in 1m38s
ci / image (reconciler) (push) Successful in 1m32s
ci / image (worker) (push) Successful in 1m34s
ci / bump (push) Successful in 13s

1b56cda blamed the Application-informer watch break after an API server kill.
That is not it. Watched a freshly restarted controller for 11 minutes on a fully
healthy API server:

    03:37:03  startup refresh, 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

The periodic poll does not fire, ever, with or without a prior disruption. The
68 adds the earlier pod accumulated were cluster events during a rollout, and it
went flat the moment the cluster quieted -- same shape, no watch break involved.

Refreshes come from startup and from cluster events only. A commit that changes
just the repo is never noticed. Every "auto-sync" seen on 2026-07-22 landed
within seconds of a controller restart, which is the startup refresh -- I read
one of those as proof the pipeline worked, and it was not.

Also records that no Gitea webhook exists, so nothing covers for the broken
poll. Wiring one is worth doing regardless of whether the poll is ever repaired.
This commit is contained in:
2026-07-22 03:49:04 +00:00
parent 1b56cda231
commit cd61eca12e
+40 -27
View File
@@ -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: