test(stats): add page-miss benches for the dashboard and the query log

ARCHITECTURE.md

@@ -262,7 +262,7 @@ Indexes are not free here. On that same 103 MiB database `dbstat` attributes 20
 
 ### Measuring these queries
 
-Index work here is measured in **page misses** — `SQLITE_DBSTATUS_CACHE_MISS`, the 4 KiB database pages SQLite has to fetch from the file — and not in milliseconds. Development happens on an SSD and the appliance runs off an SD card, where the same page count costs orders of magnitude more; a query that reads the whole table can look free on one machine and take seconds on the other. `tests/stats_page_miss_bench.rs` reports the figure against a real database and `tests/stats_page_miss_test.rs` asserts the properties behind it; `tests/stats_parallel_bench.rs` is the wall-clock companion, and is the one to distrust when the two disagree.
+Index work here is measured in **page misses** — `SQLITE_DBSTATUS_CACHE_MISS`, the 4 KiB database pages SQLite has to fetch from the file — and not in milliseconds. Development happens on an SSD and the appliance runs off an SD card, where the same page count costs orders of magnitude more; a query that reads the whole table can look free on one machine and take seconds on the other. `tests/stats_page_miss_bench.rs` reports the figure against a real database and `tests/stats_page_miss_test.rs` asserts the properties behind it; `tests/dashboard_page_miss_bench.rs` does the same for the dashboard's first response and its recurring event-stream tick, and `tests/logs_page_miss_bench.rs` for every filter the query log offers, with values drawn from the database under test. All three take `BENCH_DB` and a `BENCH_NOW` that pins the clock, so a copy older than its windows still measures the traffic it holds; `tests/stats_parallel_bench.rs` is the wall-clock companion, and is the one to distrust when the two disagree.
 
 That distinction is not hypothetical. `outcome_breakdown_since` was left uncovered through version 11 because carrying `result` in an index measured *slower* on wall clock — but the plain table lookup it was compared against read 12 173 pages to the covered form's 2 157, or the entire 10 784-page table of a 370 k-row database. On an SSD with a warm OS page cache that difference does not show up in a duration.
 

CLAUDE.md

@@ -132,7 +132,7 @@ Statistics adds the conventions for a page whose readings sit in a **chosen wind
 - **`app.js` does not redraw what it did not need to draw.** `StatsPage` is three charts and one date; the bar-list, health-grid and highlights renderers are gone rather than kept as a second copy of the markup. There is no polling here — this page is history, not a live reading.
 - **The range is in the URL and the switcher is three `<a>`s** (`/stats?range=30d`), because the range picks the *server's* window. `StatsRange::label()` is the one spelling shared by the link, the parse and every card title. An unrecognised range renders the default rather than 400ing — it is a link an operator can edit, and every window on offer is spelled out right above it.
 - **A date the server can only write in UTC ships as an ISO day plus its timestamp** (`data-date-ts`), and `app.js` restates it in the browser's locale — the same division as the query log's relative times, and for the same reason.
