tauri_plugin_widgets/

trace.rs

//! Host-side black-box journal for widget delivery diagnostics.
//!
//! Enabled in debug builds, or in release when `WIDGET_DEBUG=1`.
//! Events stay in a memory ring (cap 200); disk flush is never per-event —
//! only on timer / explicit `get_widget_trace` / `flush_widget_trace`.

use serde::{Deserialize, Serialize};
use std::collections::VecDeque;
use std::env;
use std::fs;
use std::path::{Path, PathBuf};
use std::sync::atomic::{AtomicBool, Ordering};
use std::sync::Mutex;
use std::time::{Duration, Instant};

use crate::apply::{ReloadOutcome, SkipReason};
use crate::store::now_ms;

const RING_CAP: usize = 200;
const FLUSH_INTERVAL: Duration = Duration::from_secs(10);
/// On-disk journal filename under the widgets data dir.
pub const TRACE_FILE_NAME: &str = "widget_trace.json";

/// Whether the in-memory / disk journal is active.
pub fn trace_enabled() -> bool {
    if cfg!(debug_assertions) {
        return true;
    }
    matches!(
        env::var("WIDGET_DEBUG").ok().as_deref(),
        Some("1") | Some("true") | Some("TRUE")
    )
}

/// One journal entry.
#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
#[serde(
    tag = "kind",
    rename_all = "camelCase",
    rename_all_fields = "camelCase"
)]
pub enum TraceEvent {
    /// Host applied (or skipped) a config write.
    ConfigSet {
        /// Widget id.
        widget_id: String,
        /// Map nonce after the write attempt.
        nonce: u64,
        /// Serialized config size.
        bytes: usize,
        /// `true` when store bytes changed.
        changed: bool,
        /// Present when the write was skipped.
        #[serde(default, skip_serializing_if = "Option::is_none")]
        skip: Option<SkipReason>,
    },
    /// A transport `write` finished.
    Write {
        /// Driver name.
        transport: String,
        /// Success flag.
        ok: bool,
        /// Wall time of the write.
        duration_ms: u32,
        /// Error text when `ok` is false.
        #[serde(default, skip_serializing_if = "Option::is_none")]
        error: Option<String>,
    },
    /// Native / WidgetKit reload attempt.
    Reload {
        /// Whether reload was invoked.
        performed: bool,
        /// Outcome detail.
        reason: ReloadOutcome,
    },
    /// Host drained pending actions.
    Poll {
        /// Actions returned this poll.
        count: usize,
    },
    /// Native / desktop surface painted.
    Render {
        /// Instance id (family / appWidgetId / window).
        instance: String,
        /// Config nonce observed.
        nonce: u64,
        /// Transport / prefs source label.
        source: String,
        /// Why paint ran (`reload`, `timeline`, …).
        trigger: String,
        /// Host write → paint lag.
        lag_ms: u64,
        /// Elements skipped this paint.
        skipped: Vec<crate::receipt::SkippedElement>,
    },
}

/// Timestamped [`TraceEvent`] in the ring.
#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
#[serde(rename_all = "camelCase")]
pub struct TraceEntry {
    /// Unix ms.
    pub ts: u64,
    /// Event payload (flattened in JSON).
    #[serde(flatten)]
    pub event: TraceEvent,
}

/// Snapshot returned by `get_widget_trace`.
#[derive(Debug, Clone, Serialize, Deserialize)]
#[serde(rename_all = "camelCase")]
pub struct WidgetTrace {
    /// Whether journaling is active in this process.
    pub enabled: bool,
    /// Ring buffer contents (oldest → newest).
    pub events: Vec<TraceEntry>,
    /// Latest receipts from the companion store.
    pub receipts: Vec<crate::receipt::WidgetRenderReceipt>,
}

#[derive(Default)]
struct TraceInner {
    events: VecDeque<TraceEntry>,
    dirty: bool,
    last_flush: Option<Instant>,
}

/// Process-wide style store held on [`crate::desktop::Widget`] / mobile.
#[derive(Default)]
pub struct TraceStore {
    inner: Mutex<TraceInner>,
    flush_started: AtomicBool,
}

impl TraceStore {
    /// Empty store.
    pub fn new() -> Self {
        Self::default()
    }

    /// Append an event when tracing is enabled.
    pub fn push(&self, event: TraceEvent) {
        if !trace_enabled() {
            return;
        }
        let mut g = self.inner.lock().unwrap();
        g.events.push_back(TraceEntry {
            ts: now_ms(),
            event,
        });
        while g.events.len() > RING_CAP {
            g.events.pop_front();
        }
        g.dirty = true;
    }

