feat: enrich patch install failure messages with diagnostics (#346)

* feat: enrich patch install failure messages with diagnostics

The `message` field in `__patch_install_failure__` events previously
contained generic strings that didn't help distinguish failure causes.

Crash recovery messages now include:
- `elapsed_secs`: time between boot start and crash recovery detection,
  helping distinguish immediate crashes (likely OOM) from delayed kills
  (user force-stop, OS reclaim hours later)
- `file_ok`/`file_size`: whether the patch file is intact at recovery
  time, catching corruption or partial writes

Message format changes:
- Crash recovery: "crash_recovery: patch N failed to boot
  (elapsed_secs=S,file_ok=bool,file_size=N)"
- Engine failure: "engine_report: patch N failed to launch"

Also adds `boot_started_at` timestamp to PatchesState (backward
compatible — older state files deserialize it as None).

* chore: fix formatting

* test: add coverage for crash recovery edge cases

- crash_recovery_with_missing_file: patch artifact deleted before
  recovery, verifies file_ok=false,file_missing in message
- crash_recovery_without_boot_timestamp: old state file without
  boot_started_at field, verifies elapsed_secs=unknown in message

* refactor: simplify file check in crash recovery diagnostics

Remove unreachable branch: Path::exists() calls fs::metadata()
internally, so if metadata fails, exists() returns false. The
separate file_unreadable case could never be reached.

* refactor: use raw timestamps instead of elapsed_secs in crash recovery

elapsed_secs was misleading because it included the time between the
crash and the user reopening the app — not just the boot duration.

Now reports boot_started_at (raw Unix timestamp) and detected_at (when
crash recovery ran). Server-side analysis can compute elapsed time and
cross-reference with successful boot durations from other devices.

Example: "crash_recovery: patch 1 failed to boot
(detected_at=1776900000,boot_started_at=1776899990,file_ok=true,file_size=524288)"

library/src/cache/patch_manager.rs

@@ -51,6 +51,11 @@ struct PatchesState {
     ///  - the system initializes (on_init, we take this to mean the patch failed to boot)
     currently_booting_patch: Option<PatchMetadata>,
 
+    /// Unix timestamp (seconds) when the current boot attempt started.
+    /// Used to compute elapsed time in crash recovery diagnostics.
+    /// Added in 1.6.93; older state files will deserialize this as None.
+    boot_started_at: Option<u64>,
+
     /// A list of patch numbers that we have tried and failed to install.
     /// We should never attempt to download or install these again for the
     /// current release.
@@ -89,6 +94,9 @@ pub trait ManagePatches {
     ///      the system crashed).
     fn currently_booting_patch(&self) -> Option<PatchInfo>;
 
+    /// Unix timestamp (seconds) when the current boot attempt started, if known.
+    fn boot_started_at(&self) -> Option<u64>;
+
     /// Returns the next patch to boot, or None if:
     /// - no patches have been downloaded
     /// - we cannot boot from the patch(es) on disk
@@ -444,6 +452,10 @@ impl ManagePatches for PatchManager {
             .map(|patch| self.patch_info_for_number(patch.number))
     }
 
+    fn boot_started_at(&self) -> Option<u64> {
+        self.patches_state.boot_started_at
+    }
+
     fn validate_next_boot_patch(&mut self) -> anyhow::Result<()> {
         let next_boot_patch = match self.patches_state.next_boot_patch.clone() {
             Some(patch) => patch,
@@ -492,6 +504,7 @@ impl ManagePatches for PatchManager {
         }
 
         self.patches_state.currently_booting_patch = Some(next_boot_patch.clone());
+        self.patches_state.boot_started_at = Some(crate::time::unix_timestamp());
         self.save_patches_state()
     }
 
@@ -503,6 +516,7 @@ impl ManagePatches for PatchManager {
             .context("No currently_booting_patch")?;
 
         self.patches_state.currently_booting_patch = None;
+        self.patches_state.boot_started_at = None;
         self.patches_state.last_booted_patch = Some(boot_patch.clone());
         if let Err(e) = self.delete_patch_artifacts_older_than(boot_patch.number) {
             shorebird_error!(
@@ -516,6 +530,7 @@ impl ManagePatches for PatchManager {
 
     fn record_boot_failure_for_patch(&mut self, patch_number: usize) -> Result<()> {
         self.patches_state.currently_booting_patch = None;
+        self.patches_state.boot_started_at = None;
         self.patches_state.known_bad_patches.insert(patch_number);
         self.try_fall_back_from_patch(patch_number)
     }
@@ -597,7 +612,7 @@ mod debug_tests {
             PatchVerificationMode::default(),
         );
         let actual = format!("{:?}", patch_manager);
-        assert!(actual.contains(r#"patches_state: PatchesState { last_booted_patch: None, next_boot_patch: None, currently_booting_patch: None, known_bad_patches: {} }, patch_public_key: Some("public_key")"#));
+        assert!(actual.contains(r#"patches_state: PatchesState { last_booted_patch: None, next_boot_patch: None, currently_booting_patch: None, boot_started_at: None, known_bad_patches: {} }, patch_public_key: Some("public_key")"#));
     }
 }
 

library/src/cache/updater_state.rs

@@ -219,6 +219,11 @@ impl UpdaterState {
         self.patch_manager.currently_booting_patch()
     }
 
+    /// Unix timestamp (seconds) when the current boot attempt started, if known.
+    pub fn boot_started_at(&self) -> Option<u64> {
+        self.patch_manager.boot_started_at()
+    }
+
     /// The last patch that was successfully booted (e.g., for which we record_boot_success was
     /// called).
     /// Will be None if:

library/src/updater.rs

@@ -224,19 +224,29 @@ pub fn handle_prior_boot_failure_if_necessary() -> Result<(), InitError> {
             config.patch_verification,
         );
         if let Some(patch) = state.currently_booting_patch() {
+            let boot_time_info = match state.boot_started_at() {
+                Some(ts) => format!("boot_started_at={ts}"),
+                None => "boot_started_at=unknown".to_string(),
+            };
+
+            let file_info = match std::fs::metadata(&patch.path) {
+                Ok(meta) => format!("file_ok=true,file_size={}", meta.len()),
+                Err(_) => "file_ok=false,file_missing".to_string(),
+            };
+
+            let now = crate::time::unix_timestamp();
+            let message = format!(
+                "crash_recovery: patch {} failed to boot (detected_at={now},{boot_time_info},{file_info})",
+                patch.number
+            );
+
             state.record_boot_failure_for_patch(patch.number)?;
             state.queue_event(PatchEvent::new(
                 config,
                 EventType::PatchInstallFailure,
                 patch.number,
                 state.client_id(),
-                Some(
-                    format!(
-                        "Patch {} was marked currently_booting in init",
-                        patch.number
-                    )
-                    .as_ref(),
-                ),
+                Some(&message),
             ))?;
         }
 
@@ -838,18 +848,13 @@ pub fn report_launch_failure() -> anyhow::Result<()> {
             shorebird_error!("Failed to mark patch as bad: {:?}", mark_result);
         }
         let client_id = state.client_id();
+        let message = format!("engine_report: patch {} failed to launch", patch.number);
         let event = PatchEvent::new(
             config,
             EventType::PatchInstallFailure,
             patch.number,
             client_id,
-            Some(
-                format!(
-                    "Install failure reported from engine for patch {}",
-                    patch.number
-                )
-                .as_ref(),
-            ),
+            Some(&message),
         );
         // Queue the failure event for later sending since right after this
         // function returns the Flutter engine is likely to abort().
@@ -1692,7 +1697,7 @@ patch_verification: bogus_mode
                 platform: current_platform().to_string(),
                 release_version: config.release_version.clone(),
                 timestamp: time::unix_timestamp(),
-                message: Some("Install failure reported from engine for patch 1".to_string()),
+                message: Some("engine_report: patch 1 failed to launch".to_string()),
             };
             // Queue 5 events.
             assert!(state.queue_event(fail_event.clone()).is_ok());
@@ -2913,6 +2918,94 @@ mod state_recovery_tests {
                 crate::events::EventType::PatchInstallFailure
             );
             assert_eq!(events[0].patch_number, 1);
+            let message = events[0].message.as_ref().unwrap();
+            assert!(
+                message.starts_with("crash_recovery: patch 1 failed to boot"),
+                "unexpected message: {message}"
+            );
+            assert!(
+                message.contains("detected_at="),
+                "message should include detection time: {message}"
+            );
+            assert!(
+                message.contains("boot_started_at="),
+                "message should include boot start time: {message}"
+            );
+            assert!(
+                message.contains("file_ok="),
+                "message should include file status: {message}"
+            );
+            Ok(())
+        })?;
+
+        Ok(())
+    }
+
+    /// Crash recovery when the patch file was deleted before recovery runs.
+    /// The message should report file_ok=false,file_missing.
+    #[serial]
+    #[test]
+    fn crash_recovery_with_missing_file() -> Result<()> {
+        let tmp_dir = TempDir::new().unwrap();
+        init_for_testing(&tmp_dir, None);
+
+        install_fake_patch(1)?;
+        report_launch_start()?;
+
+        // Delete the patch artifact to simulate file going missing.
+        let patches_dir = tmp_dir.path().join("patches");
+        std::fs::remove_dir_all(&patches_dir)?;
+
+        // Reinitialize — triggers crash recovery.
+        init_for_testing(&tmp_dir, None);
+
+        with_state(|state| {
+            let events = state.copy_events(10);
+            assert_eq!(events.len(), 1);
+            let message = events[0].message.as_ref().unwrap();
+            assert!(
+                message.contains("file_ok=false,file_missing"),
+                "expected file_missing in message: {message}"
+            );
+            Ok(())
+        })?;
+
+        Ok(())
+    }
+
+    /// Crash recovery when boot_started_at is not set (old state file format).
+    /// The message should report elapsed_secs=unknown.
+    #[serial]
+    #[test]
+    fn crash_recovery_without_boot_timestamp() -> Result<()> {
+        let tmp_dir = TempDir::new().unwrap();
+        init_for_testing(&tmp_dir, None);
+
+        install_fake_patch(1)?;
+        report_launch_start()?;
+
+        // Manually clear boot_started_at from the state file to simulate
+        // an old state format that doesn't have this field.
+        let state_path = tmp_dir.path().join("patches_state.json");
+        let state_json = std::fs::read_to_string(&state_path)?;
+        let mut state_value: serde_json::Value = serde_json::from_str(&state_json)?;
+        state_value
+            .as_object_mut()
+            .unwrap()
+            .remove("boot_started_at");
+        std::fs::write(&state_path, serde_json::to_string(&state_value)?)?;
+
+        // Reinitialize — triggers crash recovery.
+        init_for_testing(&tmp_dir, None);
+
+        with_state(|state| {
+            let events = state.copy_events(10);
+            assert_eq!(events.len(), 1);
+            let message = events[0].message.as_ref().unwrap();
+            assert!(
+                message.contains("boot_started_at=unknown"),
+                "expected boot_started_at=unknown in message: {message}"
+            );
             Ok(())
         })?;