diff --git a/apps/web/src/app/api/crawlstats/route.js b/apps/web/src/app/api/crawlstats/route.js index 4d6691b..bc52d8f 100644 --- a/apps/web/src/app/api/crawlstats/route.js +++ b/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, diff --git a/packages/db/src/queries.js b/packages/db/src/queries.js index 2a78d05..c24c73e 100644 --- a/packages/db/src/queries.js +++ b/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], }), diff --git a/packages/db/test/job-backlog-plans.test.js b/packages/db/test/job-backlog-plans.test.js new file mode 100644 index 0000000..c8b5236 --- /dev/null +++ b/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} + */ +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'); +});