/crawlstats: stop paying thirty seconds for a planner's guess (#143)

Three findings, measured against production at 444,009 feeds.

**This database has never been ANALYZEd.** There is no `sqlite_stat1`, so SQLite
falls back to its built-in guess that an equality test is more selective than a
range test. Two of `jobBacklogs`'s five reads ask for a date and filter on a
status, and the guess picks the status index for both:

  submitted  17,722ms -> 654ms   (seeks 330k `pending` rows to find 5,954)
  enriched   16,067ms ->  119ms  (seeks 109k `active` rows; the partial index
                                  is keyed by the very column being counted)

Both are now `indexed by`. Identical results, 27x and 135x. Not a hint SQLite
may ignore -- naming a missing index fails at prepare time -- so a test asserts
both indexes exist as well as asserting the plans.

**The API route bypassed every cache the page uses.** `/api/crawlstats` called
`q.jobBacklogs` directly while `/crawlstats` has always called the cached
reader, which is why the endpoint took 53 seconds to serve numbers the page
rendered in 3.7. It now uses the same reader. The liveness numbers stay
uncached -- `crawlStats` and `logActivity` are still read fresh -- so the
endpoint still cannot report a dead crawler as alive, which is the one thing a
status endpoint must never do.

Together: jobBacklogs 27.9s -> 3.2s cold and 263ms warm, and the JSON endpoint
drops from 53s to roughly the page's own cost.

Left alone deliberately. `categoryStats`'s totals query wants `status`,
`last_success_at` and `item_count` for every non-dead row and cannot finish
inside the 30s deadline; the covering index that would fix it is over three
columns rewritten on every crawl, and writes are the binding constraint. It is
served stale-while-revalidate and the stale value is what the page shows.
`failingFeeds` (2.4s) sorts every error row by `error_count`, which is written
on every successful crawl too, so an index there has the same problem. Both want
a rollup rather than an index.

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>

Author: ralyodio

apps/web/src/app/api/crawlstats/route.js

@@ -1,7 +1,7 @@
 import { q, discovery, alerts } from '@rssamplifier/db';
 
 import { db } from '../../../lib/db.js';
-import { categoryStats, indexingHistory } from '../../../lib/crawlstats.js';
+import { categoryStats, indexingHistory, jobBacklogs } from '../../../lib/crawlstats.js';
 import { toLine } from '../../../lib/crawlLog.js';
 import { jobRows } from '../../../lib/jobs.js';
 
