Skip to main content

recall_server/store/
audit.rs

1//! The `audit_log` table: append-only storage for the Merkle tree in
2//! [`crate::audit::merkle`], and the one transactional primitive
3//! ([`Store::audited`]) every authenticated state change goes through so
4//! its leaf commits with it.
5//!
6//! Every method on [`Store`] the server uses to change a file, a device, an
7//! authkey, a passkey, a bootstrap code or a merge job's outcome takes the
8//! leaf it appends as an argument; none can change one without it. The
9//! writes left without a leaf are deliberate, and none changes a file, a
10//! credential or what a job came to: an enrolment waiting for approval
11//! (anyone may ask, and unauthenticated routes append nothing), a
12//! machine's poll for it, a device's `last_seen`, the sweep of
13//! long-expired enrolments, an admin session started by a sign-in, used,
14//! ended by a sign-out or swept once idle, a passkey's signature counter,
15//! the release of a revoked worker's leases before the server claims them
16//! itself ([`Store::release_open_jobs`]), and the pruning of finished jobs.
17//!
18//! Another process may append: `recall-server reset-passkeys` does, on the
19//! host, and so do `recall-server admin`'s renames, removes and restores
20//! (`store/admin.rs`). Every append first reads in any leaf the table holds
21//! past this store's tree, so they all write one log rather than a fork.
22
23use anyhow::{bail, Result};
24use rusqlite::{Connection, TransactionBehavior};
25
26use super::Store;
27use crate::audit::merkle::{self, Hash, Tree};
28
29/// Created alongside `memory_files` and the device tables, every time the
30/// store opens.
31///
32/// `leaf` and `leaf_hash` are both stored: `leaf` is the exact bytes a
33/// verifier hashes and exports, and `leaf_hash` is what the leaf hashed to
34/// when it was written, which [`load`] checks it still does.
35///
36/// The triggers are what makes this append-only in the database itself,
37/// not only by convention: even a bug — or a future migration reaching for
38/// `UPDATE` out of habit — cannot rewrite, remove or skip a leaf. The
39/// insert trigger is the one that stops `INSERT OR REPLACE`, whose
40/// replacing delete does not fire a delete trigger, and an insert that
41/// leaves a gap.
42///
43/// None of it stops someone holding the database file: they can drop a
44/// trigger, or rewrite the table and every hash in it consistently. That
45/// is what a checkpoint an owner saved elsewhere is for — a rewritten log
46/// no longer extends it.
47pub(super) const SCHEMA: &str = "
48    CREATE TABLE IF NOT EXISTS audit_log (
49        seq       INTEGER PRIMARY KEY,
50        leaf      BLOB NOT NULL,
51        leaf_hash BLOB NOT NULL
52    );
53    CREATE TRIGGER IF NOT EXISTS audit_log_no_update
54        BEFORE UPDATE ON audit_log
55    BEGIN
56        SELECT RAISE(ABORT, 'audit_log is append-only');
57    END;
58    CREATE TRIGGER IF NOT EXISTS audit_log_no_delete
59        BEFORE DELETE ON audit_log
60    BEGIN
61        SELECT RAISE(ABORT, 'audit_log is append-only');
62    END;
63    CREATE TRIGGER IF NOT EXISTS audit_log_next_seq
64        BEFORE INSERT ON audit_log
65        WHEN NEW.seq IS NOT (SELECT COALESCE(MAX(seq), -1) + 1 FROM audit_log)
66    BEGIN
67        SELECT RAISE(ABORT, 'audit_log is append-only: a leaf takes the next seq');
68    END;
69";
70
71/// What [`load`] read back.
72pub(super) struct Loaded {
73    /// Every leaf's hash, as a tree.
74    pub(super) tree: Tree,
75    /// The newest leaf's `at`, or empty for an empty log.
76    pub(super) last_at: String,
77}
78
79/// Reads every leaf back at open and rebuilds the tree from them, refusing
80/// a log that is not what this server wrote: a `seq` missing or out of
81/// place, or a leaf whose bytes no longer hash to its stored `leaf_hash`.
82/// The triggers keep both from happening through SQL; this is for the
83/// file changed some other way, by a disk or by hand.
84///
85/// The hashes are recomputed from the leaves rather than trusted, which
86/// is most of what opening costs: measured at 8.5 seconds for a million
87/// leaves (a gigabyte of them) on a small VM, against 1.8 seconds to read
88/// the stored hashes alone, and 64 bytes of memory a leaf for the tree
89/// kept after. A log that size is years of one owner's syncing; the check
90/// is worth its wait. A server that started anyway would sign every later
91/// checkpoint over a tree it had already lost, so it does not start; the
92/// error says to restore the database from a backup.
93pub(super) fn load(conn: &Connection) -> Result<Loaded> {
94    let mut tree = Tree::new();
95    read_from(conn, 0, |hash| tree.append(hash))?;
96    let last_at = last_at(conn, tree.size())?;
97    Ok(Loaded { tree, last_at })
98}
99
100/// Reads every leaf from `seq` `from` on, in order, checked as [`load`]
101/// describes, handing each one's hash to `each`. What both opening and
102/// [`Store::audited_each`]'s catching up do. Answers how many it read.
103fn read_from(conn: &Connection, from: u64, each: impl FnMut(Hash)) -> Result<u64> {
104    read_range(conn, from, i64::MAX as u64, each)
105}
106
107/// [`read_from`], stopping after `most` leaves.
108fn read_range(conn: &Connection, from: u64, most: u64, mut each: impl FnMut(Hash)) -> Result<u64> {
109    let mut stmt = conn.prepare(
110        "SELECT seq, leaf, leaf_hash FROM audit_log WHERE seq >= ?1 ORDER BY seq LIMIT ?2",
111    )?;
112    let mut rows = stmt.query((from as i64, most.min(i64::MAX as u64) as i64))?;
113    let mut want = from;
114    while let Some(row) = rows.next()? {
115        let seq: i64 = row.get(0)?;
116        if seq != want as i64 {
117            bail!(
118                "the audit log is damaged: leaf {want} is missing (the next one stored is {seq}); \
119                 restore the database from a backup"
120            );
121        }
122        let leaf = row.get_ref(1)?.as_blob()?;
123        let hash = merkle::hash_leaf(leaf);
124        if row.get_ref(2)?.as_blob()? != hash.as_slice() {
125            bail!(
126                "the audit log is damaged: leaf {seq} no longer hashes to its stored leaf_hash; \
127                 restore the database from a backup"
128            );
129        }
130        each(hash);
131        want += 1;
132    }
133    Ok(want - from)
134}
135
136/// The `at` of the newest of `size` leaves, or empty for none.
137fn last_at(conn: &Connection, size: u64) -> Result<String> {
138    if size == 0 {
139        return Ok(String::new());
140    }
141    let leaf: Vec<u8> = conn.query_row(
142        "SELECT leaf FROM audit_log WHERE seq = ?1",
143        (size as i64 - 1,),
144        |r| r.get(0),
145    )?;
146    // Every leaf `leaf::encode` wrote has one; one that somehow does not
147    // only means the next `at` is not held to it.
148    Ok(serde_json::from_slice::<serde_json::Value>(&leaf)
149        .ok()
150        .and_then(|v| v.get("at")?.as_str().map(str::to_string))
151        .unwrap_or_default())
152}
153
154/// The leaves the table holds past the `held` this store's tree has, for
155/// leaves another process appended since this one last looked:
156/// `recall-server reset-passkeys` or `recall-server admin`, run on the host
157/// beside a running server.
158/// Their hashes, checked as [`load`] checks them, and the newest one's
159/// `at`, for the tree to take once the transaction this runs in commits;
160/// its lock keeps anything else from appending until then.
161///
162/// A table that holds fewer leaves than `held` was rolled back under a
163/// running server, and nothing more is appended onto it until the server
164/// restarts and reads it afresh. A backup put in place of the file of a
165/// running server is mostly not seen here, since under WAL the server's
166/// connection goes by its WAL and its cache rather than the file. The
167/// check that the path still names the file it opened (`FileId` in the
168/// store), made before this, catches a file moved aside or replaced by a
169/// new one; one overwritten in place is caught by neither, which is why a
170/// restore stops the server first and never copies over `recall.db`
171/// (`deploy/README.md`).
172fn catch_up(conn: &Connection, held: u64) -> Result<(Vec<Hash>, Option<String>)> {
173    let stored: i64 =
174        conn.query_row("SELECT COALESCE(MAX(seq) + 1, 0) FROM audit_log", [], |r| {
175            r.get(0)
176        })?;
177    if stored < held as i64 {
178        bail!(
179            "the audit log holds {stored} leaves, fewer than the {held} this server appended: \
180             the database was replaced under a running server; restart it"
181        );
182    }
183    let mut hashes = Vec::new();
184    if stored == held as i64 {
185        return Ok((hashes, None));
186    }
187    let read = read_from(conn, held, |hash| hashes.push(hash))?;
188    Ok((hashes, Some(last_at(conn, held + read)?)))
189}
190
191/// What [`Store::audited`]'s write closure hands back.
192pub enum Outcome<T> {
193    /// The write happened; its leaf is appended in the same transaction.
194    Commit(T),
195    /// Nothing happened — a refused request, such as an unknown code or one
196    /// already decided. The transaction rolls back and no leaf is
197    /// appended, matching "unauthenticated routes and refused requests
198    /// append nothing" for the requests that do carry a credential but are
199    /// refused for another reason.
200    Refuse(T),
201}
202
203/// One stored leaf, as [`Store::audit_entries`] returns it: its position and
204/// its exact bytes.
205#[derive(Debug, Clone, PartialEq, Eq)]
206pub struct AuditEntry {
207    /// Its index in the tree, from 0.
208    pub seq: u64,
209    /// The leaf exactly as written — never re-serialized.
210    pub leaf: Vec<u8>,
211}
212
213/// Why a consistency proof could not be produced.
214#[derive(Debug, Clone, Copy, PartialEq, Eq, thiserror::Error)]
215pub enum ConsistencyError {
216    /// `first` is 0, or greater than `second`.
217    #[error("first must be at least 1 and at most second")]
218    BadRange,
219    /// `second` is past the tree's current size.
220    #[error("second is past the end of the log")]
221    SecondBeyondTreeSize,
222}
223
224/// The `at` the next leaf carries: now, or the newest leaf's `at` (the
225/// later of the two given) if the clock has gone back since — so `at` never
226/// decreases along `seq`. Read under the store's lock, like the `seq` it
227/// goes with. Being one fixed-width format, two of these compare as
228/// strings.
229fn next_at(one: &str, other: &str) -> String {
230    let newest = one.max(other);
231    let now = crate::now();
232    if now.as_str() < newest {
233        newest.to_string()
234    } else {
235        now
236    }
237}
238
239impl Store {
240    /// Runs `write` inside one transaction and, only if it commits,
241    /// appends the leaf `build_leaf` makes from the position that leaf
242    /// will hold (its `seq`), its `at`, and `write`'s own result — then,
243    /// and only then, the in-memory tree learns about it.
244    ///
245    /// `write` is given the same `at`, so a row it stamps and the leaf
246    /// that records it carry one time. Both are taken under the lock the
247    /// whole transaction holds, which is what makes `at` rise with `seq`.
248    ///
249    /// This and [`Store::audited_each`] are the only places a leaf is ever
250    /// appended, so "every authenticated state change appends its leaf, in
251    /// the same transaction as the change" is true by construction: nothing
252    /// calls `INSERT INTO audit_log` any other way, and a write that never
253    /// commits — because `write` returned [`Outcome::Refuse`] or an error —
254    /// leaves neither the state change nor a leaf behind.
255    pub fn audited<T>(
256        &self,
257        write: impl FnOnce(&rusqlite::Transaction, &str) -> Result<Outcome<T>>,
258        build_leaf: impl FnOnce(u64, &str, &T) -> Vec<u8>,
259    ) -> Result<T> {
260        self.audited_each(write, |seq, at, value| vec![build_leaf(seq, at, value)])
261    }
262
263    /// [`Store::audited`], for a write that records any number of changes
264    /// at once: `build_leaves` returns one leaf per change, the first
265    /// taking `seq` and each after it the next, all appended in `write`'s
266    /// transaction. The sweep is the one user: every device it removes has
267    /// a leaf, and they commit together with the removals.
268    pub fn audited_each<T>(
269        &self,
270        write: impl FnOnce(&rusqlite::Transaction, &str) -> Result<Outcome<T>>,
271        build_leaves: impl FnOnce(u64, &str, &T) -> Vec<Vec<u8>>,
272    ) -> Result<T> {
273        self.audited_each_as(
274            anyhow::Error::from,
275            anyhow::Error::from,
276            write,
277            build_leaves,
278        )
279    }
280
281    /// [`Store::audited_each`], with the error that starting the
282    /// transaction or committing it becomes chosen by the caller:
283    /// `recall-server admin` tells the owner which of the two it was, and
284    /// that the database stayed locked, since those are the failures they
285    /// can do something about (wait, and run it again).
286    pub(crate) fn audited_each_as<T>(
287        &self,
288        begin_failed: impl FnOnce(rusqlite::Error) -> anyhow::Error,
289        commit_failed: impl FnOnce(rusqlite::Error) -> anyhow::Error,
290        write: impl FnOnce(&rusqlite::Transaction, &str) -> Result<Outcome<T>>,
291        build_leaves: impl FnOnce(u64, &str, &T) -> Vec<Vec<u8>>,
292    ) -> Result<T> {
293        let mut state = self.lock();
294        // Before anything is written: is the path still the file this
295        // connection opened? See `FileId` in the store.
296        if let Some(opened) = state.file {
297            if super::file_id(&state.conn) != Some(opened) {
298                let why = format!(
299                    "the database file {} was moved or replaced under this running server, \
300                     which would otherwise go on writing into the file it had opened. Nothing \
301                     was written. Restart the server, so it opens the file that is there now",
302                    state.conn.path().unwrap_or("")
303                );
304                // Every write from here on is refused with this, as a 500
305                // the owner may never see; the server's log says it once.
306                if !std::mem::replace(&mut state.moved_said, true) && state.log_moved {
307                    eprintln!("{why}");
308                }
309                bail!(why);
310            }
311        }
312        let (held, held_at) = (state.audit.size(), state.audit_at.clone());
313        // `IMMEDIATE`: the database's write lock from the start, so another
314        // process (`reset-passkeys`, `admin`) cannot append between the
315        // catch-up below and this transaction's own leaves. The transaction
316        // borrows the whole state, so the tree cannot learn of anything
317        // until it commits.
318        let tx = state
319            .conn
320            .transaction_with_behavior(TransactionBehavior::Immediate)
321            .map_err(begin_failed)?;
322        let (caught, caught_at) = catch_up(&tx, held)?;
323        // The position the first leaf will hold if this commits: the size
324        // of the tree the table holds, read under the lock the transaction
325        // holds for its whole duration, so no other request or process can
326        // claim this seq first.
327        let seq = held + caught.len() as u64;
328        let at = next_at(caught_at.as_deref().unwrap_or(""), &held_at);
329        let value = match write(&tx, &at)? {
330            Outcome::Commit(value) => value,
331            Outcome::Refuse(value) => return Ok(value), // `tx` drops here: rolled back.
332        };
333        let leaves = build_leaves(seq, &at, &value);
334        let mut hashes = Vec::with_capacity(leaves.len());
335        for (i, leaf) in leaves.iter().enumerate() {
336            let leaf_hash = merkle::hash_leaf(leaf);
337            tx.execute(
338                "INSERT INTO audit_log (seq, leaf, leaf_hash) VALUES (?1, ?2, ?3)",
339                (seq as i64 + i as i64, leaf, leaf_hash.as_slice()),
340            )?;
341            hashes.push(leaf_hash);
342        }
343        tx.commit().map_err(commit_failed)?;
344        for leaf_hash in caught.into_iter().chain(hashes) {
345            state.audit.append(leaf_hash);
346        }
347        if !leaves.is_empty() {
348            state.audit_at = at;
349        } else if let Some(caught_at) = caught_at.filter(|c| *c > state.audit_at) {
350            state.audit_at = caught_at;
351        }
352        Ok(value)
353    }
354
355    /// Reads into the tree every leaf the table holds past it, outside any
356    /// write transaction and a few thousand leaves at a time, for a process
357    /// that opened the database without reading its log: `recall-server
358    /// admin`, about to append.
359    ///
360    /// Only to be quick about it. [`Store::audited_each`] catches up with
361    /// the table by itself, but it does so holding the write lock, which a
362    /// running server then waits on for no more than its busy timeout: 5
363    /// seconds, against 8.5 to read a million leaves. Read here first, the
364    /// catch-up under the lock is only the leaves appended since, and each
365    /// read here holds a read lock for a fraction of a second. The leaves
366    /// are checked as [`load`] checks them; the log is append-only, so what
367    /// this reads stays true.
368    pub(crate) fn audit_read_ahead(&self) -> Result<()> {
369        self.audit_read_ahead_by(4096)
370    }
371
372    /// [`Store::audit_read_ahead`], `chunk` leaves at a time.
373    fn audit_read_ahead_by(&self, chunk: u64) -> Result<()> {
374        let mut state = self.lock();
375        loop {
376            let held = state.audit.size();
377            let mut hashes = Vec::new();
378            let read = read_range(&state.conn, held, chunk, |hash| hashes.push(hash))?;
379            if read == 0 {
380                return Ok(());
381            }
382            let at = last_at(&state.conn, held + read)?;
383            for hash in hashes {
384                state.audit.append(hash);
385            }
386            if at > state.audit_at {
387                state.audit_at = at;
388            }
389        }
390    }
391
392    /// Appends a leaf with no other state to change: a pull, the server's
393    /// own `start`. Still one transaction (of one statement), so it shares
394    /// [`Store::audited`]'s all-or-nothing behaviour rather than being a
395    /// special case.
396    ///
397    /// Returns the leaf's `seq`, read out of the same closure `audited`
398    /// calls under its lock — not by asking the tree its size again
399    /// afterwards, which another append could have moved on by then.
400    pub fn audit_append(&self, build_leaf: impl FnOnce(u64, &str) -> Vec<u8>) -> Result<u64> {
401        let assigned = std::cell::Cell::new(0u64);
402        self.audited(
403            |_tx, _at| Ok(Outcome::Commit(())),
404            |seq, at, ()| {
405                assigned.set(seq);
406                build_leaf(seq, at)
407            },
408        )?;
409        Ok(assigned.get())
410    }
411
412    /// The tree's size and root, for `GET /v1/audit/checkpoint` and the
413    /// `Recall-Audit-Checkpoint` header every pull carries.
414    pub fn audit_checkpoint(&self) -> (u64, Hash) {
415        let state = self.lock();
416        (state.audit.size(), state.audit.root())
417    }
418
419    /// Leaves `start` to `end - 1`, stopping early once they come to more
420    /// than `max_bytes` together — though never before the first, however
421    /// large, so a caller paging on from the last `seq` it got always
422    /// moves. The caller (the route handler) is responsible for
423    /// `end <= tree_size` and the 1,000-row page limit.
424    pub fn audit_entries(&self, start: u64, end: u64, max_bytes: usize) -> Result<Vec<AuditEntry>> {
425        let state = self.lock();
426        let mut stmt = state
427            .conn
428            .prepare("SELECT seq, leaf FROM audit_log WHERE seq >= ?1 AND seq < ?2 ORDER BY seq")?;
429        let mut rows = stmt.query((start as i64, end as i64))?;
430        let (mut out, mut bytes) = (Vec::new(), 0usize);
431        while let Some(row) = rows.next()? {
432            let leaf: Vec<u8> = row.get(1)?;
433            bytes += leaf.len();
434            if bytes > max_bytes && !out.is_empty() {
435                break;
436            }
437            out.push(AuditEntry {
438                seq: row.get::<_, i64>(0)? as u64,
439                leaf,
440            });
441        }
442        Ok(out)
443    }
444
445    /// The RFC 9162 §2.1.4 proof that the tree at `second` extends the one
446    /// at `first`, from the tree in memory: a few hundred hashes at most,
447    /// and no read of the database, however long the log.
448    pub fn audit_consistency(
449        &self,
450        first: u64,
451        second: u64,
452    ) -> Result<Result<Vec<Hash>, ConsistencyError>> {
453        let state = self.lock();
454        if first == 0 || first > second {
455            return Ok(Err(ConsistencyError::BadRange));
456        }
457        if second > state.audit.size() {
458            return Ok(Err(ConsistencyError::SecondBeyondTreeSize));
459        }
460        Ok(Ok(state.audit.consistency(first, second)))
461    }
462}
463
464#[cfg(test)]
465mod tests {
466    use super::*;
467    use crate::audit::leaf;
468
469    fn store() -> Store {
470        Store::open_in_memory().unwrap()
471    }
472
473    fn push_leaf(seq: u64) -> Vec<u8> {
474        leaf::encode(
475            seq,
476            "2026-01-01T00:00:00.000Z",
477            leaf::action::PUSH,
478            &leaf::Actor::Operator,
479            leaf::subject_file(&leaf::FileChange {
480                project_key: "acme/app",
481                file_path: "a.md",
482                deleted: false,
483                stored_sha256: "abc",
484                base_sha256: None,
485                merged: false,
486                merge_job: None,
487            }),
488            None,
489        )
490    }
491
492    fn append(st: &Store) {
493        st.audited(
494            |_tx, _| Ok(Outcome::Commit(())),
495            |seq, _, ()| push_leaf(seq),
496        )
497        .unwrap();
498    }
499
500    const INSERT_FILE: &str = "INSERT INTO memory_files \
501         (project_key, file_path, content, source_env, updated_at) VALUES ('a','b','c','d','e')";
502
503    #[test]
504    fn a_committed_write_appends_exactly_one_leaf() {
505        let st = store();
506        st.audited(
507            |tx, _| {
508                tx.execute(INSERT_FILE, [])?;
509                Ok(Outcome::Commit(()))
510            },
511            |seq, _, ()| push_leaf(seq),
512        )
513        .unwrap();
514        let (size, _) = st.audit_checkpoint();
515        assert_eq!(size, 1);
516        assert_eq!(st.audit_entries(0, 1, usize::MAX).unwrap().len(), 1);
517    }
518
519    /// The atomicity the mutation table asks for: a write that returns an
520    /// error after already changing something rolls the whole transaction
521    /// back, leaf included.
522    #[test]
523    fn a_failing_write_appends_no_leaf_and_keeps_no_change() {
524        let st = store();
525        let result = st.audited(
526            |tx, _| {
527                tx.execute(INSERT_FILE, [])?;
528                Err(anyhow::Error::from(rusqlite::Error::ExecuteReturnedResults))
529            },
530            |seq, _, ()| push_leaf(seq),
531        );
532        assert!(result.is_err());
533        assert_eq!(
534            st.audit_checkpoint().0,
535            0,
536            "no leaf from a rolled-back write"
537        );
538        assert!(st.get("a", "b").unwrap().is_none(), "no row either");
539    }
540
541    /// And the other way round: a leaf that cannot be written takes the
542    /// change down with it. The leaf goes in inside the change's own
543    /// transaction, before it commits, so there is never a moment when the
544    /// change is stored and its leaf is not.
545    #[test]
546    fn a_leaf_that_cannot_be_written_undoes_the_change() {
547        let st = store();
548        st.with_raw(|c| {
549            c.execute_batch(
550                "CREATE TEMP TRIGGER no_leaves BEFORE INSERT ON audit_log
551                 BEGIN SELECT RAISE(ABORT, 'no leaves today'); END;",
552            )
553        })
554        .unwrap();
555        let result = st.audited(
556            |tx, _| {
557                tx.execute(INSERT_FILE, [])?;
558                Ok(Outcome::Commit(()))
559            },
560            |seq, _, ()| push_leaf(seq),
561        );
562        assert!(result.is_err(), "the leaf's insert failed");
563        assert!(
564            st.get("a", "b").unwrap().is_none(),
565            "so the row is not there"
566        );
567        assert_eq!(st.audit_checkpoint().0, 0);
568    }
569
570    /// A refused request — nothing wrong at the database level, just a
571    /// decision not to proceed — is the same all-or-nothing story: no leaf.
572    #[test]
573    fn a_refused_write_appends_no_leaf() {
574        let st = store();
575        let refusal: &str = st
576            .audited(
577                |_tx, _| Ok(Outcome::Refuse("no such code")),
578                |seq, _, _| push_leaf(seq),
579            )
580            .unwrap();
581        assert_eq!(refusal, "no such code");
582        assert_eq!(st.audit_checkpoint().0, 0);
583    }
584
585    /// Several leaves from one write take consecutive seqs, and commit or
586    /// roll back together.
587    #[test]
588    fn one_write_can_append_several_leaves_in_order() {
589        let st = store();
590        append(&st);
591        st.audited_each(
592            |_tx, _| Ok(Outcome::Commit(3u64)),
593            |seq, _, n| (seq..seq + n).map(push_leaf).collect(),
594        )
595        .unwrap();
596        let seqs: Vec<u64> = st
597            .audit_entries(0, 4, usize::MAX)
598            .unwrap()
599            .iter()
600            .map(|e| e.seq)
601            .collect();
602        assert_eq!(seqs, vec![0, 1, 2, 3]);
603        assert_eq!(
604            st.audit_entries(1, 2, usize::MAX).unwrap()[0].leaf,
605            push_leaf(1)
606        );
607    }
608
609    /// `at` is taken under the lock, and never goes back: a leaf written
610    /// after the clock has moved backwards carries the newest `at` already
611    /// in the log, not an earlier one.
612    #[test]
613    fn at_never_decreases_along_seq() {
614        let st = store();
615        let mut ats = Vec::new();
616        for _ in 0..3 {
617            st.audit_append(|seq, at| {
618                ats.push(at.to_string());
619                push_leaf(seq)
620            })
621            .unwrap();
622        }
623        assert!(ats.windows(2).all(|w| w[0] <= w[1]), "{ats:?}");
624        assert_eq!(ats[0].len(), 24, "the API's timestamp format");
625
626        // A newest leaf from the future: the clock went back after it.
627        st.lock().audit_at = "2999-01-01T00:00:00.000Z".into();
628        let mut got = String::new();
629        st.audit_append(|seq, at| {
630            got = at.to_string();
631            push_leaf(seq)
632        })
633        .unwrap();
634        assert_eq!(got, "2999-01-01T00:00:00.000Z");
635    }
636
637    #[test]
638    fn checkpoint_matches_the_merkle_root_of_every_leaf() {
639        let st = store();
640        for _ in 0..5 {
641            append(&st);
642        }
643        let (size, root) = st.audit_checkpoint();
644        assert_eq!(size, 5);
645        let leaves: Vec<Hash> = (0..5)
646            .map(push_leaf)
647            .map(|l| merkle::hash_leaf(&l))
648            .collect();
649        assert_eq!(root, merkle::root(&leaves));
650    }
651
652    #[test]
653    fn entries_pages_by_seq_and_by_bytes() {
654        let st = store();
655        for _ in 0..3 {
656            append(&st);
657        }
658        let got = st.audit_entries(1, 3, usize::MAX).unwrap();
659        assert_eq!(got.iter().map(|e| e.seq).collect::<Vec<_>>(), vec![1, 2]);
660        assert_eq!(got[0].leaf, push_leaf(1));
661
662        let one = push_leaf(0).len();
663        let seqs = |max| -> Vec<u64> {
664            st.audit_entries(0, 3, max)
665                .unwrap()
666                .iter()
667                .map(|e| e.seq)
668                .collect()
669        };
670        assert_eq!(seqs(2 * one), vec![0, 1], "two fit exactly");
671        assert_eq!(seqs(2 * one - 1), vec![0], "the second would overflow");
672        assert_eq!(seqs(1), vec![0], "never fewer than one");
673    }
674
675    #[test]
676    fn consistency_matches_merkle_and_rejects_bad_ranges() {
677        let st = store();
678        for _ in 0..8 {
679            append(&st);
680        }
681        let proof = st.audit_consistency(3, 8).unwrap().unwrap();
682        let leaves: Vec<Hash> = (0..8)
683            .map(push_leaf)
684            .map(|l| merkle::hash_leaf(&l))
685            .collect();
686        assert_eq!(proof, merkle::consistency(3, 8, &leaves));
687
688        assert_eq!(
689            st.audit_consistency(0, 8).unwrap(),
690            Err(ConsistencyError::BadRange)
691        );
692        assert_eq!(
693            st.audit_consistency(5, 3).unwrap(),
694            Err(ConsistencyError::BadRange)
695        );
696        assert_eq!(
697            st.audit_consistency(1, 100).unwrap(),
698            Err(ConsistencyError::SecondBeyondTreeSize)
699        );
700    }
701
702    /// A proof comes from the tree in memory: the table can be out of reach
703    /// entirely and it is still served, which is what keeps the store's one
704    /// lock from being held over a read of every leaf.
705    #[test]
706    fn a_proof_does_not_read_the_table() {
707        let st = store();
708        for _ in 0..40 {
709            append(&st);
710        }
711        let want = st.audit_consistency(7, 40).unwrap().unwrap();
712        st.with_raw(|c| c.execute_batch("ALTER TABLE audit_log RENAME TO audit_log_away"))
713            .unwrap();
714        assert_eq!(st.audit_consistency(7, 40).unwrap().unwrap(), want);
715    }
716
717    /// The triggers, not just application discipline: a raw `UPDATE`,
718    /// `DELETE`, upsert, `INSERT OR REPLACE` over a leaf, or an insert that
719    /// skips a seq, aborts.
720    #[test]
721    fn nothing_but_the_next_leaf_can_be_written() {
722        let st = store();
723        append(&st);
724        append(&st);
725
726        let refused = |sql: &str| {
727            assert!(st.with_raw(|c| c.execute(sql, [])).is_err(), "{sql}");
728        };
729        refused("UPDATE audit_log SET seq = 99 WHERE seq = 0");
730        refused("DELETE FROM audit_log WHERE seq = 0");
731        refused(
732            "INSERT OR REPLACE INTO audit_log (seq, leaf, leaf_hash) \
733             VALUES (0, CAST('forged' AS BLOB), zeroblob(32))",
734        );
735        refused(
736            "INSERT INTO audit_log (seq, leaf, leaf_hash) VALUES (0, x'01', zeroblob(32)) \
737             ON CONFLICT(seq) DO UPDATE SET leaf = excluded.leaf",
738        );
739        refused("INSERT INTO audit_log (seq, leaf, leaf_hash) VALUES (100, x'02', zeroblob(32))");
740        refused("INSERT INTO audit_log (leaf, leaf_hash) VALUES (x'02', zeroblob(32))");
741        assert_eq!(
742            st.audit_entries(0, 2, usize::MAX).unwrap()[0].leaf,
743            push_leaf(0),
744            "leaf 0 is what was written"
745        );
746        assert_eq!(st.audit_checkpoint().0, 2);
747
748        // The next seq is still accepted — the trigger stops only the rest.
749        st.with_raw(|c| {
750            c.execute(
751                "INSERT INTO audit_log (seq, leaf, leaf_hash) VALUES (2, x'03', zeroblob(32))",
752                [],
753            )
754        })
755        .unwrap();
756    }
757
758    /// The tree is rebuilt at open from what the file holds, so a reopened
759    /// store answers with the same checkpoint and goes on from the same seq.
760    #[test]
761    fn reopening_rebuilds_the_same_tree() {
762        let dir = tempfile::tempdir().unwrap();
763        let path = dir.path().join("r.db");
764        let before = {
765            let st = Store::open(&path).unwrap();
766            for _ in 0..5 {
767                append(&st);
768            }
769            st.audit_checkpoint()
770        };
771        let st = Store::open(&path).unwrap();
772        assert_eq!(st.audit_checkpoint(), before);
773        assert_eq!(st.audit_append(|seq, _| push_leaf(seq)).unwrap(), 5);
774    }
775
776    /// A leaf another process appends to the same file, as
777    /// `recall-server reset-passkeys` does beside a running server, is read
778    /// into this one's tree before its next append, which then takes the
779    /// seq after it; the two agree on the tree after. A log that went back
780    /// under a running store stops its appends rather than growing a fork.
781    #[test]
782    fn a_leaf_another_process_appended_is_read_in_before_the_next() {
783        let dir = tempfile::tempdir().unwrap();
784        let path = dir.path().join("r.db");
785        let server = Store::open(&path).unwrap();
786        append(&server);
787        append(&server);
788        let host = Store::open(&path).unwrap();
789        assert_eq!(host.audit_append(|seq, _| push_leaf(seq)).unwrap(), 2);
790        assert_eq!(server.audit_checkpoint().0, 2, "not read until it appends");
791        assert_eq!(server.audit_append(|seq, _| push_leaf(seq)).unwrap(), 3);
792        assert_eq!(
793            server.audit_checkpoint(),
794            Store::open(&path).unwrap().audit_checkpoint()
795        );
796
797        // A store that has never looked at the log reads all of it in first.
798        let blank = Store::with_connection(Connection::open(&path).unwrap()).unwrap();
799        blank.lock().audit = Tree::new();
800        assert_eq!(blank.audit_append(|seq, _| push_leaf(seq)).unwrap(), 4);
801
802        // The log gone back under the running store. Done through SQLite,
803        // not by copying an older file over this one: under WAL the store
804        // would not see a copy at all (its WAL and cache still describe the
805        // file it had) and would write on over it, which is why a restore
806        // stops the server and moves its WAL aside first.
807        Connection::open(&path)
808            .unwrap()
809            .execute_batch("DROP TRIGGER audit_log_no_delete; DELETE FROM audit_log WHERE seq >= 1")
810            .unwrap();
811        let err = server.audit_append(|seq, _| push_leaf(seq)).unwrap_err();
812        assert!(format!("{err:#}").contains("restart it"), "{err:#}");
813    }
814
815    /// Reading ahead, a chunk at a time, leaves the tree where the catch-up
816    /// under the write lock would: the same checkpoint, the same next seq,
817    /// and the newest `at` to hold the next one to. A damaged leaf is
818    /// refused here as at open.
819    #[test]
820    fn reading_ahead_builds_the_tree_catching_up_would() {
821        let dir = tempfile::tempdir().unwrap();
822        let path = dir.path().join("r.db");
823        let server = Store::open(&path).unwrap();
824        for _ in 0..5 {
825            append(&server);
826        }
827        let host = Store::with_connection(Connection::open(&path).unwrap()).unwrap();
828        host.lock().audit = Tree::new();
829        host.lock().audit_at = String::new();
830        host.audit_read_ahead_by(2).unwrap();
831        assert_eq!(host.audit_checkpoint(), server.audit_checkpoint());
832        assert_eq!(host.lock().audit_at, "2026-01-01T00:00:00.000Z");
833        append(&server);
834        host.audit_read_ahead_by(2).unwrap();
835        assert_eq!(host.audit_checkpoint(), server.audit_checkpoint());
836        assert_eq!(host.audit_append(|seq, _| push_leaf(seq)).unwrap(), 6);
837        assert_eq!(server.audit_append(|seq, _| push_leaf(seq)).unwrap(), 7);
838        assert_eq!(host.audit_append(|seq, _| push_leaf(seq)).unwrap(), 8);
839
840        let conn = Connection::open(&path).unwrap();
841        conn.execute_batch(
842            "DROP TRIGGER audit_log_no_update;
843             UPDATE audit_log SET leaf = CAST('forged' AS BLOB) WHERE seq = 3",
844        )
845        .unwrap();
846        let blank =
847            Store::with_connection(Connection::open(dir.path().join("x.db")).unwrap()).unwrap();
848        blank.lock().conn = Connection::open(&path).unwrap();
849        let err = blank.audit_read_ahead_by(2).unwrap_err();
850        assert!(
851            format!("{err:#}").contains("leaf 3 no longer hashes"),
852            "{err:#}"
853        );
854    }
855
856    /// Opening refuses a log changed behind the triggers' back: a leaf
857    /// rewritten without its hash, one rewritten with it but the hash row
858    /// left, or a gap.
859    #[test]
860    fn opening_refuses_a_damaged_log() {
861        let damaged = |how: &str| -> String {
862            let dir = tempfile::tempdir().unwrap();
863            let path = dir.path().join("r.db");
864            {
865                let st = Store::open(&path).unwrap();
866                for _ in 0..4 {
867                    append(&st);
868                }
869            }
870            let conn = Connection::open(&path).unwrap();
871            conn.execute_batch(&format!(
872                "DROP TRIGGER audit_log_no_update; DROP TRIGGER audit_log_no_delete; {how}"
873            ))
874            .unwrap();
875            drop(conn);
876            match Store::open(&path) {
877                Ok(_) => panic!("opened a log damaged by {how}"),
878                Err(e) => format!("{e:#}"),
879            }
880        };
881        let e = damaged("UPDATE audit_log SET leaf = CAST('forged' AS BLOB) WHERE seq = 1");
882        assert!(e.contains("leaf 1 no longer hashes"), "{e}");
883        let e = damaged("DELETE FROM audit_log WHERE seq = 2");
884        assert!(e.contains("leaf 2 is missing"), "{e}");
885        let e = damaged("UPDATE audit_log SET leaf_hash = zeroblob(32) WHERE seq = 3");
886        assert!(e.contains("leaf 3 no longer hashes"), "{e}");
887    }
888}