From 6339a2384be1edba0557f6999b45d0f688020467 Mon Sep 17 00:00:00 2001 From: atlas Date: Mon, 13 Jul 2026 18:17:10 +0200 Subject: [PATCH] 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. --- hive-forge/src/verbs/ci_log.rs | 119 ++++++++++++++++++++------------- 1 file changed, 71 insertions(+), 48 deletions(-) diff --git a/hive-forge/src/verbs/ci_log.rs b/hive-forge/src/verbs/ci_log.rs index 43ac7488..a871a62e 100644 --- a/hive-forge/src/verbs/ci_log.rs +++ b/hive-forge/src/verbs/ci_log.rs @@ -1,30 +1,26 @@ //! `ci-log --run [--job ] [--step ]` — 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 ///actions/runs/ -//! /jobs/` 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/` 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, -//! `///actions/runs//jobs//attempt//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, +//! `///actions/runs//jobs//attempt//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 { 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)]