@@ -43,7 +43,17 @@ export async function GET() {
     discovery.countQueuedKeywords(client),
     indexingHistory(),
     categoryStats(),
-    q.jobBacklogs(client),
+    // The cached reader, which is what the page has always used. This route
+    // called `q.jobBacklogs` directly and so paid the uncached count on every
+    // request -- 27.9 seconds of a 53-second response, while /crawlstats
+    // rendered the same numbers in 3.7. Nothing about a status endpoint wants
+    // that: the backlog it reports is hundreds of thousands of feeds draining
+    // at a few hundred an hour, so a sixty-second-old answer is the same answer.
+    //
+    // The liveness numbers stay uncached, which is the distinction that matters
+    // -- `crawlStats` and `logActivity` below are still read fresh, so this
+    // endpoint can still never claim a dead crawler is alive.
+    jobBacklogs(),
     q.logActivity(client, 1),
     // See the page: this only tells a sender with nobody to serve from one that
     // has stopped, which the log alone cannot say.
@@ -52,7 +62,11 @@ export async function GET() {
   ]);
 
   const jobs = jobRows({
-    backlogs,
+    // Null when the read failed and nothing was cached. `jobBacklogs` returns
+    // null rather than zeroes on purpose -- "0 waiting" reads as "all caught
+    // up", which would be a lie -- and an empty object leaves each backlog
+    // undefined, which serialises as unknown rather than as done.
+    backlogs: backlogs ?? {},
     activity,
     fetchedLastHour: stats.fetchedLastHour,
     keywordQueue: keywordsQueued,

packages/db/src/queries.js

@@ -1398,8 +1398,17 @@ export async function jobBacklogs(db) {
 
     // A short range read off feeds_created_idx: an hour of submissions is a
     // handful of rows however large the directory gets.
+    //
+    // `indexed by` because the planner does not agree, and gets it badly wrong.
+    // **This database has never been ANALYZEd** -- there is no `sqlite_stat1` --
+    // so SQLite falls back to its built-in guess that an equality test beats a
+    // range test, picks `feeds_status_success_idx (status=?)`, and visits every
+    // `pending` row to check its `created_at`. `pending` is 330k of 444k rows.
+    // Measured: 17,722ms this way, 654ms forced onto the range, and the same
+    // 5,954 rows come back either way.
     db.execute({
-      sql: `select count(*) as n from feeds where created_at >= ? and status = 'pending'`,
+      sql: `select count(*) as n from feeds indexed by feeds_created_idx
+             where created_at >= ? and status = 'pending'`,
       args: [hourAgo],
     }),
 
@@ -1417,10 +1426,16 @@ export async function jobBacklogs(db) {
     // for the reason this whole function exists: 3,275 of 369,056 feeds carry a
     // stamp, so this touches a few thousand index entries, while asking for the
     // complement would visit every row. The backlog is arithmetic afterwards.
+    //
+    // `indexed by` for the same reason as `submitted` above, and it costs even
+    // more here: unforced the planner seeks `status='active'` (109k rows) on
+    // `feeds_status_success_idx` and reads `authors_checked_at` off each one,
+    // when the partial index *is* keyed by exactly the column being counted and
+    // filtered. Measured: 16,067ms unforced, 119ms forced -- 135x, same answer.
     db.execute({
       sql: `select count(*) as n,
                    sum(case when authors_checked_at >= ? then 1 else 0 end) as hour
-            from feeds
+            from feeds indexed by feeds_authors_due_idx
            where status = 'active' and authors_checked_at is not null`,
       args: [hourAgo],
     }),

packages/db/test/job-backlog-plans.test.js

@@ -0,0 +1,102 @@
+import assert from 'node:assert/strict';
+import { test, before, after } from 'node:test';
+import { mkdtemp, rm } from 'node:fs/promises';
+import { tmpdir } from 'node:os';
+import { join } from 'node:path';
+
+import { connect, newId, nowIso } from '../src/client.js';
+import { migrate } from '../src/migrate.js';
+import * as q from '../src/queries.js';
+
+/**
+ * The index choices behind `jobBacklogs`, pinned.
+ *
+ * These are `indexed by` in the query because this database has **never been
+ * ANALYZEd** — there is no `sqlite_stat1` — so SQLite falls back to its built-in
+ * guess that an equality beats a range, and picks the status index for two
+ * queries that want a date. Measured against production: 17.7s vs 654ms, and
+ * 16.1s vs 119ms, for identical results.
+ *
+ * A plan regression is invisible from the outside — same rows, same numbers,
+ * thirty times the wall clock — so the plan itself is the thing worth asserting.
+ * Locally the tables are tiny and both plans are instant; only the shape can be
+ * checked here, which is precisely why it needs a test rather than a benchmark.
+ */
+
+let dir;
+let db;
+
+before(async () => {
+  dir = await mkdtemp(join(tmpdir(), 'rssamp-plans-'));
+  db = connect({ url: `file:${join(dir, 'test.db')}` });
+  await migrate(db);
+});
+
+after(async () => {
+  await rm(dir, { recursive: true, force: true });
+});
+
+/**
+ * @param {string} sql
+ * @param {unknown[]} args
+ * @returns {Promise<string>}
+ */
+async function plan(sql, args = []) {
+  const { rows } = await db.execute({ sql: `explain query plan ${sql}`, args });
+  return rows.map((r) => String(r.detail)).join(' | ');
+}
+
+test('the submissions count is read off the created_at index, not the status one', async () => {
+  const detail = await plan(
+    `select count(*) as n from feeds indexed by feeds_created_idx
+      where created_at >= ? and status = 'pending'`,
+    [nowIso(-3_600_000)],
+  );
+
+  assert.match(detail, /feeds_created_idx/);
+  assert.doesNotMatch(detail, /feeds_status_success_idx/);
+});
+
+test('the enrichment count is read off its own partial index', async () => {
+  const detail = await plan(
+    `select count(*) as n,
+            sum(case when authors_checked_at >= ? then 1 else 0 end) as hour
+       from feeds indexed by feeds_authors_due_idx
+      where status = 'active' and authors_checked_at is not null`,
+    [nowIso(-3_600_000)],
+  );
+
+  assert.match(detail, /feeds_authors_due_idx/);
+  assert.doesNotMatch(detail, /feeds_status_success_idx/);
+});
+
+test('both forced indexes exist, so the hint cannot become an error', async () => {
+  // `indexed by` is not a hint SQLite may ignore -- naming an index that does
+  // not exist is a hard failure at prepare time. A migration that renamed or
+  // dropped either of these would take the whole jobs board down, so the
+  // coupling is asserted rather than left to be discovered in production.
+  const { rows } = await db.execute(
+    `select name from sqlite_master where type = 'index'
+       and name in ('feeds_created_idx', 'feeds_authors_due_idx')`,
+  );
+
+  assert.equal(rows.length, 2, 'both indexes must exist for jobBacklogs to prepare');
+});
+
+test('jobBacklogs still answers with the forced indexes in place', async () => {
+  // The plans above say which index; this says the numbers survived the change.
+  const now = nowIso();
+  await db.execute({
+    sql: `insert into feeds (id, slug, title, feed_url, status, next_fetch_at, created_at, updated_at)
+          values (?, 'a', 'A', 'https://a.example/feed', 'pending', ?, ?, ?)`,
+    args: [newId(), now, now, now],
+  });
+
+  const backlogs = await q.jobBacklogs(db);
+
+  assert.equal(typeof backlogs.submittedLastHour, 'number');
+  assert.equal(backlogs.submittedLastHour, 1);
+  assert.equal(typeof backlogs.pendingFirstCrawl, 'number');
+  assert.equal(typeof backlogs.authorsDone, 'number');
+  assert.equal(typeof backlogs.authorsLastHour, 'number');
+});