jlxq0/caldav-mcp
1
0
Fork 0
Code Issues 3 Pull requests Projects Releases Packages 1 Wiki Activity Actions

upstream: the MCP connector appears to open a fresh session per tool call #21

New issue
Open
opened 2026-08-26 10:12:33 +00:00 by jlxq0 · 2 comments
jlxq0 commented 2026-08-26 10:12:33 +00:00
Owner
Copy link

Not ours to fix, and filed anyway. This is the bug; #20 is the symptom's blast radius.

The observation

Twenty-four calendar events cost twenty-four initialize requests. That means the MCP connector opens a fresh session per tool call rather than reusing the one it handshook, so a single conversation burns session slots in proportion to how much work it does.

Why raising the limit does not fix it

#20 raises the initialize burst from 8 to 32. That covers twenty-four events. It does not cover forty, and the next person meeting the ceiling has the same afternoon at a higher number.

This issue exists so that person finds the reason rather than raising it to 64. Every raise looks like it worked, because the raise is always larger than the workload that provoked it, right up until the workload grows.

What is on our side

Nothing to fix, and two things to keep honest:

  • The initialize limiter's key set — sha256(bearer)[..16] and the Logto sub — is what makes this visible at all. A client minting a fresh token per session gets a fresh bearer bucket and the same sub bucket, so the sub bucket is what refuses. Without the second key this would have been invisible until the session pool filled.
  • session::SESSION_KEEP_ALIVE is 30 minutes precisely so a connector with a slow tool-call cadence does not lose its session and re-handshake. If sessions are being discarded after one call, that keep-alive is buying nothing for this client.

What would confirm it

The warn line from #20's first step, on beta, showing consecutive initialize requests carrying different session ids from one conversation. That is a direct observation rather than the current inference from a request count, and it is cheap: beta has logged two lines since it started.

Until then this is a well-supported reading of a count, not a measurement — the same distinction #20 is about.

Where it goes

Upstream, if it reproduces against a current connector build. Recorded here first because the reasoning is ours and it is the thing that will be forgotten once the limit is raised and the symptom stops.

Not ours to fix, and filed anyway. **This is the bug; #20 is the symptom's blast radius.** ## The observation Twenty-four calendar events cost twenty-four `initialize` requests. That means the MCP connector opens a **fresh session per tool call** rather than reusing the one it handshook, so a single conversation burns session slots in proportion to how much work it does. ## Why raising the limit does not fix it #20 raises the initialize burst from 8 to 32. That covers twenty-four events. It does not cover forty, and the next person meeting the ceiling has the same afternoon at a higher number. **This issue exists so that person finds the reason rather than raising it to 64.** Every raise looks like it worked, because the raise is always larger than the workload that provoked it, right up until the workload grows. ## What is on our side Nothing to fix, and two things to keep honest: - The initialize limiter's key set — `sha256(bearer)[..16]` **and** the Logto `sub` — is what makes this visible at all. A client minting a fresh token per session gets a fresh bearer bucket and the same `sub` bucket, so the `sub` bucket is what refuses. Without the second key this would have been invisible until the session pool filled. - `session::SESSION_KEEP_ALIVE` is 30 minutes precisely so a connector with a slow tool-call cadence does not lose its session and re-handshake. If sessions are being discarded after one call, that keep-alive is buying nothing for this client. ## What would confirm it The warn line from #20's first step, on beta, showing consecutive `initialize` requests carrying **different session ids from one conversation**. That is a direct observation rather than the current inference from a request count, and it is cheap: beta has logged two lines since it started. Until then this is a well-supported reading of a count, not a measurement — the same distinction #20 is about. ## Where it goes Upstream, if it reproduces against a current connector build. Recorded here first because the reasoning is ours and it is the thing that will be forgotten once the limit is raised and the symptom stops.
jlxq0 commented 2026-08-26 15:02:32 +00:00
Author
Owner
Copy link

First evidence since the instrument exists, and it points here rather than at the limiter

Production has run v0.2.0 since 14:37:52Z. Everything it has logged:

14:37:52  caldav-mcp listening (public)
14:37:52  caldav-mcp metrics listening (internal)
14:58:10  introspect  outcome=active  user_hash=f5a076c6a6c82848
14:58:11  introspect  outcome=active  user_hash=f5a076c6a6c82848
14:58:12  introspect  outcome=active  user_hash=f5a076c6a6c82848
14:58:13  introspect  outcome=active  user_hash=f5a076c6a6c82848

Four authenticated requests in four seconds, zero refusals, zero tool calls. f5a076c6a6c82848 is julian@kampong.social.

What that settles and what it does not

Settles: the limiter did not refuse him. A refusal now writes refused MCP initialize with scope, user_hash and retry_after_seconds, and increments caldav_mcp_initialize_refusals_total{scope}. Neither appears. That is the silent direction of a check that can fail both ways, and it is an answer rather than an absence of one, which is the first time tonight this question has had one.

Does not settle: that these four were initialize requests. introspect fires on any authenticated request, and the limiter logs only when it refuses, so an accepted initialize is indistinguishable in the log from any other authenticated call. What the log does establish is that four requests authenticated and none became a tool call, which is the same auth-succeeds-nothing-follows shape as before with our limiter now excluded from the candidates.

Four authentications in four seconds with nothing following is the signature this issue describes: one session opened per attempt rather than one reused.

The gap this exposes

We count refusals and not acceptances, so the server still cannot say how many sessions an identity opened, only how many it was denied. That makes the central claim here, twenty-four events costing twenty-four initializes, still unmeasurable from our side.

The fix is small and is not in v0.2.0: log or count accepted initialize requests, at debug or as a counter, so sessions-opened becomes a number rather than an inference from a request count. Filed as a follow-up rather than done, because it is a new behaviour rather than a correction and the release is already out.

Related: the connect-time mount pitfall, matrix-mcp#118 — a mount keeps the tool set it connected with and this server emits no list_changed, so tools vanishing from a session is explained by the mount rather than by the server, and a fresh conversation restores them.

## First evidence since the instrument exists, and it points here rather than at the limiter Production has run `v0.2.0` since `14:37:52Z`. Everything it has logged: ```text 14:37:52 caldav-mcp listening (public) 14:37:52 caldav-mcp metrics listening (internal) 14:58:10 introspect outcome=active user_hash=f5a076c6a6c82848 14:58:11 introspect outcome=active user_hash=f5a076c6a6c82848 14:58:12 introspect outcome=active user_hash=f5a076c6a6c82848 14:58:13 introspect outcome=active user_hash=f5a076c6a6c82848 ``` **Four authenticated requests in four seconds, zero refusals, zero tool calls.** `f5a076c6a6c82848` is `julian@kampong.social`. ## What that settles and what it does not **Settles:** the limiter did not refuse him. A refusal now writes `refused MCP initialize` with `scope`, `user_hash` and `retry_after_seconds`, and increments `caldav_mcp_initialize_refusals_total{scope}`. Neither appears. That is the silent direction of a check that can fail both ways, and it is an answer rather than an absence of one, which is the first time tonight this question has had one. **Does not settle:** that these four were `initialize` requests. `introspect` fires on any authenticated request, and the limiter logs only when it refuses, so an accepted `initialize` is indistinguishable in the log from any other authenticated call. What the log does establish is that four requests authenticated and **none became a tool call**, which is the same auth-succeeds-nothing-follows shape as before with our limiter now excluded from the candidates. Four authentications in four seconds with nothing following is the signature this issue describes: one session opened per attempt rather than one reused. ## The gap this exposes **We count refusals and not acceptances**, so the server still cannot say how many sessions an identity opened, only how many it was denied. That makes the central claim here, twenty-four events costing twenty-four initializes, still unmeasurable from our side. The fix is small and is not in `v0.2.0`: log or count accepted `initialize` requests, at debug or as a counter, so sessions-opened becomes a number rather than an inference from a request count. Filed as a follow-up rather than done, because it is a new behaviour rather than a correction and the release is already out. Related: the connect-time mount pitfall, `matrix-mcp#118` — a mount keeps the tool set it connected with and this server emits no `list_changed`, so tools vanishing from a session is explained by the mount rather than by the server, and a fresh conversation restores them.
jlxq0 commented 2026-08-27 03:42:26 +00:00
Author
Owner
Copy link

The count exists now, and it is not the shape this issue predicted

v0.2.1 has been serving since 2026-08-26T16:22Z. Eleven hours of production traffic, counted from the server rather than inferred from a call graph:

admitted initializes                36
refused initializes                  0
tool calls                           0
authenticated non-introspect requests  109
token introspections                113

Zero tool calls. Not one in eleven hours, against 36 sessions opened. So the claim in this issue, that twenty-four events cost twenty-four initializes, is not what this server sees. Sessions are being opened and nothing is being invoked in them.

The initializes arrive in pairs

Every connection event produces exactly two, in the same second or one apart. Eighteen events, thirty-six sessions:

16:29:24  16:29:24
16:44:39  16:44:39
23:17:24  23:17:25
23:22:53  23:22:53
23:49:26  23:49:27
23:53:24  23:53:24        23:53:29  23:53:29
00:59:54  00:59:54
01:09:34  01:09:35
01:42:58  01:42:59
01:59:32  01:59:33
02:11:41  02:11:42        02:11:46  02:11:47
02:13:03  02:13:03
02:17:12  02:17:12
03:12:24  03:12:25

