Skip to content

Commit b705853

Browse files
Render dropped rerank failure detail; count DegradeFlags to catch silent degradation (#11)
* Interpolate caught error detail into rerank/search log messages RerankHttpError already builds a fully diagnostic message (status, URL, body snippet), and search.ts already passed it through as a structured `error` context field on log.warn/log.error calls — but the configured log sink doesn't render context fields for these call sites, so the detail never reached a human. This is what let CL-4600's 100% rerank failure rate read as "retrieval is just a bit weak" for as long as it was deployed. Fix: interpolate the caught error's message directly into the log template at every affected call site, via a new formatCaughtError() helper (src/log.ts), while keeping the structured context field for sinks that do render it. Audited and fixed all catch sites in the search path with the same pattern: dense-retrieval fallback, all three rerank catch branches (RerankQueryTooLongError / RerankConfigError / generic), and the outer route-level catch in routes/search.ts. No behavior change — soft-degrade to fused ranking is preserved. Claude-Session: https://claude.ai/code/session_017GTgGzn5xAwvkU2GAPAHpF * Emit a counter per DegradeFlag so silent degradation is visible Reranking degraded on 100% of queries for as long as CL-4600 was deployed and nobody noticed, because DegradeFlag values were logged per-request but never aggregated — a flag nobody counts is indistinguishable from no flag at all. There is no metrics facility anywhere in this repo (no statsd, prometheus, or otel dependency; @intx/log exports no counter), and this is a mountable library, not a standalone service that owns its own /metrics port — so this adds none. New src/core/degrade-metrics.ts: an in-process counter per DegradeFlag plus a totalSearches counter (so a rate, not just a raw count, is computable), exported as getDegradeMetricsSnapshot() for a host with its own metrics backend to poll and forward, and re-exported from the package entrypoint. Rather than a setInterval, a structured summary log line fires every 100th call inside recordDegrade() itself, and escalates from log.info to log.error when a single flag has saturated the entire window — the exact shape of the incident that motivated this ticket. recordDegrade() is wired into hybridSearch once per invocation, immediately before return, covering every degrade path (dense down, rerank down, rerank query-too-long) and the fully healthy case. Claude-Session: https://claude.ai/code/session_017GTgGzn5xAwvkU2GAPAHpF * Rework degrade-metrics to detect near-neighbour incident shapes Replace the binary "every call in a fixed 100-call bucket" saturation check with a per-tenant, rate-based rolling window (200 calls) with hysteresis (20%/10% watermarks), so 99% failure, single-tenant outages among many tenants, and mid-window onset all escalate instead of only the exact 100%-of-100 shape from CL-4600. Escalation is checked on every call rather than only at the periodic-summary boundary. Key recordDegrade/getDegradeMetricsSnapshot by tenant with an LRU eviction over tracked tenants to bound memory. Add getAllDegradeMetricsSnapshots for hosts that poll every tenant. The snapshot now exposes a windowed rate alongside the lifetime cumulative counts, since cumulative-only numbers dilute a live incident into an unremarkable average. Interpolate every log message's numbers into the message string itself rather than relying on the context object, since some @intx/log sinks drop context — the same bug this PR's earlier commits fixed at routes/search.ts is also present at routes/capture.ts, embed-model-registry.ts, services/capture.ts, services/transform.ts, and a bare catch in knowledge.ts that discarded the error entirely. Fix all of them. Make ALL_DEGRADE_FLAGS exhaustive at compile time via a `satisfies Record<DegradeFlag, true>` object, so a new flag added to hybrid-search.ts without updating this module is a compile error. Decouple SUMMARY_INTERVAL (reporting cadence) from the detection window, and expose both plus the watermarks via configureDegradeMetrics so a host can tune them. Adopt the reviewer's scenario tests (mid-run onset, 99% failure, cumulative dilution, multi-tenant isolation) into the real suite as assertions against the fixed behavior. Claude-Session: https://claude.ai/code/session_017GTgGzn5xAwvkU2GAPAHpF * Guard degrade-metrics escalation against cold-start noise and fix exports A rate/hysteresis redesign closed the 99%/multi-tenant/mid-onset gaps but had no minimum-sample floor, so a cold or freshly-evicted tenant could escalate off one or two calls at small-sample noise. Hold escalation evaluation until a tenant's window has at least minSamplesFor(highWatermark) samples (32 at the default 20% watermark), derived from the n*p*(1-p) >= 5 rule of thumb for when a binomial proportion's normal approximation is trustworthy. Export configureDegradeMetrics and getAllDegradeMetricsSnapshots from the package entrypoint — the PR body promised a tunable operator surface, but only getDegradeMetricsSnapshot was reachable from outside core/degrade-metrics.ts. Validate every configureDegradeMetrics field, not just highWatermark > lowWatermark: reject non-integer or non-positive windowSize/summaryInterval/maxTrackedTenants (windowSize=0 previously made the window grow unbounded via slice(-0); summaryInterval=0 divided by zero and silenced summaries permanently) and out-of-[0,1)/[0,1] watermarks. Stop treating LRU eviction as tenant-blind: never evict a tenant that is currently escalated (falling back to evicting it anyway, loudly, only once every tracked tenant is escalated), and log every eviction so a tenant disappearing from getAllDegradeMetricsSnapshots is visible rather than silent. Replace the per-call O(windowSize) rate re-scan with a fixed-size circular buffer plus running per-flag counts, since the rate is computed up to 3 flags x (escalate-check + summary) times per search. Add tests for cold-start/low-sample escalation, an idle tenant's escalated state surviving in its snapshot, eviction during a live incident, and configureDegradeMetrics validation. Claude-Session: https://claude.ai/code/session_017GTgGzn5xAwvkU2GAPAHpF * Close configuration paths that could disable degrade escalation Round 2's minimum-sample floor stopped cold-start false positives but introduced three config-dependent ways to silence the alarm entirely: highWatermark=1 makes the floor's denominator p*(1-p) zero (Infinity samples needed, so escalation never evaluates); a windowSize smaller than the derived floor for a given watermark is unreachable the same way; and shrinking windowSize on a live tenant left its buffer length and windowFilled counter out of sync, producing a windowedDegradeRate above 1.0. Add one invariant, enforced in configureDegradeMetrics/validateConfig: no config the validator accepts may make escalation unreachable. The derived minimum-sample floor for highWatermark must be finite and must not exceed windowSize, or the config is rejected outright. This subsumes highWatermark=1 (non-finite floor) and any windowSize/ highWatermark pairing where the floor can't fit in the window, rather than special-casing either symptom. Resize every tracked tenant's rolling window in place when windowSize is reconfigured, rather than leaving existing tenants on their creation-time buffer length: cumulative totals survive, the window resets to empty and re-accumulates under the same minimum-sample floor as a new tenant. Adopt the reviewer's probes (watermark=1, window-smaller-than-floor, shrink-produces-rate>1) as permanent tests, plus new coverage that specifically reconfigures a watermark or windowSize and asserts escalation still fires afterward — the gap that let all three survive review. tmp/critique-tests/ removed. Claude-Session: https://claude.ai/code/session_017GTgGzn5xAwvkU2GAPAHpF
1 parent b3ab858 commit b705853

12 files changed

Lines changed: 1015 additions & 57 deletions

File tree

‎src/core/degrade-metrics.test.ts‎

Lines changed: 468 additions & 0 deletions
Large diffs are not rendered by default.

‎src/core/degrade-metrics.ts‎

Lines changed: 427 additions & 0 deletions
Large diffs are not rendered by default.

‎src/core/embed-model-registry.ts‎

Lines changed: 4 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
import { createHash, randomUUID } from "node:crypto";
22
import { type EmbedClientConfig, probeEmbedDims } from "./embed-client.ts";
3-
import { log } from "../log.ts";
3+
import { formatCaughtError, log } from "../log.ts";
44

55
// Dims are dynamic and discovered, never hard-coded — the dimension travels
66
// with exactly one artifact: the knowledge_embed_model.dims column,
@@ -102,12 +102,10 @@ export async function activateEmbedModel(
102102
[],
103103
);
104104
} catch (err) {
105+
const errMessage = formatCaughtError(err);
105106
log.warn(
106-
"embed-model-registry: hnsw index creation failed; falling back to ivfflat",
107-
{
108-
indexName,
109-
error: err instanceof Error ? err.message : String(err),
110-
},
107+
`embed-model-registry: hnsw index creation failed; falling back to ivfflat: ${errMessage}`,
108+
{ indexName, error: errMessage },
111109
);
112110
await client.query(
113111
`CREATE INDEX IF NOT EXISTS ${indexName} ON ${tableName} USING ivfflat (embedding vector_cosine_ops) WITH (lists = 100)`,

‎src/index.ts‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,16 @@ export type { KnowledgePlane } from "./knowledge.ts";
3030
export { CaptureLog, type CaptureEvent } from "./capture-log.ts";
3131
// Migrations
3232
export { runKnowledgeMigrations } from "./migrations.ts";
33+
// Degrade metrics — no metrics dependency exists in this package (see
34+
// core/degrade-metrics.ts); a host with its own metrics backend polls this
35+
// snapshot and forwards it, rather than the engine owning a /metrics port.
36+
export {
37+
getDegradeMetricsSnapshot,
38+
getAllDegradeMetricsSnapshots,
39+
configureDegradeMetrics,
40+
type DegradeMetricsSnapshot,
41+
type DegradeMetricsConfig,
42+
} from "./core/degrade-metrics.ts";
3343
// Granular mount (compose your own)
3444
export { mountKnowledgeRoutes, type GrantConfig } from "./routes/mount.ts";
3545

‎src/knowledge.ts‎

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
* and hybrid-search services directly — no HTTP hop.
44
*/
55
import type { EngineConfig } from "./config.ts";
6-
import { log } from "./log.ts";
6+
import { formatCaughtError, log } from "./log.ts";
77
import { createDb, type Db, type RawSql } from "./db/client.ts";
88
import type { VisibilitySpec } from "./core/schemas/document.ts";
99
import { captureDocument } from "./services/capture.ts";
@@ -87,12 +87,14 @@ export function createKnowledgePlane(config: KnowledgeConfig): KnowledgePlane {
8787
let list: unknown;
8888
try {
8989
list = JSON.parse(raw);
90-
} catch {
90+
} catch (err) {
9191
// Unparseable block list → fail closed: hide the doc rather than
9292
// risk surfacing something a corrupt ACL meant to block.
93-
log.warn("search: unparseable acl_block, blocking document", {
94-
documentId: row.id,
95-
});
93+
const errMessage = formatCaughtError(err);
94+
log.warn(
95+
`search: unparseable acl_block, blocking document: ${errMessage}`,
96+
{ documentId: row.id, error: errMessage },
97+
);
9698
blocked.add(row.id);
9799
continue;
98100
}

‎src/log.test.ts‎

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,26 @@
1+
import { describe, expect, it } from "bun:test";
2+
import { formatCaughtError } from "./log.ts";
3+
import { RerankHttpError } from "./core/rerank-client.ts";
4+
5+
describe("formatCaughtError", () => {
6+
it("returns an Error's message, unchanged", () => {
7+
expect(formatCaughtError(new Error("boom"))).toBe("boom");
8+
});
9+
10+
it("carries a RerankHttpError's full diagnostic message (status, url, body) through untouched — this is the exact detail CL-4599 was dropping at render time", () => {
11+
const err = new RerankHttpError(
12+
413,
13+
'{"error":"Input validation error: `inputs` must have less than 512 tokens. Given: 855"}',
14+
"https://rerank.example/rerank",
15+
);
16+
const message = formatCaughtError(err);
17+
expect(message).toContain("413");
18+
expect(message).toContain("https://rerank.example/rerank");
19+
expect(message).toContain("must have less than 512 tokens");
20+
});
21+
22+
it("stringifies a non-Error thrown value rather than dropping it", () => {
23+
expect(formatCaughtError("plain string throw")).toBe("plain string throw");
24+
expect(formatCaughtError(42)).toBe("42");
25+
});
26+
});

‎src/log.ts‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,3 +2,14 @@ import { getLogger } from "@intx/log";
22

33
/** Category-bound logger for the knowledge engine (uses the host's sinks). */
44
export const log = getLogger(["knowledge-engine"]);
5+
6+
// Some `@intx/log` sinks do not render a call's context object into the
7+
// terminal/aggregator output — only the message string is guaranteed to
8+
// reach a human. Every catch site in the search path must therefore
9+
// interpolate the caught error's detail directly into the log message
10+
// template, not rely solely on passing it as a structured context field.
11+
// This is the single place that formats "whatever got thrown" into a string
12+
// worth reading, so every call site produces the same shape.
13+
export function formatCaughtError(err: unknown): string {
14+
return err instanceof Error ? err.message : String(err);
15+
}

‎src/routes/capture.ts‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@ import type { TenantEnv } from "@intx/hub-api";
33
import { describeRoute, resolver, validator } from "hono-openapi";
44
import { type } from "arktype";
55

6-
import { log } from "../log.ts";
6+
import { formatCaughtError, log } from "../log.ts";
77
import { parseAcl } from "../acl.ts";
88
import type { RouteDeps } from "./deps.ts";
99
import { caller, grantGuard } from "./deps.ts";
@@ -60,7 +60,8 @@ export function mountCaptureRoute(app: Hono<TenantEnv>, deps: RouteDeps): void {
6060
});
6161
return c.json({ status: "captured" });
6262
} catch (err) {
63-
log.error("knowledge capture failed", { err });
63+
const errMessage = formatCaughtError(err);
64+
log.error(`knowledge capture failed: ${errMessage}`, { error: errMessage });
6465
return c.json({ error: "capture failed" }, 502);
6566
}
6667
},

