|
root / bugs / archive / 003-supervisor-exec-race-first-boot-exit-minus-1.md
003-supervisor-exec-race-first-boot-exit-minus-1.md markdown 127 lines 7.0 KB

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.