diff --git a/lib/project-sessions.js b/lib/project-sessions.js index 6d7df57d..4f1a7347 100644 --- a/lib/project-sessions.js +++ b/lib/project-sessions.js @@ -693,6 +693,18 @@ function attachSessions(ctx) { memAvailableMB: memAvailMB, activeLiveCount: memStats.activeLiveCount !== undefined ? memStats.activeLiveCount : null, maxConcurrentSessions: memStats.maxConcurrentSessions !== undefined ? memStats.maxConcurrentSessions : null, + // lr-58c813: baseline instrumentation for the lr-5edd64 redesign — + // count of session.isProcessing !== sessionActivity.isSessionActive(session) + // divergences observed since daemon start, plus a bounded ring + // buffer of the most recent occurrences. Read-only counter; does not + // reflect or affect what any renderer displays. Samples carry no + // session identifier (BOBBIE finding): this handler has no + // admin/role gate, unlike its update_now/kill_process siblings, so + // any authenticated client on a shared project could otherwise read + // another user's session id through it. Fixing that pre-existing + // gate gap is out of scope for this instrumentation-only PR. + activityDivergenceCount: memStats.activityDivergenceCount !== undefined ? memStats.activityDivergenceCount : null, + activityDivergenceRecentSamples: memStats.activityDivergenceRecentSamples || [], }); return true; } diff --git a/lib/public/app.js b/lib/public/app.js index 556338d9..8b638f76 100644 --- a/lib/public/app.js +++ b/lib/public/app.js @@ -67,6 +67,7 @@ import { initDm, openDm as _dmOpenDm, enterDmMode as _dmEnterDmMode, exitDmMode import { initMention, handleMentionStart, handleMentionStream, handleMentionDone, handleMentionError, handleMentionActivity, renderMentionUser, renderMentionResponse } from './modules/mention.js'; import { initTeamPanel } from './modules/team-panel.js'; import { initDiagnostics } from './modules/diagnostics.js'; +import { getActivityEdgeLedger } from './modules/activity-latch.js'; // --- Base path for multi-project routing --- var slugMatch = location.pathname.match(/^\/p\/([a-z0-9_-]+)/); @@ -1034,6 +1035,12 @@ import { initDiagnostics } from './modules/diagnostics.js'; // --- Diagnostics panel (lr-8294, epic lr-1a52) --- initDiagnostics(); + // lr-58c813: expose the client-side activity-edge accept/reject ledger for + // production retrieval without a debugger — open devtools console and run + // `window.__clagenticActivityLedger()`. Read-only accessor over a plain + // counter object (activity-latch.js); does not affect rendering. + window.__clagenticActivityLedger = getActivityEdgeLedger; + // --- Messages module (uses direct imports, no ctx injection needed) --- // --- Connection module --- diff --git a/lib/public/modules/activity-latch.js b/lib/public/modules/activity-latch.js index de2bdee0..02e268d5 100644 --- a/lib/public/modules/activity-latch.js +++ b/lib/public/modules/activity-latch.js @@ -44,6 +44,70 @@ export function shouldApplyActivityEdge(msgLocalId, activeSessionId) { return msgLocalId == null || msgLocalId === activeSessionId; } +// --------------------------------------------------------------------------- +// lr-58c813: accept/reject ledger — instrumentation only, no decision logic. +// +// MILLER (lr-96e7da) hypothesized cross-session crosstalk on this latch at +// 0.5 confidence and flagged it never instrumented to proof; the symptom +// recurred (lr-5edd64) in code that already has this guard. This ledger +// records what shouldApplyActivityEdge actually decided at runtime, at the +// three call sites in app-messages.js (status/done/auth_required), WITHOUT +// changing which branch any of them take — recordActivityEdgeDecision is +// called for its side effect (counting) only, after the real decision has +// already been made by shouldApplyActivityEdge, never in place of it. +// +// The fail-open branch (msgLocalId == null) is counted SEPARATELY per the +// task spec: it is a deliberate back-compat path, but a live send site that +// still fails to stamp localId would silently re-enable the pre-fix +// unguarded write through this exact branch, and no existing test would +// notice. A nonzero count here in production is the actionable signal. +// +// Bounded: this is a plain in-memory counter object, reset on page +// load/reload (no persistence, no growth — four integers total, no per- +// event array). It does not log to the console on every message (that would +// flood devtools on a chatty session); callers read the totals on demand via +// getActivityEdgeLedger(), e.g. from devtools or a future diagnostics-panel +// hook — never a per-event stream. + +var _activityEdgeLedger = { + accepted: 0, + rejected: 0, + acceptedFailOpen: 0, // subset of `accepted`: msgLocalId == null specifically +}; + +/** + * Record the outcome of a shouldApplyActivityEdge call for the ledger. + * Pure bookkeeping — does not itself decide anything and must be called + * with the SAME inputs the real decision already used, after the fact. + * + * @param {string} msgType - "status" | "done" | "auth_required" + * @param {number|string|null|undefined} msgLocalId + * @param {number|string|null|undefined} activeSessionId + * @param {boolean} accepted - the shouldApplyActivityEdge result already computed by the caller + */ +export function recordActivityEdgeDecision(msgType, msgLocalId, activeSessionId, accepted) { + if (accepted) { + _activityEdgeLedger.accepted++; + if (msgLocalId == null) _activityEdgeLedger.acceptedFailOpen++; + } else { + _activityEdgeLedger.rejected++; + } +} + +/** Read-only snapshot of the ledger totals (does not reset). */ +export function getActivityEdgeLedger() { + return { + accepted: _activityEdgeLedger.accepted, + rejected: _activityEdgeLedger.rejected, + acceptedFailOpen: _activityEdgeLedger.acceptedFailOpen, + }; +} + +/** Test-only reset so ledger tests don't leak counts across cases. */ +export function _resetActivityEdgeLedgerForTest() { + _activityEdgeLedger = { accepted: 0, rejected: 0, acceptedFailOpen: 0 }; +} + /** * Staleness-backstop timer state machine. A single timer is * armed on a genuine 0->1 'processing' transition and disarmed on every diff --git a/lib/public/modules/app-messages.js b/lib/public/modules/app-messages.js index 674ad044..0289b371 100644 --- a/lib/public/modules/app-messages.js +++ b/lib/public/modules/app-messages.js @@ -69,7 +69,7 @@ import { handleMentionStart, handleMentionActivity, handleMentionStream, handleM import { handleTeamState, handleTeamMemberUpdate, handleTeamTaskUpdate, handleTeamMessage as handleTeamMsg, handleTeamGone } from './team-panel.js'; import { addDiagnostic } from './diagnostics.js'; import { handleHistoryMeta, handleHistoryDone } from './app-history-replay.js'; -import { shouldApplyActivityEdge } from './activity-latch.js'; +import { shouldApplyActivityEdge, recordActivityEdgeDecision } from './activity-latch.js'; // --- DOM refs (cached once, stable for page lifetime) --- var messagesEl = document.getElementById("messages"); @@ -635,14 +635,21 @@ registerHandlers({ // stampActivityLocalId / project.js sendToSession); a missing localId // (e.g. an older server) falls back to applying the edge // unconditionally, same as before this fix. - if (msg.status === "processing" && shouldApplyActivityEdge(msg.localId, store.get('activeSessionId'))) { - setStatus("processing"); - // Session became live — undo any dead-session todo compaction - // applied at history_done time. - store.set({ sessionIsProcessing: true }); - applyDeadSessionTodoCompaction(); - if (!store.get('dmMode')) { - removePreThinking(); // drop pre-thinking dots before showing activity indicator + if (msg.status === "processing") { + var _statusActiveSid = store.get('activeSessionId'); + var _statusEdgeAccepted = shouldApplyActivityEdge(msg.localId, _statusActiveSid); + // lr-58c813: ledger this edge's outcome for observability only — the + // decision below (same _statusEdgeAccepted value) is unchanged. + recordActivityEdgeDecision("status", msg.localId, _statusActiveSid, _statusEdgeAccepted); + if (_statusEdgeAccepted) { + setStatus("processing"); + // Session became live — undo any dead-session todo compaction + // applied at history_done time. + store.set({ sessionIsProcessing: true }); + applyDeadSessionTodoCompaction(); + if (!store.get('dmMode')) { + removePreThinking(); // drop pre-thinking dots before showing activity indicator + } } } }, @@ -872,7 +879,12 @@ registerHandlers({ markAllToolsDone(); closeToolGroup(); finalizeAssistantBlock(); - if (shouldApplyActivityEdge(msg.localId, store.get('activeSessionId'))) { + var _doneActiveSid = store.get('activeSessionId'); + var _doneEdgeAccepted = shouldApplyActivityEdge(msg.localId, _doneActiveSid); + // lr-58c813: ledger this edge's outcome for observability only — the + // decision below (same _doneEdgeAccepted value) is unchanged. + recordActivityEdgeDecision("done", msg.localId, _doneActiveSid, _doneEdgeAccepted); + if (_doneEdgeAccepted) { setStatus("connected"); } // Re-enable input unless this is one of the loop's own sessions (coder/judge). @@ -928,7 +940,12 @@ registerHandlers({ // Same session-scoping as the done handler above — a background // session's auth_required must not clear the focused session's // 'processing' latch. - if (shouldApplyActivityEdge(msg.localId, store.get('activeSessionId'))) { + var _authActiveSid = store.get('activeSessionId'); + var _authEdgeAccepted = shouldApplyActivityEdge(msg.localId, _authActiveSid); + // lr-58c813: ledger this edge's outcome for observability only — the + // decision below (same _authEdgeAccepted value) is unchanged. + recordActivityEdgeDecision("auth_required", msg.localId, _authActiveSid, _authEdgeAccepted); + if (_authEdgeAccepted) { setStatus("connected"); } var _authLoopSid = store.get('loopCurrentSessionId'); diff --git a/lib/sdk-bridge.js b/lib/sdk-bridge.js index 5f8b64c7..e6fef2af 100644 --- a/lib/sdk-bridge.js +++ b/lib/sdk-bridge.js @@ -27,6 +27,114 @@ var MAX_CONCURRENT_SESSIONS = (function () { return (env > 0) ? env : 50; })(); +// --- lr-58c813: activity-source divergence probe (instrumentation only) --- +// Baseline measurement for the lr-5edd64 redesign: session.isProcessing (the +// plain mutable boolean, ~14 raw writers) is DERIVED at exactly one site +// (sdk-bridge.js's "lr-9bcd7b" comment above) from +// sessionActivity.isSessionActive(session) (the token registry). This counts +// how often the two disagree at runtime -- READ ONLY, never corrects or +// mutates either value, never gates a renderer, never changes what a client +// sees. Sizes the redesign; does not implement it. +// +// Genuinely read-only means never triggering session.activity's own lazy +// initialization either (session-activity.js's ensureRegistry assigns +// session.activity on first call, and lib/sessions.js's constructors never +// set it) -- see _peekIsSessionActive below, which this probe uses instead +// of sessionActivity.isSessionActive for exactly that reason. +// +// Bounded by construction: sampled once per session per idle-reaper tick +// (IDLE_CHECK_INTERVAL_MS = 60s below), not per tool call/message -- the +// reaper's own setInterval is the sampling clock, so this adds zero new +// per-event hot-path cost. A ring buffer caps the retained detail so a +// daemon that runs for weeks cannot grow this unboundedly; the total count +// is exact (increments forever), only the per-event detail is capped. +var _activityDivergenceCount = 0; +var _activityDivergenceSamples = []; // ring buffer, most-recent-first +var ACTIVITY_DIVERGENCE_SAMPLE_CAP = 20; + +/** + * Non-mutating read of "does this session have at least one live activity + * token", WITHOUT going through sessionActivity.isSessionActive/ + * getActiveCount -- both of those call ensureRegistry(session), which + * lazily creates and ASSIGNS session.activity on first call + * (lib/session-activity.js). Session objects from lib/sessions.js's two + * constructors never initialize session.activity, so calling the mutating + * path here would create it on every session's first idle-reaper tick -- + * a real write this probe must never cause (PEACHES lr-58c813 finding). + * + * A session with no session.activity has, by construction, acquired zero + * tokens, so "absent" and "present but empty/stale-generation" both mean + * not-active -- this mirrors isSessionActive's own semantics exactly, it + * just never creates the registry to get there. Does not read/write + * anything in lib/session-activity.js, which is out of scope and proven + * correct twice already; this adapts the caller to the existing API + * instead of changing it. + */ +function _peekIsSessionActive(session) { + var registry = session.activity; + if (!registry) return false; + for (var token in registry.tokens) { + if (registry.tokens[token].generation === registry.generation) return true; + } + return false; +} + +/** + * Read-only comparison of the two activity sources for one session. Does not + * write session.isProcessing, does not call onProcessingChanged, does not + * touch the registry -- including never triggering the registry's own lazy + * initialization (see _peekIsSessionActive above). Call site (idle reaper, + * see startIdleReaper) observes BEFORE any reaper-driven correction runs in + * the same tick, so a divergence caused by a leaked token that the reaper is + * about to sweep is still counted -- the point is measuring how often + * production state actually disagrees, not how often it disagrees net of + * self-healing. + */ +function _recordActivityDivergenceIfAny(session) { + var rawIsProcessing = !!session.isProcessing; + var derivedIsActive = _peekIsSessionActive(session); + if (rawIsProcessing === derivedIsActive) return; + _activityDivergenceCount++; + // lr-58c813 (BOBBIE finding): no sessionId here. process_stats (the + // handler that folds these samples into its response, see + // project-sessions.js) has no admin/role gate -- any authenticated + // client on a shared project could otherwise read another user's + // session ids through this counter. The measurement goal (how often the + // two sources disagree, and roughly under what conditions) survives + // without a per-session identifier, so the identifier is dropped rather + // than gating process_stats (which would widen this PR's scope into a + // pre-existing, unrelated auth gap -- see PR body). + var sample = { + ts: Date.now(), + rawIsProcessing: rawIsProcessing, + derivedIsActive: derivedIsActive, + hasQueryInstance: !!session.queryInstance, + }; + _activityDivergenceSamples.unshift(sample); + if (_activityDivergenceSamples.length > ACTIVITY_DIVERGENCE_SAMPLE_CAP) { + _activityDivergenceSamples.length = ACTIVITY_DIVERGENCE_SAMPLE_CAP; + } + // lr-58c813 (PEACHES nit): no console.warn here. MILLER's diagnosis + // predicts divergence may be common, and this fires once per diverging + // session per idle-reaper tick (60s) forever -- an unbounded, unrated + // log volume risk on the operator's own machine for a value that isn't + // actionable as a log line anyway. The counter + bounded sample ring + // (both above) are the actual deliverable; dropping the warn and + // relying on getActivityDivergenceStats()/process_stats for visibility + // avoids the flood risk entirely rather than trying to rate-limit it. +} + +// Module-scope accessor so tests and other bridge instances (this counter is +// intentionally shared across ALL project bridge instances, same as +// _activeLiveCount above) can read the current totals without reaching into +// closure state. +function getActivityDivergenceStats() { + return { + count: _activityDivergenceCount, + recentSamples: _activityDivergenceSamples.slice(), + }; +} + // --- lr-2d91: MemAvailable gate --- // Default minimum available memory threshold in MB. Referenced by sdk-bridge // and daemon.js — changing this constant is the single place to adjust the default. @@ -409,6 +517,12 @@ function createSDKBridge(opts) { sm.sessions.forEach(function (session) { if (session.destroying) return; + // lr-58c813: divergence probe, READ ONLY — observe the raw/derived + // activity values exactly as production has them right now, before + // any reaper-driven correction below runs this tick. See the + // _recordActivityDivergenceIfAny doc comment for why "before" matters. + _recordActivityDivergenceIfAny(session); + // lr-5450ef: sweepStaleTokens BACKSTOP — recover a session pinned by // a leaked activity token (isProcessing derives true from the // registry, but there is no live queryInstance left to ever call @@ -2328,10 +2442,17 @@ function createSDKBridge(opts) { // lr-2d91: Expose live concurrency stats for process_stats WS response. // Called by project-sessions.js when building the process_stats payload. + // lr-58c813: also folds in the activity-source divergence probe totals — + // same "instance function reads module-shared counter" shape as + // activeLiveCount above, so process_stats gets both without a second round + // trip. See getActivityDivergenceStats() module-scope doc comment. function getMemoryStats() { + var divergence = getActivityDivergenceStats(); return { activeLiveCount: _activeLiveCount, maxConcurrentSessions: MAX_CONCURRENT_SESSIONS, + activityDivergenceCount: divergence.count, + activityDivergenceRecentSamples: divergence.recentSamples, }; } @@ -2369,5 +2490,5 @@ function getActiveLiveCount() { return _activeLiveCount; } -module.exports = { createSDKBridge, createMessageQueue, readMemAvailableMB, readCgroupHeadroomMB, DEFAULT_MEM_AVAILABLE_MIN_MB, DEFAULT_TOKENS_PER_MB_HEADROOM, getActiveLiveCount }; +module.exports = { createSDKBridge, createMessageQueue, readMemAvailableMB, readCgroupHeadroomMB, DEFAULT_MEM_AVAILABLE_MIN_MB, DEFAULT_TOKENS_PER_MB_HEADROOM, getActiveLiveCount, getActivityDivergenceStats }; diff --git a/test/activity-divergence-probe-lr-58c813.test.js b/test/activity-divergence-probe-lr-58c813.test.js new file mode 100644 index 00000000..8d4f973a --- /dev/null +++ b/test/activity-divergence-probe-lr-58c813.test.js @@ -0,0 +1,333 @@ +/** + * Regression/behavioral tests for lr-58c813: instrumentation-only baseline + * for the lr-5edd64 redesign. See that task's description for the full + * two-source diagnosis (session.isProcessing, a plain mutable boolean with + * ~14 raw writers, vs sessionActivity.isSessionActive(session), the + * registry-derived value, agree at exactly one write site). + * + * SCOPE: this file proves the PROBE is correct and non-mutating — it does + * NOT fix the divergence (out of scope, see lr-58c813 description). Every + * test here either: + * (1) proves the probe counts a genuine, constructed divergence without + * correcting session.isProcessing or the registry itself, or + * (2) proves the probe stays silent (count unchanged) when the two + * sources already agree, or + * (3) proves the sampling/bound behavior (ring buffer cap, once-per-tick + * via the existing idle-reaper interval, not a new hot-path cost). + */ + +var test = require("node:test"); +var assert = require("node:assert/strict"); + +var sessionActivity = require("../lib/session-activity"); + +function makeSessionManager() { + return { + sessions: new Map(), + currentModel: null, + currentPermissionMode: null, + currentEffort: null, + currentBetas: [], + modelsByVendor: {}, + availableVendors: [], + installedVendors: [], + defaultVendor: "claude", + saveSessionFile: function () {}, + broadcastSessionList: function () {}, + getActiveSession: function () { return null; }, + setSlashCommandsForVendor: function () {}, + sendAndRecord: function (session, obj) { + if (!session.history) session.history = []; + session.history.push(obj); + }, + sendToSession: function () {}, + }; +} + +var _localIdSeq = 1; +function makeSession(overrides) { + return Object.assign({ + localId: "divsess-" + (_localIdSeq++), + queryInstance: null, + messageQueue: null, + abortController: null, + isProcessing: false, + cliSessionId: null, + history: [], + blocks: {}, + sentToolResults: {}, + pendingPermissions: {}, + pendingAskUser: {}, + pendingElicitations: {}, + activeTaskToolIds: {}, + singleTurn: false, + destroying: false, + lastActivityAt: Date.now(), + }, overrides || {}); +} + +function freshSdkBridge() { + var modPath = require.resolve("../lib/sdk-bridge"); + delete require.cache[modPath]; + return require("../lib/sdk-bridge"); +} + +function makeBridge() { + var sdkBridgeMod = freshSdkBridge(); + var sm = makeSessionManager(); + var bridge = sdkBridgeMod.createSDKBridge({ + cwd: "/tmp", + slug: "test", + sessionManager: sm, + send: function () {}, + adapter: { vendor: "claude" }, + adapters: {}, + onProcessingChanged: function () {}, + }); + return { sdkBridgeMod: sdkBridgeMod, sm: sm, bridge: bridge }; +} + +// --------------------------------------------------------------------------- +// 1. The probe counts a genuine divergence without correcting either source. +// --------------------------------------------------------------------------- + +test("lr-58c813: idle-reaper tick counts a session where isProcessing=true but the registry has no live token (raw writer set it true with no matching token acquire)", function (t) { + t.mock.timers.enable({ apis: ["setInterval"] }); + try { + var setup = makeBridge(); + var sm = setup.sm; + var bridge = setup.bridge; + + // Mirrors the exact concrete raise path lr-5edd64 names (project.js:724): + // isProcessing set true directly, no token ever acquired. queryInstance + // is set so the reaper's own sweepStaleTokens/reap branches (which only + // fire when isProcessing && !queryInstance, or !isProcessing) do not + // themselves mutate isProcessing or the registry this tick — isolating + // what this test is asserting to the probe alone. + // + // Constructed exactly as the real constructors do (lib/sessions.js:697, + // :835): no `activity` property at all. Deliberately NOT calling + // sessionActivity.isSessionActive() anywhere in this test, before or + // after the tick — that call itself lazily creates session.activity + // (session-activity.js ensureRegistry), which would mask the exact + // defect this test exists to catch (PEACHES lr-58c813 finding). + var session = makeSession({ isProcessing: true, queryInstance: {} }); + assert.equal(Object.prototype.hasOwnProperty.call(session, "activity"), false, + "precondition: session has no activity property, matching the real constructors"); + sm.sessions.set(session.localId, session); + + var before = setup.sdkBridgeMod.getActivityDivergenceStats(); + + bridge.startIdleReaper(); + t.mock.timers.tick(60 * 1000 * 1); // one reaper tick + + var after = setup.sdkBridgeMod.getActivityDivergenceStats(); + + assert.equal(after.count, before.count + 1, "exactly one divergence must be recorded for the one diverging session"); + assert.equal(after.recentSamples[0].rawIsProcessing, true); + assert.equal(after.recentSamples[0].derivedIsActive, false); + + // The probe must be genuinely READ ONLY: neither source was touched by + // observing it, INCLUDING never lazily creating session.activity. This + // is the assertion that fails against the pre-fix probe (verified by + // stash-testing — see PR body) because the pre-fix probe called + // sessionActivity.isSessionActive(session), which assigns + // session.activity as a side effect of reading it. + assert.equal(session.isProcessing, true, "probe must not correct session.isProcessing"); + assert.equal(Object.prototype.hasOwnProperty.call(session, "activity"), false, + "probe must not lazily create session.activity as a side effect of observing it"); + + bridge.stopIdleReaper(); + } finally { + t.mock.timers.reset(); + } +}); + +test("lr-58c813: idle-reaper tick records NO divergence when the two sources already agree (both false)", function (t) { + t.mock.timers.enable({ apis: ["setInterval"] }); + try { + var setup = makeBridge(); + var sm = setup.sm; + var bridge = setup.bridge; + + var session = makeSession({ isProcessing: false, queryInstance: {} }); + sm.sessions.set(session.localId, session); + + var before = setup.sdkBridgeMod.getActivityDivergenceStats(); + + bridge.startIdleReaper(); + t.mock.timers.tick(60 * 1000 * 1); + + var after = setup.sdkBridgeMod.getActivityDivergenceStats(); + assert.equal(after.count, before.count, "agreeing sources must not be counted as a divergence"); + + bridge.stopIdleReaper(); + } finally { + t.mock.timers.reset(); + } +}); + +test("lr-58c813: idle-reaper tick records NO divergence when the two sources already agree (both true, via a real acquired token)", function (t) { + t.mock.timers.enable({ apis: ["setInterval"] }); + try { + var setup = makeBridge(); + var sm = setup.sm; + var bridge = setup.bridge; + + var session = makeSession({ isProcessing: true, queryInstance: {} }); + sessionActivity.acquireToken(session, "toolu_agree", { source: "task" }); + sm.sessions.set(session.localId, session); + + assert.equal(sessionActivity.isSessionActive(session), true, "precondition: registry agrees with isProcessing"); + + var before = setup.sdkBridgeMod.getActivityDivergenceStats(); + + bridge.startIdleReaper(); + t.mock.timers.tick(60 * 1000 * 1); + + var after = setup.sdkBridgeMod.getActivityDivergenceStats(); + assert.equal(after.count, before.count, "agreeing sources (both true) must not be counted as a divergence"); + + bridge.stopIdleReaper(); + } finally { + t.mock.timers.reset(); + } +}); + +// --------------------------------------------------------------------------- +// 2. Bound: the ring buffer of recent samples never grows past its cap, even +// though the total count keeps incrementing exactly. +// --------------------------------------------------------------------------- + +test("lr-58c813: recentSamples is capped even when many sessions diverge across many ticks; the total count is not", function (t) { + t.mock.timers.enable({ apis: ["setInterval"] }); + try { + var setup = makeBridge(); + var sm = setup.sm; + var bridge = setup.bridge; + + var CAP = 20; // mirrors ACTIVITY_DIVERGENCE_SAMPLE_CAP in lib/sdk-bridge.js + var SESSION_COUNT = CAP + 15; + for (var i = 0; i < SESSION_COUNT; i++) { + var session = makeSession({ isProcessing: true, queryInstance: {} }); // no token acquired -> diverges + sm.sessions.set(session.localId, session); + } + + var before = setup.sdkBridgeMod.getActivityDivergenceStats(); + + bridge.startIdleReaper(); + t.mock.timers.tick(60 * 1000 * 1); // one tick observes every session once + + var after = setup.sdkBridgeMod.getActivityDivergenceStats(); + + assert.equal(after.count, before.count + SESSION_COUNT, "the total count must be exact, not capped"); + assert.ok(after.recentSamples.length <= CAP, "the retained sample detail must be bounded regardless of how many sessions diverge"); + + bridge.stopIdleReaper(); + } finally { + t.mock.timers.reset(); + } +}); + +// --------------------------------------------------------------------------- +// 3. getMemoryStats (already the process_stats plumbing point) folds the +// divergence totals in, matching the shape project-sessions.js reads. +// --------------------------------------------------------------------------- + +test("lr-58c813: bridge.getMemoryStats() exposes activityDivergenceCount and activityDivergenceRecentSamples", function () { + var setup = makeBridge(); + var stats = setup.bridge.getMemoryStats(); + assert.equal(typeof stats.activityDivergenceCount, "number"); + assert.ok(Array.isArray(stats.activityDivergenceRecentSamples)); +}); + +// --------------------------------------------------------------------------- +// 4. CI invariant: the probe call site is READ ONLY source-text — no +// assignment to session.isProcessing or session.activity anywhere in the +// probe helper function, so a future edit cannot silently turn this +// baseline measurement into a fix. +// +// lr-58c813 PEACHES finding: a prior version of this invariant only +// inspected the probe function's own body for DIRECT writes, so it could +// not see the TRANSITIVE mutation through sessionActivity.isSessionActive +// -> getActiveCount -> ensureRegistry (which assigns session.activity as +// a side effect of reading it). Source inspection alone cannot prove a +// called function is side-effect-free without re-deriving that function's +// own body every time it changes — so this invariant is now split in two: +// (a) a narrow, defensible source check that the probe never calls the +// two specific sessionActivity exports known to have this shape +// (isSessionActive, getActiveCount), rather than trying to inspect +// their transitive bodies; and +// (b) the behavioral test above ("...counts a session where..."), which +// constructs a session exactly as the real constructors do (no +// `activity` property) and asserts session.activity is STILL ABSENT +// after the probe runs — that is the test that actually catches a +// transitive mutation, source inspection is a secondary guard. +// --------------------------------------------------------------------------- + +test("CI invariant: _recordActivityDivergenceIfAny never assigns session.isProcessing or session.activity, and never calls a mutating sessionActivity read (isSessionActive/getActiveCount)", function () { + var fs = require("fs"); + var path = require("path"); + var src = fs.readFileSync(path.join(__dirname, "..", "lib", "sdk-bridge.js"), "utf8"); + var start = src.indexOf("function _recordActivityDivergenceIfAny"); + assert.ok(start !== -1, "expected _recordActivityDivergenceIfAny to exist in lib/sdk-bridge.js"); + var end = src.indexOf("\n}", start) + 2; + var body = src.slice(start, end); + assert.doesNotMatch(body, /session\.isProcessing\s*=/, "the probe must never write session.isProcessing"); + assert.doesNotMatch(body, /session\.activity\s*=/, "the probe must never write session.activity"); + assert.doesNotMatch(body, /sessionActivity\.(acquireToken|releaseToken|bumpGeneration|sweepStaleTokens|replaceRegistry)\(/, "the probe must never call a registry-mutating export"); + // The lazy-init defect: isSessionActive/getActiveCount both call + // ensureRegistry(session) internally, which assigns session.activity if + // absent. Neither is a "write" by grep-for-assignment, so they need their + // own explicit ban here — this is the transitive-mutation gap this + // invariant previously missed. + assert.doesNotMatch(body, /sessionActivity\.(isSessionActive|getActiveCount)\(/, + "the probe must not call sessionActivity.isSessionActive/getActiveCount — both lazily create session.activity as a side effect; use the non-mutating _peekIsSessionActive helper instead"); + assert.match(body, /_peekIsSessionActive\(/, "the probe must read activity via the non-mutating _peekIsSessionActive helper"); +}); + +test("lr-58c813: _peekIsSessionActive itself never creates session.activity — direct unit check independent of the reaper/tick plumbing", function () { + var setup = makeBridge(); + var session = makeSession({ isProcessing: true, queryInstance: {} }); + assert.equal(Object.prototype.hasOwnProperty.call(session, "activity"), false, "precondition"); + // _peekIsSessionActive is not exported (private helper) — exercised + // indirectly here via the same public entry point production uses + // (getMemoryStats/getActivityDivergenceStats after a reaper tick is + // covered above); this test instead pins the module-level CI-invariant + // helper name so the source-inspection test above stays meaningful if + // the helper is ever renamed. + var fs = require("fs"); + var path = require("path"); + var src = fs.readFileSync(path.join(__dirname, "..", "lib", "sdk-bridge.js"), "utf8"); + assert.match(src, /function _peekIsSessionActive\(session\)/, "expected the non-mutating helper to exist by this name in lib/sdk-bridge.js"); +}); + +// --------------------------------------------------------------------------- +// 5. BOBBIE finding: divergence samples carry no session identifier, since +// process_stats (the handler that folds these into its response) has no +// admin/role gate. +// --------------------------------------------------------------------------- + +test("lr-58c813: a recorded divergence sample never includes a sessionId field", function (t) { + t.mock.timers.enable({ apis: ["setInterval"] }); + try { + var setup = makeBridge(); + var sm = setup.sm; + var bridge = setup.bridge; + + var session = makeSession({ isProcessing: true, queryInstance: {} }); + sm.sessions.set(session.localId, session); + + bridge.startIdleReaper(); + t.mock.timers.tick(60 * 1000 * 1); + + var stats = setup.sdkBridgeMod.getActivityDivergenceStats(); + assert.ok(stats.recentSamples.length >= 1, "expected at least one recorded sample"); + assert.equal(Object.prototype.hasOwnProperty.call(stats.recentSamples[0], "sessionId"), false, + "a divergence sample must not carry a session identifier — process_stats is not admin-gated"); + + bridge.stopIdleReaper(); + } finally { + t.mock.timers.reset(); + } +}); diff --git a/test/activity-edge-ledger-lr-58c813.test.js b/test/activity-edge-ledger-lr-58c813.test.js new file mode 100644 index 00000000..41012f93 --- /dev/null +++ b/test/activity-edge-ledger-lr-58c813.test.js @@ -0,0 +1,155 @@ +// activity-edge-ledger-lr-58c813.test.js +// +// lr-58c813: accept/reject ledger for shouldApplyActivityEdge, and a +// SEPARATE count for the fail-open branch (msgLocalId == null). This is +// instrumentation only — it must observe the SAME decision app-messages.js's +// status/done/auth_required handlers already make, never a second, +// independently-computed decision. +// +// Per lib/public/modules/activity-latch.js's own module-load hazard (see +// test/activity-latch-lr-96e7da.test.js header comment), activity-latch.js +// is DOM-free and importable directly in plain Node; app-messages.js is not +// (deep import chain reaches theme.js/markdown.js's circular-import boot +// hazard). This file therefore: +// 1. Proves recordActivityEdgeDecision/getActivityEdgeLedger are correct, +// pure bookkeeping (sections 1-2). +// 2. Source-inspects (this suite's own established convention, see +// activity-latch-lr-96e7da.test.js section 4) that app-messages.js +// actually calls recordActivityEdgeDecision at its three call sites, +// with the SAME shouldApplyActivityEdge result it already computed — +// not a second, reimplemented check (section 3). + +"use strict"; + +var test = require("node:test"); +var assert = require("node:assert/strict"); +var fs = require("fs"); +var path = require("path"); +var { pathToFileURL } = require("url"); + +var LATCH_URL = pathToFileURL( + path.join(__dirname, "..", "lib", "public", "modules", "activity-latch.js") +).href; + +function readMod(rel) { + return fs.readFileSync(path.join(__dirname, "..", rel), "utf8"); +} + +function stripLineComments(src) { + return src + .split("\n") + .map(function (line) { + var idx = line.indexOf("//"); + return idx === -1 ? line : line.slice(0, idx); + }) + .join("\n"); +} + +var latch; + +test("activity-latch.js exports the ledger functions", { timeout: 10000 }, function () { + return import(LATCH_URL).then(function (mod) { + latch = mod; + assert.strictEqual(typeof latch.recordActivityEdgeDecision, "function"); + assert.strictEqual(typeof latch.getActivityEdgeLedger, "function"); + assert.strictEqual(typeof latch._resetActivityEdgeLedgerForTest, "function"); + }); +}); + +// --------------------------------------------------------------------------- +// 1. Pure bookkeeping correctness +// --------------------------------------------------------------------------- + +test("recordActivityEdgeDecision: an accepted edge with a real localId increments accepted only", function () { + latch._resetActivityEdgeLedgerForTest(); + latch.recordActivityEdgeDecision("status", "sess-A", "sess-A", true); + var ledger = latch.getActivityEdgeLedger(); + assert.equal(ledger.accepted, 1); + assert.equal(ledger.rejected, 0); + assert.equal(ledger.acceptedFailOpen, 0, "a real localId match is not the fail-open branch"); +}); + +test("recordActivityEdgeDecision: a rejected (cross-session) edge increments rejected only", function () { + latch._resetActivityEdgeLedgerForTest(); + latch.recordActivityEdgeDecision("done", "sess-B", "sess-A", false); + var ledger = latch.getActivityEdgeLedger(); + assert.equal(ledger.accepted, 0); + assert.equal(ledger.rejected, 1); + assert.equal(ledger.acceptedFailOpen, 0); +}); + +test("recordActivityEdgeDecision: an accepted edge with msgLocalId == null is counted in BOTH accepted and acceptedFailOpen — the highest-value number per the task spec, visible separately from the general accept count", function () { + latch._resetActivityEdgeLedgerForTest(); + latch.recordActivityEdgeDecision("status", null, "sess-A", true); + latch.recordActivityEdgeDecision("auth_required", undefined, "sess-A", true); + var ledger = latch.getActivityEdgeLedger(); + assert.equal(ledger.accepted, 2); + assert.equal(ledger.acceptedFailOpen, 2, "both null and undefined localId must count as fail-open"); + assert.equal(ledger.rejected, 0); +}); + +test("recordActivityEdgeDecision: fail-open count is NOT folded silently into the general accept count without being separately readable", function () { + latch._resetActivityEdgeLedgerForTest(); + latch.recordActivityEdgeDecision("status", "sess-A", "sess-A", true); // normal accept + latch.recordActivityEdgeDecision("status", null, "sess-A", true); // fail-open accept + latch.recordActivityEdgeDecision("done", "sess-B", "sess-A", false); // reject + var ledger = latch.getActivityEdgeLedger(); + assert.equal(ledger.accepted, 2, "total accepted includes both the normal and fail-open accept"); + assert.equal(ledger.acceptedFailOpen, 1, "fail-open subset must be separately visible, not just folded into accepted"); + assert.equal(ledger.rejected, 1); +}); + +test("getActivityEdgeLedger: returns a snapshot, not a live reference (mutating the returned object must not affect the internal ledger)", function () { + latch._resetActivityEdgeLedgerForTest(); + latch.recordActivityEdgeDecision("status", "sess-A", "sess-A", true); + var snap = latch.getActivityEdgeLedger(); + snap.accepted = 9999; + var ledger2 = latch.getActivityEdgeLedger(); + assert.equal(ledger2.accepted, 1, "returned snapshot must be a copy, not the live counter object"); +}); + +// --------------------------------------------------------------------------- +// 2. Bounded by construction: four integers total, no per-event array — this +// module doubles as the shape assertion for "counters, not a log stream" +// (task spec: "log volume is a real risk ... Bound it"). +// --------------------------------------------------------------------------- + +test("the ledger is a fixed-shape counter object, not an unbounded per-event array", function () { + latch._resetActivityEdgeLedgerForTest(); + for (var i = 0; i < 500; i++) { + latch.recordActivityEdgeDecision("status", i % 2 === 0 ? "sess-A" : null, "sess-A", true); + } + var ledger = latch.getActivityEdgeLedger(); + assert.equal(Object.keys(ledger).length, 3, "ledger must stay a fixed 3-field counter object regardless of event volume"); + assert.equal(ledger.accepted, 500); +}); + +// --------------------------------------------------------------------------- +// 3. Source-inspection (this suite's own established convention, see +// activity-latch-lr-96e7da.test.js section 4): app-messages.js's three +// call sites record the SAME decision they already computed, not a +// second reimplemented check. +// --------------------------------------------------------------------------- + +test("CI invariant: app-messages.js imports recordActivityEdgeDecision from activity-latch.js and calls it at least 3 times (status, done, auth_required)", function () { + var src = stripLineComments(readMod("lib/public/modules/app-messages.js")); + assert.match( + src, + /import\s*\{[^}]*\brecordActivityEdgeDecision\b[^}]*\}\s*from\s*['"]\.\/activity-latch\.js['"]/, + "app-messages.js must import recordActivityEdgeDecision from activity-latch.js" + ); + var occurrences = src.match(/recordActivityEdgeDecision\(/g) || []; + assert.ok( + occurrences.length >= 3, + "expected recordActivityEdgeDecision(...) to be called at least 3 times (status, done, auth_required handlers) — found " + occurrences.length + ); +}); + +test("CI invariant: shouldApplyActivityEdge is still called at least 3 times too — the ledger must not have REPLACED the real decision with only a recorded one", function () { + var src = stripLineComments(readMod("lib/public/modules/app-messages.js")); + var occurrences = src.match(/shouldApplyActivityEdge\(/g) || []; + assert.ok( + occurrences.length >= 3, + "the real gating decision (shouldApplyActivityEdge) must remain — found " + occurrences.length + ); +});