From 8c1ad87c79328110cd69bee682e34c984f5508be Mon Sep 17 00:00:00 2001 From: Lev Neiman Date: Thu, 30 Jul 2026 18:49:28 -0700 Subject: [PATCH 1/6] feat: group shadow config and add mismatch logging --- README.md | 42 ++- scripts/benchmark-request-local.mjs | 10 +- scripts/test-package.mjs | 28 +- src/config.ts | 48 +++- src/dialcache.ts | 161 +++++++++-- src/index.ts | 2 +- src/internal/runtime-config.ts | 42 ++- test/dialcache-config-ramp.test.ts | 112 +++++++- .../dialcache-observability-internals.test.ts | 37 ++- test/dialcache-shadow-confirmation.test.ts | 262 +++++++++++++++++- test/dialcache-shadow-validation.test.ts | 116 ++++++-- test/redis-real.integration.test.ts | 8 +- 12 files changed, 766 insertions(+), 102 deletions(-) diff --git a/README.md b/README.md index d757740..7a07728 100644 --- a/README.md +++ b/README.md @@ -205,25 +205,25 @@ Instance-wide behavior is set through the `DialCache` constructor: | `shadowMaxInFlight` | `1` | Maximum scheduled or active shadow jobs per `DialCache` instance, including uncancellable underlying work. Positive safe integer; excess work is dropped without queuing. | | `cacheConfigProvider` | none | Resolves runtime config per enabled invocation as a sparse overlay on the function's `defaultConfig`; `null` applies no overrides. | | `metrics` | disabled | A `DialCacheMetricsAdapter` (see [Metrics](#metrics)). | -| `logger` | `console` | Receives operational cache failures (`debug`, `warn`, `error`). Synchronous throws and rejections from returned promises or thenables are isolated without being awaited. | +| `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, an optional `remoteReadTimeoutMs`, and the scalar `shadowRamp` percentage. +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, an optional `remoteReadTimeoutMs`, and an optional `shadow` group. `ShadowConfig` contains the independent shadow `ramp` percentage plus the default-off `logMismatches` and `logMismatchDetails` controls. 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 work to 0%. 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 `shadowRamp` 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 both shadow logging controls 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. -A provider result of `null` (or defensive `undefined`) applies no overrides. An empty `DialCacheKeyConfig` and omitted runtime fields also inherit the baseline. 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, with both shared layers ramped to 0. 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 `shadowRamp` 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, 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 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 must be objects, and `requestLocal` must be a boolean when present. Invalid defaults are rejected immediately. +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`, `shadow.logMismatches`, and `shadow.logMismatchDetails` must be booleans when present. Invalid defaults are rejected immediately. 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, or explicit `remoteReadTimeoutMs` fails config resolution for the invocation, records `config_error`, and executes the fallback uncached without attempting Redis. -An invalid runtime `shadowRamp` 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.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. After tracked traversal reaches a valid nonzero shadow ramp, invalid runtime shadow logging leaves likewise preserve the cache result, Redis policy, shadow result, and shadow metric: an invalid `logMismatches` disables the warning, while an invalid `logMismatchDetails` downgrades it to the metadata-only warning. Both cases record `config_resolution`, even when the metrics hook is absent or the exact key is outside the shadow cohort. `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. @@ -237,7 +237,11 @@ const dialcache = new DialCache({ // Sparse override: inherit both TTLs and the local ramp from defaultConfig. ramp: { [CacheLayer.REMOTE]: 25 }, // Independently sample tracked Redis keys for detached validation/fill. - shadowRamp: 5, + shadow: { + ramp: 5, + // Emit one metadata-only warning for each confirmed mismatch. + logMismatches: true, + }, // Can be changed by the provider at runtime for this use case. remoteReadTimeoutMs: 35, }); @@ -259,9 +263,9 @@ const getUser = dialcache.cached((userId: string) => db.fetchUser(userId), { `ramp` values are percentages from 0 to 100. `0` disables the layer, `100` enables it, and intermediate values are deterministically sampled by cache key and layer, so the same key is consistently sampled in or out of a partial rollout across calls and instances. The assignment algorithm is owned by DialCache and remains stable across releases. Applications that need an externally coordinated cohort can use `cacheConfigProvider` to return a sparse per-key ramp override of `0` or `100`. DialCache fetches and resolves one config snapshot per enabled invocation. Provider errors do not activate defaults: they fail open, record `config_error`, and execute the fallback function uncached. -`shadowRamp` uses the same inclusive 0–100 percentage domain but is independent of cache-layer serving ramps. Omission and `0` disable shadow work; `100` selects every eligible tracked Redis key; intermediate values assign each exact cache key to a stable shadow cohort across calls and instances. A valid remote policy can therefore use `ramp.remote: 0` with a nonzero `shadowRamp` to exercise and populate Redis without serving from it. A nonzero value explicitly authorizes detached tracked writes after clean shadow-only misses. It does not create another `CacheLayer`, activate Redis without a valid remote TTL, or make a request-local/process-local hit continue to Redis. +`shadow.ramp` uses the same inclusive 0–100 percentage domain but is independent of cache-layer serving ramps. Omission and `0` disable shadow work; `100` selects every eligible tracked Redis key; intermediate values assign each exact cache key to a stable shadow cohort across calls and instances. A valid remote policy can therefore use `ramp.remote: 0` with a nonzero `shadow.ramp` to exercise and populate Redis without serving from it. A nonzero value explicitly authorizes detached tracked writes after clean shadow-only misses. It does not create another `CacheLayer`, activate Redis without a valid remote TTL, or make a request-local/process-local hit continue to Redis. -Remote serving and shadow sampling use independent deterministic cohorts. Equal partial percentages do not imply the same keys, so a partial shadow cohort does not guarantee that every key admitted by a later partial serving ramp was warmed or validated. Use `shadowRamp: 100` when every otherwise eligible invocation must exercise the non-serving Redis path before a serving-ramp increase. +Remote serving and shadow sampling use independent deterministic cohorts. Equal partial percentages do not imply the same keys, so a partial shadow cohort does not guarantee that every key admitted by a later partial serving ramp was warmed or validated. Use `shadow: { ramp: 100 }` when every otherwise eligible invocation must exercise the non-serving Redis path before a serving-ramp increase. ## Cache layers @@ -455,7 +459,7 @@ This guard is deliberately conservative and is not a proof of runtime data. Type #### Shadow validation -Shadow mode runs a sampled, detached Redis path for tracked keys without allowing that path to serve the caller. A Redis hit is compared with the source of truth (SoT); a clean Redis miss can be filled from the caller-accepted SoT value. Redis serving and shadow execution are independent, and shadowing is opt-in per use case through `shadowRamp`: +Shadow mode runs a sampled, detached Redis path for tracked keys without allowing that path to serve the caller. A Redis hit is compared with the source of truth (SoT); a clean Redis miss can be filled from the caller-accepted SoT value. Redis serving and shadow execution are independent, and shadowing is opt-in per use case through `shadow.ramp`: ```ts import { CacheLayer, DialCache, DialCacheKeyConfig } from "dialcache"; @@ -483,13 +487,19 @@ const getUser = dialcache.cached( ttlSec: { [CacheLayer.REMOTE]: 300 }, // Exercise and populate Redis without serving it to callers. ramp: { [CacheLayer.REMOTE]: 0 }, - shadowRamp: 5, + shadow: { + ramp: 5, + // Default-off metadata warning for a confirmed mismatch. + logMismatches: true, + // Keep false unless this logger is approved for key/value data. + logMismatchDetails: false, + }, }), }, ); ``` -Shadow work is eligible only when the operation sets `trackForInvalidation: true`, a valid remote TTL/policy exists, its effective `shadowRamp` selects the exact cache key, a configured metrics adapter implements `shadowValidation`, and capacity is available. The bundled Prometheus and Datadog adapters implement that hook. There are two paths: +Shadow work is eligible only when the operation sets `trackForInvalidation: true`, 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. Logging is supplemental to that metric; enabling either logging flag 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 tracked 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 tracked Redis read for `C0`. 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. @@ -534,6 +544,10 @@ 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`. 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. +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`. With details disabled, the single warning contains only `cacheNamespace`, `useCase`, `keyType`, and `outcome: "mismatch"`. Setting `shadow.logMismatchDetails: true` enriches that same warning with `cacheKey`, `cachedValue`, and `sourceValue`, but is inert unless `logMismatches` is also true. `cacheKey` is the logical DialCache URN, not the physical Redis storage key. The two values are the deserialized cached snapshot and raw source value supplied to the comparator; DialCache does not compute or serialize a textual diff and does not call the serializer again for logging. + +Detailed mismatch logging is intentionally default-off. Logical URNs can contain ids and arguments, while cached and source values may contain secrets, personal data, cyclic structures, or arbitrarily large graphs. DialCache passes those values to the logger by reference without cloning; the logger must not mutate them and may retain them after the shadow job releases its own references. Enable details only with an approved logger, redaction, transport, access, and retention policy. 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. The command amplification is bounded: a selected served hit adds one SoT read and adds `C1` only for a semantic mismatch candidate; a selected ramped-down hit adds detached `C0`, reuses the caller's existing SoT read, and likewise adds `C1` only for a candidate; a selected ramped-down miss adds detached `C0` and at most one tracked fill. `superseded` means only that the original observation could not be confirmed. `mismatch` means the exact `C0` payload survived a tracked Redis read after the SoT disagreement; it is not a cross-system atomic snapshot or a guarantee that the mismatch persists. @@ -542,7 +556,7 @@ The initial `C0` read and later fill are not atomic. The fill is a normal tracke A served-hit sample invokes the wrapped function or inline loader as an additional source read, so that loader must be safe to call for observation. A ramped-down sample reuses the caller's ordinary invocation and does not add another SoT call. -For valid policies, shadow-specific source calls, cache-path Redis traffic, returned values, and metrics are unchanged when `shadowRamp` is omitted or `0`. Independently of shadow execution, this release rejects malformed runtime ramps instead of clamping them, isolates rejected observer promises and thenables, and makes `DialCacheKeyConfig.disabled()` explicitly set `shadowRamp: 0`. The opt-in feature adds the per-key `shadowRamp` and `shadowComparator` settings, the per-instance `shadowMaxInFlight` limit, and the `shadowValidation` metrics hook/instrument. The clean-miss bootstrap adds no additional ramp knob, Redis protocol operation, metric instrument, or label key; enabling shadowing authorizes the tracked Redis write described above. Exported unions widen: `MetricLayer` gains `remote_shadow`, and `ShadowValidationOutcome` gains `superseded`, `filled`, `fill_blocked`, `fill_error`, `redis_error`, and `confirmation_error`. TypeScript consumers with exhaustive switches or `Record` values must add those cases, and dashboards restricted to `layer="remote"` intentionally exclude detached traffic. +For valid policies, shadow-specific source calls, cache-path Redis traffic, returned values, and metrics are unchanged when `shadow` is omitted or `shadow.ramp` is `0`. Shadow policy is grouped under `DialCacheKeyConfig.shadow`; consumers of the former flat ramp field must migrate to `shadow: { ramp }`, and the removed field is rejected rather than silently ignored. `DialCacheKeyConfig.disabled()` explicitly sets the shadow ramp and both logging gates to their disabled values. `shadowComparator` remains a typed `cached()` / `getOrLoad()` option because it defines stable use-case equality, while `shadowMaxInFlight` remains a per-instance concurrency limit. The clean-miss bootstrap adds no additional ramp knob, Redis protocol operation, metric instrument, or label key; enabling shadowing authorizes the tracked Redis write described above. Exported unions include `remote_shadow` in `MetricLayer` and `superseded`, `filled`, `fill_blocked`, `fill_error`, `redis_error`, and `confirmation_error` in `ShadowValidationOutcome`. TypeScript consumers with exhaustive switches or `Record` values must include those cases, and dashboards restricted to `layer="remote"` intentionally exclude detached traffic. ## Cached-value ownership @@ -819,7 +833,7 @@ These values are defined by the backend-neutral core and are identical for every ### Custom adapters -For other telemetry backends, implement `DialCacheMetricsAdapter` and pass the adapter through `new DialCache({ metrics })`. Every backend-neutral label object exposes the logical namespace as camel-case `cacheNamespace`; adapters should map it to their backend's `cache_namespace` label/tag. This field is present even when no key or cache layer was reached. Implement the optional `shadowValidation` method to enable shadow work as well as record its outcomes; omitting it leaves all shadow work disabled even when `shadowRamp` is nonzero. Every metrics callback is fire-and-forget: DialCache isolates synchronous throws and consumes rejections from returned promises or thenables, but never awaits or drains observer work. Omit `metrics` to disable metrics. +For other telemetry backends, implement `DialCacheMetricsAdapter` and pass the adapter through `new DialCache({ metrics })`. Every backend-neutral label object exposes the logical namespace as camel-case `cacheNamespace`; adapters should map it to their backend's `cache_namespace` label/tag. This field is present even when no key or cache layer was reached. Implement the optional `shadowValidation` method to enable shadow work as well as record its outcomes; omitting it leaves all shadow work disabled even when `shadow.ramp` is nonzero or mismatch logging is enabled. Every metrics callback is fire-and-forget: DialCache isolates synchronous throws and consumes rejections from returned promises or thenables, but never awaits or drains observer work. Omit `metrics` to disable metrics. ## Maintainers diff --git a/scripts/benchmark-request-local.mjs b/scripts/benchmark-request-local.mjs index d5ef82e..8a0c3b9 100644 --- a/scripts/benchmark-request-local.mjs +++ b/scripts/benchmark-request-local.mjs @@ -35,7 +35,7 @@ const results = [ scenario: "tracked Redis hits, shadow ramped out", useCase: "BenchmarkTrackedRedisShadowRampedOut", // This exact key's stable shadow sample is about 90.11. - shadowRamp: 50, + shadowPercentage: 50, }), await benchmarkDarkShadowDetachment(), await benchmarkDarkShadowFillDetachment(), @@ -314,7 +314,7 @@ async function benchmarkRedisReadDeadlineCoalescing(fanout) { } } -async function benchmarkSequentialTrackedRedisHits(iterations, { scenario, useCase, shadowRamp }) { +async function benchmarkSequentialTrackedRedisHits(iterations, { scenario, useCase, shadowPercentage }) { let redisReadCalls = 0; let redisWriteCalls = 0; let redisInvalidationCalls = 0; @@ -351,7 +351,7 @@ async function benchmarkSequentialTrackedRedisHits(iterations, { scenario, useCa defaultConfig: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 100 }, - ...(shadowRamp === undefined ? {} : { shadowRamp }), + ...(shadowPercentage === undefined ? {} : { shadow: { ramp: shadowPercentage } }), }), }, ); @@ -429,7 +429,7 @@ async function benchmarkDarkShadowDetachment() { defaultConfig: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 0 }, - shadowRamp: 100, + shadow: { ramp: 100 }, }), }, ); @@ -514,7 +514,7 @@ async function benchmarkDarkShadowFillDetachment() { defaultConfig: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 0 }, - shadowRamp: 100, + shadow: { ramp: 100 }, }), }, ); diff --git a/scripts/test-package.mjs b/scripts/test-package.mjs index 1b40c53..d3b86a2 100644 --- a/scripts/test-package.mjs +++ b/scripts/test-package.mjs @@ -42,6 +42,7 @@ const rootConsumer = `import { type RedisWriteRequest, type Serializer, type ShadowComparator, + type ShadowConfig, type ShadowValidationMetricLabels, type ShadowValidationOutcome, } from "dialcache"; @@ -115,7 +116,12 @@ const shadowCacheConfig: DialCacheConfig = { shadowMaxInFlight: 2, }; const shadowCache = new DialCache(shadowCacheConfig); -const shadowKeyConfig = new DialCacheKeyConfig({ shadowRamp: 50 }); +const shadowConfig: ShadowConfig = { + ramp: 50, + logMismatches: true, + logMismatchDetails: false, +}; +const shadowKeyConfig = new DialCacheKeyConfig({ shadow: shadowConfig }); const dogStatsDClient: DatadogDogStatsDClient = { increment: () => undefined, histogram: () => undefined, @@ -631,7 +637,14 @@ if ("MissingKeyConfigError" in root) { throw new Error("The removed MissingKeyConfigError class must not be exported from the root ESM entry"); } const esmDisabledOverlay = root.DialCacheKeyConfig.disabled(); -if (esmDisabledOverlay.requestLocal !== false || esmDisabledOverlay.shadowRamp !== 0 || esmDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 || esmDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0) { +if ( + esmDisabledOverlay.requestLocal !== false + || esmDisabledOverlay.shadow?.ramp !== 0 + || esmDisabledOverlay.shadow.logMismatches !== false + || esmDisabledOverlay.shadow.logMismatchDetails !== false + || esmDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 + || esmDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0 +) { throw new Error("The packed ESM runtime did not build the disabled() kill-switch overlay"); } let calls = 0; @@ -774,7 +787,7 @@ const load = cache.cached(async () => await new Promise(() => undefined), { defaultConfig: new root.DialCacheKeyConfig({ ttlSec: { [root.CacheLayer.REMOTE]: 60 }, ramp: { [root.CacheLayer.REMOTE]: 100 }, - shadowRamp: 100, + shadow: { ramp: 100 }, }), }); let value = await cache.enable(() => load()); @@ -863,7 +876,14 @@ if ("MissingKeyConfigError" in root) { throw new Error("The removed MissingKeyConfigError class must not be exported from the root CommonJS entry"); } const cjsDisabledOverlay = root.DialCacheKeyConfig.disabled(); -if (cjsDisabledOverlay.requestLocal !== false || cjsDisabledOverlay.shadowRamp !== 0 || cjsDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 || cjsDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0) { +if ( + cjsDisabledOverlay.requestLocal !== false + || cjsDisabledOverlay.shadow?.ramp !== 0 + || cjsDisabledOverlay.shadow.logMismatches !== false + || cjsDisabledOverlay.shadow.logMismatchDetails !== false + || cjsDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 + || cjsDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0 +) { throw new Error("The packed CommonJS runtime did not build the disabled() kill-switch overlay"); } void (async () => { diff --git a/src/config.ts b/src/config.ts index 2e72cb4..1bd93f5 100644 --- a/src/config.ts +++ b/src/config.ts @@ -11,17 +11,25 @@ export enum CacheLayer { export type Awaitable = T | Promise; export type LayerConfig = Partial>; +/** 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 for each confirmed mismatch. Defaults to false. */ + readonly logMismatches?: boolean; + /** + * Enrich that warning with the logical cache key and compared values. + * Defaults to false and has no effect unless `logMismatches` is true. + */ + readonly logMismatchDetails?: boolean; +} + export class DialCacheKeyConfig { /** Per-layer TTLs in seconds, from 1 through 31,536,000 (365 days). */ readonly ttlSec: LayerConfig; readonly ramp: LayerConfig; - /** - * Percentage of tracked Redis keys that asynchronously exercise Redis - * without changing what serves the caller. Hits validate against the source - * of truth and ramped-down clean misses populate Redis. This shadow cohort is - * independent of the Redis serving ramp. Omitted and zero disable it. - */ - readonly shadowRamp?: number; + /** Per-use-case runtime policy for detached Redis shadow work. */ + readonly shadow?: ShadowConfig; /** * Memoize successful values for the lifetime of the outermost enabled scope. * Request-local caching is disabled by default and has no TTL or ramp. @@ -36,17 +44,21 @@ export class DialCacheKeyConfig { constructor(config: { ttlSec?: LayerConfig; ramp?: LayerConfig; - shadowRamp?: number; + shadow?: ShadowConfig; requestLocal?: boolean; remoteReadTimeoutMs?: number; }) { 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"'); + } this.ttlSec = cloneLayerConfig(config.ttlSec, "ttlSec"); this.ramp = cloneLayerConfig(config.ramp, "ramp"); - if (config.shadowRamp !== undefined) { - this.shadowRamp = config.shadowRamp; + const shadow = cloneShadowConfig(config.shadow); + if (shadow !== undefined) { + this.shadow = shadow; } if (config.requestLocal !== undefined && typeof config.requestLocal !== "boolean") { throw new TypeError("DialCache requestLocal config must be a boolean"); @@ -83,7 +95,11 @@ export class DialCacheKeyConfig { static disabled(): DialCacheKeyConfig { return new DialCacheKeyConfig({ requestLocal: false, - shadowRamp: 0, + shadow: { + ramp: 0, + logMismatches: false, + logMismatchDetails: false, + }, ramp: { [CacheLayer.LOCAL]: 0, [CacheLayer.REMOTE]: 0, @@ -102,6 +118,16 @@ function cloneLayerConfig(config: LayerConfig | undefined, name: "ttlSec" | "ram return { ...config }; } +function cloneShadowConfig(config: ShadowConfig | undefined): ShadowConfig | undefined { + if (config === undefined) { + return undefined; + } + if (config === null || typeof config !== "object" || Array.isArray(config)) { + throw new TypeError("DialCache shadow config must be an object"); + } + return { ...config }; +} + /** * Resolves runtime cache policy. Async implementations must settle within a * finite application-defined deadline; DialCache does not add one. diff --git a/src/dialcache.ts b/src/dialcache.ts index 42c64d5..d17f1c2 100644 --- a/src/dialcache.ts +++ b/src/dialcache.ts @@ -222,6 +222,16 @@ interface ShadowValidationPlan { readonly didCallerFallbackTimeout: () => boolean; } +interface ResolvedShadowLogging { + readonly logMismatches: boolean; + readonly logMismatchDetails: boolean; +} + +interface ShadowMismatchDetails { + readonly cachedValue: unknown; + readonly sourceValue: unknown; +} + type ShadowValidationStart = | { readonly kind: "retained"; readonly payload: RedisCachePayload } | { @@ -707,7 +717,7 @@ export class DialCache { fallback: () => Promise, shadowValidation: ShadowValidationPlan, ): Promise { - const shadowStartedAtMs = keyConfig?.shadowRamp === undefined || keyConfig.shadowRamp === 0 + const shadowStartedAtMs = keyConfig?.shadow?.ramp === undefined || keyConfig.shadow.ramp === 0 ? null : performance.now(); const valuePromise = this.callFallback(fallbackLabels, fallback); @@ -793,18 +803,37 @@ export class DialCache { return; } - const shadowRamp = keyConfig?.shadowRamp; - if (shadowRamp === undefined || shadowRamp === 0) { + const shadowConfig: unknown = keyConfig?.shadow; + if ( + shadowConfig === null + || typeof shadowConfig !== "object" + || Array.isArray(shadowConfig) + ) { + if (shadowConfig !== undefined) { + this.recordError(key, CacheLayer.REMOTE, "config_resolution"); + } return; } - if (typeof shadowRamp !== "number" || !Number.isFinite(shadowRamp) || shadowRamp < 0 || shadowRamp > 100) { + + const resolvedShadowConfig = shadowConfig as Record; + const shadowPercentage: unknown = resolvedShadowConfig.ramp; + if (shadowPercentage === undefined || shadowPercentage === 0) { + return; + } + if ( + typeof shadowPercentage !== "number" + || !Number.isFinite(shadowPercentage) + || shadowPercentage < 0 + || shadowPercentage > 100 + ) { this.recordError(key, CacheLayer.REMOTE, "config_resolution"); return; } + const shadowLogging = this.resolveShadowLogging(key, resolvedShadowConfig); if (this.metrics?.shadowValidation === undefined) { return; } - if (shadowRamp < 100 && deterministicShadowRampSample(key) >= shadowRamp) { + if (shadowPercentage < 100 && deterministicShadowRampSample(key) >= shadowPercentage) { return; } @@ -831,9 +860,41 @@ export class DialCache { runStart, validation, readTimeoutMs, + shadowLogging, ); } + private resolveShadowLogging( + key: DialCacheKey, + shadowConfig: Record, + ): ResolvedShadowLogging { + const configuredLogMismatches = shadowConfig.logMismatches; + const configuredLogMismatchDetails = shadowConfig.logMismatchDetails; + + let logMismatches = false; + if (configuredLogMismatches !== undefined) { + if (typeof configuredLogMismatches === "boolean") { + logMismatches = configuredLogMismatches; + } else { + this.recordError(key, CacheLayer.REMOTE, "config_resolution"); + } + } + + let logMismatchDetails = false; + if (configuredLogMismatchDetails !== undefined) { + if (typeof configuredLogMismatchDetails === "boolean") { + logMismatchDetails = configuredLogMismatchDetails; + } else { + this.recordError(key, CacheLayer.REMOTE, "config_resolution"); + } + } + + return { + logMismatches, + logMismatchDetails: logMismatches && logMismatchDetails, + }; + } + private deferShadowValidation( redisCache: RedisCache, key: DialCacheKey, @@ -841,6 +902,7 @@ export class DialCache { start: ShadowValidationRunStart, validation: ShadowValidationPlan, readTimeoutMs: number, + shadowLogging: ResolvedShadowLogging, ): void { setImmediate(() => { this.runShadowValidation( @@ -850,6 +912,7 @@ export class DialCache { start, validation, readTimeoutMs, + shadowLogging, ); }).unref(); } @@ -861,6 +924,7 @@ export class DialCache { start: ShadowValidationRunStart, plan: ShadowValidationPlan, readTimeoutMs: number, + shadowLogging: ResolvedShadowLogging, ): void { const pendingRedisReads = new Set>(); let operationFinished = false; @@ -910,6 +974,7 @@ export class DialCache { }; const elapsedBeforeStartMs = Math.max(performance.now() - deadlineStartedAtMs, 0); const remainingTimeoutMs = Math.max(plan.timeoutMs - elapsedBeforeStartMs, 0); + let mismatchDetails: ShadowMismatchDetails | undefined; const validation = withMonotonicDeadline({ timeoutMs: remainingTimeoutMs, @@ -1040,9 +1105,13 @@ export class DialCache { if (originalPayload === null) { return "timeout"; } - return confirmationPayload === null || !redisPayloadsEqual(originalPayload, confirmationPayload) - ? "superseded" - : "mismatch"; + if (confirmationPayload === null || !redisPayloadsEqual(originalPayload, confirmationPayload)) { + return "superseded"; + } + if (shadowLogging.logMismatchDetails) { + mismatchDetails = { cachedValue, sourceValue }; + } + return "mismatch"; } finally { finishOperation(); } @@ -1050,18 +1119,45 @@ export class DialCache { }); void validation.then( - (outcome) => this.recordShadowValidation(key, outcome), + (outcome) => this.recordShadowValidation(key, outcome, shadowLogging, mismatchDetails), () => this.recordShadowValidation(key, "timeout"), ); } - private recordShadowValidation(key: DialCacheKey, outcome: ShadowValidationOutcome): void { - this.metrics?.shadowValidation?.({ + private recordShadowValidation( + key: DialCacheKey, + outcome: ShadowValidationOutcome, + logging?: ResolvedShadowLogging, + mismatchDetails?: ShadowMismatchDetails, + ): void { + const labels = { cacheNamespace: key.namespace, useCase: key.useCase, keyType: key.keyType, outcome, - }); + } as const; + this.metrics?.shadowValidation?.(labels); + if (outcome !== "mismatch" || logging?.logMismatches !== true) { + return; + } + + const warning = { + cacheNamespace: key.namespace, + useCase: key.useCase, + keyType: key.keyType, + outcome: "mismatch", + } as const; + this.logger.warn( + "DialCache shadow validation mismatch", + logging.logMismatchDetails && mismatchDetails !== undefined + ? { + ...warning, + cacheKey: key.urn, + cachedValue: mismatchDetails.cachedValue, + sourceValue: mismatchDetails.sourceValue, + } + : warning, + ); } private async resolveLocalLayerConfig( @@ -1292,9 +1388,12 @@ 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 shadowRamp = config.shadowRamp; + const shadowConfig = config.shadow; const requestLocal = config.requestLocal; const remoteReadTimeoutMs = config.remoteReadTimeoutMs; if (requestLocal !== undefined && typeof requestLocal !== "boolean") { @@ -1303,13 +1402,14 @@ function snapshotDefaultConfig(config: DialCacheKeyConfig | null | undefined): D assertDefaultLayerMap(ttlSecConfig, "ttlSec"); assertDefaultLayerMap(rampConfig, "ramp"); + assertDefaultShadowConfig(shadowConfig); const snapshot = new DialCacheKeyConfig({ ttlSec: ttlSecConfig, ramp: rampConfig, ...(requestLocal === undefined ? {} : { requestLocal }), ...(remoteReadTimeoutMs === undefined ? {} : { remoteReadTimeoutMs }), - ...(shadowRamp === undefined ? {} : { shadowRamp }), + ...(shadowConfig === undefined ? {} : { shadow: shadowConfig }), }); for (const layer of [CacheLayer.LOCAL, CacheLayer.REMOTE]) { @@ -1336,17 +1436,31 @@ function snapshotDefaultConfig(config: DialCacheKeyConfig | null | undefined): D } } - if (snapshot.shadowRamp !== undefined) { - if (typeof snapshot.shadowRamp !== "number") { - throw new TypeError("DialCache defaultConfig shadowRamp must be a number"); + if (snapshot.shadow !== undefined) { + if (snapshot.shadow.ramp !== undefined) { + if (typeof snapshot.shadow.ramp !== "number") { + throw new TypeError("DialCache defaultConfig shadow.ramp must be a number"); + } + if (!Number.isFinite(snapshot.shadow.ramp) || snapshot.shadow.ramp < 0 || snapshot.shadow.ramp > 100) { + throw new RangeError("DialCache defaultConfig shadow.ramp must be between 0 and 100"); + } } - if (!Number.isFinite(snapshot.shadowRamp) || snapshot.shadowRamp < 0 || snapshot.shadowRamp > 100) { - throw new RangeError("DialCache defaultConfig shadowRamp 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"); + } + if ( + snapshot.shadow.logMismatchDetails !== undefined + && typeof snapshot.shadow.logMismatchDetails !== "boolean" + ) { + throw new TypeError("DialCache defaultConfig shadow.logMismatchDetails must be a boolean"); } } Object.freeze(snapshot.ttlSec); Object.freeze(snapshot.ramp); + if (snapshot.shadow !== undefined) { + Object.freeze(snapshot.shadow); + } return Object.freeze(snapshot); } @@ -1356,6 +1470,15 @@ function assertDefaultLayerMap(config: unknown, name: "ttlSec" | "ramp"): void { } } +function assertDefaultShadowConfig(config: unknown): asserts config is Record | undefined { + if ( + config !== undefined + && (config === null || typeof config !== "object" || Array.isArray(config)) + ) { + throw new TypeError("DialCache defaultConfig shadow must be an object"); + } +} + function resolveFallbackTimeoutMs(value: number | null | undefined): number | null { if (value === null) { return null; diff --git a/src/index.ts b/src/index.ts index c3faad0..bfa5a63 100644 --- a/src/index.ts +++ b/src/index.ts @@ -1,5 +1,5 @@ export { CacheLayer, DialCacheKeyConfig } from "./config.js"; -export type { CacheConfigProvider, DialCacheConfig, LayerConfig, Logger } from "./config.js"; +export type { CacheConfigProvider, DialCacheConfig, LayerConfig, Logger, ShadowConfig } 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 e657328..7e619f6 100644 --- a/src/internal/runtime-config.ts +++ b/src/internal/runtime-config.ts @@ -3,6 +3,7 @@ import { DialCacheKeyConfig, type CacheConfigProvider, type LayerConfig, + type ShadowConfig, } from "../config.js"; import type { DialCacheKey } from "../key.js"; import type { DisabledReason } from "../metrics.js"; @@ -107,16 +108,14 @@ function mergeKeyConfig( const remoteReadTimeoutMs = overlay?.remoteReadTimeoutMs !== undefined ? overlay.remoteReadTimeoutMs : defaultConfig?.remoteReadTimeoutMs; - const shadowRamp = overlay?.shadowRamp !== undefined - ? overlay.shadowRamp - : defaultConfig?.shadowRamp; + const shadow = mergeShadowConfig(defaultConfig?.shadow, overlay?.shadow); return new DialCacheKeyConfig({ ttlSec: mergeLayerConfig(defaultConfig?.ttlSec, overlay?.ttlSec, "ttlSec"), ramp: mergeLayerConfig(defaultConfig?.ramp, overlay?.ramp, "ramp"), requestLocal, ...(remoteReadTimeoutMs === undefined ? {} : { remoteReadTimeoutMs }), - ...(shadowRamp === undefined ? {} : { shadowRamp }), + ...(shadow === undefined ? {} : { shadow }), }); } @@ -124,6 +123,9 @@ 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( @@ -150,3 +152,35 @@ function assertLayerConfig(config: LayerConfig | undefined, name: "ttlSec" | "ra throw new TypeError(`DialCache ${name} config must be a layer map`); } } + +function mergeShadowConfig( + defaults: ShadowConfig | undefined, + overlay: ShadowConfig | undefined, +): ShadowConfig | undefined { + assertShadowConfig(defaults); + assertShadowConfig(overlay); + + if (defaults === undefined && overlay === undefined) { + return undefined; + } + + const ramp = overlay?.ramp !== undefined ? overlay.ramp : defaults?.ramp; + const logMismatches = overlay?.logMismatches !== undefined + ? overlay.logMismatches + : defaults?.logMismatches; + const logMismatchDetails = overlay?.logMismatchDetails !== undefined + ? overlay.logMismatchDetails + : defaults?.logMismatchDetails; + + return { + ...(ramp === undefined ? {} : { ramp }), + ...(logMismatches === undefined ? {} : { logMismatches }), + ...(logMismatchDetails === undefined ? {} : { logMismatchDetails }), + }; +} + +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"); + } +} diff --git a/test/dialcache-config-ramp.test.ts b/test/dialcache-config-ramp.test.ts index 91c2d7a..1de6955 100644 --- a/test/dialcache-config-ramp.test.ts +++ b/test/dialcache-config-ramp.test.ts @@ -38,16 +38,51 @@ describe("DialCache runtime config and ramp controls", () => { expect(new DialCacheKeyConfig({ requestLocal: false }).requestLocal).toBe(false); }); - it("preserves shadowRamp omission and explicit kill-switch values", () => { - expect(new DialCacheKeyConfig({}).shadowRamp).toBeUndefined(); - expect(new DialCacheKeyConfig({ shadowRamp: 0 }).shadowRamp).toBe(0); + it("preserves shadow omission and explicit kill-switch values", () => { + expect(new DialCacheKeyConfig({}).shadow).toBeUndefined(); + expect(new DialCacheKeyConfig({ shadow: {} }).shadow).toEqual({}); + expect(new DialCacheKeyConfig({ + shadow: { + ramp: 0, + logMismatches: false, + logMismatchDetails: false, + }, + }).shadow).toEqual({ + ramp: 0, + logMismatches: false, + logMismatchDetails: false, + }); + }); + + it("clones the supplied shadow policy", () => { + const suppliedShadow = { + ramp: 25, + logMismatches: true, + logMismatchDetails: true, + }; + const config = new DialCacheKeyConfig({ shadow: suppliedShadow }); + + suppliedShadow.ramp = 0; + suppliedShadow.logMismatches = false; + suppliedShadow.logMismatchDetails = false; + + expect(config.shadow).not.toBe(suppliedShadow); + expect(config.shadow).toEqual({ + ramp: 25, + logMismatches: true, + logMismatchDetails: true, + }); }); it("captures an immutable default policy snapshot when the use case is registered", async () => { const suppliedDefault = new DialCacheKeyConfig({ ttlSec: { [CacheLayer.LOCAL]: 60 }, ramp: { [CacheLayer.LOCAL]: 100 }, - shadowRamp: 25, + shadow: { + ramp: 25, + logMismatches: true, + logMismatchDetails: true, + }, }); const observedDefaults: Array = []; const dialcache = new DialCache({ @@ -67,7 +102,14 @@ describe("DialCache runtime config and ramp controls", () => { suppliedDefault.ttlSec[CacheLayer.LOCAL] = 0; suppliedDefault.ramp[CacheLayer.LOCAL] = 0; - (suppliedDefault as { shadowRamp?: number }).shadowRamp = 0; + const mutableShadow = suppliedDefault.shadow as { + ramp?: number; + logMismatches?: boolean; + logMismatchDetails?: boolean; + }; + mutableShadow.ramp = 0; + mutableShadow.logMismatches = false; + mutableShadow.logMismatchDetails = false; const first = await dialcache.enable(async () => await getUser("123")); const second = await dialcache.enable(async () => await getUser("123")); @@ -78,10 +120,15 @@ describe("DialCache runtime config and ramp controls", () => { expect(observedDefaults[1]).toBe(observedDefaults[0]); expect(observedDefaults[0]?.ttlSec[CacheLayer.LOCAL]).toBe(60); expect(observedDefaults[0]?.ramp[CacheLayer.LOCAL]).toBe(100); - expect(observedDefaults[0]?.shadowRamp).toBe(25); + expect(observedDefaults[0]?.shadow).toEqual({ + ramp: 25, + logMismatches: true, + logMismatchDetails: true, + }); 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); }); it("enables request-local caching without TTL or ramp policy", async () => { @@ -273,6 +320,16 @@ describe("DialCache runtime config and ramp controls", () => { () => new DialCacheKeyConfig({ requestLocal: null as unknown as boolean }), "DialCache requestLocal config must be a boolean", ], + [ + "a null shadow config", + () => new DialCacheKeyConfig({ shadow: null 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); }); @@ -297,11 +354,21 @@ describe("DialCache runtime config and ramp controls", () => { ["negative ramp", new DialCacheKeyConfig({ ramp: { [CacheLayer.LOCAL]: -1 } }), RangeError, "between 0 and 100"], ["over-100 ramp", new DialCacheKeyConfig({ ramp: { [CacheLayer.LOCAL]: 101 } }), RangeError, "between 0 and 100"], ["non-finite ramp", new DialCacheKeyConfig({ ramp: { [CacheLayer.LOCAL]: Number.POSITIVE_INFINITY } }), RangeError, "between 0 and 100"], - ["negative shadow ramp", new DialCacheKeyConfig({ shadowRamp: -1 }), RangeError, "between 0 and 100"], - ["over-100 shadow ramp", new DialCacheKeyConfig({ shadowRamp: 101 }), RangeError, "between 0 and 100"], + [ + "negative shadow ramp", + new DialCacheKeyConfig({ shadow: { ramp: -1 } }), + RangeError, + "between 0 and 100", + ], + [ + "over-100 shadow ramp", + new DialCacheKeyConfig({ shadow: { ramp: 101 } }), + RangeError, + "between 0 and 100", + ], [ "non-finite shadow ramp", - new DialCacheKeyConfig({ shadowRamp: Number.POSITIVE_INFINITY }), + new DialCacheKeyConfig({ shadow: { ramp: Number.POSITIVE_INFINITY } }), RangeError, "between 0 and 100", ], @@ -319,10 +386,22 @@ describe("DialCache runtime config and ramp controls", () => { ], [ "wrong-type shadow ramp", - new DialCacheKeyConfig({ shadowRamp: null as unknown as number }), + new DialCacheKeyConfig({ shadow: { ramp: null as unknown as number } }), TypeError, "must be a number", ], + [ + "wrong-type shadow mismatch logging flag", + new DialCacheKeyConfig({ shadow: { logMismatches: null as unknown as boolean } }), + TypeError, + "must be a boolean", + ], + [ + "wrong-type shadow mismatch detail flag", + new DialCacheKeyConfig({ shadow: { logMismatchDetails: null as unknown as boolean } }), + TypeError, + "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"], [ @@ -331,6 +410,12 @@ describe("DialCache runtime config and ramp controls", () => { TypeError, "must be a layer map", ], + [ + "removed shadowRamp", + { ttlSec: {}, ramp: {}, shadowRamp: 100 } as unknown as DialCacheKeyConfig, + TypeError, + 'shadowRamp was replaced by "shadow.ramp"', + ], ])("rejects a malformed static defaultConfig with $0 at registration", (_name, defaultConfig, ErrorType, message) => { const dialcache = new DialCache(); @@ -362,6 +447,7 @@ describe("DialCache runtime config and ramp controls", () => { ["an array", []], ["a null layer map", { ttlSec: null, ramp: {} }], ["a null requestLocal value", { ttlSec: {}, ramp: {}, requestLocal: null }], + ["the removed shadowRamp field", { ttlSec: {}, ramp: {}, shadowRamp: 100 }], ] as const)("fails open instead of inheriting defaults when the provider returns %s", async (_name, runtimeConfig) => { const cacheConfigProvider = vi.fn(async () => runtimeConfig as unknown as DialCacheKeyConfig); const dialcache = new DialCache({ cacheConfigProvider }); @@ -384,7 +470,11 @@ describe("DialCache runtime config and ramp controls", () => { it("returns the explicit kill-switch overlay from DialCacheKeyConfig.disabled()", () => { expect(DialCacheKeyConfig.disabled()).toEqual(new DialCacheKeyConfig({ requestLocal: false, - shadowRamp: 0, + shadow: { + ramp: 0, + logMismatches: false, + logMismatchDetails: false, + }, ramp: { [CacheLayer.LOCAL]: 0, [CacheLayer.REMOTE]: 0 }, })); }); diff --git a/test/dialcache-observability-internals.test.ts b/test/dialcache-observability-internals.test.ts index 8cb43ae..615f82f 100644 --- a/test/dialcache-observability-internals.test.ts +++ b/test/dialcache-observability-internals.test.ts @@ -15,7 +15,11 @@ describe("DialCache observability internal compatibility paths", () => { requestLocal: true, ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 120 }, ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 50 }, - shadowRamp: 20, + shadow: { + ramp: 20, + logMismatches: true, + logMismatchDetails: true, + }, }); const cases = [ { @@ -23,25 +27,50 @@ describe("DialCache observability internal compatibility paths", () => { requestLocal: false, ttlSec: { [CacheLayer.LOCAL]: 30 }, ramp: { [CacheLayer.REMOTE]: 75 }, - shadowRamp: 80, + shadow: { ramp: 80 }, }), expected: new DialCacheKeyConfig({ requestLocal: false, ttlSec: { [CacheLayer.LOCAL]: 30, [CacheLayer.REMOTE]: 120 }, ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 75 }, - shadowRamp: 80, + shadow: { + ramp: 80, + logMismatches: true, + logMismatchDetails: true, + }, }), }, { runtime: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 90 }, ramp: { [CacheLayer.LOCAL]: 10 }, + shadow: { + logMismatches: false, + logMismatchDetails: false, + }, }), expected: new DialCacheKeyConfig({ requestLocal: true, ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 90 }, ramp: { [CacheLayer.LOCAL]: 10, [CacheLayer.REMOTE]: 50 }, - shadowRamp: 20, + shadow: { + ramp: 20, + logMismatches: false, + logMismatchDetails: false, + }, + }), + }, + { + runtime: new DialCacheKeyConfig({ shadow: {} }), + expected: new DialCacheKeyConfig({ + requestLocal: true, + ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 120 }, + ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 50 }, + shadow: { + ramp: 20, + logMismatches: true, + logMismatchDetails: true, + }, }), }, ]; diff --git a/test/dialcache-shadow-confirmation.test.ts b/test/dialcache-shadow-confirmation.test.ts index 9cf64b5..03cbef2 100644 --- a/test/dialcache-shadow-confirmation.test.ts +++ b/test/dialcache-shadow-confirmation.test.ts @@ -138,11 +138,18 @@ class RecordingMetrics implements DialCacheMetricsAdapter { } } -function remoteConfig(remoteRamp: number, shadowRamp = 100): DialCacheKeyConfig { +function remoteConfig( + remoteRamp: number, + shadowPercentage = 100, + logging: { + readonly logMismatches?: boolean; + readonly logMismatchDetails?: boolean; + } = {}, +): DialCacheKeyConfig { return new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: remoteRamp }, - shadowRamp, + shadow: { ramp: shadowPercentage, ...logging }, }); } @@ -156,7 +163,7 @@ function localAndRemoteConfig(): DialCacheKeyConfig { [CacheLayer.LOCAL]: 100, [CacheLayer.REMOTE]: 0, }, - shadowRamp: 100, + shadow: { ramp: 100 }, }); } @@ -254,6 +261,142 @@ describe("DialCache Redis shadow confirmation", () => { expect(redis.invalidate).not.toHaveBeenCalled(); }); + it.each([ + { name: "logging is omitted", logging: {} }, + { name: "only detail logging is enabled", logging: { logMismatchDetails: true } }, + ] as const)("does not log confirmed mismatches when $name", async ({ name, logging }) => { + const payload = JSON.stringify({ id: "private-id", 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: "private-id", version: 2 }), { + ...trackedOptions( + name === "logging is omitted" + ? "ShadowMismatchLoggingOff" + : "ShadowMismatchDetailsOnly", + remoteConfig(100, 100, logging), + ), + cacheKey: () => ({ + id: "private-id", + args: { tenant: "private-tenant" }, + }), + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + expect(warn).not.toHaveBeenCalled(); + }); + + it("logs one bounded warning for a served-hit confirmed mismatch", async () => { + const payload = JSON.stringify({ id: "private-id", version: 1 }); + const redis = new ScriptedRedis([() => payload, () => payload]); + const metrics = new RecordingMetrics(); + vi.spyOn(metrics, "shadowValidation").mockImplementation((labels) => { + metrics.shadowEvents.push({ ...labels }); + Object.assign(labels as unknown as Record, { + cacheNamespace: "mutated-by-metrics", + cacheKey: "injected-by-metrics", + }); + }); + const warn = vi.fn(() => Promise.reject(new Error("logger unavailable"))); + const dialcache = createCache(redis, metrics, { + namespace: "private-namespace", + logger: { + debug: () => undefined, + error: () => undefined, + warn, + }, + }); + const getUser = dialcache.cached(async () => ({ id: "private-id", version: 2 }), { + ...trackedOptions( + "ShadowMismatchMetadata", + remoteConfig(100, 100, { logMismatches: true }), + ), + cacheKey: () => ({ + id: "private-id", + args: { tenant: "private-tenant" }, + }), + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "private-namespace", + useCase: "ShadowMismatchMetadata", + keyType: "user_id", + outcome: "mismatch", + }, + ); + await nextImmediate(); + }); + + it("logs the logical key and compared values for a ramped-down confirmed mismatch", async () => { + const cachedValue = { id: "123", version: 1 }; + const sourceValue = { id: "123", version: 2 }; + const payload = JSON.stringify(cachedValue); + const serializer: Serializer = { + dump: vi.fn((value) => JSON.stringify(value)), + load: vi.fn((value) => JSON.parse( + Buffer.isBuffer(value) ? value.toString("utf8") : value, + ) as typeof cachedValue), + }; + 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 () => sourceValue, { + ...trackedOptions( + "ShadowMismatchDetails", + remoteConfig(0, 100, { + logMismatches: true, + logMismatchDetails: true, + }), + ), + cacheKey: () => ({ + id: "123", + args: { locale: "en-US" }, + }), + serializer, + }); + + await expect(dialcache.enable(async () => await getUser())).resolves.toBe(sourceValue); + await waitForShadowEvents(metrics, 1); + + expect(warn).toHaveBeenCalledTimes(1); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase: "ShadowMismatchDetails", + keyType: "user_id", + outcome: "mismatch", + cacheKey: "{urn:user_id:123}?locale=en-US#ShadowMismatchDetails", + cachedValue, + sourceValue, + }, + ); + expect(serializer.dump).not.toHaveBeenCalled(); + }); + it.each([ { name: "missing", confirmation: null }, { @@ -284,6 +427,37 @@ describe("DialCache Redis shadow confirmation", () => { expectTrackedReads(redis, 2); }); + it("does not log a mismatch candidate when C1 is superseded", async () => { + const original = JSON.stringify({ id: "123", version: 1 }); + const confirmation = JSON.stringify({ id: "123", version: 3 }); + const redis = new ScriptedRedis([() => original, () => confirmation]); + 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( + "ShadowMismatchSuperseded", + remoteConfig(100, 100, { + logMismatches: true, + logMismatchDetails: true, + }), + ), + cacheKey: () => "123", + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["superseded"]); + expect(warn).not.toHaveBeenCalled(); + }); + it.each([ { name: "string to string", @@ -931,7 +1105,7 @@ describe("DialCache Redis shadow confirmation", () => { const cacheConfigProvider = vi.fn(async () => new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: runtimeTtlSec }, ramp: { [CacheLayer.REMOTE]: 0 }, - shadowRamp: 100, + shadow: { ramp: 100 }, remoteReadTimeoutMs: 321, })); const dialcache = createCache(redis, metrics, { cacheConfigProvider }); @@ -1000,7 +1174,7 @@ describe("DialCache Redis shadow confirmation", () => { name: "missing remote policy", tracked: true, metrics: new RecordingMetrics(), - config: new DialCacheKeyConfig({ shadowRamp: 100 }), + config: new DialCacheKeyConfig({ shadow: { ramp: 100 } }), }, { name: "untracked", @@ -1077,7 +1251,7 @@ describe("DialCache Redis shadow confirmation", () => { { name: "invalid shadow ramp", provider: async () => new DialCacheKeyConfig({ - shadowRamp: Number.NaN, + shadow: { ramp: Number.NaN }, }), }, { @@ -1111,6 +1285,80 @@ describe("DialCache Redis shadow confirmation", () => { } }); + it.each([ + { + name: "base logging flag", + runtimeShadow: { + logMismatches: "yes" as never, + }, + expectedWarning: null, + }, + { + name: "detail logging flag", + runtimeShadow: { + logMismatchDetails: "yes" as never, + }, + expectedWarning: { + cacheNamespace: "urn", + useCase: "ShadowInvalidLoggingDetails", + keyType: "user_id", + outcome: "mismatch", + }, + }, + ] as const)("fails closed for an invalid runtime $name without suppressing mismatch metrics", async ({ + name, + runtimeShadow, + expectedWarning, + }) => { + const cachedValue = { id: "123", version: 1 }; + const sourceValue = { id: "123", version: 2 }; + 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: runtimeShadow, + }), + logger: { + debug: () => undefined, + error: () => undefined, + warn, + }, + }); + const useCase = name === "base logging flag" + ? "ShadowInvalidLoggingBase" + : "ShadowInvalidLoggingDetails"; + const getUser = dialcache.cached(async () => sourceValue, { + ...trackedOptions( + useCase, + remoteConfig(100, 100, { + logMismatches: true, + logMismatchDetails: true, + }), + ), + 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); + if (expectedWarning === null) { + expect(warn).not.toHaveBeenCalled(); + } else { + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + expectedWarning, + ); + } + }); + it("treats DialCacheKeyConfig.disabled() as a complete shadow kill switch", async () => { const redis = new ScriptedRedis([]); const metrics = new RecordingMetrics(); @@ -1244,7 +1492,7 @@ describe("DialCache Redis shadow confirmation", () => { ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 0 }, requestLocal: true, - shadowRamp: 100, + shadow: { ramp: 100 }, })), cacheKey: () => "123", }); diff --git a/test/dialcache-shadow-validation.test.ts b/test/dialcache-shadow-validation.test.ts index d80b122..61fecf8 100644 --- a/test/dialcache-shadow-validation.test.ts +++ b/test/dialcache-shadow-validation.test.ts @@ -60,16 +60,16 @@ function deferred(): Deferred { return { promise, resolve, reject }; } -function remoteOnly(shadowRamp?: number, requestLocal = false): DialCacheKeyConfig { +function remoteOnly(shadowPercentage?: number, requestLocal = false): DialCacheKeyConfig { return new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 100 }, - ...(shadowRamp === undefined ? {} : { shadowRamp }), + ...(shadowPercentage === undefined ? {} : { shadow: { ramp: shadowPercentage } }), ...(requestLocal ? { requestLocal: true } : {}), }); } -function localAndRemote(shadowRamp: number): DialCacheKeyConfig { +function localAndRemote(shadowPercentage: number): DialCacheKeyConfig { return new DialCacheKeyConfig({ ttlSec: { [CacheLayer.LOCAL]: 60, @@ -79,7 +79,7 @@ function localAndRemote(shadowRamp: number): DialCacheKeyConfig { [CacheLayer.LOCAL]: 100, [CacheLayer.REMOTE]: 100, }, - shadowRamp, + shadow: { ramp: shadowPercentage }, }); } @@ -134,12 +134,12 @@ function createShadowCache( }); } -function trackedRemoteDefaults(useCase: string, shadowRamp = 100) { +function trackedRemoteDefaults(useCase: string, shadowPercentage = 100) { return { keyType: "user_id", useCase, trackForInvalidation: true, - defaultConfig: remoteOnly(shadowRamp), + defaultConfig: remoteOnly(shadowPercentage), } as const; } @@ -368,9 +368,32 @@ describe("DialCache Redis shadow validation", () => { const useCase = "ShadowNoMetricHook"; seedRedis(redis, { id: "123", useCase, payload: JSON.stringify({ id: "123" }) }); const source = vi.fn(async () => ({ id: "123" })); - const dialcache = createShadowCache(redis, metricsWithoutShadow()); + const error = vi.fn(); + const warn = vi.fn(); + const dialcache = createShadowCache(redis, { + ...metricsWithoutShadow(), + error, + }, { + cacheConfigProvider: async () => new DialCacheKeyConfig({ + shadow: { logMismatchDetails: "yes" as never }, + }), + logger: { + debug: () => undefined, + error: () => undefined, + warn, + }, + }); const getUser = dialcache.cached(source, { ...trackedRemoteDefaults(useCase), + defaultConfig: new DialCacheKeyConfig({ + ttlSec: { [CacheLayer.REMOTE]: 60 }, + ramp: { [CacheLayer.REMOTE]: 100 }, + shadow: { + ramp: 100, + logMismatches: true, + logMismatchDetails: true, + }, + }), cacheKey: () => "123", }); @@ -378,18 +401,75 @@ describe("DialCache Redis shadow validation", () => { await nextImmediate(); expect(source).not.toHaveBeenCalled(); + expect(warn).not.toHaveBeenCalled(); + expect(error).toHaveBeenCalledWith({ + cacheNamespace: "urn", + useCase, + keyType: "user_id", + layer: CacheLayer.REMOTE, + error: "config_resolution", + inFallback: false, + }); + }); + + it("reports malformed runtime shadow logging for a key outside the shadow cohort", async () => { + const redis = new FakeRedis(); + const metrics = new RecordingMetrics(); + const useCase = "ShadowExcludedInvalidLogging"; + const excludedId = Array.from({ length: 1_000 }, (_, index) => `excluded-${index}`) + .find((id) => deterministicShadowRampSample(new DialCacheKey({ + keyType: "user_id", + id, + useCase, + trackForInvalidation: true, + })) >= 50); + if (excludedId === undefined) { + throw new Error("Could not find a key outside the partial shadow cohort"); + } + seedRedis(redis, { + id: excludedId, + useCase, + payload: JSON.stringify({ id: excludedId }), + }); + const source = vi.fn(async (id: string) => ({ id })); + const dialcache = createShadowCache(redis, metrics, { + cacheConfigProvider: async () => new DialCacheKeyConfig({ + shadow: { logMismatches: "yes" as never }, + }), + }); + const getUser = dialcache.cached(source, { + keyType: "user_id", + useCase, + trackForInvalidation: true, + defaultConfig: new DialCacheKeyConfig({ + ttlSec: { [CacheLayer.REMOTE]: 60 }, + ramp: { [CacheLayer.REMOTE]: 100 }, + shadow: { ramp: 50 }, + }), + cacheKey: (id: string) => id, + }); + + expect(await dialcache.enable(async () => await getUser(excludedId))).toEqual({ id: excludedId }); + await nextImmediate(); + + expect(source).not.toHaveBeenCalled(); + expect(metrics.shadowEvents).toHaveLength(0); + expect(metrics.errorEvents.filter((labels) => + labels.layer === CacheLayer.REMOTE + && labels.error === "config_resolution" + )).toHaveLength(1); }); it.each([ - { name: "omitted", shadowRamp: undefined, recordsError: false }, - { name: "zero", shadowRamp: 0, recordsError: false }, - { name: "a string", shadowRamp: "100", recordsError: true }, - { name: "NaN", shadowRamp: Number.NaN, recordsError: true }, - { name: "negative", shadowRamp: -1, recordsError: true }, - { name: "above one hundred", shadowRamp: 101, recordsError: true }, - ])("treats runtime shadowRamp $name as a no-op without disturbing a valid Redis hit", async ({ + { name: "omitted", shadowPercentage: undefined, recordsError: false }, + { name: "zero", shadowPercentage: 0, recordsError: false }, + { name: "a string", shadowPercentage: "100", recordsError: true }, + { name: "NaN", shadowPercentage: Number.NaN, recordsError: true }, + { name: "negative", shadowPercentage: -1, recordsError: true }, + { name: "above one hundred", shadowPercentage: 101, recordsError: true }, + ])("treats runtime shadow.ramp $name as a no-op without disturbing a valid Redis hit", async ({ name, - shadowRamp, + shadowPercentage, recordsError, }) => { const redis = new FakeRedis(); @@ -398,7 +478,7 @@ describe("DialCache Redis shadow validation", () => { const cachedValue = { id: "123", source: "cache" }; seedRedis(redis, { id: "123", useCase, payload: JSON.stringify(cachedValue) }); const runtimeConfig = new DialCacheKeyConfig({ - ...(shadowRamp === undefined ? {} : { shadowRamp: shadowRamp as number }), + ...(shadowPercentage === undefined ? {} : { shadow: { ramp: shadowPercentage as number } }), }); const source = vi.fn(async () => ({ id: "123", source: "truth" })); const dialcache = createShadowCache(redis, metrics, { @@ -440,7 +520,7 @@ describe("DialCache Redis shadow validation", () => { runtimeShadowRamp: 0, expectedValidations: 0, }, - ])("runtime shadowRamp $name", async ({ + ])("runtime shadow.ramp $name", async ({ staticShadowRamp, runtimeShadowRamp, expectedValidations, @@ -452,7 +532,7 @@ describe("DialCache Redis shadow validation", () => { seedRedis(redis, { id: "123", useCase, payload: JSON.stringify(cachedValue) }); const source = vi.fn(async () => cachedValue); const dialcache = createShadowCache(redis, metrics, { - cacheConfigProvider: async () => new DialCacheKeyConfig({ shadowRamp: runtimeShadowRamp }), + cacheConfigProvider: async () => new DialCacheKeyConfig({ shadow: { ramp: runtimeShadowRamp } }), }); const getUser = dialcache.cached(source, { ...trackedRemoteDefaults(useCase), diff --git a/test/redis-real.integration.test.ts b/test/redis-real.integration.test.ts index 75e0f7b..4ca5df9 100644 --- a/test/redis-real.integration.test.ts +++ b/test/redis-real.integration.test.ts @@ -345,7 +345,7 @@ describe.each(engines)("DialCache Lua protocol on $name", ({ image }) => { const shadowRemoteOnly = new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 100 }, - shadowRamp: 100, + shadow: { ramp: 100 }, }); const dialcache = new DialCache({ namespace, @@ -508,7 +508,7 @@ describe.each(engines)("DialCache Lua protocol on $name", ({ image }) => { defaultConfig: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 0 }, - shadowRamp: 100, + shadow: { ramp: 100 }, }), }); @@ -623,7 +623,7 @@ describe.each(engines)("DialCache Lua protocol on $name", ({ image }) => { cacheConfigProvider: async () => new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: serveFromRedis ? 100 : 0 }, - shadowRamp: serveFromRedis ? 0 : 100, + shadow: { ramp: serveFromRedis ? 0 : 100 }, }), }); const source = vi.fn(async () => sourceValue); @@ -746,7 +746,7 @@ describe.each(engines)("DialCache Lua protocol on $name", ({ image }) => { defaultConfig: new DialCacheKeyConfig({ ttlSec: { [CacheLayer.REMOTE]: 60 }, ramp: { [CacheLayer.REMOTE]: 0 }, - shadowRamp: 100, + shadow: { ramp: 100 }, }), }); From 319fca6075572c4e16c2491e61528ef8a835cab7 Mon Sep 17 00:00:00 2001 From: Lev Neiman Date: Thu, 30 Jul 2026 19:44:07 -0700 Subject: [PATCH 2/6] fix: bound shadow mismatch log details --- README.md | 6 +- src/config.ts | 3 +- src/dialcache.ts | 9 +- src/internal/shadow-log-preview.ts | 376 +++++++++++++++++++++ test/dialcache-shadow-confirmation.test.ts | 58 +++- test/shadow-log-preview.test.ts | 223 ++++++++++++ 6 files changed, 667 insertions(+), 8 deletions(-) create mode 100644 src/internal/shadow-log-preview.ts create mode 100644 test/shadow-log-preview.test.ts diff --git a/README.md b/README.md index 7a07728..b5a7179 100644 --- a/README.md +++ b/README.md @@ -544,9 +544,11 @@ 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`. 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. -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`. With details disabled, the single warning contains only `cacheNamespace`, `useCase`, `keyType`, and `outcome: "mismatch"`. Setting `shadow.logMismatchDetails: true` enriches that same warning with `cacheKey`, `cachedValue`, and `sourceValue`, but is inert unless `logMismatches` is also true. `cacheKey` is the logical DialCache URN, not the physical Redis storage key. The two values are the deserialized cached snapshot and raw source value supplied to the comparator; DialCache does not compute or serialize a textual diff and does not call the serializer again for logging. +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`. With details disabled, the single warning contains only `cacheNamespace`, `useCase`, `keyType`, and `outcome: "mismatch"`. Setting `shadow.logMismatchDetails: true` enriches that same warning with `cacheKey`, `cachedValuePreview`, `sourceValuePreview`, and `detailsTruncated`, but is inert unless `logMismatches` is also true. `cacheKey` is a UTF-8 preview of the logical DialCache URN capped at 2 KiB, not the physical Redis storage key. The two value previews are capped at 8 KiB each and represent the deserialized cached snapshot and raw source value supplied to the comparator. Every clipped field ends in `...[truncated]`, counted inside its cap; `detailsTruncated` is true when any field is byte-clipped or structurally shortened. DialCache does not compute or serialize a textual diff and does not call the configured serializer again for logging. -Detailed mismatch logging is intentionally default-off. Logical URNs can contain ids and arguments, while cached and source values may contain secrets, personal data, cyclic structures, or arbitrarily large graphs. DialCache passes those values to the logger by reference without cloning; the logger must not mutate them and may retain them after the shadow job releases its own references. Enable details only with an approved logger, redaction, transport, access, and retention policy. Logger throws and rejected promises or thenables remain isolated from cache and shadow correctness. +Detailed 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 value previews only after terminal mismatch confirmation and never passes the raw compared-value references to the logger. Value previews cover primitives, indexed array elements, and own enumerable string-keyed fields on plain records. Non-enumerable and symbol properties, plus extra named properties on arrays, are outside that JSON-like preview domain. Accessors, proxies, cycles, functions, class instances, and other unsupported or limited structures are represented by opaque markers and set `detailsTruncated`; the renderer does not invoke property getters, `toJSON`, custom inspection hooks, user iterators, or constructors. + +Enable details only with an approved logger, redaction, transport, access, and retention policy. The limits bound rendered fields, recursion, and preview bytes, but JavaScript property enumeration may still inspect more keys than DialCache renders for a pathological plain record. The byte caps apply to the three detail fields 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. 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. diff --git a/src/config.ts b/src/config.ts index 1bd93f5..ce11eb3 100644 --- a/src/config.ts +++ b/src/config.ts @@ -18,7 +18,8 @@ export interface ShadowConfig { /** Emit one warning for each confirmed mismatch. Defaults to false. */ readonly logMismatches?: boolean; /** - * Enrich that warning with the logical cache key and compared values. + * Enrich that warning with bounded previews of the logical cache key and + * compared values. * Defaults to false and has no effect unless `logMismatches` is true. */ readonly logMismatchDetails?: boolean; diff --git a/src/dialcache.ts b/src/dialcache.ts index d17f1c2..48f03c7 100644 --- a/src/dialcache.ts +++ b/src/dialcache.ts @@ -41,6 +41,7 @@ import { type LayerConfigResolution, type ResolvedLayerConfig, } from "./internal/runtime-config.js"; +import { shadowMismatchLogDetails } from "./internal/shadow-log-preview.js"; type CacheKeyArgs = Record; type Id = string | number | bigint; @@ -1152,9 +1153,11 @@ export class DialCache { logging.logMismatchDetails && mismatchDetails !== undefined ? { ...warning, - cacheKey: key.urn, - cachedValue: mismatchDetails.cachedValue, - sourceValue: mismatchDetails.sourceValue, + ...shadowMismatchLogDetails( + key.urn, + mismatchDetails.cachedValue, + mismatchDetails.sourceValue, + ), } : warning, ); diff --git a/src/internal/shadow-log-preview.ts b/src/internal/shadow-log-preview.ts new file mode 100644 index 0000000..2a058cf --- /dev/null +++ b/src/internal/shadow-log-preview.ts @@ -0,0 +1,376 @@ +import { types as utilTypes } from "node:util"; + +export const SHADOW_LOG_KEY_MAX_BYTES = 2 * 1024; +export const SHADOW_LOG_VALUE_MAX_BYTES = 8 * 1024; +export const SHADOW_LOG_TRUNCATION_MARKER = "...[truncated]"; + +const MAX_DEPTH = 4; +const MAX_CONTAINER_ENTRIES = 32; +const MAX_VISITED_NODES = 128; +const MAX_OBJECT_SCAN = MAX_CONTAINER_ENTRIES * 2; +const MAX_RENDERED_BIGINT_MAGNITUDE = 10n ** 100n; + +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 BoundedLogPreview { + readonly text: string; + readonly truncated: boolean; +} + +export interface ShadowMismatchLogDetails { + readonly cacheKey: string; + readonly cachedValuePreview: string; + readonly sourceValuePreview: string; + readonly detailsTruncated: boolean; +} + +interface PreviewState { + readonly writer: Utf8PreviewWriter; + readonly ancestors: WeakSet; + visitedNodes: number; +} + +class Utf8PreviewWriter { + private readonly bytes: Uint8Array; + private offset = 0; + private truncated = false; + + constructor(private readonly maxBytes: number) { + this.bytes = new Uint8Array(maxBytes); + } + + get isFull(): boolean { + return this.offset >= this.contentLimit; + } + + write(value: string): boolean { + if (value.length === 0) { + return true; + } + + const destination = this.bytes.subarray(this.offset, this.contentLimit); + const { read, written } = UTF8_ENCODER.encodeInto(value, destination); + this.offset += written; + if (read === value.length) { + return true; + } + + this.markTruncated(); + return false; + } + + markTruncated(): void { + if (this.truncated) { + return; + } + + this.truncated = true; + if (this.offset > this.contentLimit) { + this.offset = completeUtf8PrefixLength(this.bytes, this.contentLimit); + } + } + + finish(): BoundedLogPreview { + if (this.truncated) { + this.bytes.set(TRUNCATION_MARKER_BYTES, this.offset); + this.offset += TRUNCATION_MARKER_BYTES.byteLength; + } + return { + text: UTF8_DECODER.decode(this.bytes.subarray(0, this.offset)), + truncated: this.truncated, + }; + } + + private get contentLimit(): number { + return this.truncated + ? this.maxBytes - TRUNCATION_MARKER_BYTES.byteLength + : this.maxBytes; + } +} + +export function previewShadowLogKey(value: string): BoundedLogPreview { + const writer = new Utf8PreviewWriter(SHADOW_LOG_KEY_MAX_BYTES); + writer.write(value); + return writer.finish(); +} + +export function previewShadowLogValue(value: unknown): BoundedLogPreview { + const state: PreviewState = { + writer: new Utf8PreviewWriter(SHADOW_LOG_VALUE_MAX_BYTES), + ancestors: new WeakSet(), + visitedNodes: 0, + }; + + try { + renderValue(state, value, 0); + return state.writer.finish(); + } catch { + return unavailablePreview(); + } +} + +export function shadowMismatchLogDetails( + cacheKey: string, + cachedValue: unknown, + sourceValue: unknown, +): ShadowMismatchLogDetails { + const keyPreview = previewShadowLogKey(cacheKey); + const cachedPreview = previewShadowLogValue(cachedValue); + const sourcePreview = previewShadowLogValue(sourceValue); + return { + cacheKey: keyPreview.text, + cachedValuePreview: cachedPreview.text, + sourceValuePreview: sourcePreview.text, + detailsTruncated: keyPreview.truncated || cachedPreview.truncated || sourcePreview.truncated, + }; +} + +function renderValue(state: PreviewState, value: unknown, depth: number): void { + if (state.writer.isFull) { + state.writer.markTruncated(); + return; + } + if (state.visitedNodes >= MAX_VISITED_NODES) { + writeTruncatedMarker(state, "[NodeLimit]"); + return; + } + state.visitedNodes += 1; + + try { + if (value === null) { + state.writer.write("null"); + return; + } + + switch (typeof value) { + case "undefined": + state.writer.write("undefined"); + return; + case "string": + writeQuotedString(state.writer, value); + return; + case "boolean": + state.writer.write(value ? "true" : "false"); + return; + case "number": + writeNumber(state.writer, value); + return; + case "bigint": + writeBigInt(state.writer, value); + return; + case "symbol": + writeTruncatedMarker(state, "[Symbol]"); + return; + case "function": + writeTruncatedMarker(state, utilTypes.isProxy(value) ? "[Proxy]" : "[Function]"); + return; + case "object": + renderObject(state, value, depth); + return; + } + } catch { + writeTruncatedMarker(state, "[unavailable]"); + } +} + +function renderObject(state: PreviewState, value: object, depth: number): void { + if (utilTypes.isProxy(value)) { + writeTruncatedMarker(state, "[Proxy]"); + return; + } + if (state.ancestors.has(value)) { + writeTruncatedMarker(state, "[Circular]"); + return; + } + if (depth >= MAX_DEPTH) { + writeTruncatedMarker(state, "[MaxDepth]"); + return; + } + + state.ancestors.add(value); + try { + if (Array.isArray(value)) { + renderArray(state, value, depth); + } else if (isPlainRecord(value)) { + renderRecord(state, value, depth); + } else { + writeTruncatedMarker(state, "[Object]"); + } + } finally { + state.ancestors.delete(value); + } +} + +function renderArray(state: PreviewState, value: readonly unknown[], depth: number): void { + state.writer.write(`Array(${value.length}) [`); + const entryCount = Math.min(value.length, MAX_CONTAINER_ENTRIES); + for (let index = 0; index < entryCount && !state.writer.isFull; index += 1) { + if (index > 0) { + state.writer.write(", "); + } + const descriptor = Object.getOwnPropertyDescriptor(value, String(index)); + if (descriptor === undefined) { + state.writer.write(""); + } else if ("value" in descriptor) { + renderValue(state, descriptor.value, depth + 1); + } else { + writeTruncatedMarker(state, "[Accessor]"); + } + } + if (value.length > entryCount) { + state.writer.markTruncated(); + } + state.writer.write("]"); +} + +function renderRecord(state: PreviewState, value: Record, depth: number): void { + state.writer.write("{"); + let emittedEntries = 0; + let scannedEntries = 0; + for (const property in value) { + scannedEntries += 1; + if (scannedEntries > MAX_OBJECT_SCAN || emittedEntries >= MAX_CONTAINER_ENTRIES) { + state.writer.markTruncated(); + break; + } + if (!Object.hasOwn(value, property)) { + continue; + } + if (emittedEntries > 0) { + state.writer.write(", "); + } + writeQuotedString(state.writer, property); + state.writer.write(": "); + const descriptor = Object.getOwnPropertyDescriptor(value, property); + if (descriptor === undefined) { + writeTruncatedMarker(state, "[unavailable]"); + } else if ("value" in descriptor) { + renderValue(state, descriptor.value, depth + 1); + } else { + writeTruncatedMarker(state, "[Accessor]"); + } + emittedEntries += 1; + if (state.writer.isFull) { + break; + } + } + state.writer.write("}"); +} + +function writeNumber(writer: Utf8PreviewWriter, value: number): void { + if (Number.isNaN(value)) { + writer.write("NaN"); + } else if (value === Number.POSITIVE_INFINITY) { + writer.write("Infinity"); + } else if (value === Number.NEGATIVE_INFINITY) { + writer.write("-Infinity"); + } else if (Object.is(value, -0)) { + writer.write("-0"); + } else { + writer.write(String(value)); + } +} + +function writeBigInt(writer: Utf8PreviewWriter, value: bigint): void { + if (value <= -MAX_RENDERED_BIGINT_MAGNITUDE || value >= MAX_RENDERED_BIGINT_MAGNITUDE) { + writer.write("[BigInt]"); + writer.markTruncated(); + return; + } + writer.write(`${value}n`); +} + +function writeQuotedString(writer: Utf8PreviewWriter, value: string): void { + if (!writer.write('"')) { + return; + } + for (let index = 0; index < value.length && !writer.isFull;) { + const codePoint = value.codePointAt(index)!; + const character = String.fromCodePoint(codePoint); + if (!writer.write(escapeCharacter(codePoint, character))) { + return; + } + index += character.length; + } + writer.write('"'); +} + +function escapeCharacter(codePoint: number, character: string): string { + switch (character) { + case '"': + return '\\"'; + case "\\": + return "\\\\"; + case "\b": + return "\\b"; + case "\f": + return "\\f"; + case "\n": + return "\\n"; + case "\r": + return "\\r"; + case "\t": + return "\\t"; + } + if ( + codePoint < 0x20 + || (codePoint >= 0xd800 && codePoint <= 0xdfff) + || codePoint === 0x2028 + || codePoint === 0x2029 + ) { + return `\\u${codePoint.toString(16).padStart(4, "0")}`; + } + return character; +} + +function writeTruncatedMarker(state: PreviewState, marker: string): void { + state.writer.write(marker); + state.writer.markTruncated(); +} + +function isPlainRecord(value: object): value is Record { + const prototype = Object.getPrototypeOf(value); + return prototype === null || prototype === Object.prototype; +} + +function unavailablePreview(): BoundedLogPreview { + const writer = new Utf8PreviewWriter(SHADOW_LOG_VALUE_MAX_BYTES); + writer.write("[unavailable]"); + writer.markTruncated(); + return writer.finish(); +} + +function completeUtf8PrefixLength(bytes: Uint8Array, proposedLength: number): number { + if (proposedLength === 0) { + return 0; + } + let sequenceStart = proposedLength; + while (sequenceStart > 0 && isUtf8ContinuationByte(bytes[sequenceStart]!)) { + sequenceStart -= 1; + } + if (sequenceStart === proposedLength) { + return proposedLength; + } + return sequenceStart + utf8SequenceLength(bytes[sequenceStart]!) <= proposedLength + ? proposedLength + : sequenceStart; +} + +function isUtf8ContinuationByte(value: number): boolean { + return (value & 0xc0) === 0x80; +} + +function utf8SequenceLength(firstByte: number): number { + if ((firstByte & 0x80) === 0) { + return 1; + } + if ((firstByte & 0xe0) === 0xc0) { + return 2; + } + if ((firstByte & 0xf0) === 0xe0) { + return 3; + } + return 4; +} diff --git a/test/dialcache-shadow-confirmation.test.ts b/test/dialcache-shadow-confirmation.test.ts index 03cbef2..60e05eb 100644 --- a/test/dialcache-shadow-confirmation.test.ts +++ b/test/dialcache-shadow-confirmation.test.ts @@ -29,6 +29,11 @@ import { deterministicRampSample, deterministicShadowRampSample, } from "../src/internal/ramp.js"; +import { + SHADOW_LOG_KEY_MAX_BYTES, + SHADOW_LOG_TRUNCATION_MARKER, + SHADOW_LOG_VALUE_MAX_BYTES, +} from "../src/internal/shadow-log-preview.js"; import { REMOTE_SHADOW_CACHE_LAYER } from "../src/metrics.js"; interface Deferred { @@ -390,13 +395,62 @@ describe("DialCache Redis shadow confirmation", () => { keyType: "user_id", outcome: "mismatch", cacheKey: "{urn:user_id:123}?locale=en-US#ShadowMismatchDetails", - cachedValue, - sourceValue, + cachedValuePreview: '{"id": "123", "version": 1}', + sourceValuePreview: '{"id": "123", "version": 2}', + detailsTruncated: false, }, ); expect(serializer.dump).not.toHaveBeenCalled(); }); + it("clamps the logical key and both value previews before handing details to the logger", async () => { + const id = "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 100); + const cachedValue = { id, content: "🙂".repeat(SHADOW_LOG_VALUE_MAX_BYTES) }; + const sourceValue = { id, content: "s".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 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, { + logger: { + debug: () => undefined, + error: () => undefined, + warn, + }, + }); + const getUser = dialcache.cached(async () => sourceValue, { + ...trackedOptions( + "ShadowMismatchClampedDetails", + remoteConfig(100, 100, { + logMismatches: true, + logMismatchDetails: true, + }), + ), + cacheKey: () => id, + }); + + await dialcache.enable(async () => await getUser()); + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + expect(warn).toHaveBeenCalledTimes(1); + const warning = warn.mock.calls[0]?.[1] as Record; + expect(warning).not.toHaveProperty("cachedValue"); + expect(warning).not.toHaveProperty("sourceValue"); + expect(warning.detailsTruncated).toBe(true); + for (const [field, maxBytes] of [ + ["cacheKey", SHADOW_LOG_KEY_MAX_BYTES], + ["cachedValuePreview", SHADOW_LOG_VALUE_MAX_BYTES], + ["sourceValuePreview", SHADOW_LOG_VALUE_MAX_BYTES], + ] as const) { + const preview = warning[field]; + expect(typeof preview).toBe("string"); + expect(Buffer.byteLength(preview as string)).toBeLessThanOrEqual(maxBytes); + expect((preview as string).endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(preview).not.toContain("\uFFFD"); + } + }); + it.each([ { name: "missing", confirmation: null }, { diff --git a/test/shadow-log-preview.test.ts b/test/shadow-log-preview.test.ts new file mode 100644 index 0000000..84998f3 --- /dev/null +++ b/test/shadow-log-preview.test.ts @@ -0,0 +1,223 @@ +import { inspect } from "node:util"; + +import { describe, expect, it, vi } from "vitest"; + +import { + SHADOW_LOG_KEY_MAX_BYTES, + SHADOW_LOG_TRUNCATION_MARKER, + SHADOW_LOG_VALUE_MAX_BYTES, + previewShadowLogKey, + previewShadowLogValue, + shadowMismatchLogDetails, +} from "../src/internal/shadow-log-preview.js"; + +describe("shadow mismatch log previews", () => { + it("keeps exact-limit strings and byte-clamps oversized ASCII and Unicode strings", () => { + const exact = "a".repeat(SHADOW_LOG_KEY_MAX_BYTES); + const exactKeyPreview = previewShadowLogKey(exact); + expect(exactKeyPreview).toEqual({ + text: exact, + truncated: false, + }); + expect(Buffer.byteLength(exactKeyPreview.text)).toBe(SHADOW_LOG_KEY_MAX_BYTES); + + const exactValue = "v".repeat(SHADOW_LOG_VALUE_MAX_BYTES - 2); + const exactValuePreview = previewShadowLogValue(exactValue); + expect(exactValuePreview).toEqual({ + text: `"${exactValue}"`, + truncated: false, + }); + expect(Buffer.byteLength(exactValuePreview.text)).toBe(SHADOW_LOG_VALUE_MAX_BYTES); + + for (const oversized of [ + "a".repeat(SHADOW_LOG_KEY_MAX_BYTES + 1), + `${"a".repeat(SHADOW_LOG_KEY_MAX_BYTES - 1)}🙂`, + ]) { + const preview = previewShadowLogKey(oversized); + + expect(preview.truncated).toBe(true); + expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); + expect(preview.text).not.toContain("\uFFFD"); + } + }); + + it("renders supported primitives and escaped strings without truncation", () => { + expect(previewShadowLogValue({ + undefined, + null: null, + text: "\"line\n\u2028", + values: [true, false, 1, -0, Number.NaN, Number.POSITIVE_INFINITY, Number.NEGATIVE_INFINITY, 12n], + })).toEqual({ + text: '{"undefined": undefined, "null": null, "text": "\\"line\\n\\u2028", ' + + '"values": Array(8) [true, false, 1, -0, NaN, Infinity, -Infinity, 12n]}', + truncated: false, + }); + }); + + it("bounds large values and aggregates field truncation", () => { + const details = shadowMismatchLogDetails( + "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 1), + "c".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), + "s".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), + ); + + expect(details.detailsTruncated).toBe(true); + expect(Buffer.byteLength(details.cacheKey)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); + expect(Buffer.byteLength(details.cachedValuePreview)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); + expect(Buffer.byteLength(details.sourceValuePreview)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); + expect(details.cacheKey.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(details.cachedValuePreview.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(details.sourceValuePreview.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + }); + + it("limits depth, entry count, node count, large BigInts, and opaque values", () => { + const deep = { one: { two: { three: { four: { five: "hidden" } } } } }; + const wide = Object.fromEntries(Array.from({ length: 40 }, (_, index) => [`key${index}`, index])); + const manyNodes = Array.from({ length: 32 }, () => [1, 2, 3, 4, 5]); + + for (const value of [ + deep, + wide, + manyNodes, + 10n ** 100n, + Symbol("symbol"), + () => undefined, + Promise.resolve(), + new WeakMap(), + new WeakSet(), + ]) { + const preview = previewShadowLogValue(value); + + expect(preview.truncated).toBe(true); + expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); + } + }); + + it("renders exotic and class instances opaquely", () => { + class Example { + readonly visible = true; + } + const values = [ + Buffer.from([0, 1, 255]), + new Uint16Array([1, 2]), + new DataView(Uint8Array.from([3, 4]).buffer), + Uint8Array.from([5, 6]).buffer, + new Map([["key", { value: 1 }]]), + new Set(["value"]), + new Date("2026-07-30T00:00:00.000Z"), + /cache/giu, + new Error("nope"), + new Example(), + ]; + + const previews = values.map((value) => previewShadowLogValue(value)); + + expect(previews).toEqual(values.map(() => ({ + text: `[Object]${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }))); + }); + + it("bounds arrays by their indexed entry limit", () => { + const sparse = Array.from({ length: 40 }, (_, index) => index); + delete sparse[1]; + Object.defineProperty(sparse, "2", { get: () => 2, enumerable: true }); + + const preview = previewShadowLogValue(sparse); + + expect(preview.truncated).toBe(true); + expect(preview.text).toContain(""); + expect(preview.text).toContain("[Accessor]"); + expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + }); + + it("does not invoke accessors, serializers, custom inspectors, or proxy traps", () => { + const getter = vi.fn(() => { + throw new Error("getter invoked"); + }); + const toJSON = vi.fn(() => { + throw new Error("toJSON invoked"); + }); + const customInspect = vi.fn(() => { + throw new Error("custom inspect invoked"); + }); + const value: Record = { toJSON }; + Object.defineProperty(value, "secret", { enumerable: true, get: getter }); + Object.defineProperty(value, Symbol.toStringTag, { get: getter }); + value[inspect.custom] = customInspect; + value.self = value; + + const ownKeys = vi.fn(() => { + throw new Error("proxy reflected"); + }); + const proxy = new Proxy({}, { ownKeys }); + const revocable = Proxy.revocable({}, {}); + revocable.revoke(); + const regexp = /safe/g; + Object.defineProperty(regexp, "global", { get: getter }); + const typedArray = new Uint8Array([1, 2]); + Object.defineProperties(typedArray, { + buffer: { get: getter }, + byteOffset: { get: getter }, + byteLength: { get: getter }, + }); + + const recordPreview = previewShadowLogValue(value); + const proxyPreview = previewShadowLogValue(proxy); + const revokedPreview = previewShadowLogValue(revocable.proxy); + const regexpPreview = previewShadowLogValue(regexp); + const typedArrayPreview = previewShadowLogValue(typedArray); + + expect(recordPreview.truncated).toBe(true); + expect(recordPreview.text).toContain("[Accessor]"); + expect(recordPreview.text).toContain("[Circular]"); + expect(getter).not.toHaveBeenCalled(); + expect(toJSON).not.toHaveBeenCalled(); + expect(customInspect).not.toHaveBeenCalled(); + expect(regexpPreview).toEqual({ + text: `[Object]${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }); + expect(typedArrayPreview).toEqual({ + text: `[Object]${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }); + expect(proxyPreview.text).toBe(`[Proxy]${SHADOW_LOG_TRUNCATION_MARKER}`); + expect(revokedPreview.text).toBe(`[Proxy]${SHADOW_LOG_TRUNCATION_MARKER}`); + expect(ownKeys).not.toHaveBeenCalled(); + }); + + it("limits its JSON-like domain to array indexes and enumerable string-keyed record fields", () => { + const hidden = Symbol("hidden"); + const record: Record = { visible: 1 }; + Object.defineProperty(record, "nonEnumerable", { value: 2 }); + record[hidden] = 3; + const array = [1] as unknown[] & Record; + array.extra = 2; + array[hidden] = 3; + + expect(previewShadowLogValue(record)).toEqual({ + text: '{"visible": 1}', + truncated: false, + }); + expect(previewShadowLogValue(array)).toEqual({ + text: "Array(1) [1]", + truncated: false, + }); + }); + + it("marks detailed output complete only when every field is complete", () => { + expect(shadowMismatchLogDetails( + "{urn:user_id:123}#Example", + { id: "123", version: 1 }, + { id: "123", version: 2 }, + )).toEqual({ + cacheKey: "{urn:user_id:123}#Example", + cachedValuePreview: '{"id": "123", "version": 1}', + sourceValuePreview: '{"id": "123", "version": 2}', + detailsTruncated: false, + }); + }); +}); From dee7829d81528f54574ec7799527236136427e4d Mon Sep 17 00:00:00 2001 From: Lev Neiman Date: Thu, 30 Jul 2026 20:25:59 -0700 Subject: [PATCH 3/6] fix: tighten shadow mismatch previews --- src/internal/shadow-log-preview.ts | 13 +++--- test/dialcache-config-ramp.test.ts | 12 +++++ test/shadow-log-preview.test.ts | 71 ++++++++++++++++++++++++++++++ 3 files changed, 89 insertions(+), 7 deletions(-) diff --git a/src/internal/shadow-log-preview.ts b/src/internal/shadow-log-preview.ts index 2a058cf..3ace8ab 100644 --- a/src/internal/shadow-log-preview.ts +++ b/src/internal/shadow-log-preview.ts @@ -7,7 +7,6 @@ export const SHADOW_LOG_TRUNCATION_MARKER = "...[truncated]"; const MAX_DEPTH = 4; const MAX_CONTAINER_ENTRIES = 32; const MAX_VISITED_NODES = 128; -const MAX_OBJECT_SCAN = MAX_CONTAINER_ENTRIES * 2; const MAX_RENDERED_BIGINT_MAGNITUDE = 10n ** 100n; const UTF8_ENCODER = new TextEncoder(); @@ -228,15 +227,15 @@ function renderArray(state: PreviewState, value: readonly unknown[], depth: numb function renderRecord(state: PreviewState, value: Record, depth: number): void { state.writer.write("{"); let emittedEntries = 0; - let scannedEntries = 0; for (const property in value) { - scannedEntries += 1; - if (scannedEntries > MAX_OBJECT_SCAN || emittedEntries >= MAX_CONTAINER_ENTRIES) { - state.writer.markTruncated(); + // Ordinary-object enumeration yields own fields before inherited fields. + // Inherited fields are outside the documented preview domain. + if (!Object.hasOwn(value, property)) { break; } - if (!Object.hasOwn(value, property)) { - continue; + if (emittedEntries >= MAX_CONTAINER_ENTRIES) { + state.writer.markTruncated(); + break; } if (emittedEntries > 0) { state.writer.write(", "); diff --git a/test/dialcache-config-ramp.test.ts b/test/dialcache-config-ramp.test.ts index 1de6955..90bad64 100644 --- a/test/dialcache-config-ramp.test.ts +++ b/test/dialcache-config-ramp.test.ts @@ -325,6 +325,11 @@ describe("DialCache runtime config and ramp controls", () => { () => new DialCacheKeyConfig({ shadow: null as never }), "DialCache shadow config must be an object", ], + [ + "an array shadow config", + () => new DialCacheKeyConfig({ shadow: [] as never }), + "DialCache shadow config must be an object", + ], [ "the removed shadowRamp field", () => new DialCacheKeyConfig({ shadowRamp: 100 } as never), @@ -410,6 +415,12 @@ describe("DialCache runtime config and ramp controls", () => { TypeError, "must be a layer map", ], + [ + "array shadow config", + { ttlSec: {}, ramp: {}, shadow: [] } as unknown as DialCacheKeyConfig, + TypeError, + "shadow must be an object", + ], [ "removed shadowRamp", { ttlSec: {}, ramp: {}, shadowRamp: 100 } as unknown as DialCacheKeyConfig, @@ -446,6 +457,7 @@ describe("DialCache runtime config and ramp controls", () => { ["a primitive", 42], ["an array", []], ["a null layer map", { ttlSec: null, ramp: {} }], + ["an array shadow config", { ttlSec: {}, ramp: {}, shadow: [] }], ["a null requestLocal value", { ttlSec: {}, ramp: {}, requestLocal: null }], ["the removed shadowRamp field", { ttlSec: {}, ramp: {}, shadowRamp: 100 }], ] as const)("fails open instead of inheriting defaults when the provider returns %s", async (_name, runtimeConfig) => { diff --git a/test/shadow-log-preview.test.ts b/test/shadow-log-preview.test.ts index 84998f3..0a4172b 100644 --- a/test/shadow-log-preview.test.ts +++ b/test/shadow-log-preview.test.ts @@ -71,6 +71,52 @@ describe("shadow mismatch log previews", () => { expect(details.sourceValuePreview.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); }); + it("aggregates byte and structural truncation from each detail field independently", () => { + const cases = [ + { + name: "cache key", + details: shadowMismatchLogDetails( + "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 1), + "cached", + "source", + ), + truncatedField: "cacheKey", + }, + { + name: "cached value", + details: shadowMismatchLogDetails( + "key", + "c".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), + "source", + ), + truncatedField: "cachedValuePreview", + }, + { + name: "source value", + details: shadowMismatchLogDetails( + "key", + "cached", + "s".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), + ), + truncatedField: "sourceValuePreview", + }, + { + name: "structurally unsupported cached value", + details: shadowMismatchLogDetails("key", new Map(), "source"), + truncatedField: "cachedValuePreview", + }, + ] as const; + + for (const { name, details, truncatedField } of cases) { + expect(details.detailsTruncated, name).toBe(true); + expect( + (["cacheKey", "cachedValuePreview", "sourceValuePreview"] as const) + .filter((field) => details[field].endsWith(SHADOW_LOG_TRUNCATION_MARKER)), + name, + ).toEqual([truncatedField]); + } + }); + it("limits depth, entry count, node count, large BigInts, and opaque values", () => { const deep = { one: { two: { three: { four: { five: "hidden" } } } } }; const wide = Object.fromEntries(Array.from({ length: 40 }, (_, index) => [`key${index}`, index])); @@ -208,6 +254,31 @@ describe("shadow mismatch log previews", () => { }); }); + it("ignores inherited enumerable fields without reporting truncation", () => { + const inheritedFields = Array.from({ length: 65 }, (_, index) => `__dialcache_preview_${index}`); + const preview = (() => { + try { + for (const [index, field] of inheritedFields.entries()) { + Object.defineProperty(Object.prototype, field, { + value: index, + enumerable: true, + configurable: true, + }); + } + return previewShadowLogValue({ visible: 1 }); + } finally { + for (const field of inheritedFields) { + delete (Object.prototype as Record)[field]; + } + } + })(); + + expect(preview).toEqual({ + text: '{"visible": 1}', + truncated: false, + }); + }); + it("marks detailed output complete only when every field is complete", () => { expect(shadowMismatchLogDetails( "{urn:user_id:123}#Example", From 393db5ce9fb0c6dfd7b9672283686f93ada6543b Mon Sep 17 00:00:00 2001 From: Lev Neiman Date: Thu, 30 Jul 2026 21:50:04 -0700 Subject: [PATCH 4/6] fix: harden shadow mismatch logging --- README.md | 12 +- src/dialcache.ts | 48 ++-- src/internal/runtime-config.ts | 22 +- src/internal/shadow-log-preview.ts | 159 ++++++++--- test/dialcache-config-ramp.test.ts | 1 - test/dialcache-metrics.test.ts | 48 ++++ .../dialcache-observability-internals.test.ts | 49 ++++ test/dialcache-shadow-confirmation.test.ts | 72 ++++- test/dialcache-shadow-validation.test.ts | 26 +- test/shadow-log-preview.test.ts | 257 +++++++++++++++++- 10 files changed, 607 insertions(+), 87 deletions(-) diff --git a/README.md b/README.md index b5a7179..fd4af4e 100644 --- a/README.md +++ b/README.md @@ -221,9 +221,9 @@ DialCache validates `defaultConfig` when `cached()` registers a definition and w 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, or explicit `remoteReadTimeoutMs` fails config resolution for the invocation, records `config_error`, and executes the fallback uncached without attempting Redis. +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, or explicit `remoteReadTimeoutMs` fails config resolution for the invocation, records `config_error`, and executes the fallback uncached without attempting Redis. The removed top-level `shadowRamp` field is the one compatibility exception for raw provider results: DialCache ignores that leaf, applies every other valid overlay field, and records one remote `config_resolution` error for that resolution. The public `DialCacheKeyConfig` constructor and static defaults still reject `shadowRamp` immediately; migrate it to `shadow.ramp`. -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. After tracked traversal reaches a valid nonzero shadow ramp, invalid runtime shadow logging leaves likewise preserve the cache result, Redis policy, shadow result, and shadow metric: an invalid `logMismatches` disables the warning, while an invalid `logMismatchDetails` downgrades it to the metadata-only warning. Both cases record `config_resolution`, even when the metrics hook is absent or the exact key is outside the shadow cohort. +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. Invalid runtime shadow logging leaves likewise preserve the cache result, Redis policy, shadow result, and shadow metric: an invalid `logMismatches` disables the warning, while an invalid `logMismatchDetails` downgrades it to the metadata-only warning. DialCache validates these diagnostic leaves only after the metrics hook, exact-key cohort, and capacity gates admit shadow work, and collapses multiple invalid logging leaves into one remote `config_resolution` error per admitted resolution. `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. @@ -544,11 +544,11 @@ 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`. 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. -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`. With details disabled, the single warning contains only `cacheNamespace`, `useCase`, `keyType`, and `outcome: "mismatch"`. Setting `shadow.logMismatchDetails: true` enriches that same warning with `cacheKey`, `cachedValuePreview`, `sourceValuePreview`, and `detailsTruncated`, but is inert unless `logMismatches` is also true. `cacheKey` is a UTF-8 preview of the logical DialCache URN capped at 2 KiB, not the physical Redis storage key. The two value previews are capped at 8 KiB each and represent the deserialized cached snapshot and raw source value supplied to the comparator. Every clipped field ends in `...[truncated]`, counted inside its cap; `detailsTruncated` is true when any field is byte-clipped or structurally shortened. DialCache does not compute or serialize a textual diff and does not call the configured serializer again for logging. +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`. With details disabled, the single warning contains only `cacheNamespace`, `useCase`, `keyType`, and `outcome: "mismatch"`. Setting `shadow.logMismatchDetails: true` enriches that same warning with `cacheKey`, `cachedValuePreview`, `sourceValuePreview`, and `detailsTruncated`, but is inert unless `logMismatches` is also true. `cacheKey` is a UTF-8 preview of the logical DialCache URN capped at 2 KiB, not the physical Redis storage key. The two value previews are capped at 8 KiB each and represent the deserialized cached snapshot and raw source value supplied to the comparator. Every byte-clipped or structurally shortened field ends in `...[truncated]`, counted inside its cap; `detailsTruncated` is true when any field is byte-clipped or structurally shortened. DialCache does not compute or serialize a textual diff and does not call the configured serializer again for logging. -Detailed 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 value previews only after terminal mismatch confirmation and never passes the raw compared-value references to the logger. Value previews cover primitives, indexed array elements, and own enumerable string-keyed fields on plain records. Non-enumerable and symbol properties, plus extra named properties on arrays, are outside that JSON-like preview domain. Accessors, proxies, cycles, functions, class instances, and other unsupported or limited structures are represented by opaque markers and set `detailsTruncated`; the renderer does not invoke property getters, `toJSON`, custom inspection hooks, user iterators, or constructors. +Detailed 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 value previews only after terminal mismatch confirmation and never passes the raw compared-value references to the logger. Value previews cover primitives, dates, collection sizes, up to 64 raw bytes from Buffers and typed arrays, indexed array elements, and own enumerable string-keyed fields on plain records. A string or property name longer than 65,536 UTF-16 code units is not content-inspected and renders as a length-only marker; the same guard applies to the logical key preview. Nonempty Map and Set contents are omitted and therefore structurally shortened. Non-enumerable and symbol properties, plus extra named properties on arrays, are outside that JSON-like preview domain. Accessors, proxies, cycles, functions, class instances, and other unsupported or limited structures are represented by opaque markers and set `detailsTruncated`; the renderer uses captured built-in intrinsics and does not invoke property getters, `toJSON`, custom inspection hooks, user iterators, or constructors. -Enable details only with an approved logger, redaction, transport, access, and retention policy. The limits bound rendered fields, recursion, and preview bytes, but JavaScript property enumeration may still inspect more keys than DialCache renders for a pathological plain record. The byte caps apply to the three detail fields 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. Logger throws and rejected promises or thenables remain isolated from cache and shadow correctness. +Enable details only with an approved logger, redaction, transport, access, and retention policy. The limits bound rendered fields, recursion, preview bytes, and individual string inspection; the string guard avoids flattening an arbitrarily large rope solely to render a bounded prefix. Detailed preview construction is synchronous. For a pathological plain record with a very large enumerable-key set, the JavaScript runtime may still enumerate and cache the full key set before DialCache reaches its 32-field limit; this can block the shared Node.js event loop and cause a tail-latency spike even though the emitted preview remains byte-clamped. Keep detailed logging disabled for untrusted or unbounded record shapes. The byte caps apply to the three detail fields 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-preview failure degrades to the metadata-only warning. 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. @@ -558,7 +558,7 @@ The initial `C0` read and later fill are not atomic. The fill is a normal tracke A served-hit sample invokes the wrapped function or inline loader as an additional source read, so that loader must be safe to call for observation. A ramped-down sample reuses the caller's ordinary invocation and does not add another SoT call. -For valid policies, shadow-specific source calls, cache-path Redis traffic, returned values, and metrics are unchanged when `shadow` is omitted or `shadow.ramp` is `0`. Shadow policy is grouped under `DialCacheKeyConfig.shadow`; consumers of the former flat ramp field must migrate to `shadow: { ramp }`, and the removed field is rejected rather than silently ignored. `DialCacheKeyConfig.disabled()` explicitly sets the shadow ramp and both logging gates to their disabled values. `shadowComparator` remains a typed `cached()` / `getOrLoad()` option because it defines stable use-case equality, while `shadowMaxInFlight` remains a per-instance concurrency limit. The clean-miss bootstrap adds no additional ramp knob, Redis protocol operation, metric instrument, or label key; enabling shadowing authorizes the tracked Redis write described above. Exported unions include `remote_shadow` in `MetricLayer` and `superseded`, `filled`, `fill_blocked`, `fill_error`, `redis_error`, and `confirmation_error` in `ShadowValidationOutcome`. TypeScript consumers with exhaustive switches or `Record` values must include those cases, and dashboards restricted to `layer="remote"` intentionally exclude detached traffic. +For valid policies, shadow-specific source calls, cache-path Redis traffic, returned values, and metrics are unchanged when `shadow` is omitted or `shadow.ramp` is `0`. Shadow policy is grouped under `DialCacheKeyConfig.shadow`; consumers of the former flat ramp field must migrate to `shadow: { ramp }`. The public constructor and static defaults reject the removed field, while raw runtime provider results ignore and report that legacy leaf as described above. `DialCacheKeyConfig.disabled()` explicitly sets the shadow ramp and both logging gates to their disabled values. `shadowComparator` remains a typed `cached()` / `getOrLoad()` option because it defines stable use-case equality, while `shadowMaxInFlight` remains a per-instance concurrency limit. The clean-miss bootstrap adds no additional ramp knob, Redis protocol operation, metric instrument, or label key; enabling shadowing authorizes the tracked Redis write described above. Exported unions include `remote_shadow` in `MetricLayer` and `superseded`, `filled`, `fill_blocked`, `fill_error`, `redis_error`, and `confirmation_error` in `ShadowValidationOutcome`. TypeScript consumers with exhaustive switches or `Record` values must include those cases, and dashboards restricted to `layer="remote"` intentionally exclude detached traffic. ## Cached-value ownership diff --git a/src/dialcache.ts b/src/dialcache.ts index 48f03c7..1eca534 100644 --- a/src/dialcache.ts +++ b/src/dialcache.ts @@ -444,7 +444,11 @@ export class DialCache { let keyConfig: DialCacheKeyConfig | null; try { - keyConfig = await fetchKeyConfig(this.configProvider, key); + keyConfig = await fetchKeyConfig( + this.configProvider, + key, + () => this.recordError(key, CacheLayer.REMOTE, "config_resolution"), + ); } 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); @@ -830,7 +834,6 @@ export class DialCache { this.recordError(key, CacheLayer.REMOTE, "config_resolution"); return; } - const shadowLogging = this.resolveShadowLogging(key, resolvedShadowConfig); if (this.metrics?.shadowValidation === undefined) { return; } @@ -842,6 +845,7 @@ export class DialCache { this.recordShadowValidation(key, "dropped"); return; } + const shadowLogging = this.resolveShadowLogging(key, resolvedShadowConfig); const flight: ShadowFlight = { cachedPayload: start.kind === "retained" ? start.payload : null, @@ -873,11 +877,12 @@ export class DialCache { const configuredLogMismatchDetails = shadowConfig.logMismatchDetails; let logMismatches = false; + let invalidLogging = false; if (configuredLogMismatches !== undefined) { if (typeof configuredLogMismatches === "boolean") { logMismatches = configuredLogMismatches; } else { - this.recordError(key, CacheLayer.REMOTE, "config_resolution"); + invalidLogging = true; } } @@ -886,9 +891,12 @@ export class DialCache { if (typeof configuredLogMismatchDetails === "boolean") { logMismatchDetails = configuredLogMismatchDetails; } else { - this.recordError(key, CacheLayer.REMOTE, "config_resolution"); + invalidLogging = true; } } + if (invalidLogging) { + this.recordError(key, CacheLayer.REMOTE, "config_resolution"); + } return { logMismatches, @@ -1148,19 +1156,25 @@ export class DialCache { keyType: key.keyType, outcome: "mismatch", } as const; - this.logger.warn( - "DialCache shadow validation mismatch", - logging.logMismatchDetails && mismatchDetails !== undefined - ? { - ...warning, - ...shadowMismatchLogDetails( - key.urn, - mismatchDetails.cachedValue, - mismatchDetails.sourceValue, - ), - } - : warning, - ); + if (logging.logMismatchDetails && mismatchDetails !== undefined) { + try { + this.logger.warn( + "DialCache shadow validation mismatch", + { + ...warning, + ...shadowMismatchLogDetails( + key.urn, + mismatchDetails.cachedValue, + mismatchDetails.sourceValue, + ), + }, + ); + return; + } catch { + // Preview construction is best-effort; preserve the metadata warning. + } + } + this.logger.warn("DialCache shadow validation mismatch", warning); } private async resolveLocalLayerConfig( diff --git a/src/internal/runtime-config.ts b/src/internal/runtime-config.ts index 7e619f6..92ac8e3 100644 --- a/src/internal/runtime-config.ts +++ b/src/internal/runtime-config.ts @@ -37,13 +37,14 @@ interface ResolveLayerConfigOptions { export async function fetchKeyConfig( configProvider: CacheConfigProvider, key: DialCacheKey, + onIgnoredRuntimeShadowRamp?: () => void, ): Promise { const defaultConfig = key.defaultConfig; const runtimeConfig = (await configProvider(key)) as DialCacheKeyConfig | null | undefined; if (runtimeConfig === null || runtimeConfig === undefined) { return defaultConfig; } - return mergeKeyConfig(defaultConfig, runtimeConfig); + return mergeKeyConfig(defaultConfig, runtimeConfig, onIgnoredRuntimeShadowRamp); } export function resolveLayerConfig(options: ResolveLayerConfigOptions): ResolvedLayerConfig | null { @@ -94,10 +95,11 @@ export function resolveLayerConfigResult(options: ResolveLayerConfigOptions): La function mergeKeyConfig( defaultConfig: DialCacheKeyConfig | null, runtimeConfig: DialCacheKeyConfig | null | undefined, + onIgnoredRuntimeShadowRamp?: () => void, ): DialCacheKeyConfig { const overlay = runtimeConfig ?? undefined; assertKeyConfig(defaultConfig); - assertKeyConfig(overlay); + assertKeyConfigShape(overlay); const defaultRequestLocal = defaultConfig?.requestLocal; const overlayRequestLocal = overlay?.requestLocal; const requestLocal = overlayRequestLocal !== undefined @@ -110,24 +112,32 @@ function mergeKeyConfig( : defaultConfig?.remoteReadTimeoutMs; const shadow = mergeShadowConfig(defaultConfig?.shadow, overlay?.shadow); - return new DialCacheKeyConfig({ + const merged = new DialCacheKeyConfig({ ttlSec: mergeLayerConfig(defaultConfig?.ttlSec, overlay?.ttlSec, "ttlSec"), ramp: mergeLayerConfig(defaultConfig?.ramp, overlay?.ramp, "ramp"), requestLocal, ...(remoteReadTimeoutMs === undefined ? {} : { remoteReadTimeoutMs }), ...(shadow === undefined ? {} : { shadow }), }); + if (overlay !== undefined && Object.hasOwn(overlay, "shadowRamp")) { + onIgnoredRuntimeShadowRamp?.(); + } + return merged; } 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"); - } + assertKeyConfigShape(config); if (config !== null && config !== undefined && Object.hasOwn(config, "shadowRamp")) { throw new TypeError('DialCacheKeyConfig.shadowRamp was replaced by "shadow.ramp"'); } } +function assertKeyConfigShape(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"); + } +} + function mergeLayerConfig( defaults: LayerConfig | undefined, overlay: LayerConfig | undefined, diff --git a/src/internal/shadow-log-preview.ts b/src/internal/shadow-log-preview.ts index 3ace8ab..8b846f3 100644 --- a/src/internal/shadow-log-preview.ts +++ b/src/internal/shadow-log-preview.ts @@ -1,3 +1,4 @@ +import { Buffer } from "node:buffer"; import { types as utilTypes } from "node:util"; export const SHADOW_LOG_KEY_MAX_BYTES = 2 * 1024; @@ -7,8 +8,20 @@ export const SHADOW_LOG_TRUNCATION_MARKER = "...[truncated]"; const MAX_DEPTH = 4; const MAX_CONTAINER_ENTRIES = 32; const MAX_VISITED_NODES = 128; +const MAX_BINARY_PREVIEW_BYTES = 64; +const MAX_STRING_INPUT_CODE_UNITS = 64 * 1024; const MAX_RENDERED_BIGINT_MAGNITUDE = 10n ** 100n; +const DATE_VALUE_OF = Date.prototype.valueOf; +const DATE_TO_ISO_STRING = Date.prototype.toISOString; +const MAP_SIZE = Object.getOwnPropertyDescriptor(Map.prototype, "size")!.get!; +const SET_SIZE = Object.getOwnPropertyDescriptor(Set.prototype, "size")!.get!; +const TYPED_ARRAY_PROTOTYPE = Object.getPrototypeOf(Uint8Array.prototype); +const TYPED_ARRAY_BUFFER = Object.getOwnPropertyDescriptor(TYPED_ARRAY_PROTOTYPE, "buffer")!.get!; +const TYPED_ARRAY_BYTE_OFFSET = Object.getOwnPropertyDescriptor(TYPED_ARRAY_PROTOTYPE, "byteOffset")!.get!; +const TYPED_ARRAY_BYTE_LENGTH = Object.getOwnPropertyDescriptor(TYPED_ARRAY_PROTOTYPE, "byteLength")!.get!; +const NATIVE_UINT8_ARRAY = Uint8Array; +const IS_BUFFER = Buffer.isBuffer; 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); @@ -91,7 +104,11 @@ class Utf8PreviewWriter { export function previewShadowLogKey(value: string): BoundedLogPreview { const writer = new Utf8PreviewWriter(SHADOW_LOG_KEY_MAX_BYTES); - writer.write(value); + if (value.length > MAX_STRING_INPUT_CODE_UNITS) { + writeOversizedStringMarker(writer, "String", value.length); + } else { + writer.write(value); + } return writer.finish(); } @@ -102,12 +119,8 @@ export function previewShadowLogValue(value: unknown): BoundedLogPreview { visitedNodes: 0, }; - try { - renderValue(state, value, 0); - return state.writer.finish(); - } catch { - return unavailablePreview(); - } + renderValue(state, value, 0); + return state.writer.finish(); } export function shadowMismatchLogDetails( @@ -148,7 +161,11 @@ function renderValue(state: PreviewState, value: unknown, depth: number): void { state.writer.write("undefined"); return; case "string": - writeQuotedString(state.writer, value); + if (value.length > MAX_STRING_INPUT_CODE_UNITS) { + writeOversizedStringMarker(state.writer, "String", value.length); + } else { + writeQuotedString(state.writer, value); + } return; case "boolean": state.writer.write(value ? "true" : "false"); @@ -192,6 +209,14 @@ function renderObject(state: PreviewState, value: object, depth: number): void { try { if (Array.isArray(value)) { renderArray(state, value, depth); + } else if (utilTypes.isDate(value)) { + renderDate(state, value); + } else if (utilTypes.isMap(value)) { + renderCollectionSize(state, "Map", MAP_SIZE.call(value) as number); + } else if (utilTypes.isSet(value)) { + renderCollectionSize(state, "Set", SET_SIZE.call(value) as number); + } else if (utilTypes.isTypedArray(value)) { + renderTypedArray(state, value); } else if (isPlainRecord(value)) { renderRecord(state, value, depth); } else { @@ -202,6 +227,85 @@ function renderObject(state: PreviewState, value: object, depth: number): void { } } +function renderDate(state: PreviewState, value: Date): void { + const timestamp = DATE_VALUE_OF.call(value); + state.writer.write(Number.isNaN(timestamp) + ? "Date(Invalid)" + : `Date(${DATE_TO_ISO_STRING.call(value)})`); +} + +function renderCollectionSize(state: PreviewState, name: "Map" | "Set", size: number): void { + state.writer.write(`${name}(${size})`); + if (size > 0) { + state.writer.markTruncated(); + } +} + +function renderTypedArray(state: PreviewState, value: NodeJS.TypedArray): void { + const buffer = TYPED_ARRAY_BUFFER.call(value) as ArrayBufferLike; + const byteOffset = TYPED_ARRAY_BYTE_OFFSET.call(value) as number; + const byteLength = TYPED_ARRAY_BYTE_LENGTH.call(value) as number; + const renderedByteLength = Math.min(byteLength, MAX_BINARY_PREVIEW_BYTES); + const bytes = new NATIVE_UINT8_ARRAY(buffer, byteOffset, renderedByteLength); + state.writer.write(`${typedArrayBrand(value)}(${byteLength} bytes) [`); + for (let index = 0; index < renderedByteLength; index += 1) { + if (index > 0) { + state.writer.write(" "); + } + state.writer.write(bytes[index]!.toString(16).padStart(2, "0")); + } + state.writer.write("]"); + if (byteLength > renderedByteLength) { + state.writer.markTruncated(); + } +} + +function typedArrayBrand(value: NodeJS.TypedArray): string { + if (IS_BUFFER(value)) { + return "Buffer"; + } + if (utilTypes.isUint8Array(value)) { + return "Uint8Array"; + } + if (utilTypes.isUint8ClampedArray(value)) { + return "Uint8ClampedArray"; + } + if (utilTypes.isUint16Array(value)) { + return "Uint16Array"; + } + if (utilTypes.isUint32Array(value)) { + return "Uint32Array"; + } + if (utilTypes.isInt8Array(value)) { + return "Int8Array"; + } + if (utilTypes.isInt16Array(value)) { + return "Int16Array"; + } + if (utilTypes.isInt32Array(value)) { + return "Int32Array"; + } + if (utilTypes.isFloat32Array(value)) { + return "Float32Array"; + } + if ( + typeof utilTypes.isFloat16Array === "function" + && utilTypes.isFloat16Array(value) + ) { + return "Float16Array"; + } + if (utilTypes.isFloat64Array(value)) { + return "Float64Array"; + } + if (utilTypes.isBigInt64Array(value)) { + return "BigInt64Array"; + } + if (utilTypes.isBigUint64Array(value)) { + return "BigUint64Array"; + } + return "TypedArray"; +} + function renderArray(state: PreviewState, value: readonly unknown[], depth: number): void { state.writer.write(`Array(${value.length}) [`); const entryCount = Math.min(value.length, MAX_CONTAINER_ENTRIES); @@ -240,7 +344,11 @@ function renderRecord(state: PreviewState, value: Record, depth if (emittedEntries > 0) { state.writer.write(", "); } - writeQuotedString(state.writer, property); + if (property.length > MAX_STRING_INPUT_CODE_UNITS) { + writeOversizedStringMarker(state.writer, "PropertyName", property.length); + } else { + writeQuotedString(state.writer, property); + } state.writer.write(": "); const descriptor = Object.getOwnPropertyDescriptor(value, property); if (descriptor === undefined) { @@ -296,6 +404,15 @@ function writeQuotedString(writer: Utf8PreviewWriter, value: string): void { writer.write('"'); } +function writeOversizedStringMarker( + writer: Utf8PreviewWriter, + kind: "String" | "PropertyName", + codeUnits: number, +): void { + writer.write(`[${kind} length=${codeUnits} code units]`); + writer.markTruncated(); +} + function escapeCharacter(codePoint: number, character: string): string { switch (character) { case '"': @@ -334,13 +451,6 @@ function isPlainRecord(value: object): value is Record { return prototype === null || prototype === Object.prototype; } -function unavailablePreview(): BoundedLogPreview { - const writer = new Utf8PreviewWriter(SHADOW_LOG_VALUE_MAX_BYTES); - writer.write("[unavailable]"); - writer.markTruncated(); - return writer.finish(); -} - function completeUtf8PrefixLength(bytes: Uint8Array, proposedLength: number): number { if (proposedLength === 0) { return 0; @@ -352,24 +462,9 @@ function completeUtf8PrefixLength(bytes: Uint8Array, proposedLength: number): nu if (sequenceStart === proposedLength) { return proposedLength; } - return sequenceStart + utf8SequenceLength(bytes[sequenceStart]!) <= proposedLength - ? proposedLength - : sequenceStart; + return sequenceStart; } function isUtf8ContinuationByte(value: number): boolean { return (value & 0xc0) === 0x80; } - -function utf8SequenceLength(firstByte: number): number { - if ((firstByte & 0x80) === 0) { - return 1; - } - if ((firstByte & 0xe0) === 0xc0) { - return 2; - } - if ((firstByte & 0xf0) === 0xe0) { - return 3; - } - return 4; -} diff --git a/test/dialcache-config-ramp.test.ts b/test/dialcache-config-ramp.test.ts index 90bad64..37e0e39 100644 --- a/test/dialcache-config-ramp.test.ts +++ b/test/dialcache-config-ramp.test.ts @@ -459,7 +459,6 @@ describe("DialCache runtime config and ramp controls", () => { ["a null layer map", { ttlSec: null, ramp: {} }], ["an array shadow config", { ttlSec: {}, ramp: {}, shadow: [] }], ["a null requestLocal value", { ttlSec: {}, ramp: {}, requestLocal: null }], - ["the removed shadowRamp field", { ttlSec: {}, ramp: {}, shadowRamp: 100 }], ] as const)("fails open instead of inheriting defaults when the provider returns %s", async (_name, runtimeConfig) => { const cacheConfigProvider = vi.fn(async () => runtimeConfig as unknown as DialCacheKeyConfig); const dialcache = new DialCache({ cacheConfigProvider }); diff --git a/test/dialcache-metrics.test.ts b/test/dialcache-metrics.test.ts index 15f5fa1..4882781 100644 --- a/test/dialcache-metrics.test.ts +++ b/test/dialcache-metrics.test.ts @@ -668,6 +668,54 @@ describe("DialCache observability metrics", () => { expect(JSON.stringify(events(metrics, "error", {}))).not.toMatch(/Tenant123ConfigProviderError|tenant-123/); }); + it("reports a stale runtime shadowRamp leaf without disabling inherited cache layers", async () => { + const metrics = new RecordingMetrics(); + const redis = new FakeRedis(); + const cacheConfigProvider = vi.fn(async () => ({ + shadowRamp: 50, + } as unknown as DialCacheKeyConfig)); + const dialcache = new DialCache({ + redis: { client: redis, readTimeoutMs: 1_000 }, + metrics, + cacheConfigProvider, + }); + const source = vi.fn(async (id: string) => ({ id, source: "fallback" })); + const getUser = dialcache.cached(source, { + keyType: "user_id", + useCase: "IgnoredRuntimeShadowRamp", + cacheKey: (id) => id, + defaultConfig: new DialCacheKeyConfig({ + ttlSec: { + [CacheLayer.LOCAL]: 60, + [CacheLayer.REMOTE]: 60, + }, + ramp: { + [CacheLayer.LOCAL]: 100, + [CacheLayer.REMOTE]: 100, + }, + }), + }); + + const first = await dialcache.enable(async () => await getUser("123")); + const second = await dialcache.enable(async () => await getUser("123")); + + expect(second).toBe(first); + expect(source).toHaveBeenCalledOnce(); + expect(cacheConfigProvider).toHaveBeenCalledTimes(2); + expect(redis.getCalls).toBe(1); + expect(redis.setCalls).toBe(1); + expect(events(metrics, "error", { + useCase: "IgnoredRuntimeShadowRamp", + layer: CacheLayer.REMOTE, + error: "config_resolution", + inFallback: false, + })).toHaveLength(2); + expect(events(metrics, "disabled", { + useCase: "IgnoredRuntimeShadowRamp", + reason: "config_error", + })).toHaveLength(0); + }); + it("classifies local cache reads and writes", async () => { const metrics = new RecordingMetrics(); const logger = { debug: vi.fn(), warn: vi.fn(), error: vi.fn() }; diff --git a/test/dialcache-observability-internals.test.ts b/test/dialcache-observability-internals.test.ts index 615f82f..a9485a4 100644 --- a/test/dialcache-observability-internals.test.ts +++ b/test/dialcache-observability-internals.test.ts @@ -80,6 +80,55 @@ describe("DialCache observability internal compatibility paths", () => { } }); + it("ignores and reports a legacy runtime shadowRamp leaf after merging valid leaves", async () => { + const defaultConfig = new DialCacheKeyConfig({ + requestLocal: true, + ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 120 }, + ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 50 }, + shadow: { + ramp: 20, + logMismatches: true, + logMismatchDetails: true, + }, + }); + const runtime = { + shadowRamp: 80, + ramp: { [CacheLayer.REMOTE]: 75 }, + shadow: { logMismatches: false }, + } as unknown as DialCacheKeyConfig; + let ignoredLegacyLeaves = 0; + + await expect(fetchKeyConfig( + async () => runtime, + key(defaultConfig), + () => { + ignoredLegacyLeaves += 1; + }, + )).resolves.toEqual(new DialCacheKeyConfig({ + requestLocal: true, + ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 120 }, + ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 75 }, + shadow: { + ramp: 20, + logMismatches: false, + logMismatchDetails: true, + }, + })); + expect(ignoredLegacyLeaves).toBe(1); + + await expect(fetchKeyConfig( + async () => ({ + shadowRamp: 80, + shadow: [], + } as unknown as DialCacheKeyConfig), + key(defaultConfig), + () => { + ignoredLegacyLeaves += 1; + }, + )).rejects.toThrow("DialCache shadow config must be an object"); + expect(ignoredLegacyLeaves).toBe(1); + }); + it("keeps LocalCache get/getIfPresent compatibility while exposing disabled reads", async () => { // Given a local cache with enabled config and a second key with no config. const cache = new LocalCache(async () => null, 10); diff --git a/test/dialcache-shadow-confirmation.test.ts b/test/dialcache-shadow-confirmation.test.ts index 60e05eb..811acac 100644 --- a/test/dialcache-shadow-confirmation.test.ts +++ b/test/dialcache-shadow-confirmation.test.ts @@ -403,6 +403,62 @@ describe("DialCache Redis shadow confirmation", () => { expect(serializer.dump).not.toHaveBeenCalled(); }); + it("falls back to a metadata warning when detailed preview construction throws", async () => { + const cachedValue = { id: "123", version: 1 }; + const sourceValue = { id: "123", version: 2 }; + const payload = JSON.stringify(cachedValue); + 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 sourceStarted = deferred(); + const sourceGate = deferred(); + const getUser = dialcache.cached(async () => { + sourceStarted.resolve(); + return await sourceGate.promise; + }, { + ...trackedOptions( + "ShadowMismatchPreviewFailure", + remoteConfig(100, 100, { + logMismatches: true, + logMismatchDetails: true, + }), + ), + cacheKey: () => "123", + }); + + await dialcache.enable(async () => await getUser()); + await sourceStarted.promise; + const encodeInto = vi.spyOn(TextEncoder.prototype, "encodeInto").mockImplementationOnce(() => { + throw new Error("preview unavailable"); + }); + try { + sourceGate.resolve(sourceValue); + await waitForShadowEvents(metrics, 1); + + expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["mismatch"]); + expect(warn).toHaveBeenCalledOnce(); + expect(warn).toHaveBeenCalledWith( + "DialCache shadow validation mismatch", + { + cacheNamespace: "urn", + useCase: "ShadowMismatchPreviewFailure", + keyType: "user_id", + outcome: "mismatch", + }, + ); + } finally { + sourceGate.resolve(sourceValue); + encodeInto.mockRestore(); + } + }); + it("clamps the logical key and both value previews before handing details to the logger", async () => { const id = "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 100); const cachedValue = { id, content: "🙂".repeat(SHADOW_LOG_VALUE_MAX_BYTES) }; @@ -1342,6 +1398,7 @@ describe("DialCache Redis shadow confirmation", () => { it.each([ { name: "base logging flag", + useCase: "ShadowInvalidLoggingBase", runtimeShadow: { logMismatches: "yes" as never, }, @@ -1349,6 +1406,7 @@ describe("DialCache Redis shadow confirmation", () => { }, { name: "detail logging flag", + useCase: "ShadowInvalidLoggingDetails", runtimeShadow: { logMismatchDetails: "yes" as never, }, @@ -1359,8 +1417,17 @@ describe("DialCache Redis shadow confirmation", () => { outcome: "mismatch", }, }, + { + name: "both logging flags", + useCase: "ShadowInvalidLoggingBoth", + runtimeShadow: { + logMismatches: "yes" as never, + logMismatchDetails: "yes" as never, + }, + expectedWarning: null, + }, ] as const)("fails closed for an invalid runtime $name without suppressing mismatch metrics", async ({ - name, + useCase, runtimeShadow, expectedWarning, }) => { @@ -1380,9 +1447,6 @@ describe("DialCache Redis shadow confirmation", () => { warn, }, }); - const useCase = name === "base logging flag" - ? "ShadowInvalidLoggingBase" - : "ShadowInvalidLoggingDetails"; const getUser = dialcache.cached(async () => sourceValue, { ...trackedOptions( useCase, diff --git a/test/dialcache-shadow-validation.test.ts b/test/dialcache-shadow-validation.test.ts index 61fecf8..06668e9 100644 --- a/test/dialcache-shadow-validation.test.ts +++ b/test/dialcache-shadow-validation.test.ts @@ -402,17 +402,10 @@ describe("DialCache Redis shadow validation", () => { expect(source).not.toHaveBeenCalled(); expect(warn).not.toHaveBeenCalled(); - expect(error).toHaveBeenCalledWith({ - cacheNamespace: "urn", - useCase, - keyType: "user_id", - layer: CacheLayer.REMOTE, - error: "config_resolution", - inFallback: false, - }); + expect(error).not.toHaveBeenCalled(); }); - it("reports malformed runtime shadow logging for a key outside the shadow cohort", async () => { + it("does not validate shadow logging for a key outside the shadow cohort", async () => { const redis = new FakeRedis(); const metrics = new RecordingMetrics(); const useCase = "ShadowExcludedInvalidLogging"; @@ -457,7 +450,7 @@ describe("DialCache Redis shadow validation", () => { expect(metrics.errorEvents.filter((labels) => labels.layer === CacheLayer.REMOTE && labels.error === "config_resolution" - )).toHaveLength(1); + )).toHaveLength(0); }); it.each([ @@ -955,7 +948,14 @@ describe("DialCache Redis shadow validation", () => { seedRedis(redis, { id: "b", useCase, payload: JSON.stringify({ id: "b" }) }); const firstGate = deferred<{ readonly id: string }>(); const sourceIds: string[] = []; - const dialcache = createShadowCache(redis, metrics, { shadowMaxInFlight: 1 }); + const dialcache = createShadowCache(redis, metrics, { + shadowMaxInFlight: 1, + cacheConfigProvider: async (key) => key.id === "b" + ? new DialCacheKeyConfig({ + shadow: { logMismatches: "yes" as never }, + }) + : null, + }); const getUser = dialcache.cached(async (id: string) => { sourceIds.push(id); return id === "a" ? await firstGate.promise : { id }; @@ -970,6 +970,10 @@ describe("DialCache Redis shadow validation", () => { expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["dropped"]); await nextImmediate(); expect(sourceIds).toEqual(["a"]); + expect(metrics.errorEvents.filter((labels) => + labels.layer === CacheLayer.REMOTE + && labels.error === "config_resolution" + )).toHaveLength(0); firstGate.resolve({ id: "a" }); await waitForShadowEvents(metrics, 2); expect(metrics.shadowEvents.map(({ outcome }) => outcome)).toEqual(["dropped", "match"]); diff --git a/test/shadow-log-preview.test.ts b/test/shadow-log-preview.test.ts index 0a4172b..5afebc9 100644 --- a/test/shadow-log-preview.test.ts +++ b/test/shadow-log-preview.test.ts @@ -1,4 +1,4 @@ -import { inspect } from "node:util"; +import { inspect, types as utilTypes } from "node:util"; import { describe, expect, it, vi } from "vitest"; @@ -13,6 +13,11 @@ import { describe("shadow mismatch log previews", () => { it("keeps exact-limit strings and byte-clamps oversized ASCII and Unicode strings", () => { + expect(previewShadowLogKey("")).toEqual({ + text: "", + truncated: false, + }); + const exact = "a".repeat(SHADOW_LOG_KEY_MAX_BYTES); const exactKeyPreview = previewShadowLogKey(exact); expect(exactKeyPreview).toEqual({ @@ -42,6 +47,46 @@ describe("shadow mismatch log previews", () => { } }); + it("rolls byte-clipped keys back to a complete two-, three-, or four-byte UTF-8 sequence", () => { + const contentLimit = SHADOW_LOG_KEY_MAX_BYTES - Buffer.byteLength(SHADOW_LOG_TRUNCATION_MARKER); + + for (const character of ["é", "€", "🙂"]) { + const prefix = "a".repeat(contentLimit - 1); + const preview = previewShadowLogKey( + `${prefix}${character}${"z".repeat(SHADOW_LOG_KEY_MAX_BYTES)}`, + ); + + expect(preview).toEqual({ + text: `${prefix}${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }); + expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); + expect(preview.text).not.toContain("\uFFFD"); + } + }); + + it("uses length-only markers before inspecting very large rope strings", () => { + let rope = "x"; + for (let index = 0; index < 17; index += 1) { + rope += rope; + } + expect(rope.length).toBe(131_072); + const marker = `[String length=${rope.length} code units]${SHADOW_LOG_TRUNCATION_MARKER}`; + + expect(previewShadowLogKey(rope)).toEqual({ + text: marker, + truncated: true, + }); + expect(previewShadowLogValue(rope)).toEqual({ + text: marker, + truncated: true, + }); + expect(previewShadowLogValue({ [rope]: 1 })).toEqual({ + text: `{[PropertyName length=${rope.length} code units]: 1}${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }); + }); + it("renders supported primitives and escaped strings without truncation", () => { expect(previewShadowLogValue({ undefined, @@ -55,6 +100,31 @@ describe("shadow mismatch log previews", () => { }); }); + it("escapes every supported string control and separator sequence", () => { + const cases = [ + ['"', '\\"'], + ["\\", "\\\\"], + ["\b", "\\b"], + ["\f", "\\f"], + ["\n", "\\n"], + ["\r", "\\r"], + ["\t", "\\t"], + ["\u0000", "\\u0000"], + ["\u001f", "\\u001f"], + ["\u2028", "\\u2028"], + ["\u2029", "\\u2029"], + ["\ud800", "\\ud800"], + ["\udfff", "\\udfff"], + ] as const; + + for (const [input, escaped] of cases) { + expect(previewShadowLogValue(input)).toEqual({ + text: `"${escaped}"`, + truncated: false, + }); + } + }); + it("bounds large values and aggregates field truncation", () => { const details = shadowMismatchLogDetails( "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 1), @@ -102,7 +172,7 @@ describe("shadow mismatch log previews", () => { }, { name: "structurally unsupported cached value", - details: shadowMismatchLogDetails("key", new Map(), "source"), + details: shadowMismatchLogDetails("key", new Map([["key", "value"]]), "source"), truncatedField: "cachedValuePreview", }, ] as const; @@ -132,6 +202,7 @@ describe("shadow mismatch log previews", () => { Promise.resolve(), new WeakMap(), new WeakSet(), + new Proxy(() => undefined, {}), ]) { const preview = previewShadowLogValue(value); @@ -141,18 +212,173 @@ describe("shadow mismatch log previews", () => { } }); - it("renders exotic and class instances opaquely", () => { + it("renders dates with intrinsic methods and distinguishes different timestamps", () => { + const valueOf = vi.fn(() => { + throw new Error("overridden valueOf invoked"); + }); + const toISOString = vi.fn(() => { + throw new Error("overridden toISOString invoked"); + }); + const hostileDate = new Date("2026-07-30T00:00:00.000Z"); + Object.defineProperties(hostileDate, { + valueOf: { value: valueOf }, + toISOString: { value: toISOString }, + }); + + expect(previewShadowLogValue(hostileDate)).toEqual({ + text: "Date(2026-07-30T00:00:00.000Z)", + truncated: false, + }); + expect(previewShadowLogValue(new Date("2026-07-31T00:00:00.000Z"))).toEqual({ + text: "Date(2026-07-31T00:00:00.000Z)", + truncated: false, + }); + expect(previewShadowLogValue(new Date(Number.NaN))).toEqual({ + text: "Date(Invalid)", + truncated: false, + }); + expect(previewShadowLogValue({ updatedAt: hostileDate })).toEqual({ + text: '{"updatedAt": Date(2026-07-30T00:00:00.000Z)}', + truncated: false, + }); + expect(valueOf).not.toHaveBeenCalled(); + expect(toISOString).not.toHaveBeenCalled(); + }); + + it("renders collection sizes without invoking instance hooks or iterators", () => { + const hook = vi.fn(() => { + throw new Error("collection hook invoked"); + }); + const map = new Map([["a", 1], ["b", 2]]); + const set = new Set(["a", "b", "c"]); + Object.defineProperties(map, { + size: { get: hook }, + entries: { value: hook }, + [Symbol.iterator]: { value: hook }, + }); + Object.defineProperties(set, { + size: { get: hook }, + values: { value: hook }, + [Symbol.iterator]: { value: hook }, + }); + + expect(previewShadowLogValue(new Map())).toEqual({ + text: "Map(0)", + truncated: false, + }); + expect(previewShadowLogValue(new Set())).toEqual({ + text: "Set(0)", + truncated: false, + }); + expect(previewShadowLogValue(map)).toEqual({ + text: `Map(2)${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }); + expect(previewShadowLogValue(set)).toEqual({ + text: `Set(3)${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }); + expect(hook).not.toHaveBeenCalled(); + }); + + it("renders bounded raw bytes for buffers and every supported typed-array brand", () => { + expect(previewShadowLogValue(Buffer.from([0, 1, 255]))).toEqual({ + text: "Buffer(3 bytes) [00 01 ff]", + truncated: false, + }); + + const typedArrays = [ + ["Uint8Array", new Uint8Array(1)], + ["Uint8ClampedArray", new Uint8ClampedArray(1)], + ["Uint16Array", new Uint16Array(1)], + ["Uint32Array", new Uint32Array(1)], + ["Int8Array", new Int8Array(1)], + ["Int16Array", new Int16Array(1)], + ["Int32Array", new Int32Array(1)], + ["Float32Array", new Float32Array(1)], + ["Float64Array", new Float64Array(1)], + ["BigInt64Array", new BigInt64Array(1)], + ["BigUint64Array", new BigUint64Array(1)], + ] as const; + + for (const [name, value] of typedArrays) { + expect(previewShadowLogValue(value)).toEqual({ + text: `${name}(${value.byteLength} bytes) [${Array.from( + { length: value.byteLength }, + () => "00", + ).join(" ")}]`, + truncated: false, + }); + } + + const oversized = Uint8Array.from({ length: 65 }, (_, index) => index); + const oversizedPreview = previewShadowLogValue(oversized); + expect(oversizedPreview.truncated).toBe(true); + expect(oversizedPreview.text).toBe( + `Uint8Array(65 bytes) [${Array.from( + { length: 64 }, + (_, index) => index.toString(16).padStart(2, "0"), + ).join(" ")}]${SHADOW_LOG_TRUNCATION_MARKER}`, + ); + expect(Buffer.byteLength(oversizedPreview.text)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); + }); + + it("keeps later typed-array brands working on the Node 22.0 util.types surface", () => { + const descriptor = Object.getOwnPropertyDescriptor(utilTypes, "isFloat16Array"); + expect(descriptor).toBeDefined(); + Reflect.deleteProperty(utilTypes, "isFloat16Array"); + + try { + expect(previewShadowLogValue(new Float64Array(1))).toEqual({ + text: "Float64Array(8 bytes) [00 00 00 00 00 00 00 00]", + truncated: false, + }); + expect(previewShadowLogValue(new BigUint64Array(1))).toEqual({ + text: "BigUint64Array(8 bytes) [00 00 00 00 00 00 00 00]", + truncated: false, + }); + } finally { + Object.defineProperty(utilTypes, "isFloat16Array", descriptor!); + } + }); + + it("reads binary metadata through intrinsics instead of instance overrides", () => { + const hook = vi.fn(() => { + throw new Error("typed-array hook invoked"); + }); + const value = Uint8Array.from([5, 6]); + Object.defineProperties(value, { + buffer: { get: hook }, + byteOffset: { get: hook }, + byteLength: { get: hook }, + constructor: { get: hook }, + [Symbol.iterator]: { value: hook }, + }); + + expect(previewShadowLogValue(value)).toEqual({ + text: "Uint8Array(2 bytes) [05 06]", + truncated: false, + }); + expect(hook).not.toHaveBeenCalled(); + }); + + it("fails closed for a detached typed-array buffer", () => { + const value = Uint8Array.from([1, 2]); + structuredClone(value.buffer, { transfer: [value.buffer] }); + + expect(previewShadowLogValue(value)).toEqual({ + text: `[unavailable]${SHADOW_LOG_TRUNCATION_MARKER}`, + truncated: true, + }); + }); + + it("keeps unsupported exotic and class instances opaque", () => { class Example { readonly visible = true; } const values = [ - Buffer.from([0, 1, 255]), - new Uint16Array([1, 2]), new DataView(Uint8Array.from([3, 4]).buffer), Uint8Array.from([5, 6]).buffer, - new Map([["key", { value: 1 }]]), - new Set(["value"]), - new Date("2026-07-30T00:00:00.000Z"), /cache/giu, new Error("nope"), new Example(), @@ -227,8 +453,8 @@ describe("shadow mismatch log previews", () => { truncated: true, }); expect(typedArrayPreview).toEqual({ - text: `[Object]${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, + text: "Uint8Array(2 bytes) [01 02]", + truncated: false, }); expect(proxyPreview.text).toBe(`[Proxy]${SHADOW_LOG_TRUNCATION_MARKER}`); expect(revokedPreview.text).toBe(`[Proxy]${SHADOW_LOG_TRUNCATION_MARKER}`); @@ -279,6 +505,17 @@ describe("shadow mismatch log previews", () => { }); }); + it("does not render a value after an oversized property name fills the preview", () => { + const preview = previewShadowLogValue({ + ["p".repeat(SHADOW_LOG_VALUE_MAX_BYTES)]: "must-not-appear", + }); + + expect(preview.truncated).toBe(true); + expect(preview.text).not.toContain("must-not-appear"); + expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); + }); + it("marks detailed output complete only when every field is complete", () => { expect(shadowMismatchLogDetails( "{urn:user_id:123}#Example", From 8f20e4267fa740178a33013c0060539829276f04 Mon Sep 17 00:00:00 2001 From: Lev Neiman Date: Thu, 30 Jul 2026 23:12:46 -0700 Subject: [PATCH 5/6] refactor: simplify shadow mismatch logging --- README.md | 25 +- scripts/test-package.mjs | 3 - src/config.ts | 10 +- src/dialcache.ts | 67 +-- src/internal/runtime-config.ts | 4 - src/internal/shadow-log-json.ts | 51 ++ src/internal/shadow-log-preview.ts | 470 ---------------- test/dialcache-config-ramp.test.ts | 16 - .../dialcache-observability-internals.test.ts | 7 - test/dialcache-shadow-confirmation.test.ts | 103 +--- test/dialcache-shadow-validation.test.ts | 3 +- test/shadow-log-json.test.ts | 62 ++ test/shadow-log-preview.test.ts | 531 ------------------ 13 files changed, 173 insertions(+), 1179 deletions(-) create mode 100644 src/internal/shadow-log-json.ts delete mode 100644 src/internal/shadow-log-preview.ts create mode 100644 test/shadow-log-json.test.ts delete mode 100644 test/shadow-log-preview.test.ts diff --git a/README.md b/README.md index fd4af4e..54d06e5 100644 --- a/README.md +++ b/README.md @@ -207,23 +207,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, an optional `remoteReadTimeoutMs`, and an optional `shadow` group. `ShadowConfig` contains the independent shadow `ramp` percentage plus the default-off `logMismatches` and `logMismatchDetails` controls. +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, an optional `remoteReadTimeoutMs`, and an optional `shadow` group. `ShadowConfig` contains the independent shadow `ramp` percentage plus the default-off `logMismatches` control. 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 both shadow logging controls 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 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. `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. 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 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`, `shadow.logMismatches`, and `shadow.logMismatchDetails` must be booleans when present. Invalid defaults are rejected immediately. +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` and `shadow.logMismatches` must be booleans when present. Invalid defaults are rejected immediately. 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, or explicit `remoteReadTimeoutMs` fails config resolution for the invocation, records `config_error`, and executes the fallback uncached without attempting Redis. The removed top-level `shadowRamp` field is the one compatibility exception for raw provider results: DialCache ignores that leaf, applies every other valid overlay field, and records one remote `config_resolution` error for that resolution. The public `DialCacheKeyConfig` constructor and static defaults still reject `shadowRamp` immediately; migrate it to `shadow.ramp`. -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. Invalid runtime shadow logging leaves likewise preserve the cache result, Redis policy, shadow result, and shadow metric: an invalid `logMismatches` disables the warning, while an invalid `logMismatchDetails` downgrades it to the metadata-only warning. DialCache validates these diagnostic leaves only after the metrics hook, exact-key cohort, and capacity gates admit shadow work, and collapses multiple invalid logging leaves into one remote `config_resolution` error per 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 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. `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. @@ -239,7 +239,7 @@ const dialcache = new DialCache({ // Independently sample tracked Redis keys for detached validation/fill. shadow: { ramp: 5, - // Emit one metadata-only warning for each confirmed mismatch. + // Emit one warning with a bounded key and native-JSON value strings. logMismatches: true, }, // Can be changed by the provider at runtime for this use case. @@ -477,7 +477,7 @@ const getUser = dialcache.cached( (userId: string) => db.fetchUser(userId), { keyType: "user_id", - useCase: "GetSensitiveUser", + useCase: "GetUser", cacheKey: (userId) => userId, trackForInvalidation: true, // Optional: override strict deep equality with use-case semantics. @@ -489,17 +489,16 @@ const getUser = dialcache.cached( ramp: { [CacheLayer.REMOTE]: 0 }, shadow: { ramp: 5, - // Default-off metadata warning for a confirmed mismatch. + // Default-off warning with a bounded key and native-JSON value strings. + // Enable only after approving the logger and data-handling policy. logMismatches: true, - // Keep false unless this logger is approved for key/value data. - logMismatchDetails: false, }, }), }, ); ``` -Shadow work is eligible only when the operation sets `trackForInvalidation: true`, 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. Logging is supplemental to that metric; enabling either logging flag 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 the operation sets `trackForInvalidation: true`, 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. Logging is supplemental to that 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: - When remote serving is enabled and produces a tracked 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 tracked Redis read for `C0`. 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. @@ -544,11 +543,11 @@ 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`. 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. -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`. With details disabled, the single warning contains only `cacheNamespace`, `useCase`, `keyType`, and `outcome: "mismatch"`. Setting `shadow.logMismatchDetails: true` enriches that same warning with `cacheKey`, `cachedValuePreview`, `sourceValuePreview`, and `detailsTruncated`, but is inert unless `logMismatches` is also true. `cacheKey` is a UTF-8 preview of the logical DialCache URN capped at 2 KiB, not the physical Redis storage key. The two value previews are capped at 8 KiB each and represent the deserialized cached snapshot and raw source value supplied to the comparator. Every byte-clipped or structurally shortened field ends in `...[truncated]`, counted inside its cap; `detailsTruncated` is true when any field is byte-clipped or structurally shortened. DialCache does not compute or serialize a textual diff and does not call the configured serializer again for logging. +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. -Detailed 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 value previews only after terminal mismatch confirmation and never passes the raw compared-value references to the logger. Value previews cover primitives, dates, collection sizes, up to 64 raw bytes from Buffers and typed arrays, indexed array elements, and own enumerable string-keyed fields on plain records. A string or property name longer than 65,536 UTF-16 code units is not content-inspected and renders as a length-only marker; the same guard applies to the logical key preview. Nonempty Map and Set contents are omitted and therefore structurally shortened. Non-enumerable and symbol properties, plus extra named properties on arrays, are outside that JSON-like preview domain. Accessors, proxies, cycles, functions, class instances, and other unsupported or limited structures are represented by opaque markers and set `detailsTruncated`; the renderer uses captured built-in intrinsics and does not invoke property getters, `toJSON`, custom inspection hooks, user iterators, or constructors. +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. -Enable details only with an approved logger, redaction, transport, access, and retention policy. The limits bound rendered fields, recursion, preview bytes, and individual string inspection; the string guard avoids flattening an arbitrarily large rope solely to render a bounded prefix. Detailed preview construction is synchronous. For a pathological plain record with a very large enumerable-key set, the JavaScript runtime may still enumerate and cache the full key set before DialCache reaches its 32-field limit; this can block the shared Node.js event loop and cause a tail-latency spike even though the emitted preview remains byte-clamped. Keep detailed logging disabled for untrusted or unbounded record shapes. The byte caps apply to the three detail fields 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-preview failure degrades to the metadata-only warning. Logger throws and rejected promises or thenables remain isolated from cache and shadow correctness. +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. 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. diff --git a/scripts/test-package.mjs b/scripts/test-package.mjs index d3b86a2..b2a9c58 100644 --- a/scripts/test-package.mjs +++ b/scripts/test-package.mjs @@ -119,7 +119,6 @@ const shadowCache = new DialCache(shadowCacheConfig); const shadowConfig: ShadowConfig = { ramp: 50, logMismatches: true, - logMismatchDetails: false, }; const shadowKeyConfig = new DialCacheKeyConfig({ shadow: shadowConfig }); const dogStatsDClient: DatadogDogStatsDClient = { @@ -641,7 +640,6 @@ if ( esmDisabledOverlay.requestLocal !== false || esmDisabledOverlay.shadow?.ramp !== 0 || esmDisabledOverlay.shadow.logMismatches !== false - || esmDisabledOverlay.shadow.logMismatchDetails !== false || esmDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 || esmDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0 ) { @@ -880,7 +878,6 @@ if ( cjsDisabledOverlay.requestLocal !== false || cjsDisabledOverlay.shadow?.ramp !== 0 || cjsDisabledOverlay.shadow.logMismatches !== false - || cjsDisabledOverlay.shadow.logMismatchDetails !== false || cjsDisabledOverlay.ramp[root.CacheLayer.LOCAL] !== 0 || cjsDisabledOverlay.ramp[root.CacheLayer.REMOTE] !== 0 ) { diff --git a/src/config.ts b/src/config.ts index ce11eb3..b40c24f 100644 --- a/src/config.ts +++ b/src/config.ts @@ -15,14 +15,11 @@ export type LayerConfig = Partial>; export interface ShadowConfig { /** Independent stable cohort percentage. Omitted and zero disable shadow work. */ readonly ramp?: number; - /** Emit one warning for each confirmed mismatch. Defaults to false. */ - readonly logMismatches?: boolean; /** - * Enrich that warning with bounded previews of the logical cache key and - * compared values. - * Defaults to false and has no effect unless `logMismatches` is true. + * Emit one warning with the logical key and bounded native-JSON strings for + * the compared values for each confirmed mismatch. Defaults to false. */ - readonly logMismatchDetails?: boolean; + readonly logMismatches?: boolean; } export class DialCacheKeyConfig { @@ -99,7 +96,6 @@ export class DialCacheKeyConfig { shadow: { ramp: 0, logMismatches: false, - logMismatchDetails: false, }, ramp: { [CacheLayer.LOCAL]: 0, diff --git a/src/dialcache.ts b/src/dialcache.ts index 1eca534..4cb261f 100644 --- a/src/dialcache.ts +++ b/src/dialcache.ts @@ -41,7 +41,7 @@ import { type LayerConfigResolution, type ResolvedLayerConfig, } from "./internal/runtime-config.js"; -import { shadowMismatchLogDetails } from "./internal/shadow-log-preview.js"; +import { shadowMismatchLogDetails } from "./internal/shadow-log-json.js"; type CacheKeyArgs = Record; type Id = string | number | bigint; @@ -223,11 +223,6 @@ interface ShadowValidationPlan { readonly didCallerFallbackTimeout: () => boolean; } -interface ResolvedShadowLogging { - readonly logMismatches: boolean; - readonly logMismatchDetails: boolean; -} - interface ShadowMismatchDetails { readonly cachedValue: unknown; readonly sourceValue: unknown; @@ -845,7 +840,7 @@ export class DialCache { this.recordShadowValidation(key, "dropped"); return; } - const shadowLogging = this.resolveShadowLogging(key, resolvedShadowConfig); + const logMismatches = this.resolveShadowLogging(key, resolvedShadowConfig); const flight: ShadowFlight = { cachedPayload: start.kind === "retained" ? start.payload : null, @@ -865,43 +860,23 @@ export class DialCache { runStart, validation, readTimeoutMs, - shadowLogging, + logMismatches, ); } private resolveShadowLogging( key: DialCacheKey, shadowConfig: Record, - ): ResolvedShadowLogging { + ): boolean { const configuredLogMismatches = shadowConfig.logMismatches; - const configuredLogMismatchDetails = shadowConfig.logMismatchDetails; - - let logMismatches = false; - let invalidLogging = false; - if (configuredLogMismatches !== undefined) { - if (typeof configuredLogMismatches === "boolean") { - logMismatches = configuredLogMismatches; - } else { - invalidLogging = true; - } - } - - let logMismatchDetails = false; - if (configuredLogMismatchDetails !== undefined) { - if (typeof configuredLogMismatchDetails === "boolean") { - logMismatchDetails = configuredLogMismatchDetails; - } else { - invalidLogging = true; - } + if (configuredLogMismatches === undefined) { + return false; } - if (invalidLogging) { + if (typeof configuredLogMismatches !== "boolean") { this.recordError(key, CacheLayer.REMOTE, "config_resolution"); + return false; } - - return { - logMismatches, - logMismatchDetails: logMismatches && logMismatchDetails, - }; + return configuredLogMismatches; } private deferShadowValidation( @@ -911,7 +886,7 @@ export class DialCache { start: ShadowValidationRunStart, validation: ShadowValidationPlan, readTimeoutMs: number, - shadowLogging: ResolvedShadowLogging, + logMismatches: boolean, ): void { setImmediate(() => { this.runShadowValidation( @@ -921,7 +896,7 @@ export class DialCache { start, validation, readTimeoutMs, - shadowLogging, + logMismatches, ); }).unref(); } @@ -933,7 +908,7 @@ export class DialCache { start: ShadowValidationRunStart, plan: ShadowValidationPlan, readTimeoutMs: number, - shadowLogging: ResolvedShadowLogging, + logMismatches: boolean, ): void { const pendingRedisReads = new Set>(); let operationFinished = false; @@ -1117,7 +1092,7 @@ export class DialCache { if (confirmationPayload === null || !redisPayloadsEqual(originalPayload, confirmationPayload)) { return "superseded"; } - if (shadowLogging.logMismatchDetails) { + if (logMismatches) { mismatchDetails = { cachedValue, sourceValue }; } return "mismatch"; @@ -1128,7 +1103,7 @@ export class DialCache { }); void validation.then( - (outcome) => this.recordShadowValidation(key, outcome, shadowLogging, mismatchDetails), + (outcome) => this.recordShadowValidation(key, outcome, logMismatches, mismatchDetails), () => this.recordShadowValidation(key, "timeout"), ); } @@ -1136,7 +1111,7 @@ export class DialCache { private recordShadowValidation( key: DialCacheKey, outcome: ShadowValidationOutcome, - logging?: ResolvedShadowLogging, + logMismatches = false, mismatchDetails?: ShadowMismatchDetails, ): void { const labels = { @@ -1146,7 +1121,7 @@ export class DialCache { outcome, } as const; this.metrics?.shadowValidation?.(labels); - if (outcome !== "mismatch" || logging?.logMismatches !== true) { + if (outcome !== "mismatch" || !logMismatches) { return; } @@ -1156,7 +1131,7 @@ export class DialCache { keyType: key.keyType, outcome: "mismatch", } as const; - if (logging.logMismatchDetails && mismatchDetails !== undefined) { + if (mismatchDetails !== undefined) { try { this.logger.warn( "DialCache shadow validation mismatch", @@ -1171,7 +1146,7 @@ export class DialCache { ); return; } catch { - // Preview construction is best-effort; preserve the metadata warning. + // JSON detail construction is best-effort; preserve the metadata warning. } } this.logger.warn("DialCache shadow validation mismatch", warning); @@ -1465,12 +1440,6 @@ function snapshotDefaultConfig(config: DialCacheKeyConfig | null | undefined): D if (snapshot.shadow.logMismatches !== undefined && typeof snapshot.shadow.logMismatches !== "boolean") { throw new TypeError("DialCache defaultConfig shadow.logMismatches must be a boolean"); } - if ( - snapshot.shadow.logMismatchDetails !== undefined - && typeof snapshot.shadow.logMismatchDetails !== "boolean" - ) { - throw new TypeError("DialCache defaultConfig shadow.logMismatchDetails must be a boolean"); - } } Object.freeze(snapshot.ttlSec); diff --git a/src/internal/runtime-config.ts b/src/internal/runtime-config.ts index 92ac8e3..4ead4c1 100644 --- a/src/internal/runtime-config.ts +++ b/src/internal/runtime-config.ts @@ -178,14 +178,10 @@ function mergeShadowConfig( const logMismatches = overlay?.logMismatches !== undefined ? overlay.logMismatches : defaults?.logMismatches; - const logMismatchDetails = overlay?.logMismatchDetails !== undefined - ? overlay.logMismatchDetails - : defaults?.logMismatchDetails; return { ...(ramp === undefined ? {} : { ramp }), ...(logMismatches === undefined ? {} : { logMismatches }), - ...(logMismatchDetails === undefined ? {} : { logMismatchDetails }), }; } diff --git a/src/internal/shadow-log-json.ts b/src/internal/shadow-log-json.ts new file mode 100644 index 0000000..a43b2db --- /dev/null +++ b/src/internal/shadow-log-json.ts @@ -0,0 +1,51 @@ +export const SHADOW_LOG_KEY_MAX_BYTES = 2 * 1024; +export const SHADOW_LOG_VALUE_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; +} + +export function previewShadowLogKey(value: string): string { + return clampUtf8(value, SHADOW_LOG_KEY_MAX_BYTES); +} + +export function previewShadowLogJson(value: unknown): string | null { + try { + const json = JSON.stringify(value); + return json === undefined ? null : clampUtf8(json, SHADOW_LOG_VALUE_MAX_BYTES); + } catch { + return null; + } +} + +export function shadowMismatchLogDetails( + cacheKey: string, + cachedValue: unknown, + sourceValue: unknown, +): ShadowMismatchLogDetails { + return { + cacheKey: previewShadowLogKey(cacheKey), + cachedValueJson: previewShadowLogJson(cachedValue), + sourceValueJson: previewShadowLogJson(sourceValue), + }; +} + +function clampUtf8(value: string, maxBytes: number): string { + const bytes = new Uint8Array(maxBytes); + const encoded = UTF8_ENCODER.encodeInto(value, bytes); + if (encoded.read === value.length) { + return value; + } + + const content = bytes.subarray(0, maxBytes - TRUNCATION_MARKER_BYTES.byteLength); + const { written } = UTF8_ENCODER.encodeInto(value, content); + bytes.set(TRUNCATION_MARKER_BYTES, written); + return UTF8_DECODER.decode(bytes.subarray(0, written + TRUNCATION_MARKER_BYTES.byteLength)); +} diff --git a/src/internal/shadow-log-preview.ts b/src/internal/shadow-log-preview.ts deleted file mode 100644 index 8b846f3..0000000 --- a/src/internal/shadow-log-preview.ts +++ /dev/null @@ -1,470 +0,0 @@ -import { Buffer } from "node:buffer"; -import { types as utilTypes } from "node:util"; - -export const SHADOW_LOG_KEY_MAX_BYTES = 2 * 1024; -export const SHADOW_LOG_VALUE_MAX_BYTES = 8 * 1024; -export const SHADOW_LOG_TRUNCATION_MARKER = "...[truncated]"; - -const MAX_DEPTH = 4; -const MAX_CONTAINER_ENTRIES = 32; -const MAX_VISITED_NODES = 128; -const MAX_BINARY_PREVIEW_BYTES = 64; -const MAX_STRING_INPUT_CODE_UNITS = 64 * 1024; -const MAX_RENDERED_BIGINT_MAGNITUDE = 10n ** 100n; - -const DATE_VALUE_OF = Date.prototype.valueOf; -const DATE_TO_ISO_STRING = Date.prototype.toISOString; -const MAP_SIZE = Object.getOwnPropertyDescriptor(Map.prototype, "size")!.get!; -const SET_SIZE = Object.getOwnPropertyDescriptor(Set.prototype, "size")!.get!; -const TYPED_ARRAY_PROTOTYPE = Object.getPrototypeOf(Uint8Array.prototype); -const TYPED_ARRAY_BUFFER = Object.getOwnPropertyDescriptor(TYPED_ARRAY_PROTOTYPE, "buffer")!.get!; -const TYPED_ARRAY_BYTE_OFFSET = Object.getOwnPropertyDescriptor(TYPED_ARRAY_PROTOTYPE, "byteOffset")!.get!; -const TYPED_ARRAY_BYTE_LENGTH = Object.getOwnPropertyDescriptor(TYPED_ARRAY_PROTOTYPE, "byteLength")!.get!; -const NATIVE_UINT8_ARRAY = Uint8Array; -const IS_BUFFER = Buffer.isBuffer; -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 BoundedLogPreview { - readonly text: string; - readonly truncated: boolean; -} - -export interface ShadowMismatchLogDetails { - readonly cacheKey: string; - readonly cachedValuePreview: string; - readonly sourceValuePreview: string; - readonly detailsTruncated: boolean; -} - -interface PreviewState { - readonly writer: Utf8PreviewWriter; - readonly ancestors: WeakSet; - visitedNodes: number; -} - -class Utf8PreviewWriter { - private readonly bytes: Uint8Array; - private offset = 0; - private truncated = false; - - constructor(private readonly maxBytes: number) { - this.bytes = new Uint8Array(maxBytes); - } - - get isFull(): boolean { - return this.offset >= this.contentLimit; - } - - write(value: string): boolean { - if (value.length === 0) { - return true; - } - - const destination = this.bytes.subarray(this.offset, this.contentLimit); - const { read, written } = UTF8_ENCODER.encodeInto(value, destination); - this.offset += written; - if (read === value.length) { - return true; - } - - this.markTruncated(); - return false; - } - - markTruncated(): void { - if (this.truncated) { - return; - } - - this.truncated = true; - if (this.offset > this.contentLimit) { - this.offset = completeUtf8PrefixLength(this.bytes, this.contentLimit); - } - } - - finish(): BoundedLogPreview { - if (this.truncated) { - this.bytes.set(TRUNCATION_MARKER_BYTES, this.offset); - this.offset += TRUNCATION_MARKER_BYTES.byteLength; - } - return { - text: UTF8_DECODER.decode(this.bytes.subarray(0, this.offset)), - truncated: this.truncated, - }; - } - - private get contentLimit(): number { - return this.truncated - ? this.maxBytes - TRUNCATION_MARKER_BYTES.byteLength - : this.maxBytes; - } -} - -export function previewShadowLogKey(value: string): BoundedLogPreview { - const writer = new Utf8PreviewWriter(SHADOW_LOG_KEY_MAX_BYTES); - if (value.length > MAX_STRING_INPUT_CODE_UNITS) { - writeOversizedStringMarker(writer, "String", value.length); - } else { - writer.write(value); - } - return writer.finish(); -} - -export function previewShadowLogValue(value: unknown): BoundedLogPreview { - const state: PreviewState = { - writer: new Utf8PreviewWriter(SHADOW_LOG_VALUE_MAX_BYTES), - ancestors: new WeakSet(), - visitedNodes: 0, - }; - - renderValue(state, value, 0); - return state.writer.finish(); -} - -export function shadowMismatchLogDetails( - cacheKey: string, - cachedValue: unknown, - sourceValue: unknown, -): ShadowMismatchLogDetails { - const keyPreview = previewShadowLogKey(cacheKey); - const cachedPreview = previewShadowLogValue(cachedValue); - const sourcePreview = previewShadowLogValue(sourceValue); - return { - cacheKey: keyPreview.text, - cachedValuePreview: cachedPreview.text, - sourceValuePreview: sourcePreview.text, - detailsTruncated: keyPreview.truncated || cachedPreview.truncated || sourcePreview.truncated, - }; -} - -function renderValue(state: PreviewState, value: unknown, depth: number): void { - if (state.writer.isFull) { - state.writer.markTruncated(); - return; - } - if (state.visitedNodes >= MAX_VISITED_NODES) { - writeTruncatedMarker(state, "[NodeLimit]"); - return; - } - state.visitedNodes += 1; - - try { - if (value === null) { - state.writer.write("null"); - return; - } - - switch (typeof value) { - case "undefined": - state.writer.write("undefined"); - return; - case "string": - if (value.length > MAX_STRING_INPUT_CODE_UNITS) { - writeOversizedStringMarker(state.writer, "String", value.length); - } else { - writeQuotedString(state.writer, value); - } - return; - case "boolean": - state.writer.write(value ? "true" : "false"); - return; - case "number": - writeNumber(state.writer, value); - return; - case "bigint": - writeBigInt(state.writer, value); - return; - case "symbol": - writeTruncatedMarker(state, "[Symbol]"); - return; - case "function": - writeTruncatedMarker(state, utilTypes.isProxy(value) ? "[Proxy]" : "[Function]"); - return; - case "object": - renderObject(state, value, depth); - return; - } - } catch { - writeTruncatedMarker(state, "[unavailable]"); - } -} - -function renderObject(state: PreviewState, value: object, depth: number): void { - if (utilTypes.isProxy(value)) { - writeTruncatedMarker(state, "[Proxy]"); - return; - } - if (state.ancestors.has(value)) { - writeTruncatedMarker(state, "[Circular]"); - return; - } - if (depth >= MAX_DEPTH) { - writeTruncatedMarker(state, "[MaxDepth]"); - return; - } - - state.ancestors.add(value); - try { - if (Array.isArray(value)) { - renderArray(state, value, depth); - } else if (utilTypes.isDate(value)) { - renderDate(state, value); - } else if (utilTypes.isMap(value)) { - renderCollectionSize(state, "Map", MAP_SIZE.call(value) as number); - } else if (utilTypes.isSet(value)) { - renderCollectionSize(state, "Set", SET_SIZE.call(value) as number); - } else if (utilTypes.isTypedArray(value)) { - renderTypedArray(state, value); - } else if (isPlainRecord(value)) { - renderRecord(state, value, depth); - } else { - writeTruncatedMarker(state, "[Object]"); - } - } finally { - state.ancestors.delete(value); - } -} - -function renderDate(state: PreviewState, value: Date): void { - const timestamp = DATE_VALUE_OF.call(value); - state.writer.write(Number.isNaN(timestamp) - ? "Date(Invalid)" - : `Date(${DATE_TO_ISO_STRING.call(value)})`); -} - -function renderCollectionSize(state: PreviewState, name: "Map" | "Set", size: number): void { - state.writer.write(`${name}(${size})`); - if (size > 0) { - state.writer.markTruncated(); - } -} - -function renderTypedArray(state: PreviewState, value: NodeJS.TypedArray): void { - const buffer = TYPED_ARRAY_BUFFER.call(value) as ArrayBufferLike; - const byteOffset = TYPED_ARRAY_BYTE_OFFSET.call(value) as number; - const byteLength = TYPED_ARRAY_BYTE_LENGTH.call(value) as number; - const renderedByteLength = Math.min(byteLength, MAX_BINARY_PREVIEW_BYTES); - const bytes = new NATIVE_UINT8_ARRAY(buffer, byteOffset, renderedByteLength); - state.writer.write(`${typedArrayBrand(value)}(${byteLength} bytes) [`); - for (let index = 0; index < renderedByteLength; index += 1) { - if (index > 0) { - state.writer.write(" "); - } - state.writer.write(bytes[index]!.toString(16).padStart(2, "0")); - } - state.writer.write("]"); - if (byteLength > renderedByteLength) { - state.writer.markTruncated(); - } -} - -function typedArrayBrand(value: NodeJS.TypedArray): string { - if (IS_BUFFER(value)) { - return "Buffer"; - } - if (utilTypes.isUint8Array(value)) { - return "Uint8Array"; - } - if (utilTypes.isUint8ClampedArray(value)) { - return "Uint8ClampedArray"; - } - if (utilTypes.isUint16Array(value)) { - return "Uint16Array"; - } - if (utilTypes.isUint32Array(value)) { - return "Uint32Array"; - } - if (utilTypes.isInt8Array(value)) { - return "Int8Array"; - } - if (utilTypes.isInt16Array(value)) { - return "Int16Array"; - } - if (utilTypes.isInt32Array(value)) { - return "Int32Array"; - } - if (utilTypes.isFloat32Array(value)) { - return "Float32Array"; - } - if ( - typeof utilTypes.isFloat16Array === "function" - && utilTypes.isFloat16Array(value) - ) { - return "Float16Array"; - } - if (utilTypes.isFloat64Array(value)) { - return "Float64Array"; - } - if (utilTypes.isBigInt64Array(value)) { - return "BigInt64Array"; - } - if (utilTypes.isBigUint64Array(value)) { - return "BigUint64Array"; - } - return "TypedArray"; -} - -function renderArray(state: PreviewState, value: readonly unknown[], depth: number): void { - state.writer.write(`Array(${value.length}) [`); - const entryCount = Math.min(value.length, MAX_CONTAINER_ENTRIES); - for (let index = 0; index < entryCount && !state.writer.isFull; index += 1) { - if (index > 0) { - state.writer.write(", "); - } - const descriptor = Object.getOwnPropertyDescriptor(value, String(index)); - if (descriptor === undefined) { - state.writer.write(""); - } else if ("value" in descriptor) { - renderValue(state, descriptor.value, depth + 1); - } else { - writeTruncatedMarker(state, "[Accessor]"); - } - } - if (value.length > entryCount) { - state.writer.markTruncated(); - } - state.writer.write("]"); -} - -function renderRecord(state: PreviewState, value: Record, depth: number): void { - state.writer.write("{"); - let emittedEntries = 0; - for (const property in value) { - // Ordinary-object enumeration yields own fields before inherited fields. - // Inherited fields are outside the documented preview domain. - if (!Object.hasOwn(value, property)) { - break; - } - if (emittedEntries >= MAX_CONTAINER_ENTRIES) { - state.writer.markTruncated(); - break; - } - if (emittedEntries > 0) { - state.writer.write(", "); - } - if (property.length > MAX_STRING_INPUT_CODE_UNITS) { - writeOversizedStringMarker(state.writer, "PropertyName", property.length); - } else { - writeQuotedString(state.writer, property); - } - state.writer.write(": "); - const descriptor = Object.getOwnPropertyDescriptor(value, property); - if (descriptor === undefined) { - writeTruncatedMarker(state, "[unavailable]"); - } else if ("value" in descriptor) { - renderValue(state, descriptor.value, depth + 1); - } else { - writeTruncatedMarker(state, "[Accessor]"); - } - emittedEntries += 1; - if (state.writer.isFull) { - break; - } - } - state.writer.write("}"); -} - -function writeNumber(writer: Utf8PreviewWriter, value: number): void { - if (Number.isNaN(value)) { - writer.write("NaN"); - } else if (value === Number.POSITIVE_INFINITY) { - writer.write("Infinity"); - } else if (value === Number.NEGATIVE_INFINITY) { - writer.write("-Infinity"); - } else if (Object.is(value, -0)) { - writer.write("-0"); - } else { - writer.write(String(value)); - } -} - -function writeBigInt(writer: Utf8PreviewWriter, value: bigint): void { - if (value <= -MAX_RENDERED_BIGINT_MAGNITUDE || value >= MAX_RENDERED_BIGINT_MAGNITUDE) { - writer.write("[BigInt]"); - writer.markTruncated(); - return; - } - writer.write(`${value}n`); -} - -function writeQuotedString(writer: Utf8PreviewWriter, value: string): void { - if (!writer.write('"')) { - return; - } - for (let index = 0; index < value.length && !writer.isFull;) { - const codePoint = value.codePointAt(index)!; - const character = String.fromCodePoint(codePoint); - if (!writer.write(escapeCharacter(codePoint, character))) { - return; - } - index += character.length; - } - writer.write('"'); -} - -function writeOversizedStringMarker( - writer: Utf8PreviewWriter, - kind: "String" | "PropertyName", - codeUnits: number, -): void { - writer.write(`[${kind} length=${codeUnits} code units]`); - writer.markTruncated(); -} - -function escapeCharacter(codePoint: number, character: string): string { - switch (character) { - case '"': - return '\\"'; - case "\\": - return "\\\\"; - case "\b": - return "\\b"; - case "\f": - return "\\f"; - case "\n": - return "\\n"; - case "\r": - return "\\r"; - case "\t": - return "\\t"; - } - if ( - codePoint < 0x20 - || (codePoint >= 0xd800 && codePoint <= 0xdfff) - || codePoint === 0x2028 - || codePoint === 0x2029 - ) { - return `\\u${codePoint.toString(16).padStart(4, "0")}`; - } - return character; -} - -function writeTruncatedMarker(state: PreviewState, marker: string): void { - state.writer.write(marker); - state.writer.markTruncated(); -} - -function isPlainRecord(value: object): value is Record { - const prototype = Object.getPrototypeOf(value); - return prototype === null || prototype === Object.prototype; -} - -function completeUtf8PrefixLength(bytes: Uint8Array, proposedLength: number): number { - if (proposedLength === 0) { - return 0; - } - let sequenceStart = proposedLength; - while (sequenceStart > 0 && isUtf8ContinuationByte(bytes[sequenceStart]!)) { - sequenceStart -= 1; - } - if (sequenceStart === proposedLength) { - return proposedLength; - } - return sequenceStart; -} - -function isUtf8ContinuationByte(value: number): boolean { - return (value & 0xc0) === 0x80; -} diff --git a/test/dialcache-config-ramp.test.ts b/test/dialcache-config-ramp.test.ts index 37e0e39..eb1b66c 100644 --- a/test/dialcache-config-ramp.test.ts +++ b/test/dialcache-config-ramp.test.ts @@ -45,12 +45,10 @@ describe("DialCache runtime config and ramp controls", () => { shadow: { ramp: 0, logMismatches: false, - logMismatchDetails: false, }, }).shadow).toEqual({ ramp: 0, logMismatches: false, - logMismatchDetails: false, }); }); @@ -58,19 +56,16 @@ describe("DialCache runtime config and ramp controls", () => { const suppliedShadow = { ramp: 25, logMismatches: true, - logMismatchDetails: true, }; const config = new DialCacheKeyConfig({ shadow: suppliedShadow }); suppliedShadow.ramp = 0; suppliedShadow.logMismatches = false; - suppliedShadow.logMismatchDetails = false; expect(config.shadow).not.toBe(suppliedShadow); expect(config.shadow).toEqual({ ramp: 25, logMismatches: true, - logMismatchDetails: true, }); }); @@ -81,7 +76,6 @@ describe("DialCache runtime config and ramp controls", () => { shadow: { ramp: 25, logMismatches: true, - logMismatchDetails: true, }, }); const observedDefaults: Array = []; @@ -105,11 +99,9 @@ describe("DialCache runtime config and ramp controls", () => { const mutableShadow = suppliedDefault.shadow as { ramp?: number; logMismatches?: boolean; - logMismatchDetails?: boolean; }; mutableShadow.ramp = 0; mutableShadow.logMismatches = false; - mutableShadow.logMismatchDetails = false; const first = await dialcache.enable(async () => await getUser("123")); const second = await dialcache.enable(async () => await getUser("123")); @@ -123,7 +115,6 @@ describe("DialCache runtime config and ramp controls", () => { expect(observedDefaults[0]?.shadow).toEqual({ ramp: 25, logMismatches: true, - logMismatchDetails: true, }); expect(Object.isFrozen(observedDefaults[0])).toBe(true); expect(Object.isFrozen(observedDefaults[0]?.ttlSec)).toBe(true); @@ -401,12 +392,6 @@ describe("DialCache runtime config and ramp controls", () => { TypeError, "must be a boolean", ], - [ - "wrong-type shadow mismatch detail flag", - new DialCacheKeyConfig({ shadow: { logMismatchDetails: null as unknown as boolean } }), - TypeError, - "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"], [ @@ -484,7 +469,6 @@ describe("DialCache runtime config and ramp controls", () => { shadow: { ramp: 0, logMismatches: false, - logMismatchDetails: false, }, ramp: { [CacheLayer.LOCAL]: 0, [CacheLayer.REMOTE]: 0 }, })); diff --git a/test/dialcache-observability-internals.test.ts b/test/dialcache-observability-internals.test.ts index a9485a4..b4c8d86 100644 --- a/test/dialcache-observability-internals.test.ts +++ b/test/dialcache-observability-internals.test.ts @@ -18,7 +18,6 @@ describe("DialCache observability internal compatibility paths", () => { shadow: { ramp: 20, logMismatches: true, - logMismatchDetails: true, }, }); const cases = [ @@ -36,7 +35,6 @@ describe("DialCache observability internal compatibility paths", () => { shadow: { ramp: 80, logMismatches: true, - logMismatchDetails: true, }, }), }, @@ -46,7 +44,6 @@ describe("DialCache observability internal compatibility paths", () => { ramp: { [CacheLayer.LOCAL]: 10 }, shadow: { logMismatches: false, - logMismatchDetails: false, }, }), expected: new DialCacheKeyConfig({ @@ -56,7 +53,6 @@ describe("DialCache observability internal compatibility paths", () => { shadow: { ramp: 20, logMismatches: false, - logMismatchDetails: false, }, }), }, @@ -69,7 +65,6 @@ describe("DialCache observability internal compatibility paths", () => { shadow: { ramp: 20, logMismatches: true, - logMismatchDetails: true, }, }), }, @@ -88,7 +83,6 @@ describe("DialCache observability internal compatibility paths", () => { shadow: { ramp: 20, logMismatches: true, - logMismatchDetails: true, }, }); const runtime = { @@ -111,7 +105,6 @@ describe("DialCache observability internal compatibility paths", () => { shadow: { ramp: 20, logMismatches: false, - logMismatchDetails: true, }, })); expect(ignoredLegacyLeaves).toBe(1); diff --git a/test/dialcache-shadow-confirmation.test.ts b/test/dialcache-shadow-confirmation.test.ts index 811acac..95e7e45 100644 --- a/test/dialcache-shadow-confirmation.test.ts +++ b/test/dialcache-shadow-confirmation.test.ts @@ -33,7 +33,7 @@ import { SHADOW_LOG_KEY_MAX_BYTES, SHADOW_LOG_TRUNCATION_MARKER, SHADOW_LOG_VALUE_MAX_BYTES, -} from "../src/internal/shadow-log-preview.js"; +} from "../src/internal/shadow-log-json.js"; import { REMOTE_SHADOW_CACHE_LAYER } from "../src/metrics.js"; interface Deferred { @@ -148,7 +148,6 @@ function remoteConfig( shadowPercentage = 100, logging: { readonly logMismatches?: boolean; - readonly logMismatchDetails?: boolean; } = {}, ): DialCacheKeyConfig { return new DialCacheKeyConfig({ @@ -266,10 +265,7 @@ describe("DialCache Redis shadow confirmation", () => { expect(redis.invalidate).not.toHaveBeenCalled(); }); - it.each([ - { name: "logging is omitted", logging: {} }, - { name: "only detail logging is enabled", logging: { logMismatchDetails: true } }, - ] as const)("does not log confirmed mismatches when $name", async ({ name, logging }) => { + it("does not log confirmed mismatches when logging is omitted", async () => { const payload = JSON.stringify({ id: "private-id", version: 1 }); const redis = new ScriptedRedis([() => payload, () => payload]); const metrics = new RecordingMetrics(); @@ -283,10 +279,8 @@ describe("DialCache Redis shadow confirmation", () => { }); const getUser = dialcache.cached(async () => ({ id: "private-id", version: 2 }), { ...trackedOptions( - name === "logging is omitted" - ? "ShadowMismatchLoggingOff" - : "ShadowMismatchDetailsOnly", - remoteConfig(100, 100, logging), + "ShadowMismatchLoggingOff", + remoteConfig(100), ), cacheKey: () => ({ id: "private-id", @@ -301,7 +295,7 @@ describe("DialCache Redis shadow confirmation", () => { expect(warn).not.toHaveBeenCalled(); }); - it("logs one bounded warning for a served-hit confirmed mismatch", async () => { + it("logs one bounded JSON warning for a served-hit confirmed mismatch", async () => { const payload = JSON.stringify({ id: "private-id", version: 1 }); const redis = new ScriptedRedis([() => payload, () => payload]); const metrics = new RecordingMetrics(); @@ -323,7 +317,7 @@ describe("DialCache Redis shadow confirmation", () => { }); const getUser = dialcache.cached(async () => ({ id: "private-id", version: 2 }), { ...trackedOptions( - "ShadowMismatchMetadata", + "ShadowMismatchJson", remoteConfig(100, 100, { logMismatches: true }), ), cacheKey: () => ({ @@ -340,9 +334,12 @@ describe("DialCache Redis shadow confirmation", () => { "DialCache shadow validation mismatch", { cacheNamespace: "private-namespace", - useCase: "ShadowMismatchMetadata", + useCase: "ShadowMismatchJson", keyType: "user_id", outcome: "mismatch", + cacheKey: "{private-namespace:user_id:private-id}?tenant=private-tenant#ShadowMismatchJson", + cachedValueJson: '{"id":"private-id","version":1}', + sourceValueJson: '{"id":"private-id","version":2}', }, ); await nextImmediate(); @@ -370,10 +367,9 @@ describe("DialCache Redis shadow confirmation", () => { }); const getUser = dialcache.cached(async () => sourceValue, { ...trackedOptions( - "ShadowMismatchDetails", + "ShadowMismatchRampedDownJson", remoteConfig(0, 100, { logMismatches: true, - logMismatchDetails: true, }), ), cacheKey: () => ({ @@ -391,19 +387,18 @@ describe("DialCache Redis shadow confirmation", () => { "DialCache shadow validation mismatch", { cacheNamespace: "urn", - useCase: "ShadowMismatchDetails", + useCase: "ShadowMismatchRampedDownJson", keyType: "user_id", outcome: "mismatch", - cacheKey: "{urn:user_id:123}?locale=en-US#ShadowMismatchDetails", - cachedValuePreview: '{"id": "123", "version": 1}', - sourceValuePreview: '{"id": "123", "version": 2}', - detailsTruncated: false, + cacheKey: "{urn:user_id:123}?locale=en-US#ShadowMismatchRampedDownJson", + cachedValueJson: '{"id":"123","version":1}', + sourceValueJson: '{"id":"123","version":2}', }, ); expect(serializer.dump).not.toHaveBeenCalled(); }); - it("falls back to a metadata warning when detailed preview construction throws", async () => { + it("falls back to a metadata warning when JSON detail construction throws", async () => { const cachedValue = { id: "123", version: 1 }; const sourceValue = { id: "123", version: 2 }; const payload = JSON.stringify(cachedValue); @@ -424,10 +419,9 @@ describe("DialCache Redis shadow confirmation", () => { return await sourceGate.promise; }, { ...trackedOptions( - "ShadowMismatchPreviewFailure", + "ShadowMismatchJsonFailure", remoteConfig(100, 100, { logMismatches: true, - logMismatchDetails: true, }), ), cacheKey: () => "123", @@ -448,7 +442,7 @@ describe("DialCache Redis shadow confirmation", () => { "DialCache shadow validation mismatch", { cacheNamespace: "urn", - useCase: "ShadowMismatchPreviewFailure", + useCase: "ShadowMismatchJsonFailure", keyType: "user_id", outcome: "mismatch", }, @@ -459,7 +453,7 @@ describe("DialCache Redis shadow confirmation", () => { } }); - it("clamps the logical key and both value previews before handing details to the logger", async () => { + it("clamps the logical key and both JSON strings before handing details to the logger", async () => { const id = "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 100); const cachedValue = { id, content: "🙂".repeat(SHADOW_LOG_VALUE_MAX_BYTES) }; const sourceValue = { id, content: "s".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1) }; @@ -476,10 +470,9 @@ describe("DialCache Redis shadow confirmation", () => { }); const getUser = dialcache.cached(async () => sourceValue, { ...trackedOptions( - "ShadowMismatchClampedDetails", + "ShadowMismatchClampedJson", remoteConfig(100, 100, { logMismatches: true, - logMismatchDetails: true, }), ), cacheKey: () => id, @@ -493,11 +486,10 @@ describe("DialCache Redis shadow confirmation", () => { const warning = warn.mock.calls[0]?.[1] as Record; expect(warning).not.toHaveProperty("cachedValue"); expect(warning).not.toHaveProperty("sourceValue"); - expect(warning.detailsTruncated).toBe(true); for (const [field, maxBytes] of [ ["cacheKey", SHADOW_LOG_KEY_MAX_BYTES], - ["cachedValuePreview", SHADOW_LOG_VALUE_MAX_BYTES], - ["sourceValuePreview", SHADOW_LOG_VALUE_MAX_BYTES], + ["cachedValueJson", SHADOW_LOG_VALUE_MAX_BYTES], + ["sourceValueJson", SHADOW_LOG_VALUE_MAX_BYTES], ] as const) { const preview = warning[field]; expect(typeof preview).toBe("string"); @@ -555,7 +547,6 @@ describe("DialCache Redis shadow confirmation", () => { "ShadowMismatchSuperseded", remoteConfig(100, 100, { logMismatches: true, - logMismatchDetails: true, }), ), cacheKey: () => "123", @@ -1395,42 +1386,8 @@ describe("DialCache Redis shadow confirmation", () => { } }); - it.each([ - { - name: "base logging flag", - useCase: "ShadowInvalidLoggingBase", - runtimeShadow: { - logMismatches: "yes" as never, - }, - expectedWarning: null, - }, - { - name: "detail logging flag", - useCase: "ShadowInvalidLoggingDetails", - runtimeShadow: { - logMismatchDetails: "yes" as never, - }, - expectedWarning: { - cacheNamespace: "urn", - useCase: "ShadowInvalidLoggingDetails", - keyType: "user_id", - outcome: "mismatch", - }, - }, - { - name: "both logging flags", - useCase: "ShadowInvalidLoggingBoth", - runtimeShadow: { - logMismatches: "yes" as never, - logMismatchDetails: "yes" as never, - }, - expectedWarning: null, - }, - ] as const)("fails closed for an invalid runtime $name without suppressing mismatch metrics", async ({ - useCase, - runtimeShadow, - expectedWarning, - }) => { + it("fails closed for invalid runtime mismatch logging without suppressing the metric", async () => { + const useCase = "ShadowInvalidLogging"; const cachedValue = { id: "123", version: 1 }; const sourceValue = { id: "123", version: 2 }; const payload = JSON.stringify(cachedValue); @@ -1439,7 +1396,7 @@ describe("DialCache Redis shadow confirmation", () => { const warn = vi.fn(); const dialcache = createCache(redis, metrics, { cacheConfigProvider: async () => new DialCacheKeyConfig({ - shadow: runtimeShadow, + shadow: { logMismatches: "yes" as never }, }), logger: { debug: () => undefined, @@ -1452,7 +1409,6 @@ describe("DialCache Redis shadow confirmation", () => { useCase, remoteConfig(100, 100, { logMismatches: true, - logMismatchDetails: true, }), ), cacheKey: () => "123", @@ -1467,14 +1423,7 @@ describe("DialCache Redis shadow confirmation", () => { && labels.layer === CacheLayer.REMOTE && labels.error === "config_resolution" )).toHaveLength(1); - if (expectedWarning === null) { - expect(warn).not.toHaveBeenCalled(); - } else { - expect(warn).toHaveBeenCalledWith( - "DialCache shadow validation mismatch", - expectedWarning, - ); - } + expect(warn).not.toHaveBeenCalled(); }); it("treats DialCacheKeyConfig.disabled() as a complete shadow kill switch", async () => { diff --git a/test/dialcache-shadow-validation.test.ts b/test/dialcache-shadow-validation.test.ts index 06668e9..34698d2 100644 --- a/test/dialcache-shadow-validation.test.ts +++ b/test/dialcache-shadow-validation.test.ts @@ -375,7 +375,7 @@ describe("DialCache Redis shadow validation", () => { error, }, { cacheConfigProvider: async () => new DialCacheKeyConfig({ - shadow: { logMismatchDetails: "yes" as never }, + shadow: { logMismatches: "yes" as never }, }), logger: { debug: () => undefined, @@ -391,7 +391,6 @@ describe("DialCache Redis shadow validation", () => { shadow: { ramp: 100, logMismatches: true, - logMismatchDetails: true, }, }), cacheKey: () => "123", diff --git a/test/shadow-log-json.test.ts b/test/shadow-log-json.test.ts new file mode 100644 index 0000000..22b1707 --- /dev/null +++ b/test/shadow-log-json.test.ts @@ -0,0 +1,62 @@ +import { describe, expect, it } from "vitest"; + +import { + SHADOW_LOG_KEY_MAX_BYTES, + SHADOW_LOG_TRUNCATION_MARKER, + SHADOW_LOG_VALUE_MAX_BYTES, + previewShadowLogJson, + previewShadowLogKey, + shadowMismatchLogDetails, +} from "../src/internal/shadow-log-json.js"; + +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("returns null independently 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(1n)).toBeNull(); + expect(previewShadowLogJson(undefined)).toBeNull(); + }); + + it("catches user JSON hook failures", () => { + const value = { + toJSON(): never { + throw new Error("not serializable"); + }, + }; + + expect(previewShadowLogJson(value)).toBeNull(); + }); + + 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(valuePreview).not.toBeNull(); + 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(valuePreview!.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); + expect(keyPreview).not.toContain("\uFFFD"); + expect(valuePreview).not.toContain("\uFFFD"); + }); +}); diff --git a/test/shadow-log-preview.test.ts b/test/shadow-log-preview.test.ts deleted file mode 100644 index 5afebc9..0000000 --- a/test/shadow-log-preview.test.ts +++ /dev/null @@ -1,531 +0,0 @@ -import { inspect, types as utilTypes } from "node:util"; - -import { describe, expect, it, vi } from "vitest"; - -import { - SHADOW_LOG_KEY_MAX_BYTES, - SHADOW_LOG_TRUNCATION_MARKER, - SHADOW_LOG_VALUE_MAX_BYTES, - previewShadowLogKey, - previewShadowLogValue, - shadowMismatchLogDetails, -} from "../src/internal/shadow-log-preview.js"; - -describe("shadow mismatch log previews", () => { - it("keeps exact-limit strings and byte-clamps oversized ASCII and Unicode strings", () => { - expect(previewShadowLogKey("")).toEqual({ - text: "", - truncated: false, - }); - - const exact = "a".repeat(SHADOW_LOG_KEY_MAX_BYTES); - const exactKeyPreview = previewShadowLogKey(exact); - expect(exactKeyPreview).toEqual({ - text: exact, - truncated: false, - }); - expect(Buffer.byteLength(exactKeyPreview.text)).toBe(SHADOW_LOG_KEY_MAX_BYTES); - - const exactValue = "v".repeat(SHADOW_LOG_VALUE_MAX_BYTES - 2); - const exactValuePreview = previewShadowLogValue(exactValue); - expect(exactValuePreview).toEqual({ - text: `"${exactValue}"`, - truncated: false, - }); - expect(Buffer.byteLength(exactValuePreview.text)).toBe(SHADOW_LOG_VALUE_MAX_BYTES); - - for (const oversized of [ - "a".repeat(SHADOW_LOG_KEY_MAX_BYTES + 1), - `${"a".repeat(SHADOW_LOG_KEY_MAX_BYTES - 1)}🙂`, - ]) { - const preview = previewShadowLogKey(oversized); - - expect(preview.truncated).toBe(true); - expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); - expect(preview.text).not.toContain("\uFFFD"); - } - }); - - it("rolls byte-clipped keys back to a complete two-, three-, or four-byte UTF-8 sequence", () => { - const contentLimit = SHADOW_LOG_KEY_MAX_BYTES - Buffer.byteLength(SHADOW_LOG_TRUNCATION_MARKER); - - for (const character of ["é", "€", "🙂"]) { - const prefix = "a".repeat(contentLimit - 1); - const preview = previewShadowLogKey( - `${prefix}${character}${"z".repeat(SHADOW_LOG_KEY_MAX_BYTES)}`, - ); - - expect(preview).toEqual({ - text: `${prefix}${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, - }); - expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); - expect(preview.text).not.toContain("\uFFFD"); - } - }); - - it("uses length-only markers before inspecting very large rope strings", () => { - let rope = "x"; - for (let index = 0; index < 17; index += 1) { - rope += rope; - } - expect(rope.length).toBe(131_072); - const marker = `[String length=${rope.length} code units]${SHADOW_LOG_TRUNCATION_MARKER}`; - - expect(previewShadowLogKey(rope)).toEqual({ - text: marker, - truncated: true, - }); - expect(previewShadowLogValue(rope)).toEqual({ - text: marker, - truncated: true, - }); - expect(previewShadowLogValue({ [rope]: 1 })).toEqual({ - text: `{[PropertyName length=${rope.length} code units]: 1}${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, - }); - }); - - it("renders supported primitives and escaped strings without truncation", () => { - expect(previewShadowLogValue({ - undefined, - null: null, - text: "\"line\n\u2028", - values: [true, false, 1, -0, Number.NaN, Number.POSITIVE_INFINITY, Number.NEGATIVE_INFINITY, 12n], - })).toEqual({ - text: '{"undefined": undefined, "null": null, "text": "\\"line\\n\\u2028", ' - + '"values": Array(8) [true, false, 1, -0, NaN, Infinity, -Infinity, 12n]}', - truncated: false, - }); - }); - - it("escapes every supported string control and separator sequence", () => { - const cases = [ - ['"', '\\"'], - ["\\", "\\\\"], - ["\b", "\\b"], - ["\f", "\\f"], - ["\n", "\\n"], - ["\r", "\\r"], - ["\t", "\\t"], - ["\u0000", "\\u0000"], - ["\u001f", "\\u001f"], - ["\u2028", "\\u2028"], - ["\u2029", "\\u2029"], - ["\ud800", "\\ud800"], - ["\udfff", "\\udfff"], - ] as const; - - for (const [input, escaped] of cases) { - expect(previewShadowLogValue(input)).toEqual({ - text: `"${escaped}"`, - truncated: false, - }); - } - }); - - it("bounds large values and aggregates field truncation", () => { - const details = shadowMismatchLogDetails( - "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 1), - "c".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), - "s".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), - ); - - expect(details.detailsTruncated).toBe(true); - expect(Buffer.byteLength(details.cacheKey)).toBeLessThanOrEqual(SHADOW_LOG_KEY_MAX_BYTES); - expect(Buffer.byteLength(details.cachedValuePreview)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); - expect(Buffer.byteLength(details.sourceValuePreview)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); - expect(details.cacheKey.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - expect(details.cachedValuePreview.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - expect(details.sourceValuePreview.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - }); - - it("aggregates byte and structural truncation from each detail field independently", () => { - const cases = [ - { - name: "cache key", - details: shadowMismatchLogDetails( - "k".repeat(SHADOW_LOG_KEY_MAX_BYTES + 1), - "cached", - "source", - ), - truncatedField: "cacheKey", - }, - { - name: "cached value", - details: shadowMismatchLogDetails( - "key", - "c".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), - "source", - ), - truncatedField: "cachedValuePreview", - }, - { - name: "source value", - details: shadowMismatchLogDetails( - "key", - "cached", - "s".repeat(SHADOW_LOG_VALUE_MAX_BYTES + 1), - ), - truncatedField: "sourceValuePreview", - }, - { - name: "structurally unsupported cached value", - details: shadowMismatchLogDetails("key", new Map([["key", "value"]]), "source"), - truncatedField: "cachedValuePreview", - }, - ] as const; - - for (const { name, details, truncatedField } of cases) { - expect(details.detailsTruncated, name).toBe(true); - expect( - (["cacheKey", "cachedValuePreview", "sourceValuePreview"] as const) - .filter((field) => details[field].endsWith(SHADOW_LOG_TRUNCATION_MARKER)), - name, - ).toEqual([truncatedField]); - } - }); - - it("limits depth, entry count, node count, large BigInts, and opaque values", () => { - const deep = { one: { two: { three: { four: { five: "hidden" } } } } }; - const wide = Object.fromEntries(Array.from({ length: 40 }, (_, index) => [`key${index}`, index])); - const manyNodes = Array.from({ length: 32 }, () => [1, 2, 3, 4, 5]); - - for (const value of [ - deep, - wide, - manyNodes, - 10n ** 100n, - Symbol("symbol"), - () => undefined, - Promise.resolve(), - new WeakMap(), - new WeakSet(), - new Proxy(() => undefined, {}), - ]) { - const preview = previewShadowLogValue(value); - - expect(preview.truncated).toBe(true); - expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); - } - }); - - it("renders dates with intrinsic methods and distinguishes different timestamps", () => { - const valueOf = vi.fn(() => { - throw new Error("overridden valueOf invoked"); - }); - const toISOString = vi.fn(() => { - throw new Error("overridden toISOString invoked"); - }); - const hostileDate = new Date("2026-07-30T00:00:00.000Z"); - Object.defineProperties(hostileDate, { - valueOf: { value: valueOf }, - toISOString: { value: toISOString }, - }); - - expect(previewShadowLogValue(hostileDate)).toEqual({ - text: "Date(2026-07-30T00:00:00.000Z)", - truncated: false, - }); - expect(previewShadowLogValue(new Date("2026-07-31T00:00:00.000Z"))).toEqual({ - text: "Date(2026-07-31T00:00:00.000Z)", - truncated: false, - }); - expect(previewShadowLogValue(new Date(Number.NaN))).toEqual({ - text: "Date(Invalid)", - truncated: false, - }); - expect(previewShadowLogValue({ updatedAt: hostileDate })).toEqual({ - text: '{"updatedAt": Date(2026-07-30T00:00:00.000Z)}', - truncated: false, - }); - expect(valueOf).not.toHaveBeenCalled(); - expect(toISOString).not.toHaveBeenCalled(); - }); - - it("renders collection sizes without invoking instance hooks or iterators", () => { - const hook = vi.fn(() => { - throw new Error("collection hook invoked"); - }); - const map = new Map([["a", 1], ["b", 2]]); - const set = new Set(["a", "b", "c"]); - Object.defineProperties(map, { - size: { get: hook }, - entries: { value: hook }, - [Symbol.iterator]: { value: hook }, - }); - Object.defineProperties(set, { - size: { get: hook }, - values: { value: hook }, - [Symbol.iterator]: { value: hook }, - }); - - expect(previewShadowLogValue(new Map())).toEqual({ - text: "Map(0)", - truncated: false, - }); - expect(previewShadowLogValue(new Set())).toEqual({ - text: "Set(0)", - truncated: false, - }); - expect(previewShadowLogValue(map)).toEqual({ - text: `Map(2)${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, - }); - expect(previewShadowLogValue(set)).toEqual({ - text: `Set(3)${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, - }); - expect(hook).not.toHaveBeenCalled(); - }); - - it("renders bounded raw bytes for buffers and every supported typed-array brand", () => { - expect(previewShadowLogValue(Buffer.from([0, 1, 255]))).toEqual({ - text: "Buffer(3 bytes) [00 01 ff]", - truncated: false, - }); - - const typedArrays = [ - ["Uint8Array", new Uint8Array(1)], - ["Uint8ClampedArray", new Uint8ClampedArray(1)], - ["Uint16Array", new Uint16Array(1)], - ["Uint32Array", new Uint32Array(1)], - ["Int8Array", new Int8Array(1)], - ["Int16Array", new Int16Array(1)], - ["Int32Array", new Int32Array(1)], - ["Float32Array", new Float32Array(1)], - ["Float64Array", new Float64Array(1)], - ["BigInt64Array", new BigInt64Array(1)], - ["BigUint64Array", new BigUint64Array(1)], - ] as const; - - for (const [name, value] of typedArrays) { - expect(previewShadowLogValue(value)).toEqual({ - text: `${name}(${value.byteLength} bytes) [${Array.from( - { length: value.byteLength }, - () => "00", - ).join(" ")}]`, - truncated: false, - }); - } - - const oversized = Uint8Array.from({ length: 65 }, (_, index) => index); - const oversizedPreview = previewShadowLogValue(oversized); - expect(oversizedPreview.truncated).toBe(true); - expect(oversizedPreview.text).toBe( - `Uint8Array(65 bytes) [${Array.from( - { length: 64 }, - (_, index) => index.toString(16).padStart(2, "0"), - ).join(" ")}]${SHADOW_LOG_TRUNCATION_MARKER}`, - ); - expect(Buffer.byteLength(oversizedPreview.text)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); - }); - - it("keeps later typed-array brands working on the Node 22.0 util.types surface", () => { - const descriptor = Object.getOwnPropertyDescriptor(utilTypes, "isFloat16Array"); - expect(descriptor).toBeDefined(); - Reflect.deleteProperty(utilTypes, "isFloat16Array"); - - try { - expect(previewShadowLogValue(new Float64Array(1))).toEqual({ - text: "Float64Array(8 bytes) [00 00 00 00 00 00 00 00]", - truncated: false, - }); - expect(previewShadowLogValue(new BigUint64Array(1))).toEqual({ - text: "BigUint64Array(8 bytes) [00 00 00 00 00 00 00 00]", - truncated: false, - }); - } finally { - Object.defineProperty(utilTypes, "isFloat16Array", descriptor!); - } - }); - - it("reads binary metadata through intrinsics instead of instance overrides", () => { - const hook = vi.fn(() => { - throw new Error("typed-array hook invoked"); - }); - const value = Uint8Array.from([5, 6]); - Object.defineProperties(value, { - buffer: { get: hook }, - byteOffset: { get: hook }, - byteLength: { get: hook }, - constructor: { get: hook }, - [Symbol.iterator]: { value: hook }, - }); - - expect(previewShadowLogValue(value)).toEqual({ - text: "Uint8Array(2 bytes) [05 06]", - truncated: false, - }); - expect(hook).not.toHaveBeenCalled(); - }); - - it("fails closed for a detached typed-array buffer", () => { - const value = Uint8Array.from([1, 2]); - structuredClone(value.buffer, { transfer: [value.buffer] }); - - expect(previewShadowLogValue(value)).toEqual({ - text: `[unavailable]${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, - }); - }); - - it("keeps unsupported exotic and class instances opaque", () => { - class Example { - readonly visible = true; - } - const values = [ - new DataView(Uint8Array.from([3, 4]).buffer), - Uint8Array.from([5, 6]).buffer, - /cache/giu, - new Error("nope"), - new Example(), - ]; - - const previews = values.map((value) => previewShadowLogValue(value)); - - expect(previews).toEqual(values.map(() => ({ - text: `[Object]${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, - }))); - }); - - it("bounds arrays by their indexed entry limit", () => { - const sparse = Array.from({ length: 40 }, (_, index) => index); - delete sparse[1]; - Object.defineProperty(sparse, "2", { get: () => 2, enumerable: true }); - - const preview = previewShadowLogValue(sparse); - - expect(preview.truncated).toBe(true); - expect(preview.text).toContain(""); - expect(preview.text).toContain("[Accessor]"); - expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - }); - - it("does not invoke accessors, serializers, custom inspectors, or proxy traps", () => { - const getter = vi.fn(() => { - throw new Error("getter invoked"); - }); - const toJSON = vi.fn(() => { - throw new Error("toJSON invoked"); - }); - const customInspect = vi.fn(() => { - throw new Error("custom inspect invoked"); - }); - const value: Record = { toJSON }; - Object.defineProperty(value, "secret", { enumerable: true, get: getter }); - Object.defineProperty(value, Symbol.toStringTag, { get: getter }); - value[inspect.custom] = customInspect; - value.self = value; - - const ownKeys = vi.fn(() => { - throw new Error("proxy reflected"); - }); - const proxy = new Proxy({}, { ownKeys }); - const revocable = Proxy.revocable({}, {}); - revocable.revoke(); - const regexp = /safe/g; - Object.defineProperty(regexp, "global", { get: getter }); - const typedArray = new Uint8Array([1, 2]); - Object.defineProperties(typedArray, { - buffer: { get: getter }, - byteOffset: { get: getter }, - byteLength: { get: getter }, - }); - - const recordPreview = previewShadowLogValue(value); - const proxyPreview = previewShadowLogValue(proxy); - const revokedPreview = previewShadowLogValue(revocable.proxy); - const regexpPreview = previewShadowLogValue(regexp); - const typedArrayPreview = previewShadowLogValue(typedArray); - - expect(recordPreview.truncated).toBe(true); - expect(recordPreview.text).toContain("[Accessor]"); - expect(recordPreview.text).toContain("[Circular]"); - expect(getter).not.toHaveBeenCalled(); - expect(toJSON).not.toHaveBeenCalled(); - expect(customInspect).not.toHaveBeenCalled(); - expect(regexpPreview).toEqual({ - text: `[Object]${SHADOW_LOG_TRUNCATION_MARKER}`, - truncated: true, - }); - expect(typedArrayPreview).toEqual({ - text: "Uint8Array(2 bytes) [01 02]", - truncated: false, - }); - expect(proxyPreview.text).toBe(`[Proxy]${SHADOW_LOG_TRUNCATION_MARKER}`); - expect(revokedPreview.text).toBe(`[Proxy]${SHADOW_LOG_TRUNCATION_MARKER}`); - expect(ownKeys).not.toHaveBeenCalled(); - }); - - it("limits its JSON-like domain to array indexes and enumerable string-keyed record fields", () => { - const hidden = Symbol("hidden"); - const record: Record = { visible: 1 }; - Object.defineProperty(record, "nonEnumerable", { value: 2 }); - record[hidden] = 3; - const array = [1] as unknown[] & Record; - array.extra = 2; - array[hidden] = 3; - - expect(previewShadowLogValue(record)).toEqual({ - text: '{"visible": 1}', - truncated: false, - }); - expect(previewShadowLogValue(array)).toEqual({ - text: "Array(1) [1]", - truncated: false, - }); - }); - - it("ignores inherited enumerable fields without reporting truncation", () => { - const inheritedFields = Array.from({ length: 65 }, (_, index) => `__dialcache_preview_${index}`); - const preview = (() => { - try { - for (const [index, field] of inheritedFields.entries()) { - Object.defineProperty(Object.prototype, field, { - value: index, - enumerable: true, - configurable: true, - }); - } - return previewShadowLogValue({ visible: 1 }); - } finally { - for (const field of inheritedFields) { - delete (Object.prototype as Record)[field]; - } - } - })(); - - expect(preview).toEqual({ - text: '{"visible": 1}', - truncated: false, - }); - }); - - it("does not render a value after an oversized property name fills the preview", () => { - const preview = previewShadowLogValue({ - ["p".repeat(SHADOW_LOG_VALUE_MAX_BYTES)]: "must-not-appear", - }); - - expect(preview.truncated).toBe(true); - expect(preview.text).not.toContain("must-not-appear"); - expect(preview.text.endsWith(SHADOW_LOG_TRUNCATION_MARKER)).toBe(true); - expect(Buffer.byteLength(preview.text)).toBeLessThanOrEqual(SHADOW_LOG_VALUE_MAX_BYTES); - }); - - it("marks detailed output complete only when every field is complete", () => { - expect(shadowMismatchLogDetails( - "{urn:user_id:123}#Example", - { id: "123", version: 1 }, - { id: "123", version: 2 }, - )).toEqual({ - cacheKey: "{urn:user_id:123}#Example", - cachedValuePreview: '{"id": "123", "version": 1}', - sourceValuePreview: '{"id": "123", "version": 2}', - detailsTruncated: false, - }); - }); -}); From 886a57e765b1aae750bd1879036bdeca9587c817 Mon Sep 17 00:00:00 2001 From: Lev Neiman Date: Fri, 31 Jul 2026 11:29:22 -0700 Subject: [PATCH 6/6] refactor: remove shadow config compatibility path --- README.md | 4 +- src/dialcache.ts | 6 +-- src/internal/runtime-config.ts | 22 +++------ test/dialcache-config-ramp.test.ts | 1 + test/dialcache-metrics.test.ts | 48 ------------------- .../dialcache-observability-internals.test.ts | 47 ------------------ 6 files changed, 10 insertions(+), 118 deletions(-) diff --git a/README.md b/README.md index 54d06e5..7d6b4c1 100644 --- a/README.md +++ b/README.md @@ -221,7 +221,7 @@ DialCache validates `defaultConfig` when `cached()` registers a definition and w 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, or explicit `remoteReadTimeoutMs` fails config resolution for the invocation, records `config_error`, and executes the fallback uncached without attempting Redis. The removed top-level `shadowRamp` field is the one compatibility exception for raw provider results: DialCache ignores that leaf, applies every other valid overlay field, and records one remote `config_resolution` error for that resolution. The public `DialCacheKeyConfig` constructor and static defaults still 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, 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`. 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. @@ -557,7 +557,7 @@ The initial `C0` read and later fill are not atomic. The fill is a normal tracke A served-hit sample invokes the wrapped function or inline loader as an additional source read, so that loader must be safe to call for observation. A ramped-down sample reuses the caller's ordinary invocation and does not add another SoT call. -For valid policies, shadow-specific source calls, cache-path Redis traffic, returned values, and metrics are unchanged when `shadow` is omitted or `shadow.ramp` is `0`. Shadow policy is grouped under `DialCacheKeyConfig.shadow`; consumers of the former flat ramp field must migrate to `shadow: { ramp }`. The public constructor and static defaults reject the removed field, while raw runtime provider results ignore and report that legacy leaf as described above. `DialCacheKeyConfig.disabled()` explicitly sets the shadow ramp and both logging gates to their disabled values. `shadowComparator` remains a typed `cached()` / `getOrLoad()` option because it defines stable use-case equality, while `shadowMaxInFlight` remains a per-instance concurrency limit. The clean-miss bootstrap adds no additional ramp knob, Redis protocol operation, metric instrument, or label key; enabling shadowing authorizes the tracked Redis write described above. Exported unions include `remote_shadow` in `MetricLayer` and `superseded`, `filled`, `fill_blocked`, `fill_error`, `redis_error`, and `confirmation_error` in `ShadowValidationOutcome`. TypeScript consumers with exhaustive switches or `Record` values must include those cases, and dashboards restricted to `layer="remote"` intentionally exclude detached traffic. +For valid policies, shadow-specific source calls, cache-path Redis traffic, returned values, and metrics are unchanged when `shadow` is omitted or `shadow.ramp` is `0`. Shadow policy is grouped under `DialCacheKeyConfig.shadow`; consumers of the former flat ramp field must migrate to `shadow: { ramp }`. The public constructor, static defaults, and runtime provider results reject the removed field. `DialCacheKeyConfig.disabled()` explicitly disables the shadow ramp and mismatch logging. `shadowComparator` remains a typed `cached()` / `getOrLoad()` option because it defines stable use-case equality, while `shadowMaxInFlight` remains a per-instance concurrency limit. The clean-miss bootstrap adds no additional ramp knob, Redis protocol operation, metric instrument, or label key; enabling shadowing authorizes the tracked Redis write described above. Exported unions include `remote_shadow` in `MetricLayer` and `superseded`, `filled`, `fill_blocked`, `fill_error`, `redis_error`, and `confirmation_error` in `ShadowValidationOutcome`. TypeScript consumers with exhaustive switches or `Record` values must include those cases, and dashboards restricted to `layer="remote"` intentionally exclude detached traffic. ## Cached-value ownership diff --git a/src/dialcache.ts b/src/dialcache.ts index 4cb261f..90f3eca 100644 --- a/src/dialcache.ts +++ b/src/dialcache.ts @@ -439,11 +439,7 @@ export class DialCache { let keyConfig: DialCacheKeyConfig | null; try { - keyConfig = await fetchKeyConfig( - this.configProvider, - key, - () => this.recordError(key, CacheLayer.REMOTE, "config_resolution"), - ); + keyConfig = await fetchKeyConfig(this.configProvider, key); } 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); diff --git a/src/internal/runtime-config.ts b/src/internal/runtime-config.ts index 4ead4c1..fec7c4e 100644 --- a/src/internal/runtime-config.ts +++ b/src/internal/runtime-config.ts @@ -37,14 +37,13 @@ interface ResolveLayerConfigOptions { export async function fetchKeyConfig( configProvider: CacheConfigProvider, key: DialCacheKey, - onIgnoredRuntimeShadowRamp?: () => void, ): Promise { const defaultConfig = key.defaultConfig; const runtimeConfig = (await configProvider(key)) as DialCacheKeyConfig | null | undefined; if (runtimeConfig === null || runtimeConfig === undefined) { return defaultConfig; } - return mergeKeyConfig(defaultConfig, runtimeConfig, onIgnoredRuntimeShadowRamp); + return mergeKeyConfig(defaultConfig, runtimeConfig); } export function resolveLayerConfig(options: ResolveLayerConfigOptions): ResolvedLayerConfig | null { @@ -95,11 +94,10 @@ export function resolveLayerConfigResult(options: ResolveLayerConfigOptions): La function mergeKeyConfig( defaultConfig: DialCacheKeyConfig | null, runtimeConfig: DialCacheKeyConfig | null | undefined, - onIgnoredRuntimeShadowRamp?: () => void, ): DialCacheKeyConfig { const overlay = runtimeConfig ?? undefined; assertKeyConfig(defaultConfig); - assertKeyConfigShape(overlay); + assertKeyConfig(overlay); const defaultRequestLocal = defaultConfig?.requestLocal; const overlayRequestLocal = overlay?.requestLocal; const requestLocal = overlayRequestLocal !== undefined @@ -112,30 +110,22 @@ function mergeKeyConfig( : defaultConfig?.remoteReadTimeoutMs; const shadow = mergeShadowConfig(defaultConfig?.shadow, overlay?.shadow); - const merged = new DialCacheKeyConfig({ + return new DialCacheKeyConfig({ ttlSec: mergeLayerConfig(defaultConfig?.ttlSec, overlay?.ttlSec, "ttlSec"), ramp: mergeLayerConfig(defaultConfig?.ramp, overlay?.ramp, "ramp"), requestLocal, ...(remoteReadTimeoutMs === undefined ? {} : { remoteReadTimeoutMs }), ...(shadow === undefined ? {} : { shadow }), }); - if (overlay !== undefined && Object.hasOwn(overlay, "shadowRamp")) { - onIgnoredRuntimeShadowRamp?.(); - } - return merged; } function assertKeyConfig(config: DialCacheKeyConfig | null | undefined): void { - assertKeyConfigShape(config); - if (config !== null && config !== undefined && Object.hasOwn(config, "shadowRamp")) { - throw new TypeError('DialCacheKeyConfig.shadowRamp was replaced by "shadow.ramp"'); - } -} - -function assertKeyConfigShape(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( diff --git a/test/dialcache-config-ramp.test.ts b/test/dialcache-config-ramp.test.ts index eb1b66c..0a1d9c3 100644 --- a/test/dialcache-config-ramp.test.ts +++ b/test/dialcache-config-ramp.test.ts @@ -443,6 +443,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 null requestLocal value", { ttlSec: {}, ramp: {}, requestLocal: null }], ] as const)("fails open instead of inheriting defaults when the provider returns %s", async (_name, runtimeConfig) => { const cacheConfigProvider = vi.fn(async () => runtimeConfig as unknown as DialCacheKeyConfig); diff --git a/test/dialcache-metrics.test.ts b/test/dialcache-metrics.test.ts index 4882781..15f5fa1 100644 --- a/test/dialcache-metrics.test.ts +++ b/test/dialcache-metrics.test.ts @@ -668,54 +668,6 @@ describe("DialCache observability metrics", () => { expect(JSON.stringify(events(metrics, "error", {}))).not.toMatch(/Tenant123ConfigProviderError|tenant-123/); }); - it("reports a stale runtime shadowRamp leaf without disabling inherited cache layers", async () => { - const metrics = new RecordingMetrics(); - const redis = new FakeRedis(); - const cacheConfigProvider = vi.fn(async () => ({ - shadowRamp: 50, - } as unknown as DialCacheKeyConfig)); - const dialcache = new DialCache({ - redis: { client: redis, readTimeoutMs: 1_000 }, - metrics, - cacheConfigProvider, - }); - const source = vi.fn(async (id: string) => ({ id, source: "fallback" })); - const getUser = dialcache.cached(source, { - keyType: "user_id", - useCase: "IgnoredRuntimeShadowRamp", - cacheKey: (id) => id, - defaultConfig: new DialCacheKeyConfig({ - ttlSec: { - [CacheLayer.LOCAL]: 60, - [CacheLayer.REMOTE]: 60, - }, - ramp: { - [CacheLayer.LOCAL]: 100, - [CacheLayer.REMOTE]: 100, - }, - }), - }); - - const first = await dialcache.enable(async () => await getUser("123")); - const second = await dialcache.enable(async () => await getUser("123")); - - expect(second).toBe(first); - expect(source).toHaveBeenCalledOnce(); - expect(cacheConfigProvider).toHaveBeenCalledTimes(2); - expect(redis.getCalls).toBe(1); - expect(redis.setCalls).toBe(1); - expect(events(metrics, "error", { - useCase: "IgnoredRuntimeShadowRamp", - layer: CacheLayer.REMOTE, - error: "config_resolution", - inFallback: false, - })).toHaveLength(2); - expect(events(metrics, "disabled", { - useCase: "IgnoredRuntimeShadowRamp", - reason: "config_error", - })).toHaveLength(0); - }); - it("classifies local cache reads and writes", async () => { const metrics = new RecordingMetrics(); const logger = { debug: vi.fn(), warn: vi.fn(), error: vi.fn() }; diff --git a/test/dialcache-observability-internals.test.ts b/test/dialcache-observability-internals.test.ts index b4c8d86..96915e4 100644 --- a/test/dialcache-observability-internals.test.ts +++ b/test/dialcache-observability-internals.test.ts @@ -75,53 +75,6 @@ describe("DialCache observability internal compatibility paths", () => { } }); - it("ignores and reports a legacy runtime shadowRamp leaf after merging valid leaves", async () => { - const defaultConfig = new DialCacheKeyConfig({ - requestLocal: true, - ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 120 }, - ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 50 }, - shadow: { - ramp: 20, - logMismatches: true, - }, - }); - const runtime = { - shadowRamp: 80, - ramp: { [CacheLayer.REMOTE]: 75 }, - shadow: { logMismatches: false }, - } as unknown as DialCacheKeyConfig; - let ignoredLegacyLeaves = 0; - - await expect(fetchKeyConfig( - async () => runtime, - key(defaultConfig), - () => { - ignoredLegacyLeaves += 1; - }, - )).resolves.toEqual(new DialCacheKeyConfig({ - requestLocal: true, - ttlSec: { [CacheLayer.LOCAL]: 60, [CacheLayer.REMOTE]: 120 }, - ramp: { [CacheLayer.LOCAL]: 25, [CacheLayer.REMOTE]: 75 }, - shadow: { - ramp: 20, - logMismatches: false, - }, - })); - expect(ignoredLegacyLeaves).toBe(1); - - await expect(fetchKeyConfig( - async () => ({ - shadowRamp: 80, - shadow: [], - } as unknown as DialCacheKeyConfig), - key(defaultConfig), - () => { - ignoredLegacyLeaves += 1; - }, - )).rejects.toThrow("DialCache shadow config must be an object"); - expect(ignoredLegacyLeaves).toBe(1); - }); - it("keeps LocalCache get/getIfPresent compatibility while exposing disabled reads", async () => { // Given a local cache with enabled config and a second key with no config. const cache = new LocalCache(async () => null, 10);