Ephemeral runners boot-loop to OpenStack ERROR → CI down, silent (no alert), burning volumes #133

Stängd
öppnade 2026-07-19 07:36:07 +00:00 av supernaut · 5 kommentarer
Ägare

Severity: HIGH (CI fully down) + silent + burning OpenStack resources. Found investigating a stuck Actions run (run 142 queued, never starts).

Symptom

Every queued Actions job (labels=ci) waits forever. Forgejo has runner registrations churning (RegisterRunner 201 → DeleteRunner 204 seconds later, orphaned).

Root cause

The runner-controller is healthy and NOT in dry-run — it boots ephemeral VMs correctly, but every ephemeral runner VM goes to OpenStack status=ERROR within seconds of boot and is reaped before it can register+run. Controller log pattern (live, container="runner-controller"):

reconcile: 0 active ephemeral VM(s) after reap
create: booting ephemeral VM 1/4 … booted volume-backed server ephemeral-runner-xxxx
reap: marking server ephemeral-runner-xxxx for deletion: status=ERROR
deleted orphaned runner registration id=NNNN

This repeats continuously — dozens of volume-backed VM boots per minute, all ERROR → real, ongoing Cinder/Nova churn (and likely orphaned boot volumes) with zero successful jobs.

The controller doesn't log the OpenStack fault, so the reason the VMs ERROR is not in Loki. Leading hypotheses (verify on host): Cinder volume quota / ceph-pool capacity exhausted (note the concurrent disk pressure — #126; and a boot-loop leaking ERROR'd volumes is self-reinforcing), OR Nova "No valid host"/capacity, OR a bad/missing gitborg-runner Glance image.

Why it's silent (monitoring gap)

gitborg_runner_controller_last_loop_ok = 1 and active_vms = 1–4 — the controller counts a boot+reap cycle as a successful loop, so no alert fires even though no runner ever becomes healthy. There is no alert on "VMs booted but 0 reached a healthy/registered state" or on a boot-error rate.

Diagnose (needs OpenStack API on the host)

openstack server list --all-projects | grep ephemeral-runner   # any stuck?
openstack server show <errored-id>                             # read the `fault` field ← the actual cause
openstack quota show                                            # volumes / gigabytes / instances vs used
openstack volume list | grep -c .                               # orphaned runner boot volumes piling up?

Remediate

  1. Immediate: stop the churn — systemctl --user stop gitborg-runner-controller.timer (as bitborg) so it stops booting failing VMs / leaking volumes while diagnosing.
  2. Fix the underlying OpenStack cause from server show … fault (raise quota / clean leaked volumes / repair image / capacity).
  3. Clean up any orphaned ephemeral-runner-* volumes left by ERROR'd boots.
  4. Monitoring: add an alert for runner boot-failure — e.g. VMs created but active_healthy == 0 over N minutes, or a boot-error-rate metric — so a 100%-ERROR loop pages instead of reading as "loop OK".
