Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 5 additions & 13 deletions crates/rhei-cli/src/cli/agent_command.rs
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,8 @@ fn build_agent_command(
task_id: &str,
state_name: &str,
visit_count: u64,
// Which attempt of this visit the invocation is. §FS-rhei-agents.4
attempt: u64,
tooling: &ResolvedTooling,
runtime_dir: &Path,
// Fan-out key of this invocation, when the state fans out: it decides which
Expand Down Expand Up @@ -179,6 +181,9 @@ fn build_agent_command(
)
.env("RHEI_STATE", state_name)
.env("RHEI_VISIT_COUNT", visit_count.to_string())
// A retry that is handed the same environment as the attempt it is
// recovering from has no way to know it is one. §FS-rhei-agents.4
.env("RHEI_ATTEMPT", attempt.to_string())
.env("RHEI_AGENT", id);
if let Some(path) = worktree_root {
cmd.env("RHEI_WORKTREE_ROOT", path);
Expand Down Expand Up @@ -570,16 +575,3 @@ fn inject_tooling_env(cmd: &mut std::process::Command, tooling: &ResolvedTooling
}
}

/// Construct the log file path for a task/state invocation.
fn agent_log_path(
runtime_dir: &Path,
task_id: &str,
state_name: &str,
suffix: Option<&str>,
) -> PathBuf {
let suffix = suffix
.filter(|value| !value.is_empty())
.map(|value| format!("-{value}"))
.unwrap_or_default();
runtime_dir.join("logs").join(format!("task-{task_id}-{state_name}{suffix}.log"))
}
93 changes: 93 additions & 0 deletions crates/rhei-cli/src/cli/agent_log_files.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,93 @@
// How `rhei run` names the transcript of one agent invocation, and how anything
// that later wants to read one finds it.
//
// Four sides have to agree on the rule: the spawn that opens the file, the
// prompt that cites an earlier visit's, the reset that sweeps a ticket's
// runtime, and the engine's own account of a ticket it finished without
// spawning a worker. A second copy of the rule is how one of them drifts, so
// the rule lives here and only here.
//
// The name says which invocation and which attempt; *which* attempt is a fact
// about the ticket's history, not about the directory listing, and it is kept
// in the spawn record next door.

// §AR-source-file-size.3 §FS-rhei-agents.8.1 §FS-rhei-memory.4.4 §FS-rhei-run.3

fn resolved_agent_log_suffix(resolved: &ResolvedAgent, visit_count: Option<u64>) -> Option<String> {
agent_log_suffix(resolved.target.as_ref(), resolved.model.as_deref(), visit_count)
}

/// The part of a log file name that follows `task-{task_id}-{state}`.
///
/// Split from the resolved-agent form so prompt composition can name the log of
/// an *earlier* visit, where no `ResolvedAgent` for that visit exists — only
/// the identity this one carries, which is the identity that wrote it.
// §FS-rhei-agents.8.1 §FS-rhei-memory.4.4
fn agent_log_suffix(
target: Option<&ExecutionTarget>,
model: Option<&str>,
visit_count: Option<u64>,
) -> Option<String> {
let base = target
.map(ExecutionTarget::slug)
.or_else(|| model.map(str::to_string).filter(|value| !value.is_empty()));
let visit_suffix = visit_count.filter(|count| *count > 1).map(|count| count.to_string());
match (base, visit_suffix) {
(Some(base), Some(visit)) => Some(format!("{base}-{visit}")),
(Some(base), None) => Some(base),
(None, Some(visit)) => Some(visit),
(None, None) => None,
}
}

/// The log file of one attempt at one visit of a state.
///
/// The first attempt of a visit keeps the plain `task-{id}-{state}{suffix}.log`
/// name every other reader already knows; a re-spawn *within the same visit*
/// appends `-attempt{n}` instead of truncating the file that says why the
/// attempt before it did not finish. The visit count cannot do that job on its
/// own: a ticket that stalls never leaves the state, so it is still on the same
/// visit when the run spawns it again — and, the other way round, a ticket that
/// leaves and returns is on a new visit that the count does not register
/// either, so it starts again at `-attempt1`'s plain name.
// §FS-rhei-agents.8.1
fn agent_log_attempt_path(
runtime_dir: &Path,
task_id: &str,
state_name: &str,
suffix: Option<&str>,
attempt: u64,
) -> PathBuf {
let suffix = suffix
.filter(|value| !value.is_empty())
.map(|value| format!("-{value}"))
.unwrap_or_default();
let attempt = if attempt > 1 { format!("-attempt{attempt}") } else { String::new() };
runtime_dir.join("logs").join(format!("task-{task_id}-{state_name}{suffix}{attempt}.log"))
}

/// The log of the *last thing that actually ran* for one invocation — whichever
/// attempt that was — and `None` when nothing did.
///
/// Read from the spawn record rather than by probing names: probing costs one
/// `exists()` per attempt ever made, and it names attempt files a spawn opened
/// and never wrote a line into. The unsuffixed name is still accepted when no
/// record answers, because a runtime written before records existed still has
/// transcripts worth citing, and citing a transcript is not a claim that a
/// worker ran — that claim has one source, and it is the record.
// §FS-rhei-agents.8.1 §FS-rhei-agents.8.4
fn latest_agent_log_path(
runtime_dir: &Path,
task_id: &str,
state_name: &str,
suffix: Option<&str>,
) -> Option<PathBuf> {
let record = spawn_record_path(runtime_dir, task_id, state_name, suffix);
if let Some(record) = read_spawn_record(&record) {
if record.log.exists() {
return Some(record.log);
}
}
let first = agent_log_attempt_path(runtime_dir, task_id, state_name, suffix, 1);
first.exists().then_some(first)
}
27 changes: 0 additions & 27 deletions crates/rhei-cli/src/cli/agent_resolution.rs
Original file line number Diff line number Diff line change
Expand Up @@ -429,33 +429,6 @@ fn ensure_orchestrator_timeout(resolved: &ResolvedAgent, state_name: &str) -> Mi
))
}

