Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion ARCHITECTURE.md
Original file line number Diff line number Diff line change
Expand Up @@ -276,7 +276,7 @@ The window's grain has no time bucket in it. Bucketing the shared grain was what

The charts did still pay for scans of their own after that: the browser fetched the timeline, which walked the metrics index again, and the heatmap, which walked `idx_query_logs_timestamp`. They now come out of the page's scan too. `stats_scan_since` reads the metrics index once from the earlier of the range's and the heatmap's windows, folds the window readings, and counts queries per UTC quarter hour into a `QuarterSeries` the page embeds; `app.js` folds that into the viewer's hours and days, which is exact because every UTC offset in use is a whole number of quarter hours. It streams rows into Rust rather than grouping in SQL, because a grain carrying both the quarter and `response_ms` approaches one group per row. On the same database with the 30-day range — the whole table — a visit went from 13 298 page misses (51.9 MiB) to 9 758 (38.1 MiB). The API's timeline and heatmap endpoints keep their own statements, and `e2e/tests/specs/stats_charts.rs` holds the browser's folds to them.

The Database Health card's row count is the one reading that is not a scan of anything. `SELECT COUNT(*)` has no shortcut in SQLite — it walks the smallest index end to end, 1 386 pages on that database, for a number the card prints and two of its estimates divide by — so the count lives in `settings` under `query_log_count`, seeded by the version-13 migration and moved by the three statements that change how many rows `query_logs` holds: the logger's insert batch, the hourly prune, and Clear All. Each moves it inside its own transaction, which is what makes the counter unable to disagree with the table; `total_log_count` falls back to counting when the row is missing, which is the state the migration seeds it out of. The card went from 1 398 pages to 14.
The Database Health card's row count is the one reading that is not a scan of anything. `SELECT COUNT(*)` has no shortcut in SQLite — it walks the smallest index end to end, 1 386 pages on that database, for a number the card prints and two of its estimates divide by — so the count lives in `settings` under `query_log_count`, seeded by the version-13 migration and moved by the three statements that change how many rows `query_logs` holds: the logger's insert batch, the hourly prune, and Clear All. Each moves it inside its own transaction, which is what makes the counter unable to disagree with the table; `total_log_count` falls back to counting when the row is missing, which is the state the migration seeds it out of. The card went from 1 398 pages to 14. The query log's pager asks for the same number whenever no filter narrows it, so `count_logs` reads the counter in that case through the same `read_log_count`, and only counts once a filter is applied.

The dashboard pays for its readings every 10 seconds rather than once a visit, which makes a scan it repeats the most expensive kind. Its summary asked two statements for totals and blocks, then cache hits and latency, over the same 30 days of the metrics index; `summary_multi_since` moves the allowed-only filter from the `WHERE` into each `CASE` and answers both from one scan, 2 152 pages a tick instead of 4 304. With the upstream index, a tick on that database dropped from 8 304 page misses to 4 755.