-- **This page is measured in page misses, not milliseconds.** Development is on an SSD and the appliance runs off an SD card, so a duration measured here says nothing about a Raspberry Pi; the pages a query fetches from the file are the same on both. `cargo nextest run --release --no-capture --run-ignored only stats_page_miss` with `BENCH_DB` pointed at a copy of a real database reports them. A wall-clock reading is the thing to distrust when the two disagree — it is what left the outcome breakdown scanning the whole table through version 11.
+- **This page is measured in page misses, not milliseconds.** Development is on an SSD and the appliance runs off an SD card, so a duration measured here says nothing about a Raspberry Pi; the pages a query fetches from the file are the same on both. `cargo nextest run --release --no-capture --run-ignored only stats_page_miss` with `BENCH_DB` pointed at a copy of a real database reports them; `dashboard_page_miss` and `logs_page_miss` do the same for the dashboard (first response and tick) and the query log (every filter), and `BENCH_NOW` pins the clock on a copy older than its windows. A wall-clock reading is the thing to distrust when the two disagree — it is what left the outcome breakdown scanning the whole table through version 11.
 - **One scan per index, not one per reading.** `stats_scan_since` and `traffic_lists_since` (`src/db.rs`) are the page's two scans — the second answering top domains, the distinct-domain count and top clients from one grouping of `(domain, client_ip, doh_token)` — and every reading on it — the charts included — is folded out of one of them; `compute_range_stats` (`src/admin/stats.rs`) is what the page calls. `stats_scan_since` streams its rows and folds them in Rust rather than grouping in SQL: a grain carrying both the quarter hour and `response_ms` approaches a group per row, which would be a temp b-tree the size of the window. The single-purpose functions `/api/stats/*` uses are statements of their own — adding a seventh reading to the page means folding it out of one of those two scans, not adding a statement.
 - **A total nobody can count cheaply is maintained, not counted.** `query_logs`' row count lives in `settings` (`query_log_count`), moved by the insert batch, the prune and Clear All inside their own transactions — `SELECT COUNT(*)` walks an index end to end and the Database Health card asks on every load. A fourth write path to `query_logs` means a fourth `bump_log_count`, not a fourth reader.
 - Four bar lists in one template share **one askama macro** (`templates/_macros.html`); `{% call … %}` needs a matching `{% endcall %}` in askama 0.16, and `{% include %}` cannot see a loop variable at all.

tests/dashboard_page_miss_bench.rs

@@ -0,0 +1,114 @@
+//! What the dashboard costs in **page misses**, the unit
+//! `stats_page_miss_bench` explains. Manual-only, gated by `#[ignore]`.
+//!
+//!   BENCH_DB=/tmp/noadd-bench.db cargo nextest run --release \
+//!     --no-capture --run-ignored only `dashboard_page_miss`
+//!
+//! Two costs, reported separately because they recur at different rates: the
+//! first response is paid once per visit, the event stream's snapshot every
+//! `TICK_INTERVAL_SECS` for as long as a dashboard stays open. The tick is the
+//! number to watch.
+//!
+//! Each reading is taken with the read pool's page cache dropped first, so the
+//! number is what a cold appliance pays. `BENCH_NOW` (unix seconds) pins the
+//! clock: every dashboard reading ends at now, so on a copy older than a day
+//! the 24-hour readings would otherwise measure an empty window.
+
+use noadd::admin::events::compute_snapshot;
+use noadd::admin::stats::{
+    compute_summary, compute_timeline, compute_top_domains_and_clients, compute_top_upstreams,
+};
+use noadd::db::Database;
+use noadd::now_unix;
+
+/// The limit and window `dashboard_page` and `compute_snapshot` pass. Kept here
+/// rather than exported, so the per-reading rows below ask for what the page
+/// asks for; the tick total goes through `compute_snapshot` itself.
+const TOP_N: i64 = 10;
+const TIMELINE_HOURS: i64 = 24;
+
+/// Run `f` with the pool's page cache dropped first, and report how many pages
+/// it had to read.
+async fn page_misses<F, Fut, T>(db: &Database, f: F) -> i64
+where
+    F: FnOnce() -> Fut,
+    Fut: std::future::Future<Output = T>,
+{
+    db.reset_read_page_accounting().await.unwrap();
+    let before = db.read_page_cache_stats().await.unwrap();
+    f().await;
+    let after = db.read_page_cache_stats().await.unwrap();
+    after.misses - before.misses
+}
+
+#[tokio::test(flavor = "multi_thread", worker_threads = 8)]
+#[ignore = "benchmark; run manually with --ignored"]
+async fn dashboard_page_miss_bench() {
+    let db_path = std::env::var("BENCH_DB").unwrap_or_else(|_| "/tmp/noadd-bench.db".into());
+    assert!(
+        std::path::Path::new(&db_path).exists(),
+        "BENCH_DB={db_path} not found — copy a production database to a scratch path before running"
+    );
+    let now = std::env::var("BENCH_NOW").ok().map_or_else(now_unix, |v| {
+        v.parse::<i64>().expect("BENCH_NOW must be unix seconds")
+    });
+
+    let db = Database::open(&db_path).await.unwrap();
+    let storage = db.db_storage_stats().await.unwrap();
+    eprintln!("dashboard_page_miss_bench: db={db_path} now={now}");
+
+    // What `dashboard_page` reads before it writes any HTML.
+    let first: Vec<(&str, i64)> = vec![
+        (
+            "summary",
+            page_misses(&db, || compute_summary(&db, now)).await,
+        ),
+        (
+            "top domains + clients",
+            page_misses(&db, || compute_top_domains_and_clients(&db, now, TOP_N)).await,
+        ),
+        (
+            "top upstreams",
+            page_misses(&db, || compute_top_upstreams(&db, now, TOP_N)).await,
+        ),
+    ];
+    let first_total: i64 = first.iter().map(|(_, n)| *n).sum();
+
+    // The tick adds the timeline to the same three readings and runs all four
+    // concurrently, so its total is measured as one call rather than summed.
+    let timeline = page_misses(&db, || compute_timeline(&db, now, TIMELINE_HOURS)).await;
+    let tick = page_misses(&db, || compute_snapshot(&db, now)).await;
+
+    let mib = |pages: i64| (pages * 4096) as f64 / (1024.0 * 1024.0);
+    eprintln!();
+    eprintln!("  {:<42} {:>9}  {:>9}", "reading", "pages", "MiB");
+    for (label, n) in &first {
+        eprintln!("  {label:<42} {n:>9}  {:>9.1}", mib(*n));
+    }
+    eprintln!(
+        "  {:<42} {first_total:>9}  {:>9.1}",
+        "FIRST RESPONSE TOTAL",
+        mib(first_total)
+    );
+    eprintln!(
+        "  {:<42} {timeline:>9}  {:>9.1}",
+        "timeline (tick only)",
+        mib(timeline)
+    );
+    eprintln!(
+        "  {:<42} {tick:>9}  {:>9.1}",
+        "TICK TOTAL (compute_snapshot)",
+        mib(tick)
+    );
+    eprintln!(
+        "  database is {:.1} MiB",
+        storage.main_bytes as f64 / (1024.0 * 1024.0)
+    );
+
+    // A reading that costs nothing means the cache was not actually dropped, so
+    // every later number would be meaningless.
+    assert!(
+        tick > 0,
+        "no page misses recorded — is BENCH_DB an empty database?"
+    );
+}

