|
| 1 | +# MCP Tracing Guide |
| 2 | + |
| 3 | +This guide explains how to enable and use raw JSON-RPC message tracing in mcpproxy to debug MCP communication issues. |
| 4 | + |
| 5 | +## Overview |
| 6 | + |
| 7 | +The tracing feature logs all MCP communication in raw JSON format: |
| 8 | + |
| 9 | +1. **Server-side tracing**: Logs requests from MCP clients to mcpproxy and responses back |
| 10 | +2. **Client-side tracing**: Logs requests from mcpproxy to upstream MCP servers and their responses |
| 11 | + |
| 12 | +This allows you to see exactly what messages are being exchanged in both directions, which is crucial for debugging issues like the `tools/list` timeout problem. |
| 13 | + |
| 14 | +## Enabling Tracing |
| 15 | + |
| 16 | +### Method 1: Command Line Flag |
| 17 | + |
| 18 | +```bash |
| 19 | +./mcpproxy --enable-tracing |
| 20 | +``` |
| 21 | + |
| 22 | +### Method 2: Environment Variable |
| 23 | + |
| 24 | +```bash |
| 25 | +export MCP_TRACE=1 |
| 26 | +./mcpproxy |
| 27 | +``` |
| 28 | + |
| 29 | +### Method 3: Configuration File |
| 30 | + |
| 31 | +Add to your `mcp_config.json`: |
| 32 | + |
| 33 | +```json |
| 34 | +{ |
| 35 | + "enable_tracing": true, |
| 36 | + "mcpServers": { |
| 37 | + // ... your server configurations |
| 38 | + } |
| 39 | +} |
| 40 | +``` |
| 41 | + |
| 42 | +## Log Output Format |
| 43 | + |
| 44 | +When tracing is enabled, you'll see log entries like: |
| 45 | + |
| 46 | +### Incoming Requests |
| 47 | +``` |
| 48 | +π MCP Request | method=tools/list | id=1 | message={"method":"tools/list","params":{"cursor":null}} |
| 49 | +``` |
| 50 | + |
| 51 | +### Successful Responses |
| 52 | +``` |
| 53 | +β
MCP Response | method=tools/list | id=1 | result={"tools":[{"name":"retrieve_tools","description":"..."}],"nextCursor":null} |
| 54 | +``` |
| 55 | + |
| 56 | +### Error Responses |
| 57 | +``` |
| 58 | +β MCP Error | method=tools/call | id=2 | error="tool not found: invalid_tool" |
| 59 | +``` |
| 60 | + |
| 61 | +## Use Cases |
| 62 | + |
| 63 | +### 1. Debugging Tool Discovery Issues |
| 64 | +Enable tracing to see exactly what tools are being requested and returned: |
| 65 | + |
| 66 | +```bash |
| 67 | +# Terminal 1: Start mcpproxy with tracing |
| 68 | +MCP_TRACE=1 ./mcpproxy |
| 69 | + |
| 70 | +# Terminal 2: Use mcpproxy tools to see traced messages |
| 71 | +./mcpproxy --help # This will trigger MCP calls that get traced |
| 72 | +``` |
| 73 | + |
| 74 | +### 2. Debugging Client Integration |
| 75 | +When integrating with MCP clients like Claude Desktop, enable tracing to see the exact JSON-RPC messages: |
| 76 | + |
| 77 | +```bash |
| 78 | +# Add to Claude Desktop config with tracing enabled mcpproxy |
| 79 | +{ |
| 80 | + "mcpServers": { |
| 81 | + "mcpproxy": { |
| 82 | + "command": "/path/to/mcpproxy", |
| 83 | + "args": ["--enable-tracing"], |
| 84 | + "env": {} |
| 85 | + } |
| 86 | + } |
| 87 | +} |
| 88 | +``` |
| 89 | + |
| 90 | +### 3. Debugging Upstream Server Communication |
| 91 | +Trace messages to see how mcpproxy communicates with upstream MCP servers: |
| 92 | + |
| 93 | +```bash |
| 94 | +# Start with tracing and debug logs |
| 95 | +./mcpproxy --enable-tracing --log-level=debug |
| 96 | +``` |
| 97 | + |
| 98 | +## Filtering Trace Output |
| 99 | + |
| 100 | +To focus on specific trace messages, use grep: |
| 101 | + |
| 102 | +```bash |
| 103 | +# Show only MCP requests |
| 104 | +./mcpproxy --enable-tracing 2>&1 | grep "π MCP Request" |
| 105 | + |
| 106 | +# Show only errors |
| 107 | +./mcpproxy --enable-tracing 2>&1 | grep "β MCP Error" |
| 108 | + |
| 109 | +# Show specific method calls |
| 110 | +./mcpproxy --enable-tracing 2>&1 | grep "tools/call" |
| 111 | +``` |
| 112 | + |
| 113 | +## Performance Considerations |
| 114 | + |
| 115 | +- Tracing adds JSON marshaling overhead for every request/response |
| 116 | +- Only enable tracing for debugging purposes, not in production |
| 117 | +- Consider using log levels to control verbosity when tracing is enabled |
| 118 | + |
| 119 | +## Troubleshooting Common Issues |
| 120 | + |
| 121 | +### 1. SSE Connection Timeouts |
| 122 | +Look for patterns like: |
| 123 | +``` |
| 124 | +π MCP Request | method=tools/list | id=1 |
| 125 | +β MCP Error | method=tools/list | id=1 | error="context deadline exceeded" |
| 126 | +``` |
| 127 | + |
| 128 | +### 2. OAuth Flow Issues |
| 129 | +Trace OAuth-related requests: |
| 130 | +```bash |
| 131 | +./mcpproxy --enable-tracing 2>&1 | grep -E "(oauth|auth)" |
| 132 | +``` |
| 133 | + |
| 134 | +### 3. Tool Call Failures |
| 135 | +Look for tool call patterns: |
| 136 | +``` |
| 137 | +π MCP Request | method=tools/call | id=2 | message={"method":"tools/call","params":{"name":"server:tool"}} |
| 138 | +β MCP Error | method=tools/call | id=2 | error="transport error: context deadline exceeded" |
| 139 | +``` |
| 140 | + |
| 141 | +## Integration with External Tools |
| 142 | + |
| 143 | +### With mcp-debug CLI |
| 144 | +You can combine mcpproxy tracing with external MCP debugging tools: |
| 145 | + |
| 146 | +```bash |
| 147 | +# Terminal 1: Start mcpproxy with tracing |
| 148 | +./mcpproxy --enable-tracing |
| 149 | + |
| 150 | +# Terminal 2: Use mcp-debug to inspect |
| 151 | +mcp-debug --endpoint http://localhost:8080/mcp --verbose |
| 152 | +``` |
| 153 | + |
| 154 | +### With Custom Scripts |
| 155 | +Parse trace output for automated analysis: |
| 156 | + |
| 157 | +```bash |
| 158 | +./mcpproxy --enable-tracing 2>&1 | \ |
| 159 | + grep "π MCP Request" | \ |
| 160 | + jq -r '.message' | \ |
| 161 | + jq '.method' | \ |
| 162 | + sort | uniq -c |
| 163 | +``` |
| 164 | + |
| 165 | +## Example Trace Session |
| 166 | + |
| 167 | +Here's what a typical trace session looks like: |
| 168 | + |
| 169 | +```bash |
| 170 | +$ MCP_TRACE=1 ./mcpproxy |
| 171 | +2025-01-11T12:00:00.000Z | INFO | Configuration loaded | enable_tracing=true |
| 172 | +2025-01-11T12:00:01.000Z | INFO | π MCP Request | method=initialize | id=1 | message={"method":"initialize","params":{"protocolVersion":"2025-03-26","capabilities":{},"clientInfo":{"name":"test-client","version":"1.0.0"}}} |
| 173 | +2025-01-11T12:00:01.001Z | INFO | β
MCP Response | method=initialize | id=1 | result={"protocolVersion":"2025-03-26","capabilities":{"tools":{"listChanged":false}},"serverInfo":{"name":"mcpproxy-go","version":"1.0.0"}} |
| 174 | +2025-01-11T12:00:01.002Z | INFO | π MCP Request | method=tools/list | id=2 | message={"method":"tools/list","params":{}} |
| 175 | +2025-01-11T12:00:01.003Z | INFO | β
MCP Response | method=tools/list | id=2 | result={"tools":[{"name":"retrieve_tools","description":"π CALL THIS FIRST to discover relevant tools!"}]} |
| 176 | +``` |
| 177 | + |
| 178 | +This shows the complete MCP handshake and tool discovery process. |
| 179 | + |
| 180 | +## Debugging the tools/list Timeout Issue |
| 181 | + |
| 182 | +If you're experiencing `tools/list` timeouts with Cloudflare servers, use this specific grep pattern to trace the issue: |
| 183 | + |
| 184 | +```bash |
| 185 | +tail -f ~/Library/Logs/mcpproxy/main.log | grep -E "(π€ MCP Request.*tools/list|π₯ MCP Response.*tools/list|β MCP Request failed.*tools/list|π MCP Transport|β
MCP Transport|context deadline exceeded|transport error)" |
| 186 | +``` |
| 187 | + |
| 188 | +### What to Look For: |
| 189 | + |
| 190 | +1. **Successful handshake but no tools/list response**: |
| 191 | + ``` |
| 192 | + π MCP Transport starting | server=cloudflare_dns_analytics |
| 193 | + β
MCP Transport started successfully | server=cloudflare_dns_analytics |
| 194 | + π€ MCP Request: Client β Server | server=cloudflare_dns_analytics | method=initialize |
| 195 | + π₯ MCP Response: Server β Client | server=cloudflare_dns_analytics | method=initialize |
| 196 | + π€ MCP Request: Client β Server | server=cloudflare_dns_analytics | method=tools/list |
| 197 | + [No response for 30+ seconds] |
| 198 | + β MCP Request failed | server=cloudflare_dns_analytics | method=tools/list | error=context deadline exceeded |
| 199 | + ``` |
| 200 | + |
| 201 | +2. **Missing Authorization headers**: |
| 202 | + Look for OAuth token debug messages and verify Authorization headers are being sent. |
| 203 | + |
| 204 | +3. **Transport-level issues**: |
| 205 | + Check for transport start/close messages and connection state changes. |
| 206 | + |
| 207 | +### Quick Test Command: |
| 208 | + |
| 209 | +```bash |
| 210 | +# Start mcpproxy with tracing and test immediately |
| 211 | +MCP_TRACE=1 ./mcpproxy --enable-tracing & |
| 212 | +MCPPROXY_PID=$! |
| 213 | + |
| 214 | +# Wait a moment for startup |
| 215 | +sleep 2 |
| 216 | + |
| 217 | +# Test tools/list directly (this will show in trace output) |
| 218 | +curl -X POST http://localhost:8080/mcp \ |
| 219 | + -H "Content-Type: application/json" \ |
| 220 | + -d '{"jsonrpc":"2.0","id":1,"method":"tools/list","params":{}}' |
| 221 | + |
| 222 | +# Clean up |
| 223 | +kill $MCPPROXY_PID |
| 224 | +``` |
0 commit comments