diff --git a/CHANGELOG.md b/CHANGELOG.md index 5dd7743..0a5cd1a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,15 +3,29 @@ ## [Unreleased] ### Added +- `counters` table (`src/db.js`): durable, never-pruned key/value aggregates — `mcp_queries_lifetime`, `health_write_failures_lifetime`, `last_health_cycle`, `health_schema_invalid`. Transactional with the writes they count and visible across both the server process and `scripts/healthcheck.js` (#313) +- Per-protocol cycle reconciliation (`src/health/checker.js`): `probed` (by result status, including `unknown`/`error`), `sibling_updated`, `skipped_unprobeable`, `excluded_inactive`, `persist_failed`, and an `unaccounted` residual that must be 0. Buckets partition the cycle-start snapshot of every row carrying the protocol — the real denominator behind the digest's "1,218" (#313) +- Reconciliation reports `added_mid_cycle` and `vanished_mid_cycle` per protocol and per cycle. The pollers share the health cycle's hourly interval and insert with `status` defaulting to `active`, so a multi-minute cycle routinely races inserts, deactivations and purges; those rows are reported separately instead of being folded into a denominator they never had a full cycle's chance to land in (#313) +- `GET /api/v1/digest`: new `health` section with `write_failures_lifetime`, `last_cycle` reconciliation, `health_schema_invalid` (present only when the status enum is broken), and `health_schema_probe_error` (present only when the boot probe could not reach a verdict) (#313) - `SKILL.md`: added `### Known-good endpoints (fallback)` sub-section under Quick Start with four verified endpoints — one per protocol (L402, x402, MPP) plus a dual-rail example (llm402 Kimi-K2.6, L402 + x402) — for use when `search_services` returns errors (#250) - `SKILL.md`: added `version: 0.1.0` to YAML frontmatter to match plugin manifest semver ### Changed +- **BEHAVIOR-CHANGE** — `uptime_30d` now excludes `rate_limited` checks from both numerator and denominator. A 429 means the provider throttled our prober and carries no availability information; counting it as downtime scored the most popular endpoints in the index as unreliable (#313) +- `GET /api/v1/digest`: `mcp_queries_total` is now a true lifetime counter (was a 90-day `COUNT` over `query_log`, which is why it dropped between digests). Window aggregates are renamed `mcp_queries_90d` / `mcp_active_days_90d`, `mcp_counter_seeded_at` marks the discontinuity, and `mcp_active_days` emits the 90d value for one release alongside `mcp_active_days_deprecated: true` (#313) +- MCP traffic is classified by one predicate shared between the JS increment and every SQL window query (`MCP_USER_AGENT_SQL`, both halves lowercased). The JS half was case-sensitive while SQL `LIKE` is case-insensitive for ASCII, so a client sending `402Index-MCP` was counted in `mcp_queries_90d` but never in `mcp_queries_lifetime` (#313) +- `GET /api/v1/digest`: `mcp_counters_ua_attested: true` marks the MCP counters for what they are. The only gate on the increment is a client-controlled `User-Agent` substring and the lifetime total is never pruned, so it is a ceiling attested by clients, not a measurement — previously the number self-healed as poisoned rows aged out of the 90-day window (#313) +- `runHealthChecks()` return contract: adds `persistFailed`, `byProtocol`, `reconciliation`, `persistFailures`, `cycle`, and accepts `{ concurrency }`. Both callers (`src/scheduler.js`, `scripts/healthcheck.js`) report the same `formatCycleSummary()` line (#313) - `SKILL.md`: generalized line 305 phrasing from "Claude Code" to "an agent" — ahead of plugin submissions to Codex/Cursor/Cline/Windsurf/Gemini CLI - MCP server contract tests (`tools.test.js`, `mcp-0.2.5-parity.test.js`, `mcp-verified.test.js`) refactored to use hand-rolled `globalThis.fetch` stubs backed by captured JSON fixtures, eliminating live HTTP calls during `npm --prefix mcp-server test` - `mcp-drift-check.yml`: Added `schedule` trigger (daily 08:00 UTC) with a `live-smoke` job that runs contract tests against production (`continue-on-error: true`) ### Fixed +- `health_checks` status CHECK constraint now includes `not_acceptable`, which `classifyHealthStatus` has emitted for HTTP 406 all along — roughly 10 endpoints per cycle were silently failing their status write. The enum is now defined once (`HEALTH_CHECK_STATUSES`) and the inline DDL, the migration, and `test/helpers/test-db.js` all derive from it (#313) +- `health_schema_invalid` is raised only when the boot probe returns a non-empty rejected list. A probe that could not run — most often `SQLITE_BUSY` from `scripts/healthcheck.js` booting against a mid-write server — is retried, then recorded under `health_schema_probe_error` instead. A latched false alarm on a healthy schema is how a loud failure signal gets ignored (#313) +- `migrateHealthChecksStatusConstraint()`: detects by insertability probe instead of DDL substring, prunes to retention and checks free space before starting, copies with explicit column lists (a positional `SELECT *` shuffled values when column order differed), verifies foreign keys before commit, and is loud on failure — the `console.warn` swallow is gone (#313) +- Health-check persists are isolated per row: one rejected write no longer aborts the remaining rows for that URL or the cycle. Failures are counted in `counters`, logged in their own category with service id and attempted status, and retried next cycle (#313) +- HTTP 406 rows now carry `error_message = 'HTTP 406: provider rejected request format before paywall'` (#313) - `publish-mcp.yml`: Added `npm_check` guard to skip npm publish when the tagged version already exists on the registry, preventing E403 failures on re-triggered workflows (#248) - `mcp-server/src/index.ts`: `fetchJson` now retries on 5xx responses (2 attempts by default, 500ms backoff, configurable via `FETCH_RETRIES` env var) — transparent to callers, no breaking changes - `mcp-server/src/index.ts`: `FETCH_RETRIES` env var now handles non-finite / negative inputs safely, falling back to default 2 attempts instead of throwing diff --git a/scripts/healthcheck.js b/scripts/healthcheck.js index 8565ce8..656ec2e 100644 --- a/scripts/healthcheck.js +++ b/scripts/healthcheck.js @@ -1,8 +1,9 @@ // Standalone script: npm run healthcheck -import { runHealthChecks } from '../src/health/checker.js' +import { runHealthChecks, formatCycleSummary } from '../src/health/checker.js' async function main() { - await runHealthChecks() + const result = await runHealthChecks() + console.log(`[healthcheck] ${formatCycleSummary(result)}`) process.exit(0) } diff --git a/src/db.js b/src/db.js index 790c137..3e024cd 100644 --- a/src/db.js +++ b/src/db.js @@ -1,5 +1,5 @@ import Database from 'better-sqlite3' -import { mkdirSync, unlinkSync, existsSync, statSync } from 'fs' +import { mkdirSync, unlinkSync, existsSync, statSync, statfsSync } from 'fs' import { dirname, join } from 'path' import { fileURLToPath } from 'url' import { createRequire } from 'module' @@ -67,6 +67,128 @@ if (process.env.DISABLE_SQLITE_VEC === '1') { console.log(`[db] SQLITE_VEC_AVAILABLE=${SQLITE_VEC_AVAILABLE}`) export { SQLITE_VEC_AVAILABLE } +// ─── health_checks status enum: the single source of truth ─────────────────── +// +// Every copy of this enum derives from this array: the CREATE TABLE below, the migration that +// rebuilds an older table, and test/helpers/test-db.js. Three hand-maintained copies is how +// `not_acceptable` — emitted by classifyHealthStatus for HTTP 406 — ended up rejected by the +// CHECK constraint on every write, silently, for ~10 endpoints per cycle. + +export const HEALTH_CHECK_STATUSES = [ + 'healthy', 'degraded', 'down', 'timeout', 'error', 'rate_limited', 'method_not_allowed', 'not_acceptable', +] + +/** health_checks columns, in canonical order. Used for explicit-column copies during rebuilds. */ +export const HEALTH_CHECK_COLUMNS = [ + 'id', 'service_id', 'checked_at', 'status', 'response_time_ms', 'http_status', 'error_message', +] + +const HEALTH_CHECK_RETENTION_DAYS = 3 + +/** + * Generate the health_checks DDL from HEALTH_CHECK_STATUSES. + * @param {string} [tableName='health_checks'] - Target table name (the rebuild uses health_checks_new) + * @param {object} [options] + * @param {boolean} [options.ifNotExists=false] - Emit CREATE TABLE IF NOT EXISTS + * @returns {string} CREATE TABLE statement + */ +export function healthChecksTableDDL(tableName = 'health_checks', { ifNotExists = false } = {}) { + const allowed = HEALTH_CHECK_STATUSES.map(s => `'${s}'`).join(', ') + return `CREATE TABLE ${ifNotExists ? 'IF NOT EXISTS ' : ''}${tableName} ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + service_id TEXT NOT NULL REFERENCES services(id), + checked_at TEXT NOT NULL DEFAULT (datetime('now')), + status TEXT NOT NULL CHECK(status IN (${allowed})), + response_time_ms INTEGER, + http_status INTEGER, + error_message TEXT + )` +} + +// ─── counters: durable, never-pruned key/value aggregates ─────────────────── +// +// Lives in the DB so it is transactional with the writes it counts, visible from both the server +// process and scripts/healthcheck.js, and survives deploys. No retention is ever applied here. + +export const COUNTERS_TABLE_DDL = ` + CREATE TABLE IF NOT EXISTS counters ( + key TEXT PRIMARY KEY, + value TEXT, + updated_at TEXT NOT NULL DEFAULT (datetime('now')) + ) +` + +export const COUNTER_KEYS = { + MCP_QUERIES_LIFETIME: 'mcp_queries_lifetime', + MCP_COUNTER_SEEDED_AT: 'mcp_counter_seeded_at', + HEALTH_WRITE_FAILURES: 'health_write_failures_lifetime', + HEALTH_SCHEMA_INVALID: 'health_schema_invalid', + // Set only when the schema state could not be determined (a lock, most often). Kept apart from + // HEALTH_SCHEMA_INVALID so a transient failure cannot cry wolf on a healthy schema. + HEALTH_SCHEMA_PROBE_ERROR: 'health_schema_probe_error', + LAST_HEALTH_CYCLE: 'last_health_cycle', +} + +export function ensureCountersTable(database = db) { + database.exec(COUNTERS_TABLE_DDL) +} + +/** @returns {string|null} raw counter value, or null when unset. */ +export function getCounter(key, database = db) { + try { + const row = database.prepare('SELECT value FROM counters WHERE key = ?').get(key) + return row?.value ?? null + } catch { + return null + } +} + +/** @returns {number} counter value as a number, 0 when unset or non-numeric. */ +export function getCounterInt(key, database = db) { + const raw = getCounter(key, database) + const parsed = Number(raw) + return Number.isFinite(parsed) ? parsed : 0 +} + +export function setCounter(key, value, database = db) { + try { + database.prepare(` + INSERT INTO counters (key, value, updated_at) VALUES (?, ?, datetime('now')) + ON CONFLICT(key) DO UPDATE SET value = excluded.value, updated_at = excluded.updated_at + `).run(key, value == null ? null : String(value)) + } catch (err) { + console.error(`[db] counter ${key} write failed: ${err.message}`) + } +} + +/** Remove a single key. This is key management, not retention — counters are never aged out. */ +export function deleteCounter(key, database = db) { + try { + database.prepare('DELETE FROM counters WHERE key = ?').run(key) + } catch (err) { + console.error(`[db] counter ${key} delete failed: ${err.message}`) + } +} + +/** @returns {number|null} the new value, or null if the increment failed. */ +export function incrementCounter(key, delta = 1, database = db) { + try { + const row = database.prepare(` + INSERT INTO counters (key, value, updated_at) VALUES (@key, CAST(@delta AS TEXT), datetime('now')) + ON CONFLICT(key) DO UPDATE SET + value = CAST(CAST(COALESCE(counters.value, '0') AS INTEGER) + @delta AS TEXT), + updated_at = datetime('now') + RETURNING value + `).get({ key, delta }) + return row ? Number(row.value) : null + } catch (err) { + console.error(`[db] counter ${key} increment failed: ${err.message}`) + return null + } +} + +db.exec(COUNTERS_TABLE_DDL) + db.exec(` CREATE TABLE IF NOT EXISTS services ( id TEXT PRIMARY KEY, @@ -101,15 +223,7 @@ db.exec(` CREATE INDEX IF NOT EXISTS idx_services_health ON services(health_status); CREATE UNIQUE INDEX IF NOT EXISTS idx_services_url_protocol ON services(url, protocol); - CREATE TABLE IF NOT EXISTS health_checks ( - id INTEGER PRIMARY KEY AUTOINCREMENT, - service_id TEXT NOT NULL REFERENCES services(id), - checked_at TEXT NOT NULL DEFAULT (datetime('now')), - status TEXT NOT NULL CHECK(status IN ('healthy', 'degraded', 'down', 'timeout', 'error', 'rate_limited', 'method_not_allowed')), - response_time_ms INTEGER, - http_status INTEGER, - error_message TEXT - ); + ${healthChecksTableDDL('health_checks', { ifNotExists: true })}; CREATE INDEX IF NOT EXISTS idx_health_checks_service ON health_checks(service_id, checked_at); @@ -325,62 +439,273 @@ try { console.warn(`[db] Homepage cleanup note: ${err.message}`) } -// Migration: expand health_checks status CHECK constraint to include rate_limited, method_not_allowed -export const HEALTH_CHECK_STATUSES = [ - 'healthy', 'degraded', 'down', 'timeout', 'error', 'rate_limited', 'method_not_allowed', -] +// ─── health_checks status CHECK constraint ────────────────────────────────── + +const SCHEMA_PROBE_SERVICE_ID = '__health_schema_probe__' +const SCHEMA_PROBE_URL = 'https://schema-probe.402index.invalid/probe' /** - * Rebuild health_checks if its status CHECK constraint is missing any allowed value. + * Insert a real (transaction-scoped) services row so the health_checks FK is genuinely satisfied. + * Columns are discovered from the live schema: a hard-coded list would break against the several + * shapes `services` has had, and a fake parent id would fail the FK instead of the CHECK (#304). + */ +function insertSchemaProbeParent(database) { + const values = {} + for (const col of database.pragma("table_info('services')")) { + const required = col.notnull === 1 && col.dflt_value === null + const isKey = col.name === 'id' || col.name === 'url' || col.name === 'protocol' + if (!required && !isKey) continue + + if (col.name === 'id') values.id = SCHEMA_PROBE_SERVICE_ID + else if (col.name === 'url') values.url = SCHEMA_PROBE_URL + else if (col.name === 'protocol') values.protocol = 'L402' + else if (/INT|REAL|NUM|DOUB|FLOA/i.test(col.type || '')) values[col.name] = 0 + else values[col.name] = 'schema-probe' + } + const names = Object.keys(values) + database.prepare( + `INSERT INTO services (${names.join(', ')}) VALUES (${names.map(n => `@${n}`).join(', ')})` + ).run(values) +} + +/** + * The probe could not reach a verdict — distinct from "the schema rejected a status". + * + * Most often a lock: the probe opens a write transaction at import time, so scripts/healthcheck.js + * booting against a mid-write server process can lose the race. That is not evidence of a broken + * enum, and flagging it as one would latch a false alarm until the next deploy. + */ +export class SchemaProbeUnavailableError extends Error { + constructor(message, cause) { + super(message) + this.name = 'SchemaProbeUnavailableError' + this.cause = cause + this.code = cause?.code ?? null + } +} + +// Lock/contention codes: the probe is worth retrying rather than giving up on. +const RETRYABLE_PROBE_CODES = new Set([ + 'SQLITE_BUSY', 'SQLITE_BUSY_SNAPSHOT', 'SQLITE_BUSY_TIMEOUT', + 'SQLITE_LOCKED', 'SQLITE_LOCKED_SHAREDCACHE', 'SQLITE_PROTOCOL', +]) + +const PROBE_ATTEMPTS = 3 +const PROBE_RETRY_MS = 50 + +/** better-sqlite3 is synchronous, so the backoff has to be too. */ +function sleepSync(ms) { + Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, ms) +} + +function probeHealthCheckStatusesOnce(database) { + const rejected = [] + let began = false + try { + database.exec('BEGIN') + began = true + insertSchemaProbeParent(database) + const insert = database.prepare('INSERT INTO health_checks (service_id, status) VALUES (?, ?)') + for (const status of HEALTH_CHECK_STATUSES) { + try { + insert.run(SCHEMA_PROBE_SERVICE_ID, status) + } catch (err) { + if (err.code === 'SQLITE_CONSTRAINT_CHECK') rejected.push(status) + else throw err + } + } + } finally { + if (began) database.exec('ROLLBACK') + } + return rejected +} + +/** + * Which canonical statuses the current health_checks CHECK constraint refuses. * - * Detection reads the stored CREATE TABLE text rather than probing with an INSERT: a probe - * insert always fails under `foreign_keys = ON` (the fake service_id has no parent row), which - * made this migration re-run on every boot and rewrite the whole table each time. + * Positive insertability probe rather than DDL substring matching: the stored CREATE TABLE text + * can mention a status without allowing it (a column default, a comment), and only an INSERT + * proves a write will land. Runs inside BEGIN ... ROLLBACK with a real parent row, so it leaves + * nothing behind and cannot fail on the services foreign key. * - * The rebuild runs in one transaction and drops any leftover health_checks_new first, so a run - * killed part-way (SQLITE_FULL, restart) cannot wedge every later boot. + * Only a CHECK violation is a verdict. Anything else means the probe could not run, is retried + * while it looks like contention, and finally surfaces as SchemaProbeUnavailableError — never as + * a rejected status. + * + * @returns {string[]} statuses the constraint rejects (empty when the table is current) + * @throws {SchemaProbeUnavailableError} when the probe could not reach a verdict + */ +export function probeHealthCheckStatuses(database = db, { attempts = PROBE_ATTEMPTS, retryMs = PROBE_RETRY_MS } = {}) { + let lastError + for (let attempt = 1; attempt <= attempts; attempt++) { + try { + return probeHealthCheckStatusesOnce(database) + } catch (err) { + lastError = err + if (attempt < attempts && RETRYABLE_PROBE_CODES.has(err.code)) { + sleepSync(retryMs * attempt) + continue + } + break + } + } + throw new SchemaProbeUnavailableError( + `health_checks status probe could not run: ${lastError?.message ?? 'unknown error'}`, + lastError + ) +} + +/** Bytes currently occupied by health_checks and its index (whole-DB size as a safe upper bound). */ +export function estimateHealthChecksBytes(database = db) { + try { + const row = database.prepare( + "SELECT SUM(pgsize) AS bytes FROM dbstat WHERE name IN ('health_checks', 'idx_health_checks_service')" + ).get() + if (row?.bytes) return row.bytes + } catch { + // dbstat not compiled in — fall back to the whole-file size, which over-estimates (safe). + } + const pageCount = database.pragma('page_count', { simple: true }) || 0 + const pageSize = database.pragma('page_size', { simple: true }) || 0 + return pageCount * pageSize +} + +/** A table rebuild needs room for a second copy. Refuse to start without it. */ +function assertSpaceForRebuild(database, statfsSyncFn, logger) { + const needed = Math.max(estimateHealthChecksBytes(database) * 2, 1) + let free + try { + const stats = statfsSyncFn(dirname(DB_PATH)) + free = stats.bfree * stats.bsize + } catch (err) { + logger.log(`[db] Could not check free space before health_checks rebuild: ${err.message} — continuing`) + return + } + if (free < needed) { + throw new Error(`insufficient free space for health_checks rebuild: need ${needed} bytes, ${free} free`) + } +} + +/** + * Rebuild health_checks when its status CHECK constraint refuses a canonical status. + * + * Prunes past retention first, refuses to start without room for a second copy, copies with an + * explicit column list (a positional `SELECT *` silently shuffles values between columns when the + * old table's column order differs), and verifies foreign keys before committing. Any failure + * rolls back: the original table stays intact and queryable, and a leftover _new table from a + * killed run is cleared on the next attempt. * * @returns {boolean} true if the table was rebuilt, false if it was already current. + * @throws when the rebuild cannot complete — callers must surface it, never swallow it. */ -export function migrateHealthChecksStatusConstraint(database = db) { +export function migrateHealthChecksStatusConstraint(database = db, { statfsSyncFn = statfsSync, logger = console } = {}) { const table = database.prepare( "SELECT sql FROM sqlite_master WHERE type = 'table' AND name = 'health_checks'" ).get() if (!table) return false - const missing = HEALTH_CHECK_STATUSES.filter(s => !table.sql.includes(`'${s}'`)) + const missing = probeHealthCheckStatuses(database) if (missing.length === 0) return false - console.log(`[db] Migrating health_checks status CHECK constraint (missing: ${missing.join(', ')})...`) - const rebuild = database.transaction(() => { - database.exec('DROP TABLE IF EXISTS health_checks_new') - database.exec(` - CREATE TABLE health_checks_new ( - id INTEGER PRIMARY KEY AUTOINCREMENT, - service_id TEXT NOT NULL REFERENCES services(id), - checked_at TEXT NOT NULL DEFAULT (datetime('now')), - status TEXT NOT NULL CHECK(status IN (${HEALTH_CHECK_STATUSES.map(s => `'${s}'`).join(', ')})), - response_time_ms INTEGER, - http_status INTEGER, - error_message TEXT - ); - INSERT INTO health_checks_new SELECT * FROM health_checks; - DROP TABLE health_checks; - ALTER TABLE health_checks_new RENAME TO health_checks; - CREATE INDEX IF NOT EXISTS idx_health_checks_service ON health_checks(service_id, checked_at); - `) - }) - rebuild() - console.log('[db] health_checks CHECK constraint updated') + logger.log(`[db] Migrating health_checks status CHECK constraint (rejected: ${missing.join(', ')})...`) + + const pruned = database.prepare( + "DELETE FROM health_checks WHERE checked_at < datetime('now', ?)" + ).run(`-${HEALTH_CHECK_RETENTION_DAYS} days`) + if (pruned.changes > 0) { + logger.log(`[db] Pruned ${pruned.changes} health checks past retention before rebuild`) + } + + assertSpaceForRebuild(database, statfsSyncFn, logger) + + const columns = HEALTH_CHECK_COLUMNS.join(', ') + // FK enforcement must be off for the DROP/RENAME dance, and cannot be toggled inside a + // transaction — same pattern as the services rebuilds above. + database.pragma('foreign_keys = OFF') + try { + const rebuild = database.transaction(() => { + database.exec('DROP TABLE IF EXISTS health_checks_new') + database.exec(healthChecksTableDDL('health_checks_new')) + database.exec(`INSERT INTO health_checks_new (${columns}) SELECT ${columns} FROM health_checks`) + database.exec('DROP TABLE health_checks') + database.exec('ALTER TABLE health_checks_new RENAME TO health_checks') + database.exec('CREATE INDEX IF NOT EXISTS idx_health_checks_service ON health_checks(service_id, checked_at)') + + const violations = database.pragma('foreign_key_check') + if (violations.length > 0) { + throw new Error(`foreign_key_check reported ${violations.length} violation(s) after rebuild`) + } + }) + rebuild() + } finally { + database.pragma('foreign_keys = ON') + } + + logger.log('[db] health_checks CHECK constraint updated') return true } -try { - migrateHealthChecksStatusConstraint(db) -} catch (err) { - console.warn(`[db] health_checks migration note: ${err.message}`) +/** + * Boot-time guard: migrate health_checks if needed, then prove every canonical status is writable. + * + * Failure is loud. It sets counters.health_schema_invalid=1 (surfaced by the digest) and logs at + * error level; the probe re-runs every boot, so a broken schema keeps complaining until it is + * fixed. The previous console.warn swallow is gone — a silenced schema failure is exactly how + * ~10 endpoints per cycle lost their status writes unnoticed. + * + * health_schema_invalid means one thing only: the probe returned a non-empty rejected list. A + * probe that could not run gets health_schema_probe_error instead. An alarm that fires on a + * transient lock is one that gets ignored, which would defeat the point of raising it at all. + * + * @returns {{migrated: boolean, valid: boolean, indeterminate: boolean, missing: string[], error?: string}} + */ +export function runHealthChecksSchemaGuard(database = db, { logger = console, statfsSyncFn = statfsSync } = {}) { + try { + ensureCountersTable(database) + } catch (err) { + logger.error(`[db] counters table unavailable: ${err.message}`) + } + + let migrated = false + let migrationError = null + try { + migrated = migrateHealthChecksStatusConstraint(database, { statfsSyncFn, logger }) + } catch (err) { + migrationError = err + if (err instanceof SchemaProbeUnavailableError) { + logger.error(`[db] health_checks schema state could not be determined: ${err.message}`) + } else { + logger.error(`[db] health_checks status migration FAILED — health writes may be rejected: ${err.message}`) + } + } + + let missing + try { + missing = probeHealthCheckStatuses(database) + } catch (err) { + const detail = migrationError && migrationError !== err + ? `${err.message} (after migration failure: ${migrationError.message})` + : err.message + logger.error(`[db] health_checks schema probe could not run: ${detail}`) + setCounter(COUNTER_KEYS.HEALTH_SCHEMA_PROBE_ERROR, detail, database) + return { migrated, valid: false, indeterminate: true, missing: [], error: detail } + } + + if (missing.length > 0) { + logger.error(`[db] health_checks CHECK still rejects: ${missing.join(', ')} — those health writes will fail`) + setCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID, '1', database) + deleteCounter(COUNTER_KEYS.HEALTH_SCHEMA_PROBE_ERROR, database) + return { migrated, valid: false, indeterminate: false, missing, error: migrationError?.message } + } + + // Determinately writable: clear both flags, including one left by an earlier locked boot. + deleteCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID, database) + deleteCounter(COUNTER_KEYS.HEALTH_SCHEMA_PROBE_ERROR, database) + return { migrated, valid: true, indeterminate: false, missing: [] } } +runHealthChecksSchemaGuard(db) + // Migration: add domain_verified flag (protects provider edits from poller overwrite) try { db.exec('ALTER TABLE services ADD COLUMN domain_verified INTEGER DEFAULT 0') @@ -917,15 +1242,92 @@ const logQueryStmt = db.prepare( 'INSERT INTO query_log (query_text, filters, result_count, response_time_ms, user_agent, degraded_reason) VALUES (@queryText, @filters, @resultCount, @responseTimeMs, @userAgent, @degradedReason)' ) +/** query_log retention. The 90d window fields are named for it; the lifetime counter outlives it. */ +export const MCP_QUERY_LOG_RETENTION_DAYS = 90 + +const MCP_USER_AGENT_MARKER = '402index-mcp' + +/** + * The SQL half of the MCP predicate, shared by every window query. + * + * User-Agent is fully client-controlled, and the two halves used to disagree: JS `includes` is + * case-sensitive while SQL `LIKE` is case-insensitive for ASCII, so `402Index-MCP` landed in + * mcp_queries_90d but never in mcp_queries_lifetime — two fields in one payload counting the same + * events by different rules. Both halves now lowercase. Interpolates a module constant only. + */ +export const MCP_USER_AGENT_SQL = `instr(lower(user_agent), '${MCP_USER_AGENT_MARKER}') > 0` + +export function isMcpUserAgent(userAgent) { + return typeof userAgent === 'string' && userAgent.toLowerCase().includes(MCP_USER_AGENT_MARKER) +} + +// Throws on failure (unlike incrementCounter) so the enclosing transaction rolls back: the +// query row and the lifetime counter move together or not at all. +const bumpMcpLifetimeStmt = db.prepare(` + INSERT INTO counters (key, value, updated_at) VALUES (@key, '1', datetime('now')) + ON CONFLICT(key) DO UPDATE SET + value = CAST(CAST(COALESCE(counters.value, '0') AS INTEGER) + 1 AS TEXT), + updated_at = datetime('now') +`) + +const logQueryTxn = db.transaction(params => { + logQueryStmt.run(params) + if (isMcpUserAgent(params.userAgent)) { + bumpMcpLifetimeStmt.run({ key: COUNTER_KEYS.MCP_QUERIES_LIFETIME }) + } +}) + export function logQuery({ queryText = null, filters = null, resultCount = null, responseTimeMs = null, userAgent = null, degradedReason = null } = {}) { try { - logQueryStmt.run({ queryText, filters, resultCount, responseTimeMs, userAgent, degradedReason }) + logQueryTxn({ queryText, filters, resultCount, responseTimeMs, userAgent, degradedReason }) } catch (err) { console.warn(`[db] logQuery failed: ${err.message}`) } } -export function pruneQueryLog(retentionDays = 90) { +/** + * MCP traffic inside the query_log retention window. These are window aggregates, not totals — + * naming them so is the point: reporting them as lifetime counts is what made the digest's MCP + * numbers drop whenever the oldest day rolled out. + * + * @returns {{queries: number, activeDays: number}} + */ +export function mcpQueryWindowStats(database = db, retentionDays = MCP_QUERY_LOG_RETENTION_DAYS) { + try { + const row = database.prepare(` + SELECT COUNT(*) AS queries, COUNT(DISTINCT date(timestamp)) AS activeDays + FROM query_log + WHERE ${MCP_USER_AGENT_SQL} + AND timestamp > datetime('now', '-' || @days || ' days') + `).get({ days: retentionDays }) + return { queries: row?.queries ?? 0, activeDays: row?.activeDays ?? 0 } + } catch (err) { + console.warn(`[db] mcpQueryWindowStats failed: ${err.message}`) + return { queries: 0, activeDays: 0 } + } +} + +/** + * Seed the lifetime MCP counter once, from the current window count — the honest floor. Pre-window + * history was deleted by prune and is unrecoverable (daily_snapshots carries no MCP columns), so no + * reconstruction is attempted; the seed timestamp is exposed in the digest to mark the discontinuity. + * + * @returns {boolean} true if this call seeded, false if it was already seeded. + */ +export function seedMcpLifetimeCounter(database = db, retentionDays = MCP_QUERY_LOG_RETENTION_DAYS) { + ensureCountersTable(database) + if (getCounter(COUNTER_KEYS.MCP_COUNTER_SEEDED_AT, database)) return false + + const { queries } = mcpQueryWindowStats(database, retentionDays) + setCounter(COUNTER_KEYS.MCP_QUERIES_LIFETIME, String(queries), database) + setCounter(COUNTER_KEYS.MCP_COUNTER_SEEDED_AT, new Date().toISOString(), database) + console.log(`[db] Seeded ${COUNTER_KEYS.MCP_QUERIES_LIFETIME} from the ${retentionDays}-day window: ${queries}`) + return true +} + +seedMcpLifetimeCounter(db) + +export function pruneQueryLog(retentionDays = MCP_QUERY_LOG_RETENTION_DAYS) { try { const result = db.prepare( "DELETE FROM query_log WHERE timestamp < datetime('now', '-' || ? || ' days')" diff --git a/src/health/checker.js b/src/health/checker.js index bafbae3..ce68fb9 100644 --- a/src/health/checker.js +++ b/src/health/checker.js @@ -3,7 +3,13 @@ import dns from 'dns' import { statfs } from 'fs/promises' import { isIPv4, isIPv6 } from 'net' import { dirname } from 'path' -import db, { DB_PATH } from '../db.js' +import db, { + DB_PATH, + HEALTH_CHECK_STATUSES, + COUNTER_KEYS, + incrementCounter, + setCounter, +} from '../db.js' import { parseWwwAuthenticate, isValidMacaroon, isValidInvoice } from '../services/l402-utils.js' import { parsePaymentRequired, parsePaymentRequiredBody, validatePaymentRequirements } from '../services/x402-utils.js' import { detectProtocol, getPrimaryDetection } from '../services/detect-protocol.js' @@ -13,6 +19,23 @@ const TIMEOUT_MS = 5000 const CONCURRENCY = 10 const HEALTH_CHECK_RETENTION_DAYS = 3 +// ─── Uptime semantics, pinned per status ───────────────────────────────────── +// +// Up counts toward numerator and denominator; down toward the denominator only; excluded statuses +// carry no availability signal at all and are left out of both. A 429 means the provider throttled +// our prober — scoring that as downtime punished the most popular endpoints in the index. + +export const UPTIME_UP_STATUSES = ['healthy', 'degraded'] +export const UPTIME_EXCLUDED_STATUSES = ['rate_limited'] +export const UPTIME_DOWN_STATUSES = HEALTH_CHECK_STATUSES.filter( + s => !UPTIME_UP_STATUSES.includes(s) && !UPTIME_EXCLUDED_STATUSES.includes(s) +) + +/** Diagnostic stored with a 406 row: the provider rejected the request before the paywall ran. */ +export const NOT_ACCEPTABLE_MESSAGE = 'HTTP 406: provider rejected request format before paywall' + +const sqlStatusList = statuses => statuses.map(s => `'${s}'`).join(', ') + /** * Check if a resolved IP address is private/reserved. * @param {string|null} ip - IPv4 or IPv6 address to check @@ -125,10 +148,11 @@ const updateService = () => stmt('updateService', ` const getUptime = () => stmt('getUptime', ` SELECT COUNT(*) as total, - SUM(CASE WHEN status IN ('healthy', 'degraded') THEN 1 ELSE 0 END) as up + SUM(CASE WHEN status IN (${sqlStatusList(UPTIME_UP_STATUSES)}) THEN 1 ELSE 0 END) as up FROM health_checks WHERE service_id = ? - AND checked_at > datetime('now', '-3 days') + AND checked_at > datetime('now', '-${HEALTH_CHECK_RETENTION_DAYS} days') + AND status NOT IN (${sqlStatusList(UPTIME_EXCLUDED_STATUSES)}) `) const getRecentLatencies = () => stmt('getRecentLatencies', ` @@ -426,8 +450,45 @@ async function checkFacilitatorReachable(url) { return reachable } +/** Row-level diagnostic for statuses whose HTTP code alone does not explain the failure. */ +function diagnosticMessage(checkStatus, httpStatus) { + if (checkStatus === 'not_acceptable') return NOT_ACCEPTABLE_MESSAGE + if (httpStatus >= 500) return `HTTP ${httpStatus}` + return null +} + +/** + * Run one persist attempt in isolation. + * + * A failed write must not abort the remaining rows for this URL, nor the cycle. Failures are + * counted in the DB (so the count survives restarts and the scripts/healthcheck.js process + * boundary) and reported in their own category — a rejected write is not a probe error. + */ +function persistIsolated(persist, serviceId, payload, { role, protocol, url }, failures) { + try { + persist(serviceId, payload) + return true + } catch (err) { + failures.push({ + category: 'persist', + role, + serviceId, + protocol: protocol || null, + url: url || null, + status: payload.checkStatus ?? null, + error: err.message, + }) + incrementCounter(COUNTER_KEYS.HEALTH_WRITE_FAILURES, 1) + console.error( + `[health] persist failed (${role}) service=${serviceId} protocol=${protocol || '?'} ` + + `status=${payload.checkStatus ?? '?'} url=${url || '?'}: ${err.message}` + ) + return false + } +} + /** Persist health check result and update service record. */ -function persistHealthResult(serviceId, { checkStatus, healthStatus, httpStatus, responseTimeMs, errorMessage, consecutiveFailures, consecutiveLatencySpikes, historicalP50, registeredAt, x402PaymentValid, x402FacilitatorReachable, x402AssetKnown, l402Compliant, l402DegradeReason, l402Format, lngetCompatible }) { +export function persistHealthResult(serviceId, { checkStatus, healthStatus, httpStatus, responseTimeMs, errorMessage, consecutiveFailures, consecutiveLatencySpikes, historicalP50, registeredAt, x402PaymentValid, x402FacilitatorReachable, x402AssetKnown, l402Compliant, l402DegradeReason, l402Format, lngetCompatible }) { try { // Read current status before update (for event emission) const oldStatus = db.prepare('SELECT health_status FROM services WHERE id = ?').get(serviceId)?.health_status @@ -437,7 +498,7 @@ function persistHealthResult(serviceId, { checkStatus, healthStatus, httpStatus, status: checkStatus, response_time_ms: responseTimeMs, http_status: httpStatus, - error_message: errorMessage || (httpStatus >= 500 ? `HTTP ${httpStatus}` : null), + error_message: errorMessage || diagnosticMessage(checkStatus, httpStatus), }) const newP50 = errorMessage ? (historicalP50 || null) : (calculateP50(serviceId) ?? responseTimeMs) @@ -649,15 +710,35 @@ export function detectProtocolChanges(url, serviceId, protocol, allDetections, h const getSiblings = () => stmt('getSiblings', "SELECT id, url, protocol, http_method, probe_body, latency_p50_ms, consecutive_failures, consecutive_latency_spikes, registered_at, x402_payment_valid, probe_status FROM services WHERE url = ? AND id != ? AND (status = 'active' OR status IS NULL) AND (provider_deleted = 0 OR provider_deleted IS NULL)") -/** Check a single service: HTTP probe, classify result, persist. */ -export async function checkService(service) { +/** + * Check a single service: HTTP probe, classify result, persist. + * + * @param {object} service - Service row + * @param {object} [options] + * @param {Function} [options.persist=persistHealthResult] - Injectable persist (tests) + * @returns {Promise<{id: string, healthStatus: string, httpStatus: number|null, skipReason?: 'unprobeable'|'dedup', + * persisted: boolean, persistFailures: object[], siblingsUpdated: {id: string, protocol: string}[]}>} + */ +export async function checkService(service, { persist = persistHealthResult } = {}) { const { id, url, protocol, http_method, probe_body, latency_p50_ms: historicalP50, consecutive_failures: prevFailures, consecutive_latency_spikes: prevLatencySpikes, x402_payment_valid: currentPaymentValid } = service + const persistFailures = [] + const siblingsUpdated = [] + const skipped = reason => ({ + id, + healthStatus: 'skipped', + httpStatus: null, + skipReason: reason, + persisted: false, + persistFailures, + siblingsUpdated, + }) + // Skip unprobeable services — their health_status is managed via admin endpoint - if (service.probe_status === 'unprobeable') return { id, healthStatus: 'skipped', httpStatus: null } + if (service.probe_status === 'unprobeable') return skipped('unprobeable') // Dedup guard: skip if already checked by a sibling in this cycle - if (checkedThisCycle.has(id)) return { id, healthStatus: 'skipped', httpStatus: null } + if (checkedThisCycle.has(id)) return skipped('dedup') checkedThisCycle.add(id) // Per-host rate limiting: wait if we probed this host recently @@ -710,7 +791,7 @@ export async function checkService(service) { // Build protocol-specific fields via extracted helper const protoFields = await buildProtocolFields(protocol, getPrimaryDetection(result.detection, protocol), result, service) - persistHealthResult(id, { + const persisted = persistIsolated(persist, id, { ...classification, httpStatus: result.httpStatus, responseTimeMs: result.responseTimeMs, @@ -721,7 +802,7 @@ export async function checkService(service) { l402DegradeReason: protocol === 'L402' ? (classification.degradeReason?.includes('payment hash') ? classification.degradeReason : null) : null, - }) + }, { role: 'primary', protocol, url }, persistFailures) // ─── Sibling lookup and update ────────────────────────────────────────── const siblings = getSiblings().all(url, id) @@ -747,7 +828,7 @@ export async function checkService(service) { sibling.consecutive_failures || 0, sibling.latency_p50_ms, result.responseTimeMs, sibling.consecutive_latency_spikes || 0 ) - persistHealthResult(sibling.id, { + if (persistIsolated(persist, sibling.id, { ...sibClassification, httpStatus: result.httpStatus, responseTimeMs: result.responseTimeMs, @@ -761,7 +842,9 @@ export async function checkService(service) { l402DegradeReason: null, l402Format: null, lngetCompatible: null, - }) + }, { role: 'sibling', protocol: sibling.protocol, url }, persistFailures)) { + siblingsUpdated.push({ id: sibling.id, protocol: sibling.protocol }) + } } else if (hasSiblingProtocol) { // Sibling's protocol detected — run protocol-specific validation const sibClassification = classifyHealthStatus( @@ -784,7 +867,7 @@ export async function checkService(service) { } const sibProtoFields = await buildProtocolFields(sibling.protocol, siblingDetection, result, sibling) - persistHealthResult(sibling.id, { + if (persistIsolated(persist, sibling.id, { ...sibClassification, httpStatus: result.httpStatus, responseTimeMs: result.responseTimeMs, @@ -795,10 +878,12 @@ export async function checkService(service) { l402DegradeReason: sibling.protocol === 'L402' ? (sibClassification.degradeReason?.includes('payment hash') ? sibClassification.degradeReason : null) : null, - }) + }, { role: 'sibling', protocol: sibling.protocol, url }, persistFailures)) { + siblingsUpdated.push({ id: sibling.id, protocol: sibling.protocol }) + } } else { // Sibling's protocol NOT in detection array — mark degraded - persistHealthResult(sibling.id, { + if (persistIsolated(persist, sibling.id, { healthStatus: 'degraded', checkStatus: 'degraded', httpStatus: result.httpStatus, @@ -815,7 +900,9 @@ export async function checkService(service) { l402DegradeReason: sibling.protocol === 'x402' ? null : 'protocol not detected in probe response', l402Format: null, lngetCompatible: null, - }) + }, { role: 'sibling', protocol: sibling.protocol, url }, persistFailures)) { + siblingsUpdated.push({ id: sibling.id, protocol: sibling.protocol }) + } } } @@ -837,10 +924,17 @@ export async function checkService(service) { console.warn(`[health] Protocol change detection failed for ${url}: ${err.message}`) } - return { id, healthStatus: classification.healthStatus, httpStatus: result.httpStatus } + return { + id, + healthStatus: classification.healthStatus, + httpStatus: result.httpStatus, + persisted, + persistFailures, + siblingsUpdated, + } } -function calculateUptime(serviceId) { +export function calculateUptime(serviceId) { const row = getUptime().get(serviceId) if (!row || row.total === 0) return null return Math.round((row.up / row.total) * 10000) / 10000 @@ -906,15 +1000,165 @@ export async function checkDiskSpace({ statfsFn = statfs, database = db } = {}) } } +// Rows a cycle never probes, classified exactly the way getServices selects them. getServices' +// exclusions are intentional (#236) and unchanged — reconciliation only has to account for them +// honestly, which means mirroring its predicates rather than approximating them. +const ACTIVE_PREDICATE = "(status = 'active' OR status IS NULL) AND (provider_deleted = 0 OR provider_deleted IS NULL)" +const PROBEABLE_PREDICATE = "(probe_status = 'probeable' OR probe_status IS NULL)" + +const emptyProbedBreakdown = () => ({ healthy: 0, degraded: 0, down: 0, unknown: 0, error: 0 }) + +/** + * Every services row as it stood when the cycle started. + * + * Reconciling a cycle-start probe set against end-of-cycle counts is not reconciliation: the + * pollers run on the same hourly interval and insert with status defaulting to 'active', so a + * multi-minute cycle routinely races inserts, deactivations and purges. Buckets are a partition of + * this fixed id set, which is the only thing that can make `unaccounted` reliably 0 — and which + * stops a row deactivated after being probed from landing in two buckets at once. + * + * @returns {{id: string, protocol: string, active: number, unprobeable: number}[]} + */ +export function snapshotServicesForCycle(database = db) { + return database.prepare( + `SELECT id, + COALESCE(protocol, 'unknown') AS protocol, + CASE WHEN ${ACTIVE_PREDICATE} THEN 1 ELSE 0 END AS active, + CASE WHEN ${PROBEABLE_PREDICATE} THEN 0 ELSE 1 END AS unprobeable + FROM services` + ).all() +} + +/** + * Account for every services row carrying each protocol. + * + * The denominator is every row with that protocol in the cycle-start snapshot — the number the + * digest calls "1,218". Buckets partition it: probed (by result status, including unknown and + * error), sibling_updated (deduped but health-updated: checked, never "skipped"), + * skipped_unprobeable, excluded_inactive, and persist_failed. `unaccounted` is the residual and + * must be 0. + * + * Rows that appear or disappear while the cycle runs are reported in their own symmetric counters + * — added_mid_cycle and vanished_mid_cycle — and never folded into the partition, because neither + * one had a full cycle's worth of chances to land in a bucket. + * + * @returns {{byProtocol: Object, vanished: number, added: number}} + */ +function buildReconciliation({ snapshot, probedById, siblingUpdatedIds, persistFailedIds, database = db }) { + const recon = {} + const bucketFor = protocol => { + const key = protocol || 'unknown' + if (!recon[key]) { + recon[key] = { + denominator: 0, + probed: emptyProbedBreakdown(), + probed_total: 0, + sibling_updated: 0, + skipped_unprobeable: 0, + excluded_inactive: 0, + persist_failed: 0, + unaccounted: 0, + added_mid_cycle: 0, + vanished_mid_cycle: 0, + } + } + return recon[key] + } + + // Precedence, applied to a fixed id set so no row can be counted twice: what actually happened + // to the row outranks what the table says about it now. A row probed at 00:05 and deactivated at + // 00:30 was probed — reporting it as excluded_inactive as well is the double-count. + const snapshotIds = new Set() + for (const row of snapshot) { + snapshotIds.add(row.id) + const bucket = bucketFor(row.protocol) + bucket.denominator++ + + if (probedById.has(row.id)) { + const status = probedById.get(row.id) + bucket.probed[status] = (bucket.probed[status] || 0) + 1 + bucket.probed_total++ + } else if (siblingUpdatedIds.has(row.id)) { + bucket.sibling_updated++ + } else if (persistFailedIds.has(row.id)) { + bucket.persist_failed++ + } else if (!row.active) { + bucket.excluded_inactive++ + } else if (row.unprobeable) { + bucket.skipped_unprobeable++ + } + } + + let added = 0 + let vanished = 0 + const endIds = new Set() + for (const row of database.prepare( + "SELECT id, COALESCE(protocol, 'unknown') AS protocol FROM services" + ).all()) { + endIds.add(row.id) + if (!snapshotIds.has(row.id)) { + added++ + bucketFor(row.protocol).added_mid_cycle++ + } + } + for (const row of snapshot) { + if (!endIds.has(row.id)) { + vanished++ + bucketFor(row.protocol).vanished_mid_cycle++ + } + } + + for (const bucket of Object.values(recon)) { + bucket.unaccounted = bucket.denominator - ( + bucket.probed_total + bucket.sibling_updated + bucket.skipped_unprobeable + + bucket.excluded_inactive + bucket.persist_failed + ) + } + + return { byProtocol: recon, vanished, added } +} + +/** + * One-line cycle summary, shared by both callers so the scheduler and scripts/healthcheck.js + * report identically. + * @param {object} result - runHealthChecks() return value + * @returns {string} + */ +export function formatCycleSummary(result) { + const recon = result?.reconciliation || {} + const unaccounted = Object.values(recon).reduce((sum, r) => sum + (r.unaccounted || 0), 0) + const perProtocol = Object.entries(recon).map(([proto, r]) => + `${proto}[denominator=${r.denominator} probed=${r.probed_total} sibling_updated=${r.sibling_updated} ` + + `unprobeable=${r.skipped_unprobeable} inactive=${r.excluded_inactive} ` + + `persist_failed=${r.persist_failed} unaccounted=${r.unaccounted}]` + ).join(' ') + + return [ + `cycle: healthy=${result?.healthy ?? 0} degraded=${result?.degraded ?? 0} down=${result?.down ?? 0}`, + `unknown=${result?.unknown ?? 0} error=${result?.error ?? 0}`, + `persist_failed=${result?.persistFailed ?? 0} unaccounted=${unaccounted}`, + `added_mid_cycle=${result?.cycle?.added_mid_cycle ?? 0} vanished_mid_cycle=${result?.cycle?.vanished_mid_cycle ?? 0}`, + perProtocol, + ].join(' ').trim() +} + /** * Run health checks for all services (prunes old records first). - * @returns {Promise<{healthy: number, degraded: number, down: number, unknown: number, error: number}>} Counts by status + * + * @param {object} [options] + * @param {number} [options.concurrency=10] - Endpoints probed in parallel per batch + * @returns {Promise<{healthy: number, degraded: number, down: number, unknown: number, error: number, + * skipped: number, persistFailed: number, byProtocol: object, reconciliation: object, + * persistFailures: object[], cycle: object|null}>} */ -export async function runHealthChecks() { +export async function runHealthChecks({ concurrency = CONCURRENCY } = {}) { // Check disk space — skip run if volume is too full const diskCheck = await checkDiskSpace() if (diskCheck === 'skip') { - return { healthy: 0, degraded: 0, down: 0, unknown: 0, error: 0 } + return { + healthy: 0, degraded: 0, down: 0, unknown: 0, error: 0, skipped: 0, persistFailed: 0, + byProtocol: {}, reconciliation: {}, persistFailures: [], cycle: null, + } } // Prune old records before running new checks @@ -924,19 +1168,27 @@ export async function runHealthChecks() { hostLastProbe.clear() checkedThisCycle.clear() + // Snapshot first, then select: a row inserted between the two calls is reported as + // added_mid_cycle rather than becoming an unaccounted residual. + const snapshot = snapshotServicesForCycle() + // Shuffle to distribute same-host endpoints across the full check cycle const services = shuffleArray(getServices().all()) console.log(`[health] Checking ${services.length} services...`) - const results = { healthy: 0, degraded: 0, down: 0, unknown: 0, error: 0, skipped: 0 } + const results = { healthy: 0, degraded: 0, down: 0, unknown: 0, error: 0, skipped: 0, persistFailed: 0 } const byProtocol = {} const errors = [] + const persistFailures = [] + const probedById = new Map() // service id → result status bucket + const siblingUpdatedIds = new Set() // deduped rows whose health was updated by a sibling pass + const persistFailedIds = new Set() let checked = 0 const startTime = Date.now() // Process in batches for concurrency control - for (let i = 0; i < services.length; i += CONCURRENCY) { - const batch = services.slice(i, i + CONCURRENCY) + for (let i = 0; i < services.length; i += concurrency) { + const batch = services.slice(i, i + concurrency) const batchResults = await Promise.allSettled( batch.map(s => checkService(s)) ) @@ -947,19 +1199,33 @@ export async function runHealthChecks() { const service = batch[j] const proto = service.protocol || 'unknown' - if (!byProtocol[proto]) byProtocol[proto] = { healthy: 0, degraded: 0, down: 0, unknown: 0, error: 0 } + if (!byProtocol[proto]) byProtocol[proto] = emptyProbedBreakdown() if (result.status === 'fulfilled') { const status = result.value.healthStatus + + for (const sibling of result.value.siblingsUpdated || []) { + siblingUpdatedIds.add(sibling.id) + } + + for (const failure of result.value.persistFailures || []) { + persistFailures.push(failure) + persistFailedIds.add(failure.serviceId) + results.persistFailed++ + } + if (status === 'skipped') { results.skipped++ - } else { + } else if (result.value.persisted) { results[status] = (results[status] || 0) + 1 byProtocol[proto][status] = (byProtocol[proto][status] || 0) + 1 + probedById.set(service.id, status) } + // A probed row whose write was rejected is reported under persist_failed, not as a result. } else { results.error++ byProtocol[proto].error++ + probedById.set(service.id, 'error') if (errors.length < 10) { errors.push({ url: service.url, protocol: proto, error: result.reason?.message || 'unknown' }) } @@ -972,11 +1238,57 @@ export async function runHealthChecks() { } const durationSec = ((Date.now() - startTime) / 1000).toFixed(1) + const { byProtocol: reconciliation, vanished, added } = buildReconciliation({ + snapshot, probedById, siblingUpdatedIds, persistFailedIds, + }) + const unaccounted = Object.values(reconciliation).reduce((sum, r) => sum + r.unaccounted, 0) + + const cycle = { + finished_at: new Date().toISOString(), + duration_sec: Number(durationSec), + concurrency, + dispatched: services.length, + results: { ...results }, + persist_failed: results.persistFailed, + unaccounted, + // The two directions the table can move under a running cycle. Reported, never folded into the + // snapshot's partition — that is what keeps `unaccounted` an integrity signal instead of noise. + vanished_mid_cycle: vanished, + added_mid_cycle: added, + by_protocol: reconciliation, + } + if (vanished > 0 || added > 0) { + console.log( + `[health] table changed under the cycle: ${added} row(s) added, ${vanished} row(s) deleted — ` + + 'reported separately, outside the cycle-start denominator' + ) + } + + // Written from whichever process ran the cycle, so the digest reports the real last cycle. + setCounter(COUNTER_KEYS.LAST_HEALTH_CYCLE, JSON.stringify(cycle)) + console.log(`[health] Done in ${durationSec}s. healthy=${results.healthy} degraded=${results.degraded} down=${results.down} unknown=${results.unknown}`) - // Per-protocol breakdown - for (const [proto, counts] of Object.entries(byProtocol)) { - console.log(`[health] ${proto}: healthy=${counts.healthy} degraded=${counts.degraded} down=${counts.down}`) + // Per-protocol reconciliation — the full breakdown, not just healthy/degraded/down + for (const [proto, r] of Object.entries(reconciliation)) { + console.log( + `[health] ${proto}: denominator=${r.denominator} probed=${r.probed_total} ` + + `(healthy=${r.probed.healthy} degraded=${r.probed.degraded} down=${r.probed.down} ` + + `unknown=${r.probed.unknown} error=${r.probed.error}) sibling_updated=${r.sibling_updated} ` + + `skipped_unprobeable=${r.skipped_unprobeable} excluded_inactive=${r.excluded_inactive} ` + + `persist_failed=${r.persist_failed} unaccounted=${r.unaccounted} ` + + `added_mid_cycle=${r.added_mid_cycle} vanished_mid_cycle=${r.vanished_mid_cycle}` + ) + } + + // Persist failures are their own category — never folded into the probe-error count + if (persistFailures.length > 0) { + const shown = persistFailures.slice(0, 10) + const truncated = persistFailures.length > shown.length ? ' — list truncated' : '' + console.error(`[health] Persist failures (${persistFailures.length} total, showing ${shown.length}${truncated}):`) + for (const f of shown) { + console.error(`[health] ${f.role} ${f.protocol || '?'} service=${f.serviceId} status=${f.status}: ${f.error}`) + } } // First N errors for debugging @@ -987,5 +1299,5 @@ export async function runHealthChecks() { } } - return results + return { ...results, byProtocol, reconciliation, persistFailures, cycle } } diff --git a/src/routes/api/digest.js b/src/routes/api/digest.js index 0513ed9..42ece46 100644 --- a/src/routes/api/digest.js +++ b/src/routes/api/digest.js @@ -1,5 +1,12 @@ import { Router } from 'express' -import db from '../../db.js' +import db, { + COUNTER_KEYS, + MCP_QUERY_LOG_RETENTION_DAYS, + MCP_USER_AGENT_SQL, + getCounter, + getCounterInt, + mcpQueryWindowStats, +} from '../../db.js' const router = Router() @@ -93,14 +100,17 @@ router.get('/digest', (req, res) => { "SELECT COUNT(DISTINCT user_agent) as c FROM query_log WHERE timestamp > date('now')" ).get().c + // Same predicate as the lifetime increment and the 90d window — one rule, three fields. const mcpToday = db.prepare( - "SELECT COUNT(*) as c FROM query_log WHERE timestamp > date('now') AND user_agent LIKE '%402index-mcp%'" + `SELECT COUNT(*) as c FROM query_log WHERE timestamp > date('now') AND ${MCP_USER_AGENT_SQL}` ).get().c - const mcpSummary = db.prepare( - `SELECT COUNT(*) as total, COUNT(DISTINCT date(timestamp)) as activeDays - FROM query_log WHERE user_agent LIKE '%402index-mcp%'` - ).get() + // MCP: a true lifetime counter, plus window aggregates named for the window they cover. + // query_log is pruned at 90 days, so the old "total"/"active_days" fields were rolling + // windows mislabeled as lifetime totals — hence their non-monotonic drops. + const mcpWindow = mcpQueryWindowStats(db, MCP_QUERY_LOG_RETENTION_DAYS) + const mcpLifetime = getCounterInt(COUNTER_KEYS.MCP_QUERIES_LIFETIME) + const mcpSeededAt = getCounter(COUNTER_KEYS.MCP_COUNTER_SEEDED_AT) // ── Search Intelligence ── const topSearches = db.prepare( @@ -166,6 +176,31 @@ router.get('/digest', (req, res) => { ORDER BY s.last_checked DESC LIMIT 10 `).all() + // ── Health-check integrity ── + // A broken status enum silently drops health writes, so it is surfaced here rather than left + // in a boot log nobody reads. Absent key = healthy schema. + const health = { + write_failures_lifetime: getCounterInt(COUNTER_KEYS.HEALTH_WRITE_FAILURES), + last_cycle: (() => { + const raw = getCounter(COUNTER_KEYS.LAST_HEALTH_CYCLE) + if (!raw) return null + try { + return JSON.parse(raw) + } catch { + return null + } + })(), + } + if (getCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID) === '1') { + health.health_schema_invalid = true + } + // Distinct condition: the boot probe could not reach a verdict (a lock, most often). Surfaced + // so it is visible, but never as a broken-enum alarm. + const schemaProbeError = getCounter(COUNTER_KEYS.HEALTH_SCHEMA_PROBE_ERROR) + if (schemaProbeError) { + health.health_schema_probe_error = schemaProbeError + } + res.json({ generated_at: new Date().toISOString(), totals: { @@ -190,14 +225,25 @@ router.get('/digest', (req, res) => { queries_7d: queries7d, unique_agents_today: uniqueAgentsToday, mcp_queries_today: mcpToday, - mcp_queries_total: mcpSummary.total, - mcp_active_days: mcpSummary.activeDays, + mcp_queries_lifetime: mcpLifetime, + mcp_queries_total: mcpLifetime, + mcp_counter_seeded_at: mcpSeededAt, + mcp_queries_90d: mcpWindow.queries, + mcp_active_days_90d: mcpWindow.activeDays, + // Deprecated: emits the 90d value for one release so the 5:30am consumer keeps working. + mcp_active_days: mcpWindow.activeDays, + mcp_active_days_deprecated: true, + // The only gate on these counters is a client-controlled User-Agent substring, and the + // lifetime total is never pruned — so it is a ceiling, not a measurement. Said here rather + // than left for a reader to infer. + mcp_counters_ua_attested: true, }, search_intelligence: { top_searches_7d: topSearches, zero_results_7d: zeroResults, top_user_agents_7d: topAgents, }, + health, health_changes: { newly_degraded_24h: newlyDegraded, newly_down_24h: newlyDown, diff --git a/src/scheduler.js b/src/scheduler.js index 95fa37c..25827b1 100644 --- a/src/scheduler.js +++ b/src/scheduler.js @@ -6,7 +6,7 @@ import { pollSponge } from './aggregators/sponge.js' import { pollL402Directory } from './aggregators/l402directory.js' import { pollMPP } from './aggregators/mpp.js' import { pollMppscan } from './aggregators/mppscan.js' -import { runHealthChecks } from './health/checker.js' +import { runHealthChecks, formatCycleSummary } from './health/checker.js' import { classifyServices } from './services/classify.js' import { captureSnapshot } from './services/daily-snapshot.js' @@ -81,7 +81,10 @@ function runHealthCheckGuarded() { if (healthCheckRunning) return healthCheckRunning = true runHealthChecks() - .then(() => runDailySnapshot()) + .then(result => { + console.log(`[scheduler] ${formatCycleSummary(result)}`) + return runDailySnapshot() + }) .catch(err => console.error('[scheduler] Health check failed:', err.message)) .finally(() => { healthCheckRunning = false }) } diff --git a/test/digest-health-mcp-fields.test.js b/test/digest-health-mcp-fields.test.js new file mode 100644 index 0000000..9c9c39b --- /dev/null +++ b/test/digest-health-mcp-fields.test.js @@ -0,0 +1,103 @@ +/** + * Digest health + MCP counter fields (#313 Part A.1, B.3, C.3). + * + * The digest is the 5:30am consumer's only view of health-check integrity: a schema flag when the + * status enum is broken, the DB-backed write-failure count, and a per-protocol reconciliation with + * unaccounted = 0. MCP window fields are named for what they are; the lifetime counter is separate. + * + * Separate file from digest-endpoint.test.js so it gets its own 10/hour rate-limit budget. + * + * Run: node --test test/digest-health-mcp-fields.test.js + */ + +import { describe, it, before, after } from 'node:test' +import assert from 'node:assert/strict' +import { startServer, stopServer } from './helpers/server.js' + +let BASE = process.env.API_BASE +let API +const DIGEST_KEY = process.env.DIGEST_API_KEY || 'test-digest-key' + +let body + +before(async () => { + BASE = BASE || await startServer() + API = `${BASE}/api/v1` + const res = await fetch(`${API}/digest`, { headers: { Authorization: `Bearer ${DIGEST_KEY}` } }) + assert.equal(res.status, 200) + body = await res.json() +}) +after(async () => { await stopServer() }) + +describe('digest traffic: MCP counters', () => { + it('reports the lifetime counter, not a rolling window, as the total', () => { + assert.ok('mcp_queries_lifetime' in body.traffic, 'missing mcp_queries_lifetime') + assert.equal(typeof body.traffic.mcp_queries_lifetime, 'number') + assert.equal( + body.traffic.mcp_queries_total, body.traffic.mcp_queries_lifetime, + 'mcp_queries_total is redefined as the lifetime counter' + ) + }) + + it('labels the window fields as 90-day windows', () => { + assert.ok('mcp_queries_90d' in body.traffic, 'missing mcp_queries_90d') + assert.ok('mcp_active_days_90d' in body.traffic, 'missing mcp_active_days_90d') + assert.equal(typeof body.traffic.mcp_queries_90d, 'number') + assert.equal(typeof body.traffic.mcp_active_days_90d, 'number') + }) + + it('keeps mcp_active_days for one release with a deprecation flag', () => { + assert.equal(body.traffic.mcp_active_days, body.traffic.mcp_active_days_90d) + assert.equal(body.traffic.mcp_active_days_deprecated, true) + }) + + it('exposes when the lifetime counter was seeded', () => { + assert.ok(body.traffic.mcp_counter_seeded_at, 'missing mcp_counter_seeded_at') + }) + + it('labels the MCP counters as user-agent attested', () => { + // The only gate on the increment is a client-controlled User-Agent substring, and the counter + // is now permanent rather than self-healing as poisoned rows age out. It is a ceiling, not a + // measurement — the payload has to say so. + assert.equal(body.traffic.mcp_counters_ua_attested, true) + }) + + it('never reports a window larger than the lifetime counter', () => { + assert.ok( + body.traffic.mcp_queries_90d <= body.traffic.mcp_queries_lifetime, + 'the window is a subset of the lifetime total — divergent predicates would break this' + ) + }) +}) + +describe('digest health section', () => { + it('reports the DB-backed write-failure count', () => { + assert.ok(body.health, 'missing health section') + assert.equal(typeof body.health.write_failures_lifetime, 'number') + }) + + it('omits health_schema_invalid when the schema is current', () => { + assert.ok( + !('health_schema_invalid' in body.health), + 'health_schema_invalid must be absent unless the schema is broken' + ) + }) + + it('omits health_schema_probe_error when the probe ran cleanly', () => { + assert.ok( + !('health_schema_probe_error' in body.health), + 'an indeterminate probe is a distinct, separately-surfaced condition' + ) + }) + + it('carries the last cycle reconciliation with per-protocol unaccounted', () => { + assert.ok('last_cycle' in body.health, 'missing health.last_cycle') + const cycle = body.health.last_cycle + if (cycle === null) return // no cycle has run in this process yet + for (const [proto, r] of Object.entries(cycle.by_protocol || {})) { + assert.equal(r.unaccounted, 0, `${proto} must have nothing unaccounted for`) + const sum = r.probed_total + r.sibling_updated + r.skipped_unprobeable + r.excluded_inactive + r.persist_failed + assert.equal(sum + r.unaccounted, r.denominator, `${proto} buckets must sum to the denominator`) + } + }) +}) diff --git a/test/health-cycle-reconciliation.test.js b/test/health-cycle-reconciliation.test.js new file mode 100644 index 0000000..f0b6274 --- /dev/null +++ b/test/health-cycle-reconciliation.test.js @@ -0,0 +1,300 @@ +/** + * Cycle reconciliation (#313 Part B). + * + * The digest's "882 of 1,218 L402 checked" came from a log line that only printed + * healthy/degraded/down. It omitted unknown, error, sibling-deduped rows (whose health_status IS + * updated), and every row getServices deliberately excludes. + * + * This is a reporting defect: probing behavior must not change. The reconciliation buckets must + * partition every services row carrying the protocol, with unaccounted = 0. + * + * Run: node --test test/health-cycle-reconciliation.test.js + */ + +import { describe, it, beforeEach, afterEach, mock } from 'node:test' +import assert from 'node:assert/strict' +import dns from 'dns' +import { readFileSync } from 'fs' +import * as dbModule from '../src/db.js' +import * as checker from '../src/health/checker.js' + +const db = dbModule.default +const { runHealthChecks } = checker + +const TEST_PREFIX = 'test-recon-' + Date.now() +let counter = 0 + +function buildSpecCompliantMacaroon() { + const id = Buffer.alloc(66) + id.writeUInt16BE(0, 0) + id.fill(0xAB, 2, 34) + id.fill(0xCD, 34, 66) + const sig = Buffer.alloc(32, 0xEE) + return Buffer.concat([ + Buffer.from([0x02]), Buffer.from([0x02]), Buffer.from([66]), id, + Buffer.from([0x00]), Buffer.from([0x06]), Buffer.from([32]), sig, Buffer.from([0x00]), + ]).toString('base64') +} +const specCompliantMacaroon = buildSpecCompliantMacaroon() +const longInvoice = 'lnbc1000n1p' + 'a'.repeat(200) + +function makePaymentHeader() { + return Buffer.from(JSON.stringify({ + accepts: [{ + payTo: '0x1234567890abcdef1234567890abcdef12345678', + asset: '0x833589fcd6edb6e08f4c7c32d4f71b54bda02913', + network: 'eip155:8453', + maxAmountRequired: '1000000', + }], + })).toString('base64') +} + +function mockResponse(status, headers = {}) { + return { + status, + ok: status >= 200 && status < 300, + headers: { + get(name) { return headers[name.toLowerCase()] || null }, + entries() { return Object.entries(headers) }, + }, + text: async () => '', + } +} + +function insertTestService(overrides = {}) { + const params = { + id: overrides.id || `${TEST_PREFIX}-${++counter}`, + name: 'Recon Test', + url: overrides.url || `https://${TEST_PREFIX}-${counter}.example.com/api`, + protocol: 'L402', + source: 'test', + status: 'active', + provider_deleted: 0, + probe_status: 'probeable', + deleted_at: null, + ...overrides, + } + db.prepare(` + INSERT INTO services (id, name, url, protocol, source, status, provider_deleted, probe_status, deleted_at, + consecutive_failures, consecutive_latency_spikes) + VALUES (@id, @name, @url, @protocol, @source, @status, @provider_deleted, @probe_status, @deleted_at, 0, 0) + `).run(params) + return params +} + +const originalFetch = globalThis.fetch +let dnsLookupMock + +beforeEach(() => { + dnsLookupMock = mock.method(dns.promises, 'lookup', async () => ({ address: '93.184.216.34' })) + globalThis.fetch = async () => mockResponse(402, { + 'www-authenticate': `L402 macaroon="${specCompliantMacaroon}", invoice="${longInvoice}"`, + 'payment-required': makePaymentHeader(), + }) +}) + +afterEach(() => { + globalThis.fetch = originalFetch + dnsLookupMock.mock.restore() + db.prepare(`DELETE FROM health_checks WHERE service_id LIKE '${TEST_PREFIX}%'`).run() + db.prepare(`DELETE FROM services WHERE id LIKE '${TEST_PREFIX}%'`).run() +}) + +/** + * probed + sibling-deduped + unprobeable + pending + soft-deleted. + * L402 denominator = 5 rows, x402 denominator = 1 row. + */ +function seedFixture() { + const pairUrl = `https://${TEST_PREFIX}-pair.example.com/api` + return { + pairL402: insertTestService({ protocol: 'L402', url: pairUrl }), + pairX402: insertTestService({ protocol: 'x402', url: pairUrl }), + solo: insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-solo.example.com/api` }), + unprobeable: insertTestService({ protocol: 'L402', probe_status: 'unprobeable' }), + pending: insertTestService({ protocol: 'L402', status: 'pending' }), + softDeleted: insertTestService({ protocol: 'L402', provider_deleted: 1, deleted_at: '2026-01-01 00:00:00' }), + } +} + +describe('reconciliation identity', () => { + it('buckets sum to the per-protocol denominator with unaccounted = 0', async () => { + seedFixture() + assert.equal( + db.prepare('SELECT COUNT(*) c FROM services').get().c, 6, + 'fixture must be the whole table for the identity to be meaningful' + ) + + // concurrency 1 makes the sibling dedup deterministic: whichever row of the pair is probed + // first, the other is skipped and updated through the sibling path. + const result = await runHealthChecks({ concurrency: 1 }) + const recon = result.reconciliation + assert.ok(recon, 'runHealthChecks must return a reconciliation') + + for (const [proto, r] of Object.entries(recon)) { + const sum = r.probed_total + r.sibling_updated + r.skipped_unprobeable + r.excluded_inactive + r.persist_failed + assert.equal(sum + r.unaccounted, r.denominator, `${proto} buckets must sum to the denominator`) + assert.equal(r.unaccounted, 0, `${proto} must have nothing unaccounted for`) + } + + assert.equal(recon.L402.denominator, 5, 'every L402 row counts toward the denominator') + assert.equal(recon.x402.denominator, 1) + assert.equal(recon.L402.skipped_unprobeable, 1) + assert.equal(recon.L402.excluded_inactive, 2, 'pending + soft-deleted') + assert.equal(recon.L402.persist_failed, 0) + + const probedTotal = recon.L402.probed_total + recon.x402.probed_total + const siblingTotal = recon.L402.sibling_updated + recon.x402.sibling_updated + assert.equal(probedTotal, 2, 'the solo row plus one row of the deduped pair') + assert.equal(siblingTotal, 1, 'the deduped row is checked, never "skipped"') + }) + + it('breaks probed results down by status including unknown and error', async () => { + seedFixture() + const result = await runHealthChecks({ concurrency: 1 }) + const probed = result.reconciliation.L402.probed + + for (const key of ['healthy', 'degraded', 'down', 'unknown', 'error']) { + assert.ok(key in probed, `probed breakdown must carry ${key}`) + } + assert.equal( + Object.values(probed).reduce((a, b) => a + b, 0), + result.reconciliation.L402.probed_total, + 'probed_total must equal the sum of its breakdown' + ) + }) + + it('counts an unreachable endpoint under probed.unknown, not as a missing row', async () => { + insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-dead.example.com/api` }) + globalThis.fetch = async () => { throw new Error('fetch failed') } + + const recon = (await runHealthChecks({ concurrency: 1 })).reconciliation + assert.equal(recon.L402.probed.unknown, 1) + assert.equal(recon.L402.probed_total, 1) + assert.equal(recon.L402.unaccounted, 0) + }) + + it('excludes a row hard-deleted mid-cycle rather than reporting a negative residual', async () => { + // purgeSoftDeleted runs hourly, so it overlaps health cycles. A row checked and then deleted + // is in no denominator; counting it anyway would make unaccounted negative on a routine purge. + const svc = insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-doomed.example.com/api` }) + globalThis.fetch = async () => { + db.prepare('DELETE FROM services WHERE id = ?').run(svc.id) + return mockResponse(402, { + 'www-authenticate': `L402 macaroon="${specCompliantMacaroon}", invoice="${longInvoice}"`, + }) + } + + const result = await runHealthChecks({ concurrency: 1 }) + + assert.equal(result.cycle.vanished_mid_cycle, 1, 'the deleted row is reported, not silently dropped') + assert.equal(result.cycle.unaccounted, 0) + for (const [proto, r] of Object.entries(result.reconciliation)) { + assert.equal(r.unaccounted, 0, `${proto} residual must stay 0`) + } + }) + + it('does not fold a service inserted mid-cycle into the denominator', async () => { + // The Bazaar/l402directory/MPP pollers share the health cycle's hourly interval and insert + // with services.status defaulting to 'active', so a cycle over ~1,200 endpoints routinely + // overlaps an insert. Counting the newcomer in an end-of-cycle denominator makes unaccounted + // non-zero on ordinary operation — the very number that exists to prove the buckets add up. + insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-incumbent.example.com/api` }) + let inserted = false + globalThis.fetch = async () => { + if (!inserted) { + inserted = true + insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-newcomer.example.com/api` }) + } + return mockResponse(402, { + 'www-authenticate': `L402 macaroon="${specCompliantMacaroon}", invoice="${longInvoice}"`, + }) + } + + const result = await runHealthChecks({ concurrency: 1 }) + const r = result.reconciliation.L402 + + assert.equal(r.denominator, 1, 'the denominator is the cycle-start snapshot, not an end-of-cycle count') + assert.equal(r.probed_total, 1) + assert.equal(r.unaccounted, 0, 'a mid-cycle insert must not show up as a residual') + assert.equal(result.cycle.added_mid_cycle, 1, 'the newcomer is reported, not silently absorbed') + assert.equal(r.added_mid_cycle, 1, 'and attributed to its protocol') + }) + + it('keeps a row deactivated mid-cycle in exactly one bucket', async () => { + // A row probed at cycle start and deactivated before cycle end used to land in BOTH probed and + // excluded_inactive, so the buckets were not a partition and unaccounted went negative. + const svc = insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-demoted.example.com/api` }) + globalThis.fetch = async () => { + db.prepare("UPDATE services SET status = 'pending' WHERE id = ?").run(svc.id) + return mockResponse(402, { + 'www-authenticate': `L402 macaroon="${specCompliantMacaroon}", invoice="${longInvoice}"`, + }) + } + + const r = (await runHealthChecks({ concurrency: 1 })).reconciliation.L402 + + assert.equal(r.denominator, 1) + assert.equal(r.probed_total, 1, 'it was probed — that is the bucket it belongs in') + assert.equal(r.excluded_inactive, 0, 'and it must not also be counted as excluded') + assert.equal(r.unaccounted, 0, 'buckets are a partition, so the residual cannot go negative') + }) + + it('reports both mid-cycle directions in the shared summary', async () => { + insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-summary.example.com/api` }) + const summary = checker.formatCycleSummary(await runHealthChecks({ concurrency: 1 })) + assert.match(summary, /added_mid_cycle=0/, 'the insert direction is reported') + assert.match(summary, /vanished_mid_cycle=0/, 'symmetrically with the delete direction') + }) + + it('does not change which endpoints get probed', async () => { + const fixture = seedFixture() + const probedUrls = new Set() + globalThis.fetch = async (url) => { + probedUrls.add(new URL(url).hostname) + return mockResponse(402, { + 'www-authenticate': `L402 macaroon="${specCompliantMacaroon}", invoice="${longInvoice}"`, + 'payment-required': makePaymentHeader(), + }) + } + + await runHealthChecks({ concurrency: 1 }) + + assert.equal(probedUrls.size, 2, 'only the pair URL and the solo URL are probed') + for (const excluded of [fixture.unprobeable, fixture.pending, fixture.softDeleted]) { + assert.ok(!probedUrls.has(new URL(excluded.url).hostname), `${excluded.id} must not be probed`) + } + }) +}) + +describe('reconciliation persistence and reporting', () => { + it('writes the cycle reconciliation to the counters table', async () => { + seedFixture() + const result = await runHealthChecks({ concurrency: 1 }) + + const raw = dbModule.getCounter('last_health_cycle') + assert.ok(raw, 'counters.last_health_cycle must be written at cycle end') + const stored = JSON.parse(raw) + assert.deepEqual(stored.by_protocol, result.reconciliation) + assert.equal(stored.persist_failed, result.persistFailed) + assert.ok(stored.finished_at, 'the summary must be timestamped') + assert.equal(stored.unaccounted, 0) + }) + + it('formats one summary both callers share', async () => { + seedFixture() + const result = await runHealthChecks({ concurrency: 1 }) + + assert.equal(typeof checker.formatCycleSummary, 'function', 'checker must export formatCycleSummary') + const summary = checker.formatCycleSummary(result) + assert.match(summary, /persist_failed=0/) + assert.match(summary, /unaccounted=0/) + assert.match(summary, /L402/) + }) + + it('both callers report the same reconciliation', () => { + const scheduler = readFileSync(new URL('../src/scheduler.js', import.meta.url), 'utf8') + const script = readFileSync(new URL('../scripts/healthcheck.js', import.meta.url), 'utf8') + assert.match(scheduler, /formatCycleSummary/, 'src/scheduler.js must report the cycle summary') + assert.match(script, /formatCycleSummary/, 'scripts/healthcheck.js must report the cycle summary') + }) +}) diff --git a/test/health-persist-isolation.test.js b/test/health-persist-isolation.test.js new file mode 100644 index 0000000..5b5ce59 --- /dev/null +++ b/test/health-persist-isolation.test.js @@ -0,0 +1,230 @@ +/** + * Per-row persist isolation and the HTTP 406 diagnostic (#313 Part A.5 + A.6). + * + * One row failing its write must not abort the other rows at the same URL, must be counted in a + * DB-backed counter that survives the scripts/healthcheck.js process boundary, and must be + * categorized as a persist failure — not silently folded into the probe-error count. + * + * Run: node --test test/health-persist-isolation.test.js + */ + +import { describe, it, beforeEach, afterEach, mock } from 'node:test' +import assert from 'node:assert/strict' +import dns from 'dns' +import * as dbModule from '../src/db.js' +import * as checker from '../src/health/checker.js' + +const db = dbModule.default +const { checkService, runHealthChecks } = checker + +const TEST_PREFIX = 'test-persist-' + Date.now() +let counter = 0 + +const OLD_STATUS_CHECK = "'healthy', 'degraded', 'down', 'timeout', 'error', 'rate_limited', 'method_not_allowed'" + +function buildSpecCompliantMacaroon() { + const id = Buffer.alloc(66) + id.writeUInt16BE(0, 0) + id.fill(0xAB, 2, 34) + id.fill(0xCD, 34, 66) + const sig = Buffer.alloc(32, 0xEE) + return Buffer.concat([ + Buffer.from([0x02]), Buffer.from([0x02]), Buffer.from([66]), id, + Buffer.from([0x00]), Buffer.from([0x06]), Buffer.from([32]), sig, Buffer.from([0x00]), + ]).toString('base64') +} +const specCompliantMacaroon = buildSpecCompliantMacaroon() +const longInvoice = 'lnbc1000n1p' + 'a'.repeat(200) + +function makePaymentHeader() { + return Buffer.from(JSON.stringify({ + accepts: [{ + payTo: '0x1234567890abcdef1234567890abcdef12345678', + asset: '0x833589fcd6edb6e08f4c7c32d4f71b54bda02913', + network: 'eip155:8453', + maxAmountRequired: '1000000', + }], + })).toString('base64') +} + +function mockResponse(status, headers = {}) { + return { + status, + ok: status >= 200 && status < 300, + headers: { + get(name) { return headers[name.toLowerCase()] || null }, + entries() { return Object.entries(headers) }, + }, + text: async () => '', + } +} + +function insertTestService(overrides = {}) { + const params = { + id: overrides.id || `${TEST_PREFIX}-${++counter}`, + name: 'Persist Test', + url: `https://${TEST_PREFIX}.example.com/api`, + protocol: 'x402', + source: 'test', + status: 'active', + ...overrides, + } + db.prepare(` + INSERT INTO services (id, name, url, protocol, source, status, consecutive_failures, consecutive_latency_spikes) + VALUES (@id, @name, @url, @protocol, @source, @status, 0, 0) + `).run(params) + return { + ...params, + latency_p50_ms: null, + consecutive_failures: 0, + consecutive_latency_spikes: 0, + x402_payment_valid: null, + http_method: null, + probe_body: null, + registered_at: null, + probe_status: 'probeable', + } +} + +const getService = id => db.prepare('SELECT * FROM services WHERE id = ?').get(id) +const getChecks = id => db.prepare('SELECT * FROM health_checks WHERE service_id = ?').all(id) + +const originalFetch = globalThis.fetch +let dnsLookupMock + +beforeEach(() => { + dnsLookupMock = mock.method(dns.promises, 'lookup', async () => ({ address: '93.184.216.34' })) +}) + +afterEach(() => { + globalThis.fetch = originalFetch + dnsLookupMock.mock.restore() + db.prepare(`DELETE FROM health_checks WHERE service_id LIKE '${TEST_PREFIX}%'`).run() + db.prepare(`DELETE FROM services WHERE id LIKE '${TEST_PREFIX}%'`).run() +}) + +describe('HTTP 406 diagnostic', () => { + it('stores a not_acceptable row carrying the pre-paywall-rejection reason', async () => { + const svc = insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-406.example.com/api` }) + globalThis.fetch = async () => mockResponse(406) + + await checkService(svc) + + const checks = getChecks(svc.id) + assert.equal(checks.length, 1, 'the 406 row must actually be written') + assert.equal(checks[0].status, 'not_acceptable') + assert.equal(checks[0].error_message, 'HTTP 406: provider rejected request format before paywall') + assert.equal(getService(svc.id).health_status, 'degraded') + }) +}) + +describe('per-row persist isolation', () => { + it('a primary persist failure still lets the sibling row update', async () => { + const url = `https://${TEST_PREFIX}-iso.example.com/api` + const primary = insertTestService({ protocol: 'L402', url }) + const sibling = insertTestService({ protocol: 'x402', url }) + + globalThis.fetch = async () => mockResponse(402, { + 'www-authenticate': `L402 macaroon="${specCompliantMacaroon}", invoice="${longInvoice}"`, + 'payment-required': makePaymentHeader(), + }) + + const before = dbModule.getCounterInt('health_write_failures_lifetime') + const result = await checkService(primary, { + persist: (serviceId, payload) => { + if (serviceId === primary.id) throw new Error('CHECK constraint failed: health_checks') + return checker.persistHealthResult(serviceId, payload) + }, + }) + + assert.equal(result.persisted, false, 'primary persist failed') + assert.equal(getChecks(primary.id).length, 0, 'no primary row written') + + assert.ok(getChecks(sibling.id).length > 0, 'sibling row must still be written') + assert.ok(getService(sibling.id).health_status, 'sibling health_status must still be updated') + + assert.equal( + dbModule.getCounterInt('health_write_failures_lifetime'), before + 1, + 'the write-failure counter lives in the DB and increments once' + ) + + assert.equal(result.persistFailures.length, 1) + assert.equal(result.persistFailures[0].serviceId, primary.id) + assert.equal(result.persistFailures[0].status, 'healthy', 'records the attempted status') + assert.equal(result.persistFailures[0].category, 'persist', 'distinct from a probe error') + assert.equal(result.persistFailures[0].role, 'primary') + }) + + it('a sibling persist failure does not abort the remaining siblings', async () => { + const url = `https://${TEST_PREFIX}-sibs.example.com/api` + const primary = insertTestService({ protocol: 'L402', url }) + const sibA = insertTestService({ protocol: 'x402', url }) + const sibB = insertTestService({ protocol: 'MPP', url }) + + globalThis.fetch = async () => mockResponse(402, { + 'www-authenticate': `L402 macaroon="${specCompliantMacaroon}", invoice="${longInvoice}"`, + 'payment-required': makePaymentHeader(), + }) + + const result = await checkService(primary, { + persist: (serviceId, payload) => { + if (serviceId === sibA.id) throw new Error('CHECK constraint failed: health_checks') + return checker.persistHealthResult(serviceId, payload) + }, + }) + + assert.equal(result.persisted, true, 'primary is unaffected') + assert.ok(getChecks(primary.id).length > 0) + assert.equal(getChecks(sibA.id).length, 0, 'failing sibling wrote nothing') + assert.ok(getChecks(sibB.id).length > 0, 'the sibling after the failure still wrote') + assert.equal(result.persistFailures.length, 1) + assert.equal(result.persistFailures[0].role, 'sibling') + }) +}) + +describe('an unwritable status is a persist failure, not a probe error', () => { + const canonicalDdl = dbModule.healthChecksTableDDL() + + function useOldConstraint() { + db.exec('DROP TABLE IF EXISTS health_checks') + db.exec(` + CREATE TABLE health_checks ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + service_id TEXT NOT NULL REFERENCES services(id), + checked_at TEXT NOT NULL DEFAULT (datetime('now')), + status TEXT NOT NULL CHECK(status IN (${OLD_STATUS_CHECK})), + response_time_ms INTEGER, + http_status INTEGER, + error_message TEXT + ); + CREATE INDEX IF NOT EXISTS idx_health_checks_service ON health_checks(service_id, checked_at); + `) + } + + function restoreSchema() { + db.exec('DROP TABLE IF EXISTS health_checks') + db.exec(` + ${canonicalDdl}; + CREATE INDEX IF NOT EXISTS idx_health_checks_service ON health_checks(service_id, checked_at); + `) + } + + afterEach(() => { restoreSchema() }) + + it('counts the rejected write, keeps the cycle running, and reports its own category', async () => { + insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-406a.example.com/api` }) + insertTestService({ protocol: 'L402', url: `https://${TEST_PREFIX}-406b.example.com/api` }) + globalThis.fetch = async () => mockResponse(406) + useOldConstraint() + + const before = dbModule.getCounterInt('health_write_failures_lifetime') + const result = await runHealthChecks({ concurrency: 1 }) + + assert.equal(result.persistFailed, 2, 'both rejected writes counted') + assert.equal(result.error, 0, 'a rejected write is not a probe error') + assert.equal(dbModule.getCounterInt('health_write_failures_lifetime'), before + 2) + assert.equal(result.reconciliation.L402.persist_failed, 2) + assert.equal(result.reconciliation.L402.probed_total, 0) + assert.equal(result.reconciliation.L402.unaccounted, 0) + }) +}) diff --git a/test/health-schema-integrity.test.js b/test/health-schema-integrity.test.js new file mode 100644 index 0000000..5f68ecc --- /dev/null +++ b/test/health-schema-integrity.test.js @@ -0,0 +1,511 @@ +/** + * Health-check schema integrity (#313 Part 0 + Part A). + * + * The health_checks status enum existed in three unsynchronized copies (inline CREATE TABLE, + * HEALTH_CHECK_STATUSES, test/helpers/test-db.js), so `not_acceptable` — which the classifier + * has emitted for HTTP 406 since #297 — silently failed its CHECK constraint on every write. + * + * These tests pin the single source of truth, the insertability of every status the classifier + * can actually emit, and a migration that is explicit-column, abort-safe, and loud on failure. + * + * Run: node --test test/health-schema-integrity.test.js + */ + +import { describe, it, afterEach } from 'node:test' +import assert from 'node:assert/strict' +import { readFileSync } from 'fs' +import Database from 'better-sqlite3' +import * as dbModule from '../src/db.js' +import { classifyHealthStatus } from '../src/health/checker.js' +import { createTestDb } from './helpers/test-db.js' + +const db = dbModule.default +const { HEALTH_CHECK_STATUSES } = dbModule + +// The constraint as it shipped before this issue — the state real production DBs are in. +const OLD_STATUS_CHECK = "'healthy', 'degraded', 'down', 'timeout', 'error', 'rate_limited', 'method_not_allowed'" + +const TEST_PREFIX = 'test-schema-' + Date.now() +let counter = 0 +const nextId = () => `${TEST_PREFIX}-${++counter}` + +function insertService(database, id) { + database.prepare( + "INSERT INTO services (id, name, url, protocol, source) VALUES (?, 'Schema Test', ?, 'L402', 'test')" + ).run(id, `https://${id}.example.com/api`) + return id +} + +afterEach(() => { + db.prepare(`DELETE FROM health_checks WHERE service_id LIKE '${TEST_PREFIX}%'`).run() + db.prepare(`DELETE FROM services WHERE id LIKE '${TEST_PREFIX}%'`).run() +}) + +/** + * Drive the classifier across the HTTP status / outcome matrix and collect every checkStatus it + * can emit. Deliberately derived from behavior — a hand-maintained array in the test would drift + * exactly the way the three schema copies did. + */ +function emittableCheckStatuses() { + const found = new Set() + const httpCases = [200, 201, 204, 301, 302, 400, 401, 402, 403, 404, 405, 406, 410, 429, 500, 502, 503, 504] + const errorCases = [null, 'timeout', 'fetch failed', 'blocked: non-http(s) scheme'] + const latencyCases = [[null, 100, 0], [100, 500, 0], [100, 500, 2], [100, 500, 5], [100, 100, 0]] + + for (const httpStatus of httpCases) { + for (const errorMessage of errorCases) { + for (const prevFailures of [0, 1, 2, 5]) { + for (const [p50, responseTime, spikes] of latencyCases) { + const { checkStatus } = classifyHealthStatus(httpStatus, errorMessage, prevFailures, p50, responseTime, spikes) + found.add(checkStatus) + } + } + } + } + return [...found] +} + +/** A scratch DB shaped like prod, with the health_checks constraint under test. */ +function createFixtureDb({ statusCheck = OLD_STATUS_CHECK, columnOrder = 'canonical' } = {}) { + const database = new Database(':memory:') + database.pragma('foreign_keys = ON') + database.exec(` + CREATE TABLE services ( + id TEXT PRIMARY KEY, + name TEXT NOT NULL, + url TEXT NOT NULL, + protocol TEXT NOT NULL CHECK(protocol IN ('L402', 'x402', 'both', 'MPP')), + source TEXT NOT NULL, + status TEXT DEFAULT 'active', + provider_deleted INTEGER DEFAULT 0, + probe_status TEXT DEFAULT 'probeable', + deleted_at TEXT + ); + `) + + // Column order differs between real production DBs (rebuilt by earlier migrations) and a fresh + // CREATE TABLE. A positional `INSERT INTO ... SELECT *` copy silently shuffles values between + // columns; the 'shuffled' variant makes that failure observable. + const columns = columnOrder === 'shuffled' + ? `id INTEGER PRIMARY KEY AUTOINCREMENT, + service_id TEXT NOT NULL REFERENCES services(id), + status TEXT NOT NULL CHECK(status IN (${statusCheck})), + http_status INTEGER, + error_message TEXT, + response_time_ms INTEGER, + checked_at TEXT NOT NULL DEFAULT (datetime('now'))` + : `id INTEGER PRIMARY KEY AUTOINCREMENT, + service_id TEXT NOT NULL REFERENCES services(id), + checked_at TEXT NOT NULL DEFAULT (datetime('now')), + status TEXT NOT NULL CHECK(status IN (${statusCheck})), + response_time_ms INTEGER, + http_status INTEGER, + error_message TEXT` + + database.exec(` + CREATE TABLE health_checks (${columns}); + CREATE INDEX idx_health_checks_service ON health_checks(service_id, checked_at); + `) + insertService(database, 'fixture-svc') + return database +} + +function captureLogger() { + const calls = { error: [], warn: [], log: [] } + return { + calls, + error: (...args) => calls.error.push(args.join(' ')), + warn: (...args) => calls.warn.push(args.join(' ')), + log: (...args) => calls.log.push(args.join(' ')), + } +} + +describe('HEALTH_CHECK_STATUSES is the single source of truth', () => { + it('includes not_acceptable — the status the classifier emits for HTTP 406', () => { + assert.ok( + HEALTH_CHECK_STATUSES.includes('not_acceptable'), + 'HEALTH_CHECK_STATUSES must include not_acceptable' + ) + }) + + it('exports a DDL generator derived from the list', () => { + assert.equal(typeof dbModule.healthChecksTableDDL, 'function', 'db.js must export healthChecksTableDDL') + const ddl = dbModule.healthChecksTableDDL() + for (const status of HEALTH_CHECK_STATUSES) { + assert.ok(ddl.includes(`'${status}'`), `generated DDL must allow ${status}`) + } + assert.ok(ddl.includes('CREATE TABLE health_checks'), 'defaults to the real table name') + assert.ok( + dbModule.healthChecksTableDDL('health_checks_new').includes('CREATE TABLE health_checks_new'), + 'accepts an alternate table name for the rebuild' + ) + }) + + it('the live schema allows exactly the canonical list', () => { + const ddl = db.prepare( + "SELECT sql FROM sqlite_master WHERE type = 'table' AND name = 'health_checks'" + ).get().sql + for (const status of HEALTH_CHECK_STATUSES) { + assert.ok(ddl.includes(`'${status}'`), `live health_checks DDL must allow ${status}`) + } + }) + + it('every canonical status inserts through the real src/db.js schema', () => { + const id = insertService(db, nextId()) + for (const status of HEALTH_CHECK_STATUSES) { + assert.doesNotThrow( + () => db.prepare('INSERT INTO health_checks (service_id, status) VALUES (?, ?)').run(id, status), + `status ${status} must be insertable` + ) + } + }) + + it('the test helper derives its schema from the same list', () => { + const testDb = createTestDb() + insertService(testDb, 'helper-svc') + for (const status of HEALTH_CHECK_STATUSES) { + assert.doesNotThrow( + () => testDb.prepare('INSERT INTO health_checks (service_id, status) VALUES (?, ?)').run('helper-svc', status), + `test-db.js must allow ${status}` + ) + } + testDb.close() + }) +}) + +describe('emittable-status coverage', () => { + it('the classifier matrix reaches not_acceptable (matrix sanity)', () => { + assert.ok(emittableCheckStatuses().includes('not_acceptable'), 'matrix must exercise HTTP 406') + }) + + it('every status the classifier can emit is in the canonical list', () => { + for (const status of emittableCheckStatuses()) { + assert.ok(HEALTH_CHECK_STATUSES.includes(status), `classifier emits ${status}, which the enum omits`) + } + }) + + it('every status the classifier can emit inserts through the real schema', () => { + const id = insertService(db, nextId()) + for (const status of emittableCheckStatuses()) { + assert.doesNotThrow( + () => db.prepare('INSERT INTO health_checks (service_id, status) VALUES (?, ?)').run(id, status), + `emitted status ${status} must be insertable` + ) + } + }) + + it('every emittable status inserts on an old-constraint DB after the real migration path', () => { + const fixture = createFixtureDb() + assert.equal(dbModule.migrateHealthChecksStatusConstraint(fixture), true, 'old constraint needs migrating') + + for (const status of emittableCheckStatuses()) { + assert.doesNotThrow( + () => fixture.prepare('INSERT INTO health_checks (service_id, status) VALUES (?, ?)').run('fixture-svc', status), + `migrated DB must accept ${status}` + ) + } + fixture.close() + }) +}) + +describe('migration detection by insertability probe', () => { + it('reports the statuses the current constraint rejects', () => { + const fixture = createFixtureDb() + assert.equal(typeof dbModule.probeHealthCheckStatuses, 'function', 'db.js must export probeHealthCheckStatuses') + assert.deepEqual(dbModule.probeHealthCheckStatuses(fixture), ['not_acceptable']) + fixture.close() + }) + + it('reports nothing once the table is current', () => { + const fixture = createFixtureDb() + dbModule.migrateHealthChecksStatusConstraint(fixture) + assert.deepEqual(dbModule.probeHealthCheckStatuses(fixture), []) + fixture.close() + }) + + it('leaves no rows behind — the probe runs inside a rolled-back transaction', () => { + const fixture = createFixtureDb() + fixture.prepare("INSERT INTO health_checks (service_id, status) VALUES ('fixture-svc', 'healthy')").run() + const servicesBefore = fixture.prepare('SELECT COUNT(*) c FROM services').get().c + const checksBefore = fixture.prepare('SELECT COUNT(*) c FROM health_checks').get().c + + dbModule.probeHealthCheckStatuses(fixture) + + assert.equal(fixture.prepare('SELECT COUNT(*) c FROM services').get().c, servicesBefore) + assert.equal(fixture.prepare('SELECT COUNT(*) c FROM health_checks').get().c, checksBefore) + fixture.close() + }) + + it('detects a stale constraint even when the DDL text mentions the status', () => { + // DDL-substring detection is fooled by a status name appearing anywhere in the CREATE TABLE + // text (a column default, a comment). Only an insert proves insertability. + const fixture = new Database(':memory:') + fixture.exec(` + CREATE TABLE services ( + id TEXT PRIMARY KEY, name TEXT NOT NULL, url TEXT NOT NULL, + protocol TEXT NOT NULL, source TEXT NOT NULL + ); + CREATE TABLE health_checks ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + service_id TEXT NOT NULL REFERENCES services(id), + checked_at TEXT NOT NULL DEFAULT (datetime('now')), + status TEXT NOT NULL CHECK(status IN (${OLD_STATUS_CHECK})), + response_time_ms INTEGER, + http_status INTEGER, + error_message TEXT DEFAULT 'not_acceptable placeholder' + ); + `) + assert.deepEqual(dbModule.probeHealthCheckStatuses(fixture), ['not_acceptable']) + fixture.close() + }) +}) + +describe('migration rebuild', () => { + it('copies rows by explicit column list, not positional SELECT *', () => { + const fixture = createFixtureDb({ columnOrder: 'shuffled' }) + fixture.prepare(` + INSERT INTO health_checks (service_id, status, http_status, error_message, response_time_ms, checked_at) + VALUES ('fixture-svc', 'down', 503, 'HTTP 503', 42, datetime('now', '-1 hour')) + `).run() + const before = fixture.prepare('SELECT * FROM health_checks').get() + + assert.equal(dbModule.migrateHealthChecksStatusConstraint(fixture), true) + + const row = fixture.prepare('SELECT * FROM health_checks').get() + assert.equal(row.status, 'down', 'status must land in status') + assert.equal(row.http_status, 503, 'http_status must land in http_status') + assert.equal(row.error_message, 'HTTP 503') + assert.equal(row.response_time_ms, 42) + assert.equal(row.checked_at, before.checked_at) + fixture.close() + }) + + it('prunes beyond retention before rebuilding', () => { + const fixture = createFixtureDb() + fixture.prepare( + "INSERT INTO health_checks (service_id, status, checked_at) VALUES ('fixture-svc', 'healthy', datetime('now', '-10 days'))" + ).run() + fixture.prepare( + "INSERT INTO health_checks (service_id, status) VALUES ('fixture-svc', 'healthy')" + ).run() + + dbModule.migrateHealthChecksStatusConstraint(fixture) + + assert.equal(fixture.prepare('SELECT COUNT(*) c FROM health_checks').get().c, 1, 'stale row pruned, fresh row kept') + fixture.close() + }) + + it('aborts without free space and leaves the original table intact and queryable', () => { + const fixture = createFixtureDb() + fixture.prepare("INSERT INTO health_checks (service_id, status) VALUES ('fixture-svc', 'healthy')").run() + const noSpace = () => ({ blocks: 1000, bsize: 4096, bfree: 0 }) + + assert.throws( + () => dbModule.migrateHealthChecksStatusConstraint(fixture, { statfsSyncFn: noSpace }), + /space/i + ) + assert.equal(fixture.prepare('SELECT COUNT(*) c FROM health_checks').get().c, 1, 'rows survive') + assert.deepEqual(dbModule.probeHealthCheckStatuses(fixture), ['not_acceptable'], 'still on the old constraint') + fixture.close() + }) + + it('is idempotent and clears a leftover _new table from a killed run', () => { + const fixture = createFixtureDb() + fixture.exec('CREATE TABLE health_checks_new (id INTEGER PRIMARY KEY)') + + assert.equal(dbModule.migrateHealthChecksStatusConstraint(fixture), true, 'first run migrates') + assert.equal(dbModule.migrateHealthChecksStatusConstraint(fixture), false, 'second run is a no-op') + assert.equal( + fixture.prepare("SELECT COUNT(*) c FROM sqlite_master WHERE name = 'health_checks_new'").get().c, + 0, + 'leftover table gone' + ) + fixture.close() + }) +}) + +describe('migration failure is loud', () => { + it('sets health_schema_invalid and logs at error level when the rebuild fails', () => { + const fixture = createFixtureDb() + // Orphan row: a health_check whose service no longer exists. The post-rebuild + // foreign_key_check refuses to commit a table carrying it. + fixture.pragma('foreign_keys = OFF') + fixture.prepare("INSERT INTO health_checks (service_id, status) VALUES ('ghost-svc', 'healthy')").run() + fixture.pragma('foreign_keys = ON') + + assert.equal(typeof dbModule.runHealthChecksSchemaGuard, 'function', 'db.js must export runHealthChecksSchemaGuard') + const logger = captureLogger() + const result = dbModule.runHealthChecksSchemaGuard(fixture, { logger }) + + assert.equal(result.valid, false, 'guard must report an invalid schema') + assert.ok(logger.calls.error.length > 0, 'must log at error level') + assert.equal(logger.calls.warn.length, 0, 'must not downgrade the failure to a warning') + assert.equal(dbModule.getCounter('health_schema_invalid', fixture), '1') + assert.equal( + dbModule.getCounter('health_schema_probe_error', fixture), null, + 'a genuinely rejected status is a verdict, not an indeterminate probe' + ) + // Abort-safe: the original table is intact and still queryable. + assert.equal(fixture.prepare('SELECT COUNT(*) c FROM health_checks').get().c, 1) + fixture.close() + }) + + it('clears health_schema_invalid once the schema is current', () => { + const fixture = createFixtureDb() + dbModule.ensureCountersTable(fixture) + dbModule.setCounter('health_schema_invalid', '1', fixture) + dbModule.setCounter('health_schema_probe_error', 'stale lock from a previous boot', fixture) + + const result = dbModule.runHealthChecksSchemaGuard(fixture, { logger: captureLogger() }) + + assert.equal(result.valid, true) + assert.equal(result.migrated, true) + assert.equal(dbModule.getCounter('health_schema_invalid', fixture), null, 'key removed when healthy') + assert.equal( + dbModule.getCounter('health_schema_probe_error', fixture), null, + 'a determinate healthy probe clears the indeterminate flag too' + ) + fixture.close() + }) + + it('the live boot left no invalid-schema flag', () => { + assert.equal(dbModule.getCounter('health_schema_invalid'), null) + assert.equal(dbModule.getCounter('health_schema_probe_error'), null) + }) + + it('src/db.js no longer swallows the migration failure in a console.warn', () => { + const source = readFileSync(new URL('../src/db.js', import.meta.url), 'utf8') + assert.ok( + !/health_checks migration note/.test(source), + 'the console.warn swallow path must be deleted, not reworded' + ) + }) +}) + +describe('a probe that could not run is not a broken schema', () => { + const CURRENT_STATUS_CHECK = HEALTH_CHECK_STATUSES.map(s => `'${s}'`).join(', ') + + /** + * A DB whose write transactions raise SQLITE_BUSY for the first `failures` attempts. + * + * Real cause: the probe opens a write transaction at src/db.js import time, so + * scripts/healthcheck.js booting while the server process is mid-write can lose the lock race. + * That says nothing about the status enum. + */ + function busyDb(realDb, failures) { + let seen = 0 + return new Proxy(realDb, { + get(target, prop) { + if (prop === 'exec') { + return sql => { + if (/^\s*BEGIN/i.test(sql) && seen++ < failures) { + const err = new Error('database is locked') + err.code = 'SQLITE_BUSY' + throw err + } + return target.exec(sql) + } + } + const value = Reflect.get(target, prop, target) + return typeof value === 'function' ? value.bind(target) : value + }, + }) + } + + it('retries a transient lock instead of returning a verdict', () => { + const fixture = createFixtureDb({ statusCheck: CURRENT_STATUS_CHECK }) + assert.deepEqual( + dbModule.probeHealthCheckStatuses(busyDb(fixture, 2), { retryMs: 1 }), [], + 'a lock that clears on retry must probe clean' + ) + fixture.close() + }) + + it('reports an unavailable probe under its own key, never as health_schema_invalid', () => { + const fixture = createFixtureDb({ statusCheck: CURRENT_STATUS_CHECK }) + dbModule.ensureCountersTable(fixture) + const logger = captureLogger() + + const result = dbModule.runHealthChecksSchemaGuard(busyDb(fixture, Infinity), { logger }) + + assert.equal(result.valid, false) + assert.equal(result.indeterminate, true, 'the guard must say it could not tell') + assert.deepEqual(result.missing, [], 'no status was actually rejected') + assert.equal( + dbModule.getCounter('health_schema_invalid', fixture), null, + 'a locked DB must not latch a schema alarm that survives until the next deploy' + ) + assert.ok( + dbModule.getCounter('health_schema_probe_error', fixture), + 'the indeterminate outcome gets its own durable key' + ) + assert.ok(logger.calls.error.length > 0, 'still loud — just not the wrong alarm') + assert.equal(logger.calls.warn.length, 0, 'and never downgraded to a warning') + fixture.close() + }) + + it('a locked probe leaves the schema flag exactly as it found it', () => { + const fixture = createFixtureDb({ statusCheck: CURRENT_STATUS_CHECK }) + dbModule.ensureCountersTable(fixture) + + dbModule.runHealthChecksSchemaGuard(busyDb(fixture, Infinity), { logger: captureLogger() }) + assert.equal(dbModule.getCounter('health_schema_invalid', fixture), null) + + // ...and the next boot, with the lock gone, resolves it determinately. + const result = dbModule.runHealthChecksSchemaGuard(fixture, { logger: captureLogger() }) + assert.equal(result.valid, true) + assert.equal(dbModule.getCounter('health_schema_probe_error', fixture), null, 'cleared once determinable') + fixture.close() + }) +}) + +describe('counters table', () => { + it('exists on the live DB with a key/value/updated_at shape', () => { + const cols = db.pragma("table_info('counters')").map(c => c.name) + assert.deepEqual(cols.sort(), ['key', 'updated_at', 'value']) + }) + + it('reads, writes, deletes and increments', () => { + const fixture = new Database(':memory:') + dbModule.ensureCountersTable(fixture) + + assert.equal(dbModule.getCounter('nope', fixture), null) + assert.equal(dbModule.getCounterInt('nope', fixture), 0) + + dbModule.setCounter('thing', 'value', fixture) + assert.equal(dbModule.getCounter('thing', fixture), 'value') + + assert.equal(dbModule.incrementCounter('tally', 1, fixture), 1) + assert.equal(dbModule.incrementCounter('tally', 4, fixture), 5) + assert.equal(dbModule.getCounterInt('tally', fixture), 5) + + dbModule.deleteCounter('tally', fixture) + assert.equal(dbModule.getCounter('tally', fixture), null) + fixture.close() + }) + + it('carries no retention', () => { + const source = readFileSync(new URL('../src/db.js', import.meta.url), 'utf8') + // Single-key deletes are key management (clearing health_schema_invalid); an age-based sweep + // would make the lifetime counters lie the same way query_log did. + assert.ok( + !/DELETE FROM counters WHERE[^']*datetime\(/.test(source), + 'counters must have no age-based delete' + ) + // Stronger than the datetime() check above, which a JS-computed cutoff would slip past: + // every delete against counters must be scoped to a single key. + for (const stmt of source.match(/DELETE FROM counters[^`'"]*/g) || []) { + assert.match(stmt.trim(), /^DELETE FROM counters WHERE key = \?$/, `counters delete must be key-scoped: ${stmt}`) + } + const pruneAll = source.match(/function pruneAll\(\)\s*\{[\s\S]*?\n\}/) + assert.ok(pruneAll, 'pruneAll must exist') + assert.ok(!/counter/i.test(pruneAll[0]), 'pruneAll must not touch counters') + }) + + it('is created by the test helper too', () => { + const testDb = createTestDb() + const cols = testDb.pragma("table_info('counters')").map(c => c.name) + assert.deepEqual(cols.sort(), ['key', 'updated_at', 'value']) + testDb.close() + }) +}) diff --git a/test/health-uptime-buckets.test.js b/test/health-uptime-buckets.test.js new file mode 100644 index 0000000..4bae261 --- /dev/null +++ b/test/health-uptime-buckets.test.js @@ -0,0 +1,112 @@ +/** + * Uptime bucket semantics, pinned per status (#313 Part A.2). + * + * Every status in HEALTH_CHECK_STATUSES belongs to exactly one bucket: + * - up (numerator + denominator): healthy, degraded + * - down (denominator only): down, timeout, error, method_not_allowed, not_acceptable + * - excluded (neither): rate_limited + * + * BEHAVIOR-CHANGE: a 429 means the provider throttled our prober. It carries no availability + * information, so it must not score a popular provider as down. + * + * Run: node --test test/health-uptime-buckets.test.js + */ + +import { describe, it, afterEach } from 'node:test' +import assert from 'node:assert/strict' +import * as dbModule from '../src/db.js' +import * as checker from '../src/health/checker.js' + +const db = dbModule.default +const { HEALTH_CHECK_STATUSES } = dbModule + +const TEST_PREFIX = 'test-uptime-' + Date.now() +let counter = 0 + +function seedService() { + const id = `${TEST_PREFIX}-${++counter}` + db.prepare( + "INSERT INTO services (id, name, url, protocol, source) VALUES (?, 'Uptime Test', ?, 'L402', 'test')" + ).run(id, `https://${id}.example.com/api`) + return id +} + +function addCheck(serviceId, status) { + db.prepare('INSERT INTO health_checks (service_id, status) VALUES (?, ?)').run(serviceId, status) +} + +afterEach(() => { + db.prepare(`DELETE FROM health_checks WHERE service_id LIKE '${TEST_PREFIX}%'`).run() + db.prepare(`DELETE FROM services WHERE id LIKE '${TEST_PREFIX}%'`).run() +}) + +describe('uptime buckets partition the status enum', () => { + it('exports the three buckets', () => { + assert.ok(Array.isArray(checker.UPTIME_UP_STATUSES), 'checker must export UPTIME_UP_STATUSES') + assert.ok(Array.isArray(checker.UPTIME_DOWN_STATUSES), 'checker must export UPTIME_DOWN_STATUSES') + assert.ok(Array.isArray(checker.UPTIME_EXCLUDED_STATUSES), 'checker must export UPTIME_EXCLUDED_STATUSES') + }) + + it('covers every canonical status exactly once', () => { + const all = [ + ...checker.UPTIME_UP_STATUSES, + ...checker.UPTIME_DOWN_STATUSES, + ...checker.UPTIME_EXCLUDED_STATUSES, + ] + assert.equal(new Set(all).size, all.length, 'no status may appear in two buckets') + assert.deepEqual([...all].sort(), [...HEALTH_CHECK_STATUSES].sort()) + }) + + it('pins the membership of each bucket', () => { + assert.deepEqual([...checker.UPTIME_UP_STATUSES].sort(), ['degraded', 'healthy']) + assert.deepEqual( + [...checker.UPTIME_DOWN_STATUSES].sort(), + ['down', 'error', 'method_not_allowed', 'not_acceptable', 'timeout'] + ) + assert.deepEqual([...checker.UPTIME_EXCLUDED_STATUSES], ['rate_limited']) + }) +}) + +describe('calculateUptime per status', () => { + for (const status of ['healthy', 'degraded']) { + it(`counts ${status} in the numerator`, () => { + const id = seedService() + addCheck(id, status) + assert.equal(checker.calculateUptime(id), 1) + }) + } + + for (const status of ['down', 'timeout', 'error', 'method_not_allowed', 'not_acceptable']) { + it(`counts ${status} in the denominator only`, () => { + const id = seedService() + addCheck(id, status) + assert.equal(checker.calculateUptime(id), 0) + }) + } + + it('excludes rate_limited from both numerator and denominator', () => { + const id = seedService() + addCheck(id, 'rate_limited') + assert.equal(checker.calculateUptime(id), null, 'a throttled prober yields no uptime signal at all') + }) + + it('a throttled provider that answered once is 100%, not 50%', () => { + const id = seedService() + addCheck(id, 'healthy') + addCheck(id, 'rate_limited') + assert.equal(checker.calculateUptime(id), 1) + }) + + it('mixes up and down statuses across the window', () => { + const id = seedService() + addCheck(id, 'healthy') + addCheck(id, 'healthy') + addCheck(id, 'not_acceptable') + addCheck(id, 'rate_limited') + assert.equal(checker.calculateUptime(id), 0.6667) + }) + + it('returns null with no checks at all', () => { + assert.equal(checker.calculateUptime(seedService()), null) + }) +}) diff --git a/test/helpers/test-db.js b/test/helpers/test-db.js index 3cc7d2c..83e86e4 100644 --- a/test/helpers/test-db.js +++ b/test/helpers/test-db.js @@ -1,4 +1,5 @@ import Database from 'better-sqlite3' +import { healthChecksTableDDL, COUNTERS_TABLE_DDL } from '../../src/db.js' /** * Create a fresh :memory: SQLite DB with the full canonical schema. @@ -6,6 +7,9 @@ import Database from 'better-sqlite3' * Source of truth: src/db.js * SYNC WARNING: Any ALTER TABLE migration added to src/db.js must be * reflected here. Run `PRAGMA table_info(services)` on both to compare. + * + * health_checks and counters are generated from src/db.js rather than copied: a hand-maintained + * copy of the status enum here is one of the three that drifted in #313. */ export function createTestDb() { const db = new Database(':memory:') @@ -74,17 +78,11 @@ export function createTestDb() { CREATE UNIQUE INDEX idx_services_url_protocol ON services(url, protocol); CREATE INDEX idx_services_hostname ON services(hostname); - CREATE TABLE health_checks ( - id INTEGER PRIMARY KEY AUTOINCREMENT, - service_id TEXT NOT NULL REFERENCES services(id), - checked_at TEXT NOT NULL DEFAULT (datetime('now')), - status TEXT NOT NULL CHECK(status IN ('healthy', 'degraded', 'down', 'timeout', 'error', 'rate_limited', 'method_not_allowed')), - response_time_ms INTEGER, - http_status INTEGER, - error_message TEXT - ); + ${healthChecksTableDDL()}; CREATE INDEX idx_health_checks_service ON health_checks(service_id, checked_at); + ${COUNTERS_TABLE_DDL}; + CREATE TABLE daily_snapshots ( id INTEGER PRIMARY KEY AUTOINCREMENT, snapshot_date TEXT NOT NULL UNIQUE, diff --git a/test/mcp-counters.test.js b/test/mcp-counters.test.js new file mode 100644 index 0000000..3ec27d0 --- /dev/null +++ b/test/mcp-counters.test.js @@ -0,0 +1,185 @@ +/** + * Honest MCP counters (#313 Part C). + * + * mcp_queries_total / mcp_active_days were COUNT queries over query_log, which pruneQueryLog + * deletes at 90 days — rolling-window aggregates mislabeled as lifetime totals. The non-monotonic + * drops in the 5:30am digest were the oldest day rolling out of the window. + * + * Run: node --test test/mcp-counters.test.js + */ + +import { describe, it } from 'node:test' +import assert from 'node:assert/strict' +import { readFileSync } from 'fs' +import Database from 'better-sqlite3' +import * as dbModule from '../src/db.js' + +const db = dbModule.default +const { logQuery, pruneQueryLog } = dbModule + +const MCP_UA = '402index-mcp/0.4.1' +const LIFETIME_KEY = 'mcp_queries_lifetime' +const SEEDED_AT_KEY = 'mcp_counter_seeded_at' + +describe('MCP user-agent classification', () => { + it('recognizes the MCP client and nothing else', () => { + assert.equal(typeof dbModule.isMcpUserAgent, 'function', 'db.js must export isMcpUserAgent') + assert.equal(dbModule.isMcpUserAgent(MCP_UA), true) + assert.equal(dbModule.isMcpUserAgent('402index-mcp'), true) + assert.equal(dbModule.isMcpUserAgent('Mozilla/5.0'), false) + assert.equal(dbModule.isMcpUserAgent(''), false) + assert.equal(dbModule.isMcpUserAgent(null), false) + assert.equal(dbModule.isMcpUserAgent(undefined), false) + }) +}) + +describe('one predicate classifies MCP traffic everywhere', () => { + // User-Agent is fully client-controlled. The JS increment used a case-sensitive includes() while + // the window queries used SQL LIKE, which is case-insensitive for ASCII — so a client sending + // "402Index-MCP" was counted in the 90d window but never in the lifetime counter, and the digest + // could report mcp_queries_90d > mcp_queries_lifetime. + const MIXED_CASE_UA = '402Index-MCP/9.9.9' + + it('classifies a mixed-case user agent as MCP', () => { + assert.equal(dbModule.isMcpUserAgent(MIXED_CASE_UA), true) + assert.equal(dbModule.isMcpUserAgent('402INDEX-MCP'), true) + }) + + it('moves the lifetime and 90-day counters together for a mixed-case agent', () => { + const lifetimeBefore = dbModule.getCounterInt(LIFETIME_KEY) + const windowBefore = dbModule.mcpQueryWindowStats().queries + + logQuery({ queryText: 'mixed case', userAgent: MIXED_CASE_UA }) + + assert.equal(dbModule.getCounterInt(LIFETIME_KEY), lifetimeBefore + 1, 'lifetime counter must see it') + assert.equal(dbModule.mcpQueryWindowStats().queries, windowBefore + 1, 'window must see the same event') + }) + + it('seeds the lifetime floor from the same predicate that increments it', () => { + const fixture = new Database(':memory:') + dbModule.ensureCountersTable(fixture) + fixture.exec(` + CREATE TABLE query_log ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + timestamp TEXT NOT NULL DEFAULT (datetime('now')), + query_text TEXT, filters TEXT, result_count INTEGER, + response_time_ms INTEGER, user_agent TEXT, degraded_reason TEXT + ); + `) + const insert = fixture.prepare('INSERT INTO query_log (user_agent) VALUES (?)') + insert.run(MCP_UA) + insert.run(MIXED_CASE_UA) + + dbModule.seedMcpLifetimeCounter(fixture) + assert.equal( + dbModule.getCounterInt(LIFETIME_KEY, fixture), 2, + 'the seed floor must count exactly what later increments will count' + ) + fixture.close() + }) + + it('the digest does not hand-roll a second MCP predicate', () => { + const source = readFileSync(new URL('../src/routes/api/digest.js', import.meta.url), 'utf8') + assert.ok( + !/user_agent LIKE/.test(source), + 'digest MCP counting must use the shared predicate exported by db.js' + ) + assert.match(source, /MCP_USER_AGENT_SQL/) + assert.equal(typeof dbModule.MCP_USER_AGENT_SQL, 'string', 'db.js must export the shared SQL predicate') + }) +}) + +describe('lifetime counter increments', () => { + it('increments when an MCP query is logged', () => { + const before = dbModule.getCounterInt(LIFETIME_KEY) + logQuery({ queryText: 'weather', userAgent: MCP_UA }) + assert.equal(dbModule.getCounterInt(LIFETIME_KEY), before + 1) + }) + + it('does not increment for browser or plain API agents', () => { + const before = dbModule.getCounterInt(LIFETIME_KEY) + logQuery({ queryText: 'weather', userAgent: 'Mozilla/5.0 (Macintosh)' }) + logQuery({ queryText: 'weather', userAgent: null }) + logQuery({ queryText: 'weather', userAgent: 'curl/8.4.0' }) + assert.equal(dbModule.getCounterInt(LIFETIME_KEY), before) + }) + + it('logs the query row and increments the counter together', () => { + const rowsBefore = db.prepare('SELECT COUNT(*) c FROM query_log').get().c + const before = dbModule.getCounterInt(LIFETIME_KEY) + logQuery({ queryText: 'atomic', userAgent: MCP_UA }) + assert.equal(db.prepare('SELECT COUNT(*) c FROM query_log').get().c, rowsBefore + 1) + assert.equal(dbModule.getCounterInt(LIFETIME_KEY), before + 1) + }) +}) + +describe('window stats are labeled as a window', () => { + it('exposes the 90-day MCP window separately from the lifetime counter', () => { + assert.equal(typeof dbModule.mcpQueryWindowStats, 'function', 'db.js must export mcpQueryWindowStats') + logQuery({ queryText: 'window', userAgent: MCP_UA }) + const stats = dbModule.mcpQueryWindowStats() + assert.ok(stats.queries >= 1, 'window query count') + assert.ok(stats.activeDays >= 1, 'window active-day count') + assert.equal(dbModule.MCP_QUERY_LOG_RETENTION_DAYS, 90, 'query_log retention stays at 90 days') + }) +}) + +describe('seeding', () => { + it('seeds once from the window count and records the seed timestamp', () => { + const fixture = new Database(':memory:') + dbModule.ensureCountersTable(fixture) + fixture.exec(` + CREATE TABLE query_log ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + timestamp TEXT NOT NULL DEFAULT (datetime('now')), + query_text TEXT, filters TEXT, result_count INTEGER, + response_time_ms INTEGER, user_agent TEXT, degraded_reason TEXT + ); + `) + const insert = fixture.prepare('INSERT INTO query_log (user_agent) VALUES (?)') + insert.run(MCP_UA) + insert.run(MCP_UA) + insert.run(MCP_UA) + insert.run('Mozilla/5.0') + + assert.equal(dbModule.seedMcpLifetimeCounter(fixture), true, 'first call seeds') + assert.equal(dbModule.getCounterInt(LIFETIME_KEY, fixture), 3, 'seeded from the honest 90-day floor') + assert.ok(dbModule.getCounter(SEEDED_AT_KEY, fixture), 'seed timestamp recorded') + + // Second call must never re-seed — that would clobber accumulated increments. + dbModule.incrementCounter(LIFETIME_KEY, 5, fixture) + assert.equal(dbModule.seedMcpLifetimeCounter(fixture), false, 'second call is a no-op') + assert.equal(dbModule.getCounterInt(LIFETIME_KEY, fixture), 8) + fixture.close() + }) + + it('seeded the live DB at boot', () => { + assert.ok(dbModule.getCounter(SEEDED_AT_KEY), 'boot must expose when the counter was seeded') + }) +}) + +describe('prune semantics', () => { + it('changes the window fields but never the lifetime counter', () => { + // Two MCP queries from an earlier day, inside the 90d window. A 1-day retention sweep stands + // in for the 90d boundary moving past them — the exact event behind the digest's drops. + const stale = db.prepare("INSERT INTO query_log (timestamp, user_agent) VALUES (datetime('now', '-2 days'), ?)") + stale.run(MCP_UA) + stale.run(MCP_UA) + logQuery({ queryText: 'recent', userAgent: MCP_UA }) + + const lifetime = dbModule.getCounterInt(LIFETIME_KEY) + const before = dbModule.mcpQueryWindowStats() + assert.ok(before.queries >= 3, 'the window sees the stale rows') + assert.ok(before.activeDays >= 2) + + pruneQueryLog(1) + + const after = dbModule.mcpQueryWindowStats() + assert.equal(after.queries, before.queries - 2, 'the window loses the pruned rows') + assert.equal(after.activeDays, before.activeDays - 1, 'and loses their active day') + assert.equal( + dbModule.getCounterInt(LIFETIME_KEY), lifetime, + 'the lifetime counter is not a query over query_log' + ) + }) +})