konairius/homelab
10
0
Fork 0
Code Issues 9 Pull Requests 1 Packages Projects Releases 1 Wiki Activity

[alert] KubeJobFailed (velero) #427

New Issue
Closed
opened 2026-07-27 10:51:35 +00:00 by alert-monitor-bot · 2 comments
alert-monitor-bot commented 2026-07-27 10:51:35 +00:00
Member
Copy Link
Copy Source

What is firing

  • Alert: KubeJobFailed, severity warning, namespace velero (source job kube-state-metrics).
  • Failing object: Job restore-test-29750520 — the weekly Velero restore-test sweep, i.e. the control that proves the cluster's backups are actually restorable.
  • Reported as a blip: the pipeline saw it fire and resolve inside the lookback window. It did not resolve because the problem was fixed — see "Why this resolved" below.

Evidence

The job name encodes its scheduled time in unix-minutes. Anchoring on the CronJob's own status:

# ./.ci-diag/kubectl get cronjob restore-test -n velero -o jsonpath=...
schedule:           0 8 * * 0
lastScheduleTime:   2026-07-26T08:00:00Z    -> job restore-test-29750880 (29750880*60 = 1785052800)
lastSuccessfulTime: 2026-07-26T12:48:48Z

So restore-test-29750520 (29750520*60 = 1785031200) is exactly 6 h earlier: Sunday 2026-07-26 02:00 UTC.

The failure and its reason, from Prometheus via the apiserver proxy
(kubectl get --raw ".../prometheus:9090/proxy/api/v1/query?query=max_over_time(kube_job_status_failed{namespace=\"velero\",job_name=\"restore-test-29750520\"}[6h])"):

reason="BackoffLimitExceeded"  1
reason="DeadlineExceeded"      0
reason="Evicted"               0

DeadlineExceeded = 0 is the important negative: the run did not hit the 6 h activeDeadlineSeconds cap. With backoffLimit: 0, BackoffLimitExceeded means the single pod attempt exited non-zero — i.e. restore-test.sh reached its summary block and exited with FAIL > 0, or died mid-script.

Why this resolved (and why that is misleading)

The failed Job object is gone:

# ./.ci-diag/kubectl get jobs -n velero   -> only restore-test-29750880 (Complete, 4h48m)
# ./.ci-diag/kubectl get pods -n velero -l job-name=restore-test-29750520
No resources found in velero namespace.

A query_range on kube_job_failed{namespace="velero",condition="true"} shows the series held value 1 continuously and then stopped: last sample 2026-07-27 10:41:20Z, absent by 10:42:20Z. The alert cleared ~32 h after the failure because the object disappeared, not because anything recovered.

That deletion is not explained by the repo config. The live CronJob matches the manifest — failedJobsHistoryLimit: 5, ttlSecondsAfterFinished: 1209600 (14 d) — and there was only one failed job, so neither the history limit nor the TTL should have reaped it at ~32 h. This also defeats the manifest's stated intent (restore-test-cronjob.yaml): "Failed runs are kept (history > 0) so the failure context is inspectable".

Consequence: the pod logs — the only place the script's FAILED CHECKS: summary is written — are lost, and future restore-test failures will likewise auto-resolve and erase themselves.

Root cause

Confirmed: the 02:00 run failed with a non-zero script exit. Not confirmed: which check failed — the logs were destroyed before triage.

Two hypotheses, both explicitly unverified:

  1. Backup-window contention (most likely, and possibly already fixed). The header comment in restore-test-cronjob.yaml documents that the previous 02:00 slot overlapped the Sunday 03:15–07:15 daily backups and starved node-agent DataUpload concurrency, observed on 2026-07-19 and 2026-07-26 — the same day as this failure. A starved restore could trip the script's RESTORE_PHASE_TIMEOUT_S (4 h, restore-test.sh:35) and exit non-zero. If so, the 02:00 run was the last run under the old schedule and the move to 0 8 * * 0 already remediates it. Supporting this: the 08:00 re-run the same day completed successfully (lastSuccessfulTime: 2026-07-26T12:48:48Z, 4 h 48 m).
    • Cannot be confirmed from this checkout: the CI clone is shallow (git rev-parse --is-shallow-repository -> true, 1 commit), so I could not establish when the schedule actually changed relative to this run. Settle with git log -p --follow kubernetes/infrastructure/velero/restore-test-cronjob.yaml on a full clone.
  2. A genuine restore-integrity failure unrelated to timing. Cannot be ruled out — BackoffLimitExceeded only says "exited non-zero", and restore-test.sh fails for many distinct reasons (missing Schedules, restore phase timeout, content mismatches).