**Severity: HIGH (CI fully down) + silent + burning OpenStack resources.** Found investigating a stuck Actions run (run 142 queued, never starts). ## Symptom Every queued Actions job (`labels=ci`) waits forever. Forgejo has runner registrations churning (`RegisterRunner` 201 → `DeleteRunner` 204 seconds later, orphaned). ## Root cause The runner-controller is healthy and NOT in dry-run — it boots ephemeral VMs correctly, but **every ephemeral runner VM goes to OpenStack `status=ERROR` within seconds of boot** and is reaped before it can register+run. Controller log pattern (live, `container="runner-controller"`): ``` reconcile: 0 active ephemeral VM(s) after reap create: booting ephemeral VM 1/4 … booted volume-backed server ephemeral-runner-xxxx reap: marking server ephemeral-runner-xxxx for deletion: status=ERROR deleted orphaned runner registration id=NNNN ``` This repeats continuously — **dozens of volume-backed VM boots per minute, all ERROR** → real, ongoing Cinder/Nova churn (and likely orphaned boot volumes) with zero successful jobs. The controller doesn't log the OpenStack fault, so the *reason* the VMs ERROR is not in Loki. Leading hypotheses (verify on host): **Cinder volume quota / ceph-pool capacity exhausted** (note the concurrent disk pressure — #126; and a boot-loop leaking ERROR'd volumes is self-reinforcing), OR Nova "No valid host"/capacity, OR a bad/missing `gitborg-runner` Glance image. ## Why it's silent (monitoring gap) `gitborg_runner_controller_last_loop_ok = 1` and `active_vms` = 1–4 — the controller counts a boot+reap cycle as a *successful* loop, so no alert fires even though **no runner ever becomes healthy**. There is no alert on "VMs booted but 0 reached a healthy/registered state" or on a boot-error rate. ## Diagnose (needs OpenStack API on the host) ``` openstack server list --all-projects | grep ephemeral-runner # any stuck? openstack server show <errored-id> # read the `fault` field ← the actual cause openstack quota show # volumes / gigabytes / instances vs used openstack volume list | grep -c . # orphaned runner boot volumes piling up? ``` ## Remediate 1. **Immediate:** stop the churn — `systemctl --user stop gitborg-runner-controller.timer` (as bitborg) so it stops booting failing VMs / leaking volumes while diagnosing. 2. Fix the underlying OpenStack cause from `server show … fault` (raise quota / clean leaked volumes / repair image / capacity). 3. Clean up any orphaned `ephemeral-runner-*` volumes left by ERROR'd boots. 4. **Monitoring:** add an alert for runner boot-failure — e.g. VMs created but `active_healthy == 0` over N minutes, or a boot-error-rate metric — so a 100%-ERROR loop pages instead of reading as "loop OK".
Upphovsperson
Ägare

Root cause CONFIRMED (via read-only OpenStack API, --os-cloud bahnhof)

Cinder volume quota is exhausted:

  • max_total_volume_gigabytes = 5000, total_gigabytes_used = 4990 → 10 GiB free.
  • 232 volumes: 4 in-use (the real persistent ones — root 20 / data 60 / backup 100 / monitoring-root 30), 228 "available" (detached/orphaned).
  • Orphans = 227 unnamed, detached, 20 GiB volumes (≈4540 GiB) + 1 leftover named gitborg-prod-root 40 GiB (from the 2026-07-09 root downsize).

With <10 GiB free, no new runner boot volume can be created → every ephemeral runner boots to status=ERROR → CI down.

Why the volumes leak (controller.py): boot uses boot_from_volume + terminate_volume=True (L516-526), and reap enumerates server.volumes to delete them (L339-356). But a server that dies in ERROR during boot has a boot volume that was created-from-image but never fully attached, so it's absent from server.volumes and terminate_volume's delete-on-terminate never fires → the volume is orphaned as detached/"available". Self-reinforcing: each ERROR boot that got as far as creating its volume leaked one, until the quota filled.

