refactor(mcp): enhance MCPService logging and error handling (#9878)

This commit is contained in:
LiuVaayne 2025-09-04 14:52:47 +08:00 committed by kangfenmao
parent 9ff4acf092
commit 07c3c33acc
2 changed files with 119 additions and 60 deletions

View File

@ -56,6 +56,45 @@ type CallToolArgs = { server: MCPServer; name: string; args: any; callId?: strin
const logger = loggerService.withContext('MCPService')
// Redact potentially sensitive fields in objects (headers, tokens, api keys)
function redactSensitive(input: any): any {
const SENSITIVE_KEYS = ['authorization', 'Authorization', 'apiKey', 'api_key', 'apikey', 'token', 'access_token']
const MAX_STRING = 300
const redact = (val: any): any => {
if (val == null) return val
if (typeof val === 'string') {
return val.length > MAX_STRING ? `${val.slice(0, MAX_STRING)}…<${val.length - MAX_STRING} more>` : val
}
if (Array.isArray(val)) return val.map((v) => redact(v))
if (typeof val === 'object') {
const out: Record<string, any> = {}
for (const [k, v] of Object.entries(val)) {
if (SENSITIVE_KEYS.includes(k)) {
out[k] = '<redacted>'
} else {
out[k] = redact(v)
}
}
return out
}
return val
}
return redact(input)
}
// Create a context-aware logger for a server
function getServerLogger(server: MCPServer, extra?: Record<string, any>) {
const base = {
serverName: server?.name,
serverId: server?.id,
baseUrl: server?.baseUrl,
type: server?.type || (server?.command ? 'stdio' : server?.baseUrl ? 'http' : 'inmemory')
}
return loggerService.withContext('MCPService', { ...base, ...(extra || {}) })
}
/**
* Higher-order function to add caching capability to any async function
* @param fn The original function to be wrapped with caching
@ -74,15 +113,17 @@ function withCache<T extends unknown[], R>(
const cacheKey = getCacheKey(...args)
if (CacheService.has(cacheKey)) {
logger.debug(`${logPrefix} loaded from cache`)
logger.debug(`${logPrefix} loaded from cache`, { cacheKey })
const cachedData = CacheService.get<R>(cacheKey)
if (cachedData) {
return cachedData
}
}
const start = Date.now()
const result = await fn(...args)
CacheService.set(cacheKey, result, ttl)
logger.debug(`${logPrefix} cached`, { cacheKey, ttlMs: ttl, durationMs: Date.now() - start })
return result
}
}
@ -128,6 +169,7 @@ class McpService {
// If there's a pending initialization, wait for it
const pendingClient = this.pendingClients.get(serverKey)
if (pendingClient) {
getServerLogger(server).silly(`Waiting for pending client initialization`)
return pendingClient
}
@ -136,8 +178,11 @@ class McpService {
if (existingClient) {
try {
// Check if the existing client is still connected
const pingResult = await existingClient.ping()
logger.debug(`Ping result for ${server.name}:`, pingResult)
const pingResult = await existingClient.ping({
// add short timeout to prevent hanging
timeout: 1000
})
getServerLogger(server).debug(`Ping result`, { ok: !!pingResult })
// If the ping fails, remove the client from the cache
// and create a new one
if (!pingResult) {
@ -146,7 +191,7 @@ class McpService {
return existingClient
}
} catch (error: any) {
logger.error(`Error pinging server ${server.name}:`, error?.message)
getServerLogger(server).error(`Error pinging server`, error as Error)
this.clients.delete(serverKey)
}
}
@ -172,15 +217,15 @@ class McpService {
> => {
// Create appropriate transport based on configuration
if (isBuiltinMCPServer(server) && server.name !== BuiltinMCPServerNames.mcpAutoInstall) {
logger.debug(`Using in-memory transport for server: ${server.name}`)
getServerLogger(server).debug(`Using in-memory transport`)
const [clientTransport, serverTransport] = InMemoryTransport.createLinkedPair()
// start the in-memory server with the given name and environment variables
const inMemoryServer = createInMemoryMCPServer(server.name, args, server.env || {})
try {
await inMemoryServer.connect(serverTransport)
logger.debug(`In-memory server started: ${server.name}`)
getServerLogger(server).debug(`In-memory server started`)
} catch (error: Error | any) {
logger.error(`Error starting in-memory server: ${error}`)
getServerLogger(server).error(`Error starting in-memory server`, error as Error)
throw new Error(`Failed to start in-memory server: ${error.message}`)
}
// set the client transport to the client
@ -193,7 +238,10 @@ class McpService {
},
authProvider
}
logger.debug(`StreamableHTTPClientTransport options:`, options)
// redact headers before logging
getServerLogger(server).debug(`StreamableHTTPClientTransport options`, {
options: redactSensitive(options)
})
return new StreamableHTTPClientTransport(new URL(server.baseUrl!), options)
} else if (server.type === 'sse') {
const options: SSEClientTransportOptions = {
@ -209,7 +257,7 @@ class McpService {
headers['Authorization'] = `Bearer ${tokens.access_token}`
}
} catch (error) {
logger.error('Failed to fetch tokens:', error as Error)
getServerLogger(server).error('Failed to fetch tokens:', error as Error)
}
}
@ -239,15 +287,18 @@ class McpService {
...server.env,
...resolvedConfig.env
}
logger.debug(`Using resolved DXT config - command: ${cmd}, args: ${args?.join(' ')}`)
getServerLogger(server).debug(`Using resolved DXT config`, {
command: cmd,
args
})
} else {
logger.warn(`Failed to resolve DXT config for ${server.name}, falling back to manifest values`)
getServerLogger(server).warn(`Failed to resolve DXT config, falling back to manifest values`)
}
}
if (server.command === 'npx') {
cmd = await getBinaryPath('bun')
logger.debug(`Using command: ${cmd}`)
getServerLogger(server).debug(`Using command`, { command: cmd })
// add -x to args if args exist
if (args && args.length > 0) {
@ -282,7 +333,7 @@ class McpService {
}
}
logger.debug(`Starting server with command: ${cmd} ${args ? args.join(' ') : ''}`)
getServerLogger(server).debug(`Starting server`, { command: cmd, args })
// Logger.info(`[MCP] Environment variables for server:`, server.env)
const loginShellEnv = await this.getLoginShellEnv()
@ -304,12 +355,14 @@ class McpService {
// For DXT servers, set the working directory to the extracted path
if (server.dxtPath) {
transportOptions.cwd = server.dxtPath
logger.debug(`Setting working directory for DXT server: ${server.dxtPath}`)
getServerLogger(server).debug(`Setting working directory for DXT server`, {
cwd: server.dxtPath
})
}
const stdioTransport = new StdioClientTransport(transportOptions)
stdioTransport.stderr?.on('data', (data) =>
logger.debug(`Stdio stderr for server: ${server.name}` + data.toString())
getServerLogger(server).debug(`Stdio stderr`, { data: data.toString() })
)
return stdioTransport
} else {
@ -318,7 +371,7 @@ class McpService {
}
const handleAuth = async (client: Client, transport: SSEClientTransport | StreamableHTTPClientTransport) => {
logger.debug(`Starting OAuth flow for server: ${server.name}`)
getServerLogger(server).debug(`Starting OAuth flow`)
// Create an event emitter for the OAuth callback
const events = new EventEmitter()
@ -331,27 +384,27 @@ class McpService {
// Set a timeout to close the callback server
const timeoutId = setTimeout(() => {
logger.warn(`OAuth flow timed out for server: ${server.name}`)
getServerLogger(server).warn(`OAuth flow timed out`)
callbackServer.close()
}, 300000) // 5 minutes timeout
try {
// Wait for the authorization code
const authCode = await callbackServer.waitForAuthCode()
logger.debug(`Received auth code: ${authCode}`)
getServerLogger(server).debug(`Received auth code`)
// Complete the OAuth flow
await transport.finishAuth(authCode)
logger.debug(`OAuth flow completed for server: ${server.name}`)
getServerLogger(server).debug(`OAuth flow completed`)
const newTransport = await initTransport()
// Try to connect again
await client.connect(newTransport)
logger.debug(`Successfully authenticated with server: ${server.name}`)
getServerLogger(server).debug(`Successfully authenticated`)
} catch (oauthError) {
logger.error(`OAuth authentication failed for server ${server.name}:`, oauthError as Error)
getServerLogger(server).error(`OAuth authentication failed`, oauthError as Error)
throw new Error(
`OAuth authentication failed: ${oauthError instanceof Error ? oauthError.message : String(oauthError)}`
)
@ -390,7 +443,7 @@ class McpService {
logger.debug(`Activated server: ${server.name}`)
return client
} catch (error: any) {
logger.error(`Error activating server ${server.name}:`, error?.message)
getServerLogger(server).error(`Error activating server`, error as Error)
throw new Error(`[MCP] Error activating server ${server.name}: ${error.message}`)
}
} finally {
@ -450,9 +503,9 @@ class McpService {
logger.debug(`Message from server ${server.name}:`, notification.params)
})
logger.debug(`Set up notification handlers for server: ${server.name}`)
getServerLogger(server).debug(`Set up notification handlers`)
} catch (error) {
logger.error(`Failed to set up notification handlers for server ${server.name}:`, error as Error)
getServerLogger(server).error(`Failed to set up notification handlers`, error as Error)
}
}
@ -470,7 +523,7 @@ class McpService {
CacheService.remove(`mcp:list_tool:${serverKey}`)
CacheService.remove(`mcp:list_prompts:${serverKey}`)
CacheService.remove(`mcp:list_resources:${serverKey}`)
logger.debug(`Cleared all caches for server: ${serverKey}`)
logger.debug(`Cleared all caches for server`, { serverKey })
}
async closeClient(serverKey: string) {
@ -478,18 +531,18 @@ class McpService {
if (client) {
// Remove the client from the cache
await client.close()
logger.debug(`Closed server: ${serverKey}`)
logger.debug(`Closed server`, { serverKey })
this.clients.delete(serverKey)
// Clear all caches for this server
this.clearServerCache(serverKey)
} else {
logger.warn(`No client found for server: ${serverKey}`)
logger.warn(`No client found for server`, { serverKey })
}
}
async stopServer(_: Electron.IpcMainInvokeEvent, server: MCPServer) {
const serverKey = this.getServerKey(server)
logger.debug(`Stopping server: ${server.name}`)
getServerLogger(server).debug(`Stopping server`)
await this.closeClient(serverKey)
}
@ -505,16 +558,16 @@ class McpService {
try {
const cleaned = this.dxtService.cleanupDxtServer(server.name)
if (cleaned) {
logger.debug(`Cleaned up DXT server directory for: ${server.name}`)
getServerLogger(server).debug(`Cleaned up DXT server directory`)
}
} catch (error) {
logger.error(`Failed to cleanup DXT server: ${server.name}`, error as Error)
getServerLogger(server).error(`Failed to cleanup DXT server`, error as Error)
}
}
}
async restartServer(_: Electron.IpcMainInvokeEvent, server: MCPServer) {
logger.debug(`Restarting server: ${server.name}`)
getServerLogger(server).debug(`Restarting server`)
const serverKey = this.getServerKey(server)
await this.closeClient(serverKey)
// Clear cache before restarting to ensure fresh data
@ -527,7 +580,7 @@ class McpService {
try {
await this.closeClient(key)
} catch (error: any) {
logger.error(`Failed to close client: ${error?.message}`)
logger.error(`Failed to close client`, error as Error)
}
}
}
@ -536,9 +589,9 @@ class McpService {
* Check connectivity for an MCP server
*/
public async checkMcpConnectivity(_: Electron.IpcMainInvokeEvent, server: MCPServer): Promise<boolean> {
logger.debug(`Checking connectivity for server: ${server.name}`)
getServerLogger(server).debug(`Checking connectivity`)
try {
logger.debug(`About to call initClient for server: ${server.name}`, { hasInitClient: !!this.initClient })
getServerLogger(server).debug(`About to call initClient`, { hasInitClient: !!this.initClient })
if (!this.initClient) {
throw new Error('initClient method is not available')
@ -547,10 +600,10 @@ class McpService {
const client = await this.initClient(server)
// Attempt to list tools as a way to check connectivity
await client.listTools()
logger.debug(`Connectivity check successful for server: ${server.name}`)
getServerLogger(server).debug(`Connectivity check successful`)
return true
} catch (error) {
logger.error(`Connectivity check failed for server: ${server.name}`, error as Error)
getServerLogger(server).error(`Connectivity check failed`, error as Error)
// Close the client if connectivity check fails to ensure a clean state for the next attempt
const serverKey = this.getServerKey(server)
await this.closeClient(serverKey)
@ -559,9 +612,8 @@ class McpService {
}
private async listToolsImpl(server: MCPServer): Promise<MCPTool[]> {
logger.debug(`Listing tools for server: ${server.name}`)
getServerLogger(server).debug(`Listing tools`)
const client = await this.initClient(server)
logger.debug(`Client for server: ${server.name}`, client)
try {
const { tools } = await client.listTools()
const serverTools: MCPTool[] = []
@ -576,7 +628,7 @@ class McpService {
})
return serverTools
} catch (error: any) {
logger.error(`Failed to list tools for server: ${server.name}`, error?.message)
getServerLogger(server).error(`Failed to list tools`, error as Error)
return []
}
}
@ -613,12 +665,16 @@ class McpService {
const callToolFunc = async ({ server, name, args }: CallToolArgs) => {
try {
logger.debug(`Calling: ${server.name} ${name} ${JSON.stringify(args)} callId: ${toolCallId}`, server)
getServerLogger(server, { tool: name, callId: toolCallId }).debug(`Calling tool`, {
args: redactSensitive(args)
})
if (typeof args === 'string') {
try {
args = JSON.parse(args)
} catch (e) {
logger.error('args parse error', args)
getServerLogger(server, { tool: name, callId: toolCallId }).error('args parse error', e as Error, {
args
})
}
if (args === '') {
args = {}
@ -627,8 +683,9 @@ class McpService {
const client = await this.initClient(server)
const result = await client.callTool({ name, arguments: args }, undefined, {
onprogress: (process) => {
logger.debug(`Progress: ${process.progress / (process.total || 1)}`)
logger.debug(`Progress notification received for server: ${server.name}`, process)
getServerLogger(server, { tool: name, callId: toolCallId }).debug(`Progress`, {
ratio: process.progress / (process.total || 1)
})
const mainWindow = windowService.getMainWindow()
if (mainWindow) {
mainWindow.webContents.send('mcp-progress', process.progress / (process.total || 1))
@ -643,7 +700,7 @@ class McpService {
})
return result as MCPCallToolResponse
} catch (error) {
logger.error(`Error calling tool ${name} on ${server.name}:`, error as Error)
getServerLogger(server, { tool: name, callId: toolCallId }).error(`Error calling tool`, error as Error)
throw error
} finally {
this.activeToolCalls.delete(toolCallId)
@ -667,7 +724,7 @@ class McpService {
*/
private async listPromptsImpl(server: MCPServer): Promise<MCPPrompt[]> {
const client = await this.initClient(server)
logger.debug(`Listing prompts for server: ${server.name}`)
getServerLogger(server).debug(`Listing prompts`)
try {
const { prompts } = await client.listPrompts()
return prompts.map((prompt: any) => ({
@ -679,7 +736,7 @@ class McpService {
} catch (error: any) {
// -32601 is the code for the method not found
if (error?.code !== -32601) {
logger.error(`Failed to list prompts for server: ${server.name}`, error?.message)
getServerLogger(server).error(`Failed to list prompts`, error as Error)
}
return []
}
@ -748,7 +805,7 @@ class McpService {
} catch (error: any) {
// -32601 is the code for the method not found
if (error?.code !== -32601) {
logger.error(`Failed to list resources for server: ${server.name}`, error?.message)
getServerLogger(server).error(`Failed to list resources`, error as Error)
}
return []
}
@ -774,7 +831,7 @@ class McpService {
* Get a specific resource from an MCP server (implementation)
*/
private async getResourceImpl(server: MCPServer, uri: string): Promise<GetResourceResponse> {
logger.debug(`Getting resource ${uri} from server: ${server.name}`)
getServerLogger(server, { uri }).debug(`Getting resource`)
const client = await this.initClient(server)
try {
const result = await client.readResource({ uri: uri })
@ -792,7 +849,7 @@ class McpService {
contents: contents
}
} catch (error: Error | any) {
logger.error(`Failed to get resource ${uri} from server: ${server.name}`, error.message)
getServerLogger(server, { uri }).error(`Failed to get resource`, error as Error)
throw new Error(`Failed to get resource ${uri} from server: ${server.name}: ${error.message}`)
}
}
@ -837,10 +894,10 @@ class McpService {
if (activeToolCall) {
activeToolCall.abort()
this.activeToolCalls.delete(callId)
logger.debug(`Aborted tool call: ${callId}`)
logger.debug(`Aborted tool call`, { callId })
return true
} else {
logger.warn(`No active tool call found for callId: ${callId}`)
logger.warn(`No active tool call found for callId`, { callId })
return false
}
}
@ -850,22 +907,22 @@ class McpService {
*/
public async getServerVersion(_: Electron.IpcMainInvokeEvent, server: MCPServer): Promise<string | null> {
try {
logger.debug(`Getting server version for: ${server.name}`)
getServerLogger(server).debug(`Getting server version`)
const client = await this.initClient(server)
// Try to get server information which may include version
const serverInfo = client.getServerVersion()
logger.debug(`Server info for ${server.name}:`, serverInfo)
getServerLogger(server).debug(`Server info`, redactSensitive(serverInfo))
if (serverInfo && serverInfo.version) {
logger.debug(`Server version for ${server.name}: ${serverInfo.version}`)
getServerLogger(server).debug(`Server version`, { version: serverInfo.version })
return serverInfo.version
}
logger.warn(`No version information available for server: ${server.name}`)
getServerLogger(server).warn(`No version information available`)
return null
} catch (error: any) {
logger.error(`Failed to get server version for ${server.name}:`, error?.message)
getServerLogger(server).error(`Failed to get server version`, error as Error)
return null
}
}

View File

@ -1,3 +1,4 @@
import { loggerService } from '@logger'
import { nanoid } from '@reduxjs/toolkit'
import CollapsibleSearchBar from '@renderer/components/CollapsibleSearchBar'
import { Sortable, useDndReorder } from '@renderer/components/dnd'
@ -23,6 +24,8 @@ import McpMarketList from './McpMarketList'
import McpServerCard from './McpServerCard'
import SyncServersPopup from './SyncServersPopup'
const logger = loggerService.withContext('McpServersList')
const McpServersList: FC = () => {
const { mcpServers, addMCPServer, deleteMCPServer, updateMcpServers, updateMCPServer } = useMCPServers()
const { t } = useTranslation()
@ -158,12 +161,11 @@ const McpServersList: FC = () => {
const handleToggleActive = async (server: MCPServer, active: boolean) => {
setLoadingServerIds((prev) => new Set(prev).add(server.id))
const oldActiveState = server.isActive
logger.silly('toggle activate', { serverId: server.id, active })
try {
if (active) {
await window.api.mcp.listTools(server)
// Fetch version when server is activated
fetchServerVersion({ ...server, isActive: active })
await fetchServerVersion({ ...server, isActive: active })
} else {
await window.api.mcp.stopServer(server)
// Clear version when server is deactivated
@ -259,7 +261,7 @@ const McpServersList: FC = () => {
server={server}
version={serverVersions[server.id]}
isLoading={loadingServerIds.has(server.id)}
onToggle={(active) => handleToggleActive(server, active)}
onToggle={async (active) => await handleToggleActive(server, active)}
onDelete={() => onDeleteMcpServer(server)}
onEdit={() => navigate(`/settings/mcp/settings/${encodeURIComponent(server.id)}`)}
onOpenUrl={(url) => window.open(url, '_blank')}