Expand Down
2 changes: 1 addition & 1 deletion CLAUDE.md
Original file line number Diff line number Diff line change
Expand Up @@ -134,7 +134,7 @@ Statistics adds the conventions for a page whose readings sit in a **chosen wind
- **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; `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.
- **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 both the Database Health card and the query log's pager (whenever no filter is applied, via `count_logs`) ask 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.

Account adds the conventions for **actions that need a password proof**:
Expand Down
14 changes: 13 additions & 1 deletion e2e/src/server.rs
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,13 @@ const STARTUP_TIMEOUT: Duration = Duration::from_secs(60);
/// How long a SIGTERM gets before the process is killed outright.
const SHUTDOWN_GRACE: Duration = Duration::from_secs(10);

/// Brings the maintained `query_logs` row count back in line after a seed —
/// see [`Server::seed`]. An upsert, because the counter row is only there once
/// noadd has migrated this database.
const RECOUNT_LOGS: &str = "INSERT INTO settings (key, value) \
SELECT 'query_log_count', COUNT(*) FROM query_logs WHERE true \
ON CONFLICT(key) DO UPDATE SET value = excluded.value;\n";

/// A noadd instance: its ports, its database, and the process serving them.
#[derive(Debug)]
pub struct Server {
Expand Down Expand Up @@ -127,6 +134,11 @@ impl Server {
/// traffic and rewrite settings noadd reads at boot, so they are written
/// between the two starts rather than underneath a live server.
///
/// Rows written here bypass the write paths that maintain `query_logs`'
/// row count in `settings`, so the count is recomputed after every seed;
/// otherwise the query log's pager and the Database Health card report the
/// total from before the fixture.
///
/// # Errors
///
/// Fails when `sqlite3` is missing or exits non-zero.
Expand All @@ -150,7 +162,7 @@ impl Server {
.stdin
.as_mut()
.context("sqlite3 stdin")?
.write_all(sql.as_bytes())
.write_all(format!("{sql}\n{RECOUNT_LOGS}").as_bytes())
.await?;
drop(child.stdin.take());
let status = child.wait().await?;
Expand Down
36 changes: 21 additions & 15 deletions src/db.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1103,6 +1103,12 @@ impl Database {
token.as_deref(),
query_type.as_deref(),
);
// Nothing narrowed the count, so it is the table's row count,
// which the write paths maintain. Counting it walks the smallest
// index end to end on every load of an unfiltered query log.
if param_values.is_empty() {
return read_log_count(conn);
}

let params_refs: Vec<&dyn rusqlite::types::ToSql> = param_values
.iter()
Expand Down Expand Up @@ -2654,25 +2660,12 @@ impl Database {
/// prints and two of its estimates divide by. The counter is one row of
/// `settings`, written inside the same transaction as every insert, prune
/// and clear, so it cannot report a total the table does not hold.
/// [`Self::count_logs`] reads the same counter when no filter is applied.
///
/// A database with no counter row counts, which is what the migration
/// seeded it from.
pub async fn total_log_count(&self) -> Result<i64, DbError> {
let result = self
.reader()
.call(|conn| {
let stored: Option<String> = conn
.prepare_cached("SELECT value FROM settings WHERE key = ?1")?
.query_row(params![QUERY_LOG_COUNT_KEY], |row| row.get(0))
.optional()?;
if let Some(count) = stored.and_then(|v| v.parse::<i64>().ok()) {
return Ok(count);
}
let count: i64 =
conn.query_row("SELECT COUNT(*) FROM query_logs", [], |row| row.get(0))?;
Ok(count)
})
.await?;
let result = self.reader().call(|conn| read_log_count(conn)).await?;
Ok(result)
}

Expand Down Expand Up @@ -2885,6 +2878,19 @@ fn set_log_count(conn: &rusqlite::Connection, count: i64) -> rusqlite::Result<()
Ok(())
}

/// The maintained `query_logs` row count, counted instead only when the
/// counter row is missing or unreadable.
fn read_log_count(conn: &rusqlite::Connection) -> rusqlite::Result<i64> {
let stored: Option<String> = conn
.prepare_cached("SELECT value FROM settings WHERE key = ?1")?
.query_row(params![QUERY_LOG_COUNT_KEY], |row| row.get(0))
.optional()?;
if let Some(count) = stored.and_then(|v| v.parse::<i64>().ok()) {
return Ok(count);
}
conn.query_row("SELECT COUNT(*) FROM query_logs", [], |row| row.get(0))
}

/// Add a column to `table` if it doesn't already exist.
///
/// `SQLite` doesn't support `ALTER TABLE ... ADD COLUMN IF NOT EXISTS`, so we
Expand Down
19 changes: 15 additions & 4 deletions tests/db_test.rs
Original file line number Diff line number Diff line change
Expand Up @@ -976,9 +976,10 @@ async fn test_filter_list_url_fetches_one_row_by_id() {
);
}

/// `total_log_count` is a counter now rather than a `COUNT(*)`, so every path
/// that changes how many rows `query_logs` holds has to move it. One that does
/// not leaves the Database Health card reporting a total the table stopped
/// `total_log_count` is a counter now rather than a `COUNT(*)`, and so is an
/// unfiltered `count_logs`, so every path that changes how many rows
/// `query_logs` holds has to move it. One that does not leaves the Database
/// Health card and the query log's pager reporting a total the table stopped
/// holding, and nothing else would notice.
#[tokio::test]
async fn the_log_count_follows_every_write_that_changes_it() {
Expand All @@ -998,13 +999,23 @@ async fn the_log_count_follows_every_write_that_changes_it() {
}
}

// The counter and a real count of the same rows, which must never differ.
// Every reader of the counter, against the rows themselves, which must
// never differ.
async fn assert_holds(db: &Database, expected: i64) {
let rows = db
.query_logs(i64::MAX, 0, None, None, None, None)
.await
.unwrap();
assert_eq!(rows.len() as i64, expected);
assert_eq!(db.total_log_count().await.unwrap(), expected);
assert_eq!(
db.count_logs(None, None, None, None).await.unwrap(),
expected
);
assert_eq!(
db.count_logs(Some(" "), None, None, None).await.unwrap(),
expected
);
}

let db = test_db().await;
Expand Down
29 changes: 28 additions & 1 deletion tests/stats_page_miss_test.rs
Original file line number Diff line number Diff line change
Expand Up @@ -300,7 +300,8 @@ async fn the_total_log_count_is_read_rather_than_counted() {
let db = seeded_db().await;

let read = page_misses(&db, || db.total_log_count()).await;
let counted = page_misses(&db, || db.count_logs(None, None, None, None)).await;
// `*` matches every domain, so this is the same total arrived at by counting.
let counted = page_misses(&db, || db.count_logs(Some("*"), None, None, None)).await;

assert!(
counted > 0,
Expand All @@ -312,3 +313,29 @@ async fn the_total_log_count_is_read_rather_than_counted() {
is total_log_count back on COUNT(*)?"
);
}

/// The query log's pager asks for its total on every load, and with no filter
/// applied that total is the table's row count — the number the write paths
/// already maintain. Counting it walks the smallest index end to end, which on
/// an unfiltered first page is nearly the whole cost of the load.
#[tokio::test]
async fn the_unfiltered_query_log_count_is_read_rather_than_counted() {
let db = seeded_db().await;

let unfiltered = page_misses(&db, || db.count_logs(None, None, None, None)).await;
// A blank search box is no filter at all, so it must take the same path.
let blank = page_misses(&db, || db.count_logs(Some(" "), None, None, None)).await;
let counted = page_misses(&db, || db.count_logs(Some("*"), None, None, None)).await;

assert!(
counted > 0,
"counting read no pages at all — the measurement is not working"
);
for (label, read) in [("no filter", unfiltered), ("blank search", blank)] {
assert!(
read * 4 < counted,
"{label} read {read} pages and counting the same rows read {counted} — \
is count_logs counting when nothing narrows it?"
);
}
}