fix(#2412): ci-log prefers persisted (complete) log over live streamer snapshot

The live run-view streamer returns a single snapshot of whatever act_runner
had buffered by poll time. For a job that's still running that's fine (no
persisted log exists yet), but for a job that already finished it silently
truncates wherever the snapshot happened to stop -- the original bug: a
failed nix flake check run returned only the ~90s eval-phase prefix and
dropped the actual build-phase error entirely.

Flip the priority: try the durable persisted-log download first (complete
once it exists), fall back to the streamer only when nothing's persisted
yet (run still live). --step still goes straight to the streamer since the
persisted log is flat and doesn't honor per-step framing.
This commit is contained in:
atlas 2026-07-13 18:17:10 +02:00 committed by mara
commit 6339a2384b

View file

@ -1,30 +1,26 @@
//! `ci-log --run <run-number> [--job <idx>] [--step <idx>]` — print a CI
//! Actions run's job step logs.
//!
//! Two log sources, tried in order, because each covers a different
//! lifecycle window:
//! Two log sources, in **completeness order** (not discovery order):
//!
//! 1. **Live run-view streamer** — `POST <base>/<owner>/<repo>/actions/runs/
//! <run>/jobs/<job>` with a `{"logCursors":[{"step":N,"cursor":C,
//! "expanded":bool}]}` body, the same endpoint the run page polls. It
//! gives rich per-step framing but reads the **live `act_runner` task
//! record**, which Forgejo prunes once a run completes — so a run that
//! finished a while ago returns `500 "task ... resource does not exist"`
//! or no lines. Keyed by the per-repo run NUMBER (the `runs/<n>` the UI
//! shows and `pr-status` surfaces as a CI context `target_url`).
//! 2. **Durable persisted-log download** — when the streamer is pruned the
//! step-log files still exist on disk (the web UI reads them fine after
//! the streamer 500s). We fetch them via the web download route the run
//! page's "view raw logs" link uses,
//! `<base>/<owner>/<repo>/actions/runs/<run>/jobs/<job>/attempt/<n>/logs`,
//! keyed by the per-repo run NUMBER (same value `--run` takes) with the
//! attempt segment. This is a flat whole-job log with no per-step framing,
//! so `--step` is not honored on this path.
//! 1. **Durable persisted-log download** — tried FIRST. Once a job has
//! finished, Forgejo has the complete flat log on disk; fetched via the
//! web route the run page's "view raw logs" link uses,
//! `<base>/<owner>/<repo>/actions/runs/<run>/jobs/<job>/attempt/<n>/logs`.
//! Flat (no per-step framing, so `--step` isn't honored here) and only
//! unavailable while the job hasn't finished yet.
//! 2. **Live run-view streamer** — the run page's own polling endpoint.
//! Rich per-step framing, but each call is a single snapshot of the live
//! `act_runner` task record: fine for a still-running job (nothing
//! persisted yet to prefer), but for a finished job it's only whatever
//! was buffered by poll time — for a multi-minute build phase that can
//! be a small fraction of the real output. This is why the priority
//! matters: a failed `nix flake check` run once returned only the ~90s
//! eval-phase prefix and silently dropped the actual build-phase error.
//!
//! Result: live + recent runs get the rich streamed view; older / quickly-
//! pruned runs (where `act_runner` has already pruned the live task record)
//! still print via the durable fallback instead of a bare
//! "logs garbage-collected" error.
//! So: persisted first (complete once it exists) unless `--step` was
//! explicitly requested (only the streamer honors per-step framing); fall
//! back to the streamer when nothing's persisted yet.
use anyhow::{Result, bail};
use clap::Args as ClapArgs;
@ -168,61 +164,88 @@ fn streamer_logs(client: &Client, path: &str, args: &Args) -> Result<(), Streame
/// (keyed by the per-repo run NUMBER, with the attempt segment). Prints the
/// text (or wraps it in JSON under `--json`). `--step` is not honored here —
/// the persisted log is flat.
fn persisted_logs(client: &Client, repo: &str, args: &Args) -> Result<()> {
///
/// Returns `Ok(true)` when it printed a real (non-empty) log, `Ok(false)`
/// when the persisted log doesn't exist yet (job still running — the
/// caller should fall back to the live streamer), and `Err` for a genuine
/// transport failure.
fn persisted_logs(client: &Client, repo: &str, args: &Args) -> Result<bool> {
let url = client.web_url(&format!(
"/{repo}/actions/runs/{}/jobs/{}/attempt/{}/logs",
args.run, args.job, args.attempt
));
let bytes = client.get_bytes_raw(&url)?;
let Ok(bytes) = client.get_bytes_raw(&url) else {
return Ok(false);
};
if bytes.is_empty() {
bail!(
"run #{} job {} returned an empty log from both the live streamer \
and the persisted-log download the run may not exist or its logs \
were fully purged.",
args.run,
args.job
);
return Ok(false);
}
let text = String::from_utf8_lossy(&bytes);
if client.json_mode() {
return crate::verbs::print_json(&json!({
crate::verbs::print_json(&json!({
"run": args.run,
"job": args.job,
"source": "persisted",
"log": text,
}));
}))?;
return Ok(true);
}
print!("{text}");
if !text.ends_with('\n') {
println!();
}
Ok(())
Ok(true)
}
/// # Errors
///
/// Returns an error if the run/job can't be fetched from either source
/// (network, an unknown run number, or a non-2xx), if a requested `--step`
/// is out of range, or if both the live streamer and the persisted-log
/// download yield no log content.
/// is out of range, or if both sources yield no log content.
pub fn run(client: &Client, args: Args) -> Result<()> {
let repo = client.repo();
let stream_path = format!("/{repo}/actions/runs/{}/jobs/{}", args.run, args.job);
// 1. Live run-view streamer first — rich per-step framing for in-progress
// and recently-finished runs.
match streamer_logs(client, &stream_path, &args) {
Ok(()) => return Ok(()),
// An out-of-range `--step` is a real usage error, not a pruned run —
// surface it instead of masking it with the fallback.
Err(StreamerMiss::StepOutOfRange(msg)) => bail!(msg),
// Pruned task or reachable-but-no-lines → fall through to the durable
// download (survives the act_runner task prune that 500s the streamer).
Err(StreamerMiss::Unavailable) => {}
// `--step` only has meaning against the live streamer's per-step
// framing (the persisted download is a flat whole-job log) — honor it
// directly instead of preferring the persisted route.
if args.step.is_some() {
return match streamer_logs(client, &stream_path, &args) {
Ok(()) => Ok(()),
Err(StreamerMiss::StepOutOfRange(msg)) => bail!(msg),
Err(StreamerMiss::Unavailable) => {
bail!(
"run #{} job {} has no live step log to read `--step` from \
(the run may have finished and the task record was pruned, \
or it hasn't started yet) retry without `--step` to read \
the persisted whole-job log instead.",
args.run,
args.job
)
}
};
}
// 2. Durable persisted-log download (the pruned-run case this verb fixes).
persisted_logs(client, repo, &args)
// 1. Durable persisted-log download first — complete once it exists,
// which is the common case for any run that has already finished
// (successfully or not). Only absent while the job is still running.
if persisted_logs(client, repo, &args)? {
return Ok(());
}
// 2. Live run-view streamer — the run hasn't finished yet (no persisted
// log), so read whatever's been buffered so far.
match streamer_logs(client, &stream_path, &args) {
Ok(()) => Ok(()),
Err(StreamerMiss::StepOutOfRange(msg)) => bail!(msg),
Err(StreamerMiss::Unavailable) => bail!(
"run #{} job {} returned no log from either the persisted download \
or the live streamer the run may not exist or its logs were \
fully purged.",
args.run,
args.job
),
}
}
#[cfg(test)]