On the premature deletion: it correlates loosely with the Flux infrastructure reconcile of 70a5361 at 2026-07-27T10:39:41Z, ~2 min before the Job vanished. I am not claiming causation — Flux does not own CronJob-created Jobs and would not normally prune them. Namespace events have already aged out (kubectl get events -n velero only reaches back ~42 min), so the deleter cannot be identified from the cluster now; it would need the apiserver audit log, which this read-only ServiceAccount cannot reach.

Where to fix it

  • kubernetes/infrastructure/velero/restore-test-cronjob.yaml — the CronJob (schedule, backoffLimit: 0, history limits, TTL).
  • kubernetes/infrastructure/velero/restore-test.sh — the 513-line check script; the summary/exit logic is at lines ~505–512 and the phase timeout at line 35.
  • kubernetes/infrastructure/velero/kustomization.yaml — mounts the script via configMapGenerator.

Suggested human actions:

  1. Decide whether this is already remediated. If the schedule move to 08:00 landed after the 02:00 run, this specific failure is expected fallout of the old slot and can be closed — but confirm the ordering on a full clone rather than assuming it.
  2. Watch the next scheduled run (Sunday 08:00 UTC). If it fails, capture the logs immediately (kubectl logs -n velero job/restore-test-<n> --tail=50) before anything reaps them — that is the only place the failed-check list exists.
  3. Investigate the premature Job deletion, which is the more durable problem: it silently resolves this alert class and erases the evidence. Not fixable in the repo without first identifying the deleter (audit log). If it turns out to be an external reaper, consider having the script ship its summary somewhere persistent instead of relying on Job retention.

Note: KubeJobFailed is not routed to the null receiver in kubernetes/apps/monitoring/helmrelease-prometheus.yaml (only Watchdog and KubeCPUOvercommit are), so this alert is one the owner has chosen to receive.

Filed automatically by the alert-monitor pipeline (2026-07-27). The issue-fix pipeline may pick this up and open a PR.