Remediation

  1. Immediate (manual, restores CI): delete the 227 unnamed/detached/20 GiB orphan volumes to reclaim ~4540 GiB (runbook handed to operator). Safe: --status available filter cannot touch the 4 in-use persistent volumes.
  2. Permanent (controller.py fix): (a) name/tag each runner boot volume at create so orphans are deterministically identifiable (they're currently unnamed); (b) on reap AND on a periodic sweep, delete detached volumes matching that tag whose server is gone/ERROR — don't rely solely on server.volumes (empty for ERROR-boot servers); (c) explicitly delete the created volume when create_server raises/ERRORs.
  3. Monitoring: alert when volume-quota usage > ~80% and when ephemeral runners are created but none reach a healthy/registered state within N min (the loop currently reads as last_loop_ok=1).
## Root cause CONFIRMED (via read-only OpenStack API, `--os-cloud bahnhof`) **Cinder volume quota is exhausted:** - `max_total_volume_gigabytes = 5000`, `total_gigabytes_used = 4990` → **10 GiB free**. - **232 volumes: 4 in-use (the real persistent ones — root 20 / data 60 / backup 100 / monitoring-root 30), 228 "available" (detached/orphaned).** - Orphans = **227 unnamed, detached, 20 GiB volumes (≈4540 GiB)** + 1 leftover named `gitborg-prod-root` 40 GiB (from the 2026-07-09 root downsize). With <10 GiB free, no new runner boot volume can be created → every ephemeral runner boots to `status=ERROR` → CI down. **Why the volumes leak (controller.py):** boot uses `boot_from_volume + terminate_volume=True` (L516-526), and reap enumerates `server.volumes` to delete them (L339-356). But a server that dies in **ERROR during boot** has a boot volume that was created-from-image but **never fully attached**, so it's absent from `server.volumes` and `terminate_volume`'s delete-on-terminate never fires → the volume is orphaned as detached/"available". Self-reinforcing: each ERROR boot that got as far as creating its volume leaked one, until the quota filled. ## Remediation 1. **Immediate (manual, restores CI):** delete the 227 unnamed/detached/20 GiB orphan volumes to reclaim ~4540 GiB (runbook handed to operator). Safe: `--status available` filter cannot touch the 4 in-use persistent volumes. 2. **Permanent (controller.py fix):** (a) **name/tag** each runner boot volume at create so orphans are deterministically identifiable (they're currently unnamed); (b) on reap AND on a periodic sweep, delete detached volumes matching that tag whose server is gone/ERROR — don't rely solely on `server.volumes` (empty for ERROR-boot servers); (c) explicitly delete the created volume when `create_server` raises/ERRORs. 3. **Monitoring:** alert when volume-quota usage > ~80% and when ephemeral runners are created but none reach a healthy/registered state within N min (the loop currently reads as `last_loop_ok=1`).
Upphovsperson
Ägare

Permanent fix drafted — PR #134 (not applied; needs the controller image rebuild + site.yml apply).

  • _sweep_orphan_volumes() deletes detached/unnamed/aged-out boot-volume leaks each cycle (three guards → cannot touch a live disk); handles the ERROR-boot orphan the server-reap misses.
  • New metrics boot_error_vms / orphan_volumes_swept / Cinder os_volume_gb_used+_quota.
  • Alerts RunnerBootFailing (boot_error_vms>0 15m) + RunnerVolumeQuotaHigh (>80%) — so a 100%-ERROR loop pages instead of reading as last_loop_ok=1.

py_compile + alert-template YAML render + ansible-lint (production) all clean. PR #134 does not delete the existing 227 legacy orphans (unnamed, pre-date the tag/heuristic) — the manual runbook still needs running to reclaim the ~4540 GiB now; the sweep prevents recurrence going forward.

Checklist:

  • Manual cleanup of the 227 legacy orphan volumes (runbook) — reclaims quota, restores CI now.
  • Merge #134 → rebuild runner-controller image → site.yml apply (prevents recurrence + adds alerts).
  • Confirm a runner boots ACTIVE and Run 142 completes.
**Permanent fix drafted — PR #134** (not applied; needs the controller image rebuild + `site.yml` apply). - `_sweep_orphan_volumes()` deletes detached/unnamed/aged-out boot-volume leaks each cycle (three guards → cannot touch a live disk); handles the ERROR-boot orphan the server-reap misses. - New metrics `boot_error_vms` / `orphan_volumes_swept` / Cinder `os_volume_gb_used`+`_quota`. - Alerts **RunnerBootFailing** (boot_error_vms>0 15m) + **RunnerVolumeQuotaHigh** (>80%) — so a 100%-ERROR loop pages instead of reading as `last_loop_ok=1`. py_compile + alert-template YAML render + `ansible-lint` (production) all clean. PR #134 does **not** delete the existing 227 legacy orphans (unnamed, pre-date the tag/heuristic) — the manual runbook still needs running to reclaim the ~4540 GiB now; the sweep prevents recurrence going forward. **Checklist:** - [x] Manual cleanup of the 227 legacy orphan volumes (runbook) — reclaims quota, restores CI **now**. - [x] Merge #134 → rebuild runner-controller image → `site.yml` apply (prevents recurrence + adds alerts). - [x] Confirm a runner boots ACTIVE and Run 142 completes.
Upphovsperson
Ägare

Post-apply verification of #134 — found + fixed a defect (PR #135).

After site.yml, the new controller image is live and healthy: metrics present (boot_error_vms=0, os_volume_gb_used=630, os_volume_gb_quota=5000, last_loop_ok=1), CI recovered (web Run 142 → success), quota reclaimed to 630/5000 GiB.

BUT orphan_volumes_swept stayed 0 with 11 orphans present. Root cause: OpenStack created_at is timezone-naive (2026-07-19T08:07:59.000000); _iso_age_seconds raised on the naive-vs-aware subtraction and the except returned 0.0, so every volume read as 0s old → the sweep (and the reap_max_age server backstop) never fired. PR #135 stamps a missing tz as UTC. Verified against the real format (0s → 1917s).

Remaining: merge #135 → rebuild image → site.yml apply. Then the sweep clears the 11 leftover orphans once they cross the 1h age threshold. (Harmless meanwhile — 630/5000 GiB used.)

**Post-apply verification of #134 — found + fixed a defect (PR #135).** After `site.yml`, the new controller image is live and healthy: metrics present (`boot_error_vms=0`, `os_volume_gb_used=630`, `os_volume_gb_quota=5000`, `last_loop_ok=1`), CI recovered (web Run 142 → **success**), quota reclaimed to 630/5000 GiB. BUT `orphan_volumes_swept` stayed 0 with 11 orphans present. Root cause: OpenStack `created_at` is timezone-**naive** (`2026-07-19T08:07:59.000000`); `_iso_age_seconds` raised on the naive-vs-aware subtraction and the `except` returned `0.0`, so every volume read as 0s old → the sweep (and the `reap_max_age` server backstop) never fired. **PR #135** stamps a missing tz as UTC. Verified against the real format (0s → 1917s). **Remaining:** merge #135 → rebuild image → `site.yml` apply. Then the sweep clears the 11 leftover orphans once they cross the 1h age threshold. (Harmless meanwhile — 630/5000 GiB used.)
Upphovsperson
Ägare

Validation after #135 apply — sweep confirmed working in prod ✅

  • The tz fix (#135) is live and the sweep is deleting real orphans: available detached volumes 12 → 5, Cinder quota 650 → 530 GiB used, as the genuine unnamed 20 GiB runner-leak volumes age past the 1h threshold.
  • Metrics healthy: boot_error_vms=0, last_loop_ok=1, quota gauges accurate; CI green (Run 142 success).

One edge case found + fixed → PR #136

The sweep was hitting a 400 every 10s on two unnamed detached volumes: Cinder refuses to delete a volume that must not have snapshots or belong to a group. Those two aren't leaks — they carry the gitborg-runner image source snapshot and the predrill-* 2026-07-09 safety snapshots (image/backup infra). The blank-name heuristic was too broad. PR #136 makes the sweep skip any volume with snapshots and skip-list any delete that's refused (no per-cycle retry/spam). Unit-tested with a stub connection.

⚠️ Do NOT manually delete those two volumes or their snapshot for gitborg-runner snapshots — they back the runner image. (The predrill-* 2026-07-09 snapshots are stale and optionally reclaimable, your call.)

Status

  • Manual cleanup of the legacy orphan glut (quota reclaimed).
  • #134 (sweep + alerts) applied.
  • #135 (naive-tz age fix) applied — sweep confirmed deleting real orphans.
  • Merge + apply #136 (skip snapshot-backed volumes; stop the 10s 400 spam). Last step, then this closes.
## Validation after #135 apply — sweep confirmed working in prod ✅ - The tz fix (#135) is live and the sweep is **deleting real orphans**: available detached volumes **12 → 5**, Cinder quota **650 → 530 GiB used**, as the genuine unnamed 20 GiB runner-leak volumes age past the 1h threshold. - Metrics healthy: `boot_error_vms=0`, `last_loop_ok=1`, quota gauges accurate; CI green (Run 142 success). ## One edge case found + fixed → PR #136 The sweep was hitting a **400 every 10s** on two unnamed detached volumes: Cinder refuses to delete a volume that `must not have snapshots or belong to a group`. Those two aren't leaks — they carry the **`gitborg-runner` image source snapshot** and the **`predrill-*` 2026-07-09 safety snapshots** (image/backup infra). The blank-name heuristic was too broad. **PR #136** makes the sweep skip any volume with snapshots and skip-list any delete that's refused (no per-cycle retry/spam). Unit-tested with a stub connection. **⚠️ Do NOT manually delete those two volumes or their `snapshot for gitborg-runner` snapshots — they back the runner image.** (The `predrill-*` 2026-07-09 snapshots are stale and optionally reclaimable, your call.) ### Status - [x] Manual cleanup of the legacy orphan glut (quota reclaimed). - [x] #134 (sweep + alerts) applied. - [x] #135 (naive-tz age fix) applied — sweep confirmed deleting real orphans. - [x] Merge + apply **#136** (skip snapshot-backed volumes; stop the 10s 400 spam). Last step, then this closes.
Upphovsperson
Ägare

Resolved + deployed + verified — closing.

The full remediation chain is merged and applied to prod (site.yml, health-gate green):

  • #134 — orphan-volume sweep + RunnerBootFailing/RunnerVolumeQuotaHigh alerts (applied earlier).
  • #135 — naive-timestamp age fix so the sweep actually fires (applied earlier).
  • #136 — sweep skips snapshot-backed volumes + skip-lists refused deletes (applied 2026-07-19, controller image 939026a2).

Verified live after the apply (controller logs):

  • sweep: skipping volume …e610f170 / …40781d11 — it has snapshot(s), image/backup infra → the two gitborg-runner/pre-drill volumes are skip-listed; the every-10s 400 spam stopped.
  • sweep: deleted orphan boot volume …0bf861f4 (20 GiB, age=3604s) → real leaks are cleaned as they age past 1h.
  • boot_error_vms=0, last_loop_ok=1; detached volumes down 228 → 3 (the 2 infra + 1 recent), Cinder quota 4990 → 470 GiB.

Original incident (ephemeral runners boot-looping to ERROR → CI down from Cinder-quota exhaustion) is fully resolved, recurrence is prevented, and it's now alertable instead of silent.

## Resolved + deployed + verified — closing. The full remediation chain is merged **and applied to prod** (`site.yml`, health-gate green): - **#134** — orphan-volume sweep + `RunnerBootFailing`/`RunnerVolumeQuotaHigh` alerts (applied earlier). - **#135** — naive-timestamp age fix so the sweep actually fires (applied earlier). - **#136** — sweep skips snapshot-backed volumes + skip-lists refused deletes (applied 2026-07-19, controller image `939026a2`). **Verified live after the apply (controller logs):** - `sweep: skipping volume …e610f170 / …40781d11 — it has snapshot(s), image/backup infra` → the two `gitborg-runner`/pre-drill volumes are skip-listed; the every-10s 400 spam **stopped**. - `sweep: deleted orphan boot volume …0bf861f4 (20 GiB, age=3604s)` → real leaks are cleaned as they age past 1h. - `boot_error_vms=0`, `last_loop_ok=1`; detached volumes down 228 → 3 (the 2 infra + 1 recent), Cinder quota 4990 → 470 GiB. Original incident (ephemeral runners boot-looping to ERROR → CI down from Cinder-quota exhaustion) is fully resolved, recurrence is prevented, and it's now alertable instead of silent.
Logga in för att delta i denna konversation.
Ingen milstolpe
Inga tilldelade
1 deltagare
Notiser
Förfallodatum
Förfallodatumet är ogiltigt eller utanför gränserna. Använd formatet "åååå-mm-dd".

Inget förfallodatum satt.

Beroenden

Inga beroenden satta

Referens
bitborg/bitborg-infra#133
Ingen beskrivning angiven.