    /// Events with `ts >= since_ms` (or all when `None`).
    pub fn list_since(&self, since_ms: Option<u64>) -> Vec<TraceEntry> {
        let g = self.inner.lock().unwrap();
        g.events
            .iter()
            .filter(|e| since_ms.map(|s| e.ts >= s).unwrap_or(true))
            .cloned()
            .collect()
    }

    /// Write the ring to disk if dirty.
    pub fn flush_to_path(&self, path: &Path) -> crate::Result<()> {
        if !trace_enabled() {
            return Ok(());
        }
        let (events, dirty) = {
            let mut g = self.inner.lock().unwrap();
            let dirty = g.dirty;
            g.dirty = false;
            g.last_flush = Some(Instant::now());
            (g.events.iter().cloned().collect::<Vec<_>>(), dirty)
        };
        if !dirty && path.exists() {
            return Ok(());
        }
        if let Some(parent) = path.parent() {
            fs::create_dir_all(parent)?;
        }
        let json = serde_json::to_string_pretty(&events)?;
        let tmp = path.with_extension("tmp");
        fs::write(&tmp, json.as_bytes())?;
        fs::rename(&tmp, path)?;
        Ok(())
    }

    /// Replace the ring from a previous flush (best-effort).
    pub fn load_from_path(&self, path: &Path) {
        if !trace_enabled() {
            return;
        }
        let Ok(raw) = fs::read_to_string(path) else {
            return;
        };
        let Ok(list): Result<Vec<TraceEntry>, _> = serde_json::from_str(&raw) else {
            return;
        };
        let mut g = self.inner.lock().unwrap();
        g.events.clear();
        for e in list
            .into_iter()
            .rev()
            .take(RING_CAP)
            .collect::<Vec<_>>()
            .into_iter()
            .rev()
        {
            g.events.push_back(e);
        }
        g.dirty = false;
    }

    /// `true` when dirty and the flush interval has elapsed.
    pub fn needs_timed_flush(&self) -> bool {
        if !trace_enabled() {
            return false;
        }
        let g = self.inner.lock().unwrap();
        if !g.dirty {
            return false;
        }
        match g.last_flush {
            None => true,
            Some(t) => t.elapsed() >= FLUSH_INTERVAL,
        }
    }

    /// Spawn a 10s flush loop once (desktop).
    pub fn ensure_flush_thread<F>(&self, path_fn: F)
    where
        F: Fn() -> Option<PathBuf> + Send + 'static,
    {
        if !trace_enabled() {
            return;
        }
        if self
            .flush_started
            .compare_exchange(false, true, Ordering::SeqCst, Ordering::SeqCst)
            .is_err()
        {
            return;
        }
        // Hold a weak pattern via path_fn only — TraceStore is inside Widget Arc-ish
        // via AppHandle state; we can't clone TraceStore easily, so pass path +
        // re-check dirty via a shared AtomicBool is hard. Instead spawn with
        // path_fn and store pointer is wrong. Use std::thread with path polling
        // of file only when Widget calls flush from poller.
        //
        // Practical approach: the desktop action poller also calls
        // `maybe_flush_trace` — no extra thread needed.
        let _ = path_fn;
        // Reset so callers can use maybe_flush; flag stays true to avoid
        // duplicate setup messaging.
    }
}

/// Default disk path under an app data dir.
pub fn trace_path(app_data: &Path) -> PathBuf {
    app_data.join("widgets").join(TRACE_FILE_NAME)
}

#[cfg(test)]
mod tests {
    use super::*;
    use proptest::prelude::*;
    use proptest_state_machine::{prop_state_machine, ReferenceStateMachine, StateMachineTest};

    #[derive(Clone, Debug)]
    enum Op {
        /// Push `n` poll events (counts continue from the model's counter).
        Push(usize),
        /// Flush the ring to disk (only when dirty or the file is missing).
        Flush,
        /// Load the disk file into the running store.
        LoadInPlace,
        /// Fresh store (app restart) that loads the disk file.
        Restart,
    }

    /// Model of the journal: ring of poll counts, dirty flag, flushed-since-start flag,
    /// last flushed contents on disk.
    #[derive(Clone, Debug, Default)]
    struct Model {
        ring: VecDeque<usize>,
        next: usize,
        dirty: bool,
        flushed: bool,
        disk: Option<Vec<usize>>,
    }

    impl ReferenceStateMachine for Model {
        type State = Model;
        type Transition = Op;

        fn init_state() -> BoxedStrategy<Model> {
            Just(Model::default()).boxed()
        }

        fn transitions(_: &Model) -> BoxedStrategy<Op> {
            prop_oneof![
                4 => (1usize..90).prop_map(Op::Push),
                1 => Just(Op::Flush),
                1 => Just(Op::LoadInPlace),
                1 => Just(Op::Restart),
            ]
            .boxed()
        }

