fix(truncate): unique cache keys per payload + read_cache truncation observability

Follow-ups from PR #480 review:

1. Multi-block cache-key collision. cache.GenerateKey mixed the timestamp
   in at second granularity. forwardContentResult truncates each oversized
   TextContent block independently and the truncator derives the key from
   toolName+args+time.Now(); two blocks truncated in the same wall-clock
   second produced the SAME key, so the second Store overwrote the first
   and the first banner resolved to the wrong payload. Same hazard for
   rapid recursive read_cache truncation. Now nanosecond granularity.

2. Doc wording. maybeTruncateAndCacheText doc now states termination is
   agent-driven (not strictly algorithmic) and that successive identical
   calls are NOT idempotent (distinct timestamped keys), bounded only by
   cache TTL + cleanup.

3. read_cache truncation observability. handleReadCache discarded
   wasTruncated; it has no token-metrics plumbing (reports via activity
   log). A recursively re-truncated page was invisible to operators — now
   surfaced as a structured Info log with key/offset/limit/size.

Tests: new GenerateKey sub-second regression assertion;
TestForwardContentResult_MultipleTextBlocksDistinctKeys. Full
internal/server, internal/cache, internal/truncate pass (incl. -race).

Author: Dumbris

internal/cache/manager.go

@@ -62,11 +62,20 @@ func NewManager(db *bbolt.DB, logger *zap.Logger) (*Manager, error) {
 	return manager, nil
 }
 
