diff --git a/README.md b/README.md index 405f0e6..40282a7 100644 --- a/README.md +++ b/README.md @@ -124,6 +124,8 @@ Use `cached(fn, options)` for an extracted, reusable function. The wrapped calla | `defaultConfig` | no | `DialCacheKeyConfig` baseline policy that runtime config overlays field by field (see [Runtime config](#runtime-config-and-ramp-controls)). | | `serializer` | when the return type is not statically JSON-compatible | Per-function `Serializer` for Redis values (see [Serialization](#serialization)). | | `shadowComparator` | no | Synchronous application-level equality for shadow validation; defaults to Node's strict deep equality. | +| `shadowMismatchLogValue` | no | Projects a compared value into its loggable form for opted-in mismatch warnings; without it those warnings log raw native JSON (see [Mismatch logging](#shadow-validation)). | +| `shadowMismatchLogDiff` | no | Replaces the built-in structural diff in opted-in mismatch warnings; receives the raw compared values. | | `trackForInvalidation` | no (default `false`) | Opts this use case's Redis entries into watermark-based targeted invalidation. | | `fallbackTimeoutMs` | no (default `60_000`) | Fallback deadline in milliseconds, at most 2,147,483,647; `null` disables it (see [Fallback deadlines](#fallback-deadlines)). | @@ -209,23 +211,23 @@ Instance-wide behavior is set through the `DialCache` constructor: | `metrics` | disabled | A `DialCacheMetricsAdapter` (see [Metrics](#metrics)). | | `logger` | `console` | Receives operational cache failures and opted-in confirmed shadow mismatch warnings (`debug`, `warn`, `error`). Synchronous throws and rejections from returned promises or thenables are isolated without being awaited. | -Per-invocation cache policy is a `DialCacheKeyConfig`: per-layer `ttlSec` and `ramp` maps keyed by `CacheLayer.LOCAL` (process-local) and `CacheLayer.REMOTE` (Redis), a `requestLocal` boolean, a `coalesce` boolean (see [Request coalescing](#request-coalescing)), an optional `remoteReadTimeoutMs`, and an optional `shadow` group. `ShadowConfig` contains the independent shadow `ramp` percentage plus the default-off `logMismatches` control. +Per-invocation cache policy is a `DialCacheKeyConfig`: per-layer `ttlSec` and `ramp` maps keyed by `CacheLayer.LOCAL` (process-local) and `CacheLayer.REMOTE` (Redis), a `requestLocal` boolean, a `coalesce` boolean (see [Request coalescing](#request-coalescing)), an optional `remoteReadTimeoutMs`, and an optional `shadow` group. `ShadowConfig` contains the independent shadow `ramp` percentage plus the default-off `mismatchLogging` group: independent `key`, `value`, and `diff` booleans selecting the content of confirmed-mismatch warnings. Every cached definition or `getOrLoad()` invocation can provide an optional per-use-case `defaultConfig`. It is the baseline policy, and the `cacheConfigProvider` result is a sparse field-level overlay on that baseline. For cache enablement fields, precedence is runtime config, then `defaultConfig`, then DialCache's disabled baseline. For the remote-read deadline, precedence is runtime `remoteReadTimeoutMs`, `defaultConfig.remoteReadTimeoutMs`, `redis.readTimeoutMs`, then the 50 ms library default. -The disabled baseline sets `requestLocal` to false, leaves the process-local and Redis TTLs unset, and sets `shadow.ramp` to 0% with mismatch logging false. A shared layer with no effective TTL is disabled by policy. When a shared layer has an effective TTL but no effective ramp, its ramp defaults to 100%. Shadow work remains disabled unless `shadow.ramp` is explicitly greater than zero. +The disabled baseline sets `requestLocal` to false, leaves the process-local and Redis TTLs unset, and sets `shadow.ramp` to 0% with every `mismatchLogging` field false. A shared layer with no effective TTL is disabled by policy. When a shared layer has an effective TTL but no effective ramp, its ramp defaults to 100%. Shadow work remains disabled unless `shadow.ramp` is explicitly greater than zero. `DialCacheKeyConfig` preserves an omitted `requestLocal` as `undefined` so the overlay can distinguish omission from an explicit `false`; the effective value still defaults to false after resolution. An omitted `coalesce` is preserved the same way, and its effective value defaults to true, so request coalescing stays on unless a use case explicitly opts out. -A provider result of `null` (or defensive `undefined`) applies no overrides. An empty `DialCacheKeyConfig` and omitted runtime fields also inherit the baseline. Top-level fields, cache-layer leaves, and leaves inside `shadow` merge independently; an explicit `false` logging flag overrides an inherited `true`. Use explicit values to override inherited policy: `requestLocal: false` disables request-local caching and a layer ramp of `0` disables that shared layer. `DialCacheKeyConfig.disabled()` is the complete new-cache-invocation kill switch in one call: request-local and shadow work off, shadow logging off, and both shared layers ramped to 0. It leaves `coalesce` unset: with every layer off there is no in-flight sharing to disable, and a use case ramped back up at runtime coalesces again unless it explicitly opts out. It does not cancel already-admitted work, and explicit maintenance operations such as `invalidateRemote()` remain available. To stop new cache-invocation Redis reads and fills while preserving other runtime settings, explicitly set both `ramp.remote` and `shadow.ramp` to `0`; the remote ramp alone stops serving but does not override an inherited nonzero shadow ramp. +A provider result of `null` (or defensive `undefined`) applies no overrides. An empty `DialCacheKeyConfig` and omitted runtime fields also inherit the baseline. Top-level fields, cache-layer leaves, leaves inside `shadow`, and leaves inside `shadow.mismatchLogging` merge independently; an explicit `false` logging leaf overrides an inherited `true`. Use explicit values to override inherited policy: `requestLocal: false` disables request-local caching and a layer ramp of `0` disables that shared layer. `DialCacheKeyConfig.disabled()` is the complete new-cache-invocation kill switch in one call: request-local and shadow work off, shadow logging off, and both shared layers ramped to 0. It leaves `coalesce` unset: with every layer off there is no in-flight sharing to disable, and a use case ramped back up at runtime coalesces again unless it explicitly opts out. It does not cancel already-admitted work, and explicit maintenance operations such as `invalidateRemote()` remain available. To stop new cache-invocation Redis reads and fills while preserving other runtime settings, explicitly set both `ramp.remote` and `shadow.ramp` to `0`; the remote ramp alone stops serving but does not override an inherited nonzero shadow ramp. -DialCache validates `defaultConfig` when `cached()` registers a definition and whenever `getOrLoad()` is invoked: TTLs must be positive safe integers no greater than 31,536,000 seconds (a fixed 365-day duration), remote-read deadlines must be positive safe integers within their documented limit, layer and shadow ramps must be finite percentages from 0 to 100, layer maps and `shadow` must be objects, and `requestLocal`, `coalesce`, and `shadow.logMismatches` must be booleans when present. Invalid defaults are rejected immediately. +DialCache validates known `defaultConfig` fields when `cached()` registers a definition and whenever `getOrLoad()` is invoked: TTLs must be positive safe integers no greater than 31,536,000 seconds (a fixed 365-day duration), remote-read deadlines must be positive safe integers within their documented limit, layer and shadow ramps must be finite percentages from 0 to 100, layer maps, `shadow`, and `shadow.mismatchLogging` must be objects, and `requestLocal`, `coalesce`, and the `shadow.mismatchLogging` fields must be booleans when present. Invalid known defaults are rejected immediately. Unknown own fields are ignored while every recognized field is retained; one `config_unknown_field` error metric is recorded when such a default is observed, without putting the field name or value in labels. Each registration or one-shot invocation captures an immutable internal snapshot of `defaultConfig`; mutating the supplied config or its maps later does not change that operation's baseline. Runtime policy changes belong in the provider's returned overlay. -Runtime TTL and ramp leaves are used as supplied instead of falling back to valid default leaves. A TTL outside the same 1-to-31,536,000-second range disables that layer with `invalid_ttl`; a nonnumeric, non-finite, or out-of-range ramp disables it with `invalid_ramp`. Valid ramps include both `0` and `100`. Other layers can still run, and invalid leaves also record a `config_resolution` error so provider garbage is alertable separately from intentional ramp-downs. A malformed runtime config object, layer-map shape, `requestLocal` value, `coalesce` value, explicit `remoteReadTimeoutMs`, or removed top-level `shadowRamp` fails config resolution for the invocation, records `config_error`, and executes the fallback uncached without attempting Redis. The public `DialCacheKeyConfig` constructor and static defaults likewise reject `shadowRamp` immediately; migrate it to `shadow.ramp`. +Runtime TTL and ramp leaves are used as supplied instead of falling back to valid default leaves. A TTL outside the same 1-to-31,536,000-second range disables that layer with `invalid_ttl`; a nonnumeric, non-finite, or out-of-range ramp disables it with `invalid_ramp`. Valid ramps include both `0` and `100`. Other layers can still run, and invalid leaves also record a `config_resolution` error so provider garbage is alertable separately from intentional ramp-downs. A malformed runtime config object, layer-map shape, `requestLocal` value, `coalesce` value, explicit `remoteReadTimeoutMs`, or non-object `shadow.mismatchLogging` group fails config resolution for the invocation, records `config_error`, and executes the fallback uncached without attempting Redis. Unknown own fields at the top level, in layer maps, in `shadow`, or in `shadow.mismatchLogging` are ignored while known fields still apply. That includes removed `shadowRamp` and `shadow.logMismatches` fields from older or mixed-version providers. Each observed config containing one or more unknown fields records one `config_unknown_field` error metric; arbitrary field names and values never become labels. -An invalid runtime `shadow.ramp` does not affect the cache result or disable an otherwise valid Redis policy. If normal traversal reaches an otherwise shadow-eligible Redis path, DialCache skips shadow work and records a `config_resolution` error. An invalid runtime `shadow.logMismatches` likewise preserves the cache result, Redis policy, shadow result, and shadow metric while suppressing the warning. DialCache validates this diagnostic leaf only after the metrics hook, exact-key cohort, and capacity gates admit shadow work, then records one remote `config_resolution` error for that admitted resolution. +An invalid runtime `shadow.ramp` does not affect the cache result or disable an otherwise valid Redis policy. If normal traversal reaches an otherwise shadow-eligible Redis path, DialCache skips shadow work and records a `config_resolution` error. An invalid known runtime `shadow.mismatchLogging` field likewise preserves the cache result, Redis policy, shadow result, and shadow metric; that field acts false while valid sibling fields still log. Unknown fields are removed before the leaf-wise merge, so recognized sibling overrides and inherited recognized defaults remain effective. DialCache validates known diagnostic leaves only after the metrics hook, exact-key cohort, and capacity gates admit shadow work, then records one remote `config_resolution` error for that admitted resolution. A non-object `mismatchLogging` group is malformed config shape rather than an invalid field: like a malformed layer map, it fails resolution as `config_error` and the invocation runs uncached. The `shadow` group and everything inside it are read by own properties only, at the constructor, defaults-snapshot, and runtime-merge boundaries alike; prototype-inherited policy never activates or triggers unknown-field telemetry. `cacheConfigProvider` is called for every enabled cache invocation before DialCache performs any cache lookup. Keep it cheap, cache any remote/config-store reads inside the provider, and avoid work that would erase the benefit of a cache hit. @@ -241,8 +243,9 @@ const dialcache = new DialCache({ // Independently sample Redis keys for detached validation/fill. shadow: { ramp: 5, - // Emit one warning with a bounded key and native-JSON value strings. - logMismatches: true, + // Emit one bounded warning per confirmed mismatch: key plus a + // structural diff, without the full value payloads. + mismatchLogging: { key: true, diff: true }, }, // Can be changed by the provider at runtime for this use case. remoteReadTimeoutMs: 35, @@ -526,22 +529,25 @@ const getUser = dialcache.cached( // Optional: override strict deep equality with use-case semantics. shadowComparator: (cached, source) => cached.id === source.id && cached.version === source.version, + // Optional: opted-in warnings log this projection instead of raw values, + // and the built-in diff runs over the same projected forms. + shadowMismatchLogValue: (value) => ({ id: value.id, version: value.version }), defaultConfig: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 300 }, // Exercise and populate Redis without serving it to callers. ramp: { [CacheLayer.REMOTE]: 0 }, shadow: { ramp: 5, - // Default-off warning with a bounded key and native-JSON value strings. - // Enable only after approving the logger and data-handling policy. - logMismatches: true, + // Default-off warning content, chosen field by field. Enable only + // after approving the logger and data-handling policy. + mismatchLogging: { key: true, value: true, diff: true }, }, }), }, ); ``` -Shadow work is eligible only when a valid remote TTL/policy exists, its effective `shadow.ramp` selects the exact cache key, a configured metrics adapter implements `shadowValidation`, and capacity is available. Tracked and untracked Redis keys are both eligible; each keeps its existing read and write mode. Logging is supplemental to the metric; enabling `logMismatches` does not activate shadow work without the metrics hook. The bundled Prometheus and Datadog adapters implement that hook. There are two paths: +Shadow work is eligible only when a valid remote TTL/policy exists, its effective `shadow.ramp` selects the exact cache key, a configured metrics adapter implements `shadowValidation`, and capacity is available. Tracked and untracked Redis keys are both eligible; each keeps its existing read and write mode. Logging is supplemental to the metric; enabling `mismatchLogging` does not activate shadow work without the metrics hook. The bundled Prometheus and Datadog adapters implement that hook. There are two paths: - When remote serving is enabled and produces a Redis hit, DialCache retains the exact serialized payload that supplied the caller as `C0`. - When the remote policy is valid but disabled specifically by `ramped_down`, DialCache starts a detached Redis read for `C0` using the key's existing tracked or untracked mode. Its result can be validated or used to decide whether a clean miss may be filled, but can never supply the caller or populate an in-memory layer. @@ -586,13 +592,23 @@ The effective serializer's `load` method therefore runs a second time for a samp Shadow metrics use the bounded outcomes `match`, `mismatch`, `superseded`, `filled`, `fill_blocked`, `fill_error`, `redis_error`, `source_error`, `deserialization_error`, `comparison_error`, `confirmation_error`, `timeout`, and `dropped`. `redis_error` applies to the initial shadow-only `C0` read; `confirmation_error` applies to `C1`; `fill_blocked` applies only when a tracked watermark rejects the write. A clean `C0` miss is an ordinary `miss{layer="remote_shadow"}` and terminates with a fill, source, or timeout outcome rather than a second shadow outcome for the miss itself. Labels never contain cache ids, values, payloads, Redis keys, or raw exception text. -A `match` or `mismatch` verdict additionally records the validated value's age through the optional `observeShadowValueAge` adapter hook: the observing process's epoch clock minus the validated frame's `createdAtMs` (the served `C0` frame, or the detached `C0` frame on a ramped-down path), in seconds, clamped at zero. The age is captured at verdict time, so a mismatch age lands one confirmation read after the comparison itself. A confirmed `mismatch` age therefore measures how long the stale value had been readable when validation caught it. Tracked frames are stamped with Redis server time and untracked frames with the writer's client clock, so the age mixes clocks and is coarse operational evidence rather than a precise measurement. Outcomes that deliver no verdict on a retained value — including `superseded`, `filled`, and every error or timeout outcome — record no age. The hook does not gate shadow eligibility; only `shadowValidation` does. +A `match` or `mismatch` verdict additionally records the validated value's age through the optional `observeShadowValueAge` adapter hook: the observing process's epoch clock minus the validated frame's `createdAtMs` (the served `C0` frame, or the detached `C0` frame on a ramped-down path), in seconds, clamped at zero. The age is captured at verdict time, so a mismatch age lands one confirmation read after the comparison itself. A confirmed `mismatch` age therefore measures how long the stale value had been readable when validation caught it. Tracked frames are stamped with Redis server time and untracked frames with the writer's client clock, so the age mixes clocks and is coarse operational evidence rather than a precise measurement. Outcomes that deliver no verdict on a retained value — including `superseded`, `filled`, and every error or timeout outcome — record no age. Opted-in mismatch warnings carry the same age as `cachedValueAgeSeconds`. The hook does not gate shadow eligibility; only `shadowValidation` does. -Confirmed-mismatch logging is separately opt-in through `shadow.logMismatches`; it never replaces the required `shadowValidation` metric or emits for a mismatch candidate that becomes `superseded`. The single warning contains `cacheNamespace`, `useCase`, `keyType`, `outcome: "mismatch"`, `cacheKey`, `cachedValueJson`, and `sourceValueJson`. `cacheKey` is the logical DialCache URN capped at 2 KiB, not the physical Redis storage key. DialCache independently applies native `JSON.stringify` to the deserialized cached snapshot and raw source value supplied to the comparator, then caps each resulting string at 8 KiB. A byte-clipped field ends in `...[truncated]`, counted inside its cap. If native JSON throws or returns `undefined`, the corresponding JSON field is `null`; the other side is still attempted. DialCache does not compute a textual diff or call the configured serializer again for logging. +Confirmed-mismatch logging is separately opt-in through the `shadow.mismatchLogging` group; it never replaces the required `shadowValidation` metric or emits for a mismatch candidate that becomes `superseded`. One warning is emitted per confirmed mismatch when at least one group field is true, and it always carries `cacheNamespace`, `useCase`, `keyType`, `outcome: "mismatch"`, and `cachedValueAgeSeconds` — the same coarse mixed-clock age the `observeShadowValueAge` hook records for the verdict, measuring how long the stale value had been readable when validation caught it. Each enabled field adds one bounded piece of content, so warnings stay useful for values that must not reach logs whole: -Mismatch logging is intentionally default-off. Logical URNs can contain ids and arguments, while cached and source values may contain secrets or personal data; truncation is not redaction. DialCache creates the JSON strings only after terminal mismatch confirmation and never passes the raw compared-value references to the logger. Native JSON semantics apply: getters and `toJSON` methods may run, unsupported values may be omitted or normalized, and cycles or `bigint` can make a field unavailable. Stringification is synchronous, and the 8 KiB caps apply only after `JSON.stringify` returns; they do not bound input traversal, hook execution, event-loop time, or the intermediate JSON string. Enable mismatch logging only for trusted, reasonably bounded values and with an approved logger, redaction, transport, access, and retention policy. +- `key: true` adds `cacheKey`: the logical DialCache URN capped at 2 KiB, not the physical Redis storage key. +- `value: true` adds `cachedValueJson` and `sourceValueJson`: native `JSON.stringify` of each compared side, capped at 8 KiB per side. When the use case defines `shadowMismatchLogValue`, each side is that projection's result instead of the raw value; the projector runs once per side. Without a projector the deserialized cached snapshot and raw source value are stringified as-is. +- `diff: true` adds `diffJson`, capped at 8 KiB: the `shadowMismatchLogDiff` result when the use case defines one (it receives the raw compared values), and otherwise a built-in structural diff — computed over the same loggable forms `value` uses, so a projector bounds the diff exactly as it bounds value logging. -The byte caps apply before logger framing or escaping, so they do not guarantee a final transport event below a sink-specific limit; the metadata fields are not size-clamped. A detail-construction failure degrades to the metadata-only warning. Logger throws and rejected promises or thenables remain isolated from cache and shadow correctness. +A byte-clipped field ends in `...[truncated]`, counted inside its cap. Every hook invocation and JSON step fails closed: a projector throw or returned promise-like value logs `null` for that side (and a `null` built-in diff), a diff-hook throw, promise-like result, or unserializable output logs `diffJson: null`, and native-JSON failure on one side leaves the other side attempted. Promise-like settlements are consumed but never awaited, preserving the synchronous hook contract without unhandled rejections. DialCache never calls the configured serializer again for logging. + +The built-in diff renders each side to native JSON exactly once per warning — the same loggable forms `value: true` shows — and derives both the value fields and the diff from those single snapshots, so `toJSON` redaction and serializer normalization bound the diff exactly as they bound value logging, a stateful `toJSON` cannot make the two outputs disagree, and a cached side deserialized to an ISO string never phantom-differs from a live source `Date` at the same instant. A side with no JSON rendering — top-level `undefined`, cycles, `bigint`, a thrown hook, or a failed projection — fails the diff closed to `null`; the diff never attests anything about inputs value logging cannot show. Identical loggable snapshots yield `[]`; with a projector that reads as "the difference is inside fields the projection hides", and structures native JSON flattens (a `Map` renders as `{}`) read the same way. Otherwise DialCache's own bounded differ emits entries of `{ type: "CREATE" | "REMOVE" | "CHANGE", path, value, oldValue }` oriented from the cached side to the source side: `oldValue` is cached, `value` is source. It walks only own enumerable keys and array indices of the parsed JSON forms. Nodes of the same container kind (both objects or both arrays) diff recursively, with array entries compared by index, so an element shift reports every later index; a pair of differing kinds — primitives, `null`, or mixed object/array — collapses to one change entry at its path, including the root. The diff is rendering evidence, not the comparator's verdict: a custom comparator can ignore fields the diff still reports, and can compare structures native JSON flattens. + +Both hooks run only after terminal mismatch confirmation, inside detached shadow work, under the comparator's discipline: synchronous, deterministic, side-effect-free, non-mutating, and bounded, over borrowed references. Hook output feeds `JSON.stringify` directly. + +Mismatch logging is intentionally default-off, and its runtime fields choose exposure per use case: logical URNs can contain ids and arguments, while cached and source values may contain secrets or personal data, and truncation is not redaction. Without a projector, `value: true` and `diff: true` log raw value material — define `shadowMismatchLogValue` for any use case whose values can carry sensitive fields before enabling those flags, and prefer `key` plus a projected `diff` over full value payloads. DialCache creates the JSON strings only after terminal mismatch confirmation and never passes the raw compared-value references to the logger. Native JSON semantics apply: getters and `toJSON` methods may run, unsupported values may be omitted or normalized, and cycles or `bigint` can make a field unavailable. Stringification is synchronous, and the byte caps apply only after `JSON.stringify` returns; they do not bound input traversal, hook execution, event-loop time, or the intermediate JSON string. Enable mismatch logging only for trusted, reasonably bounded values and with an approved logger, redaction, transport, access, and retention policy. + +The byte caps apply before logger framing or escaping, so they do not guarantee a final transport event below a sink-specific limit; the metadata fields are not size-clamped. Every warning field fails closed independently — a failed preview logs `null` for that field while the rest still emit. Logger throws and rejected promises or thenables remain isolated from cache and shadow correctness. Detached Redis reads, serializer loads/dumps, payload sizes, and read/write errors use the existing layer label with `layer="remote_shadow"`. This distinguishes non-serving Redis cost from caller-path `layer="remote"` telemetry without adding a metric or label. The established `observeGet{layer="remote"}` boundary includes caller-path deserialization, while `observeGet{layer="remote_shadow"}` ends when the deadline-bounded Redis read result settles; detached serializer work and any later raw-client settlement are outside that timer. The request-path read that supplied a served `C0` keeps `layer="remote"`, and a ramped-down caller keeps `disabled{layer="remote", reason="ramped_down"}`. No `disabled{layer="remote_shadow"}` event is emitted for ineligible or dropped work; `dropped` remains the terminal shadow outcome. Confirmation reads use the same `remote_shadow` value, with `superseded` or `confirmation_error` describing their role. @@ -872,12 +888,13 @@ Observer throws and rejections from returned promises or thenables are isolated ### Error categories -The `error` label reports where an operation failed rather than copying the thrown value's class or `Error.name`: +The `error` label reports a bounded operational category rather than copying a thrown value's class, `Error.name`, or config field name: | `error` | Meaning | | --- | --- | | `key_construction` | The cache-key selector or `DialCacheKey` construction failed | | `config_resolution` | Runtime or layer configuration, or ramp resolution, failed | +| `config_unknown_field` | A default or runtime key config carried one or more ignored unknown own fields | | `cache_read` | A local-cache or Redis read failed | | `cache_read_timeout` | A Redis read exceeded its effective remote-read deadline | | `cache_write` | A local-cache or Redis write failed; tracked Redis writes add a benign self-healing floor under same-key contention (see [Redis-backed TTL cache](#redis-backed-ttl-cache)) | diff --git a/scripts/test-package.mjs b/scripts/test-package.mjs index 03b00ed..5245619 100644 --- a/scripts/test-package.mjs +++ b/scripts/test-package.mjs @@ -47,6 +47,7 @@ const rootConsumer = `import { type Serializer, type ShadowComparator, type ShadowConfig, + type ShadowMismatchLoggingConfig, type ShadowValidationMetricLabels, type ShadowValidationOutcome, } from "dialcache"; @@ -147,9 +148,14 @@ const shadowCacheConfig: DialCacheConfig = { shadowMaxInFlight: 2, }; const shadowCache = new DialCache(shadowCacheConfig); +const shadowMismatchLoggingConfig: ShadowMismatchLoggingConfig = { + key: true, + value: true, + diff: true, +}; const shadowConfig: ShadowConfig = { ramp: 50, - logMismatches: true, + mismatchLogging: shadowMismatchLoggingConfig, }; const shadowKeyConfig = new DialCacheKeyConfig({ shadow: shadowConfig }); const dogStatsDClient: DatadogDogStatsDClient = { @@ -203,6 +209,11 @@ const load = cache.cached(async (id: string) => id, { cacheKey: (id) => id, fallbackTimeoutMs: 1_000, shadowComparator: stringShadowComparator, + shadowMismatchLogValue: (value) => value.length, + shadowMismatchLogDiff: (cachedValue, sourceValue) => ({ + cachedLength: cachedValue.length, + sourceLength: sourceValue.length, + }), defaultConfig: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.LOCAL]: 100, [CacheLayer.REMOTE]: 100 }, @@ -361,6 +372,7 @@ const legacyMissingConfigReason: DisabledReason = "missing_config"; const metricErrorKinds: Readonly> = { key_construction: true, config_resolution: true, + config_unknown_field: true, cache_read: true, cache_read_timeout: true, cache_write: true, @@ -909,7 +921,9 @@ if ( esmDisabledOverlay.requestLocal !== false || esmDisabledOverlay.coalesce !== undefined || esmDisabledOverlay.shadow?.ramp !== 0 - || esmDisabledOverlay.shadow.logMismatches !== false + || esmDisabledOverlay.shadow.mismatchLogging?.key !== false + || esmDisabledOverlay.shadow.mismatchLogging.value !== false + || esmDisabledOverlay.shadow.mismatchLogging.diff !== false || esmDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 || esmDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0 ) { @@ -1284,7 +1298,9 @@ if ( cjsDisabledOverlay.requestLocal !== false || cjsDisabledOverlay.coalesce !== undefined || cjsDisabledOverlay.shadow?.ramp !== 0 - || cjsDisabledOverlay.shadow.logMismatches !== false + || cjsDisabledOverlay.shadow.mismatchLogging?.key !== false + || cjsDisabledOverlay.shadow.mismatchLogging.value !== false + || cjsDisabledOverlay.shadow.mismatchLogging.diff !== false || cjsDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 || cjsDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0 ) { diff --git a/src/config.ts b/src/config.ts index 5b89c81..d38e7a1 100644 --- a/src/config.ts +++ b/src/config.ts @@ -11,15 +11,108 @@ export enum CacheLayer { export type Awaitable = T | Promise; export type LayerConfig = Partial>; +/** + * Content controls for the one warning emitted per confirmed shadow mismatch. + * Every field defaults to false; the warning is emitted only when at least one + * field is true. Fields merge independently at runtime, like cache-layer leaves. + */ +export interface ShadowMismatchLoggingConfig { + /** Include the logical cache key (the DialCache URN, byte-capped). */ + readonly key?: boolean; + /** + * Include bounded native-JSON strings for the compared values. Values pass + * through the use case's `shadowMismatchLogValue` projection when one is + * defined and are logged raw otherwise. + */ + readonly value?: boolean; + /** + * Include a bounded JSON diff of the compared values: the use case's + * `shadowMismatchLogDiff` result when defined, and otherwise a structural + * diff of the same loggable forms `value` uses. + */ + readonly diff?: boolean; +} + /** Per-use-case runtime policy for detached Redis shadow work. */ export interface ShadowConfig { /** Independent stable cohort percentage. Omitted and zero disable shadow work. */ readonly ramp?: number; - /** - * Emit one warning with the logical key and bounded native-JSON strings for - * the compared values for each confirmed mismatch. Defaults to false. - */ - readonly logMismatches?: boolean; + /** Confirmed-mismatch warning content. Omitted, empty, and all-false disable the warning. */ + readonly mismatchLogging?: ShadowMismatchLoggingConfig; +} + +interface DialCacheKeyConfigInput { + readonly ttlSec?: LayerConfig; + readonly ramp?: LayerConfig; + readonly shadow?: ShadowConfig; + readonly requestLocal?: boolean; + readonly coalesce?: boolean; + readonly remoteReadTimeoutMs?: number; +} + +// `satisfies Record` fails to compile when the interface gains +// a field this set is missing, so every leaf loop stays exhaustive. +const SHADOW_MISMATCH_LOGGING_LEAF_SET = { + key: true, + value: true, + diff: true, +} as const satisfies Record; + +/** Internal: the exhaustive `ShadowMismatchLoggingConfig` field list. */ +export const SHADOW_MISMATCH_LOGGING_LEAVES = Object.keys( + SHADOW_MISMATCH_LOGGING_LEAF_SET, +) as readonly (keyof ShadowMismatchLoggingConfig)[]; + +const KEY_CONFIG_FIELD_SET = { + ttlSec: true, + ramp: true, + shadow: true, + requestLocal: true, + coalesce: true, + remoteReadTimeoutMs: true, +} as const satisfies Record; +const KEY_CONFIG_FIELDS = Object.keys(KEY_CONFIG_FIELD_SET); +const SHADOW_CONFIG_FIELD_SET = { + ramp: true, + mismatchLogging: true, +} as const satisfies Record; +const SHADOW_CONFIG_FIELDS = Object.keys(SHADOW_CONFIG_FIELD_SET); +const UNKNOWN_KEY_CONFIG_FIELDS = Symbol("DialCacheKeyConfig.unknownFields"); + +interface UnknownFieldMarkedConfig { + readonly [UNKNOWN_KEY_CONFIG_FIELDS]?: true; +} + +/** Internal: reports unknown own string fields without exposing their names. */ +export function hasUnknownKeyConfigFields(config: unknown): boolean { + if (!isConfigObject(config)) { + return false; + } + if ( + Object.hasOwn(config, UNKNOWN_KEY_CONFIG_FIELDS) + && (config as UnknownFieldMarkedConfig)[UNKNOWN_KEY_CONFIG_FIELDS] === true + ) { + return true; + } + if (hasUnknownOwnFields(config, KEY_CONFIG_FIELDS)) { + return true; + } + + const ttlSec = readOwnUnknown(config, "ttlSec"); + const ramp = readOwnUnknown(config, "ramp"); + const shadow = readOwnUnknown(config, "shadow"); + if ( + hasUnknownOwnFields(ttlSec, Object.values(CacheLayer)) + || hasUnknownOwnFields(ramp, Object.values(CacheLayer)) + || hasUnknownOwnFields(shadow, SHADOW_CONFIG_FIELDS) + ) { + return true; + } + + const mismatchLogging = isConfigObject(shadow) + ? readOwnUnknown(shadow, "mismatchLogging") + : undefined; + return hasUnknownOwnFields(mismatchLogging, SHADOW_MISMATCH_LOGGING_LEAVES); } export class DialCacheKeyConfig { @@ -46,23 +139,17 @@ export class DialCacheKeyConfig { */ readonly remoteReadTimeoutMs?: number; - constructor(config: { - ttlSec?: LayerConfig; - ramp?: LayerConfig; - shadow?: ShadowConfig; - requestLocal?: boolean; - coalesce?: boolean; - remoteReadTimeoutMs?: number; - }) { + constructor(config: DialCacheKeyConfigInput) { if (config === null || typeof config !== "object" || Array.isArray(config)) { throw new TypeError("DialCache key config must be an object"); } - if (Object.hasOwn(config, "shadowRamp")) { - throw new TypeError('DialCacheKeyConfig.shadowRamp was replaced by "shadow.ramp"'); - } + const hasUnknownFields = hasUnknownKeyConfigFields(config); this.ttlSec = cloneLayerConfig(config.ttlSec, "ttlSec"); this.ramp = cloneLayerConfig(config.ramp, "ramp"); - const shadow = cloneShadowConfig(config.shadow); + // Own-property read: `shadow` carries the log-content controls, so a + // prototype-inherited group must not activate policy (its leaves would + // all be own properties and pass every later gate). + const shadow = cloneShadowConfig(Object.hasOwn(config, "shadow") ? config.shadow : undefined); if (shadow !== undefined) { this.shadow = shadow; } @@ -82,6 +169,9 @@ export class DialCacheKeyConfig { assertValidDeadlineMs(config.remoteReadTimeoutMs, "DialCache remoteReadTimeoutMs"); this.remoteReadTimeoutMs = config.remoteReadTimeoutMs; } + if (hasUnknownFields) { + Object.defineProperty(this, UNKNOWN_KEY_CONFIG_FIELDS, { value: true }); + } } static enabled(ttlSec: number): DialCacheKeyConfig { @@ -109,7 +199,14 @@ export class DialCacheKeyConfig { requestLocal: false, shadow: { ramp: 0, - logMismatches: false, + // `Required` keeps this kill-switch overlay exhaustive: leaves merge + // independently, so an omitted leaf would let an inherited `true` + // survive disabled(). + mismatchLogging: { + key: false, + value: false, + diff: false, + } satisfies Required, }, ramp: { [CacheLayer.LOCAL]: 0, @@ -126,7 +223,14 @@ function cloneLayerConfig(config: LayerConfig | undefined, name: "ttlSec" | "ram if (config === null || typeof config !== "object" || Array.isArray(config)) { throw new TypeError(`DialCache ${name} config must be a layer map`); } - return { ...config }; + const clone: LayerConfig = {}; + for (const layer of Object.values(CacheLayer)) { + const value = Object.hasOwn(config, layer) ? config[layer] : undefined; + if (value !== undefined) { + clone[layer] = value; + } + } + return clone; } function cloneShadowConfig(config: ShadowConfig | undefined): ShadowConfig | undefined { @@ -136,7 +240,37 @@ function cloneShadowConfig(config: ShadowConfig | undefined): ShadowConfig | und if (config === null || typeof config !== "object" || Array.isArray(config)) { throw new TypeError("DialCache shadow config must be an object"); } - return { ...config }; + const ramp = Object.hasOwn(config, "ramp") ? config.ramp : undefined; + const mismatchLogging = Object.hasOwn(config, "mismatchLogging") ? config.mismatchLogging : undefined; + if (mismatchLogging === undefined) { + return ramp === undefined ? {} : { ramp }; + } + if (mismatchLogging === null || typeof mismatchLogging !== "object" || Array.isArray(mismatchLogging)) { + throw new TypeError("DialCache shadow mismatchLogging config must be an object"); + } + const clonedLogging: Record = {}; + for (const leaf of SHADOW_MISMATCH_LOGGING_LEAVES) { + if (Object.hasOwn(mismatchLogging, leaf)) { + clonedLogging[leaf] = mismatchLogging[leaf]; + } + } + return { + ...(ramp === undefined ? {} : { ramp }), + mismatchLogging: clonedLogging as ShadowMismatchLoggingConfig, + }; +} + +function isConfigObject(value: unknown): value is Record { + return value !== null && typeof value === "object" && !Array.isArray(value); +} + +function hasUnknownOwnFields(value: unknown, knownFields: readonly string[]): boolean { + return isConfigObject(value) + && Object.keys(value).some((name) => !knownFields.includes(name)); +} + +function readOwnUnknown(source: Record, key: string): unknown { + return Object.hasOwn(source, key) ? source[key] : undefined; } /** diff --git a/src/dialcache.ts b/src/dialcache.ts index afd8468..bf6e963 100644 --- a/src/dialcache.ts +++ b/src/dialcache.ts @@ -4,10 +4,13 @@ import { isDeepStrictEqual } from "node:util"; import { CacheLayer, DialCacheKeyConfig, + SHADOW_MISMATCH_LOGGING_LEAVES, + hasUnknownKeyConfigFields, type Awaitable, type CacheConfigProvider, type DialCacheConfig, type Logger, + type ShadowMismatchLoggingConfig, } from "./config.js"; import { DialCacheContext, getOrCreateRequestLocalCache, type RequestLocalCache } from "./context.js"; import { FallbackTimeoutError, UseCaseIsAlreadyRegisteredError, UseCaseNameIsReservedError } from "./errors.js"; @@ -41,7 +44,14 @@ import { type LayerConfigResolution, type ResolvedLayerConfig, } from "./internal/runtime-config.js"; -import { shadowMismatchLogDetails } from "./internal/shadow-log-json.js"; +import { + SHADOW_LOG_DIFF_MAX_BYTES, + previewShadowLogJson, + previewShadowLogKey, + renderShadowMismatchJson, + type ShadowLoggableSide, + type ShadowMismatchLogFields, +} from "./internal/shadow-log-json.js"; type CacheKeyArgs = Record; type Id = string | number | bigint; @@ -126,6 +136,24 @@ interface CacheOperationOptionsBase { * This is stable use-case behavior, not runtime rollout configuration. */ readonly shadowComparator?: ShadowComparator; + /** + * Projects a compared value into its loggable form for mismatch warnings. + * Feeds `mismatchLogging.value` output and the built-in structural diff; + * without it, opted-in warnings log the raw native-JSON forms. Runs once per + * side after terminal mismatch confirmation, inside detached shadow work. + * Must be synchronous, deterministic, side-effect-free, non-mutating, and + * bounded; inputs are borrowed snapshots. A throw or returned promise-like + * value logs `null` for that side. + */ + readonly shadowMismatchLogValue?: (value: Value) => unknown; + /** + * Replaces the built-in structural diff for mismatch warnings that enable + * `mismatchLogging.diff`. Receives the raw compared values, not the + * `shadowMismatchLogValue` projections. Same execution constraints as + * `shadowMismatchLogValue`; a throw or returned promise-like value logs a + * `null` diff. + */ + readonly shadowMismatchLogDiff?: (cachedValue: Value, sourceValue: Value) => unknown; /** * Monotonic deadline applied once an initially enabled invocation starts its * fallback, in milliseconds. Must be at most 2,147,483,647. Defaults to 60 @@ -221,11 +249,17 @@ interface ShadowValidationPlan { readonly comparator: ShadowComparator; readonly timeoutMs: number; readonly didCallerFallbackTimeout: () => boolean; + readonly logValue?: (value: Value) => unknown; + readonly logDiff?: (cachedValue: Value, sourceValue: Value) => unknown; } -interface ShadowMismatchDetails { - readonly cachedValue: unknown; - readonly sourceValue: unknown; +/** Resolved runtime content controls for one admitted shadow job's warning. */ +type ShadowLogPlan = Required; + +const SHADOW_LOG_PLAN_OFF: ShadowLogPlan = { key: false, value: false, diff: false }; + +function shadowLogPlanActive(plan: ShadowLogPlan): boolean { + return Object.values(plan).some(Boolean); } type ShadowValidationStart = @@ -347,10 +381,14 @@ export class DialCache { * values are shared by reference and must be treated as immutable. */ cached(fn: Fn, options: CachedOptions): CachedFn { + const hasUnknownDefaultFields = hasUnknownKeyConfigFields(options.defaultConfig); const defaultConfig = snapshotDefaultConfig(options.defaultConfig); const fallbackTimeoutMs = resolveFallbackTimeoutMs(options.fallbackTimeoutMs); const shadowComparator = resolveShadowComparator(options.shadowComparator); this.registerUseCase(options.useCase); + if (hasUnknownDefaultFields) { + this.recordUnknownConfigFields(options); + } return (...args: Parameters): Promise> => this.executeCacheOperation( @@ -372,10 +410,14 @@ export class DialCache { * shared by reference and must be treated as immutable. */ getOrLoad(load: () => Awaitable, options: GetOrLoadOptions): Promise { + const hasUnknownDefaultFields = hasUnknownKeyConfigFields(options.defaultConfig); const defaultConfig = snapshotDefaultConfig(options.defaultConfig); const fallbackTimeoutMs = resolveFallbackTimeoutMs(options.fallbackTimeoutMs); const shadowComparator = resolveShadowComparator(options.shadowComparator); this.assertUseCaseIsNotReserved(options.useCase); + if (hasUnknownDefaultFields) { + this.recordUnknownConfigFields(options); + } return this.executeCacheOperation( load, @@ -422,6 +464,12 @@ export class DialCache { comparator: shadowComparator, timeoutMs: fallbackTimeoutMs ?? DEFAULT_FALLBACK_TIMEOUT_MS, didCallerFallbackTimeout: () => callerFallbackTimedOut, + ...(options.shadowMismatchLogValue === undefined + ? {} + : { logValue: options.shadowMismatchLogValue }), + ...(options.shadowMismatchLogDiff === undefined + ? {} + : { logDiff: options.shadowMismatchLogDiff }), }; let key: DialCacheKey; @@ -439,7 +487,11 @@ export class DialCache { let keyConfig: DialCacheKeyConfig | null; try { - keyConfig = await fetchKeyConfig(this.configProvider, key); + keyConfig = await fetchKeyConfig( + this.configProvider, + key, + () => this.recordError(key, NO_CACHE_LAYER, "config_unknown_field"), + ); } catch (error) { // Provider failure: fail open and run uncached, mirroring the per-layer config_error path. this.logger.warn("Could not resolve DialCache key config", error); @@ -821,7 +873,11 @@ export class DialCache { } const resolvedShadowConfig = shadowConfig as Record; - const shadowPercentage: unknown = resolvedShadowConfig.ramp; + // Own-property reads throughout runtime shadow config: neither admission + // nor warning content may be inherited from a prototype. + const shadowPercentage: unknown = Object.hasOwn(resolvedShadowConfig, "ramp") + ? resolvedShadowConfig.ramp + : undefined; if (shadowPercentage === undefined || shadowPercentage === 0) { return; } @@ -845,7 +901,7 @@ export class DialCache { this.recordShadowValidation(key, "dropped"); return; } - const logMismatches = this.resolveShadowLogging(key, resolvedShadowConfig); + const logPlan = this.resolveShadowLogging(key, resolvedShadowConfig); const flight: ShadowFlight = { cachedFrame: start.kind === "retained" ? start.frame : null, @@ -865,23 +921,45 @@ export class DialCache { runStart, validation, readTimeoutMs, - logMismatches, + logPlan, ); } private resolveShadowLogging( key: DialCacheKey, shadowConfig: Record, - ): boolean { - const configuredLogMismatches = shadowConfig.logMismatches; - if (configuredLogMismatches === undefined) { - return false; + ): ShadowLogPlan { + // A non-object group never reaches this read: the constructor and the + // runtime merge both reject malformed group shapes as config errors, like + // malformed layer maps. Only leaf values arrive unvalidated. + const configured = Object.hasOwn(shadowConfig, "mismatchLogging") + ? shadowConfig.mismatchLogging + : undefined; + if (configured === undefined) { + return SHADOW_LOG_PLAN_OFF; } - if (typeof configuredLogMismatches !== "boolean") { + const group = configured as Record; + let sawInvalidLeaf = false; + const resolveLeaf = (name: keyof ShadowMismatchLoggingConfig): boolean => { + const leaf = Object.hasOwn(group, name) ? group[name] : undefined; + if (leaf === undefined) { + return false; + } + if (typeof leaf !== "boolean") { + sawInvalidLeaf = true; + return false; + } + return leaf; + }; + const plan: ShadowLogPlan = { + key: resolveLeaf("key"), + value: resolveLeaf("value"), + diff: resolveLeaf("diff"), + }; + if (sawInvalidLeaf) { this.recordError(key, CacheLayer.REMOTE, "config_resolution"); - return false; } - return configuredLogMismatches; + return plan; } private deferShadowValidation( @@ -891,7 +969,7 @@ export class DialCache { start: ShadowValidationRunStart, validation: ShadowValidationPlan, readTimeoutMs: number, - logMismatches: boolean, + logPlan: ShadowLogPlan, ): void { setImmediate(() => { this.runShadowValidation( @@ -901,7 +979,7 @@ export class DialCache { start, validation, readTimeoutMs, - logMismatches, + logPlan, ); }).unref(); } @@ -913,7 +991,7 @@ export class DialCache { start: ShadowValidationRunStart, plan: ShadowValidationPlan, readTimeoutMs: number, - logMismatches: boolean, + logPlan: ShadowLogPlan, ): void { const pendingRedisReads = new Set>(); let operationFinished = false; @@ -963,7 +1041,7 @@ export class DialCache { }; const elapsedBeforeStartMs = Math.max(performance.now() - deadlineStartedAtMs, 0); const remainingTimeoutMs = Math.max(plan.timeoutMs - elapsedBeforeStartMs, 0); - let mismatchDetails: ShadowMismatchDetails | undefined; + let mismatchLogDetails: ShadowMismatchLogFields | undefined; let validatedValueAgeSeconds: number | undefined; const validation = withMonotonicDeadline({ @@ -1099,8 +1177,10 @@ export class DialCache { if (confirmationFrame === null || !redisPayloadsEqual(originalFrame.payload, confirmationFrame.payload)) { return "superseded"; } - if (logMismatches) { - mismatchDetails = { cachedValue, sourceValue }; + if (logPlan.value || logPlan.diff) { + // Cannot throw: every hook call and preview inside fails closed + // to a null field. + mismatchLogDetails = renderShadowMismatchLog(logPlan, plan, cachedValue, sourceValue); } validatedValueAgeSeconds = shadowValueAgeSeconds(originalFrame.createdAtMs); return "mismatch"; @@ -1111,7 +1191,7 @@ export class DialCache { }); void validation.then( - (outcome) => this.recordShadowValidation(key, outcome, logMismatches, mismatchDetails, validatedValueAgeSeconds), + (outcome) => this.recordShadowValidation(key, outcome, logPlan, mismatchLogDetails, validatedValueAgeSeconds), () => this.recordShadowValidation(key, "timeout"), ); } @@ -1119,8 +1199,8 @@ export class DialCache { private recordShadowValidation( key: DialCacheKey, outcome: ShadowValidationOutcome, - logMismatches = false, - mismatchDetails?: ShadowMismatchDetails, + logPlan: ShadowLogPlan = SHADOW_LOG_PLAN_OFF, + mismatchLogDetails?: ShadowMismatchLogFields, valueAgeSeconds?: number, ): void { const labels = { @@ -1133,35 +1213,26 @@ export class DialCache { if (valueAgeSeconds !== undefined) { this.metrics?.observeShadowValueAge?.(labels, valueAgeSeconds); } - if (outcome !== "mismatch" || !logMismatches) { + if (outcome !== "mismatch" || !shadowLogPlanActive(logPlan)) { return; } - const warning = { + // Throw-free by construction: every preview fails closed to null and the + // logger is observer-isolated, so no belt-and-suspenders fallback exists. + // Built fresh rather than from `labels`, which a metrics adapter may have + // mutated after it was handed over above. + this.logger.warn("DialCache shadow validation mismatch", { cacheNamespace: key.namespace, useCase: key.useCase, keyType: key.keyType, outcome: "mismatch", - } as const; - if (mismatchDetails !== undefined) { - try { - this.logger.warn( - "DialCache shadow validation mismatch", - { - ...warning, - ...shadowMismatchLogDetails( - key.urn, - mismatchDetails.cachedValue, - mismatchDetails.sourceValue, - ), - }, - ); - return; - } catch { - // JSON detail construction is best-effort; preserve the metadata warning. - } - } - this.logger.warn("DialCache shadow validation mismatch", warning); + // The same coarse mixed-clock age observeShadowValueAge records for + // this verdict: how long the stale value had been readable when + // validation caught it. Metadata-tier, so it rides on every warning. + ...(valueAgeSeconds === undefined ? {} : { cachedValueAgeSeconds: valueAgeSeconds }), + ...(logPlan.key ? { cacheKey: previewShadowLogKey(key.urn) } : {}), + ...mismatchLogDetails, + }); } private async resolveLocalLayerConfig( @@ -1260,6 +1331,17 @@ export class DialCache { this.metrics?.error({ ...labelsFor(key, layer), error: kind, inFallback: false }); } + private recordUnknownConfigFields(options: { readonly useCase: string; readonly keyType: string }): void { + this.metrics?.error({ + cacheNamespace: this.namespace, + useCase: options.useCase, + keyType: options.keyType, + layer: NO_CACHE_LAYER, + error: "config_unknown_field", + inFallback: false, + }); + } + /** * Invalid runtime TTL/ramp leaves can only come from provider results, since * static defaults are validated before the operation executes. Count them as @@ -1392,12 +1474,11 @@ function snapshotDefaultConfig(config: DialCacheKeyConfig | null | undefined): D if (typeof config !== "object" || Array.isArray(config)) { throw new TypeError("DialCache defaultConfig must be an object"); } - if (Object.hasOwn(config, "shadowRamp")) { - throw new TypeError('DialCacheKeyConfig.shadowRamp was replaced by "shadow.ramp"'); - } const ttlSecConfig = config.ttlSec; const rampConfig = config.ramp; - const shadowConfig = config.shadow; + // Own-property read, mirroring the constructor: an inherited shadow group + // must not activate log-content policy. + const shadowConfig = Object.hasOwn(config, "shadow") ? config.shadow : undefined; const requestLocal = config.requestLocal; const coalesce = config.coalesce; const remoteReadTimeoutMs = config.remoteReadTimeoutMs; @@ -1454,14 +1535,23 @@ function snapshotDefaultConfig(config: DialCacheKeyConfig | null | undefined): D throw new RangeError("DialCache defaultConfig shadow.ramp must be between 0 and 100"); } } - if (snapshot.shadow.logMismatches !== undefined && typeof snapshot.shadow.logMismatches !== "boolean") { - throw new TypeError("DialCache defaultConfig shadow.logMismatches must be a boolean"); + const mismatchLogging = snapshot.shadow.mismatchLogging; + if (mismatchLogging !== undefined) { + for (const leaf of SHADOW_MISMATCH_LOGGING_LEAVES) { + const configured = mismatchLogging[leaf]; + if (configured !== undefined && typeof configured !== "boolean") { + throw new TypeError(`DialCache defaultConfig shadow.mismatchLogging.${leaf} must be a boolean`); + } + } } } Object.freeze(snapshot.ttlSec); Object.freeze(snapshot.ramp); if (snapshot.shadow !== undefined) { + if (snapshot.shadow.mismatchLogging !== undefined) { + Object.freeze(snapshot.shadow.mismatchLogging); + } Object.freeze(snapshot.shadow); } return Object.freeze(snapshot); @@ -1574,6 +1664,67 @@ function resolveShadowComparator( return comparator ?? isDeepStrictEqual; } +// Runs only after terminal mismatch confirmation, inside detached shadow work. +// Every hook invocation and JSON step fails closed to a `null` field so a bad +// projection can never surface raw values or affect the recorded outcome. +function renderShadowMismatchLog( + logPlan: ShadowLogPlan, + plan: ShadowValidationPlan, + cachedValue: Value, + sourceValue: Value, +): ShadowMismatchLogFields { + const includeBuiltInDiff = logPlan.diff && plan.logDiff === undefined; + const logValue = plan.logValue; + const needsProjection = logValue !== undefined && (logPlan.value || includeBuiltInDiff); + const cachedLoggable: ShadowLoggableSide = needsProjection + ? runShadowLogHook(() => logValue(cachedValue)) + : { available: true, value: cachedValue }; + const sourceLoggable: ShadowLoggableSide = needsProjection + ? runShadowLogHook(() => logValue(sourceValue)) + : { available: true, value: sourceValue }; + + const rendered: ShadowMismatchLogFields = logPlan.value || includeBuiltInDiff + ? renderShadowMismatchJson( + cachedLoggable, + sourceLoggable, + { value: logPlan.value, diff: includeBuiltInDiff }, + ) + : {}; + const logDiff = plan.logDiff; + if (logPlan.diff && logDiff !== undefined) { + const diff = runShadowLogHook(() => logDiff(cachedValue, sourceValue)); + return { + ...rendered, + diffJson: diff.available + ? previewShadowLogJson(diff.value, SHADOW_LOG_DIFF_MAX_BYTES) + : null, + }; + } + return rendered; +} + +function runShadowLogHook(hook: () => unknown): ShadowLoggableSide { + try { + const value = hook(); + if (isThenable(value)) { + // The hook contract is synchronous, but its `unknown` return type also + // accepts async functions. Ignore their output and consume rejection; + // awaiting here would silently turn this into a second async contract. + void Promise.resolve(value).catch(() => undefined); + return { available: false }; + } + return { available: true, value }; + } catch { + return { available: false }; + } +} + +function isThenable(value: unknown): value is PromiseLike { + return value !== null + && (typeof value === "object" || typeof value === "function") + && typeof (value as { readonly then?: unknown }).then === "function"; +} + // Frame stamps are epoch-based (Redis server time for tracked writes, writer // client clock for untracked), so the age uses the epoch clock and clamps // negative cross-clock skew to zero. A custom client that violates the decode diff --git a/src/index.ts b/src/index.ts index cc10a23..a5df1e2 100644 --- a/src/index.ts +++ b/src/index.ts @@ -1,5 +1,12 @@ export { CacheLayer, DialCacheKeyConfig } from "./config.js"; -export type { CacheConfigProvider, DialCacheConfig, LayerConfig, Logger, ShadowConfig } from "./config.js"; +export type { + CacheConfigProvider, + DialCacheConfig, + LayerConfig, + Logger, + ShadowConfig, + ShadowMismatchLoggingConfig, +} from "./config.js"; export { DialCacheContext } from "./context.js"; export type { CacheMetricLabels, diff --git a/src/internal/runtime-config.ts b/src/internal/runtime-config.ts index fdabb70..dcb6ed5 100644 --- a/src/internal/runtime-config.ts +++ b/src/internal/runtime-config.ts @@ -1,9 +1,12 @@ import { CacheLayer, DialCacheKeyConfig, + SHADOW_MISMATCH_LOGGING_LEAVES, + hasUnknownKeyConfigFields, type CacheConfigProvider, type LayerConfig, type ShadowConfig, + type ShadowMismatchLoggingConfig, } from "../config.js"; import type { DialCacheKey } from "../key.js"; import type { DisabledReason } from "../metrics.js"; @@ -37,12 +40,16 @@ interface ResolveLayerConfigOptions { export async function fetchKeyConfig( configProvider: CacheConfigProvider, key: DialCacheKey, + onUnknownFields?: () => void, ): Promise { const defaultConfig = key.defaultConfig; const runtimeConfig = (await configProvider(key)) as DialCacheKeyConfig | null | undefined; if (runtimeConfig === null || runtimeConfig === undefined) { return defaultConfig; } + if (hasUnknownKeyConfigFields(runtimeConfig)) { + onUnknownFields?.(); + } return mergeKeyConfig(defaultConfig, runtimeConfig); } @@ -112,7 +119,10 @@ function mergeKeyConfig( const remoteReadTimeoutMs = overlay?.remoteReadTimeoutMs !== undefined ? overlay.remoteReadTimeoutMs : defaultConfig?.remoteReadTimeoutMs; - const shadow = mergeShadowConfig(defaultConfig?.shadow, overlay?.shadow); + const shadow = mergeShadowConfig( + readOwn(defaultConfig ?? undefined, "shadow"), + readOwn(overlay, "shadow"), + ); return new DialCacheKeyConfig({ ttlSec: mergeLayerConfig(defaultConfig?.ttlSec, overlay?.ttlSec, "ttlSec"), @@ -128,9 +138,6 @@ function assertKeyConfig(config: DialCacheKeyConfig | null | undefined): void { if (config !== null && config !== undefined && (typeof config !== "object" || Array.isArray(config))) { throw new TypeError("DialCache key config must be an object"); } - if (config !== null && config !== undefined && Object.hasOwn(config, "shadowRamp")) { - throw new TypeError('DialCacheKeyConfig.shadowRamp was replaced by "shadow.ramp"'); - } } function mergeLayerConfig( @@ -169,19 +176,57 @@ function mergeShadowConfig( return undefined; } - const ramp = overlay?.ramp !== undefined ? overlay.ramp : defaults?.ramp; - const logMismatches = overlay?.logMismatches !== undefined - ? overlay.logMismatches - : defaults?.logMismatches; + const overlayRamp = readOwn(overlay, "ramp"); + const ramp = overlayRamp !== undefined ? overlayRamp : readOwn(defaults, "ramp"); + const mismatchLogging = mergeMismatchLoggingConfig( + readOwn(defaults, "mismatchLogging"), + readOwn(overlay, "mismatchLogging"), + ); return { ...(ramp === undefined ? {} : { ramp }), - ...(logMismatches === undefined ? {} : { logMismatches }), + ...(mismatchLogging === undefined ? {} : { mismatchLogging }), }; } +function mergeMismatchLoggingConfig( + defaults: ShadowMismatchLoggingConfig | undefined, + overlay: ShadowMismatchLoggingConfig | undefined, +): ShadowMismatchLoggingConfig | undefined { + assertMismatchLoggingConfig(defaults); + assertMismatchLoggingConfig(overlay); + + if (defaults === undefined && overlay === undefined) { + return undefined; + } + + const merged: Record = {}; + for (const leaf of SHADOW_MISMATCH_LOGGING_LEAVES) { + const overlayValue = readOwn(overlay, leaf); + const value = overlayValue !== undefined ? overlayValue : readOwn(defaults, leaf); + if (value !== undefined) { + merged[leaf] = value; + } + } + return merged as ShadowMismatchLoggingConfig; +} + +// Own-property reads keep runtime shadow config immune to inherited values: +// prototype-carried leaves must never merge into an own `mismatchLogging` +// group (its failure direction is payload data reaching logs, unlike a TTL) +// and the same rule is applied to `ramp` so admission cannot be inherited. +function readOwn(source: T | undefined, key: Key): T[Key] | undefined { + return source !== undefined && Object.hasOwn(source, key) ? source[key] : undefined; +} + function assertShadowConfig(config: ShadowConfig | undefined): void { if (config !== undefined && (config === null || typeof config !== "object" || Array.isArray(config))) { throw new TypeError("DialCache shadow config must be an object"); } } + +function assertMismatchLoggingConfig(config: ShadowMismatchLoggingConfig | undefined): void { + if (config !== undefined && (config === null || typeof config !== "object" || Array.isArray(config))) { + throw new TypeError("DialCache shadow mismatchLogging config must be an object"); + } +} diff --git a/src/internal/shadow-log-json.ts b/src/internal/shadow-log-json.ts index a43b2db..cdeb25b 100644 --- a/src/internal/shadow-log-json.ts +++ b/src/internal/shadow-log-json.ts @@ -1,42 +1,188 @@ export const SHADOW_LOG_KEY_MAX_BYTES = 2 * 1024; export const SHADOW_LOG_VALUE_MAX_BYTES = 8 * 1024; +export const SHADOW_LOG_DIFF_MAX_BYTES = 8 * 1024; export const SHADOW_LOG_TRUNCATION_MARKER = "...[truncated]"; const UTF8_ENCODER = new TextEncoder(); const UTF8_DECODER = new TextDecoder("utf-8", { fatal: true }); const TRUNCATION_MARKER_BYTES = UTF8_ENCODER.encode(SHADOW_LOG_TRUNCATION_MARKER); -export interface ShadowMismatchLogDetails { - readonly cacheKey: string; - readonly cachedValueJson: string | null; - readonly sourceValueJson: string | null; +type JsonObject = { [key: string]: JsonValue }; +type JsonValue = null | boolean | number | string | JsonValue[] | JsonObject; + +/** One loggable side of a confirmed mismatch; unavailable when its projection failed. */ +export interface ShadowLoggableSide { + readonly available: boolean; + readonly value?: unknown; +} + +export interface ShadowMismatchLogFields { + readonly cachedValueJson?: string | null; + readonly sourceValueJson?: string | null; + readonly diffJson?: string | null; } -export function previewShadowLogKey(value: string): string { - return clampUtf8(value, SHADOW_LOG_KEY_MAX_BYTES); +export interface ShadowLogDifferenceCreate { + readonly type: "CREATE"; + readonly path: readonly (string | number)[]; + readonly value: JsonValue; +} +export interface ShadowLogDifferenceRemove { + readonly type: "REMOVE"; + readonly path: readonly (string | number)[]; + readonly oldValue: JsonValue; +} +export interface ShadowLogDifferenceChange { + readonly type: "CHANGE"; + readonly path: readonly (string | number)[]; + readonly value: JsonValue; + readonly oldValue: JsonValue; +} +export type ShadowLogDifference = + | ShadowLogDifferenceCreate + | ShadowLogDifferenceRemove + | ShadowLogDifferenceChange; + +export function previewShadowLogKey(value: string): string | null { + try { + return clampUtf8(value, SHADOW_LOG_KEY_MAX_BYTES); + } catch { + return null; + } } -export function previewShadowLogJson(value: unknown): string | null { +export function previewShadowLogJson( + value: unknown, + maxBytes: number = SHADOW_LOG_VALUE_MAX_BYTES, +): string | null { try { const json = JSON.stringify(value); - return json === undefined ? null : clampUtf8(json, SHADOW_LOG_VALUE_MAX_BYTES); + return json === undefined ? null : clampUtf8(json, maxBytes); } catch { return null; } } -export function shadowMismatchLogDetails( - cacheKey: string, - cachedValue: unknown, - sourceValue: unknown, -): ShadowMismatchLogDetails { +/** + * Renders both loggable sides to native JSON exactly once and derives every + * requested built-in warning field from those two snapshots, so `toJSON` + * hooks run once per side and the diff provably compares the same forms that + * value logging shows. An unavailable or unrenderable side yields `null` for + * its value field and a `null` diff; equal snapshots yield `"[]"`. + */ +export function renderShadowMismatchJson( + cached: ShadowLoggableSide, + source: ShadowLoggableSide, + include: { readonly value: boolean; readonly diff: boolean }, +): ShadowMismatchLogFields { + const cachedJson = renderLoggableJson(cached); + const sourceJson = renderLoggableJson(source); return { - cacheKey: previewShadowLogKey(cacheKey), - cachedValueJson: previewShadowLogJson(cachedValue), - sourceValueJson: previewShadowLogJson(sourceValue), + ...(include.value + ? { + cachedValueJson: cachedJson === null ? null : clampJson(cachedJson, SHADOW_LOG_VALUE_MAX_BYTES), + sourceValueJson: sourceJson === null ? null : clampJson(sourceJson, SHADOW_LOG_VALUE_MAX_BYTES), + } + : {}), + ...(include.diff ? { diffJson: builtInDiffJson(cachedJson, sourceJson) } : {}), }; } +function renderLoggableJson(side: ShadowLoggableSide): string | null { + if (!side.available) { + return null; + } + try { + const json = JSON.stringify(side.value); + return json === undefined ? null : json; + } catch { + return null; + } +} + +function clampJson(json: string, maxBytes: number): string | null { + try { + return clampUtf8(json, maxBytes); + } catch { + return null; + } +} + +/** + * Bounded JSON of the differences between the two rendered snapshots, + * oriented from the cached side to the source side: `oldValue` is cached, + * `value` is source. A side without a JSON rendering fails the diff closed to + * `null` — the diff never attests anything about inputs value logging cannot + * show. Identical snapshots yield `[]`. + */ +function builtInDiffJson(cachedJson: string | null, sourceJson: string | null): string | null { + if (cachedJson === null || sourceJson === null) { + return null; + } + if (cachedJson === sourceJson) { + return "[]"; + } + try { + // Both strings came from successful native JSON rendering above, so this + // is the single boundary from arbitrary loggable values to the closed JSON + // domain consumed by the built-in differ. + const cached = JSON.parse(cachedJson) as JsonValue; + const source = JSON.parse(sourceJson) as JsonValue; + const entries: ShadowLogDifference[] = []; + appendJsonDifferences(cached, source, [], entries); + return previewShadowLogJson(entries, SHADOW_LOG_DIFF_MAX_BYTES); + } catch { + return null; + } +} + +// Structural difference between two parsed-JSON values. Only own enumerable +// keys and array indices are visited, matching JSON object and array semantics. +// Same-kind containers recurse (arrays index-wise, so an element shift reports +// every later index); any other pair is one CHANGE entry at its path. +function appendJsonDifferences( + cached: JsonValue, + source: JsonValue, + path: readonly (string | number)[], + out: ShadowLogDifference[], +): void { + if (Array.isArray(cached) && Array.isArray(source)) { + const shared = Math.min(cached.length, source.length); + for (let index = 0; index < shared; index += 1) { + appendJsonDifferences(cached[index]!, source[index]!, [...path, index], out); + } + for (let index = shared; index < cached.length; index += 1) { + out.push({ type: "REMOVE", path: [...path, index], oldValue: cached[index]! }); + } + for (let index = shared; index < source.length; index += 1) { + out.push({ type: "CREATE", path: [...path, index], value: source[index]! }); + } + return; + } + if (isJsonObject(cached) && isJsonObject(source)) { + for (const name of Object.keys(cached)) { + if (Object.hasOwn(source, name)) { + appendJsonDifferences(cached[name]!, source[name]!, [...path, name], out); + } else { + out.push({ type: "REMOVE", path: [...path, name], oldValue: cached[name]! }); + } + } + for (const name of Object.keys(source)) { + if (!Object.hasOwn(cached, name)) { + out.push({ type: "CREATE", path: [...path, name], value: source[name]! }); + } + } + return; + } + if (cached !== source) { + out.push({ type: "CHANGE", path, value: source, oldValue: cached }); + } +} + +function isJsonObject(value: JsonValue): value is JsonObject { + return typeof value === "object" && value !== null && !Array.isArray(value); +} + function clampUtf8(value: string, maxBytes: number): string { const bytes = new Uint8Array(maxBytes); const encoded = UTF8_ENCODER.encodeInto(value, bytes); diff --git a/src/metrics.ts b/src/metrics.ts index 998469f..67c1ea6 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -43,10 +43,11 @@ export type CompressionOutcome = | "read_over_limit"; /** Bounded reasons for skipping cache work; policy_disabled means a shared layer has no effective TTL. */ export type DisabledReason = "context" | "policy_disabled" | "invalid_ttl" | "invalid_ramp" | "ramped_down" | "config_error"; -/** Stable failure sites used instead of backend- or application-defined error names. */ +/** Stable operational categories used instead of backend- or application-defined error names. */ export type MetricErrorKind = | "key_construction" | "config_resolution" + | "config_unknown_field" | "cache_read" | "cache_read_timeout" | "cache_write" diff --git a/test/datadog.test.ts b/test/datadog.test.ts index fbb6b93..5ac1a45 100644 --- a/test/datadog.test.ts +++ b/test/datadog.test.ts @@ -93,6 +93,7 @@ const disabledReasons = Object.keys(DISABLED_REASONS) as DisabledReason[]; const ERROR_KINDS: Readonly> = { key_construction: true, config_resolution: true, + config_unknown_field: true, cache_read: true, cache_read_timeout: true, cache_write: true, diff --git a/test/dialcache-config-ramp.test.ts b/test/dialcache-config-ramp.test.ts index eb0d8ae..81acab9 100644 --- a/test/dialcache-config-ramp.test.ts +++ b/test/dialcache-config-ramp.test.ts @@ -50,28 +50,87 @@ describe("DialCache runtime config and ramp controls", () => { expect(new DialCacheKeyConfig({ shadow: { ramp: 0, - logMismatches: false, + mismatchLogging: { + key: false, + value: false, + diff: false, + }, }, }).shadow).toEqual({ ramp: 0, - logMismatches: false, + mismatchLogging: { + key: false, + value: false, + diff: false, + }, + }); + }); + + it("ignores unknown own fields while preserving every known config field", () => { + const config = new DialCacheKeyConfig({ + ttlSec: { [CacheLayer.LOCAL]: 60, edge: 120 } as never, + ramp: { [CacheLayer.LOCAL]: 100, edge: 50 } as never, + shadow: { + ramp: 25, + logMismatches: true, + futureShadowField: true, + mismatchLogging: { key: true, vaule: false }, + }, + requestLocal: true, + futureTopLevelField: true, + } as never); + + expect(config.ttlSec).toEqual({ [CacheLayer.LOCAL]: 60 }); + expect(config.ramp).toEqual({ [CacheLayer.LOCAL]: 100 }); + expect(config.shadow).toEqual({ + ramp: 25, + mismatchLogging: { key: true }, }); + expect(config.requestLocal).toBe(true); + expect(Object.keys(config)).not.toContain("futureTopLevelField"); + }); + + it("ignores a prototype-inherited shadow group at the constructor boundary", () => { + const config = new DialCacheKeyConfig(Object.create({ + shadow: { + ramp: 100, + mismatchLogging: { value: true, diff: true }, + }, + }) as ConstructorParameters[0]); + + expect(config.shadow).toBeUndefined(); + }); + + it("rejects a non-object shadow mismatchLogging group", () => { + for (const mismatchLogging of [null, 5, "keys", [true]]) { + expect(() => new DialCacheKeyConfig({ + shadow: { mismatchLogging } as never, + })).toThrow("DialCache shadow mismatchLogging config must be an object"); + } }); it("clones the supplied shadow policy", () => { const suppliedShadow = { ramp: 25, - logMismatches: true, + mismatchLogging: { + key: true, + value: true, + }, }; const config = new DialCacheKeyConfig({ shadow: suppliedShadow }); suppliedShadow.ramp = 0; - suppliedShadow.logMismatches = false; + suppliedShadow.mismatchLogging.key = false; + suppliedShadow.mismatchLogging.value = false; expect(config.shadow).not.toBe(suppliedShadow); + expect(config.shadow?.mismatchLogging).not.toBe(suppliedShadow.mismatchLogging); expect(config.shadow).toEqual({ ramp: 25, - logMismatches: true, + mismatchLogging: { + key: true, + value: true, + }, }); }); @@ -81,7 +140,7 @@ describe("DialCache runtime config and ramp controls", () => { ramp: { [CacheLayer.LOCAL]: 100 }, shadow: { ramp: 25, - logMismatches: true, + mismatchLogging: { key: true, value: true }, }, coalesce: false, }); @@ -105,10 +164,10 @@ describe("DialCache runtime config and ramp controls", () => { suppliedDefault.ramp[CacheLayer.LOCAL] = 0; const mutableShadow = suppliedDefault.shadow as { ramp?: number; - logMismatches?: boolean; + mismatchLogging?: { key?: boolean; value?: boolean }; }; mutableShadow.ramp = 0; - mutableShadow.logMismatches = false; + mutableShadow.mismatchLogging = { key: false, value: false }; const first = await dialcache.enable(async () => await getUser("123")); const second = await dialcache.enable(async () => await getUser("123")); @@ -121,13 +180,14 @@ describe("DialCache runtime config and ramp controls", () => { expect(observedDefaults[0]?.ramp[CacheLayer.LOCAL]).toBe(100); expect(observedDefaults[0]?.shadow).toEqual({ ramp: 25, - logMismatches: true, + mismatchLogging: { key: true, value: true }, }); expect(observedDefaults[0]?.coalesce).toBe(false); expect(Object.isFrozen(observedDefaults[0])).toBe(true); expect(Object.isFrozen(observedDefaults[0]?.ttlSec)).toBe(true); expect(Object.isFrozen(observedDefaults[0]?.ramp)).toBe(true); expect(Object.isFrozen(observedDefaults[0]?.shadow)).toBe(true); + expect(Object.isFrozen(observedDefaults[0]?.shadow?.mismatchLogging)).toBe(true); }); it("enables request-local caching without TTL or ramp policy", async () => { @@ -334,11 +394,6 @@ describe("DialCache runtime config and ramp controls", () => { () => new DialCacheKeyConfig({ shadow: [] as never }), "DialCache shadow config must be an object", ], - [ - "the removed shadowRamp field", - () => new DialCacheKeyConfig({ shadowRamp: 100 } as never), - 'DialCacheKeyConfig.shadowRamp was replaced by "shadow.ramp"', - ], ])("rejects $0 in the public config constructor", (_name, construct, message) => { expect(construct).toThrow(message); }); @@ -400,10 +455,10 @@ describe("DialCache runtime config and ramp controls", () => { "must be a number", ], [ - "wrong-type shadow mismatch logging flag", - new DialCacheKeyConfig({ shadow: { logMismatches: null as unknown as boolean } }), + "wrong-type shadow mismatch logging leaf", + new DialCacheKeyConfig({ shadow: { mismatchLogging: { value: null as unknown as boolean } } }), TypeError, - "must be a boolean", + "shadow.mismatchLogging.value must be a boolean", ], ["primitive config", 42 as unknown as DialCacheKeyConfig, TypeError, "must be an object"], ["array config", [] as unknown as DialCacheKeyConfig, TypeError, "must be an object"], @@ -419,12 +474,6 @@ describe("DialCache runtime config and ramp controls", () => { TypeError, "shadow must be an object", ], - [ - "removed shadowRamp", - { ttlSec: {}, ramp: {}, shadowRamp: 100 } as unknown as DialCacheKeyConfig, - TypeError, - 'shadowRamp was replaced by "shadow.ramp"', - ], [ "a null coalesce value", { ttlSec: {}, ramp: {}, coalesce: null } as unknown as DialCacheKeyConfig, @@ -462,7 +511,7 @@ describe("DialCache runtime config and ramp controls", () => { ["an array", []], ["a null layer map", { ttlSec: null, ramp: {} }], ["an array shadow config", { ttlSec: {}, ramp: {}, shadow: [] }], - ["the removed shadowRamp field", { ttlSec: {}, ramp: {}, shadowRamp: 100 }], + ["a non-object shadow mismatchLogging group", { ttlSec: {}, ramp: {}, shadow: { mismatchLogging: null } }], ["a null requestLocal value", { ttlSec: {}, ramp: {}, requestLocal: null }], ["a null coalesce value", { ttlSec: {}, ramp: {}, coalesce: null }], ] as const)("fails open instead of inheriting defaults when the provider returns %s", async (_name, runtimeConfig) => { @@ -489,7 +538,11 @@ describe("DialCache runtime config and ramp controls", () => { requestLocal: false, shadow: { ramp: 0, - logMismatches: false, + mismatchLogging: { + key: false, + value: false, + diff: false, + }, }, ramp: { [CacheLayer.LOCAL]: 0, [CacheLayer.REMOTE]: 0 }, })); diff --git a/test/dialcache-metrics.test.ts b/test/dialcache-metrics.test.ts index 15f5fa1..b2c68dc 100644 --- a/test/dialcache-metrics.test.ts +++ b/test/dialcache-metrics.test.ts @@ -80,6 +80,74 @@ const remoteOnly = () => const tick = (): Promise => new Promise((resolve) => setTimeout(resolve, 0)); describe("DialCache observability metrics", () => { + it("reports one bounded error while ignoring unknown static config fields", async () => { + const metrics = new RecordingMetrics(); + const defaultConfig = new DialCacheKeyConfig({ + ttlSec: { [CacheLayer.LOCAL]: 60, future: 1 } as never, + ramp: { [CacheLayer.LOCAL]: 100 }, + shadow: { + logMismatches: true, + mismatchLogging: { key: true, vaule: false }, + }, + shadowRamp: 100, + futureTopLevel: true, + } as never); + const dialcache = new DialCache({ metrics }); + let calls = 0; + const getUser = dialcache.cached(async (id: string) => ({ id, calls: ++calls }), { + keyType: "user_id", + useCase: "UnknownStaticConfigFields", + cacheKey: (id) => id, + defaultConfig, + }); + + await dialcache.enable(async () => await getUser("123")); + await dialcache.enable(async () => await getUser("123")); + + const warnings = events(metrics, "error", { + useCase: "UnknownStaticConfigFields", + layer: "noop", + error: "config_unknown_field", + inFallback: false, + }); + expect(warnings).toHaveLength(1); + expect(calls).toBe(1); + expect(JSON.stringify(warnings)).not.toMatch(/future|logMismatches|shadowRamp|vaule/); + }); + + it("reports once per runtime config while applying its known fields", async () => { + const metrics = new RecordingMetrics(); + const cacheConfigProvider = vi.fn(async () => ({ + ttlSec: { [CacheLayer.LOCAL]: 60, future: 1 }, + ramp: { [CacheLayer.LOCAL]: 100, future: 50 }, + shadow: { + logMismatches: true, + future: true, + mismatchLogging: { vaule: false }, + }, + future: true, + }) as unknown as DialCacheKeyConfig); + const dialcache = new DialCache({ metrics, cacheConfigProvider }); + let calls = 0; + const getUser = dialcache.cached(async (id: string) => ({ id, calls: ++calls }), { + keyType: "user_id", + useCase: "UnknownRuntimeConfigFields", + cacheKey: (id) => id, + }); + + await dialcache.enable(async () => await getUser("123")); + await dialcache.enable(async () => await getUser("123")); + + expect(cacheConfigProvider).toHaveBeenCalledTimes(2); + expect(calls).toBe(1); + expect(events(metrics, "error", { + useCase: "UnknownRuntimeConfigFields", + layer: "noop", + error: "config_unknown_field", + inFallback: false, + })).toHaveLength(2); + }); + it("consumes rejecting thenables returned by every metrics method without awaiting them", async () => { const then = vi.fn(( _onFulfilled: ((value: unknown) => unknown) | null | undefined, diff --git a/test/dialcache-observability-internals.test.ts b/test/dialcache-observability-internals.test.ts index d6ec4a4..ef92c95 100644 --- a/test/dialcache-observability-internals.test.ts +++ b/test/dialcache-observability-internals.test.ts @@ -18,7 +18,7 @@ describe("DialCache observability internal compatibility paths", () => { ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 50 }, shadow: { ramp: 20, - logMismatches: true, + mismatchLogging: { key: true, value: true }, }, }); const cases = [ @@ -37,7 +37,7 @@ describe("DialCache observability internal compatibility paths", () => { ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 75 }, shadow: { ramp: 80, - logMismatches: true, + mismatchLogging: { key: true, value: true }, }, }), }, @@ -46,7 +46,7 @@ describe("DialCache observability internal compatibility paths", () => { ttlSec: { [CacheLayer.REMOTE]: 90 }, ramp: { [CacheLayer.LOCAL]: 10 }, shadow: { - logMismatches: false, + mismatchLogging: { value: false, diff: true }, }, }), expected: new DialCacheKeyConfig({ @@ -56,7 +56,7 @@ describe("DialCache observability internal compatibility paths", () => { ramp: { [CacheLayer.LOCAL]: 10, [CacheLayer.REMOTE]: 50 }, shadow: { ramp: 20, - logMismatches: false, + mismatchLogging: { key: true, value: false, diff: true }, }, }), }, @@ -69,7 +69,7 @@ describe("DialCache observability internal compatibility paths", () => { ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 50 }, shadow: { ramp: 20, - logMismatches: true, + mismatchLogging: { key: true, value: true }, }, }), }, @@ -80,6 +80,48 @@ describe("DialCache observability internal compatibility paths", () => { } }); + it("merges only own mismatch logging leaves, ignoring prototype-carried values", async () => { + const defaultConfig = new DialCacheKeyConfig({ + ttlSec: { [CacheLayer.LOCAL]: 60 }, + ramp: { [CacheLayer.LOCAL]: 100 }, + shadow: { ramp: 20 }, + }); + const runtime = { + shadow: { mismatchLogging: Object.create({ value: true }) as { value?: boolean } }, + } as DialCacheKeyConfig; + + const merged = await fetchKeyConfig(async () => runtime, key(defaultConfig)); + + expect(merged?.shadow?.mismatchLogging).toEqual({}); + expect(Object.hasOwn(merged?.shadow?.mismatchLogging ?? {}, "value")).toBe(false); + }); + + it("ignores a prototype-inherited shadow group in a runtime overlay", async () => { + const defaultConfig = new DialCacheKeyConfig({ + ttlSec: { [CacheLayer.REMOTE]: 60 }, + ramp: { [CacheLayer.REMOTE]: 100 }, + shadow: { + ramp: 20, + mismatchLogging: { key: true }, + }, + }); + // A provider result whose shadow policy lives on the prototype: every leaf + // inside it is an own property, so only the group boundary can reject it. + const overlay = Object.create({ + shadow: { + ramp: 100, + mismatchLogging: { value: true, diff: true }, + }, + }) as DialCacheKeyConfig; + + const merged = await fetchKeyConfig(async () => overlay, key(defaultConfig)); + + expect(merged?.shadow).toEqual({ + ramp: 20, + mismatchLogging: { key: true }, + }); + }); + it("preserves omitted requestLocal and coalesce through a runtime merge", async () => { // The gates own the effective defaults, so the merge must not materialize // either boolean when both sides omit it. diff --git a/test/dialcache-shadow-confirmation.test.ts b/test/dialcache-shadow-confirmation.test.ts index 0bd33b7..c72e603 100644 --- a/test/dialcache-shadow-confirmation.test.ts +++ b/test/dialcache-shadow-confirmation.test.ts @@ -161,14 +161,19 @@ class RecordingMetrics implements DialCacheMetricsAdapter { function remoteConfig( remoteRamp: number, shadowPercentage = 100, - logging: { - readonly logMismatches?: boolean; - } = {}, + mismatchLogging?: { + readonly key?: boolean; + readonly value?: boolean; + readonly diff?: boolean; + }, ): DialCacheKeyConfig { return new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: remoteRamp }, - shadow: { ramp: shadowPercentage, ...logging }, + shadow: { + ramp: shadowPercentage, + ...(mismatchLogging === undefined ? {} : { mismatchLogging }), + }, }); } @@ -338,7 +343,7 @@ describe("DialCache Redis shadow confirmation", () => { const getUser = dialcache.cached(async () => ({ id: "private-id", version: 2 }), { ...trackedOptions( "ShadowMismatchJson", - remoteConfig(100, 100, { logMismatches: true }), + remoteConfig(100, 100, { key: true, value: true }), ), cacheKey: () => ({ id: "private-id", @@ -357,6 +362,7 @@ describe("DialCache Redis shadow confirmation", () => { useCase: "ShadowMismatchJson", keyType: "user_id", outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), cacheKey: "{private-namespace:user_id:private-id}?tenant=private-tenant#ShadowMismatchJson", cachedValueJson: '{"id":"private-id","version":1}', sourceValueJson: '{"id":"private-id","version":2}', @@ -388,9 +394,7 @@ describe("DialCache Redis shadow confirmation", () => { const getUser = dialcache.cached(async () => sourceValue, { ...trackedOptions( "ShadowMismatchRampedDownJson", - remoteConfig(0, 100, { - logMismatches: true, - }), + remoteConfig(0, 100, { key: true, value: true }), ), cacheKey: () => ({ id: "123", @@ -410,6 +414,7 @@ describe("DialCache Redis shadow confirmation", () => { useCase: "ShadowMismatchRampedDownJson", keyType: "user_id", outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), cacheKey: "{urn:user_id:123}?locale=en-US#ShadowMismatchRampedDownJson", cachedValueJson: '{"id":"123","version":1}', sourceValueJson: '{"id":"123","version":2}', @@ -418,7 +423,7 @@ describe("DialCache Redis shadow confirmation", () => { expect(serializer.dump).not.toHaveBeenCalled(); }); - it("falls back to a metadata warning when JSON detail construction throws", async () => { + it("fails closed per field when preview encoding fails", async () => { const cachedValue = { id: "123", version: 1 }; const sourceValue = { id: "123", version: 2 }; const payload = JSON.stringify(cachedValue); @@ -440,16 +445,16 @@ describe("DialCache Redis shadow confirmation", () => { }, { ...trackedOptions( "ShadowMismatchJsonFailure", - remoteConfig(100, 100, { - logMismatches: true, - }), + remoteConfig(100, 100, { key: true, value: true }), ), cacheKey: () => "123", }); await dialcache.enable(async () => await getUser()); await sourceStarted.promise; - const encodeInto = vi.spyOn(TextEncoder.prototype, "encodeInto").mockImplementationOnce(() => { + // A persistent throw nulls both value previews at render time and the key + // preview at emit time; the warning still emits with every field null. + const encodeInto = vi.spyOn(TextEncoder.prototype, "encodeInto").mockImplementation(() => { throw new Error("preview unavailable"); }); try { @@ -465,6 +470,10 @@ describe("DialCache Redis shadow confirmation", () => { useCase: "ShadowMismatchJsonFailure", keyType: "user_id", outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: null, + cachedValueJson: null, + sourceValueJson: null, }, ); } finally { @@ -491,9 +500,7 @@ describe("DialCache Redis shadow confirmation", () => { const getUser = dialcache.cached(async () => sourceValue, { ...trackedOptions( "ShadowMismatchClampedJson", - remoteConfig(100, 100, { - logMismatches: true, - }), + remoteConfig(100, 100, { key: true, value: true }), ), cacheKey: () => id, }); @@ -519,6 +526,583 @@ describe("DialCache Redis shadow confirmation", () => { } }); + it("logs a key-only warning when only mismatchLogging.key is enabled", async () => { + const useCase = "ShadowMismatchKeyOnly"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true })), + cacheKey: () => "123", + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + }, + ); + }); + + it("logs values without the key when mismatchLogging.key is off", async () => { + const useCase = "ShadowMismatchValueOnly"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { value: true })), + cacheKey: () => "123", + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cachedValueJson: '{"id":"123","version":1}', + sourceValueJson: '{"id":"123","version":2}', + }, + ); + }); + + it("projects both sides through shadowMismatchLogValue before logging", async () => { + const useCase = "ShadowMismatchProjectedValues"; + const payload = JSON.stringify({ id: "123", version: 1, secret: "cached-secret" }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached( + async () => ({ id: "123", version: 2, secret: "source-secret" }), + { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true, value: true })), + cacheKey: () => "123", + shadowMismatchLogValue: (value) => ({ version: value.version }), + }, + ); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + cachedValueJson: '{"version":1}', + sourceValueJson: '{"version":2}', + }, + ); + }); + + it("logs null for the side whose shadowMismatchLogValue projection throws", async () => { + const useCase = "ShadowMismatchProjectionThrow"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { value: true })), + cacheKey: () => "123", + shadowMismatchLogValue: (value) => { + if (value.version === 1) { + throw new Error("unprojectable"); + } + return { version: value.version }; + }, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cachedValueJson: null, + sourceValueJson: '{"version":2}', + }, + ); + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + }); + + it("fails rejected shadowMismatchLogValue promises closed without an unhandled rejection", async () => { + const useCase = "ShadowMismatchAsyncProjection"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const projector = vi.fn(async () => { + throw new Error("async projection unavailable"); + }); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { value: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: projector, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + await nextImmediate(); + + expect(projector).toHaveBeenCalledTimes(2); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cachedValueJson: null, + sourceValueJson: null, + diffJson: null, + }, + ); + }); + + it("logs a structural diff of the raw values when no hooks are defined", async () => { + const useCase = "ShadowMismatchBuiltInDiff"; + const payload = JSON.stringify({ id: "123", version: 1, tags: ["a", "b"] }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached( + async () => ({ id: "123", version: 2, tags: ["a", "c"] }), + { + ...trackedOptions(useCase, remoteConfig(100, 100, { diff: true })), + cacheKey: () => "123", + }, + ); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning).not.toHaveProperty("cacheKey"); + expect(warning).not.toHaveProperty("cachedValueJson"); + expect(warning).not.toHaveProperty("sourceValueJson"); + expect(JSON.parse(warning.diffJson as string)).toEqual([ + { type: "CHANGE", path: ["version"], value: 2, oldValue: 1 }, + { type: "CHANGE", path: ["tags", 1], value: "c", oldValue: "b" }, + ]); + }); + + it("computes the built-in diff over projected values", async () => { + const useCase = "ShadowMismatchProjectedDiff"; + const payload = JSON.stringify({ id: "123", version: 1, secret: "cached-secret" }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached( + async () => ({ id: "123", version: 2, secret: "source-secret" }), + { + ...trackedOptions(useCase, remoteConfig(100, 100, { diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: (value) => ({ id: value.id, version: value.version }), + }, + ); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning.diffJson).not.toContain("secret"); + expect(JSON.parse(warning.diffJson as string)).toEqual([ + { type: "CHANGE", path: ["version"], value: 2, oldValue: 1 }, + ]); + }); + + it("logs an empty diff when the projection hides the difference", async () => { + const useCase = "ShadowMismatchRedactedDiff"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: (value) => ({ id: value.id }), + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning.diffJson).toBe("[]"); + }); + + it("prefers shadowMismatchLogDiff over the built-in diff and passes raw values", async () => { + const useCase = "ShadowMismatchCustomDiff"; + const cachedValue = { id: "123", version: 1 }; + const payload = JSON.stringify(cachedValue); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const projector = vi.fn(() => ({})); + const logDiff = vi.fn( + (cached: { version: number }, source: { version: number }) => + ({ from: cached.version, to: source.version }), + ); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: projector, + shadowMismatchLogDiff: logDiff, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(logDiff).toHaveBeenCalledTimes(1); + expect(logDiff).toHaveBeenCalledWith({ id: "123", version: 1 }, { id: "123", version: 2 }); + expect(projector).not.toHaveBeenCalled(); + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning.diffJson).toBe('{"from":1,"to":2}'); + }); + + it("logs a null built-in diff when the projection throws for either side", async () => { + const useCase = "ShadowMismatchDiffProjectionThrow"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: (value) => { + if (value.version === 1) { + throw new Error("unprojectable"); + } + return { version: value.version }; + }, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + diffJson: null, + }, + ); + }); + + it("projects each side once when value and diff logging are both enabled", async () => { + const useCase = "ShadowMismatchSharedProjection"; + const payload = JSON.stringify({ id: "123", version: 1, secret: "cached-secret" }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const projector = vi.fn( + (value: { version: number }) => ({ version: value.version }), + ); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached( + async () => ({ id: "123", version: 2, secret: "source-secret" }), + { + ...trackedOptions(useCase, remoteConfig(100, 100, { value: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: projector, + }, + ); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(projector).toHaveBeenCalledTimes(2); + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning.cachedValueJson).toBe('{"version":1}'); + expect(warning.sourceValueJson).toBe('{"version":2}'); + expect(JSON.parse(warning.diffJson as string)).toEqual([ + { type: "CHANGE", path: ["version"], value: 2, oldValue: 1 }, + ]); + }); + + it("does not invoke shadowMismatchLogDiff when diff logging is off", async () => { + const useCase = "ShadowMismatchDiffHookIdle"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const logDiff = vi.fn(() => ({})); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { value: true })), + cacheKey: () => "123", + shadowMismatchLogDiff: logDiff, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(logDiff).not.toHaveBeenCalled(); + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning).not.toHaveProperty("diffJson"); + expect(warning.cachedValueJson).toBe('{"id":"123","version":1}'); + }); + + it("does not invoke log hooks or warn for a superseded mismatch candidate", async () => { + const useCase = "ShadowSupersededHooksIdle"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const confirmation = JSON.stringify({ id: "123", version: 3 }); + const redis = new ScriptedRedis([() => payload, () => confirmation]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const projector = vi.fn(() => ({})); + const logDiff = vi.fn(() => ({})); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true, value: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: projector, + shadowMismatchLogDiff: logDiff, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["superseded"]); + expect(projector).not.toHaveBeenCalled(); + expect(logDiff).not.toHaveBeenCalled(); + expect(warn).not.toHaveBeenCalled(); + }); + + it("projects values while the diff hook receives raw values when both are enabled", async () => { + const useCase = "ShadowMismatchBothHooks"; + const payload = JSON.stringify({ id: "123", version: 1, secret: "cached-secret" }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const projector = vi.fn( + (value: { version: number }) => ({ version: value.version }), + ); + const logDiff = vi.fn( + (cached: { version: number }, source: { version: number }) => + ({ from: cached.version, to: source.version }), + ); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached( + async () => ({ id: "123", version: 2, secret: "source-secret" }), + { + ...trackedOptions(useCase, remoteConfig(100, 100, { value: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogValue: projector, + shadowMismatchLogDiff: logDiff, + }, + ); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(projector).toHaveBeenCalledTimes(2); + expect(logDiff).toHaveBeenCalledTimes(1); + expect(logDiff).toHaveBeenCalledWith( + { id: "123", version: 1, secret: "cached-secret" }, + { id: "123", version: 2, secret: "source-secret" }, + ); + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning.cachedValueJson).toBe('{"version":1}'); + expect(warning.sourceValueJson).toBe('{"version":2}'); + expect(warning.cachedValueJson).not.toContain("secret"); + expect(warning.sourceValueJson).not.toContain("secret"); + expect(warning.diffJson).toBe('{"from":1,"to":2}'); + }); + + it("ignores prototype-inherited mismatch logging fields", async () => { + const useCase = "ShadowMismatchPollutedPrototype"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true })), + cacheKey: () => "123", + }); + + // Pollute only around admission (the logging plan resolves synchronously + // inside enable); wider pollution breaks vitest's own descriptor use. + (Object.prototype as Record).value = true; + (Object.prototype as Record).diff = true; + try { + await dialcache.enable(async () => await getUser()); + } finally { + delete (Object.prototype as Record).value; + delete (Object.prototype as Record).diff; + } + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + }, + ); + }); + + it("logs a null diff when shadowMismatchLogDiff throws", async () => { + const useCase = "ShadowMismatchCustomDiffThrow"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogDiff: () => { + throw new Error("diff unavailable"); + }, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + diffJson: null, + }, + ); + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + }); + + it("fails a rejected shadowMismatchLogDiff promise closed without an unhandled rejection", async () => { + const useCase = "ShadowMismatchAsyncCustomDiff"; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const logDiff = vi.fn(async () => { + throw new Error("async diff unavailable"); + }); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true, diff: true })), + cacheKey: () => "123", + shadowMismatchLogDiff: logDiff, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + await nextImmediate(); + + expect(logDiff).toHaveBeenCalledOnce(); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + diffJson: null, + }, + ); + }); + it.each([ { name: "missing", confirmation: null }, { @@ -567,9 +1151,12 @@ describe("DialCache Redis shadow confirmation", () => { ]); redis.frameCreatedAtMs = nowMs - 90_000; const metrics = new RecordingMetrics(); - const dialcache = createCache(redis, metrics); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + logger: { debug: () => undefined, error: () => undefined, warn }, + }); const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { - ...trackedOptions("ShadowMismatchValueAge", remoteConfig(100)), + ...trackedOptions("ShadowMismatchValueAge", remoteConfig(100, 100, { key: true })), cacheKey: () => "123", }); @@ -584,6 +1171,9 @@ describe("DialCache Redis shadow confirmation", () => { keyType: "user_id", outcome: "mismatch", }); + // The warning carries the exact age the metric observed. + expect(warn).toHaveBeenCalledTimes(1); + expect(warn.mock.calls[0]?.[1]).toMatchObject({ cachedValueAgeSeconds: 90 }); } finally { nowSpy.mockRestore(); } @@ -623,9 +1213,7 @@ describe("DialCache Redis shadow confirmation", () => { const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { ...trackedOptions( "ShadowMismatchSuperseded", - remoteConfig(100, 100, { - logMismatches: true, - }), + remoteConfig(100, 100, { key: true, value: true }), ), cacheKey: () => "123", }); @@ -1506,7 +2094,7 @@ describe("DialCache Redis shadow confirmation", () => { const warn = vi.fn(); const dialcache = createCache(redis, metrics, { cacheConfigProvider: async () => new DialCacheKeyConfig({ - shadow: { logMismatches: "yes" as never }, + shadow: { mismatchLogging: { value: "yes" as never } }, }), logger: { debug: () => undefined, @@ -1515,12 +2103,7 @@ describe("DialCache Redis shadow confirmation", () => { }, }); const getUser = dialcache.cached(async () => sourceValue, { - ...trackedOptions( - useCase, - remoteConfig(100, 100, { - logMismatches: true, - }), - ), + ...trackedOptions(useCase, remoteConfig(100)), cacheKey: () => "123", }); @@ -1536,6 +2119,99 @@ describe("DialCache Redis shadow confirmation", () => { expect(warn).not.toHaveBeenCalled(); }); + it.each([ + ["false", false], + ["undefined", undefined], + ] as const)("ignores an unknown logging field set to $0 while preserving known fields", async (suffix, value) => { + const useCase = `ShadowUnknownLoggingLeaf${suffix}`; + const payload = JSON.stringify({ id: "123", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + cacheConfigProvider: async () => new DialCacheKeyConfig({ + shadow: { mismatchLogging: { vaule: value } as never }, + }), + logger: { + debug: () => undefined, + error: () => undefined, + warn, + }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100, 100, { key: true, value: true })), + cacheKey: () => "123", + }); + + expect(await dialcache.enable(async () => await getUser())).toEqual({ id: "123", version: 1 }); + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + expect(metrics.ordinaryEvents.filter(({ name: metricName, labels }) => + metricName === "error" + && labels.layer === "noop" + && labels.error === "config_unknown_field" + )).toHaveLength(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + cachedValueJson: '{"id":"123","version":1}', + sourceValueJson: '{"id":"123","version":2}', + }, + ); + }); + + it("resolves an invalid mismatch logging leaf to off without suppressing valid leaves", async () => { + const useCase = "ShadowInvalidLoggingLeaf"; + const cachedValue = { id: "123", version: 1 }; + const payload = JSON.stringify(cachedValue); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + const warn = vi.fn(); + const dialcache = createCache(redis, metrics, { + cacheConfigProvider: async () => new DialCacheKeyConfig({ + shadow: { mismatchLogging: { key: true, value: 5 as never } }, + }), + logger: { + debug: () => undefined, + error: () => undefined, + warn, + }, + }); + const getUser = dialcache.cached(async () => ({ id: "123", version: 2 }), { + ...trackedOptions(useCase, remoteConfig(100)), + cacheKey: () => "123", + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + expect(metrics.ordinaryEvents.filter(({ name: metricName, labels }) => + metricName === "error" + && labels.layer === CacheLayer.REMOTE + && labels.error === "config_resolution" + )).toHaveLength(1); + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase, + keyType: "user_id", + outcome: "mismatch", + cachedValueAgeSeconds: expect.any(Number), + cacheKey: `{urn:user_id:123}#${useCase}`, + }, + ); + }); + it("treats DialCacheKeyConfig.disabled() as a complete shadow kill switch", async () => { const redis = new ScriptedRedis([]); const metrics = new RecordingMetrics(); diff --git a/test/dialcache-shadow-validation.test.ts b/test/dialcache-shadow-validation.test.ts index 0eed650..4f31ec4 100644 --- a/test/dialcache-shadow-validation.test.ts +++ b/test/dialcache-shadow-validation.test.ts @@ -487,7 +487,7 @@ describe("DialCache Redis shadow validation", () => { error, }, { cacheConfigProvider: async () => new DialCacheKeyConfig({ - shadow: { logMismatches: "yes" as never }, + shadow: { mismatchLogging: { value: "yes" as never } }, }), logger: { debug: () => undefined, @@ -502,7 +502,7 @@ describe("DialCache Redis shadow validation", () => { ramp: { [CacheLayer.REMOTE]: 100 }, shadow: { ramp: 100, - logMismatches: true, + mismatchLogging: { key: true, value: true }, }, }), cacheKey: () => "123", @@ -538,7 +538,7 @@ describe("DialCache Redis shadow validation", () => { const source = vi.fn(async (id: string) => ({ id })); const dialcache = createShadowCache(redis, metrics, { cacheConfigProvider: async () => new DialCacheKeyConfig({ - shadow: { logMismatches: "yes" as never }, + shadow: { mismatchLogging: { value: "yes" as never } }, }), }); const getUser = dialcache.cached(source, { @@ -1063,7 +1063,7 @@ describe("DialCache Redis shadow validation", () => { shadowMaxInFlight: 1, cacheConfigProvider: async (key) => key.id === "b" ? new DialCacheKeyConfig({ - shadow: { logMismatches: "yes" as never }, + shadow: { mismatchLogging: { value: "yes" as never } }, }) : null, }); diff --git a/test/prometheus.test.ts b/test/prometheus.test.ts index bcfebbc..da28555 100644 --- a/test/prometheus.test.ts +++ b/test/prometheus.test.ts @@ -40,6 +40,7 @@ const CONFIGURED_TIMER_BUCKETS = [0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0. const METRIC_ERROR_KINDS: Readonly> = { key_construction: true, config_resolution: true, + config_unknown_field: true, cache_read: true, cache_read_timeout: true, cache_write: true, diff --git a/test/shadow-log-json.test.ts b/test/shadow-log-json.test.ts index 22b1707..5d61d39 100644 --- a/test/shadow-log-json.test.ts +++ b/test/shadow-log-json.test.ts @@ -1,36 +1,35 @@ import { describe, expect, it } from "vitest"; import { + SHADOW_LOG_DIFF_MAX_BYTES, SHADOW_LOG_KEY_MAX_BYTES, SHADOW_LOG_TRUNCATION_MARKER, SHADOW_LOG_VALUE_MAX_BYTES, previewShadowLogJson, previewShadowLogKey, - shadowMismatchLogDetails, + renderShadowMismatchJson, } from "../src/internal/shadow-log-json.js"; +const diffOf = (cached: unknown, source: unknown): string | null => + renderShadowMismatchJson( + { available: true, value: cached }, + { available: true, value: source }, + { value: false, diff: true }, + ).diffJson ?? null; + describe("shadow mismatch log JSON", () => { - it("uses native JSON for the values supplied to the comparator", () => { - expect(shadowMismatchLogDetails( - "urn:user_id:123#GetUser", - { id: "123", updatedAt: new Date("2026-07-31T00:00:00.000Z") }, - { id: "123", updatedAt: new Date("2026-08-01T00:00:00.000Z") }, - )).toEqual({ - cacheKey: "urn:user_id:123#GetUser", - cachedValueJson: '{"id":"123","updatedAt":"2026-07-31T00:00:00.000Z"}', - sourceValueJson: '{"id":"123","updatedAt":"2026-08-01T00:00:00.000Z"}', - }); + it("uses native JSON for log previews", () => { + expect(previewShadowLogJson({ + id: "123", + updatedAt: new Date("2026-07-31T00:00:00.000Z"), + })).toBe('{"id":"123","updatedAt":"2026-07-31T00:00:00.000Z"}'); }); - it("returns null independently for values that native JSON cannot serialize", () => { + it("returns null for values that native JSON cannot serialize", () => { const circular: { self?: unknown } = {}; circular.self = circular; - expect(shadowMismatchLogDetails("key", circular, { version: 2 })).toEqual({ - cacheKey: "key", - cachedValueJson: null, - sourceValueJson: '{"version":2}', - }); + expect(previewShadowLogJson(circular)).toBeNull(); expect(previewShadowLogJson(1n)).toBeNull(); expect(previewShadowLogJson(undefined)).toBeNull(); }); @@ -45,18 +44,242 @@ describe("shadow mismatch log JSON", () => { expect(previewShadowLogJson(value)).toBeNull(); }); + it("honors an explicit byte budget", () => { + const preview = previewShadowLogJson({ text: "a".repeat(200) }, 64); + + expect(preview).not.toBeNull(); + expect(Buffer.byteLength(preview!)).toBeLessThanOrEqual(64); + expect(preview!.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + }); + it("byte-clamps keys and JSON without splitting UTF-8 sequences", () => { const key = `${"k".repeat(SHADOW_LOG_KEY_MAX_BYTES)}🙂`; const value = { text: "🙂".repeat(SHADOW_LOG_VALUE_MAX_BYTES) }; const keyPreview = previewShadowLogKey(key); const valuePreview = previewShadowLogJson(value); + expect(keyPreview).not.toBeNull(); expect(valuePreview).not.toBeNull(); - expect(Buffer.byteLength(keyPreview)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); + expect(Buffer.byteLength(keyPreview!)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); expect(Buffer.byteLength(valuePreview!)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); - expect(keyPreview.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(keyPreview!.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); expect(valuePreview!.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - expect(keyPreview).not.toContain("\uFFFD"); - expect(valuePreview).not.toContain("\uFFFD"); + expect(keyPreview).not.toContain("�"); + expect(valuePreview).not.toContain("�"); + }); + + it("diffs plain objects and arrays from the cached side to the source side", () => { + const diffJson = diffOf( + { id: "123", version: 1, tags: ["a", "b"] }, + { id: "123", version: 2, tags: ["a"] }, + ); + + expect(JSON.parse(diffJson!)).toEqual([ + { type: "CHANGE", path: ["version"], value: 2, oldValue: 1 }, + { type: "REMOVE", path: ["tags", 1], oldValue: "b" }, + ]); + }); + + it("reports source-only fields as CREATE entries", () => { + expect(JSON.parse(diffOf({ a: 1 }, { a: 1, b: 2 })!)).toEqual([ + { type: "CREATE", path: ["b"], value: 2 }, + ]); + }); + + it("diffs the loggable forms, so toJSON redaction bounds the diff like value logging", () => { + class User { + constructor( + readonly id: number, + readonly apiKey: string, + ) {} + + toJSON(): { id: number } { + return { id: this.id }; + } + } + // Runtime shape: the cached side is deserialized JSON, the source is live. + const cached = { user: { id: 1 } }; + + expect(diffOf(cached, { user: new User(1, "SECRET-TOKEN") })).toBe("[]"); + const changed = diffOf(cached, { user: new User(2, "SECRET-TOKEN") }); + expect(changed).not.toContain("SECRET-TOKEN"); + expect(JSON.parse(changed!)).toEqual([ + { type: "CHANGE", path: ["user", "id"], value: 2, oldValue: 1 }, + ]); + }); + + it("does not emit phantom entries for serializer-normalized fields", () => { + // Runtime shape: the cached Date arrived as its ISO string; the live + // source still holds a Date for the same instant. + const diffJson = diffOf( + { updatedAt: "2026-07-31T00:00:00.000Z", n: 1 }, + { updatedAt: new Date("2026-07-31T00:00:00.000Z"), n: 2 }, + ); + + expect(JSON.parse(diffJson!)).toEqual([ + { type: "CHANGE", path: ["n"], value: 2, oldValue: 1 }, + ]); + }); + + it("renders nested Date leaves as ISO strings in diff entries", () => { + expect(JSON.parse(diffOf( + { updatedAt: new Date("2026-07-31T00:00:00.000Z") }, + { updatedAt: new Date("2026-08-01T00:00:00.000Z") }, + )!)).toEqual([ + { + type: "CHANGE", + path: ["updatedAt"], + value: "2026-08-01T00:00:00.000Z", + oldValue: "2026-07-31T00:00:00.000Z", + }, + ]); + }); + + it("reports an element shift as index-wise changes", () => { + // Documented noise: array entries compare by index, so a shift reports + // every later index instead of one insertion. + expect(JSON.parse(diffOf(["a", "b", "c"], ["x", "a", "b"])!)).toEqual([ + { type: "CHANGE", path: [0], value: "x", oldValue: "a" }, + { type: "CHANGE", path: [1], value: "a", oldValue: "b" }, + { type: "CHANGE", path: [2], value: "b", oldValue: "c" }, + ]); + }); + + it("returns an empty diff for identical loggable forms", () => { + expect(diffOf({ id: "123" }, { id: "123" })).toBe("[]"); + expect(diffOf("same", "same")).toBe("[]"); + // A Map renders as {} on both sides; the emptiness matches what value + // logging would show for the same inputs. + expect(diffOf({ m: {} }, { m: new Map([["k", 1]]) })).toBe("[]"); + }); + + it("collapses non-container and mixed-kind roots to one root-level change entry", () => { + expect(JSON.parse(diffOf("cached", "source")!)).toEqual([ + { type: "CHANGE", path: [], value: "source", oldValue: "cached" }, + ]); + expect(JSON.parse(diffOf({ id: "123" }, null)!)).toEqual([ + { type: "CHANGE", path: [], value: null, oldValue: { id: "123" } }, + ]); + expect(JSON.parse(diffOf( + new Date("2026-07-31T00:00:00.000Z"), + new Date("2026-08-01T00:00:00.000Z"), + )!)).toEqual([ + { + type: "CHANGE", + path: [], + value: "2026-08-01T00:00:00.000Z", + oldValue: "2026-07-31T00:00:00.000Z", + }, + ]); + expect(JSON.parse(diffOf({ a: 1, b: 2 }, [1, 2])!)).toEqual([ + { type: "CHANGE", path: [], value: [1, 2], oldValue: { a: 1, b: 2 } }, + ]); + expect(JSON.parse(diffOf({}, [])!)).toEqual([ + { type: "CHANGE", path: [], value: [], oldValue: {} }, + ]); + }); + + it("reports nested kind mismatches at their path", () => { + expect(JSON.parse(diffOf({ data: { a: 1 } }, { data: [1] })!)).toEqual([ + { type: "CHANGE", path: ["data"], value: [1], oldValue: { a: 1 } }, + ]); + }); + + it("fails the diff closed when either side has no JSON rendering", () => { + expect(diffOf(undefined, null)).toBeNull(); + expect(diffOf(null, undefined)).toBeNull(); + expect(diffOf(undefined, undefined)).toBeNull(); + expect(diffOf(undefined, { a: 1 })).toBeNull(); + }); + + it("renders null value fields and a null diff for an unavailable side", () => { + expect(renderShadowMismatchJson( + { available: false }, + { available: true, value: { id: "123" } }, + { value: true, diff: true }, + )).toEqual({ + cachedValueJson: null, + sourceValueJson: '{"id":"123"}', + diffJson: null, + }); + }); + + it("runs toJSON once per side and derives value and diff from the same snapshot", () => { + const makeSide = (id: number) => { + let calls = 0; + return { + calls: () => calls, + value: { + user: { + toJSON(): { id: number; calls: number } { + calls += 1; + return { id, calls }; + }, + }, + }, + }; + }; + const cached = makeSide(1); + const source = makeSide(2); + + const fields = renderShadowMismatchJson( + { available: true, value: cached.value }, + { available: true, value: source.value }, + { value: true, diff: true }, + ); + + // A second stringify per side would render calls: 2 somewhere; both + // outputs must come from the single calls: 1 snapshot. + expect(cached.calls()).toBe(1); + expect(source.calls()).toBe(1); + expect(fields.cachedValueJson).toBe('{"user":{"id":1,"calls":1}}'); + expect(fields.sourceValueJson).toBe('{"user":{"id":2,"calls":1}}'); + expect(JSON.parse(fields.diffJson!)).toEqual([ + { type: "CHANGE", path: ["user", "id"], value: 2, oldValue: 1 }, + ]); + }); + + it("diffs only own JSON members", () => { + const objectProto = Object.prototype as unknown as Record; + const arrayProto = Array.prototype as unknown as Record; + objectProto.polluted = "PROTOTYPE-ONLY"; + arrayProto.pollutedEntry = "PROTOTYPE-ONLY"; + try { + const diffJson = diffOf({ a: 1, list: ["x"] }, { a: 2, list: ["x"] }); + + expect(diffJson).not.toContain("PROTOTYPE-ONLY"); + expect(diffJson).not.toContain("polluted"); + expect(JSON.parse(diffJson!)).toEqual([ + { type: "CHANGE", path: ["a"], value: 2, oldValue: 1 }, + ]); + } finally { + delete objectProto.polluted; + delete arrayProto.pollutedEntry; + } + }); + + it("fails closed to null for cyclic inputs instead of throwing", () => { + const cached: { id: string; self?: unknown } = { id: "cached" }; + cached.self = cached; + const source: { id: string; self?: unknown } = { id: "source" }; + source.self = source; + + // The loggable-form rendering throws on cycles before any diffing. + expect(diffOf(cached, source)).toBeNull(); + }); + + it("fails the diff closed for bigint inputs", () => { + expect(diffOf({ n: 1n }, { n: 2n })).toBeNull(); + }); + + it("byte-clamps the diff", () => { + const diffJson = diffOf( + { text: "a".repeat(SHADOW_LOG_DIFF_MAX_BYTES) }, + { text: "b".repeat(SHADOW_LOG_DIFF_MAX_BYTES) }, + ); + + expect(diffJson).not.toBeNull(); + expect(Buffer.byteLength(diffJson!)).toBeLessThanOrEqual(SHADOW_LOG_DIFF_MAX_BYTES); + expect(diffJson!.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); }); });