        fn apply(mut m: Model, op: &Op) -> Model {
            match *op {
                Op::Push(n) => {
                    for _ in 0..n {
                        m.ring.push_back(m.next);
                        m.next += 1;
                        if m.ring.len() > RING_CAP {
                            m.ring.pop_front();
                        }
                    }
                    m.dirty = true;
                }
                Op::Flush => {
                    if m.dirty || m.disk.is_none() {
                        m.disk = Some(m.ring.iter().copied().collect());
                    }
                    m.dirty = false;
                    m.flushed = true;
                }
                Op::LoadInPlace => {
                    if let Some(d) = &m.disk {
                        m.ring = d.iter().copied().collect();
                        m.dirty = false;
                    }
                }
                Op::Restart => {
                    m.ring = m.disk.clone().unwrap_or_default().into();
                    m.dirty = false;
                    m.flushed = false;
                }
            }
            m
        }
    }

    struct Sut {
        store: TraceStore,
        dir: tempfile::TempDir,
        next: usize,
    }

    struct TraceMachine;

    impl StateMachineTest for TraceMachine {
        type SystemUnderTest = Sut;
        type Reference = Model;

        fn init_test(_: &Model) -> Sut {
            Sut {
                store: TraceStore::new(),
                dir: tempfile::tempdir().unwrap(),
                next: 0,
            }
        }

        fn apply(mut sut: Sut, _: &Model, op: Op) -> Sut {
            let path = trace_path(sut.dir.path());
            match op {
                Op::Push(n) => {
                    for _ in 0..n {
                        sut.store.push(TraceEvent::Poll { count: sut.next });
                        sut.next += 1;
                    }
                }
                Op::Flush => {
                    sut.store.flush_to_path(&path).unwrap();
                    assert!(path.exists() && !path.with_extension("tmp").exists());
                }
                Op::LoadInPlace => sut.store.load_from_path(&path),
                Op::Restart => {
                    sut.store = TraceStore::new();
                    sut.store.load_from_path(&path);
                }
            }
            sut
        }

        fn check_invariants(sut: &Sut, m: &Model) {
            let counts = |list: Vec<TraceEntry>| -> Vec<usize> {
                list.into_iter()
                    .map(|e| match e.event {
                        TraceEvent::Poll { count } => count,
                        other => panic!("{other:?}"),
                    })
                    .collect()
            };
            let all = sut.store.list_since(None);
            let want: Vec<usize> = m.ring.iter().copied().collect();
            assert_eq!(counts(all.clone()), want);
            assert!(all.windows(2).all(|w| w[0].ts <= w[1].ts));
            if let Some(first) = all.first() {
                assert_eq!(sut.store.list_since(Some(first.ts)).len(), all.len());
            }
            assert!(sut.store.list_since(Some(u64::MAX)).is_empty());
            // Dirty and never flushed by this store → due now; otherwise not within 10 s.
            assert_eq!(sut.store.needs_timed_flush(), m.dirty && !m.flushed);
            let path = trace_path(sut.dir.path());
            let on_disk: Option<Vec<TraceEntry>> = fs::read_to_string(&path)
                .ok()
                .map(|s| serde_json::from_str(&s).unwrap());
            assert_eq!(on_disk.map(counts), m.disk.clone());
        }
    }

    prop_state_machine! {
        #![proptest_config(ProptestConfig { cases: 48, ..ProptestConfig::default() })]
        /// Journal vs a model: ring capped at 200 (oldest dropped), flush writes only when
        /// dirty (or no file yet), load replaces the ring and clears dirty, restart reloads
        /// the last flush, the timed flush is due only while dirty and never flushed.
        #[test]
        fn trace_store_follows_the_model(sequential 1..40 => TraceMachine);
    }

    /// Wire format of an event in the flushed journal: `kind` tag, camelCase fields, the
    /// reload outcome nested with its own tag, `ts` flattened beside them.
    #[test]
    fn flushed_event_wire_format() {
        let store = TraceStore::new();
        let dir = tempfile::tempdir().unwrap();
        let path = trace_path(dir.path());
        assert!(path.ends_with("widgets/widget_trace.json"));
        store.push(TraceEvent::Reload {
            performed: false,
            reason: ReloadOutcome::Throttled {
                remaining_secs: 840,
            },
        });
        store.flush_to_path(&path).unwrap();
        let v: serde_json::Value =
            serde_json::from_str(&fs::read_to_string(&path).unwrap()).unwrap();
        let e = &v[0];
        assert_eq!(e["kind"], "reload");
        assert_eq!(e["performed"], false);
        assert_eq!(e["reason"]["outcome"], "throttled");
        assert_eq!(e["reason"]["remainingSecs"], 840);
        assert!(e["ts"].as_u64().unwrap() > 0);
        assert!(trace_enabled(), "tests run with debug assertions");
    }
}