mirror of
https://github.com/block/buzz.git
synced 2026-10-27 04:30:52 +00:00
feat(desktop): raise the install ceiling and make installs observable (#3368)
Windows installs of Goose and other harnesses failed at exactly five minutes with an empty error (#2401). The 300s ceiling was killing installs that were working, just slowly — the Goose step pulls a ~79MB release asset, and Windows Defender scans every file npm extracts. When the ceiling fired it discarded the output it had already read, so the user got a bare timeout string and no way to tell a hang from a large download. ## The ceiling `INSTALL_TIMEOUT` is 900s, and the error names the limit: `install command exceeded the 15m ceiling and was terminated`. It stays a pure wall-clock ceiling with no inactivity kill — nothing observable distinguishes a hung installer from one silently transferring a large artifact, so silence alone never kills an install. A ceiling kill remains non-retryable; re-running a command that already burned 15 minutes costs the user more time with no plausible path to success. The child's exit and both stream drains fold into one resumable settle governed by a single deadline. Waiting on the drains outside that deadline would let a descendant that outlived the install shell hold the output pipes — and the per-runtime install guard behind them — open with no bound, which is the failure the ceiling exists to prevent. So the deadline path terminates the process group on the normal-exit branch too: a leader that exited with a real status still gets its stragglers killed, and the guard cannot stick either way. Whether the leader had already exited only decides the verdict — its real status outranks a timeout. The install shell is a session leader and its descendants inherit the output pipes, so signalling only the leader left them running and the drains blocked on a pipe nobody would close. Escalation keys off the *group's* liveness rather than the leader's, since a descendant that ignores SIGTERM outlives the leader and would otherwise never receive the group SIGKILL. Reaping the killed child and finishing the drains share one bounded grace, so a termination that failed outright cannot extend the ceiling that just fired. ## Output capture Each stream drains into a bounded capture that is *shared* with the reader rather than returned by it, so whatever arrived before a stall is readable at the ceiling — exactly when the output matters most. Output of any size costs a fixed amount of memory. One capture holds two independently bounded views of the same bytes: | View | Head / tail | Cut marker | |------|-------------|------------| | UI (`InstallStepResult`) | 512 B / 1024 B | `... (N bytes omitted) ...` | | Log file | 128 KiB / 128 KiB | `... [N bytes omitted at cap] ...` | The UI budget is screen space; the log's is disk. Both markers are inline, so neither ever implies completeness it does not have. Both ends are cut at arbitrary byte offsets, so a partial character is trimmed and the partial token each cut left behind is dropped — the marker's byte count includes both trims. ## Install log `steps` carries only the last attempt of each step, truncated for display. Everything else — earlier retries, the prerequisite step that actually broke, the managed-Node bootstrap — used to be discarded. `InstallReporter` now appends one self-contained record per attempt of per step to `install-<runtime-id>.log` beside the agent logs, and `InstallRuntimeResult.log_path` carries the file to the UI, where a failure message ends with `Full log: <path>`. Each record is bounded independently by the log-scale capture that produced it, so a first attempt that printed megabytes cannot push out the later record explaining the failure; the run's total is bounded by steps × attempts × per-record cap. Every early return builds its result through one `InstallReporter::failed` helper, so no failure path can omit the log pointer, and synthesized steps go through `record_step` — a step that reaches the UI without passing it would be invisible in the file. Install output can echo a registry token or proxy credential from the environment it ran in, and the file is written unattended. Redaction keys off the *names* of the environment variables the install inherited, snapshotted once per run, rather than a list of known secret value prefixes: a credential with no recognisable shape is exactly the one a prefix match misses. Three name rules apply, because the variables need different treatment: | Rule | Variables | Redacted | |------|-----------|----------| | URL userinfo | `HTTP_PROXY`, `HTTPS_PROXY`, `ALL_PROXY`, `NPM_CONFIG_PROXY`, `NPM_CONFIG_HTTPS_PROXY`, `NPM_CONFIG_REGISTRY` | `user:password` only | | Exact name | `NPM_CONFIG_KEY`, `NPM_CONFIG__AUTH`, `NPM_CONFIG_OTP` | whole value | | Marker substring | `*TOKEN*`, `*SECRET*`, `*PASSWORD*`, `*_PAT`, … | whole value, 8-byte floor | A proxy or registry keeps its host and port, because an install that fails behind one is diagnosable only if the record still says which one it went through, and a bare `user@` with no password is not treated as a credential. npm's own settings are listed by exact name rather than matched on `KEY` or `AUTH` substrings — both occur throughout an ordinary environment on values that are paths and people's names — and they bypass the 8-byte floor, since a six-digit one-time password is a credential at that length. Matching is case-insensitive, which is what npm's lowercase `npm_config_*` spelling needs. `0o600` is set by the create rather than a later `chmod`, which would leave a window where the umask decides. A runtime id that cannot safely be a filename yields no log rather than a sanitized one — a rewritten id could collide with another runtime's log. The file holds exactly one run. A run opens its own session after the runtime id has been canonically resolved — the previous file rotates to `.1` and any older `.1` is removed before the rename, since a rename that will not replace its destination would otherwise wedge rotation permanently on Windows. The session writes a header naming the runtime, the app version (`app.package_info().version` on the Rust side — cannot be mocked or fail), the OS (`std::env::consts::OS`), and the start time: a Windows failure and a macOS one on the same runtime are different bugs, and a stale app version explains a failure that no longer reproduces. Each record carries its attempt's elapsed time. ## Live output line A 15-minute ceiling with nothing behind it but a spinner is indistinguishable from a hang. The same drain seam feeds an `acp-install-output` event carrying the newest complete line, and the three install entry points — Doctor harness rows, the harness catalog dialog, and onboarding runtime cards — render it under the spinner with `aria-live="polite"`. Ordering is keyed on a `seq` monotonic across the whole install, not on the attempt number, which restarts at 1 for every step: keyed on attempt, one step succeeding on attempt 2 would make the next step's attempt-1 output look stale and freeze the display for the rest of the install. Each executed attempt begins with an unthrottled `line: null` clear signal, so a stale failure line cannot sit under the spinner while the retry runs. Events are otherwise throttled to four per second, and the throttle *retains* the newest pending line and flushes it when the window reopens rather than dropping it — at an attempt boundary a drop would silently eat the new attempt's first line. The subscription is mounted for the runtime's whole lifetime rather than started when the install begins. The install command is invoked from the click handler, so the clear and a fast command's first lines can be emitted before React has committed the pending state, and nothing replays them — a subscription that waited for that state would lose the entire output of a short install. The run boundary resets the ordering key when the install settles, since `seq` restarts for the next run, and the line renders only while installing, so a straggler from a finishing drain cannot appear under a fresh Install button. The 15-minute ceiling deliberately stops waiting on stuck drain threads — a hung installer must not freeze the app. That means a drain thread can outlive its `InstallReporter`. Without a generation guard, a drain that calls `offer` after the run settles would publish an event with the run's high `seq`, poison the permanent listener's React state, and cause the next install's restarted `seq=0` events to be rejected. `Live` now carries a `lifecycle: Arc<RwLock<bool>>`; drain threads hold a **shared read guard** from the admission check through the `(self.emit)(...)` call, making the check-then-emit pair atomic with respect to shutdown. `InstallReporter::drop` takes the **exclusive write guard** and stores `false` — this blocks until every in-flight drain publication releases its read guard, then prevents any new admission. Deactivation is bounded: the write lock holds only for the flag store, so it can block at most for the duration of one emit call (microseconds to low milliseconds). Rust drops locals in reverse-declaration order, so `reporter` drops before `_guard`, ensuring the exclusive write completes before the per-runtime concurrency guard releases and a new install can start. ## Also Install result types move to `desktop/src/shared/api/installTypes.ts`, following the existing `searchTypes.ts` / `workflowTypes.ts` convention, and are re-exported from `tauri.ts` and `types.ts` — both already over the file-size cap, so neither can grow to carry them. Two comments described `AdapterOutdated` as applying only to the deprecated package; it also covers a version below the supported floor. Report: #2401 --------- Signed-off-by: Will Pfleger <pfleger.will@gmail.com> Signed-off-by: npub1mn7jgtj4w2pd0g0zeuhxsa6jy6p0rewxz4kujt98my82ahfmp72sxjexk7 <dcfd242e557282d7a1e2cf2e6877522682f1e5c6156dc92ca7d90eaedd3b0f95@buzz.block.builderlab.xyz> Co-authored-by: npub1mn7jgtj4w2pd0g0zeuhxsa6jy6p0rewxz4kujt98my82ahfmp72sxjexk7 <dcfd242e557282d7a1e2cf2e6877522682f1e5c6156dc92ca7d90eaedd3b0f95@buzz.block.builderlab.xyz>
This commit is contained in:
Will Pfleger
@@ -236,10 +236,12 @@ pub async fn install_acp_runtime(
|
||||
// returns (Guard impl Drop) — so Phase 2's restart path runs outside
|
||||
// the guard and cannot re-enter the mutex.
|
||||
let runtime_id_clone = runtime_id.clone();
|
||||
let install_result =
|
||||
tokio::task::spawn_blocking(move || install_acp_runtime_blocking(&runtime_id_clone))
|
||||
.await
|
||||
.map_err(|e| format!("install task panicked: {e}"))??;
|
||||
let app_clone = app.clone();
|
||||
let install_result = tokio::task::spawn_blocking(move || {
|
||||
install_acp_runtime_blocking(&runtime_id_clone, &app_clone)
|
||||
})
|
||||
.await
|
||||
.map_err(|e| format!("install task panicked: {e}"))??;
|
||||
|
||||
if !install_result.success {
|
||||
return Ok(install_result);
|
||||
@@ -259,12 +261,21 @@ pub async fn install_acp_runtime(
|
||||
steps: install_result.steps,
|
||||
restarted_count,
|
||||
failed_restart_count,
|
||||
log_path: install_result.log_path,
|
||||
})
|
||||
}
|
||||
|
||||
/// Err(_) = infrastructure failure (panic, concurrency guard).
|
||||
/// Ok({success: false}) = an install step failed (stderr captured in steps).
|
||||
fn install_acp_runtime_blocking(runtime_id: &str) -> Result<InstallRuntimeResult, String> {
|
||||
///
|
||||
/// The reporter is built here rather than by the caller so this run's log
|
||||
/// session starts only once the concurrency guard is held and the runtime id is
|
||||
/// resolved to its canonical catalog form: a rejected install must not rotate a
|
||||
/// running one's log, and the log filename is derived from that id.
|
||||
fn install_acp_runtime_blocking(
|
||||
runtime_id: &str,
|
||||
app: &tauri::AppHandle,
|
||||
) -> Result<InstallRuntimeResult, String> {
|
||||
// Re-fetch the login-shell PATH so a Node.js installation that happened
|
||||
// after app launch (or after a previous failed install) is visible to this
|
||||
// run and to the subsequent discover_acp_providers call.
|
||||
@@ -297,6 +308,8 @@ fn install_acp_runtime_blocking(runtime_id: &str) -> Result<InstallRuntimeResult
|
||||
let runtime = crate::managed_agents::known_acp_runtime_exact(runtime_id)
|
||||
.ok_or_else(|| format!("unknown runtime: {runtime_id}"))?;
|
||||
|
||||
let reporter = InstallReporter::for_run(app, runtime.id);
|
||||
|
||||
let mut steps = Vec::new();
|
||||
|
||||
// Phase 1: Install CLI if missing and commands are available.
|
||||
@@ -306,16 +319,11 @@ fn install_acp_runtime_blocking(runtime_id: &str) -> Result<InstallRuntimeResult
|
||||
if let Some(cli) = runtime.underlying_cli {
|
||||
if crate::managed_agents::resolve_command(cli).is_none() {
|
||||
for cmd in runtime.cli_install_commands_for_os() {
|
||||
let result = run_install_command_with_retry("cli", cmd);
|
||||
let result = run_install_command_with_retry("cli", cmd, &reporter);
|
||||
let success = result.success;
|
||||
steps.push(result);
|
||||
if !success {
|
||||
return Ok(InstallRuntimeResult {
|
||||
success: false,
|
||||
steps,
|
||||
restarted_count: 0,
|
||||
failed_restart_count: 0,
|
||||
});
|
||||
return Ok(reporter.failed(steps));
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -340,13 +348,8 @@ fn install_acp_runtime_blocking(runtime_id: &str) -> Result<InstallRuntimeResult
|
||||
cmds.iter().any(|cmd| is_npm_global_install(cmd)) && managed_node_runtime_supported();
|
||||
if use_managed_npm {
|
||||
if let Err(step) = ensure_managed_node_runtime_blocking() {
|
||||
steps.push(*step);
|
||||
return Ok(InstallRuntimeResult {
|
||||
success: false,
|
||||
steps,
|
||||
restarted_count: 0,
|
||||
failed_restart_count: 0,
|
||||
});
|
||||
reporter.record_step(&mut steps, *step);
|
||||
return Ok(reporter.failed(steps));
|
||||
}
|
||||
}
|
||||
|
||||
@@ -359,40 +362,31 @@ fn install_acp_runtime_blocking(runtime_id: &str) -> Result<InstallRuntimeResult
|
||||
Ok(Some(command)) => command,
|
||||
Ok(None) => cmd.to_string(),
|
||||
Err(step) => {
|
||||
steps.push(*step);
|
||||
return Ok(InstallRuntimeResult {
|
||||
success: false,
|
||||
steps,
|
||||
restarted_count: 0,
|
||||
failed_restart_count: 0,
|
||||
});
|
||||
reporter.record_step(&mut steps, *step);
|
||||
return Ok(reporter.failed(steps));
|
||||
}
|
||||
};
|
||||
|
||||
let mut result = run_install_command_with_retry("adapter", &planned);
|
||||
let mut result = run_install_command_with_retry("adapter", &planned, &reporter);
|
||||
if !result.success && result.hint.is_none() && is_npm_global_install(cmd) {
|
||||
result.hint = npm_eacces_hint(&result.stderr, cmd);
|
||||
}
|
||||
let success = result.success;
|
||||
steps.push(result);
|
||||
if !success {
|
||||
return Ok(InstallRuntimeResult {
|
||||
success: false,
|
||||
steps,
|
||||
restarted_count: 0,
|
||||
failed_restart_count: 0,
|
||||
});
|
||||
return Ok(reporter.failed(steps));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
post_install_verification::run(runtime_id, &mut steps);
|
||||
post_install_verification::run(runtime_id, &mut steps, &reporter);
|
||||
|
||||
Ok(InstallRuntimeResult {
|
||||
success: steps.iter().all(|step| step.success),
|
||||
steps,
|
||||
restarted_count: 0,
|
||||
failed_restart_count: 0,
|
||||
log_path: reporter.log_path(),
|
||||
})
|
||||
}
|
||||
|
||||
@@ -1016,8 +1010,11 @@ fn build_install_command(command: &str) -> Result<std::process::Command, String>
|
||||
}
|
||||
|
||||
// ── install command execution ─────────────────────────────────────────────────
|
||||
mod install_capture;
|
||||
mod install_exec;
|
||||
mod install_report;
|
||||
use install_exec::run_install_command_with_retry;
|
||||
use install_report::InstallReporter;
|
||||
|
||||
// ── managed Node/npm runtime ──────────────────────────────────────────────────
|
||||
mod managed_node;
|
||||
|
||||
@@ -0,0 +1,319 @@
|
||||
//! Bounded capture of an install command's output.
|
||||
//!
|
||||
//! One drain per stream feeds a [`Capture`], which holds two independently
|
||||
//! bounded views of the same bytes: a small one sized for an error toast and a
|
||||
//! large one sized for the install log file. Both are shared with the draining
|
||||
//! reader rather than returned by it, so whatever arrived before a stall is
|
||||
//! readable at the ceiling — exactly when the output matters most.
|
||||
|
||||
use std::collections::VecDeque;
|
||||
use std::io::Read;
|
||||
use std::sync::{Arc, Mutex};
|
||||
use std::time::{Duration, Instant};
|
||||
|
||||
/// How much of each end a capture keeps, and how it names what was cut.
|
||||
#[derive(Clone, Copy)]
|
||||
struct Caps {
|
||||
head: usize,
|
||||
tail: usize,
|
||||
marker: fn(usize) -> String,
|
||||
}
|
||||
|
||||
/// Sized for a UI error message: enough to identify the failure, small enough
|
||||
/// to read in a toast.
|
||||
const UI_CAPS: Caps = Caps {
|
||||
head: 512,
|
||||
tail: 1024,
|
||||
marker: |omitted| format!("... ({omitted} bytes omitted) ..."),
|
||||
};
|
||||
|
||||
/// Sized for the log file, where the budget is disk rather than screen. At this
|
||||
/// cap a real install log is complete in practice; the marker names the cases
|
||||
/// where it is not, so the file never implies completeness it does not have.
|
||||
const LOG_CAPS: Caps = Caps {
|
||||
head: 128 * 1024,
|
||||
tail: 128 * 1024,
|
||||
marker: |omitted| format!("... [{omitted} bytes omitted at cap] ..."),
|
||||
};
|
||||
|
||||
/// Bounded capture of one stream: its first `head` bytes, its last `tail`
|
||||
/// bytes, and the total byte count. Output of any size costs a fixed amount of
|
||||
/// memory, so an installer that prints megabytes cannot grow the process.
|
||||
struct BoundedOutput {
|
||||
head: Vec<u8>,
|
||||
tail: VecDeque<u8>,
|
||||
total: usize,
|
||||
caps: Caps,
|
||||
}
|
||||
|
||||
type SharedOutput = Arc<Mutex<BoundedOutput>>;
|
||||
|
||||
impl BoundedOutput {
|
||||
fn shared(caps: Caps) -> SharedOutput {
|
||||
Arc::new(Mutex::new(Self {
|
||||
head: Vec::new(),
|
||||
tail: VecDeque::new(),
|
||||
total: 0,
|
||||
caps,
|
||||
}))
|
||||
}
|
||||
|
||||
/// Absorb one read. Chunk boundaries are irrelevant to the result: the head
|
||||
/// fills first, the remainder rolls through the tail window.
|
||||
fn push(&mut self, chunk: &[u8]) {
|
||||
self.total += chunk.len();
|
||||
let head_room = self
|
||||
.caps
|
||||
.head
|
||||
.saturating_sub(self.head.len())
|
||||
.min(chunk.len());
|
||||
let (head_part, tail_part) = chunk.split_at(head_room);
|
||||
self.head.extend_from_slice(head_part);
|
||||
self.tail.extend(tail_part);
|
||||
while self.tail.len() > self.caps.tail {
|
||||
self.tail.pop_front();
|
||||
}
|
||||
}
|
||||
|
||||
fn render(&self) -> String {
|
||||
let tail: Vec<u8> = self.tail.iter().copied().collect();
|
||||
if self.total <= self.caps.head + self.caps.tail {
|
||||
// Nothing was dropped, so head followed by tail is the whole stream.
|
||||
let mut whole = self.head.clone();
|
||||
whole.extend_from_slice(&tail);
|
||||
return decode(&whole);
|
||||
}
|
||||
// Both ends are cut at arbitrary byte offsets, so trim any partial
|
||||
// character rather than emitting replacement chars, then drop the
|
||||
// partial *token* each cut left behind. The marker counts every dropped
|
||||
// byte, including both trims.
|
||||
let head = erode_head(utf8_prefix(&self.head));
|
||||
let tail = erode_tail(utf8_suffix(&tail));
|
||||
let omitted = self.total - head.len() - tail.len();
|
||||
format!(
|
||||
"{}\n{}\n{}",
|
||||
decode(head),
|
||||
(self.caps.marker)(omitted),
|
||||
decode(tail)
|
||||
)
|
||||
}
|
||||
}
|
||||
|
||||
/// The two bounded views of one stream, filled by a single drain.
|
||||
pub(super) struct Capture {
|
||||
ui: SharedOutput,
|
||||
log: SharedOutput,
|
||||
}
|
||||
|
||||
impl Capture {
|
||||
pub(super) fn new() -> Self {
|
||||
Self {
|
||||
ui: BoundedOutput::shared(UI_CAPS),
|
||||
log: BoundedOutput::shared(LOG_CAPS),
|
||||
}
|
||||
}
|
||||
|
||||
/// What the UI shows for this stream.
|
||||
pub(super) fn ui(&self) -> String {
|
||||
render(&self.ui)
|
||||
}
|
||||
|
||||
/// What the install log records for this stream.
|
||||
pub(super) fn log(&self) -> String {
|
||||
render(&self.log)
|
||||
}
|
||||
|
||||
fn push(&self, chunk: &[u8]) {
|
||||
for sink in [&self.ui, &self.log] {
|
||||
if let Ok(mut sink) = sink.lock() {
|
||||
sink.push(chunk);
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// Called with each complete line an install prints, for the live output line
|
||||
/// in the UI. Shared across both drain threads of one attempt.
|
||||
pub(super) type LineObserver = Arc<dyn Fn(&str) + Send + Sync>;
|
||||
|
||||
/// Render a capture even if its drain thread panicked mid-write — a poisoned
|
||||
/// lock must not cost the diagnostics.
|
||||
fn render(sink: &SharedOutput) -> String {
|
||||
sink.lock().unwrap_or_else(|p| p.into_inner()).render()
|
||||
}
|
||||
|
||||
/// Read `pipe` to EOF, feeding fixed-size chunks into `capture` and each
|
||||
/// complete line to `observer`. Read errors end the drain — a broken pipe means
|
||||
/// the child is gone and there is nothing left to capture.
|
||||
pub(super) fn drain_into(mut pipe: impl Read, capture: &Capture, observer: Option<&LineObserver>) {
|
||||
let mut chunk = [0u8; 8192];
|
||||
let mut lines = LineSplitter::default();
|
||||
loop {
|
||||
match pipe.read(&mut chunk) {
|
||||
Ok(0) => return,
|
||||
Ok(n) => {
|
||||
capture.push(&chunk[..n]);
|
||||
if let Some(observe) = observer {
|
||||
lines.feed(&chunk[..n], |line| observe(line));
|
||||
}
|
||||
}
|
||||
Err(e) if e.kind() == std::io::ErrorKind::Interrupted => continue,
|
||||
Err(_) => return,
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// Reassembles lines from arbitrary read chunks. A partial trailing line is
|
||||
/// held until its newline arrives, so an observer only ever sees complete
|
||||
/// lines. The buffer is capped: a program that prints megabytes without a
|
||||
/// newline must not grow it without bound.
|
||||
#[derive(Default)]
|
||||
struct LineSplitter {
|
||||
partial: Vec<u8>,
|
||||
}
|
||||
|
||||
impl LineSplitter {
|
||||
/// Longest line reassembled. Beyond this the excess is dropped, since the
|
||||
/// consumer displays a single truncated line anyway.
|
||||
const MAX_LINE: usize = 4096;
|
||||
|
||||
fn feed(&mut self, chunk: &[u8], mut emit: impl FnMut(&str)) {
|
||||
for byte in chunk {
|
||||
if *byte == b'\n' {
|
||||
let line = String::from_utf8_lossy(&self.partial).trim().to_string();
|
||||
self.partial.clear();
|
||||
if !line.is_empty() {
|
||||
emit(&line);
|
||||
}
|
||||
} else if self.partial.len() < Self::MAX_LINE {
|
||||
self.partial.push(*byte);
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// Rate limiter for the live output line: at most one event per
|
||||
/// `min_interval`.
|
||||
///
|
||||
/// A line arriving inside the window is *held* rather than dropped, and the
|
||||
/// newest held line replaces any older one. Dropping was wrong at two points:
|
||||
/// the last line of an attempt — typically the failure that caused the retry —
|
||||
/// vanished if it landed inside the window, and so did a new attempt's first
|
||||
/// line when it arrived within 250ms of the previous attempt's last.
|
||||
pub(super) struct Throttle {
|
||||
min_interval: Duration,
|
||||
state: Mutex<ThrottleState>,
|
||||
}
|
||||
|
||||
#[derive(Default)]
|
||||
struct ThrottleState {
|
||||
last_emitted: Option<Instant>,
|
||||
pending: Option<String>,
|
||||
}
|
||||
|
||||
impl Throttle {
|
||||
pub(super) fn new(min_interval: Duration) -> Self {
|
||||
Self {
|
||||
min_interval,
|
||||
state: Mutex::new(ThrottleState::default()),
|
||||
}
|
||||
}
|
||||
|
||||
/// Offer one line. `Some` means emit it now; `None` means it is held as the
|
||||
/// newest pending line, to be emitted by [`Throttle::take_pending`] or
|
||||
/// replaced by a line that supersedes it.
|
||||
pub(super) fn offer(&self, line: &str, now: Instant) -> Option<String> {
|
||||
let Ok(mut state) = self.state.lock() else {
|
||||
return None;
|
||||
};
|
||||
if state
|
||||
.last_emitted
|
||||
.is_some_and(|prev| now.duration_since(prev) < self.min_interval)
|
||||
{
|
||||
state.pending = Some(line.to_string());
|
||||
return None;
|
||||
}
|
||||
state.last_emitted = Some(now);
|
||||
// Emitting a newer line makes the held one obsolete: the display shows
|
||||
// one line, and it must be the latest.
|
||||
state.pending = None;
|
||||
Some(line.to_string())
|
||||
}
|
||||
|
||||
/// Take the held line, if the window closed on one.
|
||||
pub(super) fn take_pending(&self) -> Option<String> {
|
||||
self.state.lock().ok()?.pending.take()
|
||||
}
|
||||
|
||||
/// Open the window for a new attempt, so its first line is emitted
|
||||
/// immediately instead of waiting out the previous attempt's window.
|
||||
pub(super) fn restart(&self) {
|
||||
if let Ok(mut state) = self.state.lock() {
|
||||
*state = ThrottleState::default();
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
fn decode(bytes: &[u8]) -> String {
|
||||
String::from_utf8_lossy(bytes).into_owned()
|
||||
}
|
||||
|
||||
/// Drop a trailing partial UTF-8 sequence, keeping mid-stream invalid bytes for
|
||||
/// the lossy decode to mark.
|
||||
fn utf8_prefix(bytes: &[u8]) -> &[u8] {
|
||||
match std::str::from_utf8(bytes) {
|
||||
Ok(_) => bytes,
|
||||
Err(e) if e.error_len().is_none() => &bytes[..e.valid_up_to()],
|
||||
Err(_) => bytes,
|
||||
}
|
||||
}
|
||||
|
||||
/// Drop leading UTF-8 continuation bytes — at most three can precede a
|
||||
/// character start.
|
||||
fn utf8_suffix(bytes: &[u8]) -> &[u8] {
|
||||
let start = bytes
|
||||
.iter()
|
||||
.take(3)
|
||||
.take_while(|b| *b & 0b1100_0000 == 0b1000_0000)
|
||||
.count();
|
||||
&bytes[start..]
|
||||
}
|
||||
|
||||
/// How far a cut edge looks for a token boundary. Sized past any credential
|
||||
/// shape worth protecting (an `nsec1` key is 63 bytes, registry tokens are
|
||||
/// shorter) and short enough that erosion costs a token rather than a chunk of
|
||||
/// output. A cut inside a longer whitespace-free run is left alone: erasing
|
||||
/// kilobytes of a single-token stream would cost more diagnostics than the
|
||||
/// fragment could leak.
|
||||
const MAX_ERODED_TOKEN: usize = 256;
|
||||
|
||||
/// Drop the partial token a head cut left at its end.
|
||||
///
|
||||
/// Redaction runs on the rendered text and matches whole tokens: a prefixed
|
||||
/// secret up to the next whitespace, or an exact env value. A cut through the
|
||||
/// middle of a secret leaves a fragment that matches neither and therefore
|
||||
/// survives scrubbing, so the fragment is removed here instead — at the cut,
|
||||
/// where it is still identifiable as partial. The omitted-byte marker counts
|
||||
/// what this drops.
|
||||
fn erode_head(bytes: &[u8]) -> &[u8] {
|
||||
let window = bytes.len().saturating_sub(MAX_ERODED_TOKEN);
|
||||
match bytes[window..].iter().rposition(u8::is_ascii_whitespace) {
|
||||
Some(last) => &bytes[..=window + last],
|
||||
None => bytes,
|
||||
}
|
||||
}
|
||||
|
||||
/// Drop the partial token a tail cut left at its start — the direction that
|
||||
/// matters most, since a fragment there has lost the `nsec1`-style prefix the
|
||||
/// scrubber keys on. See [`erode_head`].
|
||||
fn erode_tail(bytes: &[u8]) -> &[u8] {
|
||||
let window = MAX_ERODED_TOKEN.min(bytes.len());
|
||||
match bytes[..window].iter().position(u8::is_ascii_whitespace) {
|
||||
Some(first) => &bytes[first..],
|
||||
None => bytes,
|
||||
}
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
#[path = "install_capture_tests.rs"]
|
||||
mod tests;
|
||||
@@ -0,0 +1,437 @@
|
||||
use super::*;
|
||||
|
||||
/// Feed `chunks` through a capture in order.
|
||||
fn capture_of(chunks: &[&[u8]]) -> Capture {
|
||||
let capture = Capture::new();
|
||||
for chunk in chunks {
|
||||
capture.push(chunk);
|
||||
}
|
||||
capture
|
||||
}
|
||||
|
||||
/// Render what the UI would show for a stream of `chunks`.
|
||||
fn ui(chunks: &[&[u8]]) -> String {
|
||||
capture_of(chunks).ui()
|
||||
}
|
||||
|
||||
// ── bounded capture ──────────────────────────────────────────────────────────
|
||||
|
||||
/// Output within the cap is passed through byte-for-byte — no marker, no loss.
|
||||
#[test]
|
||||
fn test_capture_leaves_short_output_untouched() {
|
||||
let short = "a".repeat(1536);
|
||||
|
||||
assert_eq!(ui(&[short.as_bytes()]), short);
|
||||
}
|
||||
|
||||
/// Over the cap, both ends survive and the middle is replaced by a marker
|
||||
/// naming the omitted byte count — the head keeps the command's opening
|
||||
/// context and the tail keeps the error that usually trails.
|
||||
#[test]
|
||||
fn test_capture_over_cap_keeps_head_and_tail_with_marker() {
|
||||
let input = format!(
|
||||
"{}{}{}",
|
||||
"H".repeat(512),
|
||||
"M".repeat(4000),
|
||||
"T".repeat(1024)
|
||||
);
|
||||
|
||||
let out = ui(&[input.as_bytes()]);
|
||||
|
||||
assert!(out.starts_with(&"H".repeat(512)));
|
||||
assert!(out.ends_with(&"T".repeat(1024)));
|
||||
assert!(
|
||||
out.contains("... (4000 bytes omitted) ..."),
|
||||
"marker must name the omitted byte count, got: {out}"
|
||||
);
|
||||
}
|
||||
|
||||
/// The rendered result depends only on the byte stream, not on how the reads
|
||||
/// happened to split it — a real drain sees arbitrary chunk sizes.
|
||||
#[test]
|
||||
fn test_capture_is_independent_of_chunk_boundaries() {
|
||||
let input = "x".repeat(9000);
|
||||
let one_shot = ui(&[input.as_bytes()]);
|
||||
|
||||
let chunked: Vec<&[u8]> = input.as_bytes().chunks(7).collect();
|
||||
|
||||
assert_eq!(ui(&chunked), one_shot);
|
||||
}
|
||||
|
||||
/// Truncation must not split a multi-byte character. Both cut points land
|
||||
/// mid-codepoint here; the partial bytes are dropped rather than decoded into
|
||||
/// replacement chars.
|
||||
#[test]
|
||||
fn test_capture_does_not_split_multibyte_characters() {
|
||||
// "é" is 2 bytes, so every candidate cut index lands mid-character.
|
||||
let input = "é".repeat(4000);
|
||||
|
||||
let out = ui(&[input.as_bytes()]);
|
||||
|
||||
assert!(out.contains("bytes omitted"), "input must exceed the cap");
|
||||
assert!(!out.contains('\u{fffd}'), "no replacement chars: {out}");
|
||||
}
|
||||
|
||||
/// Memory stays flat regardless of how much the installer prints: the rendered
|
||||
/// UI result of a 4MiB stream is no larger than that of a 6KiB one.
|
||||
#[test]
|
||||
fn test_capture_of_huge_output_stays_bounded() {
|
||||
let chunk = vec![b'z'; 8192];
|
||||
|
||||
let capture = Capture::new();
|
||||
for _ in 0..512 {
|
||||
capture.push(&chunk);
|
||||
}
|
||||
|
||||
let out = capture.ui();
|
||||
assert!(
|
||||
out.len() < 2048,
|
||||
"4MiB of output must render bounded, got {} bytes",
|
||||
out.len()
|
||||
);
|
||||
assert!(out.contains("bytes omitted"));
|
||||
}
|
||||
|
||||
// ── the log view is separately bounded ───────────────────────────────────────
|
||||
|
||||
/// The log view holds output the UI view had to cut. A toast is capped for
|
||||
/// readability; the log file's budget is disk, and "Full log: {path}" has to
|
||||
/// point at more than the toast already showed.
|
||||
#[test]
|
||||
fn test_log_view_keeps_output_the_ui_view_truncates() {
|
||||
let input = format!("start{}end", "m".repeat(64 * 1024));
|
||||
|
||||
let capture = capture_of(&[input.as_bytes()]);
|
||||
|
||||
assert!(
|
||||
capture.ui().contains("bytes omitted"),
|
||||
"64KiB must exceed the UI cap"
|
||||
);
|
||||
assert_eq!(
|
||||
capture.log(),
|
||||
input,
|
||||
"the same output must be complete in the log view"
|
||||
);
|
||||
}
|
||||
|
||||
/// Even the log view is bounded — a runaway installer cannot fill the disk —
|
||||
/// and when it does cut, the record says so inline at the cap rather than
|
||||
/// implying completeness.
|
||||
#[test]
|
||||
fn test_log_view_is_bounded_and_marks_its_cap() {
|
||||
let head = "H".repeat(128 * 1024);
|
||||
let middle = "M".repeat(5000);
|
||||
let tail = "T".repeat(128 * 1024);
|
||||
let input = format!("{head}{middle}{tail}");
|
||||
|
||||
let capture = capture_of(&[input.as_bytes()]);
|
||||
|
||||
let out = capture.log();
|
||||
assert!(
|
||||
out.len() < 300 * 1024,
|
||||
"output past the log cap must render bounded, got {} bytes",
|
||||
out.len()
|
||||
);
|
||||
assert!(out.starts_with(&head), "the log head must survive intact");
|
||||
assert!(out.ends_with(&tail), "the log tail must survive intact");
|
||||
assert!(
|
||||
out.contains("... [5000 bytes omitted at cap] ..."),
|
||||
"a cut log record must name the cap inline, got the middle: {}",
|
||||
&out[128 * 1024..(128 * 1024 + 64).min(out.len())]
|
||||
);
|
||||
}
|
||||
|
||||
/// The two views mark their cuts differently on purpose: the toast reads as
|
||||
/// prose, the log record reads as a machine-scannable annotation.
|
||||
#[test]
|
||||
fn test_ui_and_log_views_use_their_own_cap_markers() {
|
||||
let input = "x".repeat(300 * 1024);
|
||||
|
||||
let capture = capture_of(&[input.as_bytes()]);
|
||||
|
||||
assert!(
|
||||
capture.ui().contains("bytes omitted) ..."),
|
||||
"the UI marker reads as prose: {}",
|
||||
capture.ui()
|
||||
);
|
||||
assert!(capture.log().contains("bytes omitted at cap] ..."));
|
||||
}
|
||||
|
||||
// ── line observation ─────────────────────────────────────────────────────────
|
||||
|
||||
/// Collect the lines a drain over `chunks` reports.
|
||||
fn observed_lines(chunks: &[&[u8]]) -> Vec<String> {
|
||||
let seen: Arc<Mutex<Vec<String>>> = Arc::new(Mutex::new(Vec::new()));
|
||||
let observer: LineObserver = {
|
||||
let seen = Arc::clone(&seen);
|
||||
Arc::new(move |line: &str| seen.lock().unwrap().push(line.to_string()))
|
||||
};
|
||||
let bytes: Vec<u8> = chunks.concat();
|
||||
|
||||
drain_into(bytes.as_slice(), &Capture::new(), Some(&observer));
|
||||
|
||||
let observed = seen.lock().unwrap().clone();
|
||||
observed
|
||||
}
|
||||
|
||||
/// The observer sees complete lines, reassembled across the read boundaries
|
||||
/// that split them — a live output line must never show half a word.
|
||||
#[test]
|
||||
fn test_observer_reassembles_lines_split_across_reads() {
|
||||
let lines = observed_lines(&[b"downloa", b"ding 40%\nunpack", b"ing\n"]);
|
||||
|
||||
assert_eq!(lines, vec!["downloading 40%", "unpacking"]);
|
||||
}
|
||||
|
||||
/// A trailing line with no newline is never reported: it may still be growing,
|
||||
/// and showing a half-line as if complete is worse than showing the previous
|
||||
/// one.
|
||||
#[test]
|
||||
fn test_observer_withholds_a_line_that_has_no_newline_yet() {
|
||||
let lines = observed_lines(&[b"complete\n", b"still-writing"]);
|
||||
|
||||
assert_eq!(lines, vec!["complete"]);
|
||||
}
|
||||
|
||||
/// Blank lines carry nothing to display; progress output is full of them.
|
||||
#[test]
|
||||
fn test_observer_skips_blank_lines() {
|
||||
let lines = observed_lines(&[b"a\n\n \nb\n"]);
|
||||
|
||||
assert_eq!(lines, vec!["a", "b"]);
|
||||
}
|
||||
|
||||
/// A pathological line with no newline must not grow the buffer without bound.
|
||||
#[test]
|
||||
fn test_observer_caps_a_pathologically_long_line() {
|
||||
let huge = "x".repeat(100_000);
|
||||
|
||||
let lines = observed_lines(&[huge.as_bytes(), b"\n"]);
|
||||
|
||||
assert_eq!(lines.len(), 1);
|
||||
assert!(
|
||||
lines[0].len() <= LineSplitter::MAX_LINE,
|
||||
"line must be capped, got {} bytes",
|
||||
lines[0].len()
|
||||
);
|
||||
}
|
||||
|
||||
/// A drain with no observer still captures — the log and UI views do not
|
||||
/// depend on anyone watching.
|
||||
#[test]
|
||||
fn test_drain_captures_without_an_observer() {
|
||||
let capture = Capture::new();
|
||||
|
||||
drain_into(b"hello\n".as_slice(), &capture, None);
|
||||
|
||||
assert_eq!(capture.ui(), "hello\n");
|
||||
}
|
||||
|
||||
// ── throttle ─────────────────────────────────────────────────────────────────
|
||||
|
||||
/// The first line goes out immediately, and one arriving inside the window is
|
||||
/// *held* rather than dropped: it becomes the pending line, so the newest output
|
||||
/// survives the rate limit instead of vanishing.
|
||||
#[test]
|
||||
fn test_throttle_emits_the_first_line_and_holds_the_next_in_window() {
|
||||
let throttle = Throttle::new(Duration::from_millis(250));
|
||||
let start = Instant::now();
|
||||
|
||||
assert_eq!(throttle.offer("first", start), Some("first".to_string()));
|
||||
assert_eq!(
|
||||
throttle.offer("second", start + Duration::from_millis(100)),
|
||||
None
|
||||
);
|
||||
assert_eq!(
|
||||
throttle.take_pending(),
|
||||
Some("second".to_string()),
|
||||
"the line inside the window must be retained, not dropped"
|
||||
);
|
||||
}
|
||||
|
||||
/// A burst inside one window collapses to its newest line: the display shows a
|
||||
/// single line, so an older held line has no value once a newer one exists.
|
||||
#[test]
|
||||
fn test_throttle_keeps_only_the_newest_held_line() {
|
||||
let throttle = Throttle::new(Duration::from_millis(250));
|
||||
let start = Instant::now();
|
||||
throttle.offer("emitted", start);
|
||||
|
||||
throttle.offer("held-then-superseded", start + Duration::from_millis(50));
|
||||
throttle.offer("newest", start + Duration::from_millis(100));
|
||||
|
||||
assert_eq!(throttle.take_pending(), Some("newest".to_string()));
|
||||
}
|
||||
|
||||
/// Once the window passes, emission resumes and nothing is left pending — the
|
||||
/// emitted line *is* the newest, so holding it too would emit it twice.
|
||||
#[test]
|
||||
fn test_throttle_emits_again_after_the_window_and_clears_the_held_line() {
|
||||
let throttle = Throttle::new(Duration::from_millis(250));
|
||||
let start = Instant::now();
|
||||
throttle.offer("first", start);
|
||||
throttle.offer("held", start + Duration::from_millis(50));
|
||||
|
||||
assert_eq!(
|
||||
throttle.offer("later", start + Duration::from_millis(300)),
|
||||
Some("later".to_string())
|
||||
);
|
||||
|
||||
assert_eq!(
|
||||
throttle.take_pending(),
|
||||
None,
|
||||
"a line emitted after the window supersedes the held one"
|
||||
);
|
||||
}
|
||||
|
||||
/// The window is measured from the last *emitted* line, not the last offer: a
|
||||
/// stream of held lines must not extend the silence.
|
||||
#[test]
|
||||
fn test_throttle_window_runs_from_the_last_emission() {
|
||||
let throttle = Throttle::new(Duration::from_millis(250));
|
||||
let start = Instant::now();
|
||||
throttle.offer("first", start);
|
||||
|
||||
assert_eq!(
|
||||
throttle.offer("held", start + Duration::from_millis(200)),
|
||||
None
|
||||
);
|
||||
|
||||
assert_eq!(
|
||||
throttle.offer("next", start + Duration::from_millis(260)),
|
||||
Some("next".to_string()),
|
||||
"a held line must not restart the window"
|
||||
);
|
||||
}
|
||||
|
||||
/// A pending line is taken once. Taking it twice would re-emit a line the
|
||||
/// display already shows.
|
||||
#[test]
|
||||
fn test_throttle_yields_a_held_line_only_once() {
|
||||
let throttle = Throttle::new(Duration::from_millis(250));
|
||||
let start = Instant::now();
|
||||
throttle.offer("first", start);
|
||||
throttle.offer("held", start + Duration::from_millis(50));
|
||||
|
||||
assert_eq!(throttle.take_pending(), Some("held".to_string()));
|
||||
|
||||
assert_eq!(throttle.take_pending(), None);
|
||||
}
|
||||
|
||||
/// Restarting opens the window immediately, which is what lets a new attempt's
|
||||
/// first line go out even when it arrives inside the previous attempt's window.
|
||||
/// It also discards a held line: that line belongs to the attempt that just
|
||||
/// ended, and the new attempt is about to clear the display.
|
||||
#[test]
|
||||
fn test_throttle_restart_opens_the_window_and_discards_the_held_line() {
|
||||
let throttle = Throttle::new(Duration::from_millis(250));
|
||||
let start = Instant::now();
|
||||
throttle.offer("previous attempt", start);
|
||||
throttle.offer("held", start + Duration::from_millis(10));
|
||||
|
||||
throttle.restart();
|
||||
|
||||
assert_eq!(throttle.take_pending(), None);
|
||||
assert_eq!(
|
||||
throttle.offer("new attempt", start + Duration::from_millis(20)),
|
||||
Some("new attempt".to_string())
|
||||
);
|
||||
}
|
||||
|
||||
// ── cut-edge erosion ─────────────────────────────────────────────────────────
|
||||
|
||||
/// A secret cut in half by the head cap must not survive as a fragment.
|
||||
/// Redaction matches whole tokens — a prefixed secret up to the next whitespace
|
||||
/// — so `nsec1qqq…` cut mid-value would still be scrubbed, but the *tail* of
|
||||
/// that same value, having lost its prefix, would not be. Both cut edges drop
|
||||
/// their partial token for that reason.
|
||||
#[test]
|
||||
fn test_capture_drops_the_partial_token_at_each_cut_edge() {
|
||||
// Positioned so the head cap lands inside the first secret and the tail cap
|
||||
// inside the second.
|
||||
let head_secret = "nsec1headsecretvalue";
|
||||
let tail_secret = "nsec1tailsecretvalue";
|
||||
let input = format!(
|
||||
"{} {head_secret} {} {tail_secret} {}",
|
||||
"h".repeat(500),
|
||||
"m".repeat(4000),
|
||||
"t".repeat(1010)
|
||||
);
|
||||
|
||||
let out = ui(&[input.as_bytes()]);
|
||||
|
||||
assert!(out.contains("bytes omitted"), "input must exceed the cap");
|
||||
for fragment in ["nsec1head", "secretvalue"] {
|
||||
assert!(
|
||||
!out.contains(fragment),
|
||||
"a fragment of a cut token must not survive: {out}"
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
/// Erosion stops at the nearest whitespace, so it costs one partial token and
|
||||
/// not the surrounding output — the head's earlier lines and the tail's later
|
||||
/// ones are what make a truncated capture readable.
|
||||
#[test]
|
||||
fn test_capture_erosion_keeps_the_complete_tokens_around_the_cut() {
|
||||
let input = format!(
|
||||
"opening line
|
||||
{}
|
||||
cut-here-head{}cut-here-tail
|
||||
{}
|
||||
closing line
|
||||
",
|
||||
"h".repeat(480),
|
||||
"m".repeat(4000),
|
||||
"t".repeat(980)
|
||||
);
|
||||
|
||||
let out = ui(&[input.as_bytes()]);
|
||||
|
||||
assert!(out.starts_with("opening line\n"), "got: {out}");
|
||||
assert!(out.ends_with("closing line\n"), "got: {out}");
|
||||
}
|
||||
|
||||
/// A cut inside a whitespace-free run longer than the erosion window is left
|
||||
/// intact. Erosion is bounded on purpose: erasing kilobytes of a single-token
|
||||
/// stream — `npm` progress bars and base64 payloads both look like this — would
|
||||
/// cost more diagnostics than a fragment of one could leak.
|
||||
#[test]
|
||||
fn test_capture_of_one_giant_token_keeps_its_cut_edges() {
|
||||
let input = "x".repeat(4000);
|
||||
|
||||
let out = ui(&[input.as_bytes()]);
|
||||
|
||||
assert!(out.starts_with(&"x".repeat(512)), "got: {out}");
|
||||
assert!(out.ends_with(&"x".repeat(1024)), "got: {out}");
|
||||
}
|
||||
|
||||
/// The marker's byte count stays honest across erosion: what it names as omitted
|
||||
/// must equal the input minus what is actually shown, or a reader cannot trust
|
||||
/// the file to say how much is missing.
|
||||
#[test]
|
||||
fn test_capture_marker_counts_the_bytes_erosion_dropped() {
|
||||
let input = format!(
|
||||
"{} {} {}",
|
||||
"h".repeat(600),
|
||||
"m".repeat(4000),
|
||||
"t".repeat(1100)
|
||||
);
|
||||
|
||||
let out = ui(&[input.as_bytes()]);
|
||||
|
||||
let (head, rest) = out.split_once('\n').expect("a marker line");
|
||||
let (marker, tail) = rest.split_once('\n').expect("a marker line");
|
||||
let omitted: usize = marker
|
||||
.trim_start_matches("... (")
|
||||
.split_once(' ')
|
||||
.expect("a byte count")
|
||||
.0
|
||||
.parse()
|
||||
.expect("a byte count");
|
||||
assert_eq!(
|
||||
head.len() + omitted + tail.len(),
|
||||
input.len(),
|
||||
"shown + omitted must account for every input byte"
|
||||
);
|
||||
}
|
||||
@@ -5,13 +5,46 @@
|
||||
//! `install_powershell_command`, `build_install_command`); this module owns
|
||||
//! only what happens once a `Command` exists.
|
||||
|
||||
use std::io::Read;
|
||||
use std::sync::Arc;
|
||||
use std::time::{Duration, Instant};
|
||||
|
||||
use super::install_capture::{drain_into, Capture, LineObserver};
|
||||
use super::install_report::{InstallOutcome, InstallReporter};
|
||||
use crate::managed_agents::InstallStepResult;
|
||||
|
||||
/// Maximum number of attempts for a transient-looking install command.
|
||||
const INSTALL_MAX_ATTEMPTS: u32 = 3;
|
||||
|
||||
/// Absolute wall-clock ceiling for a single install command.
|
||||
///
|
||||
/// This is a ceiling, not an inactivity timeout: nothing observable
|
||||
/// distinguishes a hung installer from one silently transferring a large
|
||||
/// artifact (the Goose step downloads a ~79MB release asset with no progress
|
||||
/// output, and npm at its default log level prints only at the end), so silence
|
||||
/// alone never kills an install. The previous 300s wall killed
|
||||
/// slow-but-working installs — Windows Defender scanning every file npm
|
||||
/// extracts pushes past it routinely (#2401).
|
||||
///
|
||||
/// The cost of a larger ceiling: skipping onboarding does not cancel a running
|
||||
/// install and a per-runtime guard rejects a second one, so this is also the
|
||||
/// longest a user who skipped a genuinely *hung* install waits before Install
|
||||
/// works again in Settings. User-facing cancellation is the product-level fix.
|
||||
const INSTALL_TIMEOUT: Duration = Duration::from_secs(900);
|
||||
|
||||
/// How long the group gets to exit on SIGTERM before the ceiling escalates to
|
||||
/// SIGKILL.
|
||||
#[cfg(unix)]
|
||||
const TERM_GRACE: Duration = Duration::from_secs(1);
|
||||
|
||||
/// How long the ceiling waits after killing the install's process group —
|
||||
/// applied separately to reaping the killed child and to the output drains
|
||||
/// finishing. The kill closes the pipe write ends, so both normally complete
|
||||
/// within microseconds; the bound covers the cases where they don't (a process
|
||||
/// that escaped the group and still holds a pipe, or a termination that failed
|
||||
/// outright). Neither may hold the install — nor the per-runtime concurrency
|
||||
/// guard behind it — open past the ceiling.
|
||||
const POST_KILL_GRACE: Duration = Duration::from_secs(2);
|
||||
|
||||
/// Run an install command, retrying transient failures with backoff.
|
||||
///
|
||||
/// Runtime installs pull artifacts over the network — Goose's `curl … | bash`
|
||||
@@ -22,10 +55,24 @@ const INSTALL_MAX_ATTEMPTS: u32 = 3;
|
||||
/// `INSTALL_MAX_ATTEMPTS` times. Failures with no exit code — a timeout or a
|
||||
/// shell that never spawned — are not retried, since re-running them just costs
|
||||
/// the user more time without a plausible path to success.
|
||||
pub(super) fn run_install_command_with_retry(step: &str, command: &str) -> InstallStepResult {
|
||||
///
|
||||
/// Every attempt is recorded through `reporter`, so the install log holds the
|
||||
/// full retry history even though the UI only ever sees the last attempt.
|
||||
pub(super) fn run_install_command_with_retry(
|
||||
step: &str,
|
||||
command: &str,
|
||||
reporter: &InstallReporter,
|
||||
) -> InstallStepResult {
|
||||
run_install_with_retry(
|
||||
INSTALL_MAX_ATTEMPTS,
|
||||
|_attempt| run_install_command(step, command),
|
||||
|attempt| {
|
||||
// Before the command spawns, so the previous attempt's last line
|
||||
// stops being displayed for the whole backoff rather than until the
|
||||
// new attempt happens to print something.
|
||||
reporter.start_attempt();
|
||||
let outcome = run_install_command(step, command, reporter.line_observer());
|
||||
reporter.record_attempt(attempt, outcome)
|
||||
},
|
||||
std::thread::sleep,
|
||||
)
|
||||
}
|
||||
@@ -92,11 +139,15 @@ fn prepare_install_command(command: &str) -> Result<std::process::Command, Strin
|
||||
Ok(cmd)
|
||||
}
|
||||
|
||||
fn run_install_command(step: &str, command: &str) -> InstallStepResult {
|
||||
fn run_install_command(
|
||||
step: &str,
|
||||
command: &str,
|
||||
observer: Option<LineObserver>,
|
||||
) -> InstallOutcome {
|
||||
let mut cmd = match prepare_install_command(command) {
|
||||
Ok(cmd) => cmd,
|
||||
Err(hint) => {
|
||||
return InstallStepResult {
|
||||
return InstallOutcome::synthesized(InstallStepResult {
|
||||
step: step.to_string(),
|
||||
command: command.to_string(),
|
||||
success: false,
|
||||
@@ -104,11 +155,11 @@ fn run_install_command(step: &str, command: &str) -> InstallStepResult {
|
||||
stderr: "no suitable shell found for install commands".to_string(),
|
||||
exit_code: None,
|
||||
hint: Some(hint),
|
||||
};
|
||||
});
|
||||
}
|
||||
};
|
||||
|
||||
let mut child = match cmd
|
||||
let child = match cmd
|
||||
.stdin(std::process::Stdio::null())
|
||||
.stdout(std::process::Stdio::piped())
|
||||
.stderr(std::process::Stdio::piped())
|
||||
@@ -116,7 +167,7 @@ fn run_install_command(step: &str, command: &str) -> InstallStepResult {
|
||||
{
|
||||
Ok(child) => child,
|
||||
Err(e) => {
|
||||
return InstallStepResult {
|
||||
return InstallOutcome::synthesized(InstallStepResult {
|
||||
step: step.to_string(),
|
||||
command: command.to_string(),
|
||||
success: false,
|
||||
@@ -124,146 +175,312 @@ fn run_install_command(step: &str, command: &str) -> InstallStepResult {
|
||||
stderr: format!("failed to spawn shell: {e}"),
|
||||
exit_code: None,
|
||||
hint: None,
|
||||
};
|
||||
});
|
||||
}
|
||||
};
|
||||
|
||||
// Drain stdout/stderr on background threads to prevent pipe buffer deadlock.
|
||||
await_install_child(step, command, child, INSTALL_TIMEOUT, observer)
|
||||
}
|
||||
|
||||
/// Drain a spawned install child's output into bounded buffers and wait for it
|
||||
/// to exit, killing it at `timeout`.
|
||||
///
|
||||
/// Split from the spawn so the timing-sensitive half is testable without a real
|
||||
/// login shell: shell startup alone can outlast a short test ceiling on a
|
||||
/// loaded machine. Production always passes [`INSTALL_TIMEOUT`].
|
||||
fn await_install_child(
|
||||
step: &str,
|
||||
command: &str,
|
||||
mut child: std::process::Child,
|
||||
timeout: Duration,
|
||||
observer: Option<LineObserver>,
|
||||
) -> InstallOutcome {
|
||||
// Drain stdout/stderr on background threads to prevent pipe buffer
|
||||
// deadlock. Each drain feeds a bounded capture the main thread can read at
|
||||
// any time, so a timeout can still surface whatever the install printed
|
||||
// before it stalled.
|
||||
let stdout_capture = Arc::new(Capture::new());
|
||||
let stderr_capture = Arc::new(Capture::new());
|
||||
let stdout_pipe = child.stdout.take();
|
||||
let stderr_pipe = child.stderr.take();
|
||||
|
||||
let stdout_thread = std::thread::spawn(move || {
|
||||
let mut buf = String::new();
|
||||
if let Some(mut pipe) = stdout_pipe {
|
||||
let _ = pipe.read_to_string(&mut buf);
|
||||
// One event stream carries every input the ceiling waits on, so the exit
|
||||
// and the drains are governed by the same deadline instead of the exit
|
||||
// releasing the drains from it.
|
||||
let (events_tx, events) = std::sync::mpsc::channel();
|
||||
|
||||
std::thread::spawn({
|
||||
let (capture, done, observer) = (
|
||||
Arc::clone(&stdout_capture),
|
||||
events_tx.clone(),
|
||||
observer.clone(),
|
||||
);
|
||||
move || {
|
||||
if let Some(pipe) = stdout_pipe {
|
||||
drain_into(pipe, &capture, observer.as_ref());
|
||||
}
|
||||
let _ = done.send(Settled::Drained);
|
||||
}
|
||||
buf
|
||||
});
|
||||
let stderr_thread = std::thread::spawn(move || {
|
||||
let mut buf = String::new();
|
||||
if let Some(mut pipe) = stderr_pipe {
|
||||
let _ = pipe.read_to_string(&mut buf);
|
||||
std::thread::spawn({
|
||||
let (capture, done) = (Arc::clone(&stderr_capture), events_tx.clone());
|
||||
move || {
|
||||
if let Some(pipe) = stderr_pipe {
|
||||
drain_into(pipe, &capture, observer.as_ref());
|
||||
}
|
||||
let _ = done.send(Settled::Drained);
|
||||
}
|
||||
buf
|
||||
});
|
||||
|
||||
// Save the PID before moving `child` into the wait thread so we can
|
||||
// kill the process on timeout.
|
||||
let child_pid = child.id();
|
||||
|
||||
let (tx, rx) = std::sync::mpsc::channel();
|
||||
let wait_thread = std::thread::spawn(move || {
|
||||
let status = child.wait();
|
||||
let _ = tx.send(status);
|
||||
std::thread::spawn(move || {
|
||||
let _ = events_tx.send(Settled::Exited(child.wait()));
|
||||
});
|
||||
|
||||
// 5-minute timeout for install commands.
|
||||
let deadline = std::time::Instant::now() + std::time::Duration::from_secs(300);
|
||||
loop {
|
||||
let remaining = deadline.saturating_duration_since(std::time::Instant::now());
|
||||
if remaining.is_zero() {
|
||||
// Timeout: kill the child process via its PID, then join all
|
||||
// threads so nothing leaks.
|
||||
#[cfg(unix)]
|
||||
unsafe {
|
||||
libc::kill(child_pid as i32, libc::SIGTERM);
|
||||
}
|
||||
#[cfg(windows)]
|
||||
{
|
||||
let _ = crate::managed_agents::taskkill_tree(child_pid);
|
||||
}
|
||||
drop(rx);
|
||||
let _ = wait_thread.join();
|
||||
let _ = stdout_thread.join();
|
||||
let _ = stderr_thread.join();
|
||||
return InstallStepResult {
|
||||
// No thread is ever joined. Each sends its one event before exiting, so a
|
||||
// join after a complete settle would add nothing — and a join before one
|
||||
// would reintroduce the unbounded wait this loop exists to prevent.
|
||||
let mut settle = Settle::default();
|
||||
let ended = settle.collect(&events, Instant::now() + timeout);
|
||||
if ended == Collected::Deadline {
|
||||
// Ceiling reached: kill the install's whole process group — the install
|
||||
// shell is a session leader (`setsid` in its `pre_exec`), so signalling
|
||||
// only the leader would leave descendants running and holding the
|
||||
// output pipes open.
|
||||
//
|
||||
// Whether the leader had already exited decides the verdict. If it had,
|
||||
// only a descendant was holding a drain open: the install genuinely
|
||||
// finished and its real status stands. If it had not, the install itself
|
||||
// was still running and this is a timeout — the status the kill produces
|
||||
// moments later describes the kill, not the install, so it is discarded.
|
||||
let install_finished = settle.status.is_some();
|
||||
terminate_install_group(child_pid);
|
||||
// Reaping the child and finishing the drains share one bound. Both
|
||||
// normally complete within microseconds of the kill, which closes the
|
||||
// pipes; when they don't — a process that escaped the group still
|
||||
// holding a pipe, or a termination that failed outright — waiting would
|
||||
// defeat the very ceiling that fired and keep the per-runtime install
|
||||
// guard behind it closed. Stragglers are detached instead; the captures
|
||||
// are read under the lock either way.
|
||||
settle.collect(&events, Instant::now() + POST_KILL_GRACE);
|
||||
if !install_finished {
|
||||
return failed_with_capture(
|
||||
step,
|
||||
command,
|
||||
timeout_message(timeout),
|
||||
&stdout_capture,
|
||||
&stderr_capture,
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
match settle.status {
|
||||
Some(Ok(status)) => InstallOutcome {
|
||||
step: InstallStepResult {
|
||||
step: step.to_string(),
|
||||
command: command.to_string(),
|
||||
success: false,
|
||||
stdout: String::new(),
|
||||
stderr: "install command timed out after 5 minutes".to_string(),
|
||||
exit_code: None,
|
||||
success: status.success(),
|
||||
stdout: stdout_capture.ui(),
|
||||
stderr: stderr_capture.ui(),
|
||||
exit_code: status.code(),
|
||||
hint: None,
|
||||
};
|
||||
}
|
||||
|
||||
match rx.recv_timeout(std::time::Duration::from_millis(200).min(remaining)) {
|
||||
Ok(Ok(status)) => {
|
||||
let _ = wait_thread.join();
|
||||
let stdout = stdout_thread.join().unwrap_or_default();
|
||||
let stderr_raw = stderr_thread.join().unwrap_or_default();
|
||||
return InstallStepResult {
|
||||
step: step.to_string(),
|
||||
command: command.to_string(),
|
||||
success: status.success(),
|
||||
stdout: truncate_output(stdout),
|
||||
stderr: truncate_output(stderr_raw),
|
||||
exit_code: status.code(),
|
||||
hint: None,
|
||||
};
|
||||
}
|
||||
Ok(Err(e)) => {
|
||||
let _ = wait_thread.join();
|
||||
let _ = stdout_thread.join();
|
||||
let _ = stderr_thread.join();
|
||||
return InstallStepResult {
|
||||
step: step.to_string(),
|
||||
command: command.to_string(),
|
||||
success: false,
|
||||
stdout: String::new(),
|
||||
stderr: format!("failed to check process status: {e}"),
|
||||
exit_code: None,
|
||||
hint: None,
|
||||
};
|
||||
}
|
||||
Err(std::sync::mpsc::RecvTimeoutError::Timeout) => {
|
||||
// Still running; loop and check deadline again.
|
||||
continue;
|
||||
}
|
||||
Err(std::sync::mpsc::RecvTimeoutError::Disconnected) => {
|
||||
// wait_thread dropped sender without sending — shouldn't happen.
|
||||
let _ = wait_thread.join();
|
||||
let _ = stdout_thread.join();
|
||||
let _ = stderr_thread.join();
|
||||
return InstallStepResult {
|
||||
step: step.to_string(),
|
||||
command: command.to_string(),
|
||||
success: false,
|
||||
stdout: String::new(),
|
||||
stderr: "internal error: wait thread disconnected".to_string(),
|
||||
exit_code: None,
|
||||
hint: None,
|
||||
};
|
||||
}
|
||||
}
|
||||
},
|
||||
log_stdout: stdout_capture.log(),
|
||||
log_stderr: stderr_capture.log(),
|
||||
},
|
||||
Some(Err(e)) => failed_with_capture(
|
||||
step,
|
||||
command,
|
||||
format!("failed to check process status: {e}"),
|
||||
&stdout_capture,
|
||||
&stderr_capture,
|
||||
),
|
||||
// Every sender is gone without an exit ever arriving.
|
||||
None => failed_with_capture(
|
||||
step,
|
||||
command,
|
||||
"internal error: install wait ended without a status".to_string(),
|
||||
&stdout_capture,
|
||||
&stderr_capture,
|
||||
),
|
||||
}
|
||||
}
|
||||
|
||||
/// Cap output to head + tail to avoid flooding the UI with large error dumps,
|
||||
/// while preserving the most useful parts of the output.
|
||||
fn truncate_output(s: String) -> String {
|
||||
const HEAD: usize = 512;
|
||||
const TAIL: usize = 1024;
|
||||
const LIMIT: usize = HEAD + TAIL;
|
||||
if s.len() <= LIMIT {
|
||||
return s;
|
||||
}
|
||||
let head_end = floor_char_boundary(&s, HEAD);
|
||||
let tail_start = floor_char_boundary(&s, s.len().saturating_sub(TAIL));
|
||||
let omitted = tail_start - head_end;
|
||||
format!(
|
||||
"{}\n... ({omitted} bytes omitted) ...\n{}",
|
||||
&s[..head_end],
|
||||
&s[tail_start..]
|
||||
)
|
||||
/// One input the ceiling waits on.
|
||||
enum Settled {
|
||||
Exited(std::io::Result<std::process::ExitStatus>),
|
||||
Drained,
|
||||
}
|
||||
|
||||
fn floor_char_boundary(s: &str, mut index: usize) -> usize {
|
||||
index = index.min(s.len());
|
||||
while index > 0 && !s.is_char_boundary(index) {
|
||||
index -= 1;
|
||||
/// How a bounded [`Settle::collect`] ended.
|
||||
#[derive(PartialEq, Debug)]
|
||||
enum Collected {
|
||||
/// The child exited and both drains reached EOF.
|
||||
Complete,
|
||||
/// The deadline passed first.
|
||||
Deadline,
|
||||
/// Every sender is gone — a thread died without reporting.
|
||||
Disconnected,
|
||||
}
|
||||
|
||||
/// What the install has settled so far: the child's exit status once it is
|
||||
/// known, and how many of the two drains have reached EOF.
|
||||
///
|
||||
/// Collecting is resumable, so the ceiling can fold more events into the same
|
||||
/// state under a second, post-kill deadline.
|
||||
#[derive(Default)]
|
||||
struct Settle {
|
||||
status: Option<std::io::Result<std::process::ExitStatus>>,
|
||||
drained: usize,
|
||||
}
|
||||
|
||||
impl Settle {
|
||||
const DRAINS: usize = 2;
|
||||
|
||||
fn is_complete(&self) -> bool {
|
||||
self.status.is_some() && self.drained >= Self::DRAINS
|
||||
}
|
||||
index
|
||||
|
||||
/// Fold events until the install has fully settled or `deadline` passes.
|
||||
///
|
||||
/// The exit and the drains share one deadline deliberately: a shell can exit
|
||||
/// while a descendant it left behind still holds the inherited output pipes,
|
||||
/// and waiting on those drains outside the deadline would let such a
|
||||
/// descendant outlast the ceiling — holding the per-runtime install guard,
|
||||
/// which is the very failure the ceiling exists to prevent.
|
||||
fn collect(
|
||||
&mut self,
|
||||
events: &std::sync::mpsc::Receiver<Settled>,
|
||||
deadline: Instant,
|
||||
) -> Collected {
|
||||
while !self.is_complete() {
|
||||
let remaining = deadline.saturating_duration_since(Instant::now());
|
||||
match events.recv_timeout(remaining) {
|
||||
Ok(Settled::Exited(status)) => self.status = Some(status),
|
||||
Ok(Settled::Drained) => self.drained += 1,
|
||||
Err(std::sync::mpsc::RecvTimeoutError::Timeout) => return Collected::Deadline,
|
||||
Err(std::sync::mpsc::RecvTimeoutError::Disconnected) => {
|
||||
return Collected::Disconnected
|
||||
}
|
||||
}
|
||||
}
|
||||
Collected::Complete
|
||||
}
|
||||
}
|
||||
|
||||
/// Kill the install's process group, escalating on the *tree's* liveness.
|
||||
///
|
||||
/// The install ceiling owns this rather than reusing
|
||||
/// `managed_agents::terminate_process`, which escalates to SIGKILL only while
|
||||
/// the group *leader* is still running: a descendant that ignores SIGTERM
|
||||
/// outlives the leader, keeps the output pipes open, and never receives the
|
||||
/// group SIGKILL. The ceiling's contract is that nothing survives it, and the
|
||||
/// shared helper's escalation is load-bearing for the agent stop/restore paths,
|
||||
/// so the stricter rule lives here instead of changing it for them.
|
||||
///
|
||||
/// Nothing is returned: every outcome — including a signal that could not be
|
||||
/// delivered at all — has the same handling, the bounded waits at the call
|
||||
/// site.
|
||||
#[cfg(unix)]
|
||||
fn terminate_install_group(pid: u32) {
|
||||
signal_install_tree(pid, libc::SIGTERM);
|
||||
let deadline = Instant::now() + TERM_GRACE;
|
||||
while install_tree_is_alive(pid) {
|
||||
if Instant::now() >= deadline {
|
||||
signal_install_tree(pid, libc::SIGKILL);
|
||||
return;
|
||||
}
|
||||
std::thread::sleep(Duration::from_millis(50));
|
||||
}
|
||||
}
|
||||
|
||||
/// Signal every process in `pid`'s group, falling back to the leader alone when
|
||||
/// the group cannot be signalled — the leader may have changed groups, or macOS
|
||||
/// may refuse one member — since killing the install shell beats killing
|
||||
/// nothing.
|
||||
#[cfg(unix)]
|
||||
fn signal_install_tree(pid: u32, signal: i32) {
|
||||
if unsafe { libc::kill(-(pid as i32), signal) } != 0 {
|
||||
unsafe { libc::kill(pid as i32, signal) };
|
||||
}
|
||||
}
|
||||
|
||||
/// Whether anything the ceiling aimed at is still running: a member of the
|
||||
/// process group, or the leader itself.
|
||||
#[cfg(unix)]
|
||||
fn install_tree_is_alive(pid: u32) -> bool {
|
||||
signal_reaches(-(pid as i32)) || signal_reaches(pid as i32)
|
||||
}
|
||||
|
||||
/// `kill(target, 0)` distinguishes "nothing there" (`ESRCH`) from every other
|
||||
/// outcome. Anything ambiguous — notably `EPERM` for a member we may not
|
||||
/// signal — counts as alive, so an unclear answer escalates rather than
|
||||
/// declaring the tree dead.
|
||||
#[cfg(unix)]
|
||||
fn signal_reaches(target: i32) -> bool {
|
||||
if unsafe { libc::kill(target, 0) } == 0 {
|
||||
return true;
|
||||
}
|
||||
std::io::Error::last_os_error().raw_os_error() != Some(libc::ESRCH)
|
||||
}
|
||||
|
||||
/// Windows has no process groups on this path: `terminate_process` runs
|
||||
/// `taskkill /T /F`, which is already tree-wide and unconditional, so there is
|
||||
/// no escalation to get wrong.
|
||||
#[cfg(not(unix))]
|
||||
fn terminate_install_group(pid: u32) {
|
||||
let _ = crate::managed_agents::terminate_process(pid);
|
||||
}
|
||||
|
||||
/// A failure carrying whatever the drains captured, with `reason` leading
|
||||
/// stderr so the surfaced message names the failure before the install's own
|
||||
/// output.
|
||||
fn failed_with_capture(
|
||||
step: &str,
|
||||
command: &str,
|
||||
reason: String,
|
||||
stdout: &Capture,
|
||||
stderr: &Capture,
|
||||
) -> InstallOutcome {
|
||||
InstallOutcome {
|
||||
step: InstallStepResult {
|
||||
step: step.to_string(),
|
||||
command: command.to_string(),
|
||||
success: false,
|
||||
stdout: stdout.ui(),
|
||||
stderr: lead_with_reason(&reason, stderr.ui()),
|
||||
exit_code: None,
|
||||
hint: None,
|
||||
},
|
||||
log_stdout: stdout.log(),
|
||||
log_stderr: lead_with_reason(&reason, stderr.log()),
|
||||
}
|
||||
}
|
||||
|
||||
/// Put `reason` ahead of the install's own stderr, so the surfaced message names
|
||||
/// the failure before the output. An empty capture leaves the reason alone,
|
||||
/// without a dangling separator.
|
||||
fn lead_with_reason(reason: &str, captured: String) -> String {
|
||||
if captured.is_empty() {
|
||||
reason.to_string()
|
||||
} else {
|
||||
format!("{reason}\n{captured}")
|
||||
}
|
||||
}
|
||||
|
||||
/// Name the limit that fired and its value, so a ceiling kill is
|
||||
/// distinguishable from the installer's own failure.
|
||||
fn timeout_message(timeout: Duration) -> String {
|
||||
let secs = timeout.as_secs();
|
||||
let limit = if secs >= 60 {
|
||||
format!("{}-minute", secs / 60)
|
||||
} else {
|
||||
format!("{secs}-second")
|
||||
};
|
||||
format!("install command exceeded the {limit} ceiling and was terminated")
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
@@ -410,48 +627,304 @@ mod tests {
|
||||
assert_eq!(cmd.get_current_dir(), Some(expected.as_path()));
|
||||
}
|
||||
|
||||
// ── output truncation ─────────────────────────────────────────────────────
|
||||
// ── install ceiling ───────────────────────────────────────────────────────
|
||||
|
||||
/// Output within the cap is passed through byte-for-byte — no marker, no loss.
|
||||
/// The ceiling is Will's ruling: 15 minutes, and the error names the limit
|
||||
/// that fired so a ceiling kill is not mistaken for the installer's own
|
||||
/// failure.
|
||||
#[test]
|
||||
fn test_truncate_output_leaves_short_output_untouched() {
|
||||
let short = "a".repeat(1536);
|
||||
|
||||
assert_eq!(truncate_output(short.clone()), short);
|
||||
}
|
||||
|
||||
/// Over the cap, both ends survive and the middle is replaced by a marker
|
||||
/// naming the omitted byte count — the head keeps the command's opening
|
||||
/// context and the tail keeps the error that usually trails.
|
||||
#[test]
|
||||
fn test_truncate_output_keeps_head_and_tail_with_marker() {
|
||||
let input = format!(
|
||||
"{}{}{}",
|
||||
"H".repeat(512),
|
||||
"M".repeat(4000),
|
||||
"T".repeat(1024)
|
||||
);
|
||||
|
||||
let out = truncate_output(input);
|
||||
|
||||
assert!(out.starts_with(&"H".repeat(512)));
|
||||
assert!(out.ends_with(&"T".repeat(1024)));
|
||||
fn test_ceiling_is_fifteen_minutes_and_error_names_it() {
|
||||
assert_eq!(INSTALL_TIMEOUT, Duration::from_secs(900));
|
||||
assert!(
|
||||
out.contains("... (4000 bytes omitted) ..."),
|
||||
"marker must name the omitted byte count, got: {out}"
|
||||
timeout_message(INSTALL_TIMEOUT).contains("15-minute"),
|
||||
"got: {}",
|
||||
timeout_message(INSTALL_TIMEOUT)
|
||||
);
|
||||
}
|
||||
|
||||
/// Truncation must not split a multi-byte character. Cutting mid-codepoint
|
||||
/// would panic on the slice; the boundary floor prevents it.
|
||||
/// Spawn `script` under `sh` as a process-group leader with piped output —
|
||||
/// the same shape [`run_install_command`] hands to
|
||||
/// [`await_install_child`], minus the login shell whose own startup can
|
||||
/// outlast a short test ceiling.
|
||||
#[cfg(unix)]
|
||||
fn spawn_group_leader(script: &str) -> std::process::Child {
|
||||
use std::os::unix::process::CommandExt;
|
||||
|
||||
let mut cmd = std::process::Command::new("/bin/sh");
|
||||
cmd.arg("-c").arg(script);
|
||||
unsafe {
|
||||
cmd.pre_exec(|| {
|
||||
libc::setsid();
|
||||
Ok(())
|
||||
});
|
||||
}
|
||||
cmd.stdin(std::process::Stdio::null())
|
||||
.stdout(std::process::Stdio::piped())
|
||||
.stderr(std::process::Stdio::piped())
|
||||
.spawn()
|
||||
.expect("sh must spawn")
|
||||
}
|
||||
|
||||
/// A command killed by the ceiling must surface what it printed before
|
||||
/// stalling — that partial output is the only evidence of where the install
|
||||
/// got stuck — and must stay unretryable, since re-running a hang just
|
||||
/// costs the user another ceiling.
|
||||
#[cfg(unix)]
|
||||
#[test]
|
||||
fn test_truncate_output_does_not_split_multibyte_characters() {
|
||||
// "é" is 2 bytes, so every candidate cut index lands mid-character.
|
||||
let input = "é".repeat(4000);
|
||||
fn test_ceiling_returns_captured_output_and_stays_unretryable() {
|
||||
let child = spawn_group_leader("echo out-before-hang; echo err-before-hang >&2; sleep 60");
|
||||
|
||||
let out = truncate_output(input);
|
||||
let started = Instant::now();
|
||||
let outcome = await_install_child("cli", "install", child, Duration::from_secs(5), None);
|
||||
let result = &outcome.step;
|
||||
|
||||
assert!(out.contains("bytes omitted"), "input must exceed the cap");
|
||||
assert!(!out.contains('\u{fffd}'), "no replacement chars: {out}");
|
||||
assert!(!result.success);
|
||||
assert_eq!(result.exit_code, None, "a killed command has no exit code");
|
||||
assert!(
|
||||
!install_failure_is_retryable(result),
|
||||
"a ceiling kill must not be retried"
|
||||
);
|
||||
assert!(
|
||||
result.stdout.contains("out-before-hang"),
|
||||
"stdout captured before the stall must survive, got: {:?}",
|
||||
result.stdout
|
||||
);
|
||||
assert!(
|
||||
result.stderr.contains("5-second ceiling"),
|
||||
"stderr must name the ceiling that actually fired, got: {:?}",
|
||||
result.stderr
|
||||
);
|
||||
assert!(
|
||||
result.stderr.contains("err-before-hang"),
|
||||
"stderr captured before the stall must survive, got: {:?}",
|
||||
result.stderr
|
||||
);
|
||||
assert!(
|
||||
started.elapsed() < Duration::from_secs(30),
|
||||
"the ceiling must not wait on the hung command's own exit"
|
||||
);
|
||||
assert!(
|
||||
outcome.log_stderr.contains("err-before-hang"),
|
||||
"the log record of a ceiling kill must carry the output too, got: {:?}",
|
||||
outcome.log_stderr
|
||||
);
|
||||
}
|
||||
|
||||
/// A failure whose stream captured nothing surfaces the reason alone — no
|
||||
/// dangling separator from an empty capture.
|
||||
#[test]
|
||||
fn test_failure_with_no_captured_output_reports_only_the_reason() {
|
||||
let result = failed_with_capture(
|
||||
"cli",
|
||||
"curl … | bash",
|
||||
"boom".to_string(),
|
||||
&Capture::new(),
|
||||
&Capture::new(),
|
||||
)
|
||||
.step;
|
||||
|
||||
assert_eq!(result.stdout, "");
|
||||
assert_eq!(result.stderr, "boom");
|
||||
}
|
||||
|
||||
// ── post-kill settle bound ────────────────────────────────────────────────
|
||||
|
||||
/// A sender that never arrives — the shape of a failed termination, whose
|
||||
/// child is never reaped — must not extend the wait past its deadline.
|
||||
#[test]
|
||||
fn test_settling_on_a_message_that_never_arrives_stops_at_the_deadline() {
|
||||
let (_tx, events) = std::sync::mpsc::channel::<Settled>();
|
||||
|
||||
let started = Instant::now();
|
||||
let ended = Settle::default().collect(&events, started + Duration::from_millis(200));
|
||||
|
||||
assert_eq!(ended, Collected::Deadline);
|
||||
assert!(
|
||||
started.elapsed() < Duration::from_secs(1),
|
||||
"the wait must end at its deadline, took {:?}",
|
||||
started.elapsed()
|
||||
);
|
||||
}
|
||||
|
||||
/// An exit alone is not a settle: the drains are inputs to the same wait, so
|
||||
/// a shell that exited while a descendant holds a pipe still hits the
|
||||
/// deadline instead of being released from it.
|
||||
#[test]
|
||||
fn test_exit_without_drains_still_hits_the_deadline() {
|
||||
let (tx, events) = std::sync::mpsc::channel();
|
||||
tx.send(Settled::Exited(Ok(exit_status_zero()))).unwrap();
|
||||
|
||||
let started = Instant::now();
|
||||
let mut settle = Settle::default();
|
||||
let ended = settle.collect(&events, started + Duration::from_millis(200));
|
||||
|
||||
assert_eq!(
|
||||
ended,
|
||||
Collected::Deadline,
|
||||
"a leader exit must not complete the settle while a drain is outstanding"
|
||||
);
|
||||
assert!(settle.status.is_some(), "the exit status must be retained");
|
||||
assert!(started.elapsed() < Duration::from_secs(1));
|
||||
}
|
||||
|
||||
/// The settle completes only when the exit and both drains have arrived, and
|
||||
/// it is resumable: state folded under the first deadline carries into the
|
||||
/// post-kill one.
|
||||
#[test]
|
||||
fn test_settle_completes_on_exit_plus_both_drains_and_resumes() {
|
||||
let (tx, events) = std::sync::mpsc::channel();
|
||||
tx.send(Settled::Drained).unwrap();
|
||||
|
||||
let mut settle = Settle::default();
|
||||
assert_eq!(
|
||||
settle.collect(&events, Instant::now() + Duration::from_millis(50)),
|
||||
Collected::Deadline
|
||||
);
|
||||
|
||||
tx.send(Settled::Exited(Ok(exit_status_zero()))).unwrap();
|
||||
tx.send(Settled::Drained).unwrap();
|
||||
|
||||
assert_eq!(
|
||||
settle.collect(&events, Instant::now() + Duration::from_secs(5)),
|
||||
Collected::Complete,
|
||||
"the second collect must build on the first's state, not restart it"
|
||||
);
|
||||
}
|
||||
|
||||
/// Exit status of a trivially successful command, for driving `Settle`
|
||||
/// without a real install.
|
||||
fn exit_status_zero() -> std::process::ExitStatus {
|
||||
std::process::Command::new("true")
|
||||
.status()
|
||||
.expect("run `true`")
|
||||
}
|
||||
|
||||
/// A shell can exit while a descendant it left behind still holds the
|
||||
/// inherited output pipes. If the exit released the drains from the
|
||||
/// deadline, that descendant would hold the install — and the per-runtime
|
||||
/// concurrency guard behind it — open indefinitely, which is exactly the
|
||||
/// failure the ceiling exists to prevent. The leader here exits in
|
||||
/// milliseconds; only the descendant outlives the ceiling.
|
||||
#[cfg(unix)]
|
||||
#[test]
|
||||
fn test_promptly_exited_leader_with_a_pipe_holding_descendant_still_obeys_the_ceiling() {
|
||||
let dir = tempfile::tempdir().expect("tempdir");
|
||||
let pidfile = dir.path().join("lingering.pid");
|
||||
let child = spawn_group_leader(&format!(
|
||||
"sh -c 'echo $$ > {pid}; sleep 120' & exit 3",
|
||||
pid = pidfile.display()
|
||||
));
|
||||
|
||||
let started = Instant::now();
|
||||
let outcome = await_install_child("cli", "install", child, Duration::from_secs(2), None);
|
||||
|
||||
assert!(
|
||||
started.elapsed() < Duration::from_secs(30),
|
||||
"a descendant holding the pipe must not outlast the ceiling, took {:?}",
|
||||
started.elapsed()
|
||||
);
|
||||
assert_eq!(
|
||||
outcome.step.exit_code,
|
||||
Some(3),
|
||||
"the leader's real status outranks the ceiling's verdict once it is known"
|
||||
);
|
||||
// The deadline must still reach the kill on this path: a leader exit that
|
||||
// skipped termination would leave the descendant running with the pipes
|
||||
// open, which is the defect itself rather than a detail of it.
|
||||
let pid = recorded_pid(&pidfile);
|
||||
assert!(
|
||||
await_death(pid),
|
||||
"descendant {pid} survived — a leader exit must not skip the ceiling's kill"
|
||||
);
|
||||
}
|
||||
|
||||
/// Wait up to 3s for `pid` to disappear.
|
||||
#[cfg(unix)]
|
||||
fn await_death(pid: u32) -> bool {
|
||||
for _ in 0..30 {
|
||||
if !crate::managed_agents::process_is_running(pid) {
|
||||
return true;
|
||||
}
|
||||
std::thread::sleep(Duration::from_millis(100));
|
||||
}
|
||||
false
|
||||
}
|
||||
|
||||
/// Read the pid a test descendant recorded for itself.
|
||||
#[cfg(unix)]
|
||||
fn recorded_pid(pidfile: &std::path::Path) -> u32 {
|
||||
for _ in 0..50 {
|
||||
if let Ok(text) = std::fs::read_to_string(pidfile) {
|
||||
if let Ok(pid) = text.trim().parse() {
|
||||
return pid;
|
||||
}
|
||||
}
|
||||
std::thread::sleep(Duration::from_millis(100));
|
||||
}
|
||||
panic!("the descendant never recorded its pid at {pidfile:?}");
|
||||
}
|
||||
|
||||
/// The install shell is a process-group leader, and its descendants inherit
|
||||
/// the output pipes. Killing only the leader leaves them running and the
|
||||
/// drains blocked on a pipe nobody will close, so the ceiling kills the
|
||||
/// whole group.
|
||||
#[cfg(unix)]
|
||||
#[test]
|
||||
fn test_ceiling_kills_descendants_holding_the_output_pipe() {
|
||||
let dir = tempfile::tempdir().expect("tempdir");
|
||||
let pidfile = dir.path().join("descendant.pid");
|
||||
let child = spawn_group_leader(&format!(
|
||||
"sh -c 'echo $$ > {pid}; sleep 60' & echo leader-up; sleep 60",
|
||||
pid = pidfile.display()
|
||||
));
|
||||
|
||||
let started = Instant::now();
|
||||
let outcome = await_install_child("cli", "install", child, Duration::from_secs(5), None);
|
||||
let result = &outcome.step;
|
||||
|
||||
assert!(!result.success);
|
||||
assert!(
|
||||
started.elapsed() < Duration::from_secs(30),
|
||||
"the drains must not block on a descendant's inherited pipe"
|
||||
);
|
||||
|
||||
let pid = recorded_pid(&pidfile);
|
||||
assert!(
|
||||
await_death(pid),
|
||||
"descendant {pid} survived the ceiling kill — the group was not signalled"
|
||||
);
|
||||
}
|
||||
|
||||
/// Escalation must key off the group, not the leader: a descendant that
|
||||
/// ignores SIGTERM outlives the leader, and if SIGKILL is skipped because
|
||||
/// the leader is gone it keeps running with the output pipes open — past the
|
||||
/// ceiling, and past the concurrency guard that blocks the next install.
|
||||
#[cfg(unix)]
|
||||
#[test]
|
||||
fn test_ceiling_kills_sigterm_ignoring_descendant() {
|
||||
let dir = tempfile::tempdir().expect("tempdir");
|
||||
let pidfile = dir.path().join("stubborn.pid");
|
||||
// An ignored disposition survives exec, so the descendant's own `sleep`
|
||||
// ignores SIGTERM too — nothing in that subtree dies without SIGKILL.
|
||||
let child = spawn_group_leader(&format!(
|
||||
"sh -c 'trap \"\" TERM; echo $$ > {pid}; sleep 60' & echo leader-up; sleep 60",
|
||||
pid = pidfile.display()
|
||||
));
|
||||
|
||||
let started = Instant::now();
|
||||
let outcome = await_install_child("cli", "install", child, Duration::from_secs(5), None);
|
||||
let result = &outcome.step;
|
||||
|
||||
assert!(!result.success);
|
||||
assert!(
|
||||
started.elapsed() < Duration::from_secs(30),
|
||||
"a SIGTERM-ignoring descendant must not hold the ceiling open"
|
||||
);
|
||||
|
||||
let pid = recorded_pid(&pidfile);
|
||||
assert!(
|
||||
await_death(pid),
|
||||
"SIGTERM-ignoring descendant {pid} survived — escalation followed the leader, not the group"
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
595
desktop/src-tauri/src/commands/agent_discovery/install_report.rs
Normal file
595
desktop/src-tauri/src/commands/agent_discovery/install_report.rs
Normal file
@@ -0,0 +1,595 @@
|
||||
//! Where an install's output goes: the install log file (complete history) and
|
||||
//! the live output line in the UI (current progress).
|
||||
//!
|
||||
//! Both destinations hang off the same drain seam in
|
||||
//! [`super::install_capture`], and both are best-effort: an install must never
|
||||
//! fail because a log write or an event emit did.
|
||||
//!
|
||||
//! [`InstallReporter`] owns two explicit lifecycles, because both the log and
|
||||
//! the live line are meaningless without a notion of "this run":
|
||||
//!
|
||||
//! * a **log session**, started once per run, which keeps the previous run's
|
||||
//! file as `.1` and writes this run's header; and
|
||||
//! * a **live-event sequence**, monotonic across the whole install, which is
|
||||
//! what lets the UI drop a superseded line. A per-command retry number
|
||||
//! cannot do that job — it restarts at 1 for every step.
|
||||
|
||||
use std::io::Write;
|
||||
use std::path::{Path, PathBuf};
|
||||
use std::sync::atomic::{AtomicU64, Ordering};
|
||||
use std::sync::{Arc, Mutex, RwLock};
|
||||
use std::time::{Duration, Instant};
|
||||
|
||||
use serde::Serialize;
|
||||
|
||||
use super::install_capture::{LineObserver, Throttle};
|
||||
use crate::managed_agents::{InstallRuntimeResult, InstallStepResult};
|
||||
|
||||
/// One install command's result: what the UI shows, and the log-scale copy of
|
||||
/// the same output for the log file.
|
||||
pub(super) struct InstallOutcome {
|
||||
pub(super) step: InstallStepResult,
|
||||
pub(super) log_stdout: String,
|
||||
pub(super) log_stderr: String,
|
||||
}
|
||||
|
||||
impl InstallOutcome {
|
||||
/// A step Buzz synthesized rather than ran — a failed prerequisite, or the
|
||||
/// post-install verification. Its own message is the whole record.
|
||||
pub(super) fn synthesized(step: InstallStepResult) -> Self {
|
||||
Self {
|
||||
log_stdout: step.stdout.clone(),
|
||||
log_stderr: step.stderr.clone(),
|
||||
step,
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// Payload of the `acp-install-output` event.
|
||||
///
|
||||
/// `seq` is monotonic across the entire install, so the UI can drop a line a
|
||||
/// later step or attempt has already superseded. The retry number cannot serve
|
||||
/// as that key: it restarts at 1 for every step, so a step that succeeded on
|
||||
/// attempt 2 would make the next step's attempt-1 output look stale and freeze
|
||||
/// the display.
|
||||
///
|
||||
/// `line: None` is the *start signal*: an attempt is beginning and the displayed
|
||||
/// line must clear now. It is emitted unthrottled, because the point is that
|
||||
/// stale output stops being shown before the new work prints anything.
|
||||
#[derive(Serialize, Clone, Debug)]
|
||||
pub(super) struct InstallOutputEvent {
|
||||
pub(super) runtime_id: String,
|
||||
pub(super) seq: u64,
|
||||
pub(super) line: Option<String>,
|
||||
}
|
||||
|
||||
/// Emits one live output event. Boxed rather than holding an `AppHandle` so the
|
||||
/// reporter is constructible — and assertable — without a Tauri app.
|
||||
type EmitEvent = Arc<dyn Fn(InstallOutputEvent) + Send + Sync>;
|
||||
|
||||
/// Literal secret values scrubbed out of everything this module publishes, in
|
||||
/// addition to the shapes [`crate::managed_agents::redact_secrets_with`]
|
||||
/// recognises on its own.
|
||||
type Secrets = Arc<Vec<String>>;
|
||||
|
||||
/// At most four live-output events per second. Coalescing *holds* the newest
|
||||
/// line rather than dropping it: a burst that ends just before the window
|
||||
/// closes would otherwise leave the display showing a line the install had
|
||||
/// already moved past.
|
||||
const LIVE_LINE_INTERVAL: Duration = Duration::from_millis(250);
|
||||
|
||||
pub(super) struct InstallReporter {
|
||||
log: Option<InstallLog>,
|
||||
/// `None` when nothing is listening, which is also what makes
|
||||
/// [`InstallReporter::line_observer`] `None` — the drain then skips line
|
||||
/// reassembly entirely instead of doing it for no one.
|
||||
live: Option<Live>,
|
||||
secrets: Secrets,
|
||||
}
|
||||
|
||||
impl Drop for InstallReporter {
|
||||
/// Serialise deactivation against in-flight publications: take the
|
||||
/// exclusive lifecycle write lock, mark the run as inactive, and return —
|
||||
/// all before the per-runtime concurrency guard releases.
|
||||
///
|
||||
/// Every drain thread holds the shared read guard from its admission check
|
||||
/// through its `(self.emit)(...)` call, so the write lock here blocks until
|
||||
/// every in-flight publication has finished. After this returns, `active`
|
||||
/// is `false` under an exclusive write, and any thread that attempts a new
|
||||
/// `offer` will read `false` under a read lock and return without emitting.
|
||||
///
|
||||
/// The ordering guarantee: `reporter` is declared after `_guard` in
|
||||
/// `install_acp_runtime_blocking` (line 311 vs line 306), so Rust drops
|
||||
/// `reporter` first in reverse-declaration order — deactivation completes
|
||||
/// before the runtime guard releases and a new install can start.
|
||||
fn drop(&mut self) {
|
||||
if let Some(live) = &self.live {
|
||||
if let Ok(mut active) = live.lifecycle.write() {
|
||||
*active = false;
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
impl InstallReporter {
|
||||
/// The reporter a real install run uses: it starts this run's log session
|
||||
/// and emits live output events through `app`.
|
||||
///
|
||||
/// `runtime_id` must already be the canonical id from the runtime catalog —
|
||||
/// the log path is built from it, so resolving it first is what keeps a raw
|
||||
/// command argument out of a filename.
|
||||
///
|
||||
/// A log that cannot be resolved or opened degrades to no log rather than
|
||||
/// failing the install: a user with a broken app-data directory still needs
|
||||
/// the install itself to work.
|
||||
pub(super) fn for_run(app: &tauri::AppHandle, runtime_id: &str) -> Self {
|
||||
// Read from the app's own package info rather than the frontend's
|
||||
// `getVersion` plugin call: the header is written on the Rust side, and
|
||||
// this cannot fail or be mocked out from under the log.
|
||||
let app_version = app.package_info().version.to_string();
|
||||
let log = crate::managed_agents::storage::install_log_path(app, runtime_id)
|
||||
.ok()
|
||||
.and_then(|path| InstallLog::start(&path, runtime_id, &app_version));
|
||||
let app = app.clone();
|
||||
let emit: EmitEvent = Arc::new(move |event| {
|
||||
use tauri::Emitter;
|
||||
let _ = app.emit("acp-install-output", event);
|
||||
});
|
||||
Self::new(runtime_id, log, Some(emit))
|
||||
}
|
||||
|
||||
fn new(runtime_id: &str, log: Option<InstallLog>, emit: Option<EmitEvent>) -> Self {
|
||||
// Snapshot the environment's secrets once, at construction: the install
|
||||
// inherits this environment, so anything it echoes came from here.
|
||||
Self::with_secrets(runtime_id, log, emit, env_secret_values())
|
||||
}
|
||||
|
||||
/// The reporter over an explicit secret set, which is what makes the
|
||||
/// scrubbing assertable: a test can name a proxy credential without
|
||||
/// exporting a real `HTTPS_PROXY` into the process every HTTP client in the
|
||||
/// suite would then read.
|
||||
fn with_secrets(
|
||||
runtime_id: &str,
|
||||
log: Option<InstallLog>,
|
||||
emit: Option<EmitEvent>,
|
||||
secrets: Vec<String>,
|
||||
) -> Self {
|
||||
let secrets: Secrets = Arc::new(secrets);
|
||||
let live = emit.map(|emit| Live {
|
||||
runtime_id: Arc::from(runtime_id),
|
||||
emit,
|
||||
throttle: Arc::new(Throttle::new(LIVE_LINE_INTERVAL)),
|
||||
seq: Arc::new(AtomicU64::new(0)),
|
||||
lifecycle: Arc::new(RwLock::new(true)),
|
||||
secrets: Arc::clone(&secrets),
|
||||
});
|
||||
Self { log, live, secrets }
|
||||
}
|
||||
|
||||
/// The log file to point the user at, or `None` when this run has no log —
|
||||
/// the failure message then omits the pointer rather than naming a file
|
||||
/// that does not exist.
|
||||
pub(super) fn log_path(&self) -> Option<String> {
|
||||
Some(self.log.as_ref()?.path.display().to_string())
|
||||
}
|
||||
|
||||
/// A failed install carrying the steps recorded so far and the log holding
|
||||
/// their full history. Every early return in the install shapes its result
|
||||
/// here, so none can forget the log pointer the failure message needs.
|
||||
pub(super) fn failed(&self, steps: Vec<InstallStepResult>) -> InstallRuntimeResult {
|
||||
InstallRuntimeResult {
|
||||
success: false,
|
||||
steps,
|
||||
restarted_count: 0,
|
||||
failed_restart_count: 0,
|
||||
log_path: self.log_path(),
|
||||
}
|
||||
}
|
||||
|
||||
/// Mark the start of one executed attempt: clear whatever line the previous
|
||||
/// attempt left on screen, and start this attempt's clock.
|
||||
///
|
||||
/// The clear is emitted unthrottled and reopens the rate window, so the new
|
||||
/// attempt's first line cannot be swallowed by the previous attempt's.
|
||||
/// Without this signal the prior attempt's last line — typically the failure
|
||||
/// that caused the retry — sits under the spinner through the backoff and
|
||||
/// through a silent next attempt.
|
||||
pub(super) fn start_attempt(&self) {
|
||||
if let Some(log) = &self.log {
|
||||
log.mark_attempt_start();
|
||||
}
|
||||
if let Some(live) = &self.live {
|
||||
live.throttle.restart();
|
||||
live.publish(None);
|
||||
}
|
||||
}
|
||||
|
||||
/// Observer for one attempt's drains, or `None` when nothing is listening.
|
||||
pub(super) fn line_observer(&self) -> Option<LineObserver> {
|
||||
let live = self.live.clone()?;
|
||||
Some(Arc::new(move |line: &str| live.offer(line)))
|
||||
}
|
||||
|
||||
/// Record one executed attempt of a step, returning the step with secrets
|
||||
/// scrubbed out of the output the UI will render.
|
||||
///
|
||||
/// The scrub happens here rather than at the construction sites because
|
||||
/// every executed step reaches the caller through this function — the
|
||||
/// timeout path, the status-check failure, and the ordinary exit all build
|
||||
/// their `InstallStepResult` straight from the captures.
|
||||
pub(super) fn record_attempt(
|
||||
&self,
|
||||
attempt: u32,
|
||||
outcome: InstallOutcome,
|
||||
) -> InstallStepResult {
|
||||
// The drains are finished, so a line the throttle is still holding is
|
||||
// this attempt's last and nothing is coming to replace it.
|
||||
if let Some(live) = &self.live {
|
||||
live.flush_pending();
|
||||
}
|
||||
self.write_record(Some(attempt), &outcome);
|
||||
self.redacted_step(outcome.step)
|
||||
}
|
||||
|
||||
/// Push a synthesized step onto `steps` and record it. Routing every step
|
||||
/// through here is what keeps the log complete: a step that reaches the UI
|
||||
/// without passing this function is invisible in the file.
|
||||
pub(super) fn record_step(&self, steps: &mut Vec<InstallStepResult>, step: InstallStepResult) {
|
||||
self.write_record(None, &InstallOutcome::synthesized(step.clone()));
|
||||
steps.push(self.redacted_step(step));
|
||||
}
|
||||
|
||||
/// Scrub the frontend-visible fields of a step. The failure message the UI
|
||||
/// builds renders `stderr`/`stdout` and the hint verbatim, so they need the
|
||||
/// same scrubbing as the log record and the live line — the log is not the
|
||||
/// only place an install's output is read.
|
||||
fn redacted_step(&self, mut step: InstallStepResult) -> InstallStepResult {
|
||||
step.command = redact(&step.command, &self.secrets);
|
||||
step.stdout = redact(&step.stdout, &self.secrets);
|
||||
step.stderr = redact(&step.stderr, &self.secrets);
|
||||
step.hint = step.hint.map(|hint| redact(&hint, &self.secrets));
|
||||
step
|
||||
}
|
||||
|
||||
/// Append one record. Best-effort by contract: a full disk or a revoked
|
||||
/// permission degrades the diagnostics, it does not fail the install.
|
||||
fn write_record(&self, attempt: Option<u32>, outcome: &InstallOutcome) {
|
||||
let Some(log) = &self.log else {
|
||||
return;
|
||||
};
|
||||
log.append(&render_record(
|
||||
attempt,
|
||||
log.take_attempt_elapsed(),
|
||||
outcome,
|
||||
&self.secrets,
|
||||
));
|
||||
}
|
||||
}
|
||||
|
||||
/// The shared half of the reporter — everything a drain thread's observer needs,
|
||||
/// owned rather than borrowed so an observer can outlive the call that made it.
|
||||
#[derive(Clone)]
|
||||
struct Live {
|
||||
runtime_id: Arc<str>,
|
||||
emit: EmitEvent,
|
||||
throttle: Arc<Throttle>,
|
||||
seq: Arc<AtomicU64>,
|
||||
/// Lifecycle lock: `true` while the run is active, `false` once
|
||||
/// `InstallReporter` has been dropped.
|
||||
///
|
||||
/// Drain threads hold a **shared read guard** from the admission check
|
||||
/// through the `(self.emit)(...)` call, making the admit-and-publish pair
|
||||
/// atomic with respect to deactivation. `InstallReporter::drop` takes the
|
||||
/// **exclusive write guard** and sets the value to `false`; this blocks
|
||||
/// until every in-flight publication finishes, then prevents any new
|
||||
/// publications from starting. The write lock is held only for the flag
|
||||
/// store and is released before the per-runtime concurrency guard drops,
|
||||
/// so its duration is bounded by the time a single `emit` call takes —
|
||||
/// microseconds to low milliseconds for the Tauri IPC broadcast.
|
||||
lifecycle: Arc<RwLock<bool>>,
|
||||
secrets: Secrets,
|
||||
}
|
||||
|
||||
impl Live {
|
||||
/// Offer one drained line to the rate limiter, emitting it if the window is
|
||||
/// open and holding it as the newest pending line if not.
|
||||
///
|
||||
/// The read guard is held from the admission check through the emit call so
|
||||
/// that `InstallReporter::drop`'s write lock must wait for any in-flight
|
||||
/// publication to complete before deactivating. This makes the
|
||||
/// check-then-emit pair atomic with respect to shutdown.
|
||||
fn offer(&self, line: &str) {
|
||||
let Ok(guard) = self.lifecycle.read() else {
|
||||
return;
|
||||
};
|
||||
if !*guard {
|
||||
return;
|
||||
}
|
||||
if let Some(line) = self.throttle.offer(line, Instant::now()) {
|
||||
self.publish_under_guard(line);
|
||||
}
|
||||
// `guard` drops here, releasing the read lock after publication.
|
||||
}
|
||||
|
||||
fn flush_pending(&self) {
|
||||
let Ok(guard) = self.lifecycle.read() else {
|
||||
return;
|
||||
};
|
||||
if !*guard {
|
||||
return;
|
||||
}
|
||||
if let Some(line) = self.throttle.take_pending() {
|
||||
self.publish_under_guard(line);
|
||||
}
|
||||
// `guard` drops here, releasing the read lock after publication.
|
||||
}
|
||||
|
||||
/// Emit `line` now, bypassing the rate window and the lifecycle lock.
|
||||
///
|
||||
/// Only called from `InstallReporter` methods that run on the reporter
|
||||
/// itself (never from detached drain threads), so no lifecycle guard is
|
||||
/// needed — the reporter is alive by definition when its own methods run.
|
||||
fn publish(&self, line: Option<String>) {
|
||||
(self.emit)(InstallOutputEvent {
|
||||
runtime_id: self.runtime_id.to_string(),
|
||||
seq: self.seq.fetch_add(1, Ordering::Relaxed),
|
||||
line: line.map(|line| redact(&line, &self.secrets)),
|
||||
});
|
||||
}
|
||||
|
||||
/// Publish `line` while already holding a read guard on `lifecycle`. The
|
||||
/// caller is responsible for checking `active` before calling this.
|
||||
fn publish_under_guard(&self, line: String) {
|
||||
(self.emit)(InstallOutputEvent {
|
||||
runtime_id: self.runtime_id.to_string(),
|
||||
seq: self.seq.fetch_add(1, Ordering::Relaxed),
|
||||
line: Some(redact(&line, &self.secrets)),
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
/// This run's log file: one session, opened once, appended to per record.
|
||||
struct InstallLog {
|
||||
path: PathBuf,
|
||||
/// When the attempt currently running started, so its record can name its
|
||||
/// own duration. A 15-minute ceiling is only diagnosable if the file says
|
||||
/// how long each attempt actually took.
|
||||
attempt_start: Mutex<Option<Instant>>,
|
||||
}
|
||||
|
||||
impl InstallLog {
|
||||
/// Start this run's session, or `None` if the file cannot be opened.
|
||||
///
|
||||
/// Rotation happens here, once per run, rather than per record: a run either
|
||||
/// gets its own file or it gets no log at all, so two runs are never
|
||||
/// interleaved in one file.
|
||||
///
|
||||
/// The header identifies the environment the run happened in, not just the
|
||||
/// run: a Windows install failure and a macOS one on the same runtime are
|
||||
/// different bugs, and a stale app version explains a failure that no longer
|
||||
/// reproduces.
|
||||
fn start(path: &Path, runtime_id: &str, app_version: &str) -> Option<Self> {
|
||||
let mut file = crate::managed_agents::storage::start_install_log_session(path).ok()?;
|
||||
let _ = file.write_all(
|
||||
format!(
|
||||
"=== install run runtime={runtime_id} app={app_version} os={} started={}\n",
|
||||
std::env::consts::OS,
|
||||
chrono::Utc::now().to_rfc3339()
|
||||
)
|
||||
.as_bytes(),
|
||||
);
|
||||
Some(Self {
|
||||
path: path.to_path_buf(),
|
||||
attempt_start: Mutex::new(None),
|
||||
})
|
||||
}
|
||||
|
||||
fn mark_attempt_start(&self) {
|
||||
if let Ok(mut start) = self.attempt_start.lock() {
|
||||
*start = Some(Instant::now());
|
||||
}
|
||||
}
|
||||
|
||||
/// How long the attempt being recorded ran, consumed so a later record
|
||||
/// cannot reuse it. `None` for a synthesized step, which never ran.
|
||||
fn take_attempt_elapsed(&self) -> Option<Duration> {
|
||||
Some(self.attempt_start.lock().ok()?.take()?.elapsed())
|
||||
}
|
||||
|
||||
fn append(&self, record: &str) {
|
||||
if let Ok(mut file) = crate::managed_agents::storage::open_install_log_file(&self.path) {
|
||||
let _ = file.write_all(record.as_bytes());
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// One self-contained record. Each is capped independently by the log-scale
|
||||
/// capture that produced it, so an early attempt that printed megabytes cannot
|
||||
/// push a later attempt — or the verification step that explains the failure —
|
||||
/// out of the file.
|
||||
fn render_record(
|
||||
attempt: Option<u32>,
|
||||
elapsed: Option<Duration>,
|
||||
outcome: &InstallOutcome,
|
||||
secrets: &Secrets,
|
||||
) -> String {
|
||||
let step = &outcome.step;
|
||||
let attempt = attempt.map_or_else(|| "-".to_string(), |n| n.to_string());
|
||||
let exit = step
|
||||
.exit_code
|
||||
.map_or_else(|| "none".to_string(), |code| code.to_string());
|
||||
let elapsed = elapsed.map_or_else(
|
||||
|| "-".to_string(),
|
||||
|elapsed| format!("{:.1}s", elapsed.as_secs_f64()),
|
||||
);
|
||||
let mut record = format!(
|
||||
"=== {} step={} attempt={attempt} success={} exit={exit} elapsed={elapsed}\n$ {}\n",
|
||||
chrono::Utc::now().to_rfc3339(),
|
||||
step.step,
|
||||
step.success,
|
||||
redact(&step.command, secrets),
|
||||
);
|
||||
for (label, text) in [
|
||||
("stdout", &outcome.log_stdout),
|
||||
("stderr", &outcome.log_stderr),
|
||||
] {
|
||||
if !text.trim().is_empty() {
|
||||
record.push_str(&format!("--- {label} ---\n{}\n", redact(text, secrets)));
|
||||
}
|
||||
}
|
||||
if let Some(hint) = &step.hint {
|
||||
record.push_str(&format!("--- hint ---\n{}\n", redact(hint, secrets)));
|
||||
}
|
||||
record
|
||||
}
|
||||
|
||||
/// Scrub secrets before anything reaches disk or the UI. The log is written
|
||||
/// unattended and the live line is rendered verbatim, so scrubbing happens at
|
||||
/// the write, not at the read.
|
||||
fn redact(text: &str, secrets: &Secrets) -> String {
|
||||
let extras: Vec<&str> = secrets.iter().map(String::as_str).collect();
|
||||
crate::managed_agents::redact_secrets_with(text, &extras)
|
||||
}
|
||||
|
||||
/// Values of environment variables whose *name* marks them as secret.
|
||||
///
|
||||
/// An install inherits Buzz's environment and installers echo it back — npm
|
||||
/// prints the resolved registry config on an auth failure, and a shell that
|
||||
/// traces its commands prints every expansion. Without this, only the
|
||||
/// hard-coded key shapes would be scrubbed, so a plain `NPM_TOKEN` or
|
||||
/// `ANTHROPIC_API_KEY` would land in the file in clear text.
|
||||
fn env_secret_values() -> Vec<String> {
|
||||
secret_values_from(std::env::vars())
|
||||
}
|
||||
|
||||
/// The secret-bearing part of each variable that carries one.
|
||||
///
|
||||
/// Split from [`env_secret_values`] so the classification is assertable without
|
||||
/// mutating the process environment — setting a real `HTTPS_PROXY` in a test
|
||||
/// would be read by every HTTP client the rest of the suite builds.
|
||||
///
|
||||
/// Three kinds of variable are recognised, because they need different
|
||||
/// treatment:
|
||||
///
|
||||
/// * **URL-valued variables**, where only the userinfo is the credential;
|
||||
/// * **exactly named credentials**, whose whole value is the secret; and
|
||||
/// * **name-marked secrets**, matched by a marker substring.
|
||||
fn secret_values_from(vars: impl IntoIterator<Item = (String, String)>) -> Vec<String> {
|
||||
vars.into_iter()
|
||||
.filter_map(|(name, value)| {
|
||||
let name = name.to_ascii_uppercase();
|
||||
if URL_CREDENTIAL_VAR_NAMES.contains(&name.as_str()) {
|
||||
// Only the userinfo, so the endpoint itself stays named in the
|
||||
// record: an install that fails against a proxy or a private
|
||||
// registry is diagnosable only if the log still says which one
|
||||
// it went through, and the host and port are not the secret.
|
||||
// Redacting the whole value would erase that while protecting
|
||||
// nothing more.
|
||||
return url_userinfo(&value).map(str::to_string);
|
||||
}
|
||||
if SECRET_VAR_NAMES.contains(&name.as_str()) {
|
||||
// Deliberately not subject to the 8-byte floor below: an exact
|
||||
// name is a fact, not the guess the marker rule makes, so there
|
||||
// is nothing for a floor to protect against. npm's one-time
|
||||
// password is six digits and is a credential at that length —
|
||||
// short, but still above the four-byte minimum
|
||||
// [`crate::managed_agents::redact_secrets_with`] applies, so it
|
||||
// survives to be scrubbed.
|
||||
return (!value.is_empty()).then_some(value);
|
||||
}
|
||||
// A value under 8 bytes is more likely a flag like `true` or a
|
||||
// version than a credential, and scrubbing those makes ordinary
|
||||
// output unreadable.
|
||||
(value.len() >= 8 && name_marks_secret(&name)).then_some(value)
|
||||
})
|
||||
.collect()
|
||||
}
|
||||
|
||||
/// Variables whose value is a URL that may embed a credential in its userinfo.
|
||||
///
|
||||
/// npm's own `npm_config_*` aliases are here too: npm resolves them ahead of
|
||||
/// the conventional names and echoes the result from `npm config list`, and
|
||||
/// none of these names carries a marker [`name_marks_secret`] would catch.
|
||||
/// Matching is case-insensitive because the caller uppercases the name first,
|
||||
/// which is what npm's lowercase spelling needs.
|
||||
const URL_CREDENTIAL_VAR_NAMES: &[&str] = &[
|
||||
"HTTP_PROXY",
|
||||
"HTTPS_PROXY",
|
||||
"ALL_PROXY",
|
||||
"NPM_CONFIG_PROXY",
|
||||
"NPM_CONFIG_HTTPS_PROXY",
|
||||
"NPM_CONFIG_REGISTRY",
|
||||
];
|
||||
|
||||
/// Variables whose whole value is a credential, recognised by exact name.
|
||||
///
|
||||
/// These are npm's supported credential settings, whose names carry no marker
|
||||
/// [`name_marks_secret`] would catch. They are listed exactly rather than
|
||||
/// matched on `KEY` or `AUTH` substrings: those occur throughout an ordinary
|
||||
/// environment, and scrubbing on them would delete unrelated values from the
|
||||
/// whole log.
|
||||
///
|
||||
/// * `NPM_CONFIG_KEY` — the PEM client key used to reach a registry.
|
||||
/// * `NPM_CONFIG__AUTH` — the base64 basic-auth blob (npm's own double
|
||||
/// underscore, matching the `_auth` setting).
|
||||
/// * `NPM_CONFIG_OTP` — the registry one-time password.
|
||||
const SECRET_VAR_NAMES: &[&str] = &["NPM_CONFIG_KEY", "NPM_CONFIG__AUTH", "NPM_CONFIG_OTP"];
|
||||
|
||||
/// Whether an environment variable's name marks its value as a credential.
|
||||
///
|
||||
/// Keyed on the name because a secret's *value* has no reliable shape. The
|
||||
/// markers avoid substrings that occur in non-secret names: `AUTH` is left out
|
||||
/// because it matches `GIT_AUTHOR_NAME`, whose value is a person's name, and
|
||||
/// personal access tokens match on `_PAT` as a *suffix* rather than a substring
|
||||
/// — `contains("_PAT")` would match every `*_PATH` variable on the system and
|
||||
/// scrub directory names out of the whole log.
|
||||
fn name_marks_secret(name: &str) -> bool {
|
||||
const SECRET_NAME_MARKERS: &[&str] = &[
|
||||
"TOKEN",
|
||||
"SECRET",
|
||||
"PASSWORD",
|
||||
"PASSWD",
|
||||
"APIKEY",
|
||||
"API_KEY",
|
||||
"PRIVATE_KEY",
|
||||
"ACCESS_KEY",
|
||||
"CREDENTIAL",
|
||||
];
|
||||
name.ends_with("_PAT")
|
||||
|| SECRET_NAME_MARKERS
|
||||
.iter()
|
||||
.any(|marker| name.contains(marker))
|
||||
}
|
||||
|
||||
/// The `user:password` credential embedded in a URL, if it has one.
|
||||
///
|
||||
/// Parsed rather than pattern-matched so a URL with no credential — the common
|
||||
/// case — contributes nothing to scrub. The last `@` in the
|
||||
/// authority separates userinfo from host, so a password containing an
|
||||
/// encoded `@` still splits correctly.
|
||||
///
|
||||
/// A bare username with no password is not treated as a credential: it is not
|
||||
/// secret on its own, and scrubbing it would erase every occurrence of a word
|
||||
/// like `user` from the whole record.
|
||||
fn url_userinfo(value: &str) -> Option<&str> {
|
||||
let authority = value
|
||||
.split_once("://")?
|
||||
.1
|
||||
.split(['/', '?', '#'])
|
||||
.next()
|
||||
.unwrap_or_default();
|
||||
let userinfo = authority.rsplit_once('@')?.0;
|
||||
userinfo.contains(':').then_some(userinfo)
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
#[path = "install_report_test_support.rs"]
|
||||
mod test_support;
|
||||
|
||||
#[cfg(test)]
|
||||
#[path = "install_report_tests.rs"]
|
||||
mod tests;
|
||||
|
||||
#[cfg(test)]
|
||||
#[path = "install_report_redaction_tests.rs"]
|
||||
mod redaction_tests;
|
||||
@@ -0,0 +1,480 @@
|
||||
use super::test_support::*;
|
||||
use super::*;
|
||||
|
||||
// ── redaction ────────────────────────────────────────────────────────────────
|
||||
|
||||
/// Secrets that an installer echoed must not land on disk. The log is written
|
||||
/// unattended, so scrubbing happens at the write, not at the read.
|
||||
#[test]
|
||||
fn test_log_redacts_secrets_before_writing() {
|
||||
let h = harness();
|
||||
let leak = "npm ERR! token nsec1qqqqqqqqqqsecretvalue failed";
|
||||
|
||||
h.reporter.record_attempt(1, outcome("cli", false, leak));
|
||||
|
||||
let log = h.log_contents();
|
||||
assert!(!log.contains("nsec1qqqqqqqqqqsecretvalue"), "got: {log}");
|
||||
assert!(log.contains("[REDACTED]"), "got: {log}");
|
||||
}
|
||||
|
||||
/// The environment's own secrets are scrubbed too, by *name* rather than shape.
|
||||
/// An install inherits Buzz's environment and installers echo it back — npm
|
||||
/// prints its resolved config on an auth failure — and a token with no
|
||||
/// recognizable prefix would otherwise reach the file verbatim.
|
||||
#[test]
|
||||
fn test_log_redacts_an_environment_secret_with_no_recognizable_prefix() {
|
||||
let secret = "0e8f31c5a4b7d296e5f1a";
|
||||
// Set before the reporter is built: the snapshot is taken at construction.
|
||||
std::env::set_var("BUZZ_TEST_REGISTRY_TOKEN", secret);
|
||||
let h = harness();
|
||||
std::env::remove_var("BUZZ_TEST_REGISTRY_TOKEN");
|
||||
|
||||
h.reporter.record_attempt(
|
||||
1,
|
||||
outcome("cli", false, &format!("npm ERR! _authToken={secret}")),
|
||||
);
|
||||
|
||||
let log = h.log_contents();
|
||||
assert!(!log.contains(secret), "got: {log}");
|
||||
assert!(log.contains("[REDACTED]"), "got: {log}");
|
||||
}
|
||||
|
||||
/// A live line carries the same scrubbing as the log record. The line is
|
||||
/// rendered verbatim in the UI, so a leak there is as visible as one on disk.
|
||||
#[test]
|
||||
fn test_a_live_line_is_redacted_before_it_is_emitted() {
|
||||
let h = harness();
|
||||
|
||||
let observer = h.reporter.line_observer().expect("an observer");
|
||||
observer("fetching with token nsec1qqqqqqqqqqleaked");
|
||||
|
||||
let lines = h.lines();
|
||||
assert_eq!(lines.len(), 1);
|
||||
let line = lines[0].clone().expect("a line, not a clear signal");
|
||||
assert!(!line.contains("nsec1qqqqqqqqqqleaked"), "got: {line}");
|
||||
assert!(line.contains("[REDACTED]"), "got: {line}");
|
||||
}
|
||||
|
||||
// ── proxy and PAT credentials ────────────────────────────────────────────────
|
||||
|
||||
/// A proxy URL's password is a credential, but the proxy itself is diagnostic
|
||||
/// information: an install that fails behind a proxy is only debuggable if the
|
||||
/// record still says which proxy it went through. So the userinfo is scrubbed
|
||||
/// and the host is kept.
|
||||
#[test]
|
||||
fn test_proxy_userinfo_is_secret_but_the_proxy_host_is_not() {
|
||||
let secrets = secret_values_from([(
|
||||
"HTTPS_PROXY".to_string(),
|
||||
"http://corpuser:hunter2pass@proxy.example:8080".to_string(),
|
||||
)]);
|
||||
|
||||
assert_eq!(secrets, vec!["corpuser:hunter2pass"]);
|
||||
}
|
||||
|
||||
/// A proxy with no credential contributes nothing — scrubbing a bare host would
|
||||
/// erase the proxy's name from every record while protecting nothing. A bare
|
||||
/// username is not a credential either, and scrubbing it would delete every
|
||||
/// occurrence of that word from the log.
|
||||
#[test]
|
||||
fn test_a_proxy_without_credentials_contributes_no_secret() {
|
||||
let secrets = secret_values_from([
|
||||
(
|
||||
"HTTP_PROXY".to_string(),
|
||||
"http://proxy.example:8080".to_string(),
|
||||
),
|
||||
(
|
||||
"ALL_PROXY".to_string(),
|
||||
"socks5://10.0.0.1:1080".to_string(),
|
||||
),
|
||||
(
|
||||
"HTTPS_PROXY".to_string(),
|
||||
"http://user@proxy.example:8080".to_string(),
|
||||
),
|
||||
]);
|
||||
|
||||
assert!(secrets.is_empty(), "got: {secrets:?}");
|
||||
}
|
||||
|
||||
/// npm reads its own `npm_config_*` aliases in preference to the conventional
|
||||
/// proxy variables and prints the resolved value back, so a credential set only
|
||||
/// under an alias would otherwise never enter the scrub list. npm spells them
|
||||
/// in lowercase, so both cases have to classify.
|
||||
#[test]
|
||||
fn test_npm_proxy_aliases_are_classified_in_either_case() {
|
||||
let secrets = secret_values_from([
|
||||
(
|
||||
"npm_config_proxy".to_string(),
|
||||
"http://corpuser:lowerplain@proxy.example:8080".to_string(),
|
||||
),
|
||||
(
|
||||
"NPM_CONFIG_PROXY".to_string(),
|
||||
"http://corpuser:upperplain@proxy.example:8080".to_string(),
|
||||
),
|
||||
(
|
||||
"npm_config_https_proxy".to_string(),
|
||||
"http://corpuser:lowertls@proxy.example:8080".to_string(),
|
||||
),
|
||||
(
|
||||
"NPM_CONFIG_HTTPS_PROXY".to_string(),
|
||||
"http://corpuser:uppertls@proxy.example:8080".to_string(),
|
||||
),
|
||||
]);
|
||||
|
||||
assert_eq!(
|
||||
secrets,
|
||||
vec![
|
||||
"corpuser:lowerplain",
|
||||
"corpuser:upperplain",
|
||||
"corpuser:lowertls",
|
||||
"corpuser:uppertls",
|
||||
]
|
||||
);
|
||||
}
|
||||
|
||||
/// The alias carries the same userinfo-only policy as the conventional names:
|
||||
/// a credential-less alias contributes nothing, so the proxy stays named in the
|
||||
/// record.
|
||||
#[test]
|
||||
fn test_an_npm_proxy_alias_without_credentials_contributes_no_secret() {
|
||||
let secrets = secret_values_from([
|
||||
(
|
||||
"npm_config_proxy".to_string(),
|
||||
"http://proxy.example:8080".to_string(),
|
||||
),
|
||||
(
|
||||
"NPM_CONFIG_HTTPS_PROXY".to_string(),
|
||||
"http://user@proxy.example:8080".to_string(),
|
||||
),
|
||||
]);
|
||||
|
||||
assert!(secrets.is_empty(), "got: {secrets:?}");
|
||||
}
|
||||
|
||||
/// The classifier and the reporter have to agree: an alias credential that
|
||||
/// classifies but never reaches the scrub list still leaks. This drives the
|
||||
/// reporter with exactly what the classifier produced for an alias, and asserts
|
||||
/// the log and the returned step both come back clean.
|
||||
#[test]
|
||||
fn test_an_npm_alias_credential_is_redacted_from_the_log_and_the_returned_step() {
|
||||
let password = "hunter2pass";
|
||||
let h = harness_with_secrets(secret_values_from([(
|
||||
"npm_config_proxy".to_string(),
|
||||
format!("http://corpuser:{password}@proxy.example:8080"),
|
||||
)]));
|
||||
|
||||
let returned = h.reporter.record_attempt(
|
||||
1,
|
||||
InstallOutcome {
|
||||
step: InstallStepResult {
|
||||
stderr: format!(
|
||||
"npm ERR! proxy=http://corpuser:{password}@proxy.example:8080 tunneling failed"
|
||||
),
|
||||
..step("cli", false, "")
|
||||
},
|
||||
log_stdout: String::new(),
|
||||
log_stderr: format!(
|
||||
"npm config: proxy = http://corpuser:{password}@proxy.example:8080"
|
||||
),
|
||||
},
|
||||
);
|
||||
|
||||
let log = h.log_contents();
|
||||
assert!(!log.contains(password), "log leaked the password: {log}");
|
||||
assert!(
|
||||
log.contains("proxy.example"),
|
||||
"the proxy host is diagnostic and must survive: {log}"
|
||||
);
|
||||
assert!(
|
||||
!returned.stderr.contains(password),
|
||||
"the returned step leaked the password: {}",
|
||||
returned.stderr
|
||||
);
|
||||
}
|
||||
|
||||
// ── npm's own credential settings ────────────────────────────────────────────
|
||||
|
||||
/// npm accepts every one of its settings as an `npm_config_*` variable, so a
|
||||
/// registry client key, a basic-auth blob or a one-time password can arrive
|
||||
/// under a name that carries no marker. Their whole value is the credential —
|
||||
/// unlike a proxy, none of it is diagnostic — and npm spells them in lowercase.
|
||||
#[test]
|
||||
fn test_npm_credential_configs_are_secret_in_either_case() {
|
||||
let secrets = secret_values_from([
|
||||
(
|
||||
"npm_config_key".to_string(),
|
||||
"-----BEGIN PRIVATE KEY-----lowerkey".to_string(),
|
||||
),
|
||||
(
|
||||
"NPM_CONFIG_KEY".to_string(),
|
||||
"-----BEGIN PRIVATE KEY-----upperkey".to_string(),
|
||||
),
|
||||
("npm_config__auth".to_string(), "bG93ZXJhdXRo".to_string()),
|
||||
("NPM_CONFIG__AUTH".to_string(), "dXBwZXJhdXRo".to_string()),
|
||||
("npm_config_otp".to_string(), "618243".to_string()),
|
||||
("NPM_CONFIG_OTP".to_string(), "907154".to_string()),
|
||||
]);
|
||||
|
||||
assert_eq!(
|
||||
secrets,
|
||||
vec![
|
||||
"-----BEGIN PRIVATE KEY-----lowerkey",
|
||||
"-----BEGIN PRIVATE KEY-----upperkey",
|
||||
"bG93ZXJhdXRo",
|
||||
"dXBwZXJhdXRo",
|
||||
"618243",
|
||||
"907154",
|
||||
]
|
||||
);
|
||||
}
|
||||
|
||||
/// An unset-but-exported credential is empty, and an empty needle would match
|
||||
/// everywhere. The name being exact does not make a blank value a secret.
|
||||
#[test]
|
||||
fn test_an_empty_npm_credential_config_contributes_no_secret() {
|
||||
let secrets = secret_values_from([
|
||||
("NPM_CONFIG_KEY".to_string(), String::new()),
|
||||
("npm_config_otp".to_string(), String::new()),
|
||||
]);
|
||||
|
||||
assert!(secrets.is_empty(), "got: {secrets:?}");
|
||||
}
|
||||
|
||||
/// A private registry's URL follows the proxy policy rather than the whole-value
|
||||
/// one: which registry an install talked to is exactly what a 401 or an ETIMEDOUT
|
||||
/// has to be read against, so only the userinfo is the secret.
|
||||
#[test]
|
||||
fn test_npm_registry_userinfo_is_secret_but_the_registry_host_is_not() {
|
||||
let secrets = secret_values_from([(
|
||||
"npm_config_registry".to_string(),
|
||||
"https://builder:hunter2pass@registry.example/api/npm/".to_string(),
|
||||
)]);
|
||||
|
||||
assert_eq!(secrets, vec!["builder:hunter2pass"]);
|
||||
}
|
||||
|
||||
/// The public registry — and any private one reached with a token header rather
|
||||
/// than URL credentials — contributes nothing, so the registry stays named in
|
||||
/// the record.
|
||||
#[test]
|
||||
fn test_an_npm_registry_without_credentials_contributes_no_secret() {
|
||||
let secrets = secret_values_from([
|
||||
(
|
||||
"npm_config_registry".to_string(),
|
||||
"https://registry.npmjs.org/".to_string(),
|
||||
),
|
||||
(
|
||||
"NPM_CONFIG_REGISTRY".to_string(),
|
||||
"https://builder@registry.example/api/npm/".to_string(),
|
||||
),
|
||||
]);
|
||||
|
||||
assert!(secrets.is_empty(), "got: {secrets:?}");
|
||||
}
|
||||
|
||||
/// The credential settings are matched by exact name, never by a `KEY` or
|
||||
/// `AUTH` substring. Those occur throughout an ordinary environment on values
|
||||
/// that are paths, agent sockets and people's names, and scrubbing them would
|
||||
/// delete unrelated text from every record.
|
||||
#[test]
|
||||
fn test_key_and_auth_inside_a_variable_name_do_not_make_it_secret() {
|
||||
let secrets = secret_values_from([
|
||||
(
|
||||
"SSH_AUTH_SOCK".to_string(),
|
||||
"/tmp/ssh-agent.socket".to_string(),
|
||||
),
|
||||
("GIT_AUTHOR_NAME".to_string(), "Ada Lovelace".to_string()),
|
||||
(
|
||||
"KEYCHAIN".to_string(),
|
||||
"/Users/dev/Library/login.keychain".to_string(),
|
||||
),
|
||||
(
|
||||
"NPM_CONFIG_KEYFILE".to_string(),
|
||||
"/Users/dev/.npm/client.pem".to_string(),
|
||||
),
|
||||
]);
|
||||
|
||||
assert!(secrets.is_empty(), "got: {secrets:?}");
|
||||
}
|
||||
|
||||
/// The wiring, not just the classification: npm prints its resolved config on an
|
||||
/// auth failure, so each of these has to be gone from the log and from the step
|
||||
/// the frontend renders. The one-time password is the interesting one — at six
|
||||
/// digits it is far shorter than any other secret here, and a value under four
|
||||
/// bytes is dropped by the shared redactor rather than scrubbed.
|
||||
#[test]
|
||||
fn test_npm_credential_configs_are_redacted_from_the_log_and_the_returned_step() {
|
||||
let client_key = "-----BEGIN PRIVATE KEY-----MIIEvQIBADAN";
|
||||
let auth = "YnVpbGRlcjpodW50ZXIycGFzcw==";
|
||||
let otp = "618243";
|
||||
let registry_password = "hunter2pass";
|
||||
let h = harness_with_secrets(secret_values_from([
|
||||
("npm_config_key".to_string(), client_key.to_string()),
|
||||
("npm_config__auth".to_string(), auth.to_string()),
|
||||
("npm_config_otp".to_string(), otp.to_string()),
|
||||
(
|
||||
"npm_config_registry".to_string(),
|
||||
format!("https://builder:{registry_password}@registry.example/api/npm/"),
|
||||
),
|
||||
]));
|
||||
|
||||
let returned = h.reporter.record_attempt(
|
||||
1,
|
||||
InstallOutcome {
|
||||
step: InstallStepResult {
|
||||
stderr: format!("npm ERR! 401 otp={otp} _auth={auth}"),
|
||||
..step("cli", false, "")
|
||||
},
|
||||
log_stdout: format!("npm config: key = {client_key}"),
|
||||
log_stderr: format!(
|
||||
"npm config: registry = https://builder:{registry_password}@registry.example/api/npm/"
|
||||
),
|
||||
},
|
||||
);
|
||||
|
||||
let log = h.log_contents();
|
||||
for secret in [client_key, auth, otp, registry_password] {
|
||||
assert!(!log.contains(secret), "log leaked {secret}: {log}");
|
||||
}
|
||||
assert!(
|
||||
log.contains("registry.example"),
|
||||
"the registry host is diagnostic and must survive: {log}"
|
||||
);
|
||||
assert!(
|
||||
!returned.stderr.contains(otp) && !returned.stderr.contains(auth),
|
||||
"the returned step leaked a credential: {}",
|
||||
returned.stderr
|
||||
);
|
||||
}
|
||||
|
||||
/// `*_PATH` variables must not be mistaken for personal access tokens. A
|
||||
/// `contains("_PAT")` rule would match `PATH` itself and scrub every directory
|
||||
/// name out of the log, which is why the rule matches `_PAT` as a suffix.
|
||||
#[test]
|
||||
fn test_a_path_variable_is_not_treated_as_a_personal_access_token() {
|
||||
let secrets = secret_values_from([
|
||||
("PATH".to_string(), "/usr/local/bin:/usr/bin".to_string()),
|
||||
("GOPATH".to_string(), "/home/user/go".to_string()),
|
||||
(
|
||||
"CARGO_HOME_PATH".to_string(),
|
||||
"/home/user/.cargo".to_string(),
|
||||
),
|
||||
]);
|
||||
|
||||
assert!(secrets.is_empty(), "got: {secrets:?}");
|
||||
}
|
||||
|
||||
/// Variables named as personal access tokens are secret by name, whatever shape
|
||||
/// their value has.
|
||||
#[test]
|
||||
fn test_pat_named_variables_are_secret() {
|
||||
let secrets = secret_values_from([
|
||||
(
|
||||
"GITHUB_PAT".to_string(),
|
||||
"ghp_abcdefghij0123456789".to_string(),
|
||||
),
|
||||
(
|
||||
"GH_PAT".to_string(),
|
||||
"github_pat_abcdefghij0123".to_string(),
|
||||
),
|
||||
]);
|
||||
|
||||
assert_eq!(secrets.len(), 2, "got: {secrets:?}");
|
||||
}
|
||||
|
||||
/// The whole point of the widening: a proxy password and a PAT that the
|
||||
/// installer echoed reach neither the log nor the live line.
|
||||
///
|
||||
/// Both are checked through the real reporter rather than the classifier, so
|
||||
/// this covers the wiring — a classifier that recognises a secret the reporter
|
||||
/// never consults would still leak.
|
||||
#[test]
|
||||
fn test_proxy_and_pat_credentials_are_redacted_from_the_log_and_the_live_line() {
|
||||
let proxy_password = "hunter2pass";
|
||||
let pat = "ghp_abcdefghij0123456789";
|
||||
// The classifier's own tests cover recognising these under their real
|
||||
// variable names; injecting the resulting secrets here keeps a live
|
||||
// `HTTPS_PROXY` out of the process the rest of the suite shares.
|
||||
let h = harness_with_secrets(vec![format!("corpuser:{proxy_password}"), pat.to_string()]);
|
||||
|
||||
h.reporter.record_attempt(
|
||||
1,
|
||||
outcome(
|
||||
"cli",
|
||||
false,
|
||||
&format!(
|
||||
"npm ERR! proxy=http://corpuser:{proxy_password}@proxy.example authToken={pat}"
|
||||
),
|
||||
),
|
||||
);
|
||||
let observer = h.reporter.line_observer().expect("an observer");
|
||||
observer(&format!("cloning https://{pat}@github.com/org/repo"));
|
||||
|
||||
let log = h.log_contents();
|
||||
assert!(
|
||||
!log.contains(proxy_password),
|
||||
"log leaked the proxy password: {log}"
|
||||
);
|
||||
assert!(!log.contains(pat), "log leaked the PAT: {log}");
|
||||
assert!(
|
||||
log.contains("proxy.example"),
|
||||
"the proxy host is diagnostic and must survive: {log}"
|
||||
);
|
||||
|
||||
let line = h.lines().into_iter().flatten().next().expect("a live line");
|
||||
assert!(!line.contains(pat), "live line leaked the PAT: {line}");
|
||||
assert!(line.contains("[REDACTED]"), "got: {line}");
|
||||
}
|
||||
|
||||
/// The third surface: the step returned to the frontend. `getInstallErrorMessage`
|
||||
/// renders the failing step's stderr verbatim, so a secret that the log and the
|
||||
/// live line both scrub would still reach the user through the error dialog.
|
||||
#[test]
|
||||
fn test_a_returned_step_is_redacted_before_the_frontend_renders_it() {
|
||||
let pat = "ghp_abcdefghij0123456789";
|
||||
let h = harness_with_secrets(vec![pat.to_string()]);
|
||||
|
||||
let returned = h.reporter.record_attempt(
|
||||
1,
|
||||
InstallOutcome {
|
||||
step: InstallStepResult {
|
||||
stdout: format!("configuring remote with {pat}"),
|
||||
stderr: format!("fatal: authentication failed for token {pat}"),
|
||||
hint: Some(format!("check that {pat} has the repo scope")),
|
||||
..step("cli", false, "")
|
||||
},
|
||||
log_stdout: String::new(),
|
||||
log_stderr: String::new(),
|
||||
},
|
||||
);
|
||||
|
||||
assert!(!returned.stdout.contains(pat), "got: {}", returned.stdout);
|
||||
assert!(!returned.stderr.contains(pat), "got: {}", returned.stderr);
|
||||
let hint = returned.hint.expect("a hint");
|
||||
assert!(!hint.contains(pat), "got: {hint}");
|
||||
}
|
||||
|
||||
/// A synthesized step reaches the frontend through the other funnel, and needs
|
||||
/// the same scrubbing — the managed-node prerequisite failures are built this
|
||||
/// way and carry whatever the underlying command printed.
|
||||
#[test]
|
||||
fn test_a_synthesized_step_is_redacted_before_it_reaches_the_caller() {
|
||||
let pat = "ghp_abcdefghij0123456789";
|
||||
let h = harness_with_secrets(vec![pat.to_string()]);
|
||||
let mut steps = Vec::new();
|
||||
|
||||
h.reporter.record_step(
|
||||
&mut steps,
|
||||
InstallStepResult {
|
||||
stderr: format!("npm ERR! 401 with {pat}"),
|
||||
..step("adapter", false, "")
|
||||
},
|
||||
);
|
||||
|
||||
assert_eq!(steps.len(), 1);
|
||||
assert!(!steps[0].stderr.contains(pat), "got: {}", steps[0].stderr);
|
||||
assert!(
|
||||
steps[0].stderr.contains("[REDACTED]"),
|
||||
"got: {}",
|
||||
steps[0].stderr
|
||||
);
|
||||
}
|
||||
@@ -0,0 +1,106 @@
|
||||
//! Shared harness for the install-report test modules.
|
||||
//!
|
||||
//! The tests are split by concern — redaction in
|
||||
//! [`super::install_report_redaction_tests`], everything else in
|
||||
//! [`super::install_report_tests`] — and both drive the reporter through the
|
||||
//! same harness, so it lives here rather than in either of them.
|
||||
|
||||
use super::*;
|
||||
use std::sync::Mutex;
|
||||
|
||||
/// Stands in for the real `app.package_info().version`, which needs a Tauri app.
|
||||
pub(crate) const TEST_APP_VERSION: &str = "9.9.9";
|
||||
|
||||
/// A reporter with a started log session in a temp dir, and the emitted events
|
||||
/// captured.
|
||||
pub(crate) struct Harness {
|
||||
/// Kept alive so the log outlives the harness; a test that reuses the
|
||||
/// directory for a second run takes it.
|
||||
pub(crate) _dir: tempfile::TempDir,
|
||||
pub(crate) log: PathBuf,
|
||||
pub(crate) reporter: InstallReporter,
|
||||
pub(crate) events: Arc<Mutex<Vec<InstallOutputEvent>>>,
|
||||
}
|
||||
|
||||
pub(crate) fn harness() -> Harness {
|
||||
harness_at(None)
|
||||
}
|
||||
|
||||
/// A harness whose log lives in `dir`, or in a fresh temp dir when `dir` is
|
||||
/// `None`. Passing a directory lets a test seed a previous run's file first.
|
||||
pub(crate) fn harness_at(dir: Option<tempfile::TempDir>) -> Harness {
|
||||
harness_inner(dir, None)
|
||||
}
|
||||
|
||||
/// A harness whose reporter scrubs exactly `secrets`, so a proxy or PAT
|
||||
/// credential can be asserted without exporting it into the process.
|
||||
pub(crate) fn harness_with_secrets(secrets: Vec<String>) -> Harness {
|
||||
harness_inner(None, Some(secrets))
|
||||
}
|
||||
|
||||
fn harness_inner(dir: Option<tempfile::TempDir>, secrets: Option<Vec<String>>) -> Harness {
|
||||
let dir = dir.unwrap_or_else(|| tempfile::tempdir().expect("tempdir"));
|
||||
let log = dir.path().join("install-goose.log");
|
||||
let events: Arc<Mutex<Vec<InstallOutputEvent>>> = Arc::new(Mutex::new(Vec::new()));
|
||||
let emit: EmitEvent = {
|
||||
let events = Arc::clone(&events);
|
||||
Arc::new(move |event| events.lock().unwrap().push(event))
|
||||
};
|
||||
let started = InstallLog::start(&log, "goose", TEST_APP_VERSION);
|
||||
Harness {
|
||||
reporter: match secrets {
|
||||
Some(secrets) => InstallReporter::with_secrets("goose", started, Some(emit), secrets),
|
||||
None => InstallReporter::new("goose", started, Some(emit)),
|
||||
},
|
||||
_dir: dir,
|
||||
log,
|
||||
events,
|
||||
}
|
||||
}
|
||||
|
||||
/// A reporter with no log file and nothing listening — the degraded shape.
|
||||
pub(crate) fn silent_reporter() -> InstallReporter {
|
||||
InstallReporter::new("goose", None, None)
|
||||
}
|
||||
|
||||
pub(crate) fn step(name: &str, success: bool, stderr: &str) -> InstallStepResult {
|
||||
InstallStepResult {
|
||||
step: name.to_string(),
|
||||
command: "curl … | bash".to_string(),
|
||||
success,
|
||||
stdout: String::new(),
|
||||
stderr: stderr.to_string(),
|
||||
exit_code: Some(if success { 0 } else { 1 }),
|
||||
hint: None,
|
||||
}
|
||||
}
|
||||
|
||||
/// An executed attempt whose log copy differs from the UI copy — the real shape,
|
||||
/// since the two views are capped differently.
|
||||
pub(crate) fn outcome(name: &str, success: bool, log_stdout: &str) -> InstallOutcome {
|
||||
InstallOutcome {
|
||||
step: step(name, success, ""),
|
||||
log_stdout: log_stdout.to_string(),
|
||||
log_stderr: String::new(),
|
||||
}
|
||||
}
|
||||
|
||||
impl Harness {
|
||||
pub(crate) fn log_contents(&self) -> String {
|
||||
std::fs::read_to_string(&self.log).unwrap_or_default()
|
||||
}
|
||||
|
||||
/// The emitted lines in order, with a clear signal rendered as `None`.
|
||||
pub(crate) fn lines(&self) -> Vec<Option<String>> {
|
||||
self.events
|
||||
.lock()
|
||||
.unwrap()
|
||||
.iter()
|
||||
.map(|e| e.line.clone())
|
||||
.collect()
|
||||
}
|
||||
|
||||
pub(crate) fn events(&self) -> Vec<InstallOutputEvent> {
|
||||
self.events.lock().unwrap().clone()
|
||||
}
|
||||
}
|
||||
@@ -0,0 +1,564 @@
|
||||
use super::test_support::*;
|
||||
use super::*;
|
||||
use crate::commands::agent_discovery::install_capture::{drain_into, Capture};
|
||||
|
||||
// ── the log records history the UI does not keep ─────────────────────────────
|
||||
|
||||
/// Every attempt is recorded, not just the one the UI surfaces. Reproducing an
|
||||
/// install failure means seeing whether attempts 1 and 2 failed the same way.
|
||||
#[test]
|
||||
fn test_log_records_every_attempt_not_only_the_last() {
|
||||
let h = harness();
|
||||
|
||||
h.reporter
|
||||
.record_attempt(1, outcome("cli", false, "attempt-one-output"));
|
||||
h.reporter
|
||||
.record_attempt(2, outcome("cli", false, "attempt-two-output"));
|
||||
|
||||
let log = h.log_contents();
|
||||
assert!(log.contains("attempt-one-output"), "got: {log}");
|
||||
assert!(log.contains("attempt-two-output"), "got: {log}");
|
||||
assert!(
|
||||
log.contains("attempt=1") && log.contains("attempt=2"),
|
||||
"got: {log}"
|
||||
);
|
||||
}
|
||||
|
||||
/// A first attempt that printed a huge amount must not push later records out of
|
||||
/// the file. Records are capped individually by the log-scale capture that
|
||||
/// produced them, so the run's total is bounded by steps × attempts × cap rather
|
||||
/// than by one runaway attempt.
|
||||
///
|
||||
/// The flood goes through a real [`Capture`] rather than straight into the
|
||||
/// record, so this exercises the cap that actually bounds a record.
|
||||
#[test]
|
||||
fn test_first_attempt_overflow_does_not_erase_later_records() {
|
||||
let h = harness();
|
||||
// Through the real drain, so the record is bounded by the cap that bounds a
|
||||
// production record rather than by a string this test chose.
|
||||
let capture = Capture::new();
|
||||
drain_into(vec![b'F'; 4 * 1024 * 1024].as_slice(), &capture, None);
|
||||
|
||||
h.reporter
|
||||
.record_attempt(1, outcome("cli", false, &capture.log()));
|
||||
h.reporter
|
||||
.record_attempt(2, outcome("cli", false, "second-attempt-detail"));
|
||||
h.reporter.record_step(
|
||||
&mut Vec::new(),
|
||||
step("verify", false, "verification-detail"),
|
||||
);
|
||||
|
||||
let log = h.log_contents();
|
||||
assert!(
|
||||
log.contains("bytes omitted at cap"),
|
||||
"the flooded record must be marked as cut"
|
||||
);
|
||||
assert!(
|
||||
log.contains("second-attempt-detail"),
|
||||
"a later attempt must survive an earlier flood"
|
||||
);
|
||||
assert!(
|
||||
log.contains("verification-detail"),
|
||||
"the synthesized step explaining the failure must survive too"
|
||||
);
|
||||
assert!(
|
||||
log.len() < 4 * 1024 * 1024,
|
||||
"4MiB of first-attempt output must not reach the file, got {} bytes",
|
||||
log.len()
|
||||
);
|
||||
}
|
||||
|
||||
/// A step Buzz synthesizes — a failed prerequisite, or post-install
|
||||
/// verification — reaches the log as well as the UI. `record_step` is the only
|
||||
/// path that guarantees this, which is why callers use it instead of
|
||||
/// `steps.push`.
|
||||
#[test]
|
||||
fn test_recording_a_synthesized_step_logs_it_and_keeps_it_for_the_ui() {
|
||||
let h = harness();
|
||||
let mut steps = Vec::new();
|
||||
|
||||
h.reporter
|
||||
.record_step(&mut steps, step("verify", false, "still-not-usable"));
|
||||
|
||||
assert_eq!(steps.len(), 1, "the UI must still receive the step");
|
||||
assert!(h.log_contents().contains("still-not-usable"));
|
||||
}
|
||||
|
||||
// ── one file per run ─────────────────────────────────────────────────────────
|
||||
|
||||
/// A run opens with a header naming the runtime and the environment the run
|
||||
/// happened in, so a file holding one run of several steps is identifiable as
|
||||
/// that run rather than a stream of records — and a failure report says which
|
||||
/// app version and OS produced it without a second round trip to the user.
|
||||
#[test]
|
||||
fn test_a_run_opens_with_a_header_naming_the_runtime_app_version_and_os() {
|
||||
let h = harness();
|
||||
let log = h.log_contents();
|
||||
|
||||
assert!(
|
||||
log.starts_with(&format!(
|
||||
"=== install run runtime=goose app={TEST_APP_VERSION} os={} started=",
|
||||
std::env::consts::OS
|
||||
)),
|
||||
"got: {log}"
|
||||
);
|
||||
}
|
||||
|
||||
/// A new run does not append to the previous run's file: it starts a fresh one
|
||||
/// and keeps the previous as `.1`. Reading a log has to mean reading one run —
|
||||
/// records accumulated across runs are indistinguishable from retries within
|
||||
/// one.
|
||||
#[test]
|
||||
fn test_a_new_run_starts_a_fresh_file_and_keeps_the_previous_as_dot_one() {
|
||||
let first = harness();
|
||||
first
|
||||
.reporter
|
||||
.record_attempt(1, outcome("cli", false, "previous-run-output"));
|
||||
let previous = first.log.clone();
|
||||
let dir = first._dir;
|
||||
drop(first.reporter);
|
||||
|
||||
let second = harness_at(Some(dir));
|
||||
second
|
||||
.reporter
|
||||
.record_attempt(1, outcome("cli", false, "current-run-output"));
|
||||
|
||||
let log = second.log_contents();
|
||||
assert!(log.contains("current-run-output"), "got: {log}");
|
||||
assert!(
|
||||
!log.contains("previous-run-output"),
|
||||
"the new run's file must not carry the previous run's records: {log}"
|
||||
);
|
||||
let rotated = std::fs::read_to_string(previous.with_extension("log.1")).expect("read .1");
|
||||
assert!(
|
||||
rotated.contains("previous-run-output"),
|
||||
"the previous run must remain readable as .1: {rotated}"
|
||||
);
|
||||
}
|
||||
|
||||
/// Each executed attempt records how long it ran. A 15-minute ceiling is only
|
||||
/// diagnosable if the file says which attempt consumed the time.
|
||||
#[test]
|
||||
fn test_an_executed_attempt_records_its_own_duration() {
|
||||
let h = harness();
|
||||
|
||||
h.reporter.start_attempt();
|
||||
h.reporter.record_attempt(1, outcome("cli", true, "done"));
|
||||
h.reporter
|
||||
.record_step(&mut Vec::new(), step("verify", true, ""));
|
||||
|
||||
let log = h.log_contents();
|
||||
assert!(
|
||||
log.contains("attempt=1") && log.contains("elapsed=0."),
|
||||
"an executed attempt must carry its duration: {log}"
|
||||
);
|
||||
assert!(
|
||||
log.contains("attempt=- ") && log.contains("elapsed=-"),
|
||||
"a synthesized step never ran, so it has no duration: {log}"
|
||||
);
|
||||
}
|
||||
|
||||
// ── the log pointer ──────────────────────────────────────────────────────────
|
||||
|
||||
/// The path is available as soon as the run's session opens, because the file
|
||||
/// exists from that moment — the header is already in it. A failure before any
|
||||
/// step ran still points the user at a real file.
|
||||
#[test]
|
||||
fn test_log_path_is_available_from_the_start_of_the_run() {
|
||||
let h = harness();
|
||||
|
||||
assert_eq!(h.reporter.log_path(), Some(h.log.display().to_string()));
|
||||
}
|
||||
|
||||
/// A reporter with no log — an unresolvable app-data directory — records
|
||||
/// nothing and reports no path, but must not panic or fail the install.
|
||||
#[test]
|
||||
fn test_reporter_without_a_log_records_nothing_and_reports_no_path() {
|
||||
let reporter = silent_reporter();
|
||||
let mut steps = Vec::new();
|
||||
|
||||
reporter.start_attempt();
|
||||
reporter.record_attempt(1, outcome("cli", false, "output"));
|
||||
reporter.record_step(&mut steps, step("verify", false, "detail"));
|
||||
|
||||
assert_eq!(reporter.log_path(), None);
|
||||
assert_eq!(steps.len(), 1, "the UI path is unaffected by a missing log");
|
||||
}
|
||||
|
||||
/// A log path inside a directory that no longer exists cannot open a session, so
|
||||
/// the run degrades to no log rather than failing.
|
||||
#[test]
|
||||
fn test_an_unopenable_log_degrades_to_no_log() {
|
||||
let path = PathBuf::from("/nonexistent-dir-for-test/install-goose.log");
|
||||
|
||||
assert!(InstallLog::start(&path, "goose", TEST_APP_VERSION).is_none());
|
||||
}
|
||||
|
||||
// ── live output line ─────────────────────────────────────────────────────────
|
||||
|
||||
/// Lines carry an install-wide monotonic sequence number, so the UI can order
|
||||
/// them across steps and attempts — which a per-step retry number cannot do.
|
||||
#[test]
|
||||
fn test_emitted_lines_carry_their_runtime_and_a_monotonic_sequence() {
|
||||
let h = harness();
|
||||
|
||||
let observer = h.reporter.line_observer().expect("an observer");
|
||||
observer("downloading");
|
||||
h.reporter.start_attempt();
|
||||
|
||||
let events = h.events();
|
||||
assert_eq!(events.len(), 2);
|
||||
assert!(events.iter().all(|e| e.runtime_id == "goose"));
|
||||
assert_eq!(events[0].line.as_deref(), Some("downloading"));
|
||||
assert_eq!(events[0].seq, 0);
|
||||
assert_eq!(
|
||||
events[1].seq, 1,
|
||||
"the clear signal takes the next sequence number, so it cannot be \
|
||||
mistaken for a stale event"
|
||||
);
|
||||
}
|
||||
|
||||
/// Starting an attempt clears the display first: the previous attempt's last
|
||||
/// line is typically the failure that caused the retry, and leaving it under the
|
||||
/// spinner through the backoff shows the user the past as if it were current.
|
||||
#[test]
|
||||
fn test_starting_an_attempt_clears_the_displayed_line() {
|
||||
let h = harness();
|
||||
let observer = h.reporter.line_observer().expect("an observer");
|
||||
observer("download failed");
|
||||
|
||||
h.reporter.start_attempt();
|
||||
|
||||
assert_eq!(
|
||||
h.lines(),
|
||||
vec![Some("download failed".to_string()), None],
|
||||
"the attempt boundary must emit a clear"
|
||||
);
|
||||
}
|
||||
|
||||
/// The clear is not rate-limited, and it reopens the window: a new attempt's
|
||||
/// first line goes out immediately even if it arrives inside the previous
|
||||
/// attempt's window. This is the case the throttle used to swallow entirely.
|
||||
#[test]
|
||||
fn test_a_new_attempts_first_line_is_emitted_even_inside_the_previous_window() {
|
||||
let h = harness();
|
||||
let observer = h.reporter.line_observer().expect("an observer");
|
||||
observer("attempt one failed");
|
||||
|
||||
// No wait: the previous line was emitted microseconds ago, so this is well
|
||||
// inside the 250ms window.
|
||||
h.reporter.start_attempt();
|
||||
observer("attempt two starting");
|
||||
|
||||
assert_eq!(
|
||||
h.lines(),
|
||||
vec![
|
||||
Some("attempt one failed".to_string()),
|
||||
None,
|
||||
Some("attempt two starting".to_string()),
|
||||
]
|
||||
);
|
||||
}
|
||||
|
||||
/// A burst inside the window coalesces to one event, and the line it emits is
|
||||
/// the *newest* — the display shows current progress, not the line that happened
|
||||
/// to arrive when the window opened.
|
||||
#[test]
|
||||
fn test_a_burst_coalesces_to_the_newest_line_not_the_first() {
|
||||
let h = harness();
|
||||
let observer = h.reporter.line_observer().expect("an observer");
|
||||
|
||||
observer("one");
|
||||
observer("two");
|
||||
observer("three");
|
||||
// Ends the attempt, which is when a held line is known to be the last.
|
||||
h.reporter.record_attempt(1, outcome("cli", true, "done"));
|
||||
|
||||
assert_eq!(
|
||||
h.lines(),
|
||||
vec![Some("one".to_string()), Some("three".to_string())],
|
||||
"the held line must be the newest, and it must not be lost"
|
||||
);
|
||||
}
|
||||
|
||||
/// The throttle is per install, not per stream: stdout and stderr of one attempt
|
||||
/// share one window, so an install printing on both does not double the event
|
||||
/// rate.
|
||||
#[test]
|
||||
fn test_both_streams_of_one_attempt_share_the_rate_window() {
|
||||
let h = harness();
|
||||
let stdout = h.reporter.line_observer().expect("an observer");
|
||||
let stderr = h.reporter.line_observer().expect("an observer");
|
||||
|
||||
stdout("progress");
|
||||
stderr("warning");
|
||||
h.reporter.record_attempt(1, outcome("cli", true, "done"));
|
||||
|
||||
assert_eq!(
|
||||
h.lines(),
|
||||
vec![Some("progress".to_string()), Some("warning".to_string())],
|
||||
"the second stream's line is held, not emitted immediately, and not lost"
|
||||
);
|
||||
}
|
||||
|
||||
/// Nothing listening means no observer at all, so the drain skips line
|
||||
/// reassembly entirely rather than doing the work and discarding it.
|
||||
#[test]
|
||||
fn test_no_observer_when_nothing_is_listening() {
|
||||
assert!(silent_reporter().line_observer().is_none());
|
||||
}
|
||||
|
||||
// ── late-drain deactivation ──────────────────────────────────────────────────
|
||||
|
||||
/// After the reporter is dropped (run settled), a drain thread that still holds
|
||||
/// a cloned observer must not be able to emit. The lifecycle lock is shared by
|
||||
/// reference with every `line_observer` clone, so taking the exclusive write
|
||||
/// lock in `Drop` — which waits out any in-flight read guards — ensures no
|
||||
/// late event can reach the listener.
|
||||
///
|
||||
/// The test resets the throttle via `start_attempt` before the late emit, so
|
||||
/// the late line would be emitted unconditionally without the lifecycle lock.
|
||||
#[test]
|
||||
fn test_a_detached_observer_cannot_emit_after_the_reporter_is_dropped() {
|
||||
let h = harness();
|
||||
|
||||
// Simulate a drain thread: `line_observer` clones `Live` (owned, not
|
||||
// borrowed), so the closure outlives the reporter.
|
||||
let observer = h.reporter.line_observer().expect("an observer");
|
||||
observer("before-settle");
|
||||
|
||||
assert_eq!(
|
||||
h.lines(),
|
||||
vec![Some("before-settle".to_string())],
|
||||
"a live observer must emit before the reporter drops"
|
||||
);
|
||||
|
||||
// Open a fresh throttle window so the next offer would emit immediately —
|
||||
// simulating the drain arriving after the 250ms rate window closed.
|
||||
h.reporter.start_attempt();
|
||||
let events = Arc::clone(&h.events);
|
||||
|
||||
// Drop the reporter — takes the exclusive lifecycle write lock, waits for
|
||||
// any in-flight publications, then deactivates.
|
||||
drop(h);
|
||||
|
||||
// A late offer after drop must be blocked by the deactivated lifecycle.
|
||||
observer("late-drain-after-settle");
|
||||
|
||||
let lines: Vec<Option<String>> = events
|
||||
.lock()
|
||||
.unwrap()
|
||||
.iter()
|
||||
.map(|e| e.line.clone())
|
||||
.collect();
|
||||
assert_eq!(
|
||||
lines,
|
||||
// before-settle + the clear from start_attempt, no late line
|
||||
vec![Some("before-settle".to_string()), None],
|
||||
"a detached observer must not emit after the reporter is dropped"
|
||||
);
|
||||
}
|
||||
|
||||
/// Deterministic concurrency pin: proves that reporter deactivation cannot
|
||||
/// complete while a drain thread is in-flight between admission and publication.
|
||||
///
|
||||
/// The lifecycle `RwLock` enforces this: drain threads hold a shared read guard
|
||||
/// for the entire (check → emit) span, so `InstallReporter::drop`'s write lock
|
||||
/// blocks until every admitted publication finishes.
|
||||
///
|
||||
/// **How this test fails on the old atomic shape** (`dc6421ac4`): on that shape,
|
||||
/// `offer` loads `active` once as a plain atomic read and then calls `publish`
|
||||
/// independently. There is no shared lock, so `drop` (an atomic store) can
|
||||
/// complete while the thread is between the load and the emit — the test
|
||||
/// exposes this by asserting the write lock CANNOT be acquired while a reader
|
||||
/// holds a read guard. On the atomic shape the `lifecycle` field does not exist,
|
||||
/// so the entire serialisation contract is absent and the pin fails.
|
||||
#[test]
|
||||
fn test_deactivation_blocks_until_in_flight_publication_completes() {
|
||||
// Build a reporter and grab a Live clone that represents a drain thread.
|
||||
let h = harness();
|
||||
let live_clone = {
|
||||
// Extract the `Live` from a `line_observer` closure by temporarily
|
||||
// building a second observer and using the lifecycle Arc directly.
|
||||
h.reporter.line_observer().expect("observer");
|
||||
// Clone the inner lifecycle from the reporter's `Live` via a
|
||||
// white-box path: the test module is a child of install_report and
|
||||
// can access private fields.
|
||||
h.reporter
|
||||
.live
|
||||
.as_ref()
|
||||
.expect("live exists")
|
||||
.lifecycle
|
||||
.clone()
|
||||
};
|
||||
|
||||
// Phase 1: acquire the shared read guard (admission).
|
||||
let guard = live_clone.read().expect("lifecycle read");
|
||||
assert!(*guard, "lifecycle must be active at admission");
|
||||
|
||||
// Phase 2: while the read guard is held, a write lock must be blocked.
|
||||
// This is the core serialisation invariant: `Drop` cannot complete until
|
||||
// every admitted reader releases its guard.
|
||||
assert!(
|
||||
live_clone.try_write().is_err(),
|
||||
"a write lock must not be acquirable while a read guard is held — \
|
||||
Drop must block while a publication is in-flight"
|
||||
);
|
||||
|
||||
// Phase 3: release the read guard (publication completed).
|
||||
drop(guard);
|
||||
|
||||
// Phase 4: write lock is now available, and Drop can set active=false.
|
||||
let mut write = live_clone.write().expect("lifecycle write");
|
||||
*write = false;
|
||||
drop(write);
|
||||
|
||||
// Phase 5: a new reader after deactivation sees active=false and returns.
|
||||
let guard2 = live_clone.read().expect("lifecycle read");
|
||||
assert!(
|
||||
!*guard2,
|
||||
"lifecycle must be inactive after deactivation — new admissions rejected"
|
||||
);
|
||||
}
|
||||
|
||||
/// Shared-consumer assertion: drive a potential late run-1 event AND run-2's
|
||||
/// events through the same `nextInstallOutputLine`-equivalent reducer and assert
|
||||
/// that run 2's output replaces — not revives — any stale run-1 state.
|
||||
///
|
||||
/// The frontend reduces events into a single consumer that resets to `null`
|
||||
/// when `isInstalling` goes false (i.e., when the run settles). This test
|
||||
/// models that reset and verifies the full cross-run contract:
|
||||
///
|
||||
/// 1. Run 1 emits normally; the late drain is silenced by the lifecycle lock
|
||||
/// (no event with a high run-1 `seq` ever reaches the shared sink).
|
||||
/// 2. At run-1 settlement the consumer resets to `null`, exactly as the
|
||||
/// frontend hook does when `isInstalling` becomes false.
|
||||
/// 3. Run 2 starts, emits its `seq=0` clear and first line. With a null-state
|
||||
/// consumer the reducer accepts both immediately — even if a late run-1
|
||||
/// event HAD arrived (it didn't), the reset would have cleared its seq.
|
||||
///
|
||||
/// **Why this test fails on the old atomic shape**: without the lifecycle lock,
|
||||
/// `obs1("late-run-one-drain")` emits a high-seq run-1 event into the shared
|
||||
/// sink. That event arrives AFTER the consumer reset (its seq is accepted from
|
||||
/// a null state), leaving `{ seq: N, line: "late-run-one-drain" }` in the
|
||||
/// consumer. Run 2 then emits `seq=0` and `seq=1`, both ≤ N, so they are
|
||||
/// rejected and the final state stays on run 1's output.
|
||||
#[test]
|
||||
fn test_run2_output_replaces_stale_run1_state_through_shared_consumer() {
|
||||
// One shared event sink for all events from both runs, simulating the
|
||||
// permanent frontend listener that receives all `acp-install-output` events.
|
||||
let all_events: Arc<Mutex<Vec<InstallOutputEvent>>> = Arc::new(Mutex::new(Vec::new()));
|
||||
// Track where run 1 settles so the consumer reset can be applied at the
|
||||
// correct boundary in the fold below.
|
||||
let run1_settle_len: Arc<Mutex<usize>> = Arc::new(Mutex::new(0));
|
||||
let runtime_id = "goose";
|
||||
|
||||
// ── Run 1 ──────────────────────────────────────────────────────────────
|
||||
let dir1 = tempfile::tempdir().expect("tempdir");
|
||||
let log1 = dir1.path().join("install-goose.log");
|
||||
let emit1: EmitEvent = {
|
||||
let sink = Arc::clone(&all_events);
|
||||
Arc::new(move |event| sink.lock().unwrap().push(event))
|
||||
};
|
||||
let reporter1 = InstallReporter::new(
|
||||
runtime_id,
|
||||
InstallLog::start(&log1, runtime_id, "1.0.0"),
|
||||
Some(emit1),
|
||||
);
|
||||
|
||||
reporter1.start_attempt();
|
||||
let obs1 = reporter1.line_observer().expect("observer");
|
||||
obs1("run-one-output");
|
||||
reporter1.record_attempt(1, outcome("cli", true, "done"));
|
||||
|
||||
// Drop reporter1 — deactivates obs1 via the exclusive lifecycle write lock,
|
||||
// which blocks until any in-flight read guard (publication) has released.
|
||||
drop(reporter1);
|
||||
|
||||
// Record the sink length at settlement — this is the point where the
|
||||
// frontend resets its consumer state to null (isInstalling = false).
|
||||
*run1_settle_len.lock().unwrap() = all_events.lock().unwrap().len();
|
||||
|
||||
// A late drain from run 1 arrives after settlement. With the lifecycle
|
||||
// lock this is silenced. Without the lock (old atomic shape) it would
|
||||
// reach the sink with a high seq, poisoning the null-reset consumer before
|
||||
// run 2 can emit its restarted seq=0.
|
||||
// Reset the throttle so the offer would emit unconditionally if the lock
|
||||
// were absent — this makes the mutation meaningful.
|
||||
{
|
||||
// We need a fresh throttle window. Simulate by directly restarting
|
||||
// via a new reporter to touch the shared Live (not possible after drop),
|
||||
// so instead just call offer — the throttle holds the last emit time
|
||||
// from flush_pending, which was microseconds ago. Give the window time
|
||||
// to expire so the offer fires immediately on the old atomic shape.
|
||||
std::thread::sleep(Duration::from_millis(300));
|
||||
}
|
||||
obs1("late-run-one-drain");
|
||||
|
||||
// ── Run 2 ──────────────────────────────────────────────────────────────
|
||||
let dir2 = tempfile::tempdir().expect("tempdir");
|
||||
let log2 = dir2.path().join("install-goose.log");
|
||||
let emit2: EmitEvent = {
|
||||
let sink = Arc::clone(&all_events);
|
||||
Arc::new(move |event| sink.lock().unwrap().push(event))
|
||||
};
|
||||
let reporter2 = InstallReporter::new(
|
||||
runtime_id,
|
||||
InstallLog::start(&log2, runtime_id, "1.0.0"),
|
||||
Some(emit2),
|
||||
);
|
||||
|
||||
reporter2.start_attempt();
|
||||
let obs2 = reporter2.line_observer().expect("observer");
|
||||
obs2("run-two-first-line");
|
||||
reporter2.record_attempt(1, outcome("cli", true, "done"));
|
||||
|
||||
// ── Shared-consumer fold ────────────────────────────────────────────────
|
||||
// Fold all emitted events through the nextInstallOutputLine reducer logic.
|
||||
// At the run-1 settlement boundary, reset consumer to null — exactly as
|
||||
// the frontend hook does when isInstalling becomes false.
|
||||
struct State {
|
||||
seq: u64,
|
||||
line: Option<String>,
|
||||
}
|
||||
let settle_at = *run1_settle_len.lock().unwrap();
|
||||
let events = all_events.lock().unwrap().clone();
|
||||
let mut consumer: Option<State> = None;
|
||||
for (i, event) in events.iter().enumerate() {
|
||||
// Simulate frontend reset at run-1 settlement boundary.
|
||||
if i == settle_at {
|
||||
consumer = None;
|
||||
}
|
||||
if event.runtime_id != runtime_id {
|
||||
continue;
|
||||
}
|
||||
if let Some(ref c) = consumer {
|
||||
if event.seq <= c.seq {
|
||||
continue; // reject stale / out-of-order
|
||||
}
|
||||
}
|
||||
consumer = Some(State {
|
||||
seq: event.seq,
|
||||
line: event.line.clone(),
|
||||
});
|
||||
}
|
||||
|
||||
// The final consumer state must be run 2's first line.
|
||||
//
|
||||
// With the lifecycle lock: obs1("late-run-one-drain") emits nothing,
|
||||
// so after the null reset only run-2 events arrive — run 2 wins cleanly.
|
||||
//
|
||||
// Without the lifecycle lock (old atomic shape): obs1 emits the late line
|
||||
// with a high seq into the already-reset (null) consumer, consumer becomes
|
||||
// { seq: N, line: "late-run-one-drain" }. Run 2's seq=0/1 are both ≤ N
|
||||
// and are rejected, leaving the final state on run 1's stale output.
|
||||
let final_line = consumer
|
||||
.as_ref()
|
||||
.and_then(|s| s.line.as_deref())
|
||||
.unwrap_or("<none>");
|
||||
assert_eq!(
|
||||
final_line, "run-two-first-line",
|
||||
"run 2 must replace — not revive — stale run-1 state through the shared consumer; \
|
||||
got: {final_line:?}"
|
||||
);
|
||||
}
|
||||
@@ -1,13 +1,19 @@
|
||||
use crate::managed_agents::{AcpAvailabilityStatus, InstallStepResult};
|
||||
|
||||
pub(super) fn run(runtime_id: &str, steps: &mut Vec<InstallStepResult>) {
|
||||
use super::install_report::InstallReporter;
|
||||
|
||||
pub(super) fn run(
|
||||
runtime_id: &str,
|
||||
steps: &mut Vec<InstallStepResult>,
|
||||
reporter: &InstallReporter,
|
||||
) {
|
||||
// Observe PATH changes and binaries added after Buzz launched.
|
||||
crate::managed_agents::refresh_login_shell_path();
|
||||
crate::managed_agents::clear_resolve_cache();
|
||||
|
||||
let availability = crate::managed_agents::discover_acp_runtime_availability(runtime_id);
|
||||
if let Some(failure) = failure(runtime_id, availability) {
|
||||
steps.push(failure);
|
||||
reporter.record_step(steps, failure);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -286,7 +286,7 @@ fn redact_secrets(s: &str) -> String {
|
||||
/// (would match every short token in normal log output). Entries are
|
||||
/// applied in decreasing length order so superstrings get scrubbed before
|
||||
/// substrings — protects against partial overlap leaks.
|
||||
fn redact_secrets_with(s: &str, extras: &[&str]) -> String {
|
||||
pub(crate) fn redact_secrets_with(s: &str, extras: &[&str]) -> String {
|
||||
let mut result = s.to_string();
|
||||
|
||||
// Extras: longest first to avoid partial-overlap leaks. We use
|
||||
@@ -305,9 +305,23 @@ fn redact_secrets_with(s: &str, extras: &[&str]) -> String {
|
||||
|
||||
// Then prefix-based scrubbing. This loop *can* re-scan because each
|
||||
// replacement shortens the buffer past the matched prefix — the
|
||||
// replacement marker `[REDACTED]` does not contain `nsec1` or
|
||||
// `sprt_tok_`, so progress is guaranteed.
|
||||
for prefix in &["nsec1", "sprt_tok_"] {
|
||||
// replacement marker `[REDACTED]` contains none of these prefixes, so
|
||||
// progress is guaranteed. Any prefix added here must preserve that.
|
||||
//
|
||||
// GitHub tokens are recognised by shape as well as by variable name: a
|
||||
// token reaches output from outside our environment too — embedded in a
|
||||
// git remote URL an installer echoes, say — where no name-based rule can
|
||||
// see it.
|
||||
for prefix in &[
|
||||
"nsec1",
|
||||
"sprt_tok_",
|
||||
"ghp_",
|
||||
"gho_",
|
||||
"ghu_",
|
||||
"ghs_",
|
||||
"ghr_",
|
||||
"github_pat_",
|
||||
] {
|
||||
while let Some(pos) = result.find(prefix) {
|
||||
let end = result[pos..]
|
||||
.find(|c: char| c.is_whitespace() || c == '"' || c == '\'')
|
||||
@@ -563,6 +577,29 @@ mod tests {
|
||||
assert!(r.contains("42"));
|
||||
}
|
||||
|
||||
/// GitHub tokens are recognised by shape, so one that never passed through
|
||||
/// our environment — embedded in a remote URL an installer echoes — is
|
||||
/// still scrubbed. The scan runs to the next whitespace or quote, so the
|
||||
/// rest of the URL goes with it; over-redaction is the safe direction.
|
||||
#[test]
|
||||
fn redact_secrets_with_scrubs_github_token_prefixes() {
|
||||
for token in [
|
||||
"ghp_abcdefghij0123456789",
|
||||
"gho_abcdefghij0123456789",
|
||||
"ghu_abcdefghij0123456789",
|
||||
"ghs_abcdefghij0123456789",
|
||||
"ghr_abcdefghij0123456789",
|
||||
"github_pat_abcdefghij0123456789",
|
||||
] {
|
||||
let r =
|
||||
redact_secrets_with(&format!("cloning https://{token}@github.com/o/r now"), &[]);
|
||||
assert!(!r.contains(token), "leaked {token}: {r}");
|
||||
assert!(r.contains("[REDACTED]"), "got: {r}");
|
||||
assert!(r.contains("cloning"), "scan must stop at whitespace: {r}");
|
||||
assert!(r.ends_with(" now"), "scan must stop at whitespace: {r}");
|
||||
}
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn redact_secrets_with_extras_terminates_when_value_substring_of_marker() {
|
||||
// Regression: an earlier impl used `while let Some(pos) = find(value)`
|
||||
|
||||
@@ -52,6 +52,34 @@ fn managed_agents_logs_dir(app: &AppHandle) -> Result<PathBuf, String> {
|
||||
Ok(dir)
|
||||
}
|
||||
|
||||
/// Install-log path for `runtime_id`, alongside the agent logs.
|
||||
pub fn install_log_path(app: &AppHandle, runtime_id: &str) -> Result<PathBuf, String> {
|
||||
Ok(managed_agents_logs_dir(app)?.join(install_log_filename(runtime_id)?))
|
||||
}
|
||||
|
||||
/// Filename for a runtime's install log, or an error for an id that must not
|
||||
/// become one.
|
||||
///
|
||||
/// The id is validated rather than trusted: ids reach this from user-defined
|
||||
/// custom harnesses as well as the catalog, and a `../` or a separator in one
|
||||
/// would place the log outside the logs directory. Rejecting beats sanitizing —
|
||||
/// a rejected id means no log, while a rewritten one could collide with another
|
||||
/// runtime's.
|
||||
fn install_log_filename(runtime_id: &str) -> Result<String, String> {
|
||||
if runtime_id.is_empty() || !runtime_id.chars().all(is_safe_id_char) {
|
||||
return Err(format!(
|
||||
"unsafe runtime id for a log filename: {runtime_id}"
|
||||
));
|
||||
}
|
||||
Ok(format!("install-{runtime_id}.log"))
|
||||
}
|
||||
|
||||
/// Characters allowed in a runtime id used as a filename. Excludes `/`, `\`,
|
||||
/// `:` and `.`, so no id can traverse or escape the logs directory.
|
||||
fn is_safe_id_char(c: char) -> bool {
|
||||
c.is_ascii_alphanumeric() || c == '-' || c == '_'
|
||||
}
|
||||
|
||||
pub fn managed_agent_log_path(app: &AppHandle, pubkey: &str) -> Result<PathBuf, String> {
|
||||
Ok(managed_agents_logs_dir(app)?.join(format!("{pubkey}.log")))
|
||||
}
|
||||
@@ -632,6 +660,62 @@ pub(crate) fn open_log_file(path: &Path) -> Result<File, String> {
|
||||
.map_err(|error| format!("failed to open log file {}: {error}", path.display()))
|
||||
}
|
||||
|
||||
/// Start a new install-log session at `path`: keep the previous run as
|
||||
/// `<path>.1` and return a freshly created, empty current file.
|
||||
///
|
||||
/// Rotating per *run* rather than by size is what bounds this file. A run
|
||||
/// writes one record per executed attempt, each capped by the log-scale
|
||||
/// capture, so one run's file is bounded by steps × attempts × cap and the
|
||||
/// history on disk is bounded at two runs. Size-triggered rotation could not
|
||||
/// promise either: it never replaced an existing `.1`, and on Windows —
|
||||
/// where rename does not replace its destination — it stopped working
|
||||
/// altogether once `.1` existed, leaving the current file to grow.
|
||||
///
|
||||
/// The old `.1` is therefore *removed* before the rename rather than renamed
|
||||
/// over. Every step is best-effort: a rotation that fails must not cost the
|
||||
/// user the install, so the session continues with a truncated current file.
|
||||
pub(crate) fn start_install_log_session(path: &Path) -> Result<File, String> {
|
||||
if path.exists() {
|
||||
let mut previous = path.as_os_str().to_owned();
|
||||
previous.push(".1");
|
||||
let previous = PathBuf::from(previous);
|
||||
let _ = fs::remove_file(&previous);
|
||||
let _ = fs::rename(path, &previous);
|
||||
}
|
||||
open_install_log(path, /* truncate */ true)
|
||||
}
|
||||
|
||||
/// Open an install log for appending one more record to the current session.
|
||||
pub(crate) fn open_install_log_file(path: &Path) -> Result<File, String> {
|
||||
open_install_log(path, /* truncate */ false)
|
||||
}
|
||||
|
||||
/// Open an install log owner-only.
|
||||
///
|
||||
/// The mode is set *in the create* rather than chmod'd afterwards, so the file
|
||||
/// is never briefly group/world-readable. Install output can carry registry
|
||||
/// tokens and proxy credentials echoed by a failing installer, so the window
|
||||
/// matters even though it is short. An existing file's mode is left as-is —
|
||||
/// `OpenOptions::mode` only applies on creation, and silently re-tightening a
|
||||
/// file the user relaxed is not this function's call to make.
|
||||
fn open_install_log(path: &Path, truncate: bool) -> Result<File, String> {
|
||||
let mut options = OpenOptions::new();
|
||||
options.create(true);
|
||||
if truncate {
|
||||
options.write(true).truncate(true);
|
||||
} else {
|
||||
options.append(true);
|
||||
}
|
||||
#[cfg(unix)]
|
||||
{
|
||||
use std::os::unix::fs::OpenOptionsExt;
|
||||
options.mode(0o600);
|
||||
}
|
||||
options
|
||||
.open(path)
|
||||
.map_err(|error| format!("failed to open log file {}: {error}", path.display()))
|
||||
}
|
||||
|
||||
pub(crate) fn append_log_marker(path: &Path, message: &str) -> Result<(), String> {
|
||||
let mut file = open_log_file(path)?;
|
||||
writeln!(file, "{message}").map_err(|error| format!("failed to write log marker: {error}"))
|
||||
|
||||
@@ -698,3 +698,135 @@ fn try_delete_agent_key_returns_result() {
|
||||
// team_snapshot::tests::rollback_aggregates_multiple_errors.
|
||||
let _: fn(&str) -> Result<(), String> = super::try_delete_agent_key;
|
||||
}
|
||||
|
||||
// ── install logs ─────────────────────────────────────────────────────────────
|
||||
|
||||
/// Install output can carry registry tokens and proxy credentials a failing
|
||||
/// installer echoed, and the file is written unattended. `0o600` must come from
|
||||
/// the create itself: a post-write `chmod` leaves a window where the umask
|
||||
/// decides, and a crash inside it leaves the log readable to other local users.
|
||||
#[cfg(unix)]
|
||||
#[test]
|
||||
fn install_log_is_created_owner_only_without_post_write_chmod() {
|
||||
use std::os::unix::fs::PermissionsExt;
|
||||
|
||||
let dir = tempfile::tempdir().expect("temp dir");
|
||||
let path = dir.path().join("install-goose.log");
|
||||
|
||||
let mut file = super::open_install_log_file(&path).expect("open install log");
|
||||
file.write_all(b"npm ERR!\n").expect("write");
|
||||
|
||||
let mode = std::fs::metadata(&path)
|
||||
.expect("metadata")
|
||||
.permissions()
|
||||
.mode()
|
||||
& 0o777;
|
||||
assert_eq!(mode, 0o600, "install logs must be owner-only");
|
||||
}
|
||||
|
||||
/// A run starts a new current file and keeps the previous run as `.1`, so the
|
||||
/// two runs are never mixed and the history on disk stays bounded at two.
|
||||
#[test]
|
||||
fn install_log_session_keeps_the_previous_run_as_dot_one() {
|
||||
let dir = tempfile::tempdir().expect("temp dir");
|
||||
let path = dir.path().join("install-goose.log");
|
||||
|
||||
let mut first = super::start_install_log_session(&path).expect("first session");
|
||||
first.write_all(b"run-one\n").expect("write");
|
||||
let mut second = super::start_install_log_session(&path).expect("second session");
|
||||
second.write_all(b"run-two\n").expect("write");
|
||||
|
||||
assert_eq!(
|
||||
std::fs::read_to_string(&path).expect("read current"),
|
||||
"run-two\n",
|
||||
"the current file must hold only the newest run"
|
||||
);
|
||||
assert_eq!(
|
||||
std::fs::read_to_string(dir.path().join("install-goose.log.1")).expect("read .1"),
|
||||
"run-one\n",
|
||||
"the previous run must be preserved as .1"
|
||||
);
|
||||
}
|
||||
|
||||
/// The third run must still rotate when `.1` already exists. Windows `rename`
|
||||
/// does not replace its destination, so a rename-only rotation silently stops
|
||||
/// working here and leaves the current file to grow across every later run —
|
||||
/// the old `.1` is removed first precisely so this cannot happen. Runs on the
|
||||
/// Windows target too: this is the path that fails there.
|
||||
#[test]
|
||||
fn install_log_session_replaces_an_existing_dot_one() {
|
||||
let dir = tempfile::tempdir().expect("temp dir");
|
||||
let path = dir.path().join("install-goose.log");
|
||||
let rotated = dir.path().join("install-goose.log.1");
|
||||
// Seed the state a rename-only rotation cannot get out of: both files exist.
|
||||
std::fs::write(&path, b"previous-run\n").expect("seed current");
|
||||
std::fs::write(&rotated, b"ancient-run\n").expect("seed .1");
|
||||
|
||||
let mut file = super::start_install_log_session(&path).expect("session");
|
||||
file.write_all(b"fresh-run\n").expect("write");
|
||||
|
||||
assert_eq!(
|
||||
std::fs::read_to_string(&path).expect("read current"),
|
||||
"fresh-run\n",
|
||||
"the current file must restart even when .1 was already present"
|
||||
);
|
||||
assert_eq!(
|
||||
std::fs::read_to_string(&rotated).expect("read .1"),
|
||||
"previous-run\n",
|
||||
".1 must be replaced by the run that just ended, not kept"
|
||||
);
|
||||
}
|
||||
|
||||
/// Records written after the session starts append to it — a run's later
|
||||
/// records must not erase its earlier ones.
|
||||
#[test]
|
||||
fn install_log_appends_within_a_session() {
|
||||
let dir = tempfile::tempdir().expect("temp dir");
|
||||
let path = dir.path().join("install-goose.log");
|
||||
|
||||
let mut session = super::start_install_log_session(&path).expect("session");
|
||||
session.write_all(b"header\n").expect("write");
|
||||
for record in ["first\n", "second\n"] {
|
||||
let mut file = super::open_install_log_file(&path).expect("open install log");
|
||||
file.write_all(record.as_bytes()).expect("write");
|
||||
}
|
||||
|
||||
assert_eq!(
|
||||
std::fs::read_to_string(&path).expect("read back"),
|
||||
"header\nfirst\nsecond\n"
|
||||
);
|
||||
}
|
||||
|
||||
/// A runtime id becomes part of a filename. Ids reach this from user-defined
|
||||
/// custom harnesses as well as the catalog, so anything that could traverse or
|
||||
/// escape the logs directory is rejected rather than sanitized — a rejected id
|
||||
/// simply means no log, while a silently rewritten one could collide with
|
||||
/// another runtime's log.
|
||||
#[test]
|
||||
fn install_log_filename_rejects_ids_that_would_escape_the_logs_dir() {
|
||||
for id in [
|
||||
"../../etc/passwd",
|
||||
"goose/../../evil",
|
||||
"sub/dir",
|
||||
"back\\slash",
|
||||
"with.dot",
|
||||
"",
|
||||
] {
|
||||
assert!(
|
||||
super::install_log_filename(id).is_err(),
|
||||
"id {id:?} must not be accepted as a filename component"
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
/// Ordinary catalog and custom-harness ids are accepted — the guard must not
|
||||
/// reject the ids it exists to serve.
|
||||
#[test]
|
||||
fn install_log_filename_accepts_ordinary_runtime_ids() {
|
||||
for id in ["goose", "claude-code", "buzz_agent", "codex2"] {
|
||||
assert_eq!(
|
||||
super::install_log_filename(id).expect("id must be usable in a log filename"),
|
||||
format!("install-{id}.log")
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -587,7 +587,8 @@ pub struct ManagedAgentLogResponse {
|
||||
pub enum AcpAvailabilityStatus {
|
||||
Available,
|
||||
AdapterMissing,
|
||||
/// Adapter binary is present but is from the deprecated package (< 1.0). Reinstall required.
|
||||
/// Adapter binary is present but unsupported — either the deprecated
|
||||
/// package or a version below the supported floor. Reinstall required.
|
||||
AdapterOutdated,
|
||||
CliMissing,
|
||||
NotInstalled,
|
||||
@@ -701,6 +702,10 @@ pub struct InstallRuntimeResult {
|
||||
/// Number of agents whose stop succeeded but respawn failed.
|
||||
/// Mirrors `GlobalAgentConfigSaveResult.failed_restart_count`.
|
||||
pub failed_restart_count: u32,
|
||||
/// Install log file for this run, when one was written. The UI surfaces it
|
||||
/// on failure so a user can read the full retry history instead of only the
|
||||
/// last step's truncated output. `None` when no log could be opened.
|
||||
pub log_path: Option<String>,
|
||||
}
|
||||
|
||||
#[derive(Debug, Clone, Serialize)]
|
||||
|
||||
@@ -0,0 +1,82 @@
|
||||
import assert from "node:assert/strict";
|
||||
import test from "node:test";
|
||||
|
||||
import { nextInstallOutputLine } from "./useInstallOutputLine.ts";
|
||||
|
||||
function event(runtimeId, seq, line) {
|
||||
return { runtime_id: runtimeId, seq, line };
|
||||
}
|
||||
|
||||
test("nextInstallOutputLine: adopts the first line for the watched runtime", () => {
|
||||
assert.deepEqual(
|
||||
nextInstallOutputLine(null, event("goose", 0, "downloading"), "goose"),
|
||||
{ seq: 0, line: "downloading" },
|
||||
);
|
||||
});
|
||||
|
||||
test("nextInstallOutputLine: a later line replaces the current one", () => {
|
||||
const current = { seq: 4, line: "downloading" };
|
||||
|
||||
assert.deepEqual(
|
||||
nextInstallOutputLine(current, event("goose", 5, "unpacking"), "goose"),
|
||||
{ seq: 5, line: "unpacking" },
|
||||
);
|
||||
});
|
||||
|
||||
test("nextInstallOutputLine: ignores a line from another runtime", () => {
|
||||
const current = { seq: 1, line: "downloading" };
|
||||
|
||||
assert.equal(
|
||||
nextInstallOutputLine(current, event("codex", 2, "other work"), "goose"),
|
||||
current,
|
||||
);
|
||||
});
|
||||
|
||||
test("nextInstallOutputLine: ignores an out-of-order line", () => {
|
||||
const current = { seq: 7, line: "retrying" };
|
||||
|
||||
assert.equal(
|
||||
nextInstallOutputLine(current, event("goose", 6, "stale line"), "goose"),
|
||||
current,
|
||||
);
|
||||
});
|
||||
|
||||
test("nextInstallOutputLine: ignores a replay of the current sequence number", () => {
|
||||
const current = { seq: 7, line: "retrying" };
|
||||
|
||||
assert.equal(
|
||||
nextInstallOutputLine(current, event("goose", 7, "duplicate"), "goose"),
|
||||
current,
|
||||
);
|
||||
});
|
||||
|
||||
test("nextInstallOutputLine: a null line clears the display", () => {
|
||||
const current = { seq: 3, line: "download failed" };
|
||||
|
||||
assert.deepEqual(
|
||||
nextInstallOutputLine(current, event("goose", 4, null), "goose"),
|
||||
{ seq: 4, line: null },
|
||||
);
|
||||
});
|
||||
|
||||
test("nextInstallOutputLine: a later step's first line is adopted after a higher attempt", () => {
|
||||
// The seq is install-wide: step 2 attempt 1 always follows step 1 attempt 2,
|
||||
// which is exactly what an attempt-keyed comparison got wrong.
|
||||
const current = { seq: 9, line: "step one, attempt two" };
|
||||
|
||||
assert.deepEqual(
|
||||
nextInstallOutputLine(
|
||||
current,
|
||||
event("goose", 10, "step two, attempt one"),
|
||||
"goose",
|
||||
),
|
||||
{ seq: 10, line: "step two, attempt one" },
|
||||
);
|
||||
});
|
||||
|
||||
test("nextInstallOutputLine: a first event mid-install is adopted", () => {
|
||||
assert.deepEqual(
|
||||
nextInstallOutputLine(null, event("goose", 42, "downloading"), "goose"),
|
||||
{ seq: 42, line: "downloading" },
|
||||
);
|
||||
});
|
||||
108
desktop/src/features/agents/lib/useInstallOutputLine.ts
Normal file
108
desktop/src/features/agents/lib/useInstallOutputLine.ts
Normal file
@@ -0,0 +1,108 @@
|
||||
import * as React from "react";
|
||||
import { listen } from "@tauri-apps/api/event";
|
||||
|
||||
/** Mirror of the Rust `InstallOutputEvent` payload (install_report.rs). */
|
||||
export type InstallOutputEvent = {
|
||||
runtime_id: string;
|
||||
/** Monotonic across the whole install, not per step or per attempt. */
|
||||
seq: number;
|
||||
/** Null is the start signal: clear the displayed line now. */
|
||||
line: string | null;
|
||||
};
|
||||
|
||||
/** The line being shown, and the sequence number that produced it. */
|
||||
export type InstallOutputState = {
|
||||
seq: number;
|
||||
line: string | null;
|
||||
};
|
||||
|
||||
/**
|
||||
* Fold one event into the displayed line.
|
||||
*
|
||||
* Events from another runtime are ignored — every install card listens to the
|
||||
* same channel. So is an out-of-order event: emission is monotonic in `seq`, so
|
||||
* a lower one has already been superseded. That matters at a retry boundary,
|
||||
* where a line emitted just as the next attempt starts would otherwise sit
|
||||
* under the spinner showing the failure the user already had.
|
||||
*
|
||||
* The ordering key is the install-wide `seq` rather than the attempt number,
|
||||
* which restarts at 1 for every step: keyed on attempt, a step that succeeded on
|
||||
* attempt 2 would make the next step's attempt-1 output look stale and freeze
|
||||
* the display for the rest of the install.
|
||||
*/
|
||||
export function nextInstallOutputLine(
|
||||
current: InstallOutputState | null,
|
||||
event: InstallOutputEvent,
|
||||
runtimeId: string,
|
||||
): InstallOutputState | null {
|
||||
if (event.runtime_id !== runtimeId) return current;
|
||||
if (current && event.seq <= current.seq) return current;
|
||||
return { seq: event.seq, line: event.line };
|
||||
}
|
||||
|
||||
/**
|
||||
* The install command's most recent output line for `runtimeId`, or null when
|
||||
* nothing is being shown — the install is not running, nothing has printed yet,
|
||||
* or the backend cleared the line because a new attempt is starting.
|
||||
*
|
||||
* An install runs for up to 15 minutes with no other feedback than a spinner;
|
||||
* this turns that wait into observable progress. The backend throttles
|
||||
* emission, so this re-renders a few times a second at most.
|
||||
*
|
||||
* Pass `isInstalling` so the line clears when the install settles — a finished
|
||||
* install must not leave its last line under a fresh Install button.
|
||||
*/
|
||||
export function useInstallOutputLine(
|
||||
runtimeId: string,
|
||||
isInstalling: boolean,
|
||||
): string | null {
|
||||
const [state, setState] = React.useState<InstallOutputState | null>(null);
|
||||
|
||||
// Subscribed for this runtime's whole lifetime, not just while installing.
|
||||
// The install command is invoked from the click handler, so the backend can
|
||||
// emit the attempt-start clear and the first line before React commits
|
||||
// `isInstalling` — and there is no replay, so a subscription that waited for
|
||||
// that commit would lose those events permanently. A fast command's entire
|
||||
// output is exactly what fits in that window.
|
||||
React.useEffect(() => {
|
||||
let cancelled = false;
|
||||
let unlisten: (() => void) | null = null;
|
||||
(async () => {
|
||||
try {
|
||||
const stop = await listen<InstallOutputEvent>(
|
||||
"acp-install-output",
|
||||
(event) => {
|
||||
if (cancelled) return;
|
||||
setState((current) =>
|
||||
nextInstallOutputLine(current, event.payload, runtimeId),
|
||||
);
|
||||
},
|
||||
);
|
||||
if (cancelled) {
|
||||
stop();
|
||||
} else {
|
||||
unlisten = stop;
|
||||
}
|
||||
} catch {
|
||||
// Event system unavailable (web/e2e) — the spinner shows alone.
|
||||
}
|
||||
})();
|
||||
return () => {
|
||||
cancelled = true;
|
||||
unlisten?.();
|
||||
};
|
||||
}, [runtimeId]);
|
||||
|
||||
// `seq` is monotonic within one install and restarts at 0 for the next, so
|
||||
// state must not outlive the run that produced it: a retained higher `seq`
|
||||
// would make every event of the following install look superseded. Settling
|
||||
// is the run boundary, so it is where the ordering key resets.
|
||||
React.useEffect(() => {
|
||||
if (!isInstalling) setState(null);
|
||||
}, [isInstalling]);
|
||||
|
||||
// Events that arrive after the install settles — a drain flushing its last
|
||||
// line — must not reappear under a fresh Install button, so the line is
|
||||
// reported only while the install is running.
|
||||
return (isInstalling ? state?.line : null) ?? null;
|
||||
}
|
||||
@@ -8,6 +8,7 @@ import {
|
||||
useConnectAcpRuntimeMutation,
|
||||
useInstallAcpRuntimeMutation,
|
||||
} from "@/features/agents/hooks";
|
||||
import { useInstallOutputLine } from "@/features/agents/lib/useInstallOutputLine";
|
||||
import { describeResolvedCommand } from "@/features/agents/ui/agentUi";
|
||||
import type { AcpAuthMethod, AcpRuntimeCatalogEntry } from "@/shared/api/types";
|
||||
import { getInstallErrorMessage } from "@/shared/lib/installError";
|
||||
@@ -483,6 +484,7 @@ function RuntimeCard({
|
||||
const installMutation = useInstallAcpRuntimeMutation();
|
||||
const installError = installResults[runtime.id]?.error ?? null;
|
||||
const isInstalling = installMutation.isPending;
|
||||
const installOutputLine = useInstallOutputLine(runtime.id, isInstalling);
|
||||
const isAvailable = runtime.availability === "available";
|
||||
const isReady = runtimeIsReadyForOnboarding(runtime);
|
||||
|
||||
@@ -499,7 +501,7 @@ function RuntimeCard({
|
||||
[runtime.id]: result.success
|
||||
? { error: null, success: true }
|
||||
: {
|
||||
error: getInstallErrorMessage(result.steps),
|
||||
error: getInstallErrorMessage(result),
|
||||
success: false,
|
||||
},
|
||||
}));
|
||||
@@ -542,7 +544,18 @@ function RuntimeCard({
|
||||
onInstall={handleInstall}
|
||||
runtime={runtime}
|
||||
/>
|
||||
{!isAvailable && runtimeDetailText(runtime) ? (
|
||||
{isInstalling && installOutputLine ? (
|
||||
// Takes the detail text's slot rather than adding a row: the card is
|
||||
// fixed-height, and during an install the live line is the more
|
||||
// useful of the two.
|
||||
<p
|
||||
aria-live="polite"
|
||||
className="max-w-[13rem] truncate font-mono text-2xs leading-4 text-muted-foreground"
|
||||
data-testid={`onboarding-runtime-install-output-${runtime.id}`}
|
||||
>
|
||||
{installOutputLine}
|
||||
</p>
|
||||
) : !isAvailable && runtimeDetailText(runtime) ? (
|
||||
<p
|
||||
aria-hidden={installError ? "true" : undefined}
|
||||
className={cn(
|
||||
|
||||
@@ -6,6 +6,7 @@ import {
|
||||
useAcpRuntimesQuery,
|
||||
useInstallAcpRuntimeMutation,
|
||||
} from "@/features/agents/hooks";
|
||||
import { useInstallOutputLine } from "@/features/agents/lib/useInstallOutputLine";
|
||||
import {
|
||||
getRuntimeDisplayLabel,
|
||||
RuntimeIcon,
|
||||
@@ -399,13 +400,14 @@ function CatalogDetail({ entry }: { entry: AcpRuntimeCatalogEntry }) {
|
||||
const description = harnessDescription(entry.id);
|
||||
const isReady = entry.availability === "available";
|
||||
const docsUrl = entry.installInstructionsUrl.trim();
|
||||
const installOutputLine = useInstallOutputLine(entry.id, install.isPending);
|
||||
|
||||
function handleInstall() {
|
||||
setInstallError(null);
|
||||
install.mutate(entry.id, {
|
||||
onSuccess: (result) => {
|
||||
if (!result.success) {
|
||||
setInstallError(getInstallErrorMessage(result.steps));
|
||||
setInstallError(getInstallErrorMessage(result));
|
||||
}
|
||||
},
|
||||
onError: (error) => {
|
||||
@@ -502,6 +504,16 @@ function CatalogDetail({ entry }: { entry: AcpRuntimeCatalogEntry }) {
|
||||
</div>
|
||||
) : null}
|
||||
|
||||
{install.isPending && installOutputLine ? (
|
||||
<p
|
||||
aria-live="polite"
|
||||
className="truncate rounded-lg border border-border/60 bg-muted/40 px-3 py-1.5 font-mono text-xs text-muted-foreground"
|
||||
data-testid={`harness-catalog-install-output-${entry.id}`}
|
||||
>
|
||||
{installOutputLine}
|
||||
</p>
|
||||
) : null}
|
||||
|
||||
{installError ? (
|
||||
<p className="whitespace-pre-line rounded-lg border border-destructive/30 bg-destructive/10 px-3 py-1.5 text-sm text-destructive">
|
||||
{installError}
|
||||
|
||||
@@ -10,6 +10,7 @@ import {
|
||||
useManagedAgentsQuery,
|
||||
usePersonasQuery,
|
||||
} from "@/features/agents/hooks";
|
||||
import { useInstallOutputLine } from "@/features/agents/lib/useInstallOutputLine";
|
||||
import { RuntimeIcon } from "@/features/onboarding/ui/RuntimeIcon";
|
||||
import type { AcpAuthMethod, AcpRuntimeCatalogEntry } from "@/shared/api/types";
|
||||
import { getInstallErrorMessage } from "@/shared/lib/installError";
|
||||
@@ -324,6 +325,7 @@ export function HarnessRow({
|
||||
}, [resetEpoch]);
|
||||
const isInstalling = installMutation.isPending;
|
||||
const installError = installResult?.error ?? null;
|
||||
const installOutputLine = useInstallOutputLine(runtime.id, isInstalling);
|
||||
|
||||
const del = useDeleteCustomHarnessMutation();
|
||||
// Blast-radius data for the delete confirmation — only fetched while the
|
||||
@@ -348,7 +350,7 @@ export function HarnessRow({
|
||||
} else {
|
||||
setInstallResult({
|
||||
success: false,
|
||||
error: getInstallErrorMessage(result.steps),
|
||||
error: getInstallErrorMessage(result),
|
||||
});
|
||||
}
|
||||
},
|
||||
@@ -479,6 +481,15 @@ export function HarnessRow({
|
||||
</p>
|
||||
) : null}
|
||||
|
||||
{isInstalling && installOutputLine ? (
|
||||
<p
|
||||
aria-live="polite"
|
||||
className="mt-2 truncate rounded-lg border border-border/60 bg-background/60 px-3 py-1.5 font-mono text-xs text-muted-foreground"
|
||||
data-testid={`doctor-runtime-install-output-${runtime.id}`}
|
||||
>
|
||||
{installOutputLine}
|
||||
</p>
|
||||
) : null}
|
||||
{installError ? (
|
||||
<p
|
||||
className="mt-2 whitespace-pre-line rounded-lg border border-destructive/30 bg-destructive/10 px-3 py-1.5 text-sm text-destructive"
|
||||
|
||||
67
desktop/src/shared/api/installTypes.ts
Normal file
67
desktop/src/shared/api/installTypes.ts
Normal file
@@ -0,0 +1,67 @@
|
||||
/**
|
||||
* Result of an ACP runtime install, in both the shape Rust sends and the shape
|
||||
* the UI consumes.
|
||||
*/
|
||||
|
||||
export type RawInstallStepResult = {
|
||||
step: string;
|
||||
command: string;
|
||||
success: boolean;
|
||||
stdout: string;
|
||||
stderr: string;
|
||||
exit_code: number | null;
|
||||
hint?: string;
|
||||
};
|
||||
|
||||
export type RawInstallRuntimeResult = {
|
||||
success: boolean;
|
||||
steps: RawInstallStepResult[];
|
||||
restarted_count: number;
|
||||
failed_restart_count: number;
|
||||
/** Absent for a run with no log file — Rust serializes `None` as null. */
|
||||
log_path?: string | null;
|
||||
};
|
||||
|
||||
export type InstallStepResult = {
|
||||
step: string;
|
||||
command: string;
|
||||
success: boolean;
|
||||
stdout: string;
|
||||
stderr: string;
|
||||
exitCode: number | null;
|
||||
hint?: string;
|
||||
};
|
||||
|
||||
export type InstallRuntimeResult = {
|
||||
success: boolean;
|
||||
steps: InstallStepResult[];
|
||||
restartedCount: number;
|
||||
failedRestartCount: number;
|
||||
/**
|
||||
* Install log file for this run, when one was written. `steps` carries only
|
||||
* the last attempt of each step; the log holds every attempt, each record
|
||||
* bounded far above the display truncation. Null when no log could be
|
||||
* written — nothing then points at a file that does not exist.
|
||||
*/
|
||||
logPath: string | null;
|
||||
};
|
||||
|
||||
export function fromRawInstallRuntimeResult(
|
||||
raw: RawInstallRuntimeResult,
|
||||
): InstallRuntimeResult {
|
||||
return {
|
||||
success: raw.success,
|
||||
steps: raw.steps.map((step) => ({
|
||||
step: step.step,
|
||||
command: step.command,
|
||||
success: step.success,
|
||||
stdout: step.stdout,
|
||||
stderr: step.stderr,
|
||||
exitCode: step.exit_code,
|
||||
hint: step.hint,
|
||||
})),
|
||||
restartedCount: raw.restarted_count,
|
||||
failedRestartCount: raw.failed_restart_count,
|
||||
logPath: raw.log_path ?? null,
|
||||
};
|
||||
}
|
||||
@@ -3,6 +3,10 @@ import {
|
||||
activateRateLimit,
|
||||
parseRateLimitHint,
|
||||
} from "@/shared/api/relayRateLimitGate";
|
||||
import {
|
||||
fromRawInstallRuntimeResult,
|
||||
type RawInstallRuntimeResult,
|
||||
} from "@/shared/api/installTypes";
|
||||
import type {
|
||||
AddChannelMembersInput,
|
||||
AddChannelMembersResult,
|
||||
@@ -202,22 +206,10 @@ export type RawAcpRuntimeCatalogEntry = {
|
||||
definition_env?: Record<string, string>;
|
||||
};
|
||||
|
||||
export type RawInstallStepResult = {
|
||||
step: string;
|
||||
command: string;
|
||||
success: boolean;
|
||||
stdout: string;
|
||||
stderr: string;
|
||||
exit_code: number | null;
|
||||
hint?: string;
|
||||
};
|
||||
|
||||
export type RawInstallRuntimeResult = {
|
||||
success: boolean;
|
||||
steps: RawInstallStepResult[];
|
||||
restarted_count: number;
|
||||
failed_restart_count: number;
|
||||
};
|
||||
export type {
|
||||
RawInstallRuntimeResult,
|
||||
RawInstallStepResult,
|
||||
} from "./installTypes";
|
||||
|
||||
type RawGitBashPrerequisite = {
|
||||
available: boolean;
|
||||
@@ -772,25 +764,6 @@ export function fromRawAcpRuntimeCatalogEntry(
|
||||
};
|
||||
}
|
||||
|
||||
function fromRawInstallRuntimeResult(
|
||||
raw: RawInstallRuntimeResult,
|
||||
): InstallRuntimeResult {
|
||||
return {
|
||||
success: raw.success,
|
||||
steps: raw.steps.map((step) => ({
|
||||
step: step.step,
|
||||
command: step.command,
|
||||
success: step.success,
|
||||
stdout: step.stdout,
|
||||
stderr: step.stderr,
|
||||
exitCode: step.exit_code,
|
||||
hint: step.hint,
|
||||
})),
|
||||
restartedCount: raw.restarted_count,
|
||||
failedRestartCount: raw.failed_restart_count,
|
||||
};
|
||||
}
|
||||
|
||||
function fromRawCommandAvailability(
|
||||
command: RawCommandAvailability,
|
||||
): CommandAvailability {
|
||||
|
||||
@@ -571,22 +571,10 @@ export type AcpRuntime = AcpRuntimeCatalogEntry & {
|
||||
binaryPath: string;
|
||||
};
|
||||
|
||||
export type InstallStepResult = {
|
||||
step: string;
|
||||
command: string;
|
||||
success: boolean;
|
||||
stdout: string;
|
||||
stderr: string;
|
||||
exitCode: number | null;
|
||||
hint?: string;
|
||||
};
|
||||
|
||||
export type InstallRuntimeResult = {
|
||||
success: boolean;
|
||||
steps: InstallStepResult[];
|
||||
restartedCount: number;
|
||||
failedRestartCount: number;
|
||||
};
|
||||
export type {
|
||||
InstallRuntimeResult,
|
||||
InstallStepResult,
|
||||
} from "./installTypes";
|
||||
|
||||
export type AcpAuthMethod = {
|
||||
id: string;
|
||||
|
||||
@@ -32,7 +32,7 @@ export type ConfigNudgeRequirement =
|
||||
* Determines which message and CTA the nudge card shows:
|
||||
* - "available" → tooling installed, needs login
|
||||
* - "adapter_missing" → CLI installed but ACP adapter missing
|
||||
* - "adapter_outdated" → ACP adapter present but from deprecated package; reinstall required
|
||||
* - "adapter_outdated" → ACP adapter present but unsupported/outdated; reinstall required
|
||||
* - "cli_missing" → ACP adapter installed but CLI missing
|
||||
* - "not_installed" → neither adapter nor CLI found
|
||||
*/
|
||||
|
||||
@@ -3,84 +3,108 @@ import test from "node:test";
|
||||
|
||||
import { getInstallErrorMessage } from "./installError.ts";
|
||||
|
||||
/** A failed install result carrying `steps` and, optionally, a log pointer. */
|
||||
function failed(steps, logPath = null) {
|
||||
return {
|
||||
success: false,
|
||||
steps,
|
||||
restartedCount: 0,
|
||||
failedRestartCount: 0,
|
||||
logPath,
|
||||
};
|
||||
}
|
||||
|
||||
test("getInstallErrorMessage: empty steps array returns fallback", () => {
|
||||
assert.equal(getInstallErrorMessage([]), "Install failed with no output.");
|
||||
assert.equal(
|
||||
getInstallErrorMessage(failed([])),
|
||||
"Install failed with no output.",
|
||||
);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: failed step without hint contains step name and stderr", () => {
|
||||
const message = getInstallErrorMessage([
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @block/buzz-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "EACCES: permission denied",
|
||||
exitCode: 1,
|
||||
},
|
||||
]);
|
||||
const message = getInstallErrorMessage(
|
||||
failed([
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @block/buzz-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "EACCES: permission denied",
|
||||
exitCode: 1,
|
||||
},
|
||||
]),
|
||||
);
|
||||
assert.match(message, /Step "adapter" failed:/);
|
||||
assert.match(message, /EACCES: permission denied/);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: failed step without hint does not contain hint-ish text", () => {
|
||||
const message = getInstallErrorMessage([
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @block/buzz-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "EACCES: permission denied",
|
||||
exitCode: 1,
|
||||
},
|
||||
]);
|
||||
const message = getInstallErrorMessage(
|
||||
failed([
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @block/buzz-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "EACCES: permission denied",
|
||||
exitCode: 1,
|
||||
},
|
||||
]),
|
||||
);
|
||||
assert.doesNotMatch(message, /npm config set prefix/);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: failed step with hint starts with hint and still contains stderr", () => {
|
||||
const hint =
|
||||
"Fix the npm prefix ownership:\n sudo chown -R $USER $(npm config get prefix)";
|
||||
const message = getInstallErrorMessage([
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @block/buzz-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "EACCES: permission denied, mkdir '/usr/local/lib'",
|
||||
exitCode: 1,
|
||||
hint,
|
||||
},
|
||||
]);
|
||||
const message = getInstallErrorMessage(
|
||||
failed([
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @block/buzz-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "EACCES: permission denied, mkdir '/usr/local/lib'",
|
||||
exitCode: 1,
|
||||
hint,
|
||||
},
|
||||
]),
|
||||
);
|
||||
assert.ok(message.startsWith(hint), "message should start with hint");
|
||||
assert.match(message, /EACCES: permission denied/);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: failed step with empty stderr falls back to stdout", () => {
|
||||
const message = getInstallErrorMessage([
|
||||
{
|
||||
step: "node",
|
||||
command: "node --version",
|
||||
success: false,
|
||||
stdout: "some stdout output",
|
||||
stderr: "",
|
||||
exitCode: 1,
|
||||
},
|
||||
]);
|
||||
const message = getInstallErrorMessage(
|
||||
failed([
|
||||
{
|
||||
step: "node",
|
||||
command: "node --version",
|
||||
success: false,
|
||||
stdout: "some stdout output",
|
||||
stderr: "",
|
||||
exitCode: 1,
|
||||
},
|
||||
]),
|
||||
);
|
||||
assert.match(message, /some stdout output/);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: hint and step detail are separated by double newline for whitespace-pre-line rendering", () => {
|
||||
const hint = "Git Bash is required. Install it from git-scm.com.";
|
||||
const message = getInstallErrorMessage([
|
||||
{
|
||||
step: "shell",
|
||||
command: "bash -l -c 'npm install'",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "bash: command not found",
|
||||
exitCode: 127,
|
||||
hint,
|
||||
},
|
||||
]);
|
||||
const message = getInstallErrorMessage(
|
||||
failed([
|
||||
{
|
||||
step: "shell",
|
||||
command: "bash -l -c 'npm install'",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "bash: command not found",
|
||||
exitCode: 127,
|
||||
hint,
|
||||
},
|
||||
]),
|
||||
);
|
||||
assert.ok(
|
||||
message.includes("\n\n"),
|
||||
"hint and step detail should be separated by a blank line",
|
||||
@@ -89,25 +113,72 @@ test("getInstallErrorMessage: hint and step detail are separated by double newli
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: only reports the last (failing) step when multiple steps present", () => {
|
||||
const message = getInstallErrorMessage([
|
||||
{
|
||||
step: "node",
|
||||
command: "node --version",
|
||||
success: true,
|
||||
stdout: "v20.0.0",
|
||||
stderr: "",
|
||||
exitCode: 0,
|
||||
},
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @agentclientprotocol/claude-code-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "npm ERR! code E404",
|
||||
exitCode: 1,
|
||||
},
|
||||
]);
|
||||
const message = getInstallErrorMessage(
|
||||
failed([
|
||||
{
|
||||
step: "node",
|
||||
command: "node --version",
|
||||
success: true,
|
||||
stdout: "v20.0.0",
|
||||
stderr: "",
|
||||
exitCode: 0,
|
||||
},
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @agentclientprotocol/claude-code-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "npm ERR! code E404",
|
||||
exitCode: 1,
|
||||
},
|
||||
]),
|
||||
);
|
||||
assert.match(message, /Step "adapter" failed:/);
|
||||
assert.match(message, /npm ERR! code E404/);
|
||||
assert.doesNotMatch(message, /Step "node"/);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: points at the install log when one was written", () => {
|
||||
const message = getInstallErrorMessage(
|
||||
failed(
|
||||
[
|
||||
{
|
||||
step: "cli",
|
||||
command: "curl … | bash",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "download failed",
|
||||
exitCode: 1,
|
||||
},
|
||||
],
|
||||
"/logs/install-goose.log",
|
||||
),
|
||||
);
|
||||
assert.match(message, /download failed/);
|
||||
assert.ok(
|
||||
message.endsWith("\n\nFull log: /logs/install-goose.log"),
|
||||
`log pointer should close the message, got: ${message}`,
|
||||
);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: omits the log pointer when no log was written", () => {
|
||||
const message = getInstallErrorMessage(
|
||||
failed([
|
||||
{
|
||||
step: "cli",
|
||||
command: "curl … | bash",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "download failed",
|
||||
exitCode: 1,
|
||||
},
|
||||
]),
|
||||
);
|
||||
assert.doesNotMatch(message, /Full log/);
|
||||
});
|
||||
|
||||
test("getInstallErrorMessage: a run with no steps at all still points at its log", () => {
|
||||
const message = getInstallErrorMessage(failed([], "/logs/install-goose.log"));
|
||||
assert.match(message, /Install failed with no output\./);
|
||||
assert.match(message, /Full log: \/logs\/install-goose\.log/);
|
||||
});
|
||||
|
||||
@@ -1,15 +1,25 @@
|
||||
import type { InstallStepResult } from "@/shared/api/types";
|
||||
import type { InstallRuntimeResult } from "@/shared/api/types";
|
||||
|
||||
/**
|
||||
* Build the user-visible error message for a failed install.
|
||||
* When the last step carries an actionable hint, it is shown first,
|
||||
* followed by the raw step failure detail.
|
||||
*
|
||||
* The step detail is truncated for display, so the message ends with a pointer
|
||||
* to the install log — which holds every attempt of every step, each record
|
||||
* bounded far above the display truncation — when one was written.
|
||||
*/
|
||||
export function getInstallErrorMessage(steps: InstallStepResult[]): string {
|
||||
export function getInstallErrorMessage(result: InstallRuntimeResult): string {
|
||||
const { steps, logPath } = result;
|
||||
const lastStep = steps[steps.length - 1];
|
||||
if (!lastStep) {
|
||||
return "Install failed with no output.";
|
||||
return withLog("Install failed with no output.", logPath);
|
||||
}
|
||||
const base = `Step "${lastStep.step}" failed: ${lastStep.stderr || lastStep.stdout || "unknown error"}`;
|
||||
return lastStep.hint ? `${lastStep.hint}\n\n${base}` : base;
|
||||
const detail = lastStep.hint ? `${lastStep.hint}\n\n${base}` : base;
|
||||
return withLog(detail, logPath);
|
||||
}
|
||||
|
||||
function withLog(message: string, logPath: string | null): string {
|
||||
return logPath ? `${message}\n\nFull log: ${logPath}` : message;
|
||||
}
|
||||
|
||||
@@ -1,4 +1,5 @@
|
||||
import { bytesToHex, hexToBytes } from "@noble/hashes/utils.js";
|
||||
import { emit } from "@tauri-apps/api/event";
|
||||
import { mockIPC, mockWindows } from "@tauri-apps/api/mocks";
|
||||
import { decode, npubEncode } from "nostr-tools/nip19";
|
||||
import { finalizeEvent, getPublicKey } from "nostr-tools/pure";
|
||||
@@ -203,6 +204,8 @@ type E2eConfig = {
|
||||
acpRuntimesCatalogAfterConnect?: RawAcpRuntimeCatalogEntry[];
|
||||
activePersonaIds?: string[];
|
||||
installAcpRuntimeDelayMs?: number;
|
||||
/** Live output lines the mocked install emits before it settles. */
|
||||
installAcpRuntimeOutputLines?: string[];
|
||||
installAcpRuntimeResult?: RawInstallRuntimeResult;
|
||||
/** Sequence of results for successive `install_acp_runtime` calls.
|
||||
* Call N returns results[N]; when exhausted the last entry repeats.
|
||||
@@ -1257,6 +1260,8 @@ const REACTION_TARGET_CONTENT = "React to me with a custom emoji";
|
||||
// REACTION_TARGET_EVENT_ID.
|
||||
const SYSTEM_REACTION_TARGET_EVENT_ID = "e".repeat(64);
|
||||
const E2E_IDENTITY_OVERRIDE_STORAGE_KEY = "buzz:e2e-identity-override.v1";
|
||||
/** Stands in for `tauri.conf.json`'s version, which no mock IPC call can read. */
|
||||
const MOCK_APP_VERSION = "0.0.0-e2e";
|
||||
const DEFAULT_MOCK_IDENTITY = {
|
||||
pubkey: "deadbeef".repeat(8),
|
||||
display_name: "npub1mock...",
|
||||
@@ -7228,6 +7233,53 @@ let personaSharePublicationCallCount = 0;
|
||||
// Per-page confirm_team_snapshot_import call counter for sequenced error testing.
|
||||
let teamSnapshotConfirmCallCount = 0;
|
||||
|
||||
// Live-output sequence for the install currently being replayed. The backend
|
||||
// counter is per run (`InstallReporter::for_run` starts a fresh one), so this
|
||||
// restarts too — a bridge that stayed monotonic across installs would hide a UI
|
||||
// that carried a stale sequence number into the next run and rejected all of it.
|
||||
let installOutputSeq = 0;
|
||||
|
||||
/**
|
||||
* Replay the live output the Rust reporter emits while an install runs: a clear
|
||||
* signal, then one line per entry. `seq` is install-wide and monotonic, matching
|
||||
* the backend contract the UI's ordering depends on.
|
||||
*
|
||||
* The clear and the first line emit synchronously with the install invocation,
|
||||
* exactly as the backend does — the command is invoked from the click handler,
|
||||
* so those events land before React has committed the pending install state.
|
||||
* Delaying them would let a listener that mounts on that state still catch them,
|
||||
* hiding the very race the UI has to survive.
|
||||
*
|
||||
* Later lines are spaced so each is observable rather than collapsing into one
|
||||
* frame with the next.
|
||||
*/
|
||||
const INSTALL_OUTPUT_REPLAY_GAP_MS = 1000;
|
||||
|
||||
async function replayInstallOutput(
|
||||
runtimeId: string,
|
||||
lines: string[],
|
||||
): Promise<void> {
|
||||
installOutputSeq = 0;
|
||||
// The leading null is the clear signal the backend sends when an attempt
|
||||
// starts, so this replays a whole attempt rather than only its output.
|
||||
const events: (string | null)[] = [null, ...lines];
|
||||
for (const [index, line] of events.entries()) {
|
||||
// Index 0 and 1 are the clear and the first line: no gap before either.
|
||||
if (index > 1) {
|
||||
await new Promise((resolve) =>
|
||||
window.setTimeout(resolve, INSTALL_OUTPUT_REPLAY_GAP_MS),
|
||||
);
|
||||
}
|
||||
// `emit` reaches listeners registered through the real `listen` API, which
|
||||
// is what the UI hook uses; mockIPC's shouldMockEvents wires the two.
|
||||
await emit("acp-install-output", {
|
||||
runtime_id: runtimeId,
|
||||
seq: installOutputSeq++,
|
||||
line,
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
async function handleInstallAcpRuntime(
|
||||
args: {
|
||||
runtimeId?: string;
|
||||
@@ -7235,6 +7287,10 @@ async function handleInstallAcpRuntime(
|
||||
config: E2eConfig | undefined,
|
||||
): Promise<RawInstallRuntimeResult> {
|
||||
const runtimeId = args.runtimeId ?? "";
|
||||
const outputLines = config?.mock?.installAcpRuntimeOutputLines;
|
||||
if (outputLines && outputLines.length > 0) {
|
||||
await replayInstallOutput(runtimeId, outputLines);
|
||||
}
|
||||
const perRuntime = config?.mock?.installAcpRuntimeByRuntime?.[runtimeId];
|
||||
|
||||
if (perRuntime) {
|
||||
@@ -7291,6 +7347,7 @@ async function handleInstallAcpRuntime(
|
||||
],
|
||||
restarted_count: 0,
|
||||
failed_restart_count: 0,
|
||||
log_path: null,
|
||||
};
|
||||
}
|
||||
|
||||
@@ -11629,6 +11686,11 @@ export function maybeInstallE2eTauriMocks() {
|
||||
return null;
|
||||
case "plugin:window|is_fullscreen":
|
||||
return false;
|
||||
// Settings reads the app version through the app plugin. Without this the
|
||||
// bridge throws an unhandled page error on every Settings render, which
|
||||
// shows up as noise in unrelated specs.
|
||||
case "plugin:app|version":
|
||||
return MOCK_APP_VERSION;
|
||||
case "merge_save_subscription_kinds": {
|
||||
// Mirrors `merge_owner_p_kinds`: union `kind` into the owner_p row's
|
||||
// kinds, creating the row if it doesn't exist yet.
|
||||
|
||||
@@ -983,4 +983,91 @@ test.describe("Doctor panel state screenshots", () => {
|
||||
path: `${SHOTS}/08-concurrent-installs-and-stale-clear.png`,
|
||||
});
|
||||
});
|
||||
/**
|
||||
* 09 — install observability: the live output line appears while the install
|
||||
* runs and disappears when it settles, and the failure message points at the
|
||||
* install log rather than only the truncated last step.
|
||||
*/
|
||||
test("09-install-output-line-and-log-pointer", async ({ page }) => {
|
||||
await installMockBridge(page, {
|
||||
acpRuntimesCatalog: [
|
||||
GOOSE_AVAILABLE,
|
||||
CLAUDE_AVAILABLE_LOGGED_IN,
|
||||
{
|
||||
...CODEX_NOT_INSTALLED,
|
||||
can_auto_install: true,
|
||||
node_required: false,
|
||||
},
|
||||
BUZZ_AGENT_AVAILABLE,
|
||||
],
|
||||
installAcpRuntimeDelayMs: 500,
|
||||
installAcpRuntimeOutputLines: [
|
||||
"npm http fetch GET 200 @zed-industries/codex-acp",
|
||||
"npm warn deprecated a transitive dependency",
|
||||
],
|
||||
installAcpRuntimeResult: {
|
||||
success: false,
|
||||
steps: [
|
||||
{
|
||||
step: "adapter",
|
||||
command: "npm install -g @zed-industries/codex-acp",
|
||||
success: false,
|
||||
stdout: "",
|
||||
stderr: "npm ERR! code E404",
|
||||
exit_code: 1,
|
||||
},
|
||||
],
|
||||
log_path: "/tmp/buzz-install-codex.log",
|
||||
},
|
||||
});
|
||||
|
||||
await page.goto("/", { waitUntil: "domcontentloaded" });
|
||||
await openSettings(page, "agents");
|
||||
|
||||
const row = page.getByTestId("doctor-runtime-codex");
|
||||
await expect(row).toBeVisible({ timeout: 10_000 });
|
||||
|
||||
const installButton = page.getByTestId("doctor-runtime-install-codex");
|
||||
await expect(installButton).toBeEnabled();
|
||||
await installButton.click();
|
||||
|
||||
// The bridge emits the attempt-start clear and the first line synchronously
|
||||
// with the install invocation — before React commits the pending state — so
|
||||
// observing this line proves the listener was already mounted at the click.
|
||||
// A subscription that waited for the install state would have missed both.
|
||||
const outputLine = page.getByTestId("doctor-runtime-install-output-codex");
|
||||
await expect(outputLine).toContainText("npm http fetch", {
|
||||
timeout: 5_000,
|
||||
});
|
||||
|
||||
// Each new line replaces the previous one rather than accumulating.
|
||||
await expect(outputLine).toContainText("npm warn deprecated", {
|
||||
timeout: 5_000,
|
||||
});
|
||||
await expect(outputLine).not.toContainText("npm http fetch");
|
||||
|
||||
// Settled: the line clears, so a finished install leaves no stale output
|
||||
// under a fresh Install button.
|
||||
const installError = page.getByTestId("doctor-runtime-install-error-codex");
|
||||
await expect(installError).toBeVisible({ timeout: 5_000 });
|
||||
await expect(outputLine).toHaveCount(0);
|
||||
|
||||
// The failure points at the log holding bounded output for every attempt.
|
||||
await expect(installError).toContainText("npm ERR! code E404");
|
||||
await expect(installError).toContainText("/tmp/buzz-install-codex.log");
|
||||
|
||||
await row.scrollIntoViewIfNeeded();
|
||||
await waitForAnimations(page);
|
||||
await row.screenshot({
|
||||
path: `${SHOTS}/09-install-output-line-and-log-pointer.png`,
|
||||
});
|
||||
|
||||
// A second install shows its own output. The backend sequence restarts per
|
||||
// run, so a display that kept the previous run's sequence number would
|
||||
// reject every event of this one and show nothing at all.
|
||||
await installButton.click();
|
||||
await expect(outputLine).toContainText("npm http fetch", {
|
||||
timeout: 5_000,
|
||||
});
|
||||
});
|
||||
});
|
||||
|
||||
@@ -131,6 +131,22 @@ export type MockAgentMemoryListing = {
|
||||
fetchedAt: number;
|
||||
};
|
||||
|
||||
/** Result returned by the `install_acp_runtime` mock command. */
|
||||
type MockInstallRuntimeResult = {
|
||||
success: boolean;
|
||||
steps: {
|
||||
step: string;
|
||||
command: string;
|
||||
success: boolean;
|
||||
stdout: string;
|
||||
stderr: string;
|
||||
exit_code: number | null;
|
||||
hint?: string;
|
||||
}[];
|
||||
/** Install log the failure message points at. Omitted = no log was written. */
|
||||
log_path?: string | null;
|
||||
};
|
||||
|
||||
type MockBridgeOptions = {
|
||||
/** Advertised HEAD for the first mock project without adding that branch. */
|
||||
projectHeadBranch?: string;
|
||||
@@ -171,35 +187,17 @@ type MockBridgeOptions = {
|
||||
connectAcpRuntimeDelayMs?: number;
|
||||
connectAcpRuntimeError?: string;
|
||||
installAcpRuntimeDelayMs?: number;
|
||||
/** Live output lines the mocked install emits before it settles, in order.
|
||||
* Each arrives as an `acp-install-output` event, preceded by the clear
|
||||
* signal the backend sends at the start of an attempt. */
|
||||
installAcpRuntimeOutputLines?: string[];
|
||||
/** Override the result returned by the `install_acp_runtime` mock command.
|
||||
* Pass `{ success: false, steps: [...] }` to exercise error/Retry states. */
|
||||
installAcpRuntimeResult?: {
|
||||
success: boolean;
|
||||
steps: {
|
||||
step: string;
|
||||
command: string;
|
||||
success: boolean;
|
||||
stdout: string;
|
||||
stderr: string;
|
||||
exit_code: number | null;
|
||||
hint?: string;
|
||||
}[];
|
||||
};
|
||||
installAcpRuntimeResult?: MockInstallRuntimeResult;
|
||||
/** Sequence of results for successive `install_acp_runtime` calls. Call N
|
||||
* returns results[N]; when exhausted the last entry repeats. Takes precedence
|
||||
* over `installAcpRuntimeResult`. Use for fail-then-succeed Retry tests. */
|
||||
installAcpRuntimeResults?: Array<{
|
||||
success: boolean;
|
||||
steps: {
|
||||
step: string;
|
||||
command: string;
|
||||
success: boolean;
|
||||
stdout: string;
|
||||
stderr: string;
|
||||
exit_code: number | null;
|
||||
hint?: string;
|
||||
}[];
|
||||
}>;
|
||||
installAcpRuntimeResults?: MockInstallRuntimeResult[];
|
||||
activePersonaIds?: string[];
|
||||
/**
|
||||
* Listing returned by the mocked `get_agent_memory` command. Pass a single
|
||||
|
||||
Reference in New Issue
Block a user