Skip to content

Report progress while provisioning, and -v to stream the log - #14

Merged
defkode merged 1 commit into
mainfrom
provisioning-progress
Aug 31, 2026
Merged

Report progress while provisioning, and -v to stream the log#14
defkode merged 1 commit into
mainfrom
provisioning-progress

Conversation

@defkode

@defkode defkode commented Aug 31, 2026

Copy link
Copy Markdown
Owner

First boot spends minutes in mise install with no output at all — the machine is already created and running, so a provision and a hang look identical from the outside. orbx logs in a second terminal was the only way to see anything.

wait_ready now reports:

  • spinner + elapsed time, redrawn in place, on a TTY;
  • one plain line (orbx: provisioning <name> … / orbx: ready in Xm YYs) when stderr is redirected — CI, or an agent driving orbx run, which is what closes the hang ambiguity for an agent;
  • -v/--verbose streams the guest's /var/log/sandbox-provision.log inline instead.

No template change: default.yaml already logs every step: orbx just never surfaced it.

Notes:

  • The stream is incremental polling, not a background tail -forbx::stream_log asks for everything past the line count it was handed and echoes the new count back. No child process to supervise, and a log that does not exist yet comes back empty.
  • An already-provisioned machine answers ready on the first poll and returns silently, so the everyday path prints nothing, exactly as before.
  • Ctrl-C wipes the spinner frame and re-raises (kill -INT "$BASHPID"), so an interrupted orbx exits 130 instead of returning as if the wait had finished. Tests cannot deliver a real Ctrl-C (a backgrounded job inherits SIGINT ignored, and bash cannot trap what was ignored on entry), so they assert the arm/disarm and the re-raise separately — AGENTS.md records why.

97 bats tests (7 new), shellcheck clean.

First boot spends minutes in `mise install` -- Ruby, Node, and since #13
the tools the mounted project pins -- while orbx sits in wait_ready
polling /etc/sandbox-status and printing nothing. The machine is created
and running by then, so from the outside a provision and a hang look
identical. The only way to see anything was `orbx logs` from a second
terminal, which you have to know about and cannot reach for once orbx has
your prompt.

The template already logs every step with a timestamp, so nothing new has
to be produced -- orbx just never surfaced it. wait_ready now reports:

  - a spinner + elapsed time, redrawn in place, on a TTY;
  - one plain line naming the machine, plus `ready in Xm YYs`, when
    stderr is redirected (CI, an agent driving `orbx run`) -- escape
    codes there would be noise, and this is what closes the hang
    ambiguity for an agent;
  - with -v/--verbose, the guest's provisioning log inline instead.

The stream is incremental polling, not a background `tail -f`:
orbx::stream_log asks for everything past the line count it was handed
and echoes the new count back, so there is no child process to supervise
and kill, and a log that does not exist yet simply comes back empty.
Latency is one poll interval.

A machine that answers `ready` on the very first poll was already
provisioned: nothing is being waited on, so wait_ready returns silently
and does not replay a log of work that finished days ago. The everyday
path -- `orbx` in a project whose sandbox exists -- prints exactly what
it printed before, which is nothing.

Every exit from the wait funnels through orbx::wait_done (clear the line,
drop the trap), the INT trap included: Ctrl-C wipes the spinner's last
frame and re-raises with `kill -INT "$BASHPID"`, so an interrupted orbx
dies of the signal (130) rather than returning as if the wait had
finished. $BASHPID rather than $$ because the script gets sourced into
other shells, where the signal must stay with the subshell running the
wait.

No test can deliver a real Ctrl-C -- a backgrounded job inherits SIGINT
ignored, and bash cannot trap what was ignored on entry -- so the tests
assert the arm/disarm and the handler's re-raise separately, and AGENTS.md
records why, so it is not "fixed" into a flaky signal test later.

Verified with 97 bats tests (7 new) and shellcheck clean, plus an
end-to-end run of `orbx up` against the suite's fake orb: the spinner
redraws in place and clears, -v prints each log line exactly once across
polls (tail -n +1 then +7), an already-ready machine prints nothing, and
a redirected stderr carries no escape codes.
@defkode
defkode merged commit b902d80 into main Aug 31, 2026
2 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant