From 54a36a779bef0ad7eb5ef0e585d746ce42cbd4ea Mon Sep 17 00:00:00 2001 From: Snider Date: Fri, 6 Mar 2026 09:30:57 +0000 Subject: [PATCH] feat: standalone structured logging and error handling Zero-dependency logging + error types extracted from core/go. - E(), Wrap(), WrapCode() structured errors with Op/Msg/Code - Structured logger with levels, security logging, key-value pairs - RotationWriterFactory hook for io.Medium integration - StackTrace(), Root(), FormatStackTrace() error introspection Co-Authored-By: Virgil --- errors.go | 260 ++++++++++++++++++++++++++++++++++++ errors_test.go | 349 +++++++++++++++++++++++++++++++++++++++++++++++++ go.mod | 14 ++ go.sum | 23 ++++ log.go | 310 +++++++++++++++++++++++++++++++++++++++++++ log_test.go | 165 +++++++++++++++++++++++ 6 files changed, 1121 insertions(+) create mode 100644 errors.go create mode 100644 errors_test.go create mode 100644 go.mod create mode 100644 go.sum create mode 100644 log.go create mode 100644 log_test.go diff --git a/errors.go b/errors.go new file mode 100644 index 0000000..af55a42 --- /dev/null +++ b/errors.go @@ -0,0 +1,260 @@ +// Package log provides structured logging and error handling for Core applications. +// +// This file implements structured error types and combined log-and-return helpers +// that simplify common error handling patterns. + +package log + +import ( + "errors" + "fmt" +) + +// Err represents a structured error with operational context. +// It implements the error interface and supports unwrapping. +type Err struct { + Op string // Operation being performed (e.g., "user.Save") + Msg string // Human-readable message + Err error // Underlying error (optional) + Code string // Error code (optional, e.g., "VALIDATION_FAILED") +} + +// Error implements the error interface. +func (e *Err) Error() string { + var prefix string + if e.Op != "" { + prefix = e.Op + ": " + } + if e.Err != nil { + if e.Code != "" { + return fmt.Sprintf("%s%s [%s]: %v", prefix, e.Msg, e.Code, e.Err) + } + return fmt.Sprintf("%s%s: %v", prefix, e.Msg, e.Err) + } + if e.Code != "" { + return fmt.Sprintf("%s%s [%s]", prefix, e.Msg, e.Code) + } + return fmt.Sprintf("%s%s", prefix, e.Msg) +} + +// Unwrap returns the underlying error for use with errors.Is and errors.As. +func (e *Err) Unwrap() error { + return e.Err +} + +// --- Error Creation Functions --- + +// E creates a new Err with operation context. +// The underlying error can be nil for creating errors without a cause. +// +// Example: +// +// return log.E("user.Save", "failed to save user", err) +// return log.E("api.Call", "rate limited", nil) // No underlying cause +func E(op, msg string, err error) error { + return &Err{Op: op, Msg: msg, Err: err} +} + +// Wrap wraps an error with operation context. +// Returns nil if err is nil, to support conditional wrapping. +// Preserves error Code if the wrapped error is an *Err. +// +// Example: +// +// return log.Wrap(err, "db.Query", "database query failed") +func Wrap(err error, op, msg string) error { + if err == nil { + return nil + } + // Preserve Code from wrapped *Err + var logErr *Err + if As(err, &logErr) && logErr.Code != "" { + return &Err{Op: op, Msg: msg, Err: err, Code: logErr.Code} + } + return &Err{Op: op, Msg: msg, Err: err} +} + +// WrapCode wraps an error with operation context and error code. +// Returns nil only if both err is nil AND code is empty. +// Useful for API errors that need machine-readable codes. +// +// Example: +// +// return log.WrapCode(err, "VALIDATION_ERROR", "user.Validate", "invalid email") +func WrapCode(err error, code, op, msg string) error { + if err == nil && code == "" { + return nil + } + return &Err{Op: op, Msg: msg, Err: err, Code: code} +} + +// NewCode creates an error with just code and message (no underlying error). +// Useful for creating sentinel errors with codes. +// +// Example: +// +// var ErrNotFound = log.NewCode("NOT_FOUND", "resource not found") +func NewCode(code, msg string) error { + return &Err{Msg: msg, Code: code} +} + +// --- Standard Library Wrappers --- + +// Is reports whether any error in err's tree matches target. +// Wrapper around errors.Is for convenience. +func Is(err, target error) bool { + return errors.Is(err, target) +} + +// As finds the first error in err's tree that matches target. +// Wrapper around errors.As for convenience. +func As(err error, target any) bool { + return errors.As(err, target) +} + +// NewError creates a simple error with the given text. +// Wrapper around errors.New for convenience. +func NewError(text string) error { + return errors.New(text) +} + +// Join combines multiple errors into one. +// Wrapper around errors.Join for convenience. +func Join(errs ...error) error { + return errors.Join(errs...) +} + +// --- Error Introspection Helpers --- + +// Op extracts the operation name from an error. +// Returns empty string if the error is not an *Err. +func Op(err error) string { + var e *Err + if As(err, &e) { + return e.Op + } + return "" +} + +// ErrCode extracts the error code from an error. +// Returns empty string if the error is not an *Err or has no code. +func ErrCode(err error) string { + var e *Err + if As(err, &e) { + return e.Code + } + return "" +} + +// Message extracts the message from an error. +// Returns the error's Error() string if not an *Err. +func Message(err error) string { + if err == nil { + return "" + } + var e *Err + if As(err, &e) { + return e.Msg + } + return err.Error() +} + +// Root returns the root cause of an error chain. +// Unwraps until no more wrapped errors are found. +func Root(err error) error { + if err == nil { + return nil + } + for { + unwrapped := errors.Unwrap(err) + if unwrapped == nil { + return err + } + err = unwrapped + } +} + +// 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. +// Reduces boilerplate in error handling paths. +// +// Example: +// +// // Before +// if err != nil { +// log.Error("failed to save", "err", err) +// return errors.Wrap(err, "user.Save", "failed to save") +// } +// +// // After +// if err != nil { +// return log.LogError(err, "user.Save", "failed to save") +// } +func LogError(err error, op, msg string) error { + if err == nil { + return nil + } + wrapped := Wrap(err, op, msg) + defaultLogger.Error(msg, "op", op, "err", err) + return wrapped +} + +// LogWarn logs at Warn level and returns a wrapped error. +// Use for recoverable errors that should be logged but not treated as critical. +// +// Example: +// +// return log.LogWarn(err, "cache.Get", "cache miss, falling back to db") +func LogWarn(err error, op, msg string) error { + if err == nil { + return nil + } + wrapped := Wrap(err, op, msg) + defaultLogger.Warn(msg, "op", op, "err", err) + return wrapped +} + +// Must panics if err is not nil, logging first. +// Use for errors that should never happen and indicate programmer error. +// +// Example: +// +// log.Must(Initialize(), "app", "startup failed") +func Must(err error, op, msg string) { + if err != nil { + defaultLogger.Error(msg, "op", op, "err", err) + panic(Wrap(err, op, msg)) + } +} diff --git a/errors_test.go b/errors_test.go new file mode 100644 index 0000000..b403cfd --- /dev/null +++ b/errors_test.go @@ -0,0 +1,349 @@ +package log + +import ( + "bytes" + "errors" + "fmt" + "strings" + "testing" + + "github.com/stretchr/testify/assert" +) + +// --- Err Type Tests --- + +func TestErr_Error_Good(t *testing.T) { + // With underlying error + err := &Err{Op: "db.Query", Msg: "failed to query", Err: errors.New("connection refused")} + assert.Equal(t, "db.Query: failed to query: connection refused", err.Error()) + + // With code + err = &Err{Op: "api.Call", Msg: "request failed", Code: "TIMEOUT"} + assert.Equal(t, "api.Call: request failed [TIMEOUT]", err.Error()) + + // With both underlying error and code + err = &Err{Op: "user.Save", Msg: "save failed", Err: errors.New("duplicate key"), Code: "DUPLICATE"} + assert.Equal(t, "user.Save: save failed [DUPLICATE]: duplicate key", err.Error()) + + // Just op and msg + err = &Err{Op: "cache.Get", Msg: "miss"} + assert.Equal(t, "cache.Get: miss", err.Error()) +} + +func TestErr_Error_EmptyOp_Good(t *testing.T) { + // No Op - should not have leading colon + err := &Err{Msg: "just a message"} + assert.Equal(t, "just a message", err.Error()) + + // No Op with code + err = &Err{Msg: "error with code", Code: "ERR_CODE"} + assert.Equal(t, "error with code [ERR_CODE]", err.Error()) + + // No Op with underlying error + err = &Err{Msg: "wrapped", Err: errors.New("underlying")} + assert.Equal(t, "wrapped: underlying", err.Error()) +} + +func TestErr_Unwrap_Good(t *testing.T) { + underlying := errors.New("underlying error") + err := &Err{Op: "test", Msg: "wrapped", Err: underlying} + + assert.Equal(t, underlying, errors.Unwrap(err)) + assert.True(t, errors.Is(err, underlying)) +} + +// --- Error Creation Function Tests --- + +func TestE_Good(t *testing.T) { + underlying := errors.New("base error") + err := E("op.Name", "something failed", underlying) + + assert.NotNil(t, err) + var logErr *Err + assert.True(t, errors.As(err, &logErr)) + assert.Equal(t, "op.Name", logErr.Op) + assert.Equal(t, "something failed", logErr.Msg) + assert.Equal(t, underlying, logErr.Err) +} + +func TestE_Good_NilError(t *testing.T) { + // E creates an error even with nil underlying - useful for errors without causes + err := E("op.Name", "message", nil) + assert.NotNil(t, err) + assert.Equal(t, "op.Name: message", err.Error()) +} + +func TestWrap_Good(t *testing.T) { + underlying := errors.New("base") + err := Wrap(underlying, "handler.Process", "processing failed") + + assert.NotNil(t, err) + assert.Contains(t, err.Error(), "handler.Process") + assert.Contains(t, err.Error(), "processing failed") + assert.True(t, errors.Is(err, underlying)) +} + +func TestWrap_PreservesCode_Good(t *testing.T) { + // Create an error with a code + inner := WrapCode(errors.New("base"), "VALIDATION_ERROR", "inner.Op", "validation failed") + + // Wrap it - should preserve the code + outer := Wrap(inner, "outer.Op", "outer context") + + assert.NotNil(t, outer) + assert.Equal(t, "VALIDATION_ERROR", ErrCode(outer)) + assert.Contains(t, outer.Error(), "[VALIDATION_ERROR]") +} + +func TestWrap_NilError_Good(t *testing.T) { + err := Wrap(nil, "op", "msg") + assert.Nil(t, err) +} + +func TestWrapCode_Good(t *testing.T) { + underlying := errors.New("validation failed") + err := WrapCode(underlying, "INVALID_INPUT", "api.Validate", "bad request") + + assert.NotNil(t, err) + var logErr *Err + assert.True(t, errors.As(err, &logErr)) + assert.Equal(t, "INVALID_INPUT", logErr.Code) + assert.Equal(t, "api.Validate", logErr.Op) + assert.Contains(t, err.Error(), "[INVALID_INPUT]") +} + +func TestWrapCode_Good_NilError(t *testing.T) { + // WrapCode with nil error but with code still creates an error + err := WrapCode(nil, "CODE", "op", "msg") + assert.NotNil(t, err) + assert.Contains(t, err.Error(), "[CODE]") + + // Only returns nil when both error and code are empty + err = WrapCode(nil, "", "op", "msg") + assert.Nil(t, err) +} + +func TestNewCode_Good(t *testing.T) { + err := NewCode("NOT_FOUND", "resource not found") + + var logErr *Err + assert.True(t, errors.As(err, &logErr)) + assert.Equal(t, "NOT_FOUND", logErr.Code) + assert.Equal(t, "resource not found", logErr.Msg) + assert.Nil(t, logErr.Err) +} + +// --- Standard Library Wrapper Tests --- + +func TestIs_Good(t *testing.T) { + sentinel := errors.New("sentinel") + wrapped := Wrap(sentinel, "test", "wrapped") + + assert.True(t, Is(wrapped, sentinel)) + assert.False(t, Is(wrapped, errors.New("other"))) +} + +func TestAs_Good(t *testing.T) { + err := E("test.Op", "message", errors.New("base")) + + var logErr *Err + assert.True(t, As(err, &logErr)) + assert.Equal(t, "test.Op", logErr.Op) +} + +func TestNewError_Good(t *testing.T) { + err := NewError("simple error") + assert.NotNil(t, err) + assert.Equal(t, "simple error", err.Error()) +} + +func TestJoin_Good(t *testing.T) { + err1 := errors.New("error 1") + err2 := errors.New("error 2") + joined := Join(err1, err2) + + assert.True(t, errors.Is(joined, err1)) + assert.True(t, errors.Is(joined, err2)) +} + +// --- Helper Function Tests --- + +func TestOp_Good(t *testing.T) { + err := E("mypackage.MyFunc", "failed", errors.New("cause")) + assert.Equal(t, "mypackage.MyFunc", Op(err)) +} + +func TestOp_Good_NotLogError(t *testing.T) { + err := errors.New("plain error") + assert.Equal(t, "", Op(err)) +} + +func TestErrCode_Good(t *testing.T) { + err := WrapCode(errors.New("base"), "ERR_CODE", "op", "msg") + assert.Equal(t, "ERR_CODE", ErrCode(err)) +} + +func TestErrCode_Good_NoCode(t *testing.T) { + err := E("op", "msg", errors.New("base")) + assert.Equal(t, "", ErrCode(err)) +} + +func TestMessage_Good(t *testing.T) { + err := E("op", "the message", errors.New("base")) + assert.Equal(t, "the message", Message(err)) +} + +func TestMessage_Good_PlainError(t *testing.T) { + err := errors.New("plain message") + assert.Equal(t, "plain message", Message(err)) +} + +func TestMessage_Good_Nil(t *testing.T) { + assert.Equal(t, "", Message(nil)) +} + +func TestRoot_Good(t *testing.T) { + root := errors.New("root cause") + level1 := Wrap(root, "level1", "wrapped once") + level2 := Wrap(level1, "level2", "wrapped twice") + + assert.Equal(t, root, Root(level2)) +} + +func TestRoot_Good_SingleError(t *testing.T) { + err := errors.New("single") + assert.Equal(t, err, Root(err)) +} + +func TestRoot_Good_Nil(t *testing.T) { + assert.Nil(t, Root(nil)) +} + +// --- Log-and-Return Helper Tests --- + +func TestLogError_Good(t *testing.T) { + // Capture log output + var buf bytes.Buffer + logger := New(Options{Level: LevelDebug, Output: &buf}) + SetDefault(logger) + defer SetDefault(New(Options{Level: LevelInfo})) + + underlying := errors.New("connection failed") + err := LogError(underlying, "db.Connect", "database unavailable") + + // Check returned error + assert.NotNil(t, err) + assert.Contains(t, err.Error(), "db.Connect") + assert.Contains(t, err.Error(), "database unavailable") + assert.True(t, errors.Is(err, underlying)) + + // Check log output + output := buf.String() + assert.Contains(t, output, "[ERR]") + assert.Contains(t, output, "database unavailable") + assert.Contains(t, output, "op=db.Connect") +} + +func TestLogError_Good_NilError(t *testing.T) { + var buf bytes.Buffer + logger := New(Options{Level: LevelDebug, Output: &buf}) + SetDefault(logger) + defer SetDefault(New(Options{Level: LevelInfo})) + + err := LogError(nil, "op", "msg") + assert.Nil(t, err) + assert.Empty(t, buf.String()) // No log output for nil error +} + +func TestLogWarn_Good(t *testing.T) { + var buf bytes.Buffer + logger := New(Options{Level: LevelDebug, Output: &buf}) + SetDefault(logger) + defer SetDefault(New(Options{Level: LevelInfo})) + + underlying := errors.New("cache miss") + err := LogWarn(underlying, "cache.Get", "falling back to db") + + assert.NotNil(t, err) + assert.True(t, errors.Is(err, underlying)) + + output := buf.String() + assert.Contains(t, output, "[WRN]") + assert.Contains(t, output, "falling back to db") +} + +func TestLogWarn_Good_NilError(t *testing.T) { + var buf bytes.Buffer + logger := New(Options{Level: LevelDebug, Output: &buf}) + SetDefault(logger) + defer SetDefault(New(Options{Level: LevelInfo})) + + err := LogWarn(nil, "op", "msg") + assert.Nil(t, err) + assert.Empty(t, buf.String()) +} + +func TestMust_Good_NoError(t *testing.T) { + // Should not panic when error is nil + assert.NotPanics(t, func() { + Must(nil, "test", "should not panic") + }) +} + +func TestMust_Ugly_Panics(t *testing.T) { + var buf bytes.Buffer + logger := New(Options{Level: LevelDebug, Output: &buf}) + SetDefault(logger) + defer SetDefault(New(Options{Level: LevelInfo})) + + assert.Panics(t, func() { + Must(errors.New("fatal error"), "startup", "initialization failed") + }) + + // Verify error was logged before panic + 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/go.mod b/go.mod new file mode 100644 index 0000000..bf25951 --- /dev/null +++ b/go.mod @@ -0,0 +1,14 @@ +module forge.lthn.ai/core/go-log + +go 1.26.0 + +require github.com/stretchr/testify v1.11.1 + +require ( + github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc // indirect + github.com/kr/pretty v0.3.1 // indirect + github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 // indirect + github.com/rogpeppe/go-internal v1.14.1 // indirect + gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect +) diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..5a10c39 --- /dev/null +++ b/go.sum @@ -0,0 +1,23 @@ +github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= +github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc h1:U9qPSI2PIWSS1VwoXQT9A3Wy9MM3WgvqSxFWenqJduM= +github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI= +github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE= +github.com/kr/pretty v0.3.1/go.mod h1:hoEshYVHaxMs3cyo3Yncou5ZscifuDolrwPKZanG3xk= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= +github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= +github.com/pkg/diff v0.0.0-20210226163009-20ebb0f2a09e/go.mod h1:pJLUxLENpZxwdsKMEsNbx1VGcRFpLqf3715MtcvvzbA= +github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 h1:Jamvg5psRIccs7FGNTlIRMkT8wgtp5eCXdBlqhYGL6U= +github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/rogpeppe/go-internal v1.9.0/go.mod h1:WtVeX8xhTBvf0smdhujwtBcq4Qrzq/fJaraNFVN+nFs= +github.com/rogpeppe/go-internal v1.14.1 h1:UQB4HGPB6osV0SQTLymcB4TgvyWu6ZyliaW0tI/otEQ= +github.com/rogpeppe/go-internal v1.14.1/go.mod h1:MaRKkUm5W0goXpeCfT7UZI6fk/L7L7so1lCWt35ZSgc= +github.com/stretchr/testify v1.11.1 h1:7s2iGBzp5EwR7/aIZr8ao5+dra3wiQyKjjFuvgVKu7U= +github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD981Nm4B6U= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/log.go b/log.go new file mode 100644 index 0000000..741468f --- /dev/null +++ b/log.go @@ -0,0 +1,310 @@ +// Package log provides structured logging and error handling for Core applications. +// +// log.SetLevel(log.LevelDebug) +// log.Info("server started", "port", 8080) +// log.Error("failed to connect", "err", err) +package log + +import ( + "fmt" + "io" + "os" + "os/user" + "sync" + "time" +) + +// Level defines logging verbosity. +type Level int + +// Logging level constants ordered by increasing verbosity. +const ( + // LevelQuiet suppresses all log output. + LevelQuiet Level = iota + // LevelError shows only error messages. + LevelError + // LevelWarn shows warnings and errors. + LevelWarn + // LevelInfo shows informational messages, warnings, and errors. + LevelInfo + // LevelDebug shows all messages including debug details. + LevelDebug +) + +// String returns the level name. +func (l Level) String() string { + switch l { + case LevelQuiet: + return "quiet" + case LevelError: + return "error" + case LevelWarn: + return "warn" + case LevelInfo: + return "info" + case LevelDebug: + return "debug" + default: + return "unknown" + } +} + +// Logger provides structured logging. +type Logger struct { + mu sync.RWMutex + level Level + output io.Writer + + // Style functions for formatting (can be overridden) + StyleTimestamp func(string) string + StyleDebug func(string) string + StyleInfo func(string) string + StyleWarn func(string) string + StyleError func(string) string + StyleSecurity func(string) string +} + +// RotationOptions defines the log rotation and retention policy. +type RotationOptions struct { + // Filename is the log file path. If empty, rotation is disabled. + Filename string + + // MaxSize is the maximum size of the log file in megabytes before it gets rotated. + // It defaults to 100 megabytes. + MaxSize int + + // MaxAge is the maximum number of days to retain old log files based on their + // file modification time. It defaults to 28 days. + // Note: set to a negative value to disable age-based retention. + MaxAge int + + // MaxBackups is the maximum number of old log files to retain. + // It defaults to 5 backups. + MaxBackups int + + // Compress determines if the rotated log files should be compressed using gzip. + // It defaults to true. + Compress bool +} + +// Options configures a Logger. +type Options struct { + Level Level + // Output is the destination for log messages. If Rotation is provided, + // Output is ignored and logs are written to the rotating file instead. + Output io.Writer + // Rotation enables log rotation to file. If provided, Filename must be set. + Rotation *RotationOptions +} + +// RotationWriterFactory creates a rotating writer from options. +// Set this to enable log rotation (provided by core/go-io integration). +var RotationWriterFactory func(RotationOptions) io.WriteCloser + +// New creates a new Logger with the given options. +func New(opts Options) *Logger { + output := opts.Output + if opts.Rotation != nil && opts.Rotation.Filename != "" && RotationWriterFactory != nil { + output = RotationWriterFactory(*opts.Rotation) + } + if output == nil { + output = os.Stderr + } + + return &Logger{ + level: opts.Level, + output: output, + StyleTimestamp: identity, + StyleDebug: identity, + StyleInfo: identity, + StyleWarn: identity, + StyleError: identity, + StyleSecurity: identity, + } +} + +func identity(s string) string { return s } + +// SetLevel changes the log level. +func (l *Logger) SetLevel(level Level) { + l.mu.Lock() + l.level = level + l.mu.Unlock() +} + +// Level returns the current log level. +func (l *Logger) Level() Level { + l.mu.RLock() + defer l.mu.RUnlock() + return l.level +} + +// SetOutput changes the output writer. +func (l *Logger) SetOutput(w io.Writer) { + l.mu.Lock() + l.output = w + l.mu.Unlock() +} + +func (l *Logger) shouldLog(level Level) bool { + l.mu.RLock() + defer l.mu.RUnlock() + return level <= l.level +} + +func (l *Logger) log(level Level, prefix, msg string, keyvals ...any) { + l.mu.RLock() + output := l.output + styleTimestamp := l.StyleTimestamp + l.mu.RUnlock() + + 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 { + kvStr = " " + for i := 0; i < len(keyvals); i += 2 { + if i > 0 { + kvStr += " " + } + key := keyvals[i] + var val any + if i+1 < len(keyvals) { + val = keyvals[i+1] + } + kvStr += fmt.Sprintf("%v=%v", key, val) + } + } + + _, _ = fmt.Fprintf(output, "%s %s %s%s\n", timestamp, prefix, msg, kvStr) +} + +// Debug logs a debug message with optional key-value pairs. +func (l *Logger) Debug(msg string, keyvals ...any) { + if l.shouldLog(LevelDebug) { + l.log(LevelDebug, l.StyleDebug("[DBG]"), msg, keyvals...) + } +} + +// Info logs an info message with optional key-value pairs. +func (l *Logger) Info(msg string, keyvals ...any) { + if l.shouldLog(LevelInfo) { + l.log(LevelInfo, l.StyleInfo("[INF]"), msg, keyvals...) + } +} + +// Warn logs a warning message with optional key-value pairs. +func (l *Logger) Warn(msg string, keyvals ...any) { + if l.shouldLog(LevelWarn) { + l.log(LevelWarn, l.StyleWarn("[WRN]"), msg, keyvals...) + } +} + +// Error logs an error message with optional key-value pairs. +func (l *Logger) Error(msg string, keyvals ...any) { + if l.shouldLog(LevelError) { + l.log(LevelError, l.StyleError("[ERR]"), msg, keyvals...) + } +} + +// Security logs a security event with optional key-value pairs. +// It uses LevelError to ensure security events are visible even in restrictive +// log configurations. +func (l *Logger) Security(msg string, keyvals ...any) { + if l.shouldLog(LevelError) { + l.log(LevelError, l.StyleSecurity("[SEC]"), msg, keyvals...) + } +} + +// Username returns the current system username. +// It uses os/user for reliability and falls back to environment variables. +func Username() string { + if u, err := user.Current(); err == nil { + return u.Username + } + // Fallback for environments where user lookup might fail + if u := os.Getenv("USER"); u != "" { + return u + } + return os.Getenv("USERNAME") +} + +// --- Default logger --- + +var defaultLogger = New(Options{Level: LevelInfo}) + +// Default returns the default logger. +func Default() *Logger { + return defaultLogger +} + +// SetDefault sets the default logger. +func SetDefault(l *Logger) { + defaultLogger = l +} + +// SetLevel sets the default logger's level. +func SetLevel(level Level) { + defaultLogger.SetLevel(level) +} + +// Debug logs to the default logger. +func Debug(msg string, keyvals ...any) { + defaultLogger.Debug(msg, keyvals...) +} + +// Info logs to the default logger. +func Info(msg string, keyvals ...any) { + defaultLogger.Info(msg, keyvals...) +} + +// Warn logs to the default logger. +func Warn(msg string, keyvals ...any) { + defaultLogger.Warn(msg, keyvals...) +} + +// Error logs to the default logger. +func Error(msg string, keyvals ...any) { + defaultLogger.Error(msg, keyvals...) +} + +// Security logs to the default logger. +func Security(msg string, keyvals ...any) { + defaultLogger.Security(msg, keyvals...) +} diff --git a/log_test.go b/log_test.go new file mode 100644 index 0000000..17a4409 --- /dev/null +++ b/log_test.go @@ -0,0 +1,165 @@ +package log + +import ( + "bytes" + "strings" + "testing" + +) + +func TestLogger_Levels(t *testing.T) { + tests := []struct { + name string + level Level + logFunc func(*Logger, string, ...any) + expected bool + }{ + {"debug at debug", LevelDebug, (*Logger).Debug, true}, + {"info at debug", LevelDebug, (*Logger).Info, true}, + {"warn at debug", LevelDebug, (*Logger).Warn, true}, + {"error at debug", LevelDebug, (*Logger).Error, true}, + + {"debug at info", LevelInfo, (*Logger).Debug, false}, + {"info at info", LevelInfo, (*Logger).Info, true}, + {"warn at info", LevelInfo, (*Logger).Warn, true}, + {"error at info", LevelInfo, (*Logger).Error, true}, + + {"debug at warn", LevelWarn, (*Logger).Debug, false}, + {"info at warn", LevelWarn, (*Logger).Info, false}, + {"warn at warn", LevelWarn, (*Logger).Warn, true}, + {"error at warn", LevelWarn, (*Logger).Error, true}, + + {"debug at error", LevelError, (*Logger).Debug, false}, + {"info at error", LevelError, (*Logger).Info, false}, + {"warn at error", LevelError, (*Logger).Warn, false}, + {"error at error", LevelError, (*Logger).Error, true}, + + {"debug at quiet", LevelQuiet, (*Logger).Debug, false}, + {"info at quiet", LevelQuiet, (*Logger).Info, false}, + {"warn at quiet", LevelQuiet, (*Logger).Warn, false}, + {"error at quiet", LevelQuiet, (*Logger).Error, false}, + + {"security at info", LevelInfo, (*Logger).Security, true}, + {"security at error", LevelError, (*Logger).Security, true}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var buf bytes.Buffer + l := New(Options{Level: tt.level, Output: &buf}) + tt.logFunc(l, "test message") + + hasOutput := buf.Len() > 0 + if hasOutput != tt.expected { + t.Errorf("expected output=%v, got output=%v", tt.expected, hasOutput) + } + }) + } +} + +func TestLogger_KeyValues(t *testing.T) { + var buf bytes.Buffer + l := New(Options{Level: LevelDebug, Output: &buf}) + + l.Info("test message", "key1", "value1", "key2", 42) + + output := buf.String() + if !strings.Contains(output, "test message") { + t.Error("expected message in output") + } + if !strings.Contains(output, "key1=value1") { + t.Error("expected key1=value1 in output") + } + if !strings.Contains(output, "key2=42") { + t.Error("expected key2=42 in output") + } +} + +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}) + + if l.Level() != LevelInfo { + t.Error("expected initial level to be Info") + } + + l.SetLevel(LevelDebug) + if l.Level() != LevelDebug { + t.Error("expected level to be Debug after SetLevel") + } +} + +func TestLevel_String(t *testing.T) { + tests := []struct { + level Level + expected string + }{ + {LevelQuiet, "quiet"}, + {LevelError, "error"}, + {LevelWarn, "warn"}, + {LevelInfo, "info"}, + {LevelDebug, "debug"}, + {Level(99), "unknown"}, + } + + for _, tt := range tests { + t.Run(tt.expected, func(t *testing.T) { + if got := tt.level.String(); got != tt.expected { + t.Errorf("expected %q, got %q", tt.expected, got) + } + }) + } +} + +func TestLogger_Security(t *testing.T) { + var buf bytes.Buffer + l := New(Options{Level: LevelError, Output: &buf}) + + l.Security("unauthorized access", "user", "admin") + + output := buf.String() + if !strings.Contains(output, "[SEC]") { + t.Error("expected [SEC] prefix in security log") + } + if !strings.Contains(output, "unauthorized access") { + t.Error("expected message in security log") + } + if !strings.Contains(output, "user=admin") { + t.Error("expected context in security log") + } +} + +func TestDefault(t *testing.T) { + // Default logger should exist + if Default() == nil { + t.Error("expected default logger to exist") + } + + // Package-level functions should work + var buf bytes.Buffer + l := New(Options{Level: LevelDebug, Output: &buf}) + SetDefault(l) + + Info("test") + if buf.Len() == 0 { + t.Error("expected package-level Info to produce output") + } +} +