-// GenerateKey generates a cache key from tool name, arguments, and timestamp
+// GenerateKey generates a cache key from tool name, arguments, and timestamp.
+//
+// The timestamp is mixed in at nanosecond granularity. The truncator calls
+// this with time.Now() once per truncated payload; a single upstream result
+// can carry multiple oversized TextContent blocks, and recursive read_cache
+// truncation can mint several keys in quick succession. At second granularity
+// any of those that landed in the same wall-clock second collided on one key,
+// so a later Store silently overwrote an earlier payload and the earlier
+// banner resolved to the wrong data. Nanosecond granularity makes each call's
+// key unique in practice.
 func GenerateKey(toolName string, args map[string]interface{}, timestamp time.Time) string {
 	// Create a consistent string representation
 	argsJSON, _ := json.Marshal(args)
-	input := fmt.Sprintf("%s:%s:%d", toolName, string(argsJSON), timestamp.Unix())
+	input := fmt.Sprintf("%s:%s:%d", toolName, string(argsJSON), timestamp.UnixNano())
 
 	hash := sha256.Sum256([]byte(input))
 	return hex.EncodeToString(hash[:])

internal/cache/manager_test.go

@@ -80,6 +80,17 @@ func TestGenerateKey(t *testing.T) {
 	if len(key1) != 64 { // SHA256 hex = 64 chars
 		t.Errorf("Expected key length 64, got %d", len(key1))
 	}
+
+	// Sub-second-distinct timestamps must produce different keys. The
+	// truncator calls GenerateKey with time.Now() for every truncated block;
+	// at second granularity two blocks truncated in the same wall-clock
+	// second collided on one key, so the second Store overwrote the first and
+	// read_cache for the first banner resolved to the wrong payload.
+	tsA := time.Unix(1700000000, 0)
+	tsB := tsA.Add(time.Nanosecond)
+	if GenerateKey("test_tool", args1, tsA) == GenerateKey("test_tool", args1, tsB) {
+		t.Error("Timestamps 1ns apart must produce different keys (multi-block collision regression)")
+	}
 }
 
 func TestStoreAndGet(t *testing.T) {

internal/server/content_forward.go

@@ -144,12 +144,21 @@ func forwardContentResult(result interface{}, truncator *truncate.Truncator, cac
 // the returned snippet carries the standard "use read_cache" banner that
 // points at it.
 //
-// The paginableUnits parameter is a guard against infinite recursion for
-// built-in tools that may themselves be paginating (notably read_cache). If
-// paginableUnits <= 1 the caller has nothing further to subdivide — caching
-// a fresh key under those circumstances just produces an identical record
-// the agent can never escape from. In that case the text is returned as-is
-// (uncaught, exceeding the limit) and the caller decides what to do.
+// The paginableUnits parameter is the recursion guard for built-in tools that
+// may themselves be paginating (notably read_cache). If paginableUnits <= 1
+// the caller has nothing further to subdivide — caching a fresh key here would
+// just hand the agent a new key resolving to the same oversize payload, an
+// inescapable loop. In that case the text is returned as-is (still over the
+// limit) and the caller decides what to do.
+//
+// Termination is therefore agent-driven, not strictly algorithmic: a level
+// whose records all fit individually but overflow collectively keeps minting
+// a fresh key per call until the agent pages down to the single-record
+// short-circuit. Each call's key is unique (timestamped at nanosecond
+// granularity), so successive identical calls are NOT idempotent — they
+// produce distinct cache entries. Unbounded growth is bounded only by the
+// cache's TTL + background cleanup (see cache.DefaultTTL), which is acceptable
+// because truncation is the exceptional path.
 //
 // Returns:
 //   - the text to actually emit (possibly truncated)

internal/server/content_forward_test.go

@@ -287,6 +287,55 @@ func TestForwardContentResult_RoundTripViaRealCacheManager(t *testing.T) {
 	assert.Equal(t, float64(19), idOf(page2.Records[9]), "page 2 should end at id 19")
 }
 
+// TestForwardContentResult_MultipleTextBlocksDistinctKeys is a regression test
+// for the multi-block cache-key collision. When an upstream result carries
+// more than one oversized TextContent block, each block is truncated
+// independently and gets its own banner + cache key. The truncator derives the
+// key from toolName+args+timestamp; at the previous second-granularity, two
+// blocks truncated within the same wall-clock second produced the SAME key, so
+// the second Store overwrote the first and the first banner resolved to the
+// wrong block's payload. Each block must persist under a distinct key and that
+// key must resolve to that block's own content.
+func TestForwardContentResult_MultipleTextBlocksDistinctKeys(t *testing.T) {
+	mkBig := func(tag string) string {
+		recs := make([]string, 0, 40)
+		for i := 0; i < 40; i++ {
+			recs = append(recs, fmt.Sprintf(`{"id":%d,"tag":"%s","pad":"%s"}`, i, tag, strings.Repeat(tag, 20)))
+		}
+		return `[` + strings.Join(recs, ",") + `]`
+	}
+	blockA := mkBig("A")
+	blockB := mkBig("B")
+
+	upstream := &mcp.CallToolResult{
+		Content: []mcp.Content{
+			mcp.NewTextContent(blockA),
+			mcp.NewTextContent(blockB),
+		},
+	}
+	store := &captureStore{}
+	_, _, wasTruncated := forwardContentResult(
+		upstream,
+		truncate.NewTruncator(500),
+		store,
+		nil,
+		"github:pull_request_read",
+		map[string]interface{}{"perPage": 100},
+	)
+	require.True(t, wasTruncated)
+
+	store.mu.Lock()
+	defer store.mu.Unlock()
+	require.Len(t, store.calls, 2, "each oversized text block must produce its own Store call")
+
+	k0, k1 := store.calls[0].key, store.calls[1].key
+	assert.NotEmpty(t, k0)
+	assert.NotEmpty(t, k1)
+	assert.NotEqual(t, k0, k1, "distinct text blocks must persist under distinct cache keys")
+	assert.Equal(t, blockA, store.calls[0].content, "block A's key must resolve to block A's content")
+	assert.Equal(t, blockB, store.calls[1].content, "block B's key must resolve to block B's content")
+}
+
 // TestMaybeTruncateAndCacheText_HappyPathStores asserts that an oversized text
 // with more than one paginable unit gets truncated AND stored under the
 // embedded cache key — the contract required for read_cache pagination to keep

internal/server/mcp.go

@@ -4129,7 +4129,7 @@ func (p *MCPProxyServer) handleReadCache(ctx context.Context, request mcp.CallTo
 	// in that case there's nothing this layer can subdivide, so the oversize
 	// text flows through unchanged. p.logger receives a zap.Warn if the cache
 	// write fails so the resulting "cache key not found" is diagnosable.
-	text, _ := maybeTruncateAndCacheText(
+	text, reTruncated := maybeTruncateAndCacheText(
 		string(jsonResult),
 		"read_cache",
 		args,
@@ -4139,6 +4139,21 @@ func (p *MCPProxyServer) handleReadCache(ctx context.Context, request mcp.CallTo
 		p.logger,
 	)
 
+	// read_cache has no token-metrics plumbing (it reports via the activity
+	// log, not the tokenMetrics/toolCallRecord path used by upstream tool
+	// calls). A recursively re-truncated page is otherwise invisible to
+	// operators, so surface it as a structured log: it signals the agent is
+	// walking a payload deep enough that even one cache page overflows.
+	if reTruncated {
+		p.logger.Info("read_cache output exceeded the response limit and was recursively truncated-and-cached",
+			zap.String("requested_key", key),
+			zap.Int("offset", offset),
+			zap.Int("limit", limit),
+			zap.Int("page_records", len(response.Records)),
+			zap.Int("full_bytes", len(jsonResult)),
+		)
+	}
+
 	// Spec 024: Emit success event with args and response
 	p.emitActivityInternalToolCall("read_cache", "", "", "", sessionID, requestID, "success", "", time.Since(startTime).Milliseconds(), args, response, nil, "")