From 9355a793bcd61b2b22331db716519042df0763ba Mon Sep 17 00:00:00 2001 From: Vitaliy Date: Mon, 10 Aug 2026 12:19:59 +0200 Subject: [PATCH 1/3] feat(server): log client-requested protocol version on initialize MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The server never negotiated: handleInitialize discarded its params and always answered with its own protocolVersion. A client moving to a newer MCP revision was therefore unobservable — we would learn about it from a failure rather than from telemetry. Logging only; the response is unchanged and a mismatch is not an error. This is step 1 of MCP-PROTOCOL-MIGRATION-2026-07-28, which turns the migration trigger from a calendar guess into an instrumented signal. --- internal/server/server.go | 46 ++++++++- internal/server/server_initialize_test.go | 120 ++++++++++++++++++++++ 2 files changed, 165 insertions(+), 1 deletion(-) create mode 100644 internal/server/server_initialize_test.go diff --git a/internal/server/server.go b/internal/server/server.go index a2c3a0d..0eb21ad 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -260,7 +260,51 @@ func (s *MCPServer) dispatch(req rpcRequest) (any, *rpcError) { } } -func (s *MCPServer) handleInitialize(_ json.RawMessage) (any, *rpcError) { +// initializeParams is the subset of the client's initialize request we inspect. +// Everything outside these fields is deliberately ignored. +type initializeParams struct { + ProtocolVersion string `json:"protocolVersion"` + ClientInfo struct { + Name string `json:"name"` + Version string `json:"version"` + } `json:"clientInfo"` +} + +// logClientProtocolVersion records which protocol revision the client asked for. +// +// The server does not negotiate: handleInitialize always answers with its own +// protocolVersion regardless of the request. Without this log line a divergence +// between client and server is unobservable, so we would learn that the client +// moved to a newer revision from a failure rather than from telemetry. Logging +// only — the response is unchanged, and a mismatch is not an error here. +func (s *MCPServer) logClientProtocolVersion(params json.RawMessage) { + if s.fileLogger == nil { + return + } + + var p initializeParams + if len(params) > 0 { + if err := json.Unmarshal(params, &p); err != nil { + s.fileLogger.Warn("initialize: failed to parse params", + zap.String("server_protocol_version", protocolVersion), + zap.Error(err), + ) + return + } + } + + s.fileLogger.Info("initialize: client protocol version", + zap.String("client_protocol_version", p.ProtocolVersion), + zap.String("server_protocol_version", protocolVersion), + zap.Bool("protocol_version_match", p.ProtocolVersion == protocolVersion), + zap.String("client_name", p.ClientInfo.Name), + zap.String("client_version", p.ClientInfo.Version), + ) +} + +func (s *MCPServer) handleInitialize(params json.RawMessage) (any, *rpcError) { + s.logClientProtocolVersion(params) + return map[string]any{ "protocolVersion": protocolVersion, "capabilities": map[string]any{ diff --git a/internal/server/server_initialize_test.go b/internal/server/server_initialize_test.go new file mode 100644 index 0000000..a4afc6d --- /dev/null +++ b/internal/server/server_initialize_test.go @@ -0,0 +1,120 @@ +package server + +import ( + "encoding/json" + "os" + "path/filepath" + "strings" + "testing" + + "github.com/ipiton/agent-memory-mcp/internal/config" + "github.com/ipiton/agent-memory-mcp/internal/paths" +) + +// newLoggingTestServer builds a server with file logging enabled and returns it +// together with the log path. newTestServer leaves LogPath empty, which makes +// fileLogger nil — any assertion on log output built on that helper would pass +// without executing the logging path at all. +func newLoggingTestServer(t *testing.T) (*MCPServer, string) { + t.Helper() + logPath := filepath.Join(t.TempDir(), "mcp.log") + cfg := config.Config{ + RootPath: t.TempDir(), + OutputMode: "line", + LogPath: logPath, + } + guard, err := paths.NewGuard(cfg) + if err != nil { + t.Fatalf("NewGuard: %v", err) + } + s := New(cfg, guard) + if s.fileLogger == nil { + t.Fatal("fileLogger is nil — the logging path would not be exercised") + } + return s, logPath +} + +func readLog(t *testing.T, logPath string) string { + t.Helper() + data, err := os.ReadFile(logPath) + if err != nil { + t.Fatalf("read log: %v", err) + } + return string(data) +} + +// TestInitializeLogsClientProtocolVersion is the acceptance check for step 1 of +// MCP-PROTOCOL-MIGRATION-2026-07-28: a client asking for a revision we do not +// implement must be visible in telemetry rather than discovered through a +// failure. The server still answers with its own version — this is observation +// only, not negotiation. +func TestInitializeLogsClientProtocolVersion(t *testing.T) { + s, logPath := newLoggingTestServer(t) + + params := json.RawMessage(`{"protocolVersion":"2026-07-28",` + + `"clientInfo":{"name":"claude-code","version":"9.9.9"}}`) + + result, rpcErr := s.handleInitialize(params) + if rpcErr != nil { + t.Fatalf("handleInitialize returned error: %+v", rpcErr) + } + + // The response must be unchanged: we report our own revision, not the one + // the client asked for. + answered := result.(map[string]any)["protocolVersion"] + if answered != protocolVersion { + t.Errorf("response protocolVersion = %v, want %q", answered, protocolVersion) + } + + logged := readLog(t, logPath) + for _, want := range []string{ + `"client_protocol_version":"2026-07-28"`, + `"server_protocol_version":"` + protocolVersion + `"`, + `"protocol_version_match":false`, + `"client_name":"claude-code"`, + } { + if !strings.Contains(logged, want) { + t.Errorf("log does not contain %s\nlog:\n%s", want, logged) + } + } +} + +// TestInitializeLogsMatchingProtocolVersion pins the other branch of the match +// flag, so a detector that always reported "false" would not pass. +func TestInitializeLogsMatchingProtocolVersion(t *testing.T) { + s, logPath := newLoggingTestServer(t) + + params := json.RawMessage(`{"protocolVersion":"` + protocolVersion + `"}`) + if _, rpcErr := s.handleInitialize(params); rpcErr != nil { + t.Fatalf("handleInitialize returned error: %+v", rpcErr) + } + + if logged := readLog(t, logPath); !strings.Contains(logged, `"protocol_version_match":true`) { + t.Errorf("expected protocol_version_match:true\nlog:\n%s", logged) + } +} + +// TestInitializeSurvivesUnusableParams guards the failure mode that matters: +// logging is diagnostics, and it must never turn a working handshake into a +// broken one. Both a malformed body and an absent one must still initialize. +func TestInitializeSurvivesUnusableParams(t *testing.T) { + cases := map[string]json.RawMessage{ + "malformed": json.RawMessage(`{"protocolVersion":`), + "absent": nil, + "empty": json.RawMessage(`{}`), + } + + for name, params := range cases { + t.Run(name, func(t *testing.T) { + s, _ := newLoggingTestServer(t) + + result, rpcErr := s.handleInitialize(params) + if rpcErr != nil { + t.Fatalf("handleInitialize returned error: %+v", rpcErr) + } + if result.(map[string]any)["protocolVersion"] != protocolVersion { + t.Error("response protocolVersion changed on unusable params") + } + }) + } +} From bda43fe59c44116e804e32f3bcd6a8581f5e1a51 Mon Sep 17 00:00:00 2001 From: Vitaliy Date: Mon, 10 Aug 2026 12:43:43 +0200 Subject: [PATCH 2/3] feat(server): log unknown methods as the protocol-migration tripwire Watching initialize turned out to be blind. Measured 2026-08-10 against a live client: Claude Code reconnects to a restarted HTTP server by going straight to tools/call and never re-sends initialize, which dispatch accepts because no handshake is required. The detector added in 9355a79 therefore never fires for the case it was built for. An unknown method is the reliable signal: a client on revision 2026-07-28 calls server/discover, a mandatory RPC we do not implement, and today that returns method-not-found silently. The line also carries the protocol version from _meta when present, so it says which revision the caller speaks rather than only that something unknown was asked for. --- internal/server/server.go | 43 +++++++++++++++ internal/server/server_initialize_test.go | 67 +++++++++++++++++++++++ 2 files changed, 110 insertions(+) diff --git a/internal/server/server.go b/internal/server/server.go index 0eb21ad..b3f151e 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -256,10 +256,53 @@ func (s *MCPServer) dispatch(req rpcRequest) (any, *rpcError) { case "tools/call": return s.handleToolsCall(req.Params) default: + s.logUnknownMethod(req) return nil, &rpcError{Code: rpcErrMethodNotFound, Message: "method not found"} } } +// requestMeta is the subset of a request's `_meta` we inspect. Under revision +// 2026-07-28 clients carry their protocol version on every request; under the +// revision we implement (2025-11-25) the field is simply absent. +type requestMeta struct { + Meta struct { + ProtocolVersion string `json:"io.modelcontextprotocol/protocolVersion"` + } `json:"_meta"` +} + +// logUnknownMethod records calls to methods we do not implement. +// +// This is the migration tripwire for MCP-PROTOCOL-MIGRATION-2026-07-28, and it +// exists because the obvious place to watch — initialize — turned out to be +// blind. Measured 2026-08-10 against a live client: Claude Code reconnects to a +// restarted HTTP server by going straight to tools/call and never re-sends +// initialize, which our dispatch accepts because no handshake is required. A +// detector on initialize therefore never fires for the case it was built for. +// +// An unknown method is the reliable signal instead: a client that has moved to +// 2026-07-28 calls server/discover, a mandatory RPC we do not implement, and +// today that returns method-not-found silently. The protocol version is read +// from _meta when present, so the line says which revision the caller speaks +// rather than only that something unknown was asked for. +func (s *MCPServer) logUnknownMethod(req rpcRequest) { + if s.fileLogger == nil { + return + } + + var m requestMeta + if len(req.Params) > 0 { + // A parse failure is not worth reporting separately: the method is + // unknown either way, and that is the fact we are recording. + _ = json.Unmarshal(req.Params, &m) + } + + s.fileLogger.Warn("unknown method", + zap.String("method", req.Method), + zap.String("client_protocol_version", m.Meta.ProtocolVersion), + zap.String("server_protocol_version", protocolVersion), + ) +} + // initializeParams is the subset of the client's initialize request we inspect. // Everything outside these fields is deliberately ignored. type initializeParams struct { diff --git a/internal/server/server_initialize_test.go b/internal/server/server_initialize_test.go index a4afc6d..bdcd841 100644 --- a/internal/server/server_initialize_test.go +++ b/internal/server/server_initialize_test.go @@ -94,6 +94,73 @@ func TestInitializeLogsMatchingProtocolVersion(t *testing.T) { } } +// TestUnknownMethodIsLogged is the working half of the migration tripwire. +// Watching initialize does not fire for a real client (measured 2026-08-10: +// Claude Code reconnects straight into tools/call), so the signal that a client +// moved to 2026-07-28 is a call to a method we do not implement. +func TestUnknownMethodIsLogged(t *testing.T) { + s, logPath := newLoggingTestServer(t) + + req := rpcRequest{ + JSONRPC: "2.0", + Method: "server/discover", + Params: json.RawMessage(`{"_meta":{"io.modelcontextprotocol/protocolVersion":"2026-07-28"}}`), + } + + result, rpcErr := s.dispatch(req) + if rpcErr == nil { + t.Fatal("server/discover unexpectedly handled — the tripwire assumes it is unimplemented") + } + if result != nil { + t.Errorf("unknown method returned a result: %v", result) + } + + logged := readLog(t, logPath) + for _, want := range []string{ + `"message":"unknown method"`, + `"method":"server/discover"`, + `"client_protocol_version":"2026-07-28"`, + } { + if !strings.Contains(logged, want) { + t.Errorf("log does not contain %s\nlog:\n%s", want, logged) + } + } +} + +// TestUnknownMethodWithoutMetaIsStillLogged covers the current-revision shape: +// clients on 2025-11-25 send no _meta at all, and the call must still be +// visible — an empty version field is data, not a reason to stay silent. +func TestUnknownMethodWithoutMetaIsStillLogged(t *testing.T) { + s, logPath := newLoggingTestServer(t) + + for _, params := range []json.RawMessage{nil, json.RawMessage(`{}`), json.RawMessage(`{"_meta":`)} { + if _, rpcErr := s.dispatch(rpcRequest{Method: "some/unimplemented", Params: params}); rpcErr == nil { + t.Fatal("expected method-not-found") + } + } + + logged := readLog(t, logPath) + if got := strings.Count(logged, `"method":"some/unimplemented"`); got != 3 { + t.Errorf("logged %d unknown-method lines, want 3\nlog:\n%s", got, logged) + } +} + +// TestKnownMethodsAreNotLoggedAsUnknown pins the other side: the tripwire must +// stay quiet on normal traffic, otherwise it is noise rather than a signal. +func TestKnownMethodsAreNotLoggedAsUnknown(t *testing.T) { + s, logPath := newLoggingTestServer(t) + + for _, method := range []string{"initialize", "tools/list", "resources/list", "resources/templates/list"} { + if _, rpcErr := s.dispatch(rpcRequest{Method: method}); rpcErr != nil { + t.Fatalf("%s returned error: %+v", method, rpcErr) + } + } + + if logged := readLog(t, logPath); strings.Contains(logged, `"message":"unknown method"`) { + t.Errorf("known methods produced an unknown-method line\nlog:\n%s", logged) + } +} + // TestInitializeSurvivesUnusableParams guards the failure mode that matters: // logging is diagnostics, and it must never turn a working handshake into a // broken one. Both a malformed body and an absent one must still initialize. From 729733b6082a2cb3ee6eed6882aa955db00b97a9 Mon Sep 17 00:00:00 2001 From: Vitaliy Date: Tue, 11 Aug 2026 20:05:32 +0200 Subject: [PATCH 3/3] fix(memory): hide superseded entries from semantic recall MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit An entry whose superseded_by points at a live successor stayed in recall with its original vector, so the dead copy kept competing with — and often out-ranking — the successor. Downranking via MarkOutdated was not enough. Recall now skips it; List/ListLightweight still return it so the maintenance and temporal-history views are unchanged. The successor is looked up in the cache rather than trusted: Delete does not clear superseded_by on predecessors, and a dangling pointer would otherwise bury the entry forever. MarkOutdated without a successor keeps the pre-existing downrank behaviour. TestMarkOutdatedDownranksMemory pinned the old contract and is renamed and updated accordingly. Also pins issue #19 (plain markdown must classify as docs) with the two regression cases from PR #17; the fix itself already landed in b052f2d. Fixes #18 Fixes #19 --- internal/memory/memory_test.go | 15 +- internal/memory/read.go | 20 +++ internal/memory/superseded_recall_test.go | 160 ++++++++++++++++++++++ internal/rag/rag_test.go | 4 + 4 files changed, 196 insertions(+), 3 deletions(-) create mode 100644 internal/memory/superseded_recall_test.go diff --git a/internal/memory/memory_test.go b/internal/memory/memory_test.go index 5c5db4f..ed985b5 100644 --- a/internal/memory/memory_test.go +++ b/internal/memory/memory_test.go @@ -967,7 +967,13 @@ func TestMergeDuplicatesAndConflictsReport(t *testing.T) { } } -func TestMarkOutdatedDownranksMemory(t *testing.T) { +// TestMarkOutdatedHidesSupersededMemoryFromRecall pins issue #18. Marking an +// entry outdated WITH a successor now removes it from semantic recall instead +// of merely downranking it: the old vector is unchanged, so downranking alone +// still let the dead copy compete with its successor. The downrank path stays +// in force for MarkOutdated without a successor — see +// TestOutdatedWithoutSuccessorStaysRecallable. +func TestMarkOutdatedHidesSupersededMemoryFromRecall(t *testing.T) { store := newTestStore(t) current := &Memory{ @@ -998,12 +1004,15 @@ func TestMarkOutdatedDownranksMemory(t *testing.T) { if err != nil { t.Fatalf("Recall: %v", err) } - if len(results) < 2 { - t.Fatalf("expected 2 results, got %d", len(results)) + if len(results) != 1 { + t.Fatalf("expected 1 result, got %d", len(results)) } if results[0].Memory.ID != current.ID { t.Fatalf("top result = %s, want %s", results[0].Memory.ID, current.ID) } + if _, err := store.Get(old.ID); err != nil { + t.Fatalf("superseded entry must stay retrievable by id: %v", err) + } outdated, err := store.Get(old.ID) if err != nil { t.Fatalf("Get old: %v", err) diff --git a/internal/memory/read.go b/internal/memory/read.go index 98b9c77..dd82418 100644 --- a/internal/memory/read.go +++ b/internal/memory/read.go @@ -27,6 +27,15 @@ func (ms *Store) snapshotReadonlyMemories() []*cachedMemory { return snapshot } +// hasMemory reports whether the given id is present in the cache. Used to tell +// a live supersession pointer from a dangling one. +func (ms *Store) hasMemory(id string) bool { + ms.mu.RLock() + defer ms.mu.RUnlock() + _, ok := ms.memories[id] + return ok +} + // snapshotForContext returns a read-only snapshot pre-filtered by context. func (ms *Store) snapshotForContext(ctx string) []*cachedMemory { if ctx == "" { @@ -197,6 +206,17 @@ func (ms *Store) Recall(ctx context.Context, query string, filters Filters, limi continue } + // Superseded entries (temporal replacement, e.g. after a merge or + // MarkOutdated) are invisible to semantic recall — the successor + // carries the current knowledge, while the old vector is unchanged and + // keeps out-ranking it. They stay visible to List/ListLightweight so + // maintenance tools still see the temporal history. The successor is + // looked up rather than trusted: Delete does not clear superseded_by on + // predecessors, and a dangling pointer would bury the entry forever. + if m.SupersededBy != "" && ms.hasMemory(m.SupersededBy) { + continue + } + // T48 layer-aware filtering: when the flag is on, surface memories // are invisible outside their originating Context. This prevents // session scratch state from leaking into unrelated recall calls. diff --git a/internal/memory/superseded_recall_test.go b/internal/memory/superseded_recall_test.go new file mode 100644 index 0000000..c935664 --- /dev/null +++ b/internal/memory/superseded_recall_test.go @@ -0,0 +1,160 @@ +package memory + +import ( + "context" + "path/filepath" + "testing" + + "github.com/ipiton/agent-memory-mcp/internal/embedder" + "go.uber.org/zap" +) + +// newSupersessionTestStore builds a store over a stub embedder that returns the +// same vector for every input — recall then ranks purely on the metadata +// weights, so the assertions below are about the filter, not about similarity. +func newSupersessionTestStore(t *testing.T) *Store { + t.Helper() + + server := newEmbeddingTestServer(t, []float64{1, 0, 0, 0}) + t.Cleanup(server.Close) + + emb, err := embedder.New(embedder.Config{ + OpenAIToken: "test-token", + OpenAIBaseURL: server.URL, + OpenAIModel: "test-model", + Dimension: 4, + }, zap.NewNop()) + if err != nil { + t.Fatalf("New embedder: %v", err) + } + + store, err := NewStore(filepath.Join(t.TempDir(), "superseded.db"), emb, zap.NewNop()) + if err != nil { + t.Fatalf("NewStore: %v", err) + } + t.Cleanup(func() { _ = store.Close() }) + + return store +} + +func storeSupersessionPair(t *testing.T, store *Store) { + t.Helper() + + ctx := context.Background() + + old := &Memory{ + ID: "old-1", + Title: "Deploy runbook", + Content: "Deploy runbook: scale the api deployment to three replicas.", + Type: TypeSemantic, + Context: "payments", + } + successor := &Memory{ + ID: "new-1", + Title: "Deploy runbook", + Content: "Deploy runbook: scale the api deployment to five replicas.", + Type: TypeSemantic, + Context: "payments", + } + for _, m := range []*Memory{old, successor} { + if err := store.Store(ctx, m); err != nil { + t.Fatalf("Store %s: %v", m.ID, err) + } + } + + if err := store.SetTemporalFields(ctx, old.ID, nil, nil, successor.ID, ""); err != nil { + t.Fatalf("SetTemporalFields: %v", err) + } +} + +func recalledIDs(t *testing.T, store *Store) map[string]bool { + t.Helper() + + results, err := store.Recall(context.Background(), "deploy runbook replicas", Filters{Context: "payments"}, 10) + if err != nil { + t.Fatalf("Recall: %v", err) + } + ids := make(map[string]bool, len(results)) + for _, r := range results { + ids[r.Memory.ID] = true + } + return ids +} + +// TestSupersededMemoryExcludedFromRecall pins issue #18: an entry whose +// superseded_by points at a live successor stays out of semantic recall (its +// vector is unchanged, so it kept out-ranking the successor), while remaining +// visible to the List-based maintenance views. +func TestSupersededMemoryExcludedFromRecall(t *testing.T) { + store := newSupersessionTestStore(t) + storeSupersessionPair(t, store) + + ids := recalledIDs(t, store) + if ids["old-1"] { + t.Error("superseded entry leaked into semantic recall") + } + if !ids["new-1"] { + t.Error("successor missing from recall") + } + + listed, err := store.List(context.Background(), Filters{Context: "payments"}, 10) + if err != nil { + t.Fatalf("List: %v", err) + } + found := false + for _, m := range listed { + if m.ID == "old-1" { + found = true + } + } + if !found { + t.Error("superseded entry must stay visible to List for temporal history") + } + + lightweight := store.ListLightweight(Filters{Context: "payments"}) + found = false + for _, m := range lightweight { + if m.ID == "old-1" { + found = true + } + } + if !found { + t.Error("superseded entry must stay visible to ListLightweight") + } +} + +// TestOutdatedWithoutSuccessorStaysRecallable guards the boundary of the new +// filter: MarkOutdated with an empty supersededBy leaves superseded_by unset, +// so the entry keeps the pre-existing downrank treatment (lower importance, +// archived metadata) and stays in recall. Nothing replaced it — hiding it would +// simply lose the knowledge. +func TestOutdatedWithoutSuccessorStaysRecallable(t *testing.T) { + store := newSupersessionTestStore(t) + storeSupersessionPair(t, store) + + if _, err := store.MarkOutdated(context.Background(), "new-1", "just stale", ""); err != nil { + t.Fatalf("MarkOutdated: %v", err) + } + + if !recalledIDs(t, store)["new-1"] { + t.Error("outdated entry without a successor must stay in recall") + } +} + +// TestSupersededByDanglingPointerStaysRecallable covers the other side of the +// filter: Delete does not clear superseded_by on predecessors, so once the +// successor is gone the pointer dangles. An archived entry beats no entry at +// all — the old memory must come back into recall rather than stay buried. +func TestSupersededByDanglingPointerStaysRecallable(t *testing.T) { + store := newSupersessionTestStore(t) + storeSupersessionPair(t, store) + + if err := store.Delete(context.Background(), "new-1"); err != nil { + t.Fatalf("Delete successor: %v", err) + } + + ids := recalledIDs(t, store) + if !ids["old-1"] { + t.Error("entry with a dangling superseded_by pointer stayed buried in recall") + } +} diff --git a/internal/rag/rag_test.go b/internal/rag/rag_test.go index d82a86f..c83854a 100644 --- a/internal/rag/rag_test.go +++ b/internal/rag/rag_test.go @@ -641,6 +641,10 @@ func TestClassifySourceType(t *testing.T) { {path: "k8s/ingress.yaml", want: "k8s"}, {path: "dead_ends/why-we-avoid-async-migration.md", want: "dead_end"}, {path: "notes/why-we-avoid-shared-mutable-state.md", want: "dead_end"}, + // Issue #19: plain markdown outside docs/ and without a "# " heading + // used to classify as "" and get silently dropped from the index. + {path: "knowledge/mahoo-architecture.md", want: "docs"}, + {path: "plans/analysis.md", want: "docs"}, } for _, tc := range tests {