Repository navigation
test(api): ignore late logs of earlier requests in McpToolErrorTests - #1249
Merged
Merged
Conversation
McpToolErrorTests cleared its sink after connecting, but the handshake's server/discover POST can finish logging after the client has returned. When that POST ended in TaskCanceledException, request logging recorded a 500 at Error after the clear, and "logs no Error" failed (main at f18267f, #1237 at d9ff13e). The assertions now read only the latest tools/call request's events, by trace id, and the clear is gone.
Reading only the call's trace also hid an Error logged with no Activity or under another trace. The sink is again cleared after connecting, and the assertions exclude only events carrying the trace of the server/discover request seen during the connect. With no such trace, nothing is excluded.
Run 38174048915 failed ConstructionFault_LogsAtError_UnlessAnArgumentIsBad on the same race as the handshake: the first call's POST logged its cancelled 500 after the test's second clear. The sink's Clear now records the trace of every request it has seen, and the assertions exclude only later events of those traces. An event with no trace or a new trace still counts.
This was referenced Oct 12, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
McpToolErrorTestsfailed intermittently in CI because of a race in the test. This PR changes only the test; product behaviour is unchanged.Closes #1246
The race
The test clears its log sink so that only the call under test remains: once after connecting, and once between the two calls in
ConstructionFault_LogsAtError_UnlessAnArgumentIsBad. A request that the client has already finished with can still be completing on the server. When it ends in aTaskCanceledException, request logging recordsHTTP POST /mcp responded 500at Error after the clear. The test then counts that event against the call under test.The CI logs show both kinds of earlier request:
server/discoverPOST. fix(mcp): match flock names ignoring case, plain optional schema types, quiet idempotent replays #1237 atd9ff13e9(run 38172596953): the stray Error and theserver/discoverhandler event share SpanId8a86d4c362ee0d85.mainatc122b150(run 38174048915), inConstructionFault_LogsAtError_UnlessAnArgumentIsBad: the stray Error shares SpanIdc5eee55c799b3148with that test's firsttools/call, logged after the second clear.The other failures listed in #1246 have the same signature:
mainatf18267fc(run 38171174745), PR #1245, and #1237 atf6db0535(run 38174306632).The fix
Every event of one request carries that request's trace id. The test sink now has a
Clear()that records the trace of every event it has seen before emptying itself. The assertions readsink.Observed, which drops only later events carrying one of those recorded traces. An event with no trace, or with a trace the sink has not seen, still counts. So an Error of unknown origin still fails the test.Proof
I could not force a real late abort without changing product code. So I injected the event CI logged into the sink, after the call under test:
POST /mcp responded 500at Error, with aTaskCanceledException. The table shows results for the 13BadArgumentcases and forConstructionFault.BadArgument(13)ConstructionFault(1)server/discover, or the first call'sWithout injection, the class (20 cases) passed 25 runs out of 25 at
6d955537.Open question
The server logs an MCP POST that the client abandons as a 500 at Error. In these runs, the handler had already completed, and the client already had its answer. That is request logging's ordinary behaviour, and this PR leaves it unchanged. Should an aborted
/mcpPOST be logged below Error?