‎src/routes/search.ts‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@ import type { TenantEnv } from "@intx/hub-api";
33
import { describeRoute, resolver, validator } from "hono-openapi";
44
import { type } from "arktype";
55

6-
import { log } from "../log.ts";
6+
import { formatCaughtError, log } from "../log.ts";
77
import { KnowledgeError } from "../knowledge.ts";
88
import { SearchResponseSchema } from "../core/schemas/search.ts";
99
import type { RouteDeps } from "./deps.ts";
@@ -45,7 +45,8 @@ export function mountSearchRoute(app: Hono<TenantEnv>, deps: RouteDeps): void {
4545
});
4646
return c.json(result);
4747
} catch (err) {
48-
log.error("knowledge search failed", { err });
48+
const errMessage = formatCaughtError(err);
49+
log.error(`knowledge search failed: ${errMessage}`, { err });
4950
if (err instanceof KnowledgeError) {
5051
return c.json({ error: err.message }, err.status as 400);
5152
}

‎src/services/capture.ts‎

Lines changed: 14 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,7 @@ import { and, desc, eq } from "drizzle-orm";
44
import type { Db, RawSql } from "../db/client.ts";
55
import type { EngineConfig } from "../config.ts";
66
import { newId } from "../core/id.ts";
7-
import { log } from "../log.ts";
7+
import { formatCaughtError, log } from "../log.ts";
88
import { stableStringify } from "../core/hash.ts";
99
import { LIVE_GENERATION } from "../core/generation.ts";
1010
import {
@@ -517,27 +517,26 @@ async function embedInsertedChunksWithConfig(
517517
);
518518

519519
if (result.clientError) {
520-
log.warn("capture: embedding client failed; chunks remain pending", {
521-
tenantId,
522-
chunkCount: chunks.length,
523-
error: result.clientError,
524-
});
520+
log.warn(
521+
`capture: embedding client failed; chunks remain pending: ${result.clientError}`,
522+
{ tenantId, chunkCount: chunks.length, error: result.clientError },
523+
);
525524
return { degraded: true };
526525
}
527526
if (result.rejected.length > 0) {
528-
log.warn("capture: some chunks were rejected during embedding", {
529-
tenantId,
530-
rejected: result.rejected,
531-
});
527+
log.warn(
528+
`capture: ${result.rejected.length} chunk(s) rejected during embedding`,
529+
{ tenantId, rejected: result.rejected },
530+
);
532531
return { degraded: true };
533532
}
534533
return { degraded: false };
535534
} catch (err) {
536-
log.warn("capture: embedding pass failed; chunks remain pending", {
537-
tenantId,
538-
chunkCount: chunks.length,
539-
error: err instanceof Error ? err.message : String(err),
540-
});
535+
const errMessage = formatCaughtError(err);
536+
log.warn(
537+
`capture: embedding pass failed; chunks remain pending: ${errMessage}`,
538+
{ tenantId, chunkCount: chunks.length, error: errMessage },
539+
);
541540
return { degraded: true };
542541
}
543542
}

0 commit comments

Comments
 (0)