Add CHALLENGES.md: retrospective on building this runner setup
This commit is contained in:
parent
93516327e9
commit
ec0c63d74d
1 changed files with 274 additions and 0 deletions
274
CHALLENGES.md
Normal file
274
CHALLENGES.md
Normal file
|
|
@ -0,0 +1,274 @@
|
|||
# Challenges building the Hetzner CI runner setup
|
||||
|
||||
A retrospective on what actually went wrong while moving chromium-fork's
|
||||
build off a resource-starved local runner onto ephemeral Hetzner Cloud
|
||||
boxes. Written for whoever touches this next — most of these took real
|
||||
debugging time to nail down, and the fixes are non-obvious enough to
|
||||
regress if the reasoning behind them gets lost.
|
||||
|
||||
## Provisioning
|
||||
|
||||
**Dedicated vCPU blocked by an account limit.** The original plan was a
|
||||
`ccx43` (dedicated vCPU, 64GB RAM). Hetzner rejected it with
|
||||
`resource_limit_exceeded` — new/unverified projects start with a
|
||||
dedicated-vCPU limit of 0 as an anti-fraud measure (dedicated vCPU and
|
||||
GPU servers are common targets for crypto-mining fraud via stolen
|
||||
payment methods), lifted only via a support ticket. Fell back to `cpx51`
|
||||
(shared vCPU, 32GB RAM, 360GB disk) instead, which was available
|
||||
immediately.
|
||||
|
||||
**SSH key mismatch on the very first manual test.** Initially attached a
|
||||
pre-registered Hetzner SSH key ("Philip Macbook Pro M2") to a
|
||||
hand-created server — `Permission denied (publickey,password)`. The
|
||||
private half of that key lived on a *different* machine than the one
|
||||
running the commands. Fixed at the design level, not just for this one
|
||||
key: every server now gets a fresh ephemeral ed25519 keypair generated
|
||||
per run and uploaded to Hetzner as part of `up`, with no dependency on
|
||||
any pre-existing registered key.
|
||||
|
||||
## depot_tools as root
|
||||
|
||||
**`python3_bin_reldir.txt` missing, breaking `install-build-deps.py`.**
|
||||
depot_tools' `python3` wrapper hard-requires a bootstrap file that's
|
||||
normally created by `update_depot_tools` — which has an explicit guard:
|
||||
|
||||
```
|
||||
if [ "$USER" == "root" ]; then
|
||||
echo Running depot tools as root is sad.
|
||||
exit
|
||||
fi
|
||||
```
|
||||
|
||||
Silently no-ops as root, which this box always is. `gclient sync` still
|
||||
worked because it goes through `vpython3` (bootstrapped separately), but
|
||||
any later direct `python3` invocation — like `install-build-deps.py`'s
|
||||
shebang — failed with `python3_bin_reldir.txt not found`.
|
||||
|
||||
Fix: call the two functions `update_depot_tools` invokes *after* its
|
||||
root check (`cipd_bin_setup`, `bootstrap_python3`) directly, sidestepping
|
||||
the check entirely. Needed `set +u` around that block too — those are
|
||||
third-party scripts not written to be safe under `nounset`, and `cipd`
|
||||
itself references an unset variable with no default.
|
||||
|
||||
**Missing `file` package.** `install-build-deps.py`'s `dev_list()` shells
|
||||
out to `file -L <path>` to detect ELF architecture. Not installed by
|
||||
default on the minimal Ubuntu cloud image. Small fix, but it took a full
|
||||
run reaching that exact line to surface.
|
||||
|
||||
## The SSH/PTY rabbit hole
|
||||
|
||||
This was the single biggest time sink, in three layers, each one looking
|
||||
like the full fix until the next real run disproved it.
|
||||
|
||||
**Layer 1 — PTY stdin doesn't deliver EOF reliably.** The original
|
||||
`sshExecScript` piped a script to `bash -s` via `session.Run()` with
|
||||
`Stdin` set to a `strings.Reader`, over a PTY (needed so the remote side
|
||||
line-buffers instead of block-buffering — see "buffering" below). It
|
||||
hung indefinitely — but only after the script's real work had already
|
||||
finished. The script would run to completion, print its own final
|
||||
output, and then the local process would just sit there for 10+ minutes
|
||||
until manually killed.
|
||||
|
||||
Root cause: SSH channel EOF just means "not sending more data on this
|
||||
channel right now" — for a plain exec channel that maps onto closing the
|
||||
child's stdin pipe (a pipe cleanly returns EOF from `read()` once closed,
|
||||
unconditionally). For a PTY-backed session, the server is managing an
|
||||
*interactive terminal*, where a pause in input isn't supposed to mean
|
||||
"hang up" — so it doesn't reliably translate into an EOF condition the
|
||||
remote shell's `read()` ever sees. Confirmed as a known class of issue,
|
||||
not specific to this codebase: [golang/go#6088](https://github.com/golang/go/issues/6088)
|
||||
(identical `x/crypto/ssh` symptom) and
|
||||
[net-ssh/net-ssh#460](https://github.com/net-ssh/net-ssh/issues/460)
|
||||
(different language entirely, same symptom, and explicitly confirms
|
||||
removing `request_pty` fixes it).
|
||||
|
||||
First fix attempt: switch to `Start()` + `StdinPipe()` + explicit
|
||||
`Close()`, and append `exit $?` to the script so bash terminates itself
|
||||
instead of depending on EOF at all. This fixed short scripts in testing.
|
||||
|
||||
**Layer 2 — a real script still hung, differently.** Against a real
|
||||
`sync.sh` (7.4KB), the process hung again — but this time a live
|
||||
inspection (once the runner moved to mainframe, making its ephemeral SSH
|
||||
key locally reachable) showed `bash` blocked in `do_select()` on its
|
||||
stdin fd, with `/root/depot_tools` not even cloned yet — despite later
|
||||
script output (an `apt-get install`) having already reached the log.
|
||||
The script was being *truncated* mid-delivery, not just missing its
|
||||
termination signal. Consistent with a PTY's small, fixed-size
|
||||
canonical-mode input queue (historically 4KB on Linux) silently dropping
|
||||
the tail of a multi-KB single `Write()` call when it arrives faster than
|
||||
bash drains it. `exit $?` didn't help because it was itself part of what
|
||||
got dropped.
|
||||
|
||||
Real fix: stop sending script content through a PTY's stdin at all.
|
||||
Upload the script as a file first (over a plain, non-PTY session — a
|
||||
pipe has no such queue-size limit), then execute it as a file with no
|
||||
stdin of its own. No script content ever touches a PTY; the PTY is still
|
||||
used for the *execution* (live output streaming), but that session has
|
||||
nothing written to its stdin, so there's no EOF ambiguity left to have.
|
||||
|
||||
**Layer 3 — the fix for layer 2 had the same bug as layer 1.** Building
|
||||
the upload mechanism (`uploadFile`, piping a file's bytes to `cat >
|
||||
path`), the very first real test of it hung — because `sshSession` was
|
||||
requesting a PTY *unconditionally*, and `uploadFile` inherited it for a
|
||||
plain `cat`. Fixed by making PTY allocation opt-in per session: on for
|
||||
anything running a real command whose output should stream live, off for
|
||||
raw file transfer. (A PTY's canonical-mode line discipline is actively
|
||||
wrong for binary-safe transfer anyway, independent of the hang — it can
|
||||
reinterpret control bytes like Ctrl-D/Ctrl-C that happen to appear in
|
||||
otherwise-arbitrary content.)
|
||||
|
||||
**Buffering, separately.** Even once EOF/truncation were fixed, build
|
||||
output over a plain (non-PTY) pipe arrives block-buffered on the remote
|
||||
side instead of line-buffered — a multi-hour build's output would show
|
||||
up in laggy multi-KB chunks instead of streaming as it happens. That's
|
||||
the reason a PTY is used for command *execution* at all, despite all of
|
||||
the above: it makes `ninja`/`gclient`/`python` think they're talking to
|
||||
a real terminal, so they line-buffer.
|
||||
|
||||
## Cleanup correctness
|
||||
|
||||
**`down()` deleted the local key even when the remote delete failed.**
|
||||
If the Hetzner API call to delete the server errored for any reason, the
|
||||
code still unconditionally removed the local ephemeral private key —
|
||||
meaning a failed teardown could both leave the server running *and*
|
||||
destroy the one thing that could get back into it to inspect or manually
|
||||
clean up. Found by hitting exactly this: a server still alive, its key
|
||||
already gone, no way back in except the Hetzner web console (which
|
||||
turned out to be VNC-over-websocket, not worth building a client for on
|
||||
the spot) or an account-level password reset (which doesn't apply to the
|
||||
already-running OS instance without a reboot, which would have destroyed
|
||||
the exact state being investigated). Fixed: only remove the local key
|
||||
once the server delete is confirmed to have succeeded.
|
||||
|
||||
**Ordinary step failure vs. Go-level error, cleanup-wise.** `exec` (used
|
||||
for each CI phase against an already-provisioned box) deliberately
|
||||
doesn't tear down on an ordinary nonzero remote exit code — that's left
|
||||
for the workflow's own separate, later `down` step, so one failing build
|
||||
phase doesn't nuke a box other phases might still want to inspect.
|
||||
But a genuine Go-level error partway through (upload failure, SSH
|
||||
connection failure, a panic) previously fell through to nothing until
|
||||
that separate step ran. Added a `defer`-based cleanup specifically for
|
||||
that case, careful to distinguish it from a normal nonzero exit code —
|
||||
verified both paths against a real box (`exit 3` from the remote command
|
||||
leaves the server alive and propagates the code; an upload failure
|
||||
against a nonexistent local file tears the server down immediately).
|
||||
|
||||
## The runner host itself
|
||||
|
||||
**Migrated off a non-cloud machine.** The `self-hosted-ubuntu` label
|
||||
(used by chromium-fork's CI *and* all six `mirror-sync/sync-*.yml` jobs)
|
||||
was originally served by some separate, apparently non-cloud machine —
|
||||
inferred from a `/Volumes/ExtremeSSD/...` workdir path in chromium-fork's
|
||||
CI history, a macOS volume mount. It restarted mid-job at least once,
|
||||
silently killing an in-flight run and orphaning a Hetzner box with no
|
||||
graceful cleanup at all (the runner process just vanished). Fixed by
|
||||
adding a new, dedicated `services.gitea-actions-runner` instance on
|
||||
`mainframe` itself (the same box already running Forgejo, already using
|
||||
Podman for other services) — reliable, cloud-hosted, and kept as its own
|
||||
instance rather than merged into the existing `ubuntu` one so it never
|
||||
contends with unrelated repos' CI for runner capacity.
|
||||
|
||||
**Registration token scope.** Needed an org-scoped (Cold-Air-Networks)
|
||||
runner registration token, not an instance-wide admin one — Forgejo's
|
||||
API exposes this via `GET` (not `POST`, despite it being a
|
||||
token-*creation* action) on
|
||||
`/orgs/{org}/actions/runners/registration-token`.
|
||||
|
||||
**agenix wiring has two separate places to update, not one.**
|
||||
`secrets/default.nix` only configures *encryption recipients* for the
|
||||
`agenix` CLI tool — it does **not** by itself expose a decrypted secret's
|
||||
path to the rest of the NixOS config. That requires a second, separate
|
||||
`age.secrets.<name> = { file = ...; owner = ...; }` declaration
|
||||
elsewhere (this repo's convention: in `linux.nix`, in the same block as
|
||||
the other secrets). Missing this second declaration means
|
||||
`config.age.secrets.<name>.path` simply doesn't exist as an option —
|
||||
easy to miss since the `.age` file itself decrypts and evaluates fine
|
||||
either way.
|
||||
|
||||
**New files need `git add` before Nix will see them, even with a dirty
|
||||
tree.** `nix eval`/`nix build` against a local flake includes
|
||||
*modifications* to already-tracked files in a dirty working tree, but
|
||||
silently ignores brand-new, not-yet-staged files entirely — surfaced as
|
||||
a confusing "Path ... is not tracked by Git" error deep in an unrelated
|
||||
evaluation trace (agenix trying to read a secret file that, from Nix's
|
||||
perspective, didn't exist yet).
|
||||
|
||||
**Stale macOS Keychain git credentials.** `git push` to
|
||||
`forge.quinefoundation.com` intermittently failed with a plain `403`
|
||||
using the credential the `osxkeychain` helper had cached, for reasons
|
||||
never fully root-caused (likely a rotated/stale stored credential).
|
||||
Explicit `https://user:pass@host/...` credentials in the push URL worked
|
||||
every time; the keychain-stored path was eventually abandoned entirely
|
||||
for this remote.
|
||||
|
||||
## The three-hour mystery
|
||||
|
||||
Two CI runs (#62, #64) died with *zero* trace: no error in the job log,
|
||||
no OOM in `dmesg`/kernel journal, nothing in the runner service's own
|
||||
systemd journal (which, at `info` level, only ever logs one line per
|
||||
*task* — dispatch — never per-step detail). Run #62 left Gitea/Forgejo
|
||||
showing "running" forever after the process and its box had already
|
||||
vanished; run #64 got marked "failure" within seconds of the log's last
|
||||
line, mid-compile, with healthy throughput right up to the cutoff.
|
||||
|
||||
First hypothesis, based on the symptom shape alone: a known upstream
|
||||
act_runner/Gitea desync bug
|
||||
([go-gitea/gitea#35645](https://github.com/go-gitea/gitea/issues/35645),
|
||||
[#35956](https://github.com/go-gitea/gitea/issues/35956)) — the runner
|
||||
and server losing sync on task state. Plausible, but unverifiable from
|
||||
outside without better visibility, so two diagnostic tools went in
|
||||
*before* trying to fix anything further:
|
||||
|
||||
- **`act_runner` debug logging** (`settings.log.level = "debug"` in the
|
||||
NixOS module) — `info` level was structurally incapable of ever
|
||||
explaining this, since it doesn't log per-step detail at all.
|
||||
- **An independent local log for `hetzner-runner` itself**
|
||||
(`~/hetzner-runner-debug.log` on the runner host, written on every
|
||||
lifecycle event) plus a 30-second heartbeat during any in-flight remote
|
||||
command — decoupled entirely from Gitea's own log capture, which had
|
||||
by then been directly observed lagging real execution state on two
|
||||
separate occasions.
|
||||
|
||||
That paid off immediately on the very next real run (#65). The local
|
||||
heartbeat log showed the process alive and healthy right up to a precise
|
||||
timestamp, then nothing — no error, no signal-caught line, just stops.
|
||||
Debug-level journal for that exact window had the real answer directly
|
||||
from act_runner itself:
|
||||
|
||||
```
|
||||
❌ Failure - Main Build chrome/browser (~5-20min)
|
||||
this step has been cancelled: signal: killed
|
||||
```
|
||||
|
||||
Not a desync bug at all. Run #65's total elapsed time from `up` to kill:
|
||||
**2h59m58s** — matching `act_runner`'s default `runner.timeout: 3h` to
|
||||
the second. A cold build (fresh box every run, no cache) genuinely takes
|
||||
longer than the default job timeout; nothing was actually wrong.
|
||||
|
||||
Fixed by doubling *both* independently-configured 3h defaults to 6h —
|
||||
`act_runner`'s own `runner.timeout`, and Forgejo's `ENDLESS_TASK_TIMEOUT`
|
||||
(`app.ini`, `[actions]` section — not managed by the NixOS flake, lives
|
||||
directly on the data volume). The runner's own generated config
|
||||
explicitly warns that either one firing independently has the same
|
||||
effect, so both had to move together.
|
||||
|
||||
**A second-order finding from the same investigation:** a
|
||||
timeout-triggered cancellation aborts the whole job immediately rather
|
||||
than continuing on to later steps — meaning the dedicated `if: always()`
|
||||
teardown step never got a chance to run, and the orphaned box from run
|
||||
#65 sat alive for 6 hours before being noticed and manually deleted. The
|
||||
cloud-init self-destruct failsafe (`max-lifetime`) would have caught it
|
||||
eventually, but at its then-default 8h it left only 2 hours of margin
|
||||
over the newly-doubled 6h job timeout — uncomfortably tight given
|
||||
provisioning/retry overhead on top. Widened to 10h.
|
||||
|
||||
## Running theme
|
||||
|
||||
Almost every one of these was invisible until proven otherwise by
|
||||
running the *actual* thing against a *real* box, for a *realistic*
|
||||
duration, with *real* output volume — short synthetic tests
|
||||
("does `run -- echo hi` work?") passed cleanly at every layer of the
|
||||
PTY bug and would never have caught it. Cost real time and real Hetzner
|
||||
spend to work through, and every orphaned server or key found mid-way
|
||||
got cleaned up as its own explicit step, not deferred to "later" — worth
|
||||
preserving as a habit for whatever gets built on top of this next.
|
||||
Loading…
Reference in a new issue