From 733a2ed4c22ae59e95150d3eb599274d53346fcd Mon Sep 17 00:00:00 2001
From: dtzp555-max <taodeng1977@gmail.com>
Date: Sat, 25 Apr 2026 19:19:38 +1000
Subject: [PATCH] chore(server): add session-create-vs-resume + lifetime
 instrumentation (refs #41 #42) (#51)
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Adds structured logging for the two forensic candidates so the eventual
fixes can be evidence-driven (per #41/#42 bodies: "Evidence needed before
code change — do not patch speculatively"). NO bug fix in this PR — the
stale-create-entry behavior (#41) and the lastUsed-resistant-expiry
behavior (#42) are intentionally left unchanged so they can be observed
in production /logs.

Three changes (server.mjs):

1. Session-create branch records `firstSeen` alongside `lastUsed` (same
   timestamp), giving the sweep loop an absolute-age signal independent
   of the actively-bumped `lastUsed` field. Resume branch is untouched
   so `firstSeen` is preserved across resumes.

2. handleSessionFailure now emits a structured `session_failure` event
   with `mode: "resume"` (action: "deleted") OR `mode: "create"`
   (action: "kept"). The "kept" branch makes #41's "stale create entries
   never deleted" pattern visible in /logs without changing behavior.

3. TTL sweep emits `session_expired` (info, with idleMs + ageMs) on
   actual expiry, and `session_long_lived` (warn) when ageMs > 4×TTL
   but the entry is not being expired this tick. The latter is the
   #42 evidence trigger — a session whose lastUsed keeps getting bumped
   and so resists idle-based expiry.

cli.js citation: N/A — logEvent payloads are OCP-internal observability,
never sent on the wire to the Anthropic API. ALIGNMENT.md Rule 2 (no
invention) is scoped to endpoints/headers/request/response fields, not
to internal server logging.

Independent reviewer: fresh-context sonnet APPROVE_WITH_MINOR.
Two minor notes — repeated `session_long_lived` emissions per 60s
sweep tick is expected (downstream analysis dedupes by conversationId).
LOC: +19 / -3 = +16 net.

Co-authored-by: Claude Opus 4.7 <noreply@anthropic.com>
---
 server.mjs | 22 +++++++++++++++++++---
 1 file changed, 19 insertions(+), 3 deletions(-)

diff --git a/server.mjs b/server.mjs
index 46ff85e..cd1f045 100644
--- a/server.mjs
+++ b/server.mjs
@@ -165,9 +165,18 @@ const sessions = new Map(); // conversationId → { uuid, messageCount, lastUsed
 const sessionCleanupInterval = setInterval(() => {
   const now = Date.now();
   for (const [id, s] of sessions) {
-    if (now - s.lastUsed > SESSION_TTL) {
+    const idleMs = now - s.lastUsed;
+    const ageMs = s.firstSeen ? now - s.firstSeen : null;
+    if (idleMs > SESSION_TTL) {
       sessions.delete(id);
-      console.log(`[session] expired ${id.slice(0, 12)}... (idle ${Math.round((now - s.lastUsed) / 60000)}m)`);
+      console.log(`[session] expired ${id.slice(0, 12)}... (idle ${Math.round(idleMs / 60000)}m)`);
+      logEvent("info", "session_expired", { conversationId: id.slice(0, 12) + "...", idleMs, ageMs });
+    } else if (ageMs !== null && ageMs > 4 * SESSION_TTL) {
+      // #42 evidence-gathering: a session whose firstSeen is more than 4× TTL old
+      // but whose lastUsed keeps getting bumped (never idle long enough to expire)
+      // is the suspected bug. Log without action so the pattern can be confirmed
+      // in /logs. Do NOT enforce an absolute age cap here speculatively.
+      logEvent("warn", "session_long_lived", { conversationId: id.slice(0, 12) + "...", idleMs, ageMs });
     }
   }
 }, 60000);
@@ -406,7 +415,8 @@ function spawnClaudeProcess(model, messages, conversationId) {
 
   } else if (conversationId) {
     const uuid = randomUUID();
-    sessions.set(conversationId, { uuid, messageCount: messages.length, lastUsed: Date.now(), model: cliModel });
+    const now = Date.now();
+    sessions.set(conversationId, { uuid, messageCount: messages.length, firstSeen: now, lastUsed: now, model: cliModel });
     sessionInfo = { uuid, resume: false };
     stats.sessionMisses++;
     prompt = messagesToPrompt(messages);
@@ -458,7 +468,13 @@ function spawnClaudeProcess(model, messages, conversationId) {
   function handleSessionFailure() {
     if (sessionInfo?.resume && conversationId) {
       console.warn(`[session] resume failed for ${conversationId.slice(0, 12)}..., removing stale session`);
+      logEvent("warn", "session_failure", { mode: "resume", conversationId: conversationId.slice(0, 12) + "...", action: "deleted" });
       sessions.delete(conversationId);
+    } else if (sessionInfo && !sessionInfo.resume && conversationId) {
+      // #41 evidence-gathering: session-create failures currently leave a stale entry
+      // in the sessions map. Log without action so the staleness pattern can be
+      // confirmed in /logs before any code change. Do NOT delete here speculatively.
+      logEvent("warn", "session_failure", { mode: "create", conversationId: conversationId.slice(0, 12) + "...", action: "kept" });
     }
   }