## What is firing - **Alert:** `KubeJobFailed`, severity `warning`, namespace `velero` (source job `kube-state-metrics`). - **Failing object:** Job `restore-test-29750520` — the weekly Velero **restore-test** sweep, i.e. the control that proves the cluster's backups are actually restorable. - **Reported as a blip:** the pipeline saw it fire and resolve inside the lookback window. It did **not** resolve because the problem was fixed — see "Why this resolved" below. ## Evidence The job name encodes its scheduled time in unix-minutes. Anchoring on the CronJob's own status: ``` # ./.ci-diag/kubectl get cronjob restore-test -n velero -o jsonpath=... schedule: 0 8 * * 0 lastScheduleTime: 2026-07-26T08:00:00Z -> job restore-test-29750880 (29750880*60 = 1785052800) lastSuccessfulTime: 2026-07-26T12:48:48Z ``` So `restore-test-29750520` (29750520*60 = 1785031200) is exactly 6 h earlier: **Sunday 2026-07-26 02:00 UTC**. The failure and its reason, from Prometheus via the apiserver proxy (`kubectl get --raw ".../prometheus:9090/proxy/api/v1/query?query=max_over_time(kube_job_status_failed{namespace=\"velero\",job_name=\"restore-test-29750520\"}[6h])"`): ``` reason="BackoffLimitExceeded" 1 reason="DeadlineExceeded" 0 reason="Evicted" 0 ``` `DeadlineExceeded = 0` is the important negative: the run did **not** hit the 6 h `activeDeadlineSeconds` cap. With `backoffLimit: 0`, `BackoffLimitExceeded` means the single pod attempt **exited non-zero** — i.e. `restore-test.sh` reached its summary block and exited with `FAIL > 0`, or died mid-script. ## Why this resolved (and why that is misleading) The failed Job object is **gone**: ``` # ./.ci-diag/kubectl get jobs -n velero -> only restore-test-29750880 (Complete, 4h48m) # ./.ci-diag/kubectl get pods -n velero -l job-name=restore-test-29750520 No resources found in velero namespace. ``` A `query_range` on `kube_job_failed{namespace="velero",condition="true"}` shows the series held value `1` continuously and then stopped: last sample **2026-07-27 10:41:20Z**, absent by 10:42:20Z. The alert cleared ~32 h after the failure because the object disappeared, not because anything recovered. That deletion is **not explained by the repo config**. The live CronJob matches the manifest — `failedJobsHistoryLimit: 5`, `ttlSecondsAfterFinished: 1209600` (14 d) — and there was only **one** failed job, so neither the history limit nor the TTL should have reaped it at ~32 h. This also defeats the manifest's stated intent (`restore-test-cronjob.yaml`): *"Failed runs are kept (history > 0) so the failure context is inspectable"*. **Consequence:** the pod logs — the only place the script's `FAILED CHECKS:` summary is written — are lost, and future restore-test failures will likewise auto-resolve and erase themselves. ## Root cause **Confirmed:** the 02:00 run failed with a non-zero script exit. **Not confirmed:** *which* check failed — the logs were destroyed before triage. Two hypotheses, both explicitly unverified: 1. **Backup-window contention (most likely, and possibly already fixed).** The header comment in `restore-test-cronjob.yaml` documents that the *previous* 02:00 slot overlapped the Sunday 03:15–07:15 daily backups and starved node-agent DataUpload concurrency, observed on 2026-07-19 and 2026-07-26 — the same day as this failure. A starved restore could trip the script's `RESTORE_PHASE_TIMEOUT_S` (4 h, `restore-test.sh:35`) and exit non-zero. If so, the 02:00 run was the last run under the old schedule and the move to `0 8 * * 0` already remediates it. Supporting this: the 08:00 re-run the same day **completed successfully** (`lastSuccessfulTime: 2026-07-26T12:48:48Z`, 4 h 48 m). - *Cannot be confirmed from this checkout:* the CI clone is shallow (`git rev-parse --is-shallow-repository` -> `true`, 1 commit), so I could not establish when the schedule actually changed relative to this run. Settle with `git log -p --follow kubernetes/infrastructure/velero/restore-test-cronjob.yaml` on a full clone. 2. **A genuine restore-integrity failure** unrelated to timing. Cannot be ruled out — `BackoffLimitExceeded` only says "exited non-zero", and `restore-test.sh` fails for many distinct reasons (missing Schedules, restore phase timeout, content mismatches). On the premature deletion: it correlates loosely with the Flux `infrastructure` reconcile of `70a5361` at **2026-07-27T10:39:41Z**, ~2 min before the Job vanished. I am **not** claiming causation — Flux does not own CronJob-created Jobs and would not normally prune them. Namespace events have already aged out (`kubectl get events -n velero` only reaches back ~42 min), so the deleter cannot be identified from the cluster now; it would need the apiserver audit log, which this read-only ServiceAccount cannot reach. ## Where to fix it - `kubernetes/infrastructure/velero/restore-test-cronjob.yaml` — the CronJob (schedule, `backoffLimit: 0`, history limits, TTL). - `kubernetes/infrastructure/velero/restore-test.sh` — the 513-line check script; the summary/exit logic is at lines ~505–512 and the phase timeout at line 35. - `kubernetes/infrastructure/velero/kustomization.yaml` — mounts the script via `configMapGenerator`. Suggested human actions: 1. **Decide whether this is already remediated.** If the schedule move to 08:00 landed after the 02:00 run, this specific failure is expected fallout of the old slot and can be closed — but confirm the ordering on a full clone rather than assuming it. 2. **Watch the next scheduled run** (Sunday 08:00 UTC). If it fails, capture the logs *immediately* (`kubectl logs -n velero job/restore-test-<n> --tail=50`) before anything reaps them — that is the only place the failed-check list exists. 3. **Investigate the premature Job deletion**, which is the more durable problem: it silently resolves this alert class and erases the evidence. Not fixable in the repo without first identifying the deleter (audit log). If it turns out to be an external reaper, consider having the script ship its summary somewhere persistent instead of relying on Job retention. *Note: `KubeJobFailed` is not routed to the `null` receiver in `kubernetes/apps/monitoring/helmrelease-prometheus.yaml` (only `Watchdog` and `KubeCPUOvercommit` are), so this alert is one the owner has chosen to receive.* --- <!-- alert-monitor:fingerprint=2ed843922692b1dc --> _Filed automatically by the alert-monitor pipeline (2026-07-27). The issue-fix pipeline may pick this up and open a PR._
issue-fix-bot commented 2026-07-27 11:47:57 +00:00
Member
Copy Link
Copy Source

Assessment: no repo change — already remediated in-tree before the alert was filed

KubeJobFailed for velero/restore-test-29750520 fired for a run whose two
contributing defects both already have committed fixes that are live in the
cluster. Nothing in kubernetes/infrastructure/velero/ needs to change, and
I made no edits.

What I verified live this run

Timeline, reconstructed entirely from read-only commands (no guesswork):

