Scrollback housekeeping runs too rarely and reclaims too little #209

Closed
opened 2026-09-12 17:08:58 -04:00 by Salastil · 2 comments
Owner

Both halves of scrollback housekeeping in run_housekeeping (src/main.rs:358) are paced by AVATAR_CACHE_SWEEP_INTERVAL — 6 hours — which was chosen for sweeping avatar caches and has nothing to do with how fast scrollback grows.

Measured on a live daemon (6,439 s uptime, consistent VACUUM INTO snapshot):

1. The prune runs too rarely. SCROLLBACK_KEEP_PER_BUFFER is 5000, and the prune statement is correct — it ran at the 60 s mark and did cut the busiest buffer to exactly 5000. But that buffer takes 2.99 msg/s, so it was back to 24,267 rows less than two hours later. At 6-hour spacing a room at that rate reaches ~65,000 rows between passes — 13× the intended cap. 13 buffers were over cap, 44,131 excess rows in total.

The prune itself is cheap: 2.1 s to delete all 44,131 rows. Running it far more often (every 15–30 min, or when a buffer crosses some multiple of the cap) is affordable and keeps each pass smaller.

2. The file never shrinks. incremental_vacuum(200) reclaims 200 pages — 800 KB at the 4096-byte page size — and only on a pass that deleted something, so at most once per 6 hours. The live file is 226 MB on disk but compacts to 149 MB, i.e. roughly 19,700 free pages. At 200 pages per 6 hours that backlog takes about 25 days to reclaim, and deletions keep adding to it faster than that. In practice the file only grows.

Fix is to loop incremental_vacuum until the freelist is actually small (PRAGMA freelist_count), or pass a page count derived from what was just deleted, rather than a fixed 200.

Neither change affects what the user sees: the retained window is still 5000 messages per buffer.

Related: #207 — with WAL in place the more frequent prune also stops blocking readers.

Checked and explicitly not a problem, so nobody spends time on it: search_messages is a LIKE scan but the cap bounds it — 6 ms on the busiest buffer, 47 ms across all 308k rows. No FTS5 needed.

Both halves of scrollback housekeeping in `run_housekeeping` (`src/main.rs:358`) are paced by `AVATAR_CACHE_SWEEP_INTERVAL` — **6 hours** — which was chosen for sweeping avatar caches and has nothing to do with how fast scrollback grows. Measured on a live daemon (6,439 s uptime, consistent `VACUUM INTO` snapshot): **1. The prune runs too rarely.** `SCROLLBACK_KEEP_PER_BUFFER` is 5000, and the prune statement is correct — it ran at the 60 s mark and did cut the busiest buffer to exactly 5000. But that buffer takes 2.99 msg/s, so it was back to **24,267 rows** less than two hours later. At 6-hour spacing a room at that rate reaches ~65,000 rows between passes — 13× the intended cap. 13 buffers were over cap, 44,131 excess rows in total. The prune itself is cheap: **2.1 s** to delete all 44,131 rows. Running it far more often (every 15–30 min, or when a buffer crosses some multiple of the cap) is affordable and keeps each pass smaller. **2. The file never shrinks.** `incremental_vacuum(200)` reclaims 200 pages — 800 KB at the 4096-byte page size — and only on a pass that deleted something, so at most once per 6 hours. The live file is **226 MB on disk but compacts to 149 MB**, i.e. roughly **19,700 free pages**. At 200 pages per 6 hours that backlog takes about **25 days** to reclaim, and deletions keep adding to it faster than that. In practice the file only grows. Fix is to loop `incremental_vacuum` until the freelist is actually small (`PRAGMA freelist_count`), or pass a page count derived from what was just deleted, rather than a fixed 200. Neither change affects what the user sees: the retained window is still 5000 messages per buffer. Related: #207 — with WAL in place the more frequent prune also stops blocking readers. Checked and explicitly *not* a problem, so nobody spends time on it: `search_messages` is a `LIKE` scan but the cap bounds it — 6 ms on the busiest buffer, 47 ms across all 308k rows. No FTS5 needed.
Salastil added the bug label 2026-09-12 17:08:58 -04:00
Author
Owner

The same 6-hour pacing shows up in the media caches, since they are swept from the same loop.

Live disk usage against each cap:

cache on disk cap
matrix-media 332 MB 250 MB
discord-thumbnails 99 MB 100 MB
sneedchat-attachments 72 MB 250 MB
sockchat-attachments 83 MB 250 MB
sneedchat-avatars 24 MB 100 MB
sockchat-avatars 19 MB 100 MB

Only matrix-media is over, by 82 MB — accumulated in the 1h46m since the sweep last ran at startup, which matches the Matrix traffic measured above (a bridged room at ~3 msg/s carrying images).

