From 81744b38d66fb478f1d1bac5a94ed73389f5bf74 Mon Sep 17 00:00:00 2001 From: Ryan Gentry <41025545+ryanthegentry@users.noreply.github.com> Date: Sun, 26 Jul 2026 14:28:01 -0500 Subject: [PATCH 1/3] test: add failing test for #313 Pins health-check integrity before any implementation: - health-schema-integrity: single-source status enum, DDL generator, insertability probe, explicit-column migration, loud failure path, counters table - health-uptime-buckets: per-status uptime bucket membership incl. the rate_limited exclusion - health-persist-isolation: HTTP 406 diagnostic, per-row persist isolation, rejected write counted as a persist failure not a probe error - health-cycle-reconciliation: per-protocol bucket identity, unaccounted=0, cycle summary persisted to counters - mcp-counters: lifetime counter vs 90d window, seeding, prune semantics - digest-health-mcp-fields: digest health section + renamed MCP fields The 406 test fails with the production error itself: CHECK constraint failed: status IN ('healthy', ..., 'method_not_allowed') [skip ci] --- test/digest-health-mcp-fields.test.js | 82 +++++ test/health-cycle-reconciliation.test.js | 227 +++++++++++++ test/health-persist-isolation.test.js | 230 +++++++++++++ test/health-schema-integrity.test.js | 410 +++++++++++++++++++++++ test/health-uptime-buckets.test.js | 112 +++++++ test/mcp-counters.test.js | 124 +++++++ 6 files changed, 1185 insertions(+) create mode 100644 test/digest-health-mcp-fields.test.js create mode 100644 test/health-cycle-reconciliation.test.js create mode 100644 test/health-persist-isolation.test.js create mode 100644 test/health-schema-integrity.test.js create mode 100644 test/health-uptime-buckets.test.js create mode 100644 test/mcp-counters.test.js diff --git a/test/digest-health-mcp-fields.test.js b/test/digest-health-mcp-fields.test.js new file mode 100644 index 0000000..0b4b85a --- /dev/null +++ b/test/digest-health-mcp-fields.test.js @@ -0,0 +1,82 @@ +/** + * 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') + }) +}) + +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('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..b8502a7 --- /dev/null +++ b/test/health-cycle-reconciliation.test.js @@ -0,0 +1,227 @@ +/** + * 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('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..4ab3f58 --- /dev/null +++ b/test/health-schema-integrity.test.js @@ -0,0 +1,410 @@ +/** + * 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, '2026-07-01 12:00:00') + `).run() + + 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, '2026-07-01 12:00:00') + 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') + // 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) + + 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') + fixture.close() + }) + + it('the live boot left no invalid-schema flag', () => { + assert.equal(dbModule.getCounter('health_schema_invalid'), 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('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('is never pruned', () => { + const source = readFileSync(new URL('../src/db.js', import.meta.url), 'utf8') + assert.ok(!/DELETE FROM counters/.test(source), 'counters must carry no retention') + }) + + 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/mcp-counters.test.js b/test/mcp-counters.test.js new file mode 100644 index 0000000..8a9e71c --- /dev/null +++ b/test/mcp-counters.test.js @@ -0,0 +1,124 @@ +/** + * 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 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('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') + }) +}) + +// Runs last: pruneQueryLog(0) empties query_log for this process. +describe('prune semantics', () => { + it('changes the 90d window but never the lifetime counter', () => { + logQuery({ queryText: 'keeper', userAgent: MCP_UA }) + logQuery({ queryText: 'keeper', userAgent: MCP_UA }) + + const lifetime = dbModule.getCounterInt(LIFETIME_KEY) + const windowBefore = dbModule.mcpQueryWindowStats() + assert.ok(windowBefore.queries >= 2) + + pruneQueryLog(0) + + const windowAfter = dbModule.mcpQueryWindowStats() + assert.equal(windowAfter.queries, 0, 'the window follows retention') + assert.equal(windowAfter.activeDays, 0) + assert.equal( + dbModule.getCounterInt(LIFETIME_KEY), lifetime, + 'the lifetime counter is not a query over query_log' + ) + }) +}) From 20c86324aee66623ac3031eb5f3425c66361c28a Mon Sep 17 00:00:00 2001 From: Ryan Gentry <41025545+ryanthegentry@users.noreply.github.com> Date: Sun, 26 Jul 2026 14:44:59 -0500 Subject: [PATCH 2/3] =?UTF-8?q?fix:=20health-check=20integrity=20=E2=80=94?= =?UTF-8?q?=20single-source=20status=20enum,=20hardened=20migration,=20cyc?= =?UTF-8?q?le=20reconciliation,=20honest=20MCP=20counters=20(#313)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Part 0 — shared infrastructure - HEALTH_CHECK_STATUSES is the only definition of the enum, now including not_acceptable. The inline CREATE TABLE, the migration DDL, and test/helpers/test-db.js all derive from healthChecksTableDDL(). - New counters table: durable, never-pruned KV aggregates, transactional with the writes they count and visible from both the server and scripts/healthcheck.js. Part A — enum, migration, uptime, failure isolation - migrateHealthChecksStatusConstraint detects by positive insertability probe (real transaction-scoped parent row, BEGIN...ROLLBACK) instead of DDL substring matching; prunes to retention and checks for 2x free space before starting; copies with explicit column lists on both sides; runs foreign_key_check inside the transaction so any failure rolls back with the original table intact. - Failure is loud: runHealthChecksSchemaGuard logs at error level and sets health_schema_invalid=1, surfaced by the digest. The console.warn swallow is deleted. - Uptime buckets pinned per status. rate_limited is excluded from numerator and denominator. - persistHealthResult calls are isolated per row: one rejected write cannot abort the URL's remaining rows or the cycle. Failures increment a DB counter, are logged in their own category with service id and attempted status, and retry next cycle. - 406 rows carry a diagnostic error_message. classifyHealthStatus and test/health-classifier.test.js are untouched. Part B — reconciliation, no probing changes - Per-protocol buckets (probed by result status incl. unknown/error, sibling_updated, skipped_unprobeable, excluded_inactive, persist_failed) sum to all rows carrying the protocol, with unaccounted pinned at 0. Rows hard-deleted mid-cycle are reported as vanished_mid_cycle rather than pushed into a negative residual. - Written to counters.last_health_cycle at cycle end; both callers report the same formatCycleSummary() line. getServices selection is unchanged. Part C — honest MCP counters - mcp_queries_lifetime is incremented transactionally in logQuery, seeded once from the 90-day floor with mcp_counter_seeded_at exposed. Window fields renamed mcp_queries_90d / mcp_active_days_90d; mcp_active_days emits the 90d value for one release with mcp_active_days_deprecated: true. Expected one-time effect: the ~10 endpoints affected by the rejected 406 writes start recording down-bucket rows, so their uptime and reliability drop and one burst of ~10 service.health_changed events fires on the first post-deploy cycle. That is the truth arriving; no suppression code was added. Reconciliation adds three GROUP BY queries over services (~1.2k rows) and one counters write per cycle — under 0.1% of a cycle that runs in minutes, well inside the 10% budget. BEHAVIOR-CHANGE: rate_limited excluded from the uptime denominator — a 429 is our prober being throttled, not provider downtime; pinned by one test per status. ASSERTION-REFACTOR: corrected two fixtures in the new tests from this issue's test commit — a rebuild fixture row dated outside retention (pruned before the assertion could read it) and a pruneQueryLog(0) call that is a no-op at second granularity; the counters retention guard now targets age-based deletes instead of any DELETE. --- CHANGELOG.md | 10 + scripts/healthcheck.js | 5 +- src/db.js | 424 ++++++++++++++++++++--- src/health/checker.js | 361 +++++++++++++++++-- src/routes/api/digest.js | 48 ++- src/scheduler.js | 7 +- test/health-cycle-reconciliation.test.js | 20 ++ test/health-schema-integrity.test.js | 17 +- test/helpers/test-db.js | 16 +- test/mcp-counters.test.js | 24 +- 10 files changed, 818 insertions(+), 114 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 5dd7743..0808ce6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,15 +3,25 @@ ## [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 sum to all rows carrying the protocol — the real denominator behind the digest's "1,218" (#313) +- `GET /api/v1/digest`: new `health` section with `write_failures_lifetime`, `last_cycle` reconciliation, and `health_schema_invalid` (present only when the status enum is broken) (#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) +- `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) +- `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..6626dc6 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,125 @@ 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', + 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 +220,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 +436,210 @@ 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' + +/** + * 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) +} /** - * Rebuild health_checks if its status CHECK constraint is missing any allowed value. + * 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. + * @returns {string[]} statuses the constraint rejects (empty when the table is current) + */ +export function probeHealthCheckStatuses(database = db) { + 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 +} + +/** 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. + * + * @returns {{migrated: boolean, valid: 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 + try { + migrated = migrateHealthChecksStatusConstraint(database, { statfsSyncFn, logger }) + } catch (err) { + logger.error(`[db] health_checks status migration FAILED — health writes will be rejected: ${err.message}`) + setCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID, '1', database) + let stillRejected + try { + stillRejected = probeHealthCheckStatuses(database) + } catch { + stillRejected = HEALTH_CHECK_STATUSES.slice() + } + return { migrated: false, valid: false, missing: stillRejected, error: err.message } + } + + let missing + try { + missing = probeHealthCheckStatuses(database) + } catch (err) { + logger.error(`[db] health_checks schema probe FAILED: ${err.message}`) + setCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID, '1', database) + return { migrated, valid: false, missing: HEALTH_CHECK_STATUSES.slice(), error: err.message } + } + + 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) + return { migrated, valid: false, missing } + } + + deleteCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID, database) + return { migrated, valid: true, 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 +1176,82 @@ 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' + +export function isMcpUserAgent(userAgent) { + return typeof userAgent === 'string' && userAgent.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 user_agent LIKE '%' || @marker || '%' + AND timestamp > datetime('now', '-' || @days || ' days') + `).get({ marker: MCP_USER_AGENT_MARKER, 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..3a87afb 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,157 @@ export async function checkDiskSpace({ statfsFn = statfs, database = db } = {}) } } +// Rows a cycle never probes, counted straight from the table. getServices' exclusions are +// intentional (#236) and unchanged — reconciliation only has to account for them honestly. +const ACTIVE_PREDICATE = "(status = 'active' OR status IS NULL) AND (provider_deleted = 0 OR provider_deleted IS NULL)" + +const emptyProbedBreakdown = () => ({ healthy: 0, degraded: 0, down: 0, unknown: 0, error: 0 }) + +/** + * Which of these service ids still exist. The hourly purge can hard-delete a row after it was + * checked, and such a row is in no bucket's denominator — counting it anyway would push + * `unaccounted` negative and turn the one number that must stay 0 into routine noise. + */ +function existingServiceIds(ids, database = db) { + const list = [...ids] + const found = new Set() + const CHUNK = 500 + for (let i = 0; i < list.length; i += CHUNK) { + const chunk = list.slice(i, i + CHUNK) + const rows = database.prepare( + `SELECT id FROM services WHERE id IN (${chunk.map(() => '?').join(', ')})` + ).all(...chunk) + for (const row of rows) found.add(row.id) + } + return found +} + +/** + * Account for every services row carrying each protocol. + * + * The denominator is all rows with that protocol — 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. + * + * @returns {{byProtocol: Object, vanished: number}} buckets, plus rows hard-deleted mid-cycle + */ +function buildReconciliation({ protocolById, 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, + } + } + return recon[key] + } + + const protocolOf = id => protocolById.get(id) || 'unknown' + + for (const row of database.prepare( + "SELECT COALESCE(protocol, 'unknown') AS protocol, COUNT(*) AS c FROM services GROUP BY protocol" + ).all()) { + bucketFor(row.protocol).denominator = row.c + } + + for (const row of database.prepare( + `SELECT COALESCE(protocol, 'unknown') AS protocol, COUNT(*) AS c FROM services + WHERE NOT (${ACTIVE_PREDICATE}) GROUP BY protocol` + ).all()) { + bucketFor(row.protocol).excluded_inactive = row.c + } + + for (const row of database.prepare( + `SELECT COALESCE(protocol, 'unknown') AS protocol, COUNT(*) AS c FROM services + WHERE ${ACTIVE_PREDICATE} AND probe_status = 'unprobeable' GROUP BY protocol` + ).all()) { + bucketFor(row.protocol).skipped_unprobeable = row.c + } + + const live = existingServiceIds( + new Set([...probedById.keys(), ...siblingUpdatedIds, ...persistFailedIds]), + database + ) + let vanished = 0 + + // Precedence: a row that was probed is reported as probed even if a sibling pass also touched + // it, and a row counted here is never double-counted in another bucket. + for (const [id, status] of probedById) { + if (!live.has(id)) { vanished++; continue } + const bucket = bucketFor(protocolOf(id)) + bucket.probed[status] = (bucket.probed[status] || 0) + 1 + bucket.probed_total++ + } + for (const id of siblingUpdatedIds) { + if (probedById.has(id)) continue + if (!live.has(id)) { vanished++; continue } + bucketFor(protocolOf(id)).sibling_updated++ + } + for (const id of persistFailedIds) { + if (probedById.has(id) || siblingUpdatedIds.has(id)) continue + if (!live.has(id)) { vanished++; continue } + bucketFor(protocolOf(id)).persist_failed++ + } + + 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 } +} + +/** + * 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}`, + 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 @@ -928,15 +1164,20 @@ export async function runHealthChecks() { 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() + const protocolById = new Map(services.map(s => [s.id, s.protocol || 'unknown'])) 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 +1188,37 @@ 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) + if (!protocolById.has(sibling.id)) protocolById.set(sibling.id, sibling.protocol || 'unknown') + } + + for (const failure of result.value.persistFailures || []) { + persistFailures.push(failure) + persistFailedIds.add(failure.serviceId) + results.persistFailed++ + if (!protocolById.has(failure.serviceId)) { + protocolById.set(failure.serviceId, failure.protocol || 'unknown') + } + } + 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 +1231,51 @@ export async function runHealthChecks() { } const durationSec = ((Date.now() - startTime) / 1000).toFixed(1) + const { byProtocol: reconciliation, vanished } = buildReconciliation({ + protocolById, 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, + // Checked, then hard-deleted before the cycle finished — in no denominator, so in no bucket. + vanished_mid_cycle: vanished, + by_protocol: reconciliation, + } + if (vanished > 0) { + console.log(`[health] ${vanished} checked row(s) were deleted mid-cycle and are excluded from reconciliation`) + } + + // 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}` + ) + } + + // 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 +1286,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..c83a99d 100644 --- a/src/routes/api/digest.js +++ b/src/routes/api/digest.js @@ -1,5 +1,11 @@ import { Router } from 'express' -import db from '../../db.js' +import db, { + COUNTER_KEYS, + MCP_QUERY_LOG_RETENTION_DAYS, + getCounter, + getCounterInt, + mcpQueryWindowStats, +} from '../../db.js' const router = Router() @@ -97,10 +103,12 @@ router.get('/digest', (req, res) => { "SELECT COUNT(*) as c FROM query_log WHERE timestamp > date('now') AND user_agent LIKE '%402index-mcp%'" ).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 +174,25 @@ 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 + } + res.json({ generated_at: new Date().toISOString(), totals: { @@ -190,14 +217,21 @@ 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, }, 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/health-cycle-reconciliation.test.js b/test/health-cycle-reconciliation.test.js index b8502a7..4dfcf34 100644 --- a/test/health-cycle-reconciliation.test.js +++ b/test/health-cycle-reconciliation.test.js @@ -173,6 +173,26 @@ describe('reconciliation identity', () => { 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 change which endpoints get probed', async () => { const fixture = seedFixture() const probedUrls = new Set() diff --git a/test/health-schema-integrity.test.js b/test/health-schema-integrity.test.js index 4ab3f58..694ad19 100644 --- a/test/health-schema-integrity.test.js +++ b/test/health-schema-integrity.test.js @@ -265,8 +265,9 @@ describe('migration rebuild', () => { 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, '2026-07-01 12:00:00') + 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) @@ -275,7 +276,7 @@ describe('migration rebuild', () => { 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, '2026-07-01 12:00:00') + assert.equal(row.checked_at, before.checked_at) fixture.close() }) @@ -396,9 +397,17 @@ describe('counters table', () => { fixture.close() }) - it('is never pruned', () => { + it('carries no retention', () => { const source = readFileSync(new URL('../src/db.js', import.meta.url), 'utf8') - assert.ok(!/DELETE FROM counters/.test(source), 'counters must carry no retention') + // 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' + ) + 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', () => { 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 index 8a9e71c..aabdf7a 100644 --- a/test/mcp-counters.test.js +++ b/test/mcp-counters.test.js @@ -101,21 +101,25 @@ describe('seeding', () => { }) }) -// Runs last: pruneQueryLog(0) empties query_log for this process. describe('prune semantics', () => { - it('changes the 90d window but never the lifetime counter', () => { - logQuery({ queryText: 'keeper', userAgent: MCP_UA }) - logQuery({ queryText: 'keeper', userAgent: MCP_UA }) + 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 windowBefore = dbModule.mcpQueryWindowStats() - assert.ok(windowBefore.queries >= 2) + const before = dbModule.mcpQueryWindowStats() + assert.ok(before.queries >= 3, 'the window sees the stale rows') + assert.ok(before.activeDays >= 2) - pruneQueryLog(0) + pruneQueryLog(1) - const windowAfter = dbModule.mcpQueryWindowStats() - assert.equal(windowAfter.queries, 0, 'the window follows retention') - assert.equal(windowAfter.activeDays, 0) + 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' From 28e71af8870b9e395e3a52a79f98fcb836532a8c Mon Sep 17 00:00:00 2001 From: Ryan Gentry <41025545+ryanthegentry@users.noreply.github.com> Date: Sun, 26 Jul 2026 15:09:17 -0500 Subject: [PATCH 3/3] fix: address review feedback for #313 (revision 1) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit [High] Reconciliation is now a partition of a cycle-start snapshot. denominator/excluded_inactive/skipped_unprobeable came from GROUP BY queries run after the cycle, while the probe set was snapshotted at cycle start. The pollers share the health cycle's hourly interval and insert with status defaulting to 'active', so an insert mid-cycle pushed unaccounted to +1 and a deactivation mid-cycle put the same row in both probed and excluded_inactive (unaccounted -1). runHealthChecks now snapshots every services row before dispatch and buckets that fixed id set by precedence (probed > sibling_updated > persist_failed > inactive > unprobeable), so no row lands in two buckets. added_mid_cycle joins vanished_mid_cycle as the symmetric counterpart, per protocol and per cycle; neither is folded into the denominator. The unprobeable flag now mirrors getServices' predicate exactly instead of matching only probe_status='unprobeable'. [Medium] health_schema_invalid no longer latches on a transient DB error. probeHealthCheckStatuses retries SQLITE_BUSY/SQLITE_LOCKED and raises SchemaProbeUnavailableError when it cannot reach a verdict; only a non-empty rejected list sets health_schema_invalid. An indeterminate probe writes health_schema_probe_error (surfaced in the digest) and is cleared on the next determinate boot, so scripts/healthcheck.js booting against a mid-write server cannot raise a schema alarm that survives until the next deploy. [Low] One MCP predicate for the lifetime increment and the window queries. The JS half was case-sensitive includes() while SQL LIKE is case-insensitive for ASCII, so 402Index-MCP counted in mcp_queries_90d but never in mcp_queries_lifetime. Both halves now lowercase via the exported MCP_USER_AGENT_SQL, which the digest's mcp_queries_today also uses. [Low/informational] mcp_counters_ua_attested: true added to the digest traffic payload and documented in CHANGELOG — the counter is gated only on a client-controlled User-Agent and is never pruned, so it is a ceiling, not a measurement. Also tightened the counters-retention guard test, which the reviewer noted was narrower than its name: every DELETE against counters must now be key-scoped, not merely free of datetime(). Tests: 15 added, all verified failing against the previous head first (the two race tests reproduce the reviewer's exact numbers: denominator=2 on insert, excluded_inactive=1 on deactivate). Full suite 2088 pass / 0 fail / 5 skipped; eslint clean. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 8 +- src/db.js | 126 ++++++++++++++---- src/health/checker.js | 163 ++++++++++++----------- src/routes/api/digest.js | 14 +- test/digest-health-mcp-fields.test.js | 21 +++ test/health-cycle-reconciliation.test.js | 53 ++++++++ test/health-schema-integrity.test.js | 92 +++++++++++++ test/mcp-counters.test.js | 57 ++++++++ 8 files changed, 431 insertions(+), 103 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 0808ce6..0a5cd1a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,14 +4,17 @@ ### 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 sum to all rows carrying the protocol — the real denominator behind the digest's "1,218" (#313) -- `GET /api/v1/digest`: new `health` section with `write_failures_lifetime`, `last_cycle` reconciliation, and `health_schema_invalid` (present only when the status enum is broken) (#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` @@ -19,6 +22,7 @@ ### 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) diff --git a/src/db.js b/src/db.js index 6626dc6..3e024cd 100644 --- a/src/db.js +++ b/src/db.js @@ -123,6 +123,9 @@ export const COUNTER_KEYS = { 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', } @@ -466,16 +469,36 @@ function insertSchemaProbeParent(database) { } /** - * Which canonical statuses the current health_checks CHECK constraint refuses. - * - * 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 probe could not reach a verdict — distinct from "the schema rejected a status". * - * @returns {string[]} statuses the constraint rejects (empty when the table is current) + * 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 function probeHealthCheckStatuses(database = db) { +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 { @@ -497,6 +520,41 @@ export function probeHealthCheckStatuses(database = db) { return rejected } +/** + * Which canonical statuses the current health_checks CHECK constraint refuses. + * + * 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. + * + * 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 { @@ -595,7 +653,11 @@ export function migrateHealthChecksStatusConstraint(database = db, { statfsSyncF * fixed. The previous console.warn swallow is gone — a silenced schema failure is exactly how * ~10 endpoints per cycle lost their status writes unnoticed. * - * @returns {{migrated: boolean, valid: boolean, missing: string[], error?: string}} + * 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 { @@ -605,37 +667,41 @@ export function runHealthChecksSchemaGuard(database = db, { logger = console, st } let migrated = false + let migrationError = null try { migrated = migrateHealthChecksStatusConstraint(database, { statfsSyncFn, logger }) } catch (err) { - logger.error(`[db] health_checks status migration FAILED — health writes will be rejected: ${err.message}`) - setCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID, '1', database) - let stillRejected - try { - stillRejected = probeHealthCheckStatuses(database) - } catch { - stillRejected = HEALTH_CHECK_STATUSES.slice() + 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}`) } - return { migrated: false, valid: false, missing: stillRejected, error: err.message } } let missing try { missing = probeHealthCheckStatuses(database) } catch (err) { - logger.error(`[db] health_checks schema probe FAILED: ${err.message}`) - setCounter(COUNTER_KEYS.HEALTH_SCHEMA_INVALID, '1', database) - return { migrated, valid: false, missing: HEALTH_CHECK_STATUSES.slice(), error: err.message } + 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) - return { migrated, valid: false, missing } + 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) - return { migrated, valid: true, missing: [] } + deleteCounter(COUNTER_KEYS.HEALTH_SCHEMA_PROBE_ERROR, database) + return { migrated, valid: true, indeterminate: false, missing: [] } } runHealthChecksSchemaGuard(db) @@ -1181,8 +1247,18 @@ 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.includes(MCP_USER_AGENT_MARKER) + return typeof userAgent === 'string' && userAgent.toLowerCase().includes(MCP_USER_AGENT_MARKER) } // Throws on failure (unlike incrementCounter) so the enclosing transaction rolls back: the @@ -1221,9 +1297,9 @@ export function mcpQueryWindowStats(database = db, retentionDays = MCP_QUERY_LOG const row = database.prepare(` SELECT COUNT(*) AS queries, COUNT(DISTINCT date(timestamp)) AS activeDays FROM query_log - WHERE user_agent LIKE '%' || @marker || '%' + WHERE ${MCP_USER_AGENT_SQL} AND timestamp > datetime('now', '-' || @days || ' days') - `).get({ marker: MCP_USER_AGENT_MARKER, days: retentionDays }) + `).get({ days: retentionDays }) return { queries: row?.queries ?? 0, activeDays: row?.activeDays ?? 0 } } catch (err) { console.warn(`[db] mcpQueryWindowStats failed: ${err.message}`) diff --git a/src/health/checker.js b/src/health/checker.js index 3a87afb..ce68fb9 100644 --- a/src/health/checker.js +++ b/src/health/checker.js @@ -1000,42 +1000,51 @@ export async function checkDiskSpace({ statfsFn = statfs, database = db } = {}) } } -// Rows a cycle never probes, counted straight from the table. getServices' exclusions are -// intentional (#236) and unchanged — reconciliation only has to account for them honestly. +// 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 }) /** - * Which of these service ids still exist. The hourly purge can hard-delete a row after it was - * checked, and such a row is in no bucket's denominator — counting it anyway would push - * `unaccounted` negative and turn the one number that must stay 0 into routine noise. + * 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}[]} */ -function existingServiceIds(ids, database = db) { - const list = [...ids] - const found = new Set() - const CHUNK = 500 - for (let i = 0; i < list.length; i += CHUNK) { - const chunk = list.slice(i, i + CHUNK) - const rows = database.prepare( - `SELECT id FROM services WHERE id IN (${chunk.map(() => '?').join(', ')})` - ).all(...chunk) - for (const row of rows) found.add(row.id) - } - return found +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 all rows with that protocol — 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. + * 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}} buckets, plus rows hard-deleted mid-cycle + * @returns {{byProtocol: Object, vanished: number, added: number}} */ -function buildReconciliation({ protocolById, probedById, siblingUpdatedIds, persistFailedIds, database = db }) { +function buildReconciliation({ snapshot, probedById, siblingUpdatedIds, persistFailedIds, database = db }) { const recon = {} const bucketFor = protocol => { const key = protocol || 'unknown' @@ -1049,56 +1058,54 @@ function buildReconciliation({ protocolById, probedById, siblingUpdatedIds, pers excluded_inactive: 0, persist_failed: 0, unaccounted: 0, + added_mid_cycle: 0, + vanished_mid_cycle: 0, } } return recon[key] } - const protocolOf = id => protocolById.get(id) || 'unknown' - - for (const row of database.prepare( - "SELECT COALESCE(protocol, 'unknown') AS protocol, COUNT(*) AS c FROM services GROUP BY protocol" - ).all()) { - bucketFor(row.protocol).denominator = row.c - } - - for (const row of database.prepare( - `SELECT COALESCE(protocol, 'unknown') AS protocol, COUNT(*) AS c FROM services - WHERE NOT (${ACTIVE_PREDICATE}) GROUP BY protocol` - ).all()) { - bucketFor(row.protocol).excluded_inactive = row.c + // 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 COALESCE(protocol, 'unknown') AS protocol, COUNT(*) AS c FROM services - WHERE ${ACTIVE_PREDICATE} AND probe_status = 'unprobeable' GROUP BY protocol` + "SELECT id, COALESCE(protocol, 'unknown') AS protocol FROM services" ).all()) { - bucketFor(row.protocol).skipped_unprobeable = row.c - } - - const live = existingServiceIds( - new Set([...probedById.keys(), ...siblingUpdatedIds, ...persistFailedIds]), - database - ) - let vanished = 0 - - // Precedence: a row that was probed is reported as probed even if a sibling pass also touched - // it, and a row counted here is never double-counted in another bucket. - for (const [id, status] of probedById) { - if (!live.has(id)) { vanished++; continue } - const bucket = bucketFor(protocolOf(id)) - bucket.probed[status] = (bucket.probed[status] || 0) + 1 - bucket.probed_total++ - } - for (const id of siblingUpdatedIds) { - if (probedById.has(id)) continue - if (!live.has(id)) { vanished++; continue } - bucketFor(protocolOf(id)).sibling_updated++ + endIds.add(row.id) + if (!snapshotIds.has(row.id)) { + added++ + bucketFor(row.protocol).added_mid_cycle++ + } } - for (const id of persistFailedIds) { - if (probedById.has(id) || siblingUpdatedIds.has(id)) continue - if (!live.has(id)) { vanished++; continue } - bucketFor(protocolOf(id)).persist_failed++ + for (const row of snapshot) { + if (!endIds.has(row.id)) { + vanished++ + bucketFor(row.protocol).vanished_mid_cycle++ + } } for (const bucket of Object.values(recon)) { @@ -1108,7 +1115,7 @@ function buildReconciliation({ protocolById, probedById, siblingUpdatedIds, pers ) } - return { byProtocol: recon, vanished } + return { byProtocol: recon, vanished, added } } /** @@ -1130,6 +1137,7 @@ export function formatCycleSummary(result) { `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() } @@ -1160,6 +1168,10 @@ export async function runHealthChecks({ concurrency = CONCURRENCY } = {}) { 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...`) @@ -1171,7 +1183,6 @@ export async function runHealthChecks({ concurrency = CONCURRENCY } = {}) { 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() - const protocolById = new Map(services.map(s => [s.id, s.protocol || 'unknown'])) let checked = 0 const startTime = Date.now() @@ -1195,16 +1206,12 @@ export async function runHealthChecks({ concurrency = CONCURRENCY } = {}) { for (const sibling of result.value.siblingsUpdated || []) { siblingUpdatedIds.add(sibling.id) - if (!protocolById.has(sibling.id)) protocolById.set(sibling.id, sibling.protocol || 'unknown') } for (const failure of result.value.persistFailures || []) { persistFailures.push(failure) persistFailedIds.add(failure.serviceId) results.persistFailed++ - if (!protocolById.has(failure.serviceId)) { - protocolById.set(failure.serviceId, failure.protocol || 'unknown') - } } if (status === 'skipped') { @@ -1231,8 +1238,8 @@ export async function runHealthChecks({ concurrency = CONCURRENCY } = {}) { } const durationSec = ((Date.now() - startTime) / 1000).toFixed(1) - const { byProtocol: reconciliation, vanished } = buildReconciliation({ - protocolById, probedById, siblingUpdatedIds, persistFailedIds, + const { byProtocol: reconciliation, vanished, added } = buildReconciliation({ + snapshot, probedById, siblingUpdatedIds, persistFailedIds, }) const unaccounted = Object.values(reconciliation).reduce((sum, r) => sum + r.unaccounted, 0) @@ -1244,12 +1251,17 @@ export async function runHealthChecks({ concurrency = CONCURRENCY } = {}) { results: { ...results }, persist_failed: results.persistFailed, unaccounted, - // Checked, then hard-deleted before the cycle finished — in no denominator, so in no bucket. + // 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) { - console.log(`[health] ${vanished} checked row(s) were deleted mid-cycle and are excluded from 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. @@ -1264,7 +1276,8 @@ export async function runHealthChecks({ concurrency = CONCURRENCY } = {}) { `(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}` + `persist_failed=${r.persist_failed} unaccounted=${r.unaccounted} ` + + `added_mid_cycle=${r.added_mid_cycle} vanished_mid_cycle=${r.vanished_mid_cycle}` ) } diff --git a/src/routes/api/digest.js b/src/routes/api/digest.js index c83a99d..42ece46 100644 --- a/src/routes/api/digest.js +++ b/src/routes/api/digest.js @@ -2,6 +2,7 @@ import { Router } from 'express' import db, { COUNTER_KEYS, MCP_QUERY_LOG_RETENTION_DAYS, + MCP_USER_AGENT_SQL, getCounter, getCounterInt, mcpQueryWindowStats, @@ -99,8 +100,9 @@ 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 // MCP: a true lifetime counter, plus window aggregates named for the window they cover. @@ -192,6 +194,12 @@ router.get('/digest', (req, res) => { 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(), @@ -225,6 +233,10 @@ router.get('/digest', (req, res) => { // 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, diff --git a/test/digest-health-mcp-fields.test.js b/test/digest-health-mcp-fields.test.js index 0b4b85a..9c9c39b 100644 --- a/test/digest-health-mcp-fields.test.js +++ b/test/digest-health-mcp-fields.test.js @@ -54,6 +54,20 @@ describe('digest traffic: MCP counters', () => { 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', () => { @@ -69,6 +83,13 @@ describe('digest health section', () => { ) }) + 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 diff --git a/test/health-cycle-reconciliation.test.js b/test/health-cycle-reconciliation.test.js index 4dfcf34..f0b6274 100644 --- a/test/health-cycle-reconciliation.test.js +++ b/test/health-cycle-reconciliation.test.js @@ -193,6 +193,59 @@ describe('reconciliation identity', () => { } }) + 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() diff --git a/test/health-schema-integrity.test.js b/test/health-schema-integrity.test.js index 694ad19..5f68ecc 100644 --- a/test/health-schema-integrity.test.js +++ b/test/health-schema-integrity.test.js @@ -341,6 +341,10 @@ describe('migration failure is loud', () => { 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() @@ -350,17 +354,23 @@ describe('migration failure is loud', () => { 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', () => { @@ -372,6 +382,83 @@ describe('migration failure is loud', () => { }) }) +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) @@ -405,6 +492,11 @@ describe('counters table', () => { !/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') diff --git a/test/mcp-counters.test.js b/test/mcp-counters.test.js index aabdf7a..3ec27d0 100644 --- a/test/mcp-counters.test.js +++ b/test/mcp-counters.test.js @@ -10,6 +10,7 @@ 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' @@ -32,6 +33,62 @@ describe('MCP user-agent classification', () => { }) }) +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)