fn resolved_agent_log_suffix(resolved: &ResolvedAgent, visit_count: Option<u64>) -> Option<String> {
agent_log_suffix(resolved.target.as_ref(), resolved.model.as_deref(), visit_count)
}

/// The part of a log file name that follows `task-{task_id}-{state}`.
///
/// Split from the resolved-agent form so prompt composition can name the log of
/// an *earlier* visit, where no `ResolvedAgent` for that visit exists — only
/// the identity this one carries, which is the identity that wrote it.
// §FS-rhei-agents.8.1 §FS-rhei-memory.4.4
fn agent_log_suffix(
target: Option<&ExecutionTarget>,
model: Option<&str>,
visit_count: Option<u64>,
) -> Option<String> {
let base = target
.map(ExecutionTarget::slug)
.or_else(|| model.map(str::to_string).filter(|value| !value.is_empty()));
let visit_suffix = visit_count.filter(|count| *count > 1).map(|count| count.to_string());
match (base, visit_suffix) {
(Some(base), Some(visit)) => Some(format!("{base}-{visit}")),
(Some(base), None) => Some(base),
(None, Some(visit)) => Some(visit),
(None, None) => None,
}
}

#[allow(clippy::too_many_arguments)]
fn state_outputs_exist_for_resolved_invocation(
workspace_root: &Path,
Expand Down
36 changes: 29 additions & 7 deletions crates/rhei-cli/src/cli/agent_spawn.rs
Original file line number Diff line number Diff line change
Expand Up @@ -163,6 +163,10 @@ fn spawn_and_wait_agent(
slot: rhei_tui::Slot,
sink: Arc<dyn rhei_tui::EventSink>,
intervene: Option<&Arc<RunInterveneSink>>,
// Which attempt of which visit this is. Recorded here, beside the footer,
// because this is the one place that knows the subprocess actually ran.
// §FS-rhei-agents.8.4
plan: &SpawnPlan,
// Fan-out key of this invocation; decides the `RHEI_RESULT_PATH` it is
// handed. §FS-rhei-states.3.3
result_identity: Option<&str>,
Expand Down Expand Up @@ -272,6 +276,7 @@ fn spawn_and_wait_agent(
task_id,
state_name,
visit_count,
plan.attempt,
tooling,
runtime_dir,
result_identity,
Expand Down Expand Up @@ -452,23 +457,40 @@ fn spawn_and_wait_agent(

// §FS-rhei-agents.8: Agent log footer, timeout and interruption causes.
let elapsed = start.elapsed();
let duration = format_duration_human(elapsed.as_secs());
let ended_wall = std::time::SystemTime::now();
let timeout_message =
if timed_out { resolved.timeout_secs.map(format_duration_human) } else { None };
// The spawn ran. Say so where the next pass, the next run, and the engine's
// own account of this state will all read it. §FS-rhei-agents.8.4
plan.record_spawn(SpawnEnding {
task_id,
state_name,
kind: "agent",
worker: resolved.agent.id(),
started: &format_iso8601_utc(started_wall),
ended: &format_iso8601_utc(ended_wall),
duration: &duration,
code: status.code(),
ending: if timed_out {
"timed out"
} else if interrupted {
"interrupted"
} else {
"exited"
},
});
with_agent_log(&log_file, |f| {
if let Some(duration) = &timeout_message {
writeln!(f, "\nagent timed out after {duration}")?;
} else if interrupted {
// The run was shutting down, not the agent failing. §FS-rhei-run.3.2
writeln!(
f,
"\nagent interrupted by run shutdown after {}",
format_duration_human(elapsed.as_secs())
)?;
writeln!(f, "\nagent interrupted by run shutdown after {duration}")?;
}
writeln!(f, "\n=== exit ===")?;
writeln!(f, "code: {}", status.code().unwrap_or(-1))?;
writeln!(f, "duration: {}", format_duration_human(elapsed.as_secs()))?;
writeln!(f, "ended: {}", format_iso8601_utc(std::time::SystemTime::now()))?;
writeln!(f, "duration: {duration}")?;
writeln!(f, "ended: {}", format_iso8601_utc(ended_wall))?;
if timed_out {
writeln!(f, "timed_out: true")?;
}
Expand Down
Loading