Description
Summary
The test "reports multiple progress updates without buffering" is intermittently failing with the error:
AssertionError: expected "spy" to be called 4 times, but got 3 timesThis is relevant to this PR: #116
Since using steps: 3 or steps: 4 can both pass the test cases, this issue did not trigger any attention.
Reproduce
- Add logging in the
FastMCP.tsline1411to see if all 4 notifications are actually sent from the server:
console.log(`Progress sent: ${progress.progress}/${progress.total}`);- Run thest test case multiple times
pnpm test -t "reports multiple progress updates without buffering"It is likely to see the below failed test result with loggings
stdout | src/FastMCP.test.ts > reports multiple progress updates without buffering
[FastMCP info] server is running on HTTP Stream at http://localhost:60312/mcp
stdout | src/FastMCP.test.ts > reports multiple progress updates without buffering
Progress sent: 0/100
stdout | src/FastMCP.test.ts > reports multiple progress updates without buffering
Progress sent: 50/100
stdout | src/FastMCP.test.ts > reports multiple progress updates without buffering
Progress sent: 90/100
stdout | src/FastMCP.test.ts > reports multiple progress updates without buffering
Progress sent: 100/100
❯ src/FastMCP.test.ts (42 tests | 1 failed | 41 skipped) 359ms
× reports multiple progress updates without buffering 358ms
→ expected "spy" to be called 4 times, but got 3 times
⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯ Failed Tests 1 ⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯
FAIL src/FastMCP.test.ts > reports multiple progress updates without buffering
AssertionError: expected "spy" to be called 4 times, but got 3 timesInvestigation Results
Through debugging with console logs, we confirmed that:
✅ All 4 progress notifications are sent from the server (logs show Progress sent: 0/100, 50/100, 90/100, 100/100)
❌ Only 3 progress notifications are received by the client intermittently
✅ Server-side event loop flushing is working correctly (#needsEventLoopFlush with setImmediate)
Potential cause
It is occurred at the transport/client layer, not the server layer. There's a race condition between:
- The final progress notification
(progress: 100, total: 100)being sent via HTTP Stream - The
tool completionresponse being sent immediately after
Solution
I am not sure if we should fix the test case like below. I am still not certain about the actual cause of it
// In the server setup, modify the tool execution:
server.addTool({
description: "Test tool for progress buffering fix",
execute: async (args, { reportProgress }) => {
const { steps } = args;
await reportProgress({ progress: 0, total: 100 });
for (let i = 1; i <= steps; i++) {
await delay(50);
if (i === 1) {
await reportProgress({ progress: 50, total: 100 });
} else if (i === 2) {
await reportProgress({ progress: 90, total: 100 });
}
}
await reportProgress({ progress: 100, total: 100 });
// Small delay to ensure final progress is processed
await delay(100);
return "Progress test completed";
},
// ... rest unchanged
});