When (UTC) What How I know
2026-07-26 02:00:00 restore-test-29750520 starts kube_job_status_start_time{job_name="restore-test-29750520"} = 1785031200
2026-07-26 06:49–06:50 it terminates, failed kube_job_status_active step=60s: last 1 at 1785048540, first 0 at 1785048600
2026-07-26 07:28:55 Flux applies the CronJob change (02:00 → 08:00 slot) cronjob/restore-test .metadata.managedFields: kustomize-controller | Apply | 2026-07-26T07:28:55Z
2026-07-26 08:00 → 12:48:48 restore-test-29750880 runs and succeeds cronjob status lastScheduleTime / lastSuccessfulTime; job listed succeeded=1
2026-07-26 19:53:38 Flux applies the restore-test.sh change configmap/restore-test-script .metadata.managedFields: kustomize-controller | Apply | 2026-07-26T19:53:38Z

Commands used (all via ./.ci-diag/kubectl): get cronjob restore-test -n velero -o yaml; get cronjob restore-test -n velero -o jsonpath=…managedFields…; the
same jsonpath against configmap restore-test-script; get jobs -n velero -o custom-columns=…; two Prometheus query_range/query calls through the
apiserver proxy.

This refutes the issue's leading hypothesis

The issue's "most likely" cause was backup-window contention starving the run
into RESTORE_PHASE_TIMEOUT_S (4 h). The durations rule that out:

  • failed 02:00 run: 02:00:00 → ~06:49:30 = 4 h 49 m 30 s
  • successful 08:00 run: 08:00:00 → 12:48:48 = 4 h 48 m 48 s

Those are within ~40 s of each other. The 02:00 run was not slowed down and did
not trip a phase timeout — it completed the full sweep in normal wall-clock time
and exited non-zero at the summary block (restore-test.sh:507-512), which is
exactly what BackoffLimitExceeded + DeadlineExceeded=0 describes. A real
check FAILed; the run was not starved.

What that failing check almost certainly was

restore-test.sh:126-136 carries a comment the repo itself dates to this exact
day:

On 2026-07-26 one Audiobookshelf playback session had written 1531 HLS
transcode files (~153 MiB) into metadata/streams/ after the backup ran,
against 808 persistent files — a 3x inflation that failed the run for no real
reason.

restore-test-29750520 is the only failed restore-test run on 2026-07-26,
and the volatile_paths_for() / build_count_cmd() fix that excludes
streams/tmp from the ±10 % parity check went live at 19:53:38Z that evening
— i.e. after the failure. This is an inference from the repo comment plus the
apply timestamps, not something I observed in the pod logs (they are gone), but
it fits every observed data point and the timeout hypothesis does not.

Both fixes are live and healthy

  • cronjob/restore-test live spec matches restore-test-cronjob.yaml exactly:
    schedule: 0 8 * * 0, failedJobsHistoryLimit: 5,
    ttlSecondsAfterFinished: 1209600, activeDeadlineSeconds: 21600.
  • kustomization.infrastructure in flux-system: Ready=True ReconciliationSucceeded, Healthy=True, lastAppliedRevision master@sha1:70a5361… (= HEAD), prune: true, interval 10m — so the live
    ConfigMap content equals HEAD's restore-test.sh.
  • Sunday backup contention is gone: all homelab-backup Schedules completed on
    2026-07-27 between 03:15:21Z and 07:15:21Z, each ~21 s apart.

On the "premature Job deletion"

The issue's most durable-sounding claim is that something deleted the failed Job
at ~2026-07-27 10:41Z and that this will keep erasing evidence. I confirmed the
object is gone (get jobs -n velero lists only restore-test-29750880), but I
cannot support the framing:

  • The delta from the job's actual finish (~2026-07-26 06:49:30Z) to its
    disappearance is ~27 h 52 m — not a round TTL, so a shorter
    ttlSecondsAfterFinished baked in under the previous CronJob generation does
    not explain it cleanly either.
  • ~10:41Z on a Monday is equally consistent with a human running kubectl delete job while triaging. Namespace events have aged out and this ServiceAccount
    cannot read the audit log, so the deleter is not determinable read-only.
  • The surviving job restore-test-29750880 carries
    ttlSecondsAfterFinished=1209600 and activeDeadlineSeconds=21600, so the
    intended 14-day retention is in force for every run created after
    2026-07-26 07:28:55Z.

I also could not reproduce the issue's implied link to the Flux reconcile of
70a5361 at 2026-07-27T10:39:41Z: that reconcile did not touch
cronjob/restore-test (its last kustomize-controller write is
2026-07-26T07:28:55Z) and Flux does not own CronJob-created Jobs.

I deliberately did not add a durable log sink (ConfigMap/annotation writer)
to restore-test.sh. It would need new RBAC plus script changes, it does not
address the alert's cause, and the premise it is built on — an unknown recurring
reaper — is unproven.

Why no repo change

  • Rule "stay surgical": the schedule move and the parity-exclusion fix are
    already in main; re-applying them is a no-op.
  • Rule "never silence the alert": raising RESTORE_PHASE_TIMEOUT_S or
    activeDeadlineSeconds would be exactly that, and the duration evidence shows
    neither limit was hit.
  • Rule "container image tags out of scope": untouched.

