Skip to content

fix(remote): report pull bootstrap progress on stderr (#882) - #883

Closed
fujibee wants to merge 2 commits into
mainfrom
fix/882-pull-progress
Closed

fix(remote): report pull bootstrap progress on stderr (#882)#883
fujibee wants to merge 2 commits into
mainfrom
fix/882-pull-progress

Conversation

@fujibee

@fujibee fujibee commented Aug 18, 2026

Copy link
Copy Markdown
Owner

Declared reviewers: 1

Closes part of #882.

Change class: user-visible output. agmsg remote pull gains lines on
stderr. It adds no stdout, so nothing that parses the result changes.

What was wrong

A pull of 2079 messages runs for 312 seconds and prints nothing at all. An
external verifier ran it against a real server on Windows, saw the silence,
concluded the command had hung, and killed it. A working command and a stalled
one were indistinguishable, and roughly half an hour of diagnosis went into a
command that may well have been fine.

What it prints now

agmsg: [0s] pulling myteam from https://... -- this can take several minutes
agmsg: [1s] fetching messages after 0 (0 pulled so far)
agmsg: [9s] applying 1000 messages
agmsg: [140s] fetching messages after 1000 (1000 pulled so far)

stderr only. cmd_pull captures this process's stdout as the result
channel — result="$(... pull-bootstrap ...)", then grep '"pull_bootstrap_result"'
— so a line written there would ride in the stream the caller parses.
scripts/remote.sh:936 already records this convention for the neighbouring
call; scripts/remote-sync.sh:47 execs node with no redirection, so stderr
reaches the operator's terminal unchanged.

Fetching and applying are named separately on purpose: applying spawns a child
process per batch and fetching does not, so when the output stops moving, the
line it stopped on says which half to look at. On Windows — where the report
came from — that is the whole open question.

Elapsed seconds are stamped because a terminal does not timestamp its own
scrollback: without them, "it printed this and then stopped" cannot say whether
the stop was ten seconds or ten minutes.

Measured

End-to-end on the shipped path (not just in-process), streams captured to
separate files:

$ node scripts/internal/remote-sync.mjs pull-bootstrap --team probe ... --endpoint http://127.0.0.1:1
STDOUT: {"at":"...","event":"fatal","message":"fetch failed","code":null}
STDERR: agmsg: [0s] pulling probe from http://127.0.0.1:1 -- this can take several minutes
        fetch failed

tests/remote_sync_engine.test.mjs — 95 pass, 0 fail. The new case captures
both streams, because the regression worth catching is a progress line
landing in stdout, and that is invisible if only stderr is measured. It asserts
stdout is exactly one line and parses as pull_bootstrap_result.

Mutation table, re-run after the assertions were rewritten for the elapsed
prefix:

mutation result
pullProgress writes to stdout instead of stderr red — stdout 4 lines, expected 1
the applying N messages line deleted red
neither (control) green, 95/95

What this does not do

It does not fix the Windows stall. It makes the stall reportable: the next run
says which phase it stopped in and after how long. Granularity is one page
(limit=1000), so a stall inside a single apply is still a silent interval —
narrowing further would mean changing the driver's protocol, which this does
not touch.

A pull of 2079 messages runs for 312 seconds and prints nothing. A verifier
running it against a real server on Windows saw the silence, concluded the
command had hung, and killed it -- a working command was indistinguishable
from a stalled one, and the diagnosis went thirty minutes in the wrong
direction (#882).

Progress goes to stderr only. cmd_pull captures this process's stdout as the
result channel and greps it for pull_bootstrap_result, so a line written
there would ride in the stream the caller parses.

The lines separate fetching from applying because applying spawns a child
process per batch and fetching does not: when the output stops moving, which
line it stopped on says which half to look at.
A terminal does not timestamp its own scrollback, so "it printed this and
then stopped" cannot say whether the stop was ten seconds or ten minutes.
The Linux run that finished took 312 seconds; without elapsed, a slow phase
and a stuck one look identical to whoever is watching.
@fujibee

fujibee commented Aug 19, 2026

Copy link
Copy Markdown
Owner Author

Folded into #895, which carries these two commits unchanged along with the fix for the failure they were written to make visible.

Keeping them apart would have landed the size fix first and the progress output later — which is the order the reporter's own experience argues against. What cost them 79 minutes was not being able to see anything, and a fix that lands without that leaves the next failure just as silent.

@fujibee fujibee closed this Aug 19, 2026
@fujibee
fujibee deleted the fix/882-pull-progress branch August 19, 2026 09:38
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