Skip to content
This repository was archived by the owner on Jun 29, 2025. It is now read-only.

Commit 8ea84a0

Browse files
jedisct1jedisct1
committed
Improve logging
1 parent 51dd451 commit 8ea84a0

File tree

3 files changed

+793
-977
lines changed

3 files changed

+793
-977
lines changed

‎cmd/openapi-mcp/server.go‎

Lines changed: 240 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88
"log"
99
"net/http"
1010
"os"
11+
"strings"
1112
"time"
1213

1314
"github.com/getkin/kin-openapi/openapi3"
@@ -129,59 +130,262 @@ func makeMCPHandler(srv *mcpserver.MCPServer, basePath string) http.Handler {
129130
return openapi2mcp.HandlerForBasePath(srv, basePath)
130131
}
131132

133+
// formatHumanReadableLog creates a human-readable log entry for MCP transactions
134+
func formatHumanReadableLog(timestamp, logType, method string, id any, data interface{}, err error) string {
135+
var log strings.Builder
136+
137+
// Header with timestamp and type
138+
log.WriteString("═══════════════════════════════════════════════════════════════════════════════\n")
139+
log.WriteString(fmt.Sprintf("🕐 %s | %s | Method: %s",
140+
timestamp, strings.ToUpper(logType), method))
141+
142+
if id != nil {
143+
log.WriteString(fmt.Sprintf(" | ID: %v", id))
144+
}
145+
log.WriteString("\n")
146+
147+
// Content based on type
148+
switch logType {
149+
case "request":
150+
log.WriteString("📤 INCOMING REQUEST\n")
151+
if req, ok := data.(map[string]interface{}); ok {
152+
if method == "tools/call" {
153+
// Special formatting for tool calls
154+
if params, ok := req["params"].(map[string]interface{}); ok {
155+
if name, ok := params["name"].(string); ok {
156+
log.WriteString(fmt.Sprintf("🔧 Tool: %s\n", name))
157+
}
158+
if args, ok := params["arguments"].(map[string]interface{}); ok && len(args) > 0 {
159+
log.WriteString("📝 Arguments:\n")
160+
for key, value := range args {
161+
valueStr := formatValue(value)
162+
log.WriteString(fmt.Sprintf(" %s: %s\n", key, valueStr))
163+
}
164+
} else {
165+
log.WriteString("📝 Arguments: (none)\n")
166+
}
167+
}
168+
} else {
169+
// Other method types - show only if there are meaningful params
170+
if params, ok := req["params"].(map[string]interface{}); ok && len(params) > 0 {
171+
prettyJSON, _ := json.MarshalIndent(params, " ", " ")
172+
log.WriteString(fmt.Sprintf("📝 Parameters:\n %s\n", string(prettyJSON)))
173+
} else {
174+
// For methods with no parameters, just note what method it is
175+
log.WriteString(fmt.Sprintf("📝 Method: %s (no parameters)\n", method))
176+
}
177+
}
178+
}
179+
180+
case "response":
181+
log.WriteString("📥 OUTGOING RESPONSE\n")
182+
if os.Getenv("DEBUG_RESPONSE") != "" {
183+
log.WriteString(fmt.Sprintf("🐛 Data type: %T\n", data))
184+
if data != nil {
185+
dataJSON, _ := json.MarshalIndent(data, " ", " ")
186+
log.WriteString(fmt.Sprintf("🐛 Data content: %s\n", string(dataJSON)))
187+
}
188+
}
189+
// Handle specific MCP result types
190+
switch result := data.(type) {
191+
case *mcp.ListToolsResult:
192+
tools := result.Tools
193+
log.WriteString(fmt.Sprintf("🔧 Tools Listed: %d tools\n", len(tools)))
194+
if len(tools) <= 10 {
195+
// Show all tools if 10 or fewer
196+
for i, tool := range tools {
197+
desc := ""
198+
if len(tool.Description) > 0 {
199+
// Extract first line of description for brevity
200+
lines := strings.Split(tool.Description, "\n")
201+
if len(lines) > 0 {
202+
desc = lines[0]
203+
if len(desc) > 80 {
204+
desc = desc[:80] + "..."
205+
}
206+
}
207+
}
208+
log.WriteString(fmt.Sprintf(" [%d] %s: %s\n", i+1, tool.Name, desc))
209+
}
210+
} else {
211+
// Show first 5 tools and mention there are more
212+
for i := 0; i < 5; i++ {
213+
desc := ""
214+
if len(tools[i].Description) > 0 {
215+
lines := strings.Split(tools[i].Description, "\n")
216+
if len(lines) > 0 {
217+
desc = lines[0]
218+
if len(desc) > 80 {
219+
desc = desc[:80] + "..."
220+
}
221+
}
222+
}
223+
log.WriteString(fmt.Sprintf(" [%d] %s: %s\n", i+1, tools[i].Name, desc))
224+
}
225+
log.WriteString(fmt.Sprintf(" ... and %d more tools\n", len(tools)-5))
226+
}
227+
case *mcp.CallToolResult:
228+
if len(result.Content) > 0 {
229+
log.WriteString("📋 Response Content:\n")
230+
for i, item := range result.Content {
231+
if textContent, ok := item.(mcp.TextContent); ok {
232+
log.WriteString(fmt.Sprintf(" [%d] Type: %s\n", i+1, textContent.Type))
233+
// Truncate very long responses
234+
if len(textContent.Text) > 500 {
235+
log.WriteString(fmt.Sprintf(" [%d] Text: %s... (%d chars total)\n",
236+
i+1, textContent.Text[:500], len(textContent.Text)))
237+
} else {
238+
log.WriteString(fmt.Sprintf(" [%d] Text: %s\n", i+1, textContent.Text))
239+
}
240+
}
241+
}
242+
}
243+
default:
244+
// Handle generic map[string]interface{} responses
245+
if result, ok := data.(map[string]interface{}); ok {
246+
if content, ok := result["content"].([]interface{}); ok && len(content) > 0 {
247+
log.WriteString("📋 Response Content:\n")
248+
for i, item := range content {
249+
if contentItem, ok := item.(map[string]interface{}); ok {
250+
if contentType, ok := contentItem["type"].(string); ok {
251+
log.WriteString(fmt.Sprintf(" [%d] Type: %s\n", i+1, contentType))
252+
}
253+
if text, ok := contentItem["text"].(string); ok {
254+
// Truncate very long responses
255+
if len(text) > 500 {
256+
log.WriteString(fmt.Sprintf(" [%d] Text: %s... (%d chars total)\n",
257+
i+1, text[:500], len(text)))
258+
} else {
259+
log.WriteString(fmt.Sprintf(" [%d] Text: %s\n", i+1, text))
260+
}
261+
}
262+
}
263+
}
264+
}
265+
} else if tools, ok := result["tools"].([]interface{}); ok {
266+
log.WriteString(fmt.Sprintf("🔧 Tools Listed: %d tools\n", len(tools)))
267+
if len(tools) <= 10 {
268+
// Show all tools if 10 or fewer
269+
for i, tool := range tools {
270+
if toolItem, ok := tool.(map[string]interface{}); ok {
271+
if name, ok := toolItem["name"].(string); ok {
272+
desc := ""
273+
if description, ok := toolItem["description"].(string); ok && len(description) > 0 {
274+
// Extract first line of description for brevity
275+
lines := strings.Split(description, "\\n")
276+
if len(lines) > 0 {
277+
desc = lines[0]
278+
if len(desc) > 80 {
279+
desc = desc[:80] + "..."
280+
}
281+
}
282+
}
283+
log.WriteString(fmt.Sprintf(" [%d] %s: %s\n", i+1, name, desc))
284+
}
285+
}
286+
}
287+
} else {
288+
// Show first 5 tools and mention there are more
289+
for i := 0; i < 5; i++ {
290+
if toolItem, ok := tools[i].(map[string]interface{}); ok {
291+
if name, ok := toolItem["name"].(string); ok {
292+
desc := ""
293+
if description, ok := toolItem["description"].(string); ok && len(description) > 0 {
294+
lines := strings.Split(description, "\\n")
295+
if len(lines) > 0 {
296+
desc = lines[0]
297+
if len(desc) > 80 {
298+
desc = desc[:80] + "..."
299+
}
300+
}
301+
}
302+
log.WriteString(fmt.Sprintf(" [%d] %s: %s\n", i+1, name, desc))
303+
}
304+
}
305+
}
306+
log.WriteString(fmt.Sprintf(" ... and %d more tools\n", len(tools)-5))
307+
}
308+
} else {
309+
// Generic response formatting - show structure for debugging
310+
prettyJSON, _ := json.MarshalIndent(result, " ", " ")
311+
if len(string(prettyJSON)) > 2000 {
312+
log.WriteString(fmt.Sprintf("📋 Result: %s... (%d chars total)\n", string(prettyJSON)[:2000], len(string(prettyJSON))))
313+
} else {
314+
log.WriteString(fmt.Sprintf("📋 Result:\n %s\n", string(prettyJSON)))
315+
}
316+
}
317+
}
318+
319+
case "error":
320+
log.WriteString("❌ ERROR OCCURRED\n")
321+
log.WriteString(fmt.Sprintf("💥 Error: %s\n", err.Error()))
322+
if data != nil {
323+
prettyJSON, _ := json.MarshalIndent(data, " ", " ")
324+
log.WriteString(fmt.Sprintf("📝 Request Data:\n %s\n", string(prettyJSON)))
325+
}
326+
}
327+
328+
log.WriteString("═══════════════════════════════════════════════════════════════════════════════\n\n")
329+
return log.String()
330+
}
331+
332+
// formatValue formats a value for human-readable display
333+
func formatValue(value interface{}) string {
334+
switch v := value.(type) {
335+
case string:
336+
if len(v) > 100 {
337+
return fmt.Sprintf("\"%s...\" (%d chars)", v[:100], len(v))
338+
}
339+
return fmt.Sprintf("\"%s\"", v)
340+
case map[string]interface{}:
341+
if len(v) == 0 {
342+
return "{}"
343+
}
344+
keys := make([]string, 0, len(v))
345+
for k := range v {
346+
keys = append(keys, k)
347+
}
348+
if len(keys) > 3 {
349+
return fmt.Sprintf("{%s, ...} (%d keys)", strings.Join(keys[:3], ", "), len(keys))
350+
}
351+
return fmt.Sprintf("{%s}", strings.Join(keys, ", "))
352+
case []interface{}:
353+
return fmt.Sprintf("[%d items]", len(v))
354+
default:
355+
return fmt.Sprintf("%v", v)
356+
}
357+
}
358+
132359
// createLoggingHooks creates MCP hooks for logging requests and responses to a file
133360
func createLoggingHooks(logFilePath string) (*mcpserver.Hooks, *os.File, error) {
134361
logFile, err := os.OpenFile(logFilePath, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o644)
135362
if err != nil {
136363
return nil, nil, fmt.Errorf("failed to open log file: %w", err)
137364
}
138365

139-
logger := log.New(logFile, "", 0) // No prefix, we'll format our own timestamps
366+
logger := log.New(logFile, "", 0) // No prefix, we'll format our own output
140367

141368
hooks := &mcpserver.Hooks{}
142369

143-
// Log requests
370+
// Log requests with human-readable format
144371
hooks.AddBeforeAny(func(ctx context.Context, id any, method mcp.MCPMethod, message any) {
145-
timestamp := time.Now().Format(time.RFC3339)
146-
reqJSON, _ := json.Marshal(message)
147-
logEntry := map[string]interface{}{
148-
"timestamp": timestamp,
149-
"type": "request",
150-
"id": id,
151-
"method": method,
152-
"message": json.RawMessage(reqJSON),
153-
}
154-
logJSON, _ := json.Marshal(logEntry)
155-
logger.Println(string(logJSON))
372+
timestamp := time.Now().Format("2006-01-02 15:04:05 MST")
373+
humanLog := formatHumanReadableLog(timestamp, "request", string(method), id, message, nil)
374+
logger.Print(humanLog)
156375
})
157376

158-
// Log successful responses
377+
// Log successful responses with human-readable format
159378
hooks.AddOnSuccess(func(ctx context.Context, id any, method mcp.MCPMethod, message any, result any) {
160-
timestamp := time.Now().Format(time.RFC3339)
161-
resJSON, _ := json.Marshal(result)
162-
logEntry := map[string]interface{}{
163-
"timestamp": timestamp,
164-
"type": "response",
165-
"id": id,
166-
"method": method,
167-
"result": json.RawMessage(resJSON),
168-
}
169-
logJSON, _ := json.Marshal(logEntry)
170-
logger.Println(string(logJSON))
379+
timestamp := time.Now().Format("2006-01-02 15:04:05 MST")
380+
humanLog := formatHumanReadableLog(timestamp, "response", string(method), id, result, nil)
381+
logger.Print(humanLog)
171382
})
172383

173-
// Log errors
384+
// Log errors with human-readable format
174385
hooks.AddOnError(func(ctx context.Context, id any, method mcp.MCPMethod, message any, err error) {
175-
timestamp := time.Now().Format(time.RFC3339)
176-
logEntry := map[string]interface{}{
177-
"timestamp": timestamp,
178-
"type": "error",
179-
"id": id,
180-
"method": method,
181-
"error": err.Error(),
182-
}
183-
logJSON, _ := json.Marshal(logEntry)
184-
logger.Println(string(logJSON))
386+
timestamp := time.Now().Format("2006-01-02 15:04:05 MST")
387+
humanLog := formatHumanReadableLog(timestamp, "error", string(method), id, message, err)
388+
logger.Print(humanLog)
185389
})
186390

187391
return hooks, logFile, nil

0 commit comments

Comments
 (0)