bugs: close 003 (fixed in 0.2.6) — archive
Author:
Chris Tusa <chris.tusa@leafscale.com>
Date:
Jul 21, 2026 14:18
Changeset:
cfb4a678d291963c74e995c98e56cd457ce5e126
Branch:
default
Changed files:
D
bugs/003-supervisor-exec-race-first-boot-exit-minus-1.md
Diff
diff -r 593a8091c02b -r cfb4a678d291 bugs/003-supervisor-exec-race-first-boot-exit-minus-1.md --- a/bugs/003-supervisor-exec-race-first-boot-exit-minus-1.md Tue Jul 21 13:33:36 2026 -0500 +++ /dev/null Thu Jan 01 00:00:00 1970 +0000 @@ -1,120 +0,0 @@ -# Bug 003: supervisor exec of service start-commands races first-boot I/O pressure, yielding spurious exit=-1 - -## Summary - -On the **first boot of a freshly-deployed system**, services intermittently -report `exit=-1` in the boot report even though their start command is present, -executable, and succeeds on a manual retry moments later. `exit=-1` here means -the supervisor could not *exec* the start command at all (the process never -ran), as distinct from the command running and exiting non-zero. - -The trigger is contention during a reconfigure first boot: `devfsadm` is -enumerating/rebuilding the device tree, the ZFS root pool is finalizing, the -`/reconfigure` flag is being processed, and many services are starting in -parallel. Under that I/O pressure a `stat()`/exec of the start command (or its -`#!` interpreter) can transiently fail, and the supervisor records the service -as failed with `exit=-1`. - -Concrete evidence (Hammerhead, hh-alpha9, fresh `hh-deploy create` first boots): - -- `acpihpd-check` is a `type="oneshot"` whose `start.sh` **always exits 0** - (both branches: controller present → `exit 0`; absent → disable acpihpd + - `exit 0`). Yet on some first boots it shows `exit=-1` and produces **no** - log output at all — i.e. `start.sh` never executed. A `zygctl restart - acpihpd-check` seconds later runs it cleanly (`exit=0`, log line written). -- Because `acpihpd-check`'s job is to disable the `acpihpd` daemon on platforms - without an ACPI hotplug controller, when the check loses the exec race it - never disables `acpihpd`, so `acpihpd` *also* starts and fails `exit=-1`. - Result: **two** failed services in the boot report instead of zero, even - though the intended end state (acpihpd off, correct for i440fx/KVM) is - reached once things settle. -- The same first-boot `exit=-1` pattern has been observed on other services - (e.g. `sysconfig`) during boot probes — it is **not acpihpd-specific**; it is - a general supervisor exec-robustness issue that only manifests under - first-boot I/O contention. - -Note: Hammerhead already mitigates a related symptom by requiring absolute -paths for every external command in service scripts (avoids `PATH`-lookup -misses), but that does not cover this case — here the exec of the start -command / interpreter itself transiently fails despite an absolute, valid path. - -## Severity - -**Low (cosmetic), but design-defeating.** The eventual end state is correct -and the failure is transient/non-reproducible at steady state, so nothing is -actually broken. However: - -- It produces **false-positive "failed" services** in the first-boot report, - which is alarming and erodes trust in the report. -- It **defeats the `acpihpd-check` oneshot design**: that split (a precheck - oneshot that disables the daemon so the daemon stays a pure `type="daemon"` - and never false-positives) was created specifically to avoid `acpihpd`'s - `exit=-1`, but it only works when the check *wins* the exec race. When the - check loses, you get exit=-1 on both. - -## Affected Version - -zyginit 0.2.5 (and earlier — this is longstanding supervisor behavior, not new -to the 0.7.6 migration). Reproduces only on first-boot-of-fresh-deploy under -I/O pressure; does not reproduce at steady state or on subsequent boots. - -## Suggested Fix (for the zyginit team) - -The supervisor should distinguish "**exec failed to start the process**" from -"process ran and exited with a code," and treat the former as retryable: - -1. On a transient exec failure (`ENOENT`/`EACCES`/`EAGAIN`/`ETXTBSY` from the - spawn), **retry the exec** a few times with a short backoff before recording - failure. A start command that is genuinely missing will still fail after the - retries; a transient stat/exec miss will succeed on retry. -2. Alternatively / additionally, **throttle or serialize oneshot exec during a - reconfigure boot** (while `/reconfigure` is being processed) so the exec - path isn't competing with devfsadm + pool-finalize I/O. -3. Consider surfacing exec-failure distinctly from process-exit in the boot - report (e.g. `spawn-failed` vs `exit=N`) so a transient spawn miss is not - reported identically to a real non-zero exit. - -## Reported by - -Hammerhead team (Chris Tusa), 2026-07-21. Observed across multiple fresh -`hh-deploy create` first boots on the hh-alpha VMs (pc-i440fx + OVMF, no ACPI -hotplug controller). Cross-ref Hammerhead memory `zyginit-service-empty-path` -(the 2026-06-08 boot probe that first characterized the transient stat() miss). - -## Resolution (2026-07-20, zyginit 0.2.6-dev) - -Investigation found `exit=-1` was **not** an exec-failure code (a real exec -failure exits **127**); it is the "could not resolve an exit code" sentinel. -Two distinct defects were fixed in `src/supervisor.reef`: - -- **Defect A — exec robustness + no silent failure.** The service child now - retries `process_exec` a bounded number of times (`EXEC_MAX_ATTEMPTS` = 5, - `EXEC_RETRY_DELAY_MS` = 100ms) to ride out the transient first-boot - stat()/exec miss. When every attempt fails, the child records the failure to - **both** its per-service `<name>.log` (via fd 2, which survives a privilege - drop) **and** the new central `zyginit.log`, then exits 127. This removes the - "failed with an empty log" symptom. Errno is not exposed by the Reef stdlib - `process_exec`, so the retry is a blind bounded retry rather than - errno-selective — a genuinely-missing command still fails all attempts. - -- **Defect B — reap-race reconciliation (the actual source of `-1`).** In the - poll loop the contract-empty event (bundle fd) can beat the child's - exit-status posting. `handle_contract_event` used to commit the `-1` sentinel - and tear down tracking, after which the catch-all reaper discarded the real - code. It now **defers** when there is no hint, no resolvable code yet, and a - child is still tracked (`rt.pid > 0`), leaving `rt.pid` + the contract map - intact so the unconditional `reap_children` re-dispatches with the true code - within ~1s. This fixes both the 127→-1 masking **and** the independent - false-positive where an exit-0 oneshot that lost the race was reported FAILED. - -New central operational log: `/var/log/zyginit/zyginit.log` (`sup_log`), -distinct from the per-service logs. No new report state/label was added -(intentionally — the exit code plumbing now carries the truth). - -Verified on Linux (non-contract path) by integration suite -(`tests/integration/run_tests.sh`, Suite 9b "Spawn-failure capture (bug 003)", -97/97 passing): a service pointing at a missing binary now populates both logs -and is reported `failed` (never `exit=-1`). **Defect B rides the Hammerhead -contract path, which the Linux stubs don't exercise — it still needs a fresh -`hh-deploy create` first-boot on an hh-alpha VM to confirm in situ before this -bug is archived.** diff -r 593a8091c02b -r cfb4a678d291 bugs/archive/003-supervisor-exec-race-first-boot-exit-minus-1.md --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/bugs/archive/003-supervisor-exec-race-first-boot-exit-minus-1.md Tue Jul 21 14:18:37 2026 -0500 @@ -0,0 +1,126 @@ +> **CLOSED (2026-07-21):** Fixed and released in **zyginit 0.2.6** (tag +> v0.2.6, rev 221). See the Resolution section below for the two-defect fix. +> Closed by decision ahead of an hh-alpha first-boot confirmation of the +> Defect B (contract reap-race) half — reopen if that boot surfaces a +> regression on the real contract path. + +# Bug 003: supervisor exec of service start-commands races first-boot I/O pressure, yielding spurious exit=-1 + +## Summary + +On the **first boot of a freshly-deployed system**, services intermittently +report `exit=-1` in the boot report even though their start command is present, +executable, and succeeds on a manual retry moments later. `exit=-1` here means +the supervisor could not *exec* the start command at all (the process never +ran), as distinct from the command running and exiting non-zero. + +The trigger is contention during a reconfigure first boot: `devfsadm` is +enumerating/rebuilding the device tree, the ZFS root pool is finalizing, the +`/reconfigure` flag is being processed, and many services are starting in +parallel. Under that I/O pressure a `stat()`/exec of the start command (or its +`#!` interpreter) can transiently fail, and the supervisor records the service +as failed with `exit=-1`. + +Concrete evidence (Hammerhead, hh-alpha9, fresh `hh-deploy create` first boots): + +- `acpihpd-check` is a `type="oneshot"` whose `start.sh` **always exits 0** + (both branches: controller present → `exit 0`; absent → disable acpihpd + + `exit 0`). Yet on some first boots it shows `exit=-1` and produces **no** + log output at all — i.e. `start.sh` never executed. A `zygctl restart + acpihpd-check` seconds later runs it cleanly (`exit=0`, log line written). +- Because `acpihpd-check`'s job is to disable the `acpihpd` daemon on platforms + without an ACPI hotplug controller, when the check loses the exec race it + never disables `acpihpd`, so `acpihpd` *also* starts and fails `exit=-1`. + Result: **two** failed services in the boot report instead of zero, even + though the intended end state (acpihpd off, correct for i440fx/KVM) is + reached once things settle. +- The same first-boot `exit=-1` pattern has been observed on other services + (e.g. `sysconfig`) during boot probes — it is **not acpihpd-specific**; it is + a general supervisor exec-robustness issue that only manifests under + first-boot I/O contention. + +Note: Hammerhead already mitigates a related symptom by requiring absolute +paths for every external command in service scripts (avoids `PATH`-lookup +misses), but that does not cover this case — here the exec of the start +command / interpreter itself transiently fails despite an absolute, valid path. + +## Severity + +**Low (cosmetic), but design-defeating.** The eventual end state is correct +and the failure is transient/non-reproducible at steady state, so nothing is +actually broken. However: + +- It produces **false-positive "failed" services** in the first-boot report, + which is alarming and erodes trust in the report. +- It **defeats the `acpihpd-check` oneshot design**: that split (a precheck + oneshot that disables the daemon so the daemon stays a pure `type="daemon"` + and never false-positives) was created specifically to avoid `acpihpd`'s + `exit=-1`, but it only works when the check *wins* the exec race. When the + check loses, you get exit=-1 on both. + +## Affected Version + +zyginit 0.2.5 (and earlier — this is longstanding supervisor behavior, not new +to the 0.7.6 migration). Reproduces only on first-boot-of-fresh-deploy under +I/O pressure; does not reproduce at steady state or on subsequent boots. + +## Suggested Fix (for the zyginit team) + +The supervisor should distinguish "**exec failed to start the process**" from +"process ran and exited with a code," and treat the former as retryable: + +1. On a transient exec failure (`ENOENT`/`EACCES`/`EAGAIN`/`ETXTBSY` from the + spawn), **retry the exec** a few times with a short backoff before recording + failure. A start command that is genuinely missing will still fail after the + retries; a transient stat/exec miss will succeed on retry. +2. Alternatively / additionally, **throttle or serialize oneshot exec during a + reconfigure boot** (while `/reconfigure` is being processed) so the exec + path isn't competing with devfsadm + pool-finalize I/O. +3. Consider surfacing exec-failure distinctly from process-exit in the boot + report (e.g. `spawn-failed` vs `exit=N`) so a transient spawn miss is not + reported identically to a real non-zero exit. + +## Reported by + +Hammerhead team (Chris Tusa), 2026-07-21. Observed across multiple fresh +`hh-deploy create` first boots on the hh-alpha VMs (pc-i440fx + OVMF, no ACPI +hotplug controller). Cross-ref Hammerhead memory `zyginit-service-empty-path` +(the 2026-06-08 boot probe that first characterized the transient stat() miss). + +## Resolution (2026-07-20, zyginit 0.2.6-dev) + +Investigation found `exit=-1` was **not** an exec-failure code (a real exec +failure exits **127**); it is the "could not resolve an exit code" sentinel. +Two distinct defects were fixed in `src/supervisor.reef`: + +- **Defect A — exec robustness + no silent failure.** The service child now + retries `process_exec` a bounded number of times (`EXEC_MAX_ATTEMPTS` = 5, + `EXEC_RETRY_DELAY_MS` = 100ms) to ride out the transient first-boot + stat()/exec miss. When every attempt fails, the child records the failure to + **both** its per-service `<name>.log` (via fd 2, which survives a privilege + drop) **and** the new central `zyginit.log`, then exits 127. This removes the + "failed with an empty log" symptom. Errno is not exposed by the Reef stdlib + `process_exec`, so the retry is a blind bounded retry rather than + errno-selective — a genuinely-missing command still fails all attempts. + +- **Defect B — reap-race reconciliation (the actual source of `-1`).** In the + poll loop the contract-empty event (bundle fd) can beat the child's + exit-status posting. `handle_contract_event` used to commit the `-1` sentinel + and tear down tracking, after which the catch-all reaper discarded the real + code. It now **defers** when there is no hint, no resolvable code yet, and a + child is still tracked (`rt.pid > 0`), leaving `rt.pid` + the contract map + intact so the unconditional `reap_children` re-dispatches with the true code + within ~1s. This fixes both the 127→-1 masking **and** the independent + false-positive where an exit-0 oneshot that lost the race was reported FAILED. + +New central operational log: `/var/log/zyginit/zyginit.log` (`sup_log`), +distinct from the per-service logs. No new report state/label was added +(intentionally — the exit code plumbing now carries the truth). + +Verified on Linux (non-contract path) by integration suite +(`tests/integration/run_tests.sh`, Suite 9b "Spawn-failure capture (bug 003)", +97/97 passing): a service pointing at a missing binary now populates both logs +and is reported `failed` (never `exit=-1`). **Defect B rides the Hammerhead +contract path, which the Linux stubs don't exercise — it still needs a fresh +`hh-deploy create` first-boot on an hh-alpha VM to confirm in situ before this +bug is archived.**