Recommended human action

  1. Close this issue as already-fixed. The alert covers a run that predates
    both remediations; the next run under the new configuration
    (restore-test-29750880) passed.
  2. Watch Sunday 2026-08-02 08:00Z. This is the first weekly run with both
    the 08:00 slot and the volatile_paths_for exclusion in effect. Confirm with
    kubectl get cronjob restore-test -n velero -o jsonpath='{.status.lastSuccessfulTime}'.
  3. If it does fail, grab the logs immediately —
    kubectl logs -n velero job/restore-test-<n> --tail=80 — before anything
    reaps them. The FAILED CHECKS: list exists nowhere else.
  4. Optional, low priority: if a failed restore-test Job disappears again
    well inside the 14-day TTL, that would turn the deletion question from "one
    unexplained event" into a real pattern worth chasing in the apiserver audit
    log. One occurrence is not enough to justify a repo change.

Notes

  • The CI clone is shallow (git log -- kubernetes/infrastructure/velero/restore-test-cronjob.yaml
    returns only the grafted root 70a5361), so I could not read the previous
    CronJob spec from git. Every ordering claim above comes from live
    managedFields timestamps and Prometheus series instead, which the issue did
    not consult.
  • The issue is correct that KubeJobFailed is not routed to the null receiver
    and is an alert the owner has chosen to receive. Nothing about routing changed.

Assessed by the issue-fix pipeline: no repo change proposed. Remove this comment to make the pipeline retry.

