feat(cli): split run events and raw logs

Make fabro events the event-stream command and repurpose fabro logs for the per-run worker tracing log returned by the server.
This commit is contained in:
Bryan Helmkamp 2026-05-06 13:29:35 -04:00
parent c39ff666ed
commit 3bfb012fab
No known key found for this signature in database
20 changed files with 1797 additions and 1530 deletions

View file

@ -158,7 +158,7 @@ For cache-backed lifecycle work, emit slow-path start events only when the opera
Check:
- CLI progress parsing
- `fabro logs`
- `fabro events`
- retro duration extraction
- store validation
- tests or fixtures that inspect event names or fields

View file

@ -1,6 +1,6 @@
# Events
Every serialized run event envelope, whether streamed over SSE, returned by `fabro logs`, or written to a JSONL sink, uses this structure:
Every serialized run event envelope, whether streamed over SSE, returned by `fabro events`, or written to a JSONL sink, uses this structure:
```json
{

View file

@ -31,7 +31,7 @@ Fixed server and per-run logs use a per-event-buffered writer opened with `O_APP
- Hot loops or per-token streaming events (use DEBUG only if truly needed for diagnosis)
- Data that belongs in user-facing output (`eprintln!` for interactive CLI feedback, not tracing)
- Detached user-visible warnings or errors that need to survive `attach`/`logs` (`detach.log` is debug-only; emit an `Event` into the run event stream instead)
- Detached user-visible warnings or errors that need to survive `attach`/`events` (`detach.log` is debug-only; emit an `Event` into the run event stream instead)
- Redundant information already captured by a parent event (if you logged "starting X", you don't need to log every sub-step at the same level)
- Events that are already traced via `EventEnum::trace()` — the event enums (`AgentEvent`, `PipelineEvent`, `ExecutionEnvEvent`) each have a `trace()` method called automatically at their emit site; do not add manual `info!`/`debug!` calls that duplicate what `trace()` already emits
- Wrapper/forwarding variants that re-emit an inner event — `PipelineEvent::Agent`, `PipelineEvent::ExecutionEnv`, and `AgentEvent::SubAgentEvent` are no-ops in `trace()` because the inner event is already traced at its origin
@ -192,7 +192,7 @@ The domain event enums (`AgentEvent`, `PipelineEvent`, `ExecutionEnvEvent`) each
- **Add tracing for new variants** by adding a match arm in the enum's `trace()` method. Choose the level based on the guidelines above (INFO for lifecycle boundaries, DEBUG for individual steps, WARN/ERROR for failures).
- **Do not add manual log calls at emit sites.** The `trace()` call in the emitter handles it. Adding `info!` or `debug!` next to an `emit()` call will double-log.
- **Detached UX belongs in events, not stderr.** If an attached user needs to see the message later via `fabro attach` or `fabro logs`, emit a workflow event (for example `RunNotice`) and let tracing capture the developer-oriented copy separately.
- **Detached UX belongs in events, not stderr.** If an attached user needs to see the message later via `fabro attach` or `fabro events`, emit a workflow event (for example `RunNotice`) and let tracing capture the developer-oriented copy separately.
- **Wrapper variants are no-ops.** When one event enum wraps another (`PipelineEvent::Agent` wraps `AgentEvent`, `AgentEvent::SubAgentEvent` wraps a child `AgentEvent`), the wrapper's `trace()` arm is `{}` because the inner event was already traced at its origin. This prevents double-logging.
- **Streaming noise variants are no-ops.** `TextDelta` and `ToolCallOutputDelta` produce no log output — per-token events would flood the logs even at DEBUG level.

View file

@ -119,7 +119,7 @@ The tracked paths are stored as `files_touched` on the stage outcome:
| Location | How it's used |
|---|---|
| `StageCompleted` event | Emitted with `files_touched` in the event stream and surfaced by `fabro logs` / exported event streams |
| `StageCompleted` event | Emitted with `files_touched` in the event stream and surfaced by `fabro events` / exported event streams |
| Preambles | Listed under each completed stage so downstream agents know what changed |
| Retros | Included per-stage and aggregated across the full run |
| `status.json` | Written to the stage's logs directory after each node completes |

View file

@ -71,14 +71,14 @@ Because event payload lives in `properties`, most shell queries should look ther
```bash
# Count tool calls in a run
fabro logs 01JKXYZ... | jq -r 'select(.event == "agent.tool.started") | .properties.tool_name' | wc -l
fabro events 01JKXYZ... | jq -r 'select(.event == "agent.tool.started") | .properties.tool_name' | wc -l
# Find stage failures
fabro logs 01JKXYZ... | jq 'select(.event == "stage.failed")'
fabro events 01JKXYZ... | jq 'select(.event == "stage.failed")'
# See which edges were taken
jq '{from: .properties.from_node, to: .properties.to_node, label: .properties.label}' \
<(fabro logs 01JKXYZ...) | head
<(fabro events 01JKXYZ...) | head
```
If you need files on disk for offline analysis, `fabro dump` exports `events.jsonl` plus run-state projections.
@ -110,7 +110,7 @@ Lifecycle events such as `agent.sub.spawned` and `agent.sub.completed` are emitt
### API: Server-Sent Events
When running workflows through the API server, subscribe to the [run events endpoint](/api-reference/runs/stream-run-events). Each SSE payload is a serialized run event envelope in the same shape used by `fabro logs` and `events.jsonl` exports.
When running workflows through the API server, subscribe to the [run events endpoint](/api-reference/runs/stream-run-events). Each SSE payload is a serialized run event envelope in the same shape used by `fabro events` and `events.jsonl` exports.
### Web UI
@ -130,7 +130,8 @@ Post-run analysis surfaces include:
| Surface | Description |
|---|---|
| `fabro logs <RUN>` | Full event envelope stream as NDJSON |
| `fabro events <RUN>` | Full event envelope stream as NDJSON |
| `fabro logs <RUN>` | Raw per-run worker tracing log, when available |
| `fabro inspect <RUN>` | Current durable run state, including run/start/checkpoint/conclusion records |
| `fabro dump --output <DIR> <RUN>` | Exported `events.jsonl` plus reconstructed JSON and node files |

View file

@ -73,11 +73,12 @@ fabro [OPTIONS] [COMMAND]
| `fabro docs` | Open the docs website in the browser |
| `fabro doctor` | Check environment and integration health |
| `fabro dump` | Export a run's durable state to a directory |
| `fabro events` | View the event log of a workflow run |
| `fabro fork` | Fork a workflow run from an earlier checkpoint into a new run |
| `fabro graph` | Render a workflow graph as SVG |
| `fabro inspect` | Show detailed information about a workflow run |
| `fabro install` | Set up the Fabro environment (LLMs, certs, GitHub) |
| `fabro logs` | View the event log of a workflow run |
| `fabro logs` | View the raw worker tracing log of a workflow run |
| `fabro model` | List and test LLM models |
| `fabro pr` | Pull request operations |
| `fabro preflight` | Validate run configuration without executing |
@ -364,6 +365,30 @@ fabro dump [OPTIONS] --output <OUTPUT> <RUN>
| `-o, --output <output>` | Output directory (must not exist or be empty) |
| `--server <server>` | Fabro server target: http(s) URL or absolute Unix socket path |
### `fabro events`
View the event log of a workflow run
```bash
fabro events [OPTIONS] <RUN>
```
#### Arguments
| Name | Description |
| --- | --- |
| `RUN` | Run ID prefix or workflow name (most recent run) |
#### Options
| Option | Description |
| --- | --- |
| `-f, --follow` | Follow event output |
| `-p, --pretty` | Formatted colored output with rendered assistant text |
| `--server <server>` | Fabro server target: http(s) URL or absolute Unix socket path |
| `--since <since>` | Events since timestamp or relative (e.g. "42m", "2h", "2026-01-02T13:00:00Z") |
| `-n, --tail <tail>` | Lines from end (default: all) |
### `fabro fork`
Fork a workflow run from an earlier checkpoint into a new run
@ -467,7 +492,7 @@ fabro install github [OPTIONS]
### `fabro logs`
View the event log of a workflow run
View the raw worker tracing log of a workflow run
```bash
fabro logs [OPTIONS] <RUN>
@ -483,10 +508,7 @@ fabro logs [OPTIONS] <RUN>
| Option | Description |
| --- | --- |
| `-f, --follow` | Follow log output |
| `-p, --pretty` | Formatted colored output with rendered assistant text |
| `--server <server>` | Fabro server target: http(s) URL or absolute Unix socket path |
| `--since <since>` | Logs since timestamp or relative (e.g. "42m", "2h", "2026-01-02T13:00:00Z") |
| `-n, --tail <tail>` | Lines from end (default: all) |
### `fabro model`

View file

@ -27,10 +27,10 @@ The naming format is `YYYYMMDD-{run_id}`, where `run_id` is the ULID assigned to
These paths are local runtime state and caches, not the canonical run state.
- **`worktree/`** — When running in worktree mode, Fabro creates a Git worktree here as the working directory for agents and commands.
- **`runtime/`** — Local runtime files. Today this is mainly materialized blob payloads under `runtime/blobs/`.
- **`runtime/`** — Local runtime files. Today this includes `runtime/server.log` for the raw per-run worker tracing log and materialized blob payloads under `runtime/blobs/`.
- **`nodes/{manager_node}_{visit}/child/`** — Nested scratch directories for manager-loop child workflows.
Large durable values, event streams, checkpoints, diffs, conclusions, and retros are no longer projected into live scratch by default. Use `fabro logs`, `fabro inspect`, the API, or `fabro dump` for those surfaces.
Large durable values, event streams, checkpoints, diffs, conclusions, and retros are no longer projected into live scratch by default. Use `fabro events`, `fabro inspect`, the API, or `fabro dump` for those surfaces. Use `fabro logs` for the raw per-run worker tracing log when it is available.
## Reconstructed and export-only layouts

View file

@ -365,16 +365,16 @@ pub(crate) struct RunsUnarchiveArgs {
}
#[derive(Args)]
pub(crate) struct LogsArgs {
pub(crate) struct EventsArgs {
#[command(flatten)]
pub(crate) server: ServerTargetArgs,
/// Run ID prefix or workflow name (most recent run)
pub(crate) run: String,
/// Follow log output
/// Follow event output
#[arg(short, long)]
pub(crate) follow: bool,
/// Logs since timestamp or relative (e.g. "42m", "2h",
/// Events since timestamp or relative (e.g. "42m", "2h",
/// "2026-01-02T13:00:00Z")
#[arg(long)]
pub(crate) since: Option<String>,
@ -386,6 +386,18 @@ pub(crate) struct LogsArgs {
pub(crate) pretty: bool,
}
#[derive(Args)]
pub(crate) struct LogsArgs {
#[command(flatten)]
pub(crate) server: ServerTargetArgs,
/// Run ID prefix or workflow name (most recent run)
pub(crate) run: String,
/// Lines from end (default: all)
#[arg(short = 'n', long)]
pub(crate) tail: Option<usize>,
}
#[derive(Args)]
pub(crate) struct ValidateArgs {
/// Path to the .fabro workflow file
@ -974,6 +986,8 @@ pub(crate) enum RunCommands {
#[command(hide = true)]
Diff(DiffArgs),
/// View the event log of a workflow run
Events(EventsArgs),
/// View the raw worker tracing log of a workflow run
Logs(LogsArgs),
/// Resume an interrupted workflow run
Resume(ResumeArgs),
@ -996,6 +1010,7 @@ impl RunCommands {
Self::Attach(_) => "attach",
Self::RunWorker(_) => "__run-worker",
Self::Diff(_) => "diff",
Self::Events(_) => "events",
Self::Logs(_) => "logs",
Self::Resume(_) => "resume",
Self::Rewind(_) => "rewind",

File diff suppressed because it is too large Load diff

File diff suppressed because it is too large Load diff

View file

@ -14,6 +14,7 @@ pub(crate) mod command;
pub(crate) mod cp;
pub(crate) mod create;
pub(crate) mod diff;
pub(crate) mod events;
pub(crate) mod fork;
pub(crate) mod logs;
pub(crate) mod output;
@ -99,10 +100,11 @@ pub(crate) async fn dispatch(
.await
}
RunCommands::Diff(args) => diff::run(args, base_ctx).await,
RunCommands::Logs(args) => {
RunCommands::Events(args) => {
let styles = Styles::detect_stdout();
logs::run(&args, &styles, base_ctx).await
events::run(&args, &styles, base_ctx).await
}
RunCommands::Logs(args) => logs::run(&args, base_ctx).await,
RunCommands::Resume(args) => {
let styles: &'static Styles = Box::leak(Box::new(Styles::detect_stderr()));
#[cfg(feature = "sleep_inhibitor")]

View file

@ -54,7 +54,8 @@ pub(crate) fn print() {
section(
"Inspect runs",
&[
("logs", "View the event log of a workflow run"),
("events", "View the event log of a workflow run"),
("logs", "View the raw worker tracing log of a workflow run"),
("sandbox ssh", "SSH into a run's sandbox"),
],
cmd_width,

View file

@ -279,7 +279,7 @@ fn attach_before_completion_streams_to_finished_state() {
#[test]
#[expect(
clippy::disallowed_methods,
reason = "This sync integration test polls logs for a human gate without creating a Tokio runtime."
reason = "This sync integration test polls events for a human gate without creating a Tokio runtime."
)]
fn attach_json_errors_without_prompting_for_human_input() {
let context = test_context!();
@ -331,13 +331,13 @@ fn attach_json_errors_without_prompting_for_human_input() {
}
let deadline = std::time::Instant::now() + SHARED_DAEMON_TIMEOUT;
loop {
let logs_output = context
let events_output = context
.command()
.args(["logs", &run_id, "--json"])
.args(["events", &run_id, "--json"])
.output()
.expect("logs should execute");
assert!(logs_output.status.success(), "logs should succeed");
let log_events: Vec<Value> = String::from_utf8(logs_output.stdout)
.expect("events should execute");
assert!(events_output.status.success(), "events should succeed");
let log_events: Vec<Value> = String::from_utf8(events_output.stdout)
.expect("stdout should be UTF-8")
.lines()
.filter(|line| !line.trim().is_empty())
@ -371,13 +371,13 @@ fn attach_json_errors_without_prompting_for_human_input() {
!stderr.contains("Approve?"),
"attach should not prompt on stderr"
);
let logs_output = context
let events_output = context
.command()
.args(["logs", &run_id, "--json"])
.args(["events", &run_id, "--json"])
.output()
.expect("logs should execute");
assert!(logs_output.status.success(), "logs should succeed");
let log_events: Vec<Value> = String::from_utf8(logs_output.stdout)
.expect("events should execute");
assert!(events_output.status.success(), "events should succeed");
let log_events: Vec<Value> = String::from_utf8(events_output.stdout)
.expect("stdout should be UTF-8")
.lines()
.filter(|line| !line.trim().is_empty())

View file

@ -0,0 +1,250 @@
use fabro_test::{fabro_snapshot, test_context};
use serde_json::Value;
use super::support::{setup_detached_dry_run, setup_seeded_completed_dry_run};
fn parse_ndjson(stdout: &[u8]) -> Vec<Value> {
String::from_utf8(stdout.to_vec())
.expect("stdout should be valid UTF-8")
.lines()
.filter(|line| !line.trim().is_empty())
.map(|line| {
serde_json::from_str::<Value>(line).expect("events output should be valid NDJSON")
})
.collect()
}
fn assert_event_sequence_contains(events: &[Value], expected: &[&str]) {
let event_names: Vec<&str> = events
.iter()
.filter_map(|event| event["event"].as_str())
.collect();
let mut cursor = 0;
for expected_name in expected {
let Some(found_at) = event_names[cursor..]
.iter()
.position(|name| name == expected_name)
else {
panic!("missing event {expected_name} in sequence: {event_names:?}");
};
cursor += found_at + 1;
}
}
fn assert_events_belong_to_run(events: &[Value], run_id: &str) {
assert!(!events.is_empty(), "expected at least one event");
for event in events {
assert_eq!(
event["run_id"].as_str(),
Some(run_id),
"event should belong to requested run: {event}"
);
}
}
#[test]
fn help() {
let context = test_context!();
let mut cmd = context.command();
cmd.args(["events", "--help"]);
fabro_snapshot!(context.filters(), cmd, @r#"
success: true
exit_code: 0
----- stdout -----
View the event log of a workflow run
Usage: fabro events [OPTIONS] <RUN>
Arguments:
<RUN> Run ID prefix or workflow name (most recent run)
Options:
--json Output as JSON [env: FABRO_JSON=]
--server <SERVER> Fabro server target: http(s) URL or absolute Unix socket path [env: FABRO_SERVER=]
--debug Enable DEBUG-level logging (default is INFO) [env: FABRO_DEBUG=]
-f, --follow Follow event output
--no-upgrade-check Disable automatic upgrade check [env: FABRO_NO_UPGRADE_CHECK=true]
--since <SINCE> Events since timestamp or relative (e.g. "42m", "2h", "2026-01-02T13:00:00Z")
-n, --tail <TAIL> Lines from end (default: all)
--quiet Suppress non-essential output [env: FABRO_QUIET=]
-p, --pretty Formatted colored output with rendered assistant text
--verbose Enable verbose output [env: FABRO_VERBOSE=]
-h, --help Print help
----- stderr -----
"#);
}
#[test]
fn events_completed_run_outputs_raw_ndjson() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut cmd = context.command();
cmd.args(["events", &run.run_id]);
let output = cmd.output().expect("command should execute");
assert!(
output.status.success(),
"events should succeed\nstdout:\n{}\nstderr:\n{}",
String::from_utf8_lossy(&output.stdout),
String::from_utf8_lossy(&output.stderr)
);
let events = parse_ndjson(&output.stdout);
assert_events_belong_to_run(&events, &run.run_id);
assert_event_sequence_contains(&events, &[
"run.created",
"run.running",
"stage.started",
"stage.completed",
"run.completed",
"sandbox.cleanup.completed",
]);
}
#[test]
fn events_completed_run_reads_store_without_progress_jsonl() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut filters = context.filters();
filters.push((
r"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?Z".to_string(),
"[TIMESTAMP]".to_string(),
));
filters.push((
r#""duration_ms":\s*\d+"#.to_string(),
r#""duration_ms": [DURATION_MS]"#.to_string(),
));
filters.push((
r#""id":"[0-9a-f-]+""#.to_string(),
r#""id":"[EVENT_ID]""#.to_string(),
));
filters.push((
r#""run_dir":"(?:\[DRY_RUN_DIR\]|\[STORAGE_DIR\]/scratch/REDACTED)""#.to_string(),
r#""run_dir":"[RUN_DIR]""#.to_string(),
));
let mut cmd = context.command();
cmd.args(["events", "--tail", "2", &run.run_id]);
fabro_snapshot!(filters, cmd, @r#"
success: true
exit_code: 0
----- stdout -----
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.started","id":"[EVENT_ID]","properties":{"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.completed","id":"[EVENT_ID]","properties":{"duration_ms": [DURATION_MS],"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
----- stderr -----
"#);
}
#[test]
fn events_tail_limits_output() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut filters = context.filters();
filters.push((
r"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?Z".to_string(),
"[TIMESTAMP]".to_string(),
));
filters.push((
r#""duration_ms":\s*\d+"#.to_string(),
r#""duration_ms": [DURATION_MS]"#.to_string(),
));
filters.push((
r#""id":"[0-9a-f-]+""#.to_string(),
r#""id":"[EVENT_ID]""#.to_string(),
));
filters.push((
r#""run_dir":"(?:\[DRY_RUN_DIR\]|\[STORAGE_DIR\]/scratch/REDACTED)""#.to_string(),
r#""run_dir":"[RUN_DIR]""#.to_string(),
));
let mut cmd = context.command();
cmd.args(["events", "--tail", "2", &run.run_id]);
fabro_snapshot!(filters, cmd, @r#"
success: true
exit_code: 0
----- stdout -----
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.started","id":"[EVENT_ID]","properties":{"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.completed","id":"[EVENT_ID]","properties":{"duration_ms": [DURATION_MS],"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
----- stderr -----
"#);
}
#[test]
fn events_since_filters_output() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut cmd = context.command();
cmd.args(["events", "--since", "2999-01-01T00:00:00Z", &run.run_id]);
fabro_snapshot!(context.filters(), cmd, @r#"
success: true
exit_code: 0
----- stdout -----
----- stderr -----
"#);
}
#[test]
fn events_pretty_formats_small_run() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut filters = context.filters();
filters.push((r"\b\d{2}:\d{2}:\d{2}\b".to_string(), "[CLOCK]".to_string()));
filters.push((
r"\b\d+(\.\d+)?(ms|s)\b".to_string(),
"[DURATION]".to_string(),
));
let mut cmd = context.command();
cmd.args(["events", "--pretty", &run.run_id]);
fabro_snapshot!(filters, cmd, @"
success: true
exit_code: 0
----- stdout -----
[CLOCK] Sandbox: local [DURATION]
[CLOCK] Simple [ULID]
Run tests and report results
[CLOCK] Start
[CLOCK] Start [DURATION]
[CLOCK] run_tests unconditional
[CLOCK] Run Tests
[CLOCK] Run Tests [DURATION]
[CLOCK] report unconditional
[CLOCK] Report
[CLOCK] Report [DURATION]
[CLOCK] exit unconditional
[CLOCK] Exit
[CLOCK] Exit [DURATION]
[CLOCK] SUCCEEDED [DURATION]
----- stderr -----
");
}
#[test]
fn events_follow_detached_run_streams_until_completion() {
let context = test_context!();
let run = setup_detached_dry_run(&context);
let mut cmd = context.command();
cmd.args(["events", "--follow", &run.run_id]);
let output = cmd.output().expect("command should execute");
assert!(
output.status.success(),
"events --follow should succeed\nstdout:\n{}\nstderr:\n{}",
String::from_utf8_lossy(&output.stdout),
String::from_utf8_lossy(&output.stderr)
);
let events = parse_ndjson(&output.stdout);
assert_events_belong_to_run(&events, &run.run_id);
assert_event_sequence_contains(&events, &[
"run.created",
"run.running",
"stage.started",
"stage.completed",
"run.completed",
"sandbox.cleanup.completed",
]);
}

View file

@ -16,7 +16,8 @@ fn help() {
create Create a workflow run (allocate run dir, persist spec)
start Start a created workflow run on the server
attach Attach to a running or finished workflow run
logs View the event log of a workflow run
events View the event log of a workflow run
logs View the raw worker tracing log of a workflow run
resume Resume an interrupted workflow run
rewind Rewind a workflow run to an earlier checkpoint
fork Fork a workflow run from an earlier checkpoint into a new run
@ -93,7 +94,8 @@ fn no_args_prints_curated_landing() {
Inspect runs
fabro logs View the event log of a workflow run
fabro events View the event log of a workflow run
fabro logs View the raw worker tracing log of a workflow run
fabro sandbox ssh SSH into a run's sandbox
If you need help along the way:

View file

@ -172,20 +172,20 @@ fn ps_supports_global_flag_and_env_var() {
}
#[test]
fn logs_json_wins_over_pretty() {
fn events_json_wins_over_pretty() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let output = context
.command()
.args(["--json", "logs", "--pretty", &run.run_id])
.args(["--json", "events", "--pretty", &run.run_id])
.output()
.expect("command should run");
assert!(output.status.success());
let stdout = String::from_utf8(output.stdout).unwrap();
let first_line = stdout.lines().find(|line| !line.is_empty()).unwrap();
let value: Value = serde_json::from_str(first_line).expect("logs output should remain JSONL");
let value: Value = serde_json::from_str(first_line).expect("events output should remain JSONL");
assert!(value.get("event").is_some());
}

View file

@ -1,46 +1,16 @@
use std::path::Path;
use fabro_test::{fabro_snapshot, test_context};
use serde_json::Value;
use super::support::{setup_detached_dry_run, setup_seeded_completed_dry_run};
use super::support::{output_stderr, setup_seeded_completed_dry_run};
fn parse_ndjson(stdout: &[u8]) -> Vec<Value> {
String::from_utf8(stdout.to_vec())
.expect("stdout should be valid UTF-8")
.lines()
.filter(|line| !line.trim().is_empty())
.map(|line| {
serde_json::from_str::<Value>(line).expect("logs output should be valid NDJSON")
})
.collect()
}
fn assert_event_sequence_contains(events: &[Value], expected: &[&str]) {
let event_names: Vec<&str> = events
.iter()
.filter_map(|event| event["event"].as_str())
.collect();
let mut cursor = 0;
for expected_name in expected {
let Some(found_at) = event_names[cursor..]
.iter()
.position(|name| name == expected_name)
else {
panic!("missing event {expected_name} in sequence: {event_names:?}");
};
cursor += found_at + 1;
}
}
fn assert_events_belong_to_run(events: &[Value], run_id: &str) {
assert!(!events.is_empty(), "expected at least one log event");
for event in events {
assert_eq!(
event["run_id"].as_str(),
Some(run_id),
"event should belong to requested run: {event}"
);
}
fn seed_run_log(run_dir: &Path, contents: &[u8]) {
// Raw logs are the CLI surface for this runtime-owned file; no public
// command creates deterministic contents suitable for exact assertions.
let log_path = run_dir.join("runtime/server.log");
std::fs::create_dir_all(log_path.parent().expect("log path should have parent"))
.expect("runtime log directory should be created");
std::fs::write(&log_path, contents).expect("runtime log should be seeded");
}
#[test]
@ -52,7 +22,7 @@ fn help() {
success: true
exit_code: 0
----- stdout -----
View the event log of a workflow run
View the raw worker tracing log of a workflow run
Usage: fabro logs [OPTIONS] <RUN>
@ -63,12 +33,9 @@ fn help() {
--json Output as JSON [env: FABRO_JSON=]
--server <SERVER> Fabro server target: http(s) URL or absolute Unix socket path [env: FABRO_SERVER=]
--debug Enable DEBUG-level logging (default is INFO) [env: FABRO_DEBUG=]
-f, --follow Follow log output
--no-upgrade-check Disable automatic upgrade check [env: FABRO_NO_UPGRADE_CHECK=true]
--since <SINCE> Logs since timestamp or relative (e.g. "42m", "2h", "2026-01-02T13:00:00Z")
-n, --tail <TAIL> Lines from end (default: all)
--no-upgrade-check Disable automatic upgrade check [env: FABRO_NO_UPGRADE_CHECK=true]
--quiet Suppress non-essential output [env: FABRO_QUIET=]
-p, --pretty Formatted colored output with rendered assistant text
--verbose Enable verbose output [env: FABRO_VERBOSE=]
-h, --help Print help
----- stderr -----
@ -76,160 +43,109 @@ fn help() {
}
#[test]
fn logs_completed_run_outputs_raw_ndjson() {
fn logs_run_outputs_seeded_runtime_log_exactly() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut cmd = context.command();
cmd.args(["logs", &run.run_id]);
let output = cmd.output().expect("command should execute");
seed_run_log(&run.run_dir, b"worker started\nworker finished");
let output = context
.command()
.args(["logs", &run.run_id])
.output()
.expect("command should run");
assert!(
output.status.success(),
"logs should succeed\nstdout:\n{}\nstderr:\n{}",
String::from_utf8_lossy(&output.stdout),
String::from_utf8_lossy(&output.stderr)
);
let events = parse_ndjson(&output.stdout);
assert_events_belong_to_run(&events, &run.run_id);
assert_event_sequence_contains(&events, &[
"run.created",
"run.running",
"stage.started",
"stage.completed",
"run.completed",
"sandbox.cleanup.completed",
]);
assert_eq!(output.stdout, b"worker started\nworker finished");
}
#[test]
fn logs_completed_run_reads_store_without_progress_jsonl() {
fn logs_tail_one_outputs_final_line() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
seed_run_log(&run.run_dir, b"worker started\nworker finished");
let mut filters = context.filters();
filters.push((
r"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?Z".to_string(),
"[TIMESTAMP]".to_string(),
));
filters.push((
r#""duration_ms":\s*\d+"#.to_string(),
r#""duration_ms": [DURATION_MS]"#.to_string(),
));
filters.push((
r#""id":"[0-9a-f-]+""#.to_string(),
r#""id":"[EVENT_ID]""#.to_string(),
));
filters.push((
r#""run_dir":"(?:\[DRY_RUN_DIR\]|\[STORAGE_DIR\]/scratch/REDACTED)""#.to_string(),
r#""run_dir":"[RUN_DIR]""#.to_string(),
));
let output = context
.command()
.args(["logs", "--tail", "1", &run.run_id])
.output()
.expect("command should run");
assert!(output.status.success());
assert_eq!(output.stdout, b"worker finished\n");
}
#[test]
fn logs_tail_zero_outputs_nothing() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
seed_run_log(&run.run_dir, b"worker started\nworker finished");
let output = context
.command()
.args(["logs", "--tail", "0", &run.run_id])
.output()
.expect("command should run");
assert!(output.status.success());
assert!(output.stdout.is_empty());
}
#[test]
fn logs_follow_is_unknown_argument() {
let context = test_context!();
let mut cmd = context.command();
cmd.args(["logs", "--tail", "2", &run.run_id]);
cmd.args(["logs", "--follow", "01K00000000000000000000000"]);
fabro_snapshot!(filters, cmd, @r#"
success: true
exit_code: 0
fabro_snapshot!(context.filters(), cmd, @r#"
success: false
exit_code: 2
----- stdout -----
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.started","id":"[EVENT_ID]","properties":{"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.completed","id":"[EVENT_ID]","properties":{"duration_ms": [DURATION_MS],"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
----- stderr -----
error: unexpected argument '--follow' found
tip: to pass '--follow' as a value, use '-- --follow'
Usage: fabro logs [OPTIONS] <RUN>
For more information, try '--help'.
"#);
}
#[test]
fn logs_tail_limits_output() {
fn logs_json_is_rejected() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut filters = context.filters();
filters.push((
r"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?Z".to_string(),
"[TIMESTAMP]".to_string(),
));
filters.push((
r#""duration_ms":\s*\d+"#.to_string(),
r#""duration_ms": [DURATION_MS]"#.to_string(),
));
filters.push((
r#""id":"[0-9a-f-]+""#.to_string(),
r#""id":"[EVENT_ID]""#.to_string(),
));
filters.push((
r#""run_dir":"(?:\[DRY_RUN_DIR\]|\[STORAGE_DIR\]/scratch/REDACTED)""#.to_string(),
r#""run_dir":"[RUN_DIR]""#.to_string(),
));
let mut cmd = context.command();
cmd.args(["logs", "--tail", "2", &run.run_id]);
seed_run_log(&run.run_dir, b"worker started\n");
fabro_snapshot!(filters, cmd, @r#"
success: true
exit_code: 0
----- stdout -----
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.started","id":"[EVENT_ID]","properties":{"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
{"actor":{"kind":"worker","run_id":"[ULID]"},"event":"sandbox.cleanup.completed","id":"[EVENT_ID]","properties":{"duration_ms": [DURATION_MS],"provider":"local"},"run_id":"[ULID]","ts":"[TIMESTAMP]"}
----- stderr -----
"#);
let output = context
.command()
.args(["--json", "logs", &run.run_id])
.output()
.expect("command should run");
assert!(!output.status.success());
let stderr = output_stderr(&output);
assert!(stderr.contains("--json is not supported for this command"));
}
#[test]
fn logs_pretty_formats_small_run() {
fn logs_missing_runtime_log_exits_nonzero() {
let context = test_context!();
let run = setup_seeded_completed_dry_run(&context);
let mut filters = context.filters();
filters.push((r"\b\d{2}:\d{2}:\d{2}\b".to_string(), "[CLOCK]".to_string()));
filters.push((
r"\b\d+(\.\d+)?(ms|s)\b".to_string(),
"[DURATION]".to_string(),
));
let mut cmd = context.command();
cmd.args(["logs", "--pretty", &run.run_id]);
let _ = std::fs::remove_file(run.run_dir.join("runtime/server.log"));
fabro_snapshot!(filters, cmd, @"
success: true
exit_code: 0
----- stdout -----
[CLOCK] Sandbox: local [DURATION]
[CLOCK] Simple [ULID]
Run tests and report results
let output = context
.command()
.args(["logs", &run.run_id])
.output()
.expect("command should run");
[CLOCK] Start
[CLOCK] Start [DURATION]
[CLOCK] run_tests unconditional
[CLOCK] Run Tests
[CLOCK] Run Tests [DURATION]
[CLOCK] report unconditional
[CLOCK] Report
[CLOCK] Report [DURATION]
[CLOCK] exit unconditional
[CLOCK] Exit
[CLOCK] Exit [DURATION]
[CLOCK] SUCCEEDED [DURATION]
----- stderr -----
");
}
#[test]
fn logs_follow_detached_run_streams_until_completion() {
let context = test_context!();
let run = setup_detached_dry_run(&context);
let mut cmd = context.command();
cmd.args(["logs", "--follow", &run.run_id]);
let output = cmd.output().expect("command should execute");
assert!(
output.status.success(),
"logs --follow should succeed\nstdout:\n{}\nstderr:\n{}",
String::from_utf8_lossy(&output.stdout),
String::from_utf8_lossy(&output.stderr)
);
let events = parse_ndjson(&output.stdout);
assert_events_belong_to_run(&events, &run.run_id);
assert_event_sequence_contains(&events, &[
"run.created",
"run.running",
"stage.started",
"stage.completed",
"run.completed",
"sandbox.cleanup.completed",
]);
assert!(!output.status.success());
let stderr = output_stderr(&output);
assert!(stderr.contains("Run log not available"));
}

View file

@ -11,6 +11,7 @@ mod discord;
mod docs;
mod doctor;
mod dump;
mod events;
mod exec;
mod fabro;
mod fork;

View file

@ -785,12 +785,12 @@ fn dry_run_persists_event_history_in_store() {
wait_for_event_names(&run_dir, &["run.completed", "sandbox.cleanup.completed"]);
let output = context
.command()
.args(["logs", &run_id])
.args(["events", &run_id])
.output()
.expect("logs command should execute");
.expect("events command should execute");
assert!(
output.status.success(),
"logs failed:\nstdout:\n{}\nstderr:\n{}",
"events failed:\nstdout:\n{}\nstderr:\n{}",
String::from_utf8_lossy(&output.stdout),
String::from_utf8_lossy(&output.stderr)
);
@ -798,7 +798,7 @@ fn dry_run_persists_event_history_in_store() {
.expect("stdout should be UTF-8")
.lines()
.filter(|line| !line.trim().is_empty())
.map(|line| serde_json::from_str(line).expect("logs output should be JSONL"))
.map(|line| serde_json::from_str(line).expect("events output should be JSONL"))
.collect();
assert!(
!progress.is_empty(),
@ -828,12 +828,12 @@ fn dry_run_persists_event_history_in_store() {
let tail_output = context
.command()
.args(["logs", "--tail", "1", &run_id])
.args(["events", "--tail", "1", &run_id])
.output()
.expect("tail logs command should execute");
.expect("tail events command should execute");
assert!(
tail_output.status.success(),
"tail logs failed:\nstdout:\n{}\nstderr:\n{}",
"tail events failed:\nstdout:\n{}\nstderr:\n{}",
String::from_utf8_lossy(&tail_output.stdout),
String::from_utf8_lossy(&tail_output.stderr)
);
@ -841,8 +841,8 @@ fn dry_run_persists_event_history_in_store() {
.expect("stdout should be UTF-8")
.lines()
.find(|line| !line.trim().is_empty())
.map(|line| serde_json::from_str(line).expect("tail logs output should be JSON"))
.expect("tail logs should include the latest event");
.map(|line| serde_json::from_str(line).expect("tail events output should be JSON"))
.expect("tail events should include the latest event");
fabro_json_snapshot!(context, &live_content, @r#"
{
"actor": {

View file

@ -67,13 +67,13 @@ fn local_run_lifecycle() {
items[0]["conclusion"].is_object(),
"inspect should include conclusion"
);
// 4. logs <run_id> — non-empty, first line is valid JSONL with event field
let logs_out = cmd(&["logs", &run_id]).success();
let logs_stdout = String::from_utf8(logs_out.get_output().stdout.clone()).unwrap();
assert!(!logs_stdout.is_empty(), "logs should not be empty");
let first_line = logs_stdout.lines().next().unwrap();
// 4. events <run_id> — non-empty, first line is valid JSONL with event field
let events_out = cmd(&["events", &run_id]).success();
let events_stdout = String::from_utf8(events_out.get_output().stdout.clone()).unwrap();
assert!(!events_stdout.is_empty(), "events should not be empty");
let first_line = events_stdout.lines().next().unwrap();
let log_entry: Value =
serde_json::from_str(first_line).expect("first log line should be valid JSON");
serde_json::from_str(first_line).expect("first event line should be valid JSON");
assert!(
log_entry["event"].is_string(),
"first log line should have an event field"