updater: three correctness fixes in rollback journaling and apply

updater/src/engine.rs

@@ -1120,6 +1120,9 @@ impl Engine {
         hook?;
 
         rec.phase(Phase::Applying, None);
+        if self.faults.fail_apply_action {
+            return Err(Error::Internal("injected apply-action failure".into()));
+        }
         self.run_apply_action(&cfg.on_apply, release_dir, rec)
             .await?;
 
@@ -1493,20 +1496,28 @@ impl Engine {
             rec.finish(&failed);
             return failed;
         }
+        // The swap has already happened, so a failed apply action means what a failed gate
+        // means: the board is on the new release with its daemons not demonstrably running.
+        // Take the same revert-and-journal path as the gate, as `apply` does for everything
+        // past the swap. Returning early here disarmed the trial and left no log entry, so
+        // the board stayed on an unverified release with no boot-counter protection and no
+        // record of it.
         rec.phase(Phase::Applying, None);
-        if let Err(e) = self
-            .run_apply_action(&cfg.on_apply, &store.release_dir(to), rec)
-            .await
-        {
-            let _ = self.boot_counter.confirm(component);
-            let failed = Err(e);
-            rec.finish(&failed);
-            return failed;
-        }
-
-        rec.phase(Phase::HealthGate, None);
-        let gate = self.health_gate(cfg).await;
-        record_gate(rec, &gate);
+        let apply_action = if self.faults.fail_apply_action {
+            Err(Error::Internal("injected apply-action failure".into()))
+        } else {
+            self.run_apply_action(&cfg.on_apply, &store.release_dir(to), rec)
+                .await
+        };
+        let gate = match apply_action {
+            Ok(()) => {
+                rec.phase(Phase::HealthGate, None);
+                let gate = self.health_gate(cfg).await;
+                record_gate(rec, &gate);
+                gate.map(|_| ())
+            }
+            Err(e) => Err(e),
+        };
 
         let outcome = match gate {
             Ok(_) => {
@@ -1872,27 +1883,16 @@ impl Engine {
 
             rec.finish(&Ok(outcome.clone()));
 
-            let logged = LogEntry {
-                at: now_unix(),
-                component: ComponentId::new(pending.component.clone()),
-                from: Some(pending.version.clone()),
-                to: match &outcome {
-                    ApplyResult::RolledBack { reverted_to, .. } => reverted_to.clone(),
-                    _ => None,
-                },
-                outcome: match &outcome {
-                    ApplyResult::Stuck { reason, .. } => Outcome::Aborted {
-                        reason: reason.clone(),
-                    },
-                    _ => Outcome::RolledBack {
-                        reason: reason.clone(),
-                    },
-                },
-                run: rec.run(),
-            };
-            if let Err(e) = self.journal.append(&logged) {
-                tracing::error!(error = %e, "could not write the update log");
-            }
+            // Through `record`, like every other outcome: the hand-built entry this replaces
+            // put the *reverted-to* version in `to` for a `RolledBack`, which `known_bad`
+            // reads as "the version that failed" — it blacklisted the release now running
+            // and never the one that actually failed. See `journal_outcome`.
+            self.record(
+                &pending.component,
+                Some(pending.version.clone()),
+                &Ok(outcome.clone()),
+                rec.run(),
+            );
 
             outcomes.push(outcome);
         }
@@ -2001,7 +2001,11 @@ impl Engine {
                     at: crate::journal::now_unix(),
                     component: crate::proto::ComponentId(name.clone()),
                     from: crumb.from.as_deref().and_then(|v| v.parse().ok()),
-                    to: crumb.to.as_deref().and_then(|v| v.parse().ok()),
+                    // A `RolledBack` entry's `to` names the version that *failed* — the one
+                    // the rescue moved off of — never the golden it landed on. `known_bad`
+                    // reads this field; naming golden here would blacklist the release the
+                    // board is successfully running. See `Engine::record`.
+                    to: crumb.from.as_deref().and_then(|v| v.parse().ok()),
                     outcome: crate::proto::Outcome::RolledBack { reason: because },
                     run: rec.run(),
                 };

updater/src/faults.rs

@@ -30,6 +30,11 @@ pub struct Faults {
     /// Make rollback itself fail, exercising the worst path: failed update *and*
     /// failed recovery, which must be reported loudly rather than silently.
     pub fail_rollback: bool,
+    /// Make the *forward* apply action fail — a unit that refuses to restart on the new
+    /// release. Only the forward direction: the revert's own apply action has
+    /// [`Self::fail_rollback_apply`]. `transition_to` once answered this failure with no
+    /// rollback and no log entry, leaving the board on an unverified release.
+    pub fail_apply_action: bool,
     /// Make the *apply action* fail while rolling back, with the swap succeeding.
     ///
     /// A different outcome from [`Self::fail_rollback`], and the distinction is the point: the
@@ -74,12 +79,13 @@ impl Faults {
                 "abort_after_swap" => faults.abort_after_swap = true,
                 "simulate_disk_full" => faults.simulate_disk_full = true,
                 "fail_rollback" => faults.fail_rollback = true,
+                "fail_apply_action" => faults.fail_apply_action = true,
                 "fail_rollback_apply" => faults.fail_rollback_apply = true,
                 other => {
                     return Err(crate::Error::Config(format!(
                         "unknown fault {other:?}; valid: corrupt_artifact, fail_post_hook, \
                          fail_health, hang_health, abort_after_swap, simulate_disk_full, \
-                         fail_rollback, fail_rollback_apply"
+                         fail_rollback, fail_apply_action, fail_rollback_apply"
                     )));
                 }
             }

updater/src/hooks.rs

@@ -174,7 +174,16 @@ pub async fn run(
 
     let mut text = String::from_utf8_lossy(&output.stdout).into_owned();
     text.push_str(&String::from_utf8_lossy(&output.stderr));
-    text.truncate(MAX_OUTPUT);
+    if text.len() > MAX_OUTPUT {
+        // Cut on a char boundary: `from_utf8_lossy` can place a multi-byte character (often a
+        // 3-byte U+FFFD for invalid input) straddling the cap, and a bare `truncate` panics on
+        // that — inside `Engine::apply`, where it kills the unattended-update task for good.
+        let mut end = MAX_OUTPUT;
+        while !text.is_char_boundary(end) {
+            end -= 1;
+        }
+        text.truncate(end);
+    }
 
     if !output.status.success() {
         return Err(Error::Hook {
@@ -379,6 +388,43 @@ mod tests {
         assert!(outcome.output.contains("migrated"));
     }
 
+    /// Hook output is capped at [`MAX_OUTPUT`], and the cap used to be a bare
+    /// `String::truncate` — which panics when the cut lands mid-character, easily reachable
+    /// because `from_utf8_lossy` pads invalid bytes into 3-byte U+FFFD runs. The panic
+    /// unwound through `Engine::apply`, killing the unattended-update task with no journal
+    /// entry. The cut must retreat to a char boundary instead.
+    #[tokio::test]
+    async fn oversized_output_is_cut_on_a_char_boundary() {
+        let dir = tempfile::tempdir().unwrap();
+        // 8191 ASCII bytes, then a two-byte `é` straddling byte 8192, then a failure so the
+        // output travels inside the error — the path the panic used to abort.
+        write_hook(
+            dir.path(),
+            HookKind::PostInstall,
+            "#!/bin/sh\nhead -c 8191 /dev/zero | tr '\\0' 'a'\nprintf 'é'\nexit 1\n",
+        );
+
+        let err = run(
+            dir.path(),
+            HookKind::PostInstall,
+            &ctx(),
+            Duration::from_secs(5),
+        )
+        .await
+        .expect_err("the hook failed; its output must come back as an error, not a panic");
+
+        let Error::Hook { detail, .. } = err else {
+            panic!("expected Error::Hook, got {err:?}");
+        };
+        let output = detail
+            .strip_prefix("exited with 1: ")
+            .expect("the exit status is reported with the output");
+        assert!(
+            output.trim().chars().all(|c| c == 'a'),
+            "the é straddling the cap must be cut away whole, not split: {output:?}"
+        );
+    }
+
     /// A non-zero exit is a failed update — the caller turns this into a rollback.
     #[tokio::test]
     async fn failing_hook_is_an_error_with_output() {

updater/tests/apply.rs

@@ -946,6 +946,19 @@ async fn crash_after_swap_is_reverted_when_the_robot_is_unhealthy() {
     assert_eq!(recovered.len(), 1, "should have reverted");
     assert_eq!(fx.live_version().as_deref(), Some("1.0.0"));
     assert_eq!(fx.live_marker().as_deref(), Some("version=1.0.0\n"));
+
+    // The revert must be journalled against the version that *failed*, so `known_bad`
+    // remembers 1.1.0 and leaves the release now running alone. An entry that named 1.0.0
+    // here blacklisted the good release and let 1.1.0 be retried forever.
+    let bad = engine.known_bad("daemon");
+    assert!(
+        bad.contains(&semver::Version::new(1, 1, 0)),
+        "the failed release is what a RolledBack entry must name: {bad:?}"
+    );
+    assert!(
+        !bad.contains(&semver::Version::new(1, 0, 0)),
+        "the release reverted TO must not be blacklisted: {bad:?}"
+    );
 }
 
 /// **A release the robot is healthy on must not be reverted for want of a confirmation.**
@@ -1571,6 +1584,64 @@ async fn failed_transition_leaves_no_armed_trial() {
     assert!(engine.recover_on_start().await.unwrap().is_empty());
 }
 
+/// **#9** A `select` whose apply action failed *after* the swap returned early: the board
+/// stayed on the unverified release, the trial was disarmed, and nothing was journalled —
+/// while `apply` rolls back on the identical failure. Reachable in production by a unit
+/// that refuses to restart (`systemd-test.sh` reproduces one), which is what
+/// `fail_apply_action` stands in for.
+#[tokio::test]
+async fn a_failed_apply_action_on_select_rolls_back_and_is_journalled() {
+    let fx = Fixture::new();
+    fx.publish("1.0.0", None);
+    fx.publish("1.1.0", None);
+    let keep = "keep_previous = 5";
+
+    let mut engine = fx.engine(Box::new(FakeRobot::healthy()), Faults::none(), keep);
+    apply_exact(&mut engine, "1.0.0").await.unwrap();
+    apply_exact(&mut engine, "1.1.0").await.unwrap();
+    assert_eq!(fx.live_version().as_deref(), Some("1.1.0"));
+
+    // Select 1.0.0 back, with the unit restart failing after the symlink has moved.
+    let mut faulty = fx.engine(
+        Box::new(FakeRobot::healthy()),
+        Faults {
+            fail_apply_action: true,
+            ..Faults::none()
+        },
+        keep,
+    );
+    let outcome = faulty
+        .select("daemon", &semver::Version::new(1, 0, 0))
+        .await
+        .unwrap();
+
+    assert!(
+        matches!(outcome, ApplyResult::RolledBack { .. }),
+        "a failed apply action past the swap is a rollback, as in `apply`: {outcome:?}"
+    );
+    assert_eq!(
+        fx.live_version().as_deref(),
+        Some("1.1.0"),
+        "back on the release the board started from"
+    );
+    assert!(
+        !fx.pending_file_exists(),
+        "the revert disarms the trial, or the next boot reverts the revert"
+    );
+
+    // Journalled against the version that failed — the select's *target* — so it is
+    // known-bad and the release still running is not.
+    let bad = faulty.known_bad("daemon");
+    assert!(
+        bad.contains(&semver::Version::new(1, 0, 0)),
+        "the select's target is what failed: {bad:?}"
+    );
+    assert!(
+        !bad.contains(&semver::Version::new(1, 1, 0)),
+        "the release reverted to must not be blacklisted: {bad:?}"
+    );
+}
+
 /// `scripts/robot-rescue` runs when `updaterd` does not, so it cannot ask this process which
 /// release is golden and must not parse `updater.toml` to find out — a release whose `updaterd`
 /// rejects that file is the likeliest thing it exists to rescue. Every start publishes the answer
@@ -1649,14 +1720,27 @@ async fn starting_up_records_a_rescue_and_releases_its_guard() {
         .expect("an entry in the update log");
     assert_eq!(entry.component.0, "daemon", "matched by install_dir");
     assert_eq!(entry.from, Some(semver::Version::new(1, 1, 0)));
-    assert_eq!(entry.to, Some(semver::Version::new(1, 0, 0)));
+    // A RolledBack entry's `to` names the version that *failed* — the one the rescue moved
+    // off of — never the golden it landed on. Naming golden here blacklists the release the
+    // board is successfully running, via `known_bad`.
+    assert_eq!(entry.to, Some(semver::Version::new(1, 1, 0)));
     match entry.outcome {
         updater::proto::Outcome::RolledBack { reason } => assert!(
             reason.contains("robotd.service"),
             "the reason the check gave has to survive into the log: {reason}"
         ),
         other => panic!("a rescue is a rollback, got {other:?}"),
     }
+
+    let bad = engine.known_bad("daemon");
+    assert!(
+        bad.contains(&semver::Version::new(1, 1, 0)),
+        "the release the rescue moved off of is the one that failed: {bad:?}"
+    );
+    assert!(
+        !bad.contains(&semver::Version::new(1, 0, 0)),
+        "golden is what the board now runs; blacklisting it would block the next rollback: {bad:?}"
+    );
 }
 
 /// A rescue outranks an armed trial, and the order inside `recover_on_start` is what enforces it.