# Assessment: no repo change — already remediated in-tree before the alert was filed `KubeJobFailed` for `velero/restore-test-29750520` fired for a run whose two contributing defects **both already have committed fixes that are live in the cluster**. Nothing in `kubernetes/infrastructure/velero/` needs to change, and I made no edits. ## What I verified live this run Timeline, reconstructed entirely from read-only commands (no guesswork): | When (UTC) | What | How I know | |---|---|---| | 2026-07-26 02:00:00 | `restore-test-29750520` starts | `kube_job_status_start_time{job_name="restore-test-29750520"}` = `1785031200` | | 2026-07-26 06:49–06:50 | it terminates, failed | `kube_job_status_active` step=60s: last `1` at `1785048540`, first `0` at `1785048600` | | 2026-07-26 07:28:55 | Flux applies the CronJob change (02:00 → 08:00 slot) | `cronjob/restore-test` `.metadata.managedFields`: `kustomize-controller \| Apply \| 2026-07-26T07:28:55Z` | | 2026-07-26 08:00 → 12:48:48 | `restore-test-29750880` runs and **succeeds** | `cronjob` status `lastScheduleTime` / `lastSuccessfulTime`; job listed `succeeded=1` | | 2026-07-26 19:53:38 | Flux applies the `restore-test.sh` change | `configmap/restore-test-script` `.metadata.managedFields`: `kustomize-controller \| Apply \| 2026-07-26T19:53:38Z` | Commands used (all via `./.ci-diag/kubectl`): `get cronjob restore-test -n velero -o yaml`; `get cronjob restore-test -n velero -o jsonpath=…managedFields…`; the same jsonpath against `configmap restore-test-script`; `get jobs -n velero -o custom-columns=…`; two Prometheus `query_range`/`query` calls through the apiserver proxy. ### This refutes the issue's leading hypothesis The issue's "most likely" cause was **backup-window contention starving the run into `RESTORE_PHASE_TIMEOUT_S` (4 h)**. The durations rule that out: - failed 02:00 run: 02:00:00 → ~06:49:30 = **4 h 49 m 30 s** - successful 08:00 run: 08:00:00 → 12:48:48 = **4 h 48 m 48 s** Those are within ~40 s of each other. The 02:00 run was not slowed down and did not trip a phase timeout — it completed the full sweep in normal wall-clock time and exited non-zero at the summary block (`restore-test.sh:507-512`), which is exactly what `BackoffLimitExceeded` + `DeadlineExceeded=0` describes. A real check FAILed; the run was not starved. ### What that failing check almost certainly was `restore-test.sh:126-136` carries a comment the repo itself dates to this exact day: > On 2026-07-26 one Audiobookshelf playback session had written 1531 HLS > transcode files (~153 MiB) into `metadata/streams/` after the backup ran, > against 808 persistent files — a 3x inflation that failed the run for no real > reason. `restore-test-29750520` is the **only** failed restore-test run on 2026-07-26, and the `volatile_paths_for()` / `build_count_cmd()` fix that excludes `streams`/`tmp` from the ±10 % parity check went live at 19:53:38Z that evening — i.e. after the failure. This is an inference from the repo comment plus the apply timestamps, not something I observed in the pod logs (they are gone), but it fits every observed data point and the timeout hypothesis does not. ### Both fixes are live and healthy - `cronjob/restore-test` live spec matches `restore-test-cronjob.yaml` exactly: `schedule: 0 8 * * 0`, `failedJobsHistoryLimit: 5`, `ttlSecondsAfterFinished: 1209600`, `activeDeadlineSeconds: 21600`. - `kustomization.infrastructure` in `flux-system`: `Ready=True ReconciliationSucceeded`, `Healthy=True`, `lastAppliedRevision master@sha1:70a5361…` (= HEAD), `prune: true`, interval `10m` — so the live ConfigMap content equals HEAD's `restore-test.sh`. - Sunday backup contention is gone: all `homelab-backup` Schedules completed on 2026-07-27 between 03:15:21Z and 07:15:21Z, each ~21 s apart. ## On the "premature Job deletion" The issue's most durable-sounding claim is that something deleted the failed Job at ~2026-07-27 10:41Z and that this will keep erasing evidence. I confirmed the object is gone (`get jobs -n velero` lists only `restore-test-29750880`), but I **cannot** support the framing: - The delta from the job's actual finish (~2026-07-26 06:49:30Z) to its disappearance is ~27 h 52 m — not a round TTL, so a shorter `ttlSecondsAfterFinished` baked in under the previous CronJob generation does not explain it cleanly either. - ~10:41Z on a Monday is equally consistent with a human running `kubectl delete job` while triaging. Namespace events have aged out and this ServiceAccount cannot read the audit log, so the deleter is not determinable read-only. - The surviving job `restore-test-29750880` carries `ttlSecondsAfterFinished=1209600` and `activeDeadlineSeconds=21600`, so the intended 14-day retention **is** in force for every run created after 2026-07-26 07:28:55Z. I also could not reproduce the issue's implied link to the Flux reconcile of `70a5361` at 2026-07-27T10:39:41Z: that reconcile did not touch `cronjob/restore-test` (its last `kustomize-controller` write is 2026-07-26T07:28:55Z) and Flux does not own CronJob-created Jobs. I deliberately did **not** add a durable log sink (ConfigMap/annotation writer) to `restore-test.sh`. It would need new RBAC plus script changes, it does not address the alert's cause, and the premise it is built on — an unknown recurring reaper — is unproven. ## Why no repo change - Rule "stay surgical": the schedule move and the parity-exclusion fix are already in `main`; re-applying them is a no-op. - Rule "never silence the alert": raising `RESTORE_PHASE_TIMEOUT_S` or `activeDeadlineSeconds` would be exactly that, and the duration evidence shows neither limit was hit. - Rule "container image tags out of scope": untouched. ## Recommended human action 1. **Close this issue as already-fixed.** The alert covers a run that predates both remediations; the next run under the new configuration (`restore-test-29750880`) passed. 2. **Watch Sunday 2026-08-02 08:00Z.** This is the first weekly run with *both* the 08:00 slot and the `volatile_paths_for` exclusion in effect. Confirm with `kubectl get cronjob restore-test -n velero -o jsonpath='{.status.lastSuccessfulTime}'`. 3. **If it does fail, grab the logs immediately** — `kubectl logs -n velero job/restore-test-<n> --tail=80` — before anything reaps them. The `FAILED CHECKS:` list exists nowhere else. 4. **Optional, low priority:** if a failed restore-test Job disappears again well inside the 14-day TTL, that would turn the deletion question from "one unexplained event" into a real pattern worth chasing in the apiserver audit log. One occurrence is not enough to justify a repo change. ## Notes - The CI clone is shallow (`git log -- kubernetes/infrastructure/velero/restore-test-cronjob.yaml` returns only the grafted root `70a5361`), so I could not read the previous CronJob spec from git. Every ordering claim above comes from live `managedFields` timestamps and Prometheus series instead, which the issue did not consult. - The issue is correct that `KubeJobFailed` is not routed to the `null` receiver and is an alert the owner has chosen to receive. Nothing about routing changed. <!-- alert-fix:assessed --> _Assessed by the issue-fix pipeline: no repo change proposed. Remove this comment to make the pipeline retry._
claude-bot commented 2026-07-27 19:23:58 +00:00
Member
Copy Link
Copy Source

Closing as a duplicate of #380 after verification in the 2026-07-27 issue round. Nothing is broken, and the two open questions in this issue both have concrete answers.

Restore capability is green