tests/logs_page_miss_bench.rs

@@ -0,0 +1,241 @@
+//! What the query log page costs in **page misses**, the unit
+//! `stats_page_miss_bench` explains. Manual-only, gated by `#[ignore]`.
+//!
+//!   BENCH_DB=/tmp/noadd-bench.db cargo nextest run --release \
+//!     --no-capture --run-ignored only `logs_page_miss`
+//!
+//! Unlike the dashboard and the Statistics page, `/logs` has no time window:
+//! the list is a page of the whole table and the count is over all of it, so
+//! what a load costs depends on the filters rather than on a range. Every
+//! filter the page offers is measured on its own and in the combinations the
+//! form allows, with a common and a rare value each, because an index choice
+//! that helps one routinely hurts the other.
+//!
+//! The filter values are picked from `BENCH_DB` itself — the busiest and the
+//! quietest domain, token and query type — so the same bench means the same
+//! thing on any database. `BENCH_NOW` (unix seconds) pins the clock for the
+//! domain suggestions, the one reading here that has a window.
+
+use noadd::admin::stats::domain_suggestions;
+use noadd::db::Database;
+use noadd::now_unix;
+use rusqlite::{Connection, OpenFlags, OptionalExtension};
+
+/// `LOGS_PAGE_SIZE` in `src/admin/pages.rs`.
+const PAGE_SIZE: i64 = 50;
+
+/// How deep the second list reading goes. `OFFSET` is not free: every skipped
+/// row is still read, so a filter that is cheap on page one can be expensive
+/// further in.
+const DEEP_PAGE: i64 = 20;
+
+/// Run `f` with the pool's page cache dropped first, and report how many pages
+/// it had to read.
+async fn page_misses<F, Fut, T>(db: &Database, f: F) -> i64
+where
+    F: FnOnce() -> Fut,
+    Fut: std::future::Future<Output = T>,
+{
+    db.reset_read_page_accounting().await.unwrap();
+    let before = db.read_page_cache_stats().await.unwrap();
+    f().await;
+    let after = db.read_page_cache_stats().await.unwrap();
+    after.misses - before.misses
+}
+
+/// The value of `column` with the most (`DESC`) or fewest (`ASC`) rows, ties
+/// broken by value so repeated runs pick the same one. Values holding a search
+/// metacharacter are passed over: as a search term one would turn the prefix
+/// match being measured into a `LIKE`.
+fn pick(conn: &Connection, column: &str, order: &str) -> Option<String> {
+    conn.query_row(
+        &format!(
+            "SELECT {column} FROM query_logs \
+             WHERE {column} IS NOT NULL AND {column} NOT GLOB '*[%_*?]*' \
+             GROUP BY {column} ORDER BY COUNT(*) {order}, {column} LIMIT 1"
+        ),
+        [],
+        |row| row.get(0),
+    )
+    .optional()
+    .unwrap()
+}
+
+/// The filters one load of `/logs` passes to `query_logs` and `count_logs`.
+struct Filter {
+    label: String,
+    search: Option<String>,
+    blocked: Option<bool>,
+    token: Option<String>,
+    query_type: Option<String>,
+}
+
+#[tokio::test(flavor = "multi_thread", worker_threads = 8)]
+#[ignore = "benchmark; run manually with --ignored"]
+async fn logs_page_miss_bench() {
+    let db_path = std::env::var("BENCH_DB").unwrap_or_else(|_| "/tmp/noadd-bench.db".into());
+    assert!(
+        std::path::Path::new(&db_path).exists(),
+        "BENCH_DB={db_path} not found — copy a production database to a scratch path before running"
+    );
+    let now = std::env::var("BENCH_NOW").ok().map_or_else(now_unix, |v| {
+        v.parse::<i64>().expect("BENCH_NOW must be unix seconds")
+    });
+
+    // Opened first so the migrations have run before anything reads the schema.
+    let db = Database::open(&db_path).await.unwrap();
+    let storage = db.db_storage_stats().await.unwrap();
+
+    // Picked on a connection outside the read pool, so none of these scans is
+    // counted against the readings below.
+    let (busy_domain, quiet_domain, busy_token, quiet_token, busy_type, quiet_type) = {
+        let conn = Connection::open_with_flags(&db_path, OpenFlags::SQLITE_OPEN_READ_ONLY).unwrap();
+        (
+            pick(&conn, "domain", "DESC"),
+            pick(&conn, "domain", "ASC"),
+            pick(&conn, "doh_token", "DESC"),
+            pick(&conn, "doh_token", "ASC"),
+            pick(&conn, "query_type", "DESC"),
+            pick(&conn, "query_type", "ASC"),
+        )
+    };
+    let busy_domain = busy_domain.expect("BENCH_DB has no query logs");
+    // A plain term is a GLOB prefix search; a wildcard makes it a LIKE.
+    let prefix = busy_domain
+        .split('.')
+        .next()
+        .unwrap_or(&busy_domain)
+        .to_string();
+    let labels: Vec<&str> = busy_domain.split('.').collect();
+    let contains = format!("*{}*", labels[labels.len().saturating_sub(2)]);
+    eprintln!(
+        "logs_page_miss_bench: db={db_path} now={now}\n  prefix={prefix:?} rare={quiet_domain:?} \
+         contains={contains:?}\n  token busy={busy_token:?} quiet={quiet_token:?}\n  \
+         type busy={busy_type:?} quiet={quiet_type:?}"
+    );
+
+    let f = |label: &str,
+             search: Option<&str>,
+             blocked: Option<bool>,
+             token: Option<&Option<String>>,
+             query_type: Option<&Option<String>>| {
+        // A database with no DoH traffic has no token to filter by; that row is
+        // skipped rather than measured as an empty filter.
+        let token = match token {
+            Some(None) => return None,
+            Some(Some(t)) => Some(t.clone()),
+            None => None,
+        };
+        let query_type = match query_type {
+            Some(None) => return None,
+            Some(Some(t)) => Some(t.clone()),
+            None => None,
+        };
+        Some(Filter {
+            label: label.to_string(),
+            search: search.map(str::to_string),
+            blocked,
+            token,
+            query_type,
+        })
+    };
+    let filters: Vec<Filter> = [
+        f("no filter", None, None, None, None),
+        f("search prefix (busy)", Some(&prefix), None, None, None),
+        f(
+            "search prefix (rare)",
+            quiet_domain.as_deref(),
+            None,
+            None,
+            None,
+        ),
+        f("search contains", Some(&contains), None, None, None),
+        f("blocked", None, Some(true), None, None),
+        f("allowed", None, Some(false), None, None),
+        f("token (busy)", None, None, Some(&busy_token), None),
+        f("token (quiet)", None, None, Some(&quiet_token), None),
+        f("type (busy)", None, None, None, Some(&busy_type)),
+        f("type (quiet)", None, None, None, Some(&quiet_type)),
+        f(
+            "blocked + type (busy)",
+            None,
+            Some(true),
+            None,
+            Some(&busy_type),
+        ),
+        f(
+            "search prefix + allowed",
+            Some(&prefix),
+            Some(false),
+            None,
+            None,
+        ),
+        f(
+            "token (busy) + blocked",
+            None,
+            Some(true),
+            Some(&busy_token),
+            None,
+        ),
+        f(
+            "token + type (both quiet)",
+            None,
+            None,
+            Some(&quiet_token),
+            Some(&quiet_type),
+        ),
+    ]
+    .into_iter()
+    .flatten()
+    .collect();
+
+    let mut rows: Vec<(String, i64)> = Vec::new();
+    for filter in &filters {
+        let (search, token, query_type) = (
+            filter.search.as_deref(),
+            filter.token.as_deref(),
+            filter.query_type.as_deref(),
+        );
+        for (page_label, page) in [("page 1", 1), ("page 20", DEEP_PAGE)] {
+            let offset = (page - 1) * PAGE_SIZE;
+            let n = page_misses(&db, || {
+                db.query_logs(PAGE_SIZE, offset, search, filter.blocked, token, query_type)
+            })
+            .await;
+            rows.push((format!("{} — list {page_label}", filter.label), n));
+        }
+        let n = page_misses(&db, || {
+            db.count_logs(search, filter.blocked, token, query_type)
+        })
+        .await;
+        rows.push((format!("{} — count", filter.label), n));
+    }
+    rows.push((
+        "domain suggestions".to_string(),
+        page_misses(&db, || domain_suggestions(&db, now)).await,
+    ));
+    let total: i64 = rows.iter().map(|(_, n)| *n).sum();
+
+    let mib = |pages: i64| (pages * 4096) as f64 / (1024.0 * 1024.0);
+    eprintln!();
+    eprintln!("  {:<50} {:>9}  {:>9}", "reading", "pages", "MiB");
+    for (label, n) in &rows {
+        eprintln!("  {label:<50} {n:>9}  {:>9.1}", mib(*n));
+    }
+    eprintln!(
+        "  {:<50} {total:>9}  {:>9.1}",
+        "SUM OF ALL READINGS",
+        mib(total)
+    );
+    eprintln!(
+        "  database is {:.1} MiB",
+        storage.main_bytes as f64 / (1024.0 * 1024.0)
+    );
+
+    // A reading that costs nothing means the cache was not actually dropped, so
+    // every later number would be meaningless.
+    assert!(
+        total > 0,
+        "no page misses recorded — is BENCH_DB an empty database?"
+    );
+}