Nothing is wrong with the caps or sweep_cache_dir; it is the interval. Whatever the prune ends up being paced at should carry the cache sweeps with it, since they overshoot for the same reason.

Total cache on disk is currently 628 MB.

The same 6-hour pacing shows up in the media caches, since they are swept from the same loop. Live disk usage against each cap: | cache | on disk | cap | | --- | --- | --- | | `matrix-media` | **332 MB** | 250 MB | | `discord-thumbnails` | 99 MB | 100 MB | | `sneedchat-attachments` | 72 MB | 250 MB | | `sockchat-attachments` | 83 MB | 250 MB | | `sneedchat-avatars` | 24 MB | 100 MB | | `sockchat-avatars` | 19 MB | 100 MB | Only `matrix-media` is over, by 82 MB — accumulated in the 1h46m since the sweep last ran at startup, which matches the Matrix traffic measured above (a bridged room at ~3 msg/s carrying images). Nothing is wrong with the caps or `sweep_cache_dir`; it is the interval. Whatever the prune ends up being paced at should carry the cache sweeps with it, since they overshoot for the same reason. Total cache on disk is currently 628 MB.
Author
Owner

Finished in nobilis be40066, carried into moho by f2fc66f.

Cadence. The scrollback prune has its own loop on a 15-minute interval; the media caches keep the six-hourly one they were written for. Worst case at 3 msg/s is now a couple of thousand rows over cap instead of thirteen times it, and each pass is small enough not to hold the database for seconds.

Vacuum. It now asks freelist_count and keeps going until little is free, in 512-page chunks taking the lock per chunk so one long vacuum is not a stall for every reader, bounded at ~80MB per call. It also runs on every pass rather than only after a delete, since a message deleted in a room frees pages too.

One thing the report could not have known, and it is the bigger half. PRAGMA incremental_vacuum(200) run through rusqlite's execute_batch was handing back one page, not 200. SQLite frees one page per step of that statement and execute_batch steps once. Traced directly - a freelist of 534 falling by exactly one per call, repeatedly - and fixed by stepping the statement to completion. So the real reclaim rate was 4KB per six hours: the "25 days" in the report was two hundred times optimistic.

A regression of mine, caught by the same test. #207 put journal_mode=WAL before auto_vacuum=INCREMENTAL in Store::open. SQLite will not change auto_vacuum on a database already in WAL mode and says nothing when it refuses, so every scrollback.db created after that change would have had auto_vacuum=NONE and could never have reclaimed anything. The pragmas are now in the order that works, and the test asserts both. Existing databases were unaffected - this one is auto_vacuum=2.

Measured against a copy of the live 225MB database, through the real code: 8,447 rows pruned in 0.1s, 10,428 pages handed back, 225MB -> 184MB, whole pass under a second.

Finished in nobilis [`be40066`](https://git.salastil.com/Salastil/nobilis/commit/be40066), carried into moho by [`f2fc66f`](https://git.salastil.com/Salastil/moho/commit/f2fc66f). **Cadence.** The scrollback prune has its own loop on a 15-minute interval; the media caches keep the six-hourly one they were written for. Worst case at 3 msg/s is now a couple of thousand rows over cap instead of thirteen times it, and each pass is small enough not to hold the database for seconds. **Vacuum.** It now asks `freelist_count` and keeps going until little is free, in 512-page chunks taking the lock per chunk so one long vacuum is not a stall for every reader, bounded at ~80MB per call. It also runs on every pass rather than only after a delete, since a message deleted in a room frees pages too. **One thing the report could not have known, and it is the bigger half.** `PRAGMA incremental_vacuum(200)` run through rusqlite's `execute_batch` was handing back **one page, not 200**. SQLite frees one page per *step* of that statement and `execute_batch` steps once. Traced directly - a freelist of 534 falling by exactly one per call, repeatedly - and fixed by stepping the statement to completion. So the real reclaim rate was 4KB per six hours: the "25 days" in the report was two hundred times optimistic. **A regression of mine, caught by the same test.** #207 put `journal_mode=WAL` before `auto_vacuum=INCREMENTAL` in `Store::open`. SQLite will not change auto_vacuum on a database already in WAL mode and says nothing when it refuses, so every scrollback.db created after that change would have had `auto_vacuum=NONE` and could never have reclaimed anything. The pragmas are now in the order that works, and the test asserts both. Existing databases were unaffected - this one is `auto_vacuum=2`. Measured against a copy of the live 225MB database, through the real code: 8,447 rows pruned in 0.1s, 10,428 pages handed back, **225MB -> 184MB**, whole pass under a second.
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: Salastil/moho#209