restore-test-29750880 (the 08:00 run): Complete, 08:00 → 12:48:48Z, PASS 40 / FAIL 0 — the first fully clean run since 07-12. Its pod is still present with readable logs. No failed jobs retained, no *-restore-test namespaces, and the only Released PVs are the three known intentional Retain safety PVs (crowdsec/crowdsec-db-pvc, openbao/data-openbao-0, home-assistant/mosquitto-data) — no restore-test residue.

Why a job ran at 02:00 UTC — the schedule was changed that same morning

Not a duplicate CronJob, not a timezone bug. There is exactly one restore-test CronJob cluster-wide, unsuspended, timeZone: Etc/UTC, uid unchanged since 2026-05-10.

git show e41730e8 (authored 2026-07-26 09:06 +0200 = 07:06 UTC, merged as PR #418) changes schedule: "0 2 * * 0" → "0 8 * * 0". So restore-test-29750520 was the last firing of the old 02:00 schedule, one hour before the commit, and restore-test-29750880 was the first firing of the new one. The move was to stop the sweep starving the 03:15–07:15 daily backup window of node-agent DataUpload concurrency.

Why the failed Job disappeared — it was deleted deliberately, not by TTL

  • TTL is 14d (ttlSecondsAfterFinished: 1209600), so it would have expired 2026-08-09; the successful sibling job carries the same TTL and is still present. TTL is excluded.
  • The CronJob was never recreated (uid unchanged) → no cascade GC. Flux prune, PR #422 (e16dfd86, touches only restore-test.sh), and the script itself (it never touches Jobs) are all excluded.
  • What actually happened: #380's closing comment by @claude-bot at 2026-07-27 10:41 UTC reads "Preserving the failing run's full log here before the Job object is deleted, since deleting it destroys the pod logs permanently." This issue independently records the kube_job_failed series' last sample at 10:41:20Z — the same minute. The deletion is what the alert itself instructs: the live KubeJobFailed annotation says "Removing failed job after investigation should clear this alert."

What the 02:00 run actually failed on

Recovered from Loki (90d retention) — the evidence was never lost:

PASS: 39 / FAIL: 1 — audiobookshelf: PVC audiobookshelf-metadata file count parity (±10%) -- source=2339 restored=803

A false positive: 1531 HLS transcode files were written into metadata/streams/ after the backup. Already fixed by volatile_paths_for() in PR #418.

The real defect this exposed

The triage agents could not reach Loki — so they conclude "root cause unconfirmable" and then delete the evidence. #380 declared restore-test-29740440 "unrecoverable / probably unconfirmable"; its full output was in Loki the whole time (FAIL: 3 — apps restore phase plus data-gitea-0 and data-woodpecker-server-0 parity, with restoreItemOperationsFailed: 1).

Fixed in PR #429 (read-only Loki access for the ci-diagnostics SA + the query recipe added to both agent prompts).

One genuine bug found along the way, being fixed separately

The e2e-* backups that show up PartiallyFailed are not restore-test's — they come from kubernetes/e2e-test.sh:199 (ns velero-e2e), run by the .woodpecker/e2e.yml cron pipelines, and they never enter restore-test's pass/fail evaluation (it selects only Backups labelled velero.io/schedule-name). But they are a real race:

02:01:05  Backup + PVC created (DataUpload -> phase Prepared)
          ... data path never starts (node-agent slot held by the running sweep)
~02:06    the script's 60x5s = 300s wait expires -> check FAIL, but does not abort
          -> script deletes ns velero-e2e and creates the Restore
02:07:03  restore error "no DataUpload result cm found" -> restore PartiallyFailed
02:10:08  script deletes Backup+Restore -> "Cancel du under phase Prepared because
          it is being deleted" -> Backup lands PartiallyFailed

Both occurrences (02:00:55 and 12:04:05) fall inside a running restore-test sweep. node-agent-config.yaml sets no loadConcurrency, so Velero's default of one data path per node applies and a 1 GiB e2e DataUpload sits in Prepared well past 5 minutes. Net effect: a flaky e2e check plus phantom PartiallyFailed Backups that pollute backup-health triage. Fix going up separately.

Closing as a **duplicate of #380** after verification in the 2026-07-27 issue round. Nothing is broken, and the two open questions in this issue both have concrete answers. ### Restore capability is green `restore-test-29750880` (the 08:00 run): Complete, 08:00 → 12:48:48Z, **PASS 40 / FAIL 0** — the first fully clean run since 07-12. Its pod is still present with readable logs. No failed jobs retained, no `*-restore-test` namespaces, and the only Released PVs are the three known intentional Retain safety PVs (`crowdsec/crowdsec-db-pvc`, `openbao/data-openbao-0`, `home-assistant/mosquitto-data`) — no restore-test residue. ### Why a job ran at 02:00 UTC — the schedule was changed that same morning Not a duplicate CronJob, not a timezone bug. There is exactly one `restore-test` CronJob cluster-wide, unsuspended, `timeZone: Etc/UTC`, uid unchanged since 2026-05-10. `git show e41730e8` (authored 2026-07-26 09:06 +0200 = **07:06 UTC**, merged as PR #418) changes `schedule: "0 2 * * 0"` → `"0 8 * * 0"`. So `restore-test-29750520` was the **last firing of the old 02:00 schedule**, one hour before the commit, and `restore-test-29750880` was the first firing of the new one. The move was to stop the sweep starving the 03:15–07:15 daily backup window of node-agent DataUpload concurrency. ### Why the failed Job disappeared — it was deleted deliberately, not by TTL - TTL is 14d (`ttlSecondsAfterFinished: 1209600`), so it would have expired 2026-08-09; the *successful* sibling job carries the same TTL and is still present. TTL is excluded. - The CronJob was never recreated (uid unchanged) → no cascade GC. Flux prune, PR #422 (`e16dfd86`, touches **only** `restore-test.sh`), and the script itself (it never touches Jobs) are all excluded. - **What actually happened:** #380's closing comment by @claude-bot at 2026-07-27 10:41 UTC reads *"Preserving the failing run's full log here before the Job object is deleted, since deleting it destroys the pod logs permanently."* This issue independently records the `kube_job_failed` series' last sample at **10:41:20Z** — the same minute. The deletion is what the alert itself instructs: the live `KubeJobFailed` annotation says *"Removing failed job after investigation should clear this alert."* ### What the 02:00 run actually failed on Recovered from Loki (90d retention) — the evidence was never lost: > `PASS: 39 / FAIL: 1` — `audiobookshelf: PVC audiobookshelf-metadata file count parity (±10%) -- source=2339 restored=803` A false positive: 1531 HLS transcode files were written into `metadata/streams/` after the backup. Already fixed by `volatile_paths_for()` in PR #418. ### The real defect this exposed The triage agents **could not reach Loki** — so they conclude "root cause unconfirmable" and then delete the evidence. #380 declared `restore-test-29740440` *"unrecoverable / probably unconfirmable"*; its full output was in Loki the whole time (`FAIL: 3` — `apps` restore phase plus `data-gitea-0` and `data-woodpecker-server-0` parity, with `restoreItemOperationsFailed: 1`). Fixed in **PR #429** (read-only Loki access for the `ci-diagnostics` SA + the query recipe added to both agent prompts). ### One genuine bug found along the way, being fixed separately The `e2e-*` backups that show up `PartiallyFailed` are **not** restore-test's — they come from `kubernetes/e2e-test.sh:199` (ns `velero-e2e`), run by the `.woodpecker/e2e.yml` cron pipelines, and they never enter restore-test's pass/fail evaluation (it selects only Backups labelled `velero.io/schedule-name`). But they are a real race: ``` 02:01:05 Backup + PVC created (DataUpload -> phase Prepared) ... data path never starts (node-agent slot held by the running sweep) ~02:06 the script's 60x5s = 300s wait expires -> check FAIL, but does not abort -> script deletes ns velero-e2e and creates the Restore 02:07:03 restore error "no DataUpload result cm found" -> restore PartiallyFailed 02:10:08 script deletes Backup+Restore -> "Cancel du under phase Prepared because it is being deleted" -> Backup lands PartiallyFailed ``` Both occurrences (02:00:55 and 12:04:05) fall inside a running restore-test sweep. `node-agent-config.yaml` sets no `loadConcurrency`, so Velero's default of one data path per node applies and a 1 GiB e2e DataUpload sits in `Prepared` well past 5 minutes. Net effect: a flaky e2e check plus phantom `PartiallyFailed` Backups that pollute backup-health triage. Fix going up separately.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
apollo
Hermes expert: Immich, Audiobookshelf, Libation, Navidrome, Music Assistant
 atlas
Hermes expert: Talos, Flux, network, Authentik, Matrix, monitoring
 clio
Hermes expert: Paperless, wiki, ical-proxy, TRMNL, websites
 daedalus
Hermes expert: Gitea, Woodpecker, Renovate, review-bot, Hermes
 hestia
Hermes expert: Home Assistant, IoT, MQTT, ESPHome, voice
No labels
Milestone
No items
No Milestone
Projects
Clear projects
No projects
Assignees
Clear assignees
alert-monitor-bot claude-bot (Claude Bot) flux hermes-bot issue-fix-bot k.renner renovate-bot review-bot (Review Bot) security-bot update-audit-bot
No Assignees
3 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: konairius/homelab#427