From 4bd3c4e0ba2646ef278ce573bc693e2e70b29dbc Mon Sep 17 00:00:00 2001 From: "Hein (Warky)" Date: Tue, 31 Mar 2026 00:16:13 +0200 Subject: [PATCH] feat(logging): enhance logging for metadata extraction and MCP tool handling --- internal/ai/compat/client.go | 34 ++++++++- internal/app/app.go | 2 +- internal/mcpserver/schema.go | 34 ++++++++- internal/mcpserver/server.go | 131 ++++++++++++++++++----------------- 4 files changed, 132 insertions(+), 69 deletions(-) diff --git a/internal/ai/compat/client.go b/internal/ai/compat/client.go index 1acdd6b..059bff1 100644 --- a/internal/ai/compat/client.go +++ b/internal/ai/compat/client.go @@ -208,6 +208,33 @@ func (c *Client) ExtractMetadata(ctx context.Context, input string) (thoughttype return thoughttypes.ThoughtMetadata{}, fmt.Errorf("%s extract metadata: input must not be empty", c.name) } + start := time.Now() + if c.log != nil { + c.log.Info("metadata client started", + slog.String("provider", c.name), + slog.String("model", c.metadataModel), + ) + } + + logCompletion := func(model string, err error) { + if c.log == nil { + return + } + + attrs := []any{ + slog.String("provider", c.name), + slog.String("model", model), + slog.Duration("duration", time.Since(start)), + } + if err != nil { + attrs = append(attrs, slog.String("error", err.Error())) + c.log.Error("metadata client completed", attrs...) + return + } + + c.log.Info("metadata client completed", attrs...) + } + result, err := c.extractMetadataWithModel(ctx, input, c.metadataModel) if errors.Is(err, errMetadataEmptyResponse) { c.noteEmptyResponse(c.metadataModel) @@ -217,6 +244,7 @@ func (c *Client) ExtractMetadata(ctx context.Context, input string) (thoughttype } if err == nil { c.noteModelSuccess(c.metadataModel) + logCompletion(c.metadataModel, nil) return result, nil } @@ -247,13 +275,16 @@ func (c *Client) ExtractMetadata(ctx context.Context, input string) (thoughttype } if fallbackErr == nil { c.noteModelSuccess(fallbackModel) + logCompletion(fallbackModel, nil) return fallbackResult, nil } err = fallbackErr } if ctx.Err() != nil { - return thoughttypes.ThoughtMetadata{}, fmt.Errorf("%s metadata: %w", c.name, ctx.Err()) + err = fmt.Errorf("%s metadata: %w", c.name, ctx.Err()) + logCompletion(c.metadataModel, err) + return thoughttypes.ThoughtMetadata{}, err } heuristic := heuristicMetadataFromInput(input) @@ -263,6 +294,7 @@ func (c *Client) ExtractMetadata(ctx context.Context, input string) (thoughttype slog.String("error", err.Error()), ) } + logCompletion(c.metadataModel, nil) return heuristic, nil } diff --git a/internal/app/app.go b/internal/app/app.go index 16fd483..ead2a7e 100644 --- a/internal/app/app.go +++ b/internal/app/app.go @@ -176,7 +176,7 @@ func routes(logger *slog.Logger, cfg *config.Config, db *store.DB, provider ai.P Skills: tools.NewSkillsTool(db, activeProjects), } - mcpHandler := mcpserver.New(cfg.MCP, toolSet) + mcpHandler := mcpserver.New(cfg.MCP, logger, toolSet) mux.Handle(cfg.MCP.Path, authMiddleware(mcpHandler)) mux.Handle("/files", authMiddleware(fileHandler(filesTool))) mux.Handle("/files/{id}", authMiddleware(fileHandler(filesTool))) diff --git a/internal/mcpserver/schema.go b/internal/mcpserver/schema.go index 9b19f5b..ee88a3c 100644 --- a/internal/mcpserver/schema.go +++ b/internal/mcpserver/schema.go @@ -3,7 +3,9 @@ package mcpserver import ( "context" "fmt" + "log/slog" "reflect" + "time" "github.com/google/jsonschema-go/jsonschema" "github.com/google/uuid" @@ -19,11 +21,39 @@ var toolSchemaOptions = &jsonschema.ForOptions{ }, } -func addTool[In any, Out any](server *mcp.Server, tool *mcp.Tool, handler func(context.Context, *mcp.CallToolRequest, In) (*mcp.CallToolResult, Out, error)) { +func addTool[In any, Out any](server *mcp.Server, logger *slog.Logger, tool *mcp.Tool, handler func(context.Context, *mcp.CallToolRequest, In) (*mcp.CallToolResult, Out, error)) { if err := setToolSchemas[In, Out](tool); err != nil { panic(fmt.Sprintf("configure MCP tool %q schemas: %v", tool.Name, err)) } - mcp.AddTool(server, tool, handler) + mcp.AddTool(server, tool, logToolCall(logger, tool.Name, handler)) +} + +func logToolCall[In any, Out any](logger *slog.Logger, toolName string, handler func(context.Context, *mcp.CallToolRequest, In) (*mcp.CallToolResult, Out, error)) func(context.Context, *mcp.CallToolRequest, In) (*mcp.CallToolResult, Out, error) { + if logger == nil { + return handler + } + + return func(ctx context.Context, req *mcp.CallToolRequest, in In) (*mcp.CallToolResult, Out, error) { + start := time.Now() + attrs := []any{slog.String("tool", toolName)} + if req != nil && req.Params != nil { + attrs = append(attrs, slog.Any("arguments", req.Params.Arguments)) + } + + logger.Info("mcp tool started", attrs...) + result, out, err := handler(ctx, req, in) + + completionAttrs := append([]any{}, attrs...) + completionAttrs = append(completionAttrs, slog.Duration("duration", time.Since(start))) + if err != nil { + completionAttrs = append(completionAttrs, slog.String("error", err.Error())) + logger.Error("mcp tool completed", completionAttrs...) + return result, out, err + } + + logger.Info("mcp tool completed", completionAttrs...) + return result, out, nil + } } func setToolSchemas[In any, Out any](tool *mcp.Tool) error { diff --git a/internal/mcpserver/server.go b/internal/mcpserver/server.go index 5fc8726..aac65fd 100644 --- a/internal/mcpserver/server.go +++ b/internal/mcpserver/server.go @@ -1,6 +1,7 @@ package mcpserver import ( + "log/slog" "net/http" "time" @@ -36,93 +37,93 @@ type ToolSet struct { Skills *tools.SkillsTool } -func New(cfg config.MCPConfig, toolSet ToolSet) http.Handler { +func New(cfg config.MCPConfig, logger *slog.Logger, toolSet ToolSet) http.Handler { server := mcp.NewServer(&mcp.Implementation{ Name: cfg.ServerName, Version: cfg.Version, }, nil) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "capture_thought", Description: "Store a thought with generated embeddings and extracted metadata.", }, toolSet.Capture.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "search_thoughts", Description: "Search stored thoughts by semantic similarity.", }, toolSet.Search.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_thoughts", Description: "List recent thoughts with optional metadata filters.", }, toolSet.List.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "thought_stats", Description: "Get counts and top metadata buckets across stored thoughts.", }, toolSet.Stats.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_thought", Description: "Retrieve a full thought by id.", }, toolSet.Get.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "update_thought", Description: "Update thought content or merge metadata.", }, toolSet.Update.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "delete_thought", Description: "Hard-delete a thought by id.", }, toolSet.Delete.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "archive_thought", Description: "Archive a thought so it is hidden from default search and listing.", }, toolSet.Archive.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "create_project", Description: "Create a named project container for thoughts.", }, toolSet.Projects.Create) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_projects", Description: "List projects and their current thought counts.", }, toolSet.Projects.List) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "set_active_project", Description: "Set the active project for the current MCP session.", }, toolSet.Projects.SetActive) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_active_project", Description: "Return the active project for the current MCP session.", }, toolSet.Projects.GetActive) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_project_context", Description: "Get recent and semantic context for a project.", }, toolSet.Context.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "recall_context", Description: "Recall semantically relevant and recent context.", }, toolSet.Recall.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "summarize_thoughts", Description: "Summarize a filtered or searched set of thoughts.", }, toolSet.Summarize.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "link_thoughts", Description: "Create a typed relationship between two thoughts.", }, toolSet.Links.Link) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "related_thoughts", Description: "Retrieve explicit links and semantic neighbors for a thought.", }, toolSet.Links.Related) @@ -133,245 +134,245 @@ func New(cfg config.MCPConfig, toolSet ToolSet) http.Handler { Description: "A stored file. Read a file's raw binary content by its id. Use load_file for metadata.", }, toolSet.Files.ReadResource) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "save_file", Description: "Store a base64-encoded file such as an image, document, or audio clip, optionally linking it to a thought.", }, toolSet.Files.Save) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "load_file", Description: "Load a previously stored file by id and return its metadata and base64 content.", }, toolSet.Files.Load) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_files", Description: "List stored files, optionally filtered by thought, project, or kind.", }, toolSet.Files.List) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "backfill_embeddings", Description: "Generate missing embeddings for stored thoughts using the active embedding model.", }, toolSet.Backfill.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "reparse_thought_metadata", Description: "Re-extract and normalize metadata for stored thoughts from their content.", }, toolSet.Reparse.Handle) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "retry_failed_metadata", Description: "Retry metadata extraction for thoughts still marked pending or failed.", }, toolSet.RetryMetadata.Handle) // Household Knowledge - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_household_item", Description: "Store a household fact (paint color, appliance details, measurement, document, etc.).", }, toolSet.Household.AddItem) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "search_household_items", Description: "Search household items by name, category, or location.", }, toolSet.Household.SearchItems) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_household_item", Description: "Retrieve a household item by id.", }, toolSet.Household.GetItem) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_vendor", Description: "Add a service provider (plumber, electrician, landscaper, etc.).", }, toolSet.Household.AddVendor) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_vendors", Description: "List household service vendors, optionally filtered by service type.", }, toolSet.Household.ListVendors) // Home Maintenance - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_maintenance_task", Description: "Create a recurring or one-time home maintenance task.", }, toolSet.Maintenance.AddTask) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "log_maintenance", Description: "Log completed maintenance work; automatically updates the task's next due date.", }, toolSet.Maintenance.LogWork) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_upcoming_maintenance", Description: "List maintenance tasks due within the next N days.", }, toolSet.Maintenance.GetUpcoming) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "search_maintenance_history", Description: "Search the maintenance log by task name, category, or date range.", }, toolSet.Maintenance.SearchHistory) // Family Calendar - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_family_member", Description: "Add a family member to the household.", }, toolSet.Calendar.AddMember) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_family_members", Description: "List all family members.", }, toolSet.Calendar.ListMembers) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_activity", Description: "Schedule a one-time or recurring family activity.", }, toolSet.Calendar.AddActivity) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_week_schedule", Description: "Get all activities scheduled for a given week.", }, toolSet.Calendar.GetWeekSchedule) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "search_activities", Description: "Search activities by title, type, or family member.", }, toolSet.Calendar.SearchActivities) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_important_date", Description: "Track a birthday, anniversary, deadline, or other important date.", }, toolSet.Calendar.AddImportantDate) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_upcoming_dates", Description: "Get important dates coming up in the next N days.", }, toolSet.Calendar.GetUpcomingDates) // Meal Planning - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_recipe", Description: "Save a recipe with ingredients and instructions.", }, toolSet.Meals.AddRecipe) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "search_recipes", Description: "Search recipes by name, cuisine, tags, or ingredient.", }, toolSet.Meals.SearchRecipes) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "update_recipe", Description: "Update an existing recipe.", }, toolSet.Meals.UpdateRecipe) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "create_meal_plan", Description: "Set the meal plan for a week; replaces any existing plan for that week.", }, toolSet.Meals.CreateMealPlan) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_meal_plan", Description: "Get the meal plan for a given week.", }, toolSet.Meals.GetMealPlan) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "generate_shopping_list", Description: "Auto-generate a shopping list from the meal plan for a given week.", }, toolSet.Meals.GenerateShoppingList) // Professional CRM - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_professional_contact", Description: "Add a professional contact to the CRM.", }, toolSet.CRM.AddContact) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "search_contacts", Description: "Search professional contacts by name, company, title, notes, or tags.", }, toolSet.CRM.SearchContacts) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "log_interaction", Description: "Log an interaction with a professional contact.", }, toolSet.CRM.LogInteraction) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_contact_history", Description: "Get full history (interactions and opportunities) for a contact.", }, toolSet.CRM.GetHistory) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "create_opportunity", Description: "Create a deal, project, or opportunity linked to a contact.", }, toolSet.CRM.CreateOpportunity) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "get_follow_ups_due", Description: "List contacts with a follow-up date due within the next N days.", }, toolSet.CRM.GetFollowUpsDue) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "link_thought_to_contact", Description: "Append a stored thought to a contact's notes.", }, toolSet.CRM.LinkThought) // Agent Skills - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_skill", Description: "Store a reusable agent skill (behavioural instruction or capability prompt).", }, toolSet.Skills.AddSkill) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "remove_skill", Description: "Delete an agent skill by id.", }, toolSet.Skills.RemoveSkill) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_skills", Description: "List all agent skills, optionally filtered by tag.", }, toolSet.Skills.ListSkills) // Agent Guardrails - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_guardrail", Description: "Store a reusable agent guardrail (constraint or safety rule).", }, toolSet.Skills.AddGuardrail) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "remove_guardrail", Description: "Delete an agent guardrail by id.", }, toolSet.Skills.RemoveGuardrail) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_guardrails", Description: "List all agent guardrails, optionally filtered by tag or severity.", }, toolSet.Skills.ListGuardrails) // Project Skills & Guardrails - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_project_skill", Description: "Link an agent skill to a project.", }, toolSet.Skills.AddProjectSkill) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "remove_project_skill", Description: "Unlink an agent skill from a project.", }, toolSet.Skills.RemoveProjectSkill) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_project_skills", Description: "List all skills linked to a project. Call this at the start of a project session to load existing agent behaviour instructions before generating new ones.", }, toolSet.Skills.ListProjectSkills) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "add_project_guardrail", Description: "Link an agent guardrail to a project.", }, toolSet.Skills.AddProjectGuardrail) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "remove_project_guardrail", Description: "Unlink an agent guardrail from a project.", }, toolSet.Skills.RemoveProjectGuardrail) - addTool(server, &mcp.Tool{ + addTool(server, logger, &mcp.Tool{ Name: "list_project_guardrails", Description: "List all guardrails linked to a project. Call this at the start of a project session to load existing agent constraints before generating new ones.", }, toolSet.Skills.ListProjectGuardrails)