Skip to content

send output in batches and add it once a frame, so a program printing a lot no longer freezes the studio - #159

Merged
irrld merged 4 commits into
mainfrom
agent/batch-output
Oct 4, 2026
Merged

irrld merged 4 commits into
mainfrom
agent/batch-output

Conversation

@cogwright

Copy link
Copy Markdown
Collaborator

Your log from the freeze shows the backend going silent right after Run: at 13:24–13:25 in window 2 ("test"), Repair IDE's 5 s ping timed out and it restarted the backend. I reproduced it with a program that logs like a game, printing 40 lines every 2 ms. On main, the backend's ping took up to 11.4 s (median 71 ms), only 5 pings in 8 s were answered, and the Output panel grew to 2.9 million characters.

There were two causes:

  • Backend: every piece the program printed went to the window as a message of its own. A game logging every frame sends thousands a second.
  • Window: each piece was formatted, appended to one ever-growing run of text, and scrolled to on its own. Appending to a single block of text means the page lays out every line again. At 10 MB of output, that took 105 ms per append; appended as separate blocks, it took 2.7 ms.

What changed

  • Output goes in batches (src/output-stream.ts). What builds and runs print is sent every 50 ms as one message, with stdout and stderr in the order they came.
    • A batch ends at the end of a line; the rest of the line goes with the next batch. A prompt with no line end still shows after an interval.
    • UTF-8 characters split between pieces arrive whole.
  • A run's output has a limit; a build's has none. A run sends at most 128 K characters per batch, about 2.5 MB/s, far more than anyone can read. Past that, the newest lines are sent after a yellow note: "657,433 lines left out: the program printed faster than they could be shown. The newest follow."
    • Build output is never cut, because a compiler's first error matters most.
  • The window adds output once per frame and scrolls once. Text is added in blocks of whole lines, so only the new lines are laid out.
    • Frames stop while the window is hidden or covered, for example by the game's own window. A quarter-second timer keeps output arriving then.
  • Each section keeps its newest 1 million characters. Past that, the oldest blocks go, down to 800 K. A line at the top says "Earlier output is not shown here, to keep the window quick. The newest is kept."
  • New strings (outputSkipped, outputTrimmed) are in English, Turkish and French.

Tests

  • tests/output-stream.test.mjs (unit test): one message per interval, order kept, split characters whole, flush, half-finished lines held back, prompts shown, the limit and the note's count, and a 2 MB build arriving whole.

  • tests/e2e/flows/output-flood.mjs (new e2e flow): builds and runs a real program. It prints like a game's log, then as fast as it can for 3 s. The flow checks that:

    • the backend keeps answering;
    • the window keeps drawing;
    • every line shown is whole and in order;
    • every jump in the line numbers matches the count in a note at that spot;
    • the last line arrives;
    • the run keeps only its newest output and says so.

    It is skipped without CMake and a C++ compiler; GitHub's Ubuntu runners have both. On main, this flow froze the page until the runner's 240 s limit. On this branch it passes in about 8 s, also with the page's CPU slowed 4×. Writing it found a real bug before this was pushed: a "lines left out" note stuck onto a half-finished line.

  • Measured:

    Worst ping Longest frame
    Browser build, game-style log 11,429 ms → 9 ms 33 ms
    Browser build, as fast as it can (118 million lines in 10 s) 13–14 ms 35 ms
    Electron app (electron-forge package), both programs 3–4 ms 12 ms, no task over 50 ms
  • tsc, lint, npm test, and all 25 e2e flows pass on macOS.

Worth knowing

  • The 1 M-character limit also applies to a build's section in the window. A build log longer than that, rare even for big projects, loses its beginning in the Output panel. That is where the first error usually is. Copy Details already kept only the last 200 K of a build log. If builds should keep more, it is one constant in src/output-history.ts.
  • The Output panel still jumps to the bottom on new output, as before. With a program printing nonstop, scrolling up to read isn't possible until it stops. Pausing auto-scroll while scrolled up would be a separate change.
  • Not verified: Windows and Linux in the app; only macOS, in the app and the browser build. The other freeze in the log (11:17–11:18, engineCheckout 33 s and checkPluginUpdates 49 s with a 14.5 s ping, right after clangd restarted) happened with nothing running. It is not explained by this, and this PR does not claim to fix it.

🤖 Generated with Claude Code

@irrld
irrld merged commit 86c5425 into main Oct 4, 2026
4 checks passed
@irrld
irrld deleted the agent/batch-output branch October 4, 2026 14:10
@cogwright

Copy link
Copy Markdown
Collaborator Author

Correction to the description above: the freezes in irrl's log were not caused by output. Both follow a clangd restart, and the cause is the backend's recursive file watch on Linux; that is fixed in #161. This PR still fixes a real stall when a program floods the Output panel, reproduced and guarded by tests/e2e/flows/output-flood.mjs.

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.

2 participants