19 of 35 inter-arrival gaps are under 60 seconds; the median gap is 5 seconds and the maximum is three hours.

Doubling, not one-per-tool-call. I cannot say from this log which of the obvious causes it is — a client that initializes twice, an initialize that fails inside the MCP layer and is retried, or two mounts connecting together — and I would rather leave that open than pick the plausible one.

What this does to the issue

The premise needs restating. The session cost here is two per connection, not one per tool call, and it is decoupled from tool use entirely because there is no tool use. Whatever is consuming sessions is doing it at connect time.

And it is consistent with the mount explanation rather than with a session-reuse bug. matrix-mcp#118: a mount keeps the tool set it connected with and this server emits no list_changed. A mount that connects, receives its tools and is never used produces exactly this: initializes, session traffic, no calls. The 73 authenticated non-introspect requests that were not initializes are session-bearing traffic, stream or teardown, with no tool among them.

The raise was still right and for a reason unaffected by this. 36 initializes in eleven hours against the old burst of 8 refilling one per thirty minutes would have refused; against 24 refilling one per minute it did not, and refused=0 across the whole window is the measurement rather than the prediction.

Method

Counted with regexp against the nested tracing fields, not | json, for the reason in AGENTS.md. admitted MCP initialize and the refusal line both landed in v0.2.1; before it, none of these numbers existed on any of the three servers this claim spans.

## The count exists now, and it is not the shape this issue predicted `v0.2.1` has been serving since `2026-08-26T16:22Z`. Eleven hours of production traffic, counted from the server rather than inferred from a call graph: ```text admitted initializes 36 refused initializes 0 tool calls 0 authenticated non-introspect requests 109 token introspections 113 ``` **Zero tool calls.** Not one in eleven hours, against 36 sessions opened. So the claim in this issue, that twenty-four events cost twenty-four initializes, is not what this server sees. Sessions are being opened and nothing is being invoked in them. ## The initializes arrive in pairs Every connection event produces exactly two, in the same second or one apart. Eighteen events, thirty-six sessions: ```text 16:29:24 16:29:24 16:44:39 16:44:39 23:17:24 23:17:25 23:22:53 23:22:53 23:49:26 23:49:27 23:53:24 23:53:24 23:53:29 23:53:29 00:59:54 00:59:54 01:09:34 01:09:35 01:42:58 01:42:59 01:59:32 01:59:33 02:11:41 02:11:42 02:11:46 02:11:47 02:13:03 02:13:03 02:17:12 02:17:12 03:12:24 03:12:25 ``` 19 of 35 inter-arrival gaps are under 60 seconds; the median gap is 5 seconds and the maximum is three hours. **Doubling, not one-per-tool-call.** I cannot say from this log which of the obvious causes it is — a client that initializes twice, an initialize that fails inside the MCP layer and is retried, or two mounts connecting together — and I would rather leave that open than pick the plausible one. ## What this does to the issue **The premise needs restating.** The session cost here is two per connection, not one per tool call, and it is decoupled from tool use entirely because there is no tool use. Whatever is consuming sessions is doing it at connect time. **And it is consistent with the mount explanation rather than with a session-reuse bug.** `matrix-mcp#118`: a mount keeps the tool set it connected with and this server emits no `list_changed`. A mount that connects, receives its tools and is never used produces exactly this: initializes, session traffic, no calls. The 73 authenticated non-introspect requests that were not initializes are session-bearing traffic, stream or teardown, with no tool among them. **The raise was still right and for a reason unaffected by this.** 36 initializes in eleven hours against the old burst of 8 refilling one per thirty minutes would have refused; against 24 refilling one per minute it did not, and `refused=0` across the whole window is the measurement rather than the prediction. ## Method Counted with `regexp` against the nested `tracing` fields, not `| json`, for the reason in `AGENTS.md`. `admitted MCP initialize` and the refusal line both landed in `v0.2.1`; before it, none of these numbers existed on any of the three servers this claim spans.
Sign in to join this conversation.
No Branch/Tag specified
Branches Tags
main
beta
v0.3.0
v0.2.2
v0.2.1
v0.2.0
v0.1.2-beta.20260826052605
v0.1.2
v0.1.1
v0.1.0
Labels
Clear labels   
blocked
Held on something external and named in the body: an issue, a credential, a measurement. Not the same as unreviewed.

  
waiting-on-julian
Blocked on Julian. The ask is in the issue.

No labels
blocked
waiting-on-julian
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
jlxq0/caldav-mcp#21
No description provided.