diff --git a/pkg/agentic/service.go b/pkg/agentic/service.go index 11364744..810abbcb 100644 --- a/pkg/agentic/service.go +++ b/pkg/agentic/service.go @@ -7,6 +7,7 @@ import ( "strings" "github.com/host-uk/core/pkg/framework" + "github.com/host-uk/core/pkg/log" ) // Tasks for AI service @@ -63,10 +64,16 @@ func (s *Service) handleTask(c *framework.Core, t framework.Task) (any, bool, er switch m := t.(type) { case TaskCommit: err := s.doCommit(m) + if err != nil { + log.Error("agentic: commit task failed", "err", err, "path", m.Path) + } return nil, true, err case TaskPrompt: err := s.doPrompt(m) + if err != nil { + log.Error("agentic: prompt task failed", "err", err) + } return nil, true, err } return nil, false, nil diff --git a/pkg/cli/daemon.go b/pkg/cli/daemon.go index 692ccd6b..ccd3678b 100644 --- a/pkg/cli/daemon.go +++ b/pkg/cli/daemon.go @@ -219,7 +219,7 @@ func (h *HealthServer) Start() error { go func() { if err := h.server.Serve(listener); err != http.ErrServerClosed { - LogError(fmt.Sprintf("health server error: %v", err)) + LogError("health server error", "err", err) } }() diff --git a/pkg/cli/errors.go b/pkg/cli/errors.go index ef39d32c..bb9e0f71 100644 --- a/pkg/cli/errors.go +++ b/pkg/cli/errors.go @@ -107,26 +107,28 @@ func Exit(code int, err error) error { // Fatal Functions (Deprecated - return error from command instead) // ───────────────────────────────────────────────────────────────────────────── -// Fatal prints an error message to stderr and exits with code 1. +// Fatal prints an error message to stderr, logs it, and exits with code 1. // // Deprecated: return an error from the command instead. func Fatal(err error) { if err != nil { + LogError("Fatal error", "err", err) fmt.Fprintln(os.Stderr, ErrorStyle.Render(Glyph(":cross:")+" "+err.Error())) os.Exit(1) } } -// Fatalf prints a formatted error message to stderr and exits with code 1. +// Fatalf prints a formatted error message to stderr, logs it, and exits with code 1. // // Deprecated: return an error from the command instead. func Fatalf(format string, args ...any) { msg := fmt.Sprintf(format, args...) + LogError("Fatal error", "msg", msg) fmt.Fprintln(os.Stderr, ErrorStyle.Render(Glyph(":cross:")+" "+msg)) os.Exit(1) } -// FatalWrap prints a wrapped error message to stderr and exits with code 1. +// FatalWrap prints a wrapped error message to stderr, logs it, and exits with code 1. // Does nothing if err is nil. // // Deprecated: return an error from the command instead. @@ -136,12 +138,13 @@ func FatalWrap(err error, msg string) { if err == nil { return } + LogError("Fatal error", "msg", msg, "err", err) fullMsg := fmt.Sprintf("%s: %v", msg, err) fmt.Fprintln(os.Stderr, ErrorStyle.Render(Glyph(":cross:")+" "+fullMsg)) os.Exit(1) } -// FatalWrapVerb prints a wrapped error using i18n grammar to stderr and exits with code 1. +// FatalWrapVerb prints a wrapped error using i18n grammar to stderr, logs it, and exits with code 1. // Does nothing if err is nil. // // Deprecated: return an error from the command instead. @@ -152,6 +155,7 @@ func FatalWrapVerb(err error, verb, subject string) { return } msg := i18n.ActionFailed(verb, subject) + LogError("Fatal error", "msg", msg, "err", err, "verb", verb, "subject", subject) fullMsg := fmt.Sprintf("%s: %v", msg, err) fmt.Fprintln(os.Stderr, ErrorStyle.Render(Glyph(":cross:")+" "+fullMsg)) os.Exit(1) diff --git a/pkg/cli/log.go b/pkg/cli/log.go index 2cc542e2..1dcd4b46 100644 --- a/pkg/cli/log.go +++ b/pkg/cli/log.go @@ -67,30 +67,30 @@ func Log() *LogService { return svc } -// LogDebug logs a debug message if log service is available. -func LogDebug(msg string) { +// LogDebug logs a debug message with optional key-value pairs if log service is available. +func LogDebug(msg string, keyvals ...any) { if l := Log(); l != nil { - l.Debug(msg) + l.Debug(msg, keyvals...) } } -// LogInfo logs an info message if log service is available. -func LogInfo(msg string) { +// LogInfo logs an info message with optional key-value pairs if log service is available. +func LogInfo(msg string, keyvals ...any) { if l := Log(); l != nil { - l.Info(msg) + l.Info(msg, keyvals...) } } -// LogWarn logs a warning message if log service is available. -func LogWarn(msg string) { +// LogWarn logs a warning message with optional key-value pairs if log service is available. +func LogWarn(msg string, keyvals ...any) { if l := Log(); l != nil { - l.Warn(msg) + l.Warn(msg, keyvals...) } } -// LogError logs an error message if log service is available. -func LogError(msg string) { +// LogError logs an error message with optional key-value pairs if log service is available. +func LogError(msg string, keyvals ...any) { if l := Log(); l != nil { - l.Error(msg) + l.Error(msg, keyvals...) } } diff --git a/pkg/cli/output.go b/pkg/cli/output.go index ccdec22b..6c4fb7fc 100644 --- a/pkg/cli/output.go +++ b/pkg/cli/output.go @@ -46,17 +46,18 @@ func Successf(format string, args ...any) { Success(fmt.Sprintf(format, args...)) } -// Error prints an error message with cross (red) to stderr. +// Error prints an error message with cross (red) to stderr and logs it. func Error(msg string) { + LogError(msg) fmt.Fprintln(os.Stderr, ErrorStyle.Render(Glyph(":cross:")+" "+msg)) } -// Errorf prints a formatted error message to stderr. +// Errorf prints a formatted error message to stderr and logs it. func Errorf(format string, args ...any) { Error(fmt.Sprintf(format, args...)) } -// ErrorWrap prints a wrapped error message to stderr. +// ErrorWrap prints a wrapped error message to stderr and logs it. func ErrorWrap(err error, msg string) { if err == nil { return @@ -64,7 +65,7 @@ func ErrorWrap(err error, msg string) { Error(fmt.Sprintf("%s: %v", msg, err)) } -// ErrorWrapVerb prints a wrapped error using i18n grammar to stderr. +// ErrorWrapVerb prints a wrapped error using i18n grammar to stderr and logs it. func ErrorWrapVerb(err error, verb, subject string) { if err == nil { return @@ -73,7 +74,7 @@ func ErrorWrapVerb(err error, verb, subject string) { Error(fmt.Sprintf("%s: %v", msg, err)) } -// ErrorWrapAction prints a wrapped error using i18n grammar to stderr. +// ErrorWrapAction prints a wrapped error using i18n grammar to stderr and logs it. func ErrorWrapAction(err error, verb string) { if err == nil { return @@ -82,12 +83,13 @@ func ErrorWrapAction(err error, verb string) { Error(fmt.Sprintf("%s: %v", msg, err)) } -// Warn prints a warning message with warning symbol (amber) to stderr. +// Warn prints a warning message with warning symbol (amber) to stderr and logs it. func Warn(msg string) { + LogWarn(msg) fmt.Fprintln(os.Stderr, WarningStyle.Render(Glyph(":warn:")+" "+msg)) } -// Warnf prints a formatted warning message to stderr. +// Warnf prints a formatted warning message to stderr and logs it. func Warnf(format string, args ...any) { Warn(fmt.Sprintf(format, args...)) } diff --git a/pkg/cli/runtime.go b/pkg/cli/runtime.go index 3291692f..9a33ccae 100644 --- a/pkg/cli/runtime.go +++ b/pkg/cli/runtime.go @@ -15,7 +15,6 @@ package cli import ( "context" - "fmt" "os" "os/signal" "sync" @@ -193,7 +192,7 @@ func (s *signalService) OnStartup(ctx context.Context) error { case syscall.SIGHUP: if s.onReload != nil { if err := s.onReload(); err != nil { - LogError(fmt.Sprintf("reload failed: %v", err)) + LogError("reload failed", "err", err) } else { LogInfo("configuration reloaded") } diff --git a/pkg/log/errors.go b/pkg/log/errors.go index c6775521..af55a429 100644 --- a/pkg/log/errors.go +++ b/pkg/log/errors.go @@ -174,6 +174,37 @@ func Root(err error) error { } } +// StackTrace returns the logical stack trace (chain of operations) from an error. +// It returns an empty slice if no operational context is found. +func StackTrace(err error) []string { + var stack []string + for err != nil { + if e, ok := err.(*Err); ok { + if e.Op != "" { + stack = append(stack, e.Op) + } + } + err = errors.Unwrap(err) + } + return stack +} + +// FormatStackTrace returns a pretty-printed logical stack trace. +func FormatStackTrace(err error) string { + stack := StackTrace(err) + if len(stack) == 0 { + return "" + } + var res string + for i, op := range stack { + if i > 0 { + res += " -> " + } + res += op + } + return res +} + // --- Combined Log-and-Return Helpers --- // LogError logs an error at Error level and returns a wrapped error. diff --git a/pkg/log/errors_test.go b/pkg/log/errors_test.go index 96cbd12f..b403cfd2 100644 --- a/pkg/log/errors_test.go +++ b/pkg/log/errors_test.go @@ -3,6 +3,7 @@ package log import ( "bytes" "errors" + "fmt" "strings" "testing" @@ -303,3 +304,46 @@ func TestMust_Ugly_Panics(t *testing.T) { output := buf.String() assert.True(t, strings.Contains(output, "[ERR]") || len(output) > 0) } + +func TestStackTrace_Good(t *testing.T) { + // Nested operations + err := E("op1", "msg1", nil) + err = Wrap(err, "op2", "msg2") + err = Wrap(err, "op3", "msg3") + + stack := StackTrace(err) + assert.Equal(t, []string{"op3", "op2", "op1"}, stack) + + // Format + formatted := FormatStackTrace(err) + assert.Equal(t, "op3 -> op2 -> op1", formatted) +} + +func TestStackTrace_PlainError(t *testing.T) { + err := errors.New("plain error") + assert.Empty(t, StackTrace(err)) + assert.Empty(t, FormatStackTrace(err)) +} + +func TestStackTrace_Nil(t *testing.T) { + assert.Empty(t, StackTrace(nil)) + assert.Empty(t, FormatStackTrace(nil)) +} + +func TestStackTrace_NoOp(t *testing.T) { + err := &Err{Msg: "no op"} + assert.Empty(t, StackTrace(err)) + assert.Empty(t, FormatStackTrace(err)) +} + +func TestStackTrace_Mixed(t *testing.T) { + err := E("inner", "msg", nil) + err = errors.New("middle: " + err.Error()) // Breaks the chain if not handled properly, but Unwrap should work if it's a wrapped error + // Wait, errors.New doesn't wrap. fmt.Errorf("%w") does. + err = E("inner", "msg", nil) + err = fmt.Errorf("wrapper: %w", err) + err = Wrap(err, "outer", "msg") + + stack := StackTrace(err) + assert.Equal(t, []string{"outer", "inner"}, stack) +} diff --git a/pkg/log/log.go b/pkg/log/log.go index 84c290de..6529fd7d 100644 --- a/pkg/log/log.go +++ b/pkg/log/log.go @@ -131,6 +131,41 @@ func (l *Logger) log(level Level, prefix, msg string, keyvals ...any) { timestamp := styleTimestamp(time.Now().Format("15:04:05")) + // Automatically extract context from error if present in keyvals + origLen := len(keyvals) + for i := 0; i < origLen; i += 2 { + if i+1 < origLen { + if err, ok := keyvals[i+1].(error); ok { + if op := Op(err); op != "" { + // Check if op is already in keyvals + hasOp := false + for j := 0; j < len(keyvals); j += 2 { + if keyvals[j] == "op" { + hasOp = true + break + } + } + if !hasOp { + keyvals = append(keyvals, "op", op) + } + } + if stack := FormatStackTrace(err); stack != "" { + // Check if stack is already in keyvals + hasStack := false + for j := 0; j < len(keyvals); j += 2 { + if keyvals[j] == "stack" { + hasStack = true + break + } + } + if !hasStack { + keyvals = append(keyvals, "stack", stack) + } + } + } + } + } + // Format key-value pairs var kvStr string if len(keyvals) > 0 { diff --git a/pkg/log/log_test.go b/pkg/log/log_test.go index 6721e395..ea7fc2a1 100644 --- a/pkg/log/log_test.go +++ b/pkg/log/log_test.go @@ -71,6 +71,24 @@ func TestLogger_KeyValues(t *testing.T) { } } +func TestLogger_ErrorContext(t *testing.T) { + var buf bytes.Buffer + l := New(Options{Output: &buf, Level: LevelInfo}) + + err := E("test.Op", "failed", NewError("root cause")) + err = Wrap(err, "outer.Op", "outer failed") + + l.Error("something failed", "err", err) + + got := buf.String() + if !strings.Contains(got, "op=outer.Op") { + t.Errorf("expected output to contain op=outer.Op, got %q", got) + } + if !strings.Contains(got, "stack=outer.Op -> test.Op") { + t.Errorf("expected output to contain stack=outer.Op -> test.Op, got %q", got) + } +} + func TestLogger_SetLevel(t *testing.T) { l := New(Options{Level: LevelInfo}) diff --git a/pkg/mcp/mcp.go b/pkg/mcp/mcp.go index 0d3dba0d..1ab3037a 100644 --- a/pkg/mcp/mcp.go +++ b/pkg/mcp/mcp.go @@ -11,6 +11,7 @@ import ( "github.com/host-uk/core/pkg/io" "github.com/host-uk/core/pkg/io/local" + "github.com/host-uk/core/pkg/log" "github.com/modelcontextprotocol/go-sdk/mcp" ) @@ -281,6 +282,7 @@ type EditDiffOutput struct { func (s *Service) readFile(ctx context.Context, req *mcp.CallToolRequest, input ReadFileInput) (*mcp.CallToolResult, ReadFileOutput, error) { content, err := s.medium.Read(input.Path) if err != nil { + log.Error("mcp: read file failed", "path", input.Path, "err", err) return nil, ReadFileOutput{}, fmt.Errorf("failed to read file: %w", err) } return nil, ReadFileOutput{ @@ -293,6 +295,7 @@ func (s *Service) readFile(ctx context.Context, req *mcp.CallToolRequest, input func (s *Service) writeFile(ctx context.Context, req *mcp.CallToolRequest, input WriteFileInput) (*mcp.CallToolResult, WriteFileOutput, error) { // Medium.Write creates parent directories automatically if err := s.medium.Write(input.Path, input.Content); err != nil { + log.Error("mcp: write file failed", "path", input.Path, "err", err) return nil, WriteFileOutput{}, fmt.Errorf("failed to write file: %w", err) } return nil, WriteFileOutput{Success: true, Path: input.Path}, nil @@ -301,6 +304,7 @@ func (s *Service) writeFile(ctx context.Context, req *mcp.CallToolRequest, input func (s *Service) listDirectory(ctx context.Context, req *mcp.CallToolRequest, input ListDirectoryInput) (*mcp.CallToolResult, ListDirectoryOutput, error) { entries, err := s.medium.List(input.Path) if err != nil { + log.Error("mcp: list directory failed", "path", input.Path, "err", err) return nil, ListDirectoryOutput{}, fmt.Errorf("failed to list directory: %w", err) } result := make([]DirectoryEntry, 0, len(entries)) @@ -322,6 +326,7 @@ func (s *Service) listDirectory(ctx context.Context, req *mcp.CallToolRequest, i func (s *Service) createDirectory(ctx context.Context, req *mcp.CallToolRequest, input CreateDirectoryInput) (*mcp.CallToolResult, CreateDirectoryOutput, error) { if err := s.medium.EnsureDir(input.Path); err != nil { + log.Error("mcp: create directory failed", "path", input.Path, "err", err) return nil, CreateDirectoryOutput{}, fmt.Errorf("failed to create directory: %w", err) } return nil, CreateDirectoryOutput{Success: true, Path: input.Path}, nil @@ -329,6 +334,7 @@ func (s *Service) createDirectory(ctx context.Context, req *mcp.CallToolRequest, func (s *Service) deleteFile(ctx context.Context, req *mcp.CallToolRequest, input DeleteFileInput) (*mcp.CallToolResult, DeleteFileOutput, error) { if err := s.medium.Delete(input.Path); err != nil { + log.Error("mcp: delete file failed", "path", input.Path, "err", err) return nil, DeleteFileOutput{}, fmt.Errorf("failed to delete file: %w", err) } return nil, DeleteFileOutput{Success: true, Path: input.Path}, nil @@ -336,6 +342,7 @@ func (s *Service) deleteFile(ctx context.Context, req *mcp.CallToolRequest, inpu func (s *Service) renameFile(ctx context.Context, req *mcp.CallToolRequest, input RenameFileInput) (*mcp.CallToolResult, RenameFileOutput, error) { if err := s.medium.Rename(input.OldPath, input.NewPath); err != nil { + log.Error("mcp: rename file failed", "oldPath", input.OldPath, "newPath", input.NewPath, "err", err) return nil, RenameFileOutput{}, fmt.Errorf("failed to rename file: %w", err) } return nil, RenameFileOutput{Success: true, OldPath: input.OldPath, NewPath: input.NewPath}, nil @@ -389,6 +396,7 @@ func (s *Service) editDiff(ctx context.Context, req *mcp.CallToolRequest, input content, err := s.medium.Read(input.Path) if err != nil { + log.Error("mcp: edit file read failed", "path", input.Path, "err", err) return nil, EditDiffOutput{}, fmt.Errorf("failed to read file: %w", err) } @@ -409,6 +417,7 @@ func (s *Service) editDiff(ctx context.Context, req *mcp.CallToolRequest, input } if err := s.medium.Write(input.Path, content); err != nil { + log.Error("mcp: edit file write failed", "path", input.Path, "err", err) return nil, EditDiffOutput{}, fmt.Errorf("failed to write file: %w", err) } diff --git a/pkg/mcp/transport_tcp.go b/pkg/mcp/transport_tcp.go index dd88b4ad..dc60b1b6 100644 --- a/pkg/mcp/transport_tcp.go +++ b/pkg/mcp/transport_tcp.go @@ -57,7 +57,7 @@ func (s *Service) ServeTCP(ctx context.Context, addr string) error { case <-ctx.Done(): return nil default: - log.Error("Accept error", "err", err) + log.Error("mcp: accept error", "err", err) continue } } @@ -83,7 +83,7 @@ func (s *Service) handleConnection(ctx context.Context, conn net.Conn) { // Run server (blocks until connection closed) // Server.Run calls Connect, then Read loop. if err := server.Run(ctx, transport); err != nil { - log.Error("Connection error", "err", err) + log.Error("mcp: connection error", "err", err, "remote", conn.RemoteAddr()) } }