Skip to content

A session's event timeline grows without bound #167

Description

@kerlenton

The problem

Nothing has been fixed here. --history-limit still bounds only how many sessions the hub backfills at startup (cmd/mcpsnoop/main.go:305, internal/hub/hub.go:206-207), and sweepSeen still bounds only the dedup map (#119, internal/hub/hub.go:249-270). Once a frame reaches the store nothing bounds what is kept. session.events is a plain slice that only ever grows, and every event holds the full observed frame.

// internal/store/store.go:242
events   []*event
// internal/store/store.go:319, :330, :343, :654
sess.events = append(sess.events, ev)

A long-lived hub watching a chatty server grows the TUI's resident set until it is killed, whether that is an agent loop running for a day or a server whose tool results are large. The frames are already durable on disk, so nothing is lost by not keeping them all in memory, and mcpsnoop open on the log remains the way to see everything.

Still reproducible at e8aace6. Synthetic stdio logs of clean tools/call pairs with a 2 KiB argument and a 2 KiB result, one session, fed to mcpsnoop check, which builds the same Store the TUI does. Peak memory footprint from /usr/bin/time -l.

  5000 pairs  log= 22M   peak=68 MiB
 10000 pairs  log= 44M   peak=132 MiB
 20000 pairs  log= 88M   peak=267 MiB
 40000 pairs  log=176M   peak=514 MiB

Nothing in that traffic is a protocol problem, so nothing warns and there is no signal that anything is wrong.

session s-bench: errors=0 invalid=0 warnings=0 mismatches=0 pending=0 deprecated=0 missing_frames=0
check passed
           234504192  maximum resident set size
           538559376  peak memory footprint

The TUI holds the same thing. mcpsnoop open on those two logs under a pty, quit after twelve seconds, max RSS from getrusage(RUSAGE_CHILDREN).

open scale-40000.jsonl: max RSS = 236 MiB
open scale-5000.jsonl:  max RSS = 66 MiB

The interaction with the frame-size cap still holds. A single observed frame can be up to maxFrameBytes, 16 MiB (internal/proxy/stdio.go:48, applied to HTTP request bodies, response bodies and SSE data at internal/proxy/http.go:307, :273, :254), so a modest event count can already be a lot of memory.

Three things the original filing understated

Each of these makes the work larger than a ring buffer in store.go.

Trimming events reclaims less than it looks. openCall puts every call in sess.calls (internal/store/store.go:725) and nothing ever deletes from that map, so it is unbounded independently of the timeline. The call does not share bytes with the event either. ParseRPC unmarshals into the json.RawMessage fields of RPCMessage (internal/proxy/frame.go:107-114, :131-136), and Go's encoding/json copies for RawMessage rather than aliasing the input (*m = append((*m)[0:0], data...) in stream.go), so call.params and call.result are separate allocations from event.raw. For request and response traffic the payload is therefore resident twice, and evicting the events reclaims only the event's copy while the call's copy of both the request and the response payload stays alive in sess.calls. sess.tasks (internal/store/store.go:759) holds the same pointers. Measured against the store directly, 20000 notification frames of 8 KiB, which produce an event and no call, retain 189 MiB, while 20000 request and response pairs of the same size, 40000 events, retain 748 MiB. That is just under twice the retained bytes per frame. Store.ToolUsage already reads sess.calls rather than the events (internal/store/views.go:582), so an events-only bound leaves that reader correct and leaves the map's footprint untouched. #190 added two more per-session maps, cacheFresh and cacheListScope (internal/store/store.go:250, :253). Their entries are small, but cacheFresh gains one per distinct resources/read URI and is only ever deleted on invalidation (internal/store/cache.go:212, :222).

The store's session map is the second unbounded dimension. s.sessions and s.order (internal/store/store.go:258-260) only ever grow. Store.Delete exists (internal/store/store.go:272) but its single caller is the interactive delete in the TUI (internal/tui/model.go:1269), and mcpsnoop prune removes log files rather than store entries. Because every run mints a unique session id (cmd/mcpsnoop/main.go:397, called at :627 for the stdio shim), a workstation that starts many short-lived MCP servers accumulates one never-evicted session per run, each holding its events, calls and tool definitions forever. A per-session ring does nothing for that workload. A concatenated log of 5000 four-call sessions, 88 MiB on disk, peaks at 273 MiB. The reverse workload has the same problem from the other end. mcpsnoop http mints one session id for the whole proxy run (cmd/mcpsnoop/main.go:740), so a proxy left up for a week is a single session whose timeline never stops growing.

The correlation risk is not the one the issue names. The session counters (internal/store/store.go:244) are incremented in Ingest and live on the session, so eviction cannot corrupt them, and a *call stays reachable through sess.calls whether or not its event survives. The real damage is that public readers derive their whole output by walking the events slice.

  • Calls walks events and emits one CallView per request event (internal/store/views.go:654-671), and mcpsnoop check evaluates --max-duration, --expect-tool and --forbid-tool against exactly that (cmd/mcpsnoop/check.go:166).
  • ToolSummary does the same for per-tool latency, error counts, result bytes and the slowest calls (internal/store/views.go:675-747). SlowToolCall.CallIndex is a position in that derived walk (internal/store/views.go:338, assigned at :728) and the export ships it as-is (internal/exporter/exporter.go:363). The export separately builds its own index over the same walk (internal/exporter/exporter.go:296-300) to join an event back to its call (:811-814, :852-853).
  • summarizeCheck counts the invalid, warn, mismatch and deprecated signals by walking Timeline (cmd/mcpsnoop/check.go:271-284).

An eviction policy baked into the store therefore changes check verdicts and export contents, not just the TUI's memory use, because one Store type serves every path. Live hub (internal/tui/run.go:28), mcpsnoop open over a whole log (cmd/mcpsnoop/main.go:869), check and export (internal/exporter/exporter.go:259), and the OTLP sink (internal/otlpsink/sink.go:169).

What the released 2026-07-28 revision changed

The release makes the unbounded case ordinary rather than pathological, so the issue should now cite it.

subscriptions/listen replaces resources/subscribe and the HTTP GET endpoint. Subscriptions (2026-07-28) states

subscriptions/listen opens a long-lived notification stream from the server to the client. Unlike one-off requests, the stream stays open and delivers notifications until the client cancels it.

and Streamable HTTP (2026-07-28) adds

Long-lived notification streams are obtained by sending a subscriptions/listen request. The server's response is itself an SSE stream that stays open and delivers the change notifications the client opted in to (such as notifications/tools/list_changed or notifications/resources/updated).

Three consequences.

  1. Every frame on a listen stream becomes one sess.events entry, on a stream that stays open until the client cancels it, the server tears it down, or the transport closes. Under earlier revisions a POST-per-request transport produced nothing while the client was idle. A listen stream is now the intended way to receive change notifications, so an idle but subscribed session still grows.

  2. The subscriptions/listen request stays open for the life of the stream, but since fix(store): treat subscriptions/listen as streaming, not pending #181 it is no longer pending. openCall gives it the Streaming state (internal/store/store.go:37-39, :713-715, isStreamOpeningMethod at :1334-1336), which never takes a pending slot, so it does not fail check --fail-on pending. What closes it is narrow. On stdio only a notifications/cancelled does (internal/store/store.go:478-482, closeStreamingCall at :1356-1366), and on HTTP the revision says "on Streamable HTTP, closing the SSE response stream is itself the cancellation signal and no notifications/cancelled message is expected", while the graceful closing response is only a SHOULD. So on HTTP nothing on the wire ever completes it. Exporting a two-frame HTTP listen capture shows what any policy has to keep explicable after the request event is gone.

    #1 2026-07-31T12:00:01Z c2s request subscriptions/listen id="1" status=streaming duration_ms=pending
    #2 2026-07-31T12:00:02Z s2c notification notifications/tools/list_changed
    
  3. On stdio a reconnect feeds the other dimension. The spec requires that "if the connection is terminated and then re-established, the client MUST re-send subscriptions/listen", and a re-established stdio connection is a new server process, therefore a new shim run with a new session id (cmd/mcpsnoop/main.go:397, :627). A flapping connection adds a fresh never-evicted session to s.sessions per attempt rather than a call to one timeline.

The same revision removed protocol-level sessions ("Removal of protocol-level sessions.", Streamable HTTP 2026-07-28), so there is no Mcp-Session-Id on the wire to split a capture on. A mcpsnoop session is now purely its own capture boundary, one shim run or one mcpsnoop http run, which is why the store's session map is a real second dimension of this issue rather than a detail.

One thing the release does not make worse. Keep-alives cost nothing, because the SSE tap accumulates only data: lines and drops every other field (internal/proxy/http.go:396-428), even though the spec encourages them on exactly these streams.

For long-lived streams — in particular the [subscriptions/listen] response stream — servers are encouraged to periodically emit an SSE comment line (a line beginning with a colon, e.g. :\r\n) as a keep-alive.

Worth recording so nobody chases it.

What a fix has to satisfy

No design is chosen here. Any candidate needs an answer to all of these.

  • The bound must not change what check and export report. Either the cap stays off on the load paths (internal/exporter/exporter.go:258-280, cmd/mcpsnoop/main.go:869), or Calls, ToolSummary and the Timeline signal counts stop being derived from the events slice.
  • A deliberate in-memory trim must not be counted as dropped frames. sess.missing (internal/store/store.go:247) means upstream Seq-gap loss, is surfaced as MissingFrames, and is gated by check --fail-on incomplete (cmd/mcpsnoop/check.go:322). Conflating a trim with that fails CI on a healthy capture.
  • The trimmed count has to be visible, the way historyTruncatedMsg already announces bounded backfill (internal/tui/model.go:79-84, :253-255). internal/otlpsink/sink.go:151-166 is the existing in-repo shape for an LRU bound with a dropped counter.
  • A call that is still open must stay explicable once its request event is gone. That covers a Pending request and a Streaming subscriptions/listen, which on HTTP never completes at all.
  • Bounding the events slice without bounding sess.calls recovers only part of the footprint, so the change should say which of the two it bounds.
  • The session map needs its own answer, or this stays open for the many-short-sessions workload and for the long-lived mcpsnoop http run.

Out of scope

  • What is written to disk. The log stays the complete record and mcpsnoop open stays the way to read all of it.
  • The frame-size cap. 16 MiB per observed frame (internal/proxy/stdio.go:48) is a separate decision and is not being revisited here.
  • The per-refresh cost of Timeline. Every refresh copies the whole timeline into the model (internal/tui/model.go:813-824) at roughly 400ms (internal/tui/model.go:92-95), allocating one EventView per event plus one CallView per correlated event (internal/store/views.go:352-388, :390-408, :535-547). A bound makes that cheaper as a side effect, but the O(n) refresh is its own issue.
  • Interpreting subscriptions/listen beyond its call state. fix(store): treat subscriptions/listen as streaming, not pending #181 gave it a Streaming state so it stops reading as a hung request, but Ingest still has no dispatch for the subscription filter or for notifications/subscriptions/acknowledged, and adding one is separate work. It appears above only because it is the workload that makes the growth unavoidable.

Where

internal/store/store.go for retention, internal/store/views.go for the readers that derive from the slice, and one of internal/tui/run.go or cmd/mcpsnoop/main.go for deciding which paths get the bound.

Metadata

Metadata

Assignees

No one assigned

    Labels

    enhancementNew feature or requesthelp wantedExtra attention is needed

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions