Repository navigation
fix(cli): terminate model output with a newline, and report cache in stats - #372
Conversation
Two things Justin hit using the REPL for real work. The model's output does not always end in a newline, and the REPL rendered whatever came next immediately after it on the same line. The CLI now emits that separator itself rather than depending on the model to produce one. run_generation_turn owns it, so it fires exactly once across every path that ends a turn -- normal completion, EOS, a stop sequence, the token ceiling, Ctrl-C, an error, and the reasoning-incomplete path that drops the exchange -- and only when the output is non-empty and does not already end with one, so a well-behaved model does not get a blank line. This is adjacent to the newline bug fixed in #289, where the decision consulted the renderer's lifecycle rather than whether the turn used live rendering; that correction is preserved. The stats block was missing prefix cache reuse, which is the most interesting number in a multi-turn session and the whole point of the prefix cache. It now reports hit tokens and percentage, alongside the budget cap from #335 so a scheduler-shortened ceiling cannot silently distort a benchmark. The block is now a deliberate two lines rather than one line left to wrap at whatever width the terminal happens to be: perf and termination on the first, cache and resources on the second. An accidental wrap splits a field from its value and looks different on every terminal; a designed break does not. A test renders a fully populated block and asserts on it, so the width is visible -- 114 and 100 columns -- and a future change that bloats it is caught rather than discovered in a narrow terminal. Piped and non-TTY output keeps its previous byte-stable single-line shape, and the JSON profile keeps every field regardless of text layout, since scripted benchmarking reads the structured form. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 023d5a3f-c551-4aa8-afbe-a329af15fbdd
Codecov Report❌ Patch coverage is Additional details and impacted files@@ Coverage Diff @@
## main #372 +/- ##
==========================================
- Coverage 81.28% 80.59% -0.70%
==========================================
Files 309 311 +2
Lines 120384 121012 +628
Branches 120384 121012 +628
==========================================
- Hits 97860 97528 -332
- Misses 18554 19505 +951
- Partials 3970 3979 +9
Flags with carried forward coverage won't be shown. Click here to find out more.
🚀 New features to boost your workflow:
|
emit_stats_line chose between the two-line block and one-liner by testing io::stdout().is_terminal(), but stats are written to stderr. This inverted the decision in both common redirection cases: generate ... > out.txt stdout=file, stderr=terminal -> old: line, correct: block generate ... 2> stats.log stdout=terminal, stderr=file -> old: block, correct: line Fix: test io::stderr().is_terminal(). To make the branch unit-testable (and prevent the same mistake from re-entering), extract fn stats_text(stderr_is_terminal: bool, ..) as a pure helper. The emit_stats_line call site passes the correct stream; tests pass the booleans directly. Add output::tests::stats_format_follows_stderr_not_stdout covering all four boolean combinations; cases A and B above are named explicitly. A profile with both headline (prompt_tokens) and resource (context) data is used so block vs line are structurally distinct. No other site in the crate cross-probed streams. The trailing-newline and reasoning-dim logic in run_generation_turn correctly probes stdout because it governs stdout content. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
Updates the CLI’s interactive UX so terminal rendering is robust (REPL-owned trailing newline) and per-turn stats are more informative (cache/resource reporting with a deliberate two-line TTY layout).
Changes:
- Ensure streamed REPL output is terminated with exactly one CLI-owned newline separator when needed (without relying on model tokens).
- Expand stats output to include prefix-cache hit info and additional resource/scheduler signals, with a two-line TTY stats block and single-line non-TTY output.
- Switch stats layout selection to follow stderr terminal state (since stats print to stderr).
Reviewed changes
Copilot reviewed 8 out of 8 changed files in this pull request and generated 2 comments.
Show a summary per file
| File | Description |
|---|---|
| README.md | Updates documentation/examples to describe the new two-line stats block and fields. |
| crates/onnx-genai-cli/src/profile.rs | Adds cache/resource fields, two-line TTY stats block formatting, percent helpers, and tests. |
| crates/onnx-genai-cli/src/output.rs | Routes stats formatting based on stderr TTY state; ensures REPL newline finalization after streaming. |
| crates/onnx-genai-cli/src/live_turn.rs | Makes live renderer finalization optionally append a trailing newline separator to scrollback. |
| crates/onnx-genai-cli/src/lib.rs | Updates tests around newline separator behavior to account for input mode. |
| crates/onnx-genai-cli/src/interactive.rs | Adjusts newline-separator policy for plain streaming vs TTY mode; adds unit tests. |
| crates/onnx-genai-cli/src/generate.rs | Changes newline behavior for one-shot generation streaming path (currently problematic; see comments). |
| .squad/agents/rachael/history.md | Records the work in agent history. |
| Ok(output) => { | ||
| if args.stream { | ||
| if args.stream && !io::stdout().is_terminal() { | ||
| println!(); | ||
| } else { | ||
| } else if !args.stream { | ||
| println!("{output}"); | ||
| } |
There was a problem hiding this comment.
The premise here is incorrect. Before this change, generate.rs emitted println!() unconditionally for piped+stream (preserving the byte-stable trailing newline), and run_generation_turn emitted it conditionally for TTY+stream. Piped output was never changed; the TTY newline was always conditional on whether the output already ended with one.
What was genuinely wrong was the shape: one concern split across two files with opposite conditions. A reviewer as capable as Copilot misread it in both directions, which is evidence the shape was confusing. The fix consolidates the whole decision into run_generation_turn: piped still gets an unconditional newline (explicit comment explains why), TTY gets the conditional one. Both callers no longer emit newlines themselves. Two new e2e tests pin the piped byte-stable guarantee.
| assert_eq!( | ||
| lines[0].chars().count(), | ||
| 114, | ||
| "headline width changed; rendered stats block:\n{block}" | ||
| ); | ||
| assert_eq!( | ||
| lines[1].chars().count(), | ||
| 100, | ||
| "resource width changed; rendered stats block:\n{block}" | ||
| ); |
There was a problem hiding this comment.
Fixed. Assertions in stats_block_has_a_deliberate_two_line_full_layout now use UnicodeWidthStr::width() instead of chars().count(). unicode-width was already a dependency (used by wrapped_rows in live_turn.rs), so no new dep needed. Added stats_block_width_uses_display_width_not_scalar_count with a CJK finish-reason (one char, two columns) to confirm the two metrics actually diverge and the test would have caught the old code.
🔴 Benchmark Regression DetectedComparison of criterion micro-benchmarks: PR head vs merge-base, measured on the same runner in the same job (base first → PR second).
Visual flags: Host infoWhat this cannot catch
|
Finding 1 - newline split across two files
------------------------------------------
Before this commit, the decision "does a streaming reply need a
terminating newline, and who emits it?" was answered in two places
with opposite conditions:
generate.rs: if stream && !is_terminal() { println!() } // piped
output.rs: if stream && is_terminal() && needs_nl { println!() } // TTY
A reviewer as capable as Copilot misread the split in both directions
(claiming the piped guarantee was removed and the TTY case was missing),
which is evidence the shape is confusing enough to cause double-newlines
or missing newlines on the next touch.
run_generation_turn now owns the whole decision:
- --stream, piped: unconditional trailing newline (backward compat)
- --stream, TTY: conditional: skip when reply already ends with newline
- non-stream: unchanged
The asymmetry is deliberate and commented: piped consumers have always
received an unconditional newline and removing it is a byte-stable
break; the TTY path is conditional because a double blank line is a
visible defect.
Callers (generate.rs, the REPL loop in interactive.rs) no longer emit
the newline themselves. plain_stream_needs_trailing_newline is removed;
its coverage moves to run_generation_turn new branch and two new e2e
tests that pin the byte-stable piped guarantee against generate --stream
and the run REPL.
Finding 2 - width assertions must use display width
---------------------------------------------------
stats_block_has_a_deliberate_two_line_full_layout asserted line widths
with chars().count(). Terminal layout uses Unicode display width: CJK
ideographs occupy two columns but count as one scalar value. Justin
works in Chinese; a model name or finish-reason string with CJK would
pass the old assertion while wrapping on real hardware.
Switch to UnicodeWidthStr::width (unicode-width is already a
dependency). Add stats_block_width_uses_display_width_not_scalar_count
with a CJK finish-reason to prove the two metrics actually diverge.
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The previous commit used cargo fmt --check (package-scoped) which passed locally but CI runs cargo fmt --all --check (workspace-wide). lib.rs had a trailing import line that needed reflowing. Also records the durable rule: run the gate command CI runs, verbatim. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Two code paths in output.rs branch on is_terminal() and have had zero terminal-specific coverage: 1. run_generation_turn (stdout): conditional trailing newline — added only when the model output does not already end with \n, preventing a blank line when it does. 2. emit_stats_line (stderr): two-line block vs single-line stats format — selected by stderr.is_terminal(), not stdout.is_terminal(). Piped-stdio tests structurally cannot cover these branches because is_terminal() returns false on every pipe. This commit adds tests/pty_tty_e2e.rs with two #[cfg(unix)] tests that drive the real CLI binary under a pseudo-terminal (nix::pty::openpty, already in the dependency graph via ctrlc) so is_terminal() returns true for the relevant streams: stats_single_line_when_stderr_is_piped_and_stdout_is_tty stdin=PTY, stdout=PTY (both TTY → stats enabled), stderr=pipe (NOT TTY). Asserts stderr does NOT contain the block-format boundary "]\n[". Against the pre-fix code (which probed stdout instead of stderr): stdout is TTY → to_stats_block() chosen → "]\n[" present → FAILS. Against the fixed code (probes stderr): stderr is pipe → to_stats_line() chosen → no "]\n[" → PASSES. Genuinely discriminating. tty_stdout_gets_exactly_one_trailing_newline_after_streaming stdout=PTY (is_terminal()=true), --stream activates the conditional newline path. The PTY's ONLCR maps \n → \r\n, so the final separator must be \r\n but not \r\n\r\n (double blank line). The assertion catches the "always add an extra newline" bug whenever the model output ends with \n; it also catches "never add any newline". Platform: #[cfg(unix)]. ConPTY on Windows is disproportionately complex; CI runs Linux and macOS jobs so the gate provides adequate PR coverage. This is a genuine platform dependency, not an incidental one. nix = "0.31" added as [target.'cfg(unix)'.dev-dependencies]; the crate is already resolved at 0.31.3 in Cargo.lock via ctrlc, so no version bump. Durable rule recorded in .squad/decisions/inbox/: terminal-only behaviour requires a PTY-driven test; piped-stdio tests structurally cannot cover it. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
First-ever execution of pty_tty_e2e.rs on Linux/WSL found three defects
that were invisible on Windows (where #[cfg(unix)] compiles to zero tests):
1. Missing nix feature flags. nix 0.31 requires opt-in features for every
subsystem. `nix::pty::openpty` is behind "term" and `nix::unistd::dup`
is behind "fs"; without them the crate compiled on Windows (no code
path reached the imports) but failed with E0432 on Linux:
error[E0432]: unresolved import `nix::pty`
note: found an item gated behind the `term` feature
error[E0432]: unresolved import `nix::unistd::dup`
note: found an item gated behind the `fs` feature
Also adds "poll" for nix::poll::poll, used by the drain timeout below.
2. No read timeout on drain_pty_master. The original blocking read() loop
would hang a CI job indefinitely if the child process never closed the
PTY slave. Replaced with a nix::poll::poll loop capped at 30 seconds.
When the deadline fires the function returns whatever bytes were collected;
the test then fails on its own assertions rather than stalling the runner.
3. Spurious `mut` on `child` bindings. Both tests bound `let mut child`
but never called a `&mut` method on it; clippy -D warnings would have
rejected these. Removed the `mut` qualifier.
Gate results (commands run verbatim):
cargo fmt --all -- --check ✓ (exit 0)
cargo clippy -p onnx-genai-cli --all-targets -- -D warnings ✓ (exit 0)
cargo test -p onnx-genai-cli ✓ 168 passed on Windows (PTY tests
gated out on Windows as expected)
wsl: cargo test -p onnx-genai-cli --test pty_tty_e2e ✓ 2 passed, 12.49 s
Discrimination outcomes recorded in .squad/decisions/inbox/:
stats test: FAILS with pre-fix (stdout probed) as expected; PASSES fixed.
newline test: PASSES with pre-fix code — tiny-llm outputs tok22tok22tok20<eos>
(no trailing \n), so conditional and unconditional println!()
are identical for this fixture. Documented as sanity check
only; a fully discriminating test requires a fixture whose
output ends with \n.
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The condition `!output.is_empty() && !output.ends_with('\n')` that guards
the conditional newline after a streamed TTY reply was inlined at one call
site, making it invisible to the test suite. An unconditional println!()
would have passed every test green.
Changes
-------
* Extract the predicate into fn needs_trailing_newline(output: &str) -> bool
in output.rs. The doc-comment explains its role and why the piped path
is out of scope.
* Replace the single inline expression with a call to the named function.
* Add tty_trailing_newline_predicate_covers_all_cases (six cases):
- non-empty, no trailing \n -> true (needs one)
- ends with \n -> false (already at new line)
- empty string -> false (nothing to terminate)
- multi-line ending with \n -> false
- ends with \n then spaces -> true (cursor is mid-line)
- internal \n, no trailing -> true
The PTY e2e test still serves as the integration proof that the add path
reaches a real terminal, but with a new comment that records its coverage
gap: the tiny-llm fixture never emits a trailing \n, so the skip branch is
untested end-to-end. The unit tests above close that gap.
Gates: cargo fmt --all -- --check, cargo clippy -p onnx-genai-cli
--all-targets -- -D warnings, cargo test -p onnx-genai-cli: 102+23+34+10
passing, 0 failed.
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
## A hazard in merged code PR #372's PTY harness calls `openpty(None, None)` — **a 0x0 window**. ratatui's `insert_before_no_scrolling_regions` **infinite-loops at zero rows**, so the harness as merged is one type-ahead test away from hanging a CI job, and the next person to extend it would have had no idea why. The window is now a real **24x80**, with the reason at the call site — a bare `24, 80` reads as arbitrary and someone would eventually "simplify" it back. The **CR-not-LF** gotcha is cross-referenced there too: terminals send `\r`, and feeding `\n` means the line never completes, which presents as a hang that looks exactly like swallowed input. Both artifacts were found the expensive way, so they now live **in the code a harness author will read**, not only in a decision record. **Confirmed neutral rather than assumed:** test 1 passes at both 0x0 and 24x80; test 2 behaves identically at both. Test 2's empty read under WSL is **not** a window-size effect — it is the harness's own 30s `drain_pty_master` timeout against a ~48s debug model load over the slow `/mnt/c` mount. A byte-for-byte replica with a 90s window returns the expected `tok22tok22tok20\r\n`. Native CI Linux loads fast enough that both pass. ## Context: three negatives on the type-ahead report This branch began as an investigation into `run` swallowing typed-ahead input. **Input is not being lost.** Each hypothesis was refuted with evidence rather than argument: - **The cursor-query theory is dead on both platforms.** crossterm 0.29's `cursor::position()` routes user keystrokes to `skipped_events` and **drains them back into the queue**; ratatui 0.30's inline viewport never reads stdin outside init/resize. Verified by withholding the DSR reply 250ms and injecting `/help` into the open window — it survived. - **Windows cannot lose it either.** `ReadConsoleInputW` reads raw records unaffected by `ENABLE_LINE_INPUT`; `SetConsoleMode` does not flush the queue; there is no `FlushConsoleInputBuffer` anywhere. Instrumented `GetConsoleMode` (`0x01f7`) and pending `INPUT_RECORD` counts across prompt boundaries confirm it, including for a **partial line with no Enter**. - **The timing gap is closed.** Re-run against `qwen2.5-0.5b` streaming **~19s**, with `/help` injected pasted, delayed, and character-by-character at human speed. Type-ahead survived every time. **Raw bytes argue against the erase hypothesis:** `/help` appears at the banner and at the next prompt — **never mid-stream**. ConPTY does not echo type-ahead during generation, so there is nothing for a repaint to overwrite. **No speculative fix shipped.** The remaining untested path is native-conhost immediate echo, which no automated harness on a headless box can produce — plausibly why it is visible in an ordinary session and not here. Fixing an unobserved mechanism would look like it worked and would not. --------- Co-authored-by: justinchuby <223556219+Copilot@users.noreply.github.com>
Recovered decision records from agents' per-worktree inbox files, which were deleted before Scribe ran. Substance survived in history.md and PR descriptions; durable rules now appended to decisions.md: From Rachael (PR #372): - Probe the stream you are writing to, not a convenient nearby one - Run the gate command CI runs, verbatim — local subset validation fails - Terminal behaviour requires PTY-driven tests; piped I/O cannot cover it From Zhora (PR #393): - Type-ahead is not lost during generation on Unix or Windows - PTY-harness hazards that present as swallowed input - Prefer an idle timeout to a total one when child is silent before first output From Leon (PRs #367/#385/#392/#395): - DeepSeek "repeats thinking" is not a backend bug, but greedy-decoding degeneration - Model-declared generation defaults are canonical; our constants are fallback, not override - CUDA driver API ships with display driver, not toolkit; inferred bad facts must be verified From Coordinator: - Standing Operational Rule: worktree lifecycle and decision merging — do not delete a worktree before Scribe has merged its decision inbox Before: 27,360 bytes | After: 34,662 bytes | Added: 7,302 bytes Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Two reports
1. The REPL owns the newline, not the model
The prompt was rendering on the same line as the last token whenever a model's final token did not happen to end in
\n. That is not the model's job to guarantee — it is a property of the display, and depending on the token stream to supply it means the layout breaks on some models and not others, for reasons that have nothing to do with the layout.So the REPL now terminates the stream itself, and only when the stream did not already end with a newline — no blank line on models that do emit one.
Note this is the interactive display path only. Piped
stdoutstays byte-stable: generated text goes to stdout and stats to stderr per the convention established earlier, and a newline injected for terminal legibility must not change what a script receives.2. Stats now covers cache and resources, not just speed
The old single line reported throughput and stopped there — so prefix cache hits were invisible, which is a strange gap in a tool whose main audience is us, developing the runtime. A cache that silently stops working looks exactly like a cache that works.
Two lines, split by what you are looking for:
Two lines rather than one because everything relevant does not fit in a terminal width, and truncating the interesting half to preserve a one-line aesthetic is the wrong trade. Widths are asserted in tests (114 / 100) so a future field addition fails a test rather than silently wrapping and mangling the display.
Verification
Formatting is covered by unit tests. The interactive rendering was eyeballed in a real terminal session — a worker cannot drive a TTY, and the failure being fixed here is precisely a rendering failure that only appears in one.
Review round (Copilot)
Newline ownership was split across two files — piped in
generate.rs, TTY inrun_generation_turn, one concern with opposite conditions in each. Copilot's specific claims were wrong (it said the change broke piped byte-stability and dropped the terminal newline; piped output was in fact byte-identical before and after), but it misread the code in both directions, which is the evidence that the shape was confusing.run_generation_turnnow owns the whole decision; both callers dropped their ownprintln!().The asymmetry is deliberate and now carries a comment: piped is unconditional for backward compatibility with existing consumers, TTY is conditional because a double blank line is a visible defect. Two e2e tests pin the piped guarantee so nobody deletes that newline later on the strength of a plausible-sounding review comment.
Width assertions used
chars().count()while the crate's actual layout (wrapped_rows) uses Unicode display width. Not hypothetical: @justinchuby works in Chinese, and one CJK character in a model name or finish reason is one scalar but two terminal cells — the test would pass while the real terminal wrapped and mangled the block. A test asserting the wrong property is worse than none, because it grants false confidence exactly where you were building some. Switched toUnicodeWidthStr(already a dependency), plus a CJK case where the two metrics diverge so the change is actually verified.168 tests pass (101 unit + 67 e2e).