From 1dc100f98214516cb4071edfc306046a11ac4556 Mon Sep 17 00:00:00 2001 From: Kyle Kincer Date: Tue, 3 Feb 2026 11:54:27 -0500 Subject: [PATCH] feat(client): add timing information to request history and notifications Add temporal context to help debug MCP server behavior: - Display request-to-response duration (e.g., "245ms", "2.4s") - Show timestamps for requests and notifications - Add expanded view with full timing details Co-Authored-By: Claude Opus 4.5 --- client/src/App.tsx | 11 +- .../components/HistoryAndNotifications.tsx | 69 +++++-- .../HistoryAndNotifications.test.tsx | 168 ++++++++++++++---- client/src/lib/hooks/useConnection.ts | 27 ++- client/src/lib/notificationTypes.ts | 6 + client/src/lib/types/requestHistory.ts | 7 + client/src/utils/__tests__/timeUtils.test.ts | 65 +++++++ client/src/utils/timeUtils.ts | 43 +++++ 8 files changed, 338 insertions(+), 58 deletions(-) create mode 100644 client/src/lib/types/requestHistory.ts create mode 100644 client/src/utils/__tests__/timeUtils.test.ts create mode 100644 client/src/utils/timeUtils.ts diff --git a/client/src/App.tsx b/client/src/App.tsx index 39fc2812a..9d8ce69b2 100644 --- a/client/src/App.tsx +++ b/client/src/App.tsx @@ -19,6 +19,7 @@ import { Task, GetTaskResultSchema, } from "@modelcontextprotocol/sdk/types.js"; +import { TimestampedNotification } from "./lib/notificationTypes"; import { OAuthTokensSchema } from "@modelcontextprotocol/sdk/shared/auth.js"; import type { AnySchema, @@ -154,7 +155,9 @@ const App = () => { }, ); const [logLevel, setLogLevel] = useState("debug"); - const [notifications, setNotifications] = useState([]); + const [notifications, setNotifications] = useState( + [], + ); const [roots, setRoots] = useState([]); const [env, setEnv] = useState>({}); @@ -366,7 +369,11 @@ const App = () => { config, connectionType, onNotification: (notification) => { - setNotifications((prev) => [...prev, notification as ServerNotification]); + const timestamped: TimestampedNotification = { + notification: notification as ServerNotification, + receivedAt: new Date().toISOString(), + }; + setNotifications((prev) => [...prev, timestamped]); if (notification.method === "notifications/tasks/list_changed") { void listTasks(); diff --git a/client/src/components/HistoryAndNotifications.tsx b/client/src/components/HistoryAndNotifications.tsx index 1c6060712..bfefbd41b 100644 --- a/client/src/components/HistoryAndNotifications.tsx +++ b/client/src/components/HistoryAndNotifications.tsx @@ -1,7 +1,13 @@ -import { ServerNotification } from "@modelcontextprotocol/sdk/types.js"; import { useState } from "react"; import JsonView from "./JsonView"; import { Button } from "@/components/ui/button"; +import { RequestHistoryEntry } from "@/lib/types/requestHistory"; +import { TimestampedNotification } from "@/lib/notificationTypes"; +import { + formatDuration, + formatTimestamp, + formatTimestampFull, +} from "@/utils/timeUtils"; const HistoryAndNotifications = ({ requestHistory, @@ -9,8 +15,8 @@ const HistoryAndNotifications = ({ onClearHistory, onClearNotifications, }: { - requestHistory: Array<{ request: string; response?: string }>; - serverNotifications: ServerNotification[]; + requestHistory: RequestHistoryEntry[]; + serverNotifications: TimestampedNotification[]; onClearHistory?: () => void; onClearNotifications?: () => void; }) => { @@ -52,7 +58,7 @@ const HistoryAndNotifications = ({ {requestHistory .slice() .reverse() - .map((request, index) => ( + .map((entry, index) => (
  • - + {requestHistory.length - index}.{" "} - {JSON.parse(request.request).method} + {JSON.parse(entry.request).method} + {entry.durationMs !== undefined && ( + + {formatDuration(entry.durationMs)} + + )} - + + + {formatTimestamp(entry.requestedAt)} + {expandedRequests[requestHistory.length - 1 - index] ? "▼" : "▶"} @@ -75,6 +89,24 @@ const HistoryAndNotifications = ({ {expandedRequests[requestHistory.length - 1 - index] && ( <> +
    +
    +
    + Requested: {formatTimestampFull(entry.requestedAt)} +
    + {entry.respondedAt && ( +
    + Responded:{" "} + {formatTimestampFull(entry.respondedAt)} + {entry.durationMs !== undefined && ( + + ({formatDuration(entry.durationMs)}) + + )} +
    + )} +
    +
    @@ -83,11 +115,11 @@ const HistoryAndNotifications = ({
    - {request.response && ( + {entry.response && (
    @@ -95,7 +127,7 @@ const HistoryAndNotifications = ({
    @@ -128,7 +160,7 @@ const HistoryAndNotifications = ({ {serverNotifications .slice() .reverse() - .map((notification, index) => ( + .map((timestamped, index) => (
  • {serverNotifications.length - index}.{" "} - {notification.method} + {timestamped.notification.method} - + + + {formatTimestamp(timestamped.receivedAt)} + {expandedNotifications[ serverNotifications.length - 1 - index ] @@ -157,13 +192,19 @@ const HistoryAndNotifications = ({ serverNotifications.length - 1 - index ] && (
    +
    +
    + Received:{" "} + {formatTimestampFull(timestamped.receivedAt)} +
    +
    Details:
    diff --git a/client/src/components/__tests__/HistoryAndNotifications.test.tsx b/client/src/components/__tests__/HistoryAndNotifications.test.tsx index 21f36a31b..3d82c0968 100644 --- a/client/src/components/__tests__/HistoryAndNotifications.test.tsx +++ b/client/src/components/__tests__/HistoryAndNotifications.test.tsx @@ -2,7 +2,8 @@ import { render, screen, fireEvent, within } from "@testing-library/react"; import { useState } from "react"; import { describe, it, expect, jest } from "@jest/globals"; import HistoryAndNotifications from "../HistoryAndNotifications"; -import { ServerNotification } from "@modelcontextprotocol/sdk/types.js"; +import { RequestHistoryEntry } from "@/lib/types/requestHistory"; +import { TimestampedNotification } from "@/lib/notificationTypes"; // Mock JsonView component jest.mock("../JsonView", () => { @@ -12,32 +13,44 @@ jest.mock("../JsonView", () => { }); describe("HistoryAndNotifications", () => { - const mockRequestHistory = [ + const mockRequestHistory: RequestHistoryEntry[] = [ { request: JSON.stringify({ method: "test/method1", params: {} }), response: JSON.stringify({ result: "success" }), + requestedAt: "2026-01-15T14:34:56.000Z", + respondedAt: "2026-01-15T14:34:56.245Z", + durationMs: 245, }, { request: JSON.stringify({ method: "test/method2", params: {} }), response: JSON.stringify({ result: "success" }), + requestedAt: "2026-01-15T14:35:00.000Z", + respondedAt: "2026-01-15T14:35:02.400Z", + durationMs: 2400, }, ]; - const mockNotifications: ServerNotification[] = [ + const mockNotifications: TimestampedNotification[] = [ { - method: "notifications/message", - params: { - level: "info" as const, - data: "First notification", + notification: { + method: "notifications/message", + params: { + level: "info" as const, + data: "First notification", + }, }, + receivedAt: "2026-01-15T14:34:56.000Z", }, { - method: "notifications/progress", - params: { - progressToken: "test-token", - progress: 50, - total: 100, + notification: { + method: "notifications/progress", + params: { + progressToken: "test-token", + progress: 50, + total: 100, + }, }, + receivedAt: "2026-01-15T14:35:00.000Z", }, ]; @@ -62,8 +75,21 @@ describe("HistoryAndNotifications", () => { ); // Items should be numbered in reverse order (newest first) - expect(screen.getByText("2. test/method2")).toBeTruthy(); - expect(screen.getByText("1. test/method1")).toBeTruthy(); + expect(screen.getByText(/2\.\s+test\/method2/)).toBeTruthy(); + expect(screen.getByText(/1\.\s+test\/method1/)).toBeTruthy(); + }); + + it("displays duration badges on request history items", () => { + render( + , + ); + + // Check for duration badges + expect(screen.getByText("245ms")).toBeTruthy(); + expect(screen.getByText("2.4s")).toBeTruthy(); }); it("displays server notifications with correct numbering", () => { @@ -75,8 +101,8 @@ describe("HistoryAndNotifications", () => { ); // Items should be numbered in reverse order (newest first) - expect(screen.getByText("2. notifications/progress")).toBeTruthy(); - expect(screen.getByText("1. notifications/message")).toBeTruthy(); + expect(screen.getByText(/2\.\s+notifications\/progress/)).toBeTruthy(); + expect(screen.getByText(/1\.\s+notifications\/message/)).toBeTruthy(); }); it("expands and collapses request items when clicked", () => { @@ -87,7 +113,7 @@ describe("HistoryAndNotifications", () => { />, ); - const firstRequestHeader = screen.getByText("2. test/method2"); + const firstRequestHeader = screen.getByText(/2\.\s+test\/method2/); // Initially collapsed - should show ▶ arrows (there are multiple) expect(screen.getAllByText("▶")).toHaveLength(2); @@ -103,6 +129,24 @@ describe("HistoryAndNotifications", () => { expect(screen.getByText("Response:")).toBeTruthy(); }); + it("shows timing details when expanded", () => { + render( + , + ); + + const firstRequestHeader = screen.getByText(/2\.\s+test\/method2/); + + // Click to expand + fireEvent.click(firstRequestHeader); + + // Should show timing details + expect(screen.getByText(/Requested:/)).toBeTruthy(); + expect(screen.getByText(/Responded:/)).toBeTruthy(); + }); + it("expands and collapses notification items when clicked", () => { render( { ); const firstNotificationHeader = screen.getByText( - "2. notifications/progress", + /2\.\s+notifications\/progress/, ); // Initially collapsed @@ -128,6 +172,25 @@ describe("HistoryAndNotifications", () => { expect(screen.getByText("Details:")).toBeTruthy(); }); + it("shows received timestamp when notification is expanded", () => { + render( + , + ); + + const firstNotificationHeader = screen.getByText( + /2\.\s+notifications\/progress/, + ); + + // Click to expand + fireEvent.click(firstNotificationHeader); + + // Should show received timestamp + expect(screen.getByText(/Received:/)).toBeTruthy(); + }); + it("maintains expanded state when new notifications are added", () => { const { rerender } = render( { // Find and expand the older notification (should be "1. notifications/message") const olderNotificationHeader = screen.getByText( - "1. notifications/message", + /1\.\s+notifications\/message/, ); fireEvent.click(olderNotificationHeader); @@ -146,10 +209,13 @@ describe("HistoryAndNotifications", () => { expect(screen.getByText("Details:")).toBeTruthy(); // Add a new notification at the beginning (simulating real behavior) - const newNotifications: ServerNotification[] = [ + const newNotifications: TimestampedNotification[] = [ { - method: "notifications/resources/updated", - params: { uri: "file://test.txt" }, + notification: { + method: "notifications/resources/updated", + params: { uri: "file://test.txt" }, + }, + receivedAt: "2026-01-15T14:36:00.000Z", }, ...mockNotifications, ]; @@ -164,9 +230,11 @@ describe("HistoryAndNotifications", () => { // The original notification should still be expanded // It's now numbered as "2. notifications/message" due to the new item - expect(screen.getByText("3. notifications/progress")).toBeTruthy(); - expect(screen.getByText("2. notifications/message")).toBeTruthy(); - expect(screen.getByText("1. notifications/resources/updated")).toBeTruthy(); + expect(screen.getByText(/3\.\s+notifications\/progress/)).toBeTruthy(); + expect(screen.getByText(/2\.\s+notifications\/message/)).toBeTruthy(); + expect( + screen.getByText(/1\.\s+notifications\/resources\/updated/), + ).toBeTruthy(); // The originally expanded notification should still show its details expect(screen.getByText("Details:")).toBeTruthy(); @@ -181,7 +249,7 @@ describe("HistoryAndNotifications", () => { ); // Find and expand the older request (should be "1. test/method1") - const olderRequestHeader = screen.getByText("1. test/method1"); + const olderRequestHeader = screen.getByText(/1\.\s+test\/method1/); fireEvent.click(olderRequestHeader); // Verify it's expanded @@ -189,10 +257,13 @@ describe("HistoryAndNotifications", () => { expect(screen.getByText("Response:")).toBeTruthy(); // Add a new request at the beginning - const newRequestHistory = [ + const newRequestHistory: RequestHistoryEntry[] = [ { request: JSON.stringify({ method: "test/new_method", params: {} }), response: JSON.stringify({ result: "new success" }), + requestedAt: "2026-01-15T14:36:00.000Z", + respondedAt: "2026-01-15T14:36:00.100Z", + durationMs: 100, }, ...mockRequestHistory, ]; @@ -207,9 +278,9 @@ describe("HistoryAndNotifications", () => { // The original request should still be expanded // It's now numbered as "2. test/method1" due to the new item - expect(screen.getByText("3. test/method2")).toBeTruthy(); - expect(screen.getByText("2. test/method1")).toBeTruthy(); - expect(screen.getByText("1. test/new_method")).toBeTruthy(); + expect(screen.getByText(/3\.\s+test\/method2/)).toBeTruthy(); + expect(screen.getByText(/2\.\s+test\/method1/)).toBeTruthy(); + expect(screen.getByText(/1\.\s+test\/new_method/)).toBeTruthy(); // The originally expanded request should still show its details expect(screen.getByText("Request:")).toBeTruthy(); @@ -227,7 +298,8 @@ describe("HistoryAndNotifications", () => { it("clears request history when Clear is clicked", () => { const Wrapper = () => { - const [history, setHistory] = useState(mockRequestHistory); + const [history, setHistory] = + useState(mockRequestHistory); return ( { render(); // Verify items are present initially - expect(screen.getByText("2. test/method2")).toBeTruthy(); - expect(screen.getByText("1. test/method1")).toBeTruthy(); + expect(screen.getByText(/2\.\s+test\/method2/)).toBeTruthy(); + expect(screen.getByText(/1\.\s+test\/method1/)).toBeTruthy(); // Click Clear in History header (scoped by the History heading's container) const historyHeader = screen.getByText("History"); @@ -259,7 +331,7 @@ describe("HistoryAndNotifications", () => { it("clears server notifications when Clear is clicked", () => { const Wrapper = () => { const [notifications, setNotifications] = - useState(mockNotifications); + useState(mockNotifications); return ( { render(); // Verify items are present initially - expect(screen.getByText("2. notifications/progress")).toBeTruthy(); - expect(screen.getByText("1. notifications/message")).toBeTruthy(); + expect(screen.getByText(/2\.\s+notifications\/progress/)).toBeTruthy(); + expect(screen.getByText(/1\.\s+notifications\/message/)).toBeTruthy(); // Click Clear in Server Notifications header (scoped by its heading's container) const notifHeader = screen.getByText("Server Notifications"); @@ -286,4 +358,28 @@ describe("HistoryAndNotifications", () => { // Notifications should now be empty expect(screen.getByText("No notifications yet")).toBeTruthy(); }); + + it("handles requests without response timing", () => { + const pendingRequest: RequestHistoryEntry[] = [ + { + request: JSON.stringify({ method: "test/pending", params: {} }), + requestedAt: "2026-01-15T14:34:56.000Z", + // No response, respondedAt, or durationMs + }, + ]; + + render( + , + ); + + // Should render without duration badge (look for the badge element by class) + expect(screen.getByText(/1\.\s+test\/pending/)).toBeTruthy(); + // The duration badge has specific styling - check it's not present + expect( + screen.queryByText(/^\d+ms$|^\d+\.\d+s$|^\d+s$|^\d+m\s*\d*s?$/), + ).toBeNull(); + }); }); diff --git a/client/src/lib/hooks/useConnection.ts b/client/src/lib/hooks/useConnection.ts index e14d1037f..4f024a55e 100644 --- a/client/src/lib/hooks/useConnection.ts +++ b/client/src/lib/hooks/useConnection.ts @@ -52,6 +52,7 @@ import { useEffect, useRef, useState } from "react"; import { useToast } from "@/lib/hooks/useToast"; import { ConnectionStatus, CLIENT_IDENTITY } from "../constants"; import { Notification } from "../notificationTypes"; +import { RequestHistoryEntry } from "../types/requestHistory"; import { auth, discoverOAuthProtectedResourceMetadata, @@ -131,9 +132,9 @@ export function useConnection({ const [clientTransport, setClientTransport] = useState( null, ); - const [requestHistory, setRequestHistory] = useState< - { request: string; response?: string }[] - >([]); + const [requestHistory, setRequestHistory] = useState( + [], + ); const [completionsSupported, setCompletionsSupported] = useState(false); const [mcpSessionId, setMcpSessionId] = useState(null); const [mcpProtocolVersion, setMcpProtocolVersion] = useState( @@ -187,12 +188,25 @@ export function useConnection({ saveScopeToSessionStorage(sseUrl, oauthScope); }, [oauthScope, sseUrl]); - const pushHistory = (request: object, response?: object) => { + const pushHistory = ( + request: object, + response?: object, + requestedAt?: string, + ) => { + const now = new Date().toISOString(); + const requestTime = requestedAt || now; + const responseTime = response !== undefined ? now : undefined; + setRequestHistory((prev) => [ ...prev, { request: JSON.stringify(request), response: response !== undefined ? JSON.stringify(response) : undefined, + requestedAt: requestTime, + respondedAt: responseTime, + durationMs: responseTime + ? new Date(responseTime).getTime() - new Date(requestTime).getTime() + : undefined, }, ]); }; @@ -205,6 +219,7 @@ export function useConnection({ if (!mcpClient) { throw new Error("MCP client not connected"); } + const requestedAt = new Date().toISOString(); try { const abortController = new AbortController(); @@ -256,11 +271,11 @@ export function useConnection({ mcpRequestOptions, ); - pushHistory(requestWithMetadata, response); + pushHistory(requestWithMetadata, response, requestedAt); } catch (error) { const errorMessage = error instanceof Error ? error.message : String(error); - pushHistory(requestWithMetadata, { error: errorMessage }); + pushHistory(requestWithMetadata, { error: errorMessage }, requestedAt); throw error; } diff --git a/client/src/lib/notificationTypes.ts b/client/src/lib/notificationTypes.ts index e7cc1cb56..ad80b890e 100644 --- a/client/src/lib/notificationTypes.ts +++ b/client/src/lib/notificationTypes.ts @@ -2,6 +2,7 @@ import { NotificationSchema as BaseNotificationSchema, ClientNotificationSchema, ServerNotificationSchema, + ServerNotification, } from "@modelcontextprotocol/sdk/types.js"; import type { SchemaOutput } from "@modelcontextprotocol/sdk/server/zod-compat.js"; @@ -10,3 +11,8 @@ export const NotificationSchema = ClientNotificationSchema.or( ).or(BaseNotificationSchema); export type Notification = SchemaOutput; + +export interface TimestampedNotification { + notification: ServerNotification; + receivedAt: string; // ISO timestamp when received +} diff --git a/client/src/lib/types/requestHistory.ts b/client/src/lib/types/requestHistory.ts new file mode 100644 index 000000000..780554e59 --- /dev/null +++ b/client/src/lib/types/requestHistory.ts @@ -0,0 +1,7 @@ +export interface RequestHistoryEntry { + request: string; + response?: string; + requestedAt: string; // ISO timestamp when request was sent + respondedAt?: string; // ISO timestamp when response received + durationMs?: number; // Calculated duration in ms +} diff --git a/client/src/utils/__tests__/timeUtils.test.ts b/client/src/utils/__tests__/timeUtils.test.ts new file mode 100644 index 000000000..618fc9de0 --- /dev/null +++ b/client/src/utils/__tests__/timeUtils.test.ts @@ -0,0 +1,65 @@ +import { describe, it, expect } from "@jest/globals"; +import { + formatDuration, + formatTimestamp, + formatTimestampFull, +} from "../timeUtils"; + +describe("timeUtils", () => { + describe("formatDuration", () => { + it("formats milliseconds for values under 1 second", () => { + expect(formatDuration(0)).toBe("0ms"); + expect(formatDuration(1)).toBe("1ms"); + expect(formatDuration(245)).toBe("245ms"); + expect(formatDuration(999)).toBe("999ms"); + }); + + it("formats seconds with one decimal for values under 10 seconds", () => { + expect(formatDuration(1000)).toBe("1.0s"); + expect(formatDuration(1500)).toBe("1.5s"); + expect(formatDuration(2400)).toBe("2.4s"); + expect(formatDuration(9999)).toBe("10.0s"); + }); + + it("formats seconds as integers for values 10 seconds and above", () => { + expect(formatDuration(10000)).toBe("10s"); + expect(formatDuration(15000)).toBe("15s"); + expect(formatDuration(59999)).toBe("60s"); + }); + + it("formats minutes and seconds for values 1 minute and above", () => { + expect(formatDuration(60000)).toBe("1m"); + expect(formatDuration(90000)).toBe("1m 30s"); + expect(formatDuration(120000)).toBe("2m"); + expect(formatDuration(150000)).toBe("2m 30s"); + }); + + it("handles edge cases", () => { + expect(formatDuration(60001)).toBe("1m"); + expect(formatDuration(61000)).toBe("1m 1s"); + }); + }); + + describe("formatTimestamp", () => { + it("formats ISO timestamp to time-only string", () => { + // Using a fixed date to ensure consistent output + const isoString = "2026-01-15T14:34:56.000Z"; + const result = formatTimestamp(isoString); + + // The exact output depends on locale, but it should contain time components + expect(result).toBeTruthy(); + expect(typeof result).toBe("string"); + }); + }); + + describe("formatTimestampFull", () => { + it("formats ISO timestamp to full date/time string", () => { + const isoString = "2026-01-15T14:34:56.000Z"; + const result = formatTimestampFull(isoString); + + // The exact output depends on locale, but it should contain date and time + expect(result).toBeTruthy(); + expect(typeof result).toBe("string"); + }); + }); +}); diff --git a/client/src/utils/timeUtils.ts b/client/src/utils/timeUtils.ts new file mode 100644 index 000000000..a62e3ae5e --- /dev/null +++ b/client/src/utils/timeUtils.ts @@ -0,0 +1,43 @@ +/** + * Format a duration in milliseconds to a human-readable string. + * Examples: "245ms", "2.4s", "1m 30s" + */ +export function formatDuration(ms: number): string { + if (ms < 1000) { + return `${Math.round(ms)}ms`; + } + + if (ms < 60000) { + const seconds = ms / 1000; + // Show one decimal place for values under 10s + if (seconds < 10) { + return `${seconds.toFixed(1)}s`; + } + return `${Math.round(seconds)}s`; + } + + const minutes = Math.floor(ms / 60000); + const seconds = Math.round((ms % 60000) / 1000); + + if (seconds === 0) { + return `${minutes}m`; + } + + return `${minutes}m ${seconds}s`; +} + +/** + * Format an ISO timestamp to a time-only string (e.g., "2:34:56 PM"). + */ +export function formatTimestamp(isoString: string): string { + const date = new Date(isoString); + return date.toLocaleTimeString(); +} + +/** + * Format an ISO timestamp to a full date/time string (e.g., "1/15/2026, 2:34:56 PM"). + */ +export function formatTimestampFull(isoString: string): string { + const date = new Date(isoString); + return date.toLocaleString(); +}