core/go-log
8
0
Fork 0
Code Issues 4 Pull requests Projects Releases Packages Wiki Activity Actions

chore(ax): AX compliance pass — variable naming, usage examples, full Good/Bad/Ugly test coverage

Browse source 
- Rename abbreviated locals: origLen→originalLength, hasOp→hasOperationKey,
  hasStack→hasStackKey, kvStr→keyValueString, logErr→typedError (errors.go, log.go)
- Add usage example comments to all exported functions lacking them:
  New, Username, SetLevel, SetRedactKeys, Debug, Info, Warn, Error, Security,
  Is, As, NewError, Join, Message (AX principle 2)
- Rewrite both test files to TestFilename_Function_{Good,Bad,Ugly} convention;
  all three categories mandatory per AX spec — every exported function now covered
- New test cases exercise edge paths: odd keyvals, injection with \r\n and null bytes,
  redaction of numeric values and duplicate keys, AllOps on nil, Must panic value type,
  LogWarn suppression at LevelError, NewCode as sentinel, rotation/output precedence

Co-Authored-By: Virgil <virgil@lethean.io>
This commit is contained in:
Claude 2026-03-31 08:12:56 +01:00
parent 0c06f1498d
commit 11d5577f4d
No known key found for this signature in database
GPG key ID: AF404715446AEB41
4 changed files with 927 additions and 386 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

39
errors.go
View file

@ -68,9 +68,9 @@ func Wrap(err error, op, msg string) error {
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}
var typedError *Err
if As(err, &typedError) && typedError.Code != "" {
return &Err{Op: op, Msg: msg, Err: err, Code: typedError.Code}
}
return &Err{Op: op, Msg: msg, Err: err}
}
@ -102,25 +102,30 @@ func NewCode(code, msg string) error {
// --- Standard Library Wrappers ---
// Is reports whether any error in err's tree matches target.
// Wrapper around errors.Is for convenience.
//
// if log.Is(err, ErrNotFound) { /* handle */ }
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.
//
// var typedError *log.Err
// if log.As(err, &typedError) { code := typedError.Code }
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.
//
// var ErrNotFound = log.NewError("not found")
func NewError(text string) error {
return errors.New(text)
}
// Join combines multiple errors into one.
// Wrapper around errors.Join for convenience.
//
// return log.Join(validationErr, permissionErr)
func Join(errs ...error) error {
return errors.Join(errs...)
}
@ -132,9 +137,9 @@ func Join(errs ...error) error {
//
// op := log.Op(err) // e.g. "user.Save"
func Op(err error) string {
var e *Err
if As(err, &e) {
return e.Op
var typedError *Err
if As(err, &typedError) {
return typedError.Op
}
return ""
}
@ -144,22 +149,24 @@ func Op(err error) string {
//
// code := log.ErrCode(err) // e.g. "VALIDATION_FAILED"
func ErrCode(err error) string {
var e *Err
if As(err, &e) {
return e.Code
var typedError *Err
if As(err, &typedError) {
return typedError.Code
}
return ""
}
// Message extracts the message from an error.
// Returns the error's Error() string if not an *Err.
//
// msg := log.Message(err) // "rate limited" (not the full "api.Call: rate limited: ...")
func Message(err error) string {
if err == nil {
return ""
}
var e *Err
if As(err, &e) {
return e.Msg
var typedError *Err
if As(err, &typedError) {
return typedError.Msg
}
return err.Error()
}

458
errors_test.go
View file

@ -10,28 +10,26 @@ import (
"github.com/stretchr/testify/assert"
)
// --- Err Type Tests ---
// --- Err type ---
func TestErr_Error_Good(t *testing.T) {
// With underlying error
func TestErrors_ErrError_Good(t *testing.T) {
// Op + Msg + 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
func TestErrors_ErrError_Bad(t *testing.T) {
// Code included in message
err := &Err{Op: "api.Call", Msg: "request failed", Code: "TIMEOUT"}
assert.Equal(t, "api.Call: request failed [TIMEOUT]", err.Error())
// All three: Op, Msg, Code, and underlying error
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())
}
func TestErrors_ErrError_Ugly(t *testing.T) {
// No Op — no leading colon
err := &Err{Msg: "just a message"}
assert.Equal(t, "just a message", err.Error())
@ -39,12 +37,18 @@ func TestErr_Error_EmptyOp_Good(t *testing.T) {
err = &Err{Msg: "error with code", Code: "ERR_CODE"}
assert.Equal(t, "error with code [ERR_CODE]", err.Error())
// No Op with underlying error
// No Op with underlying error only
err = &Err{Msg: "wrapped", Err: errors.New("underlying")}
assert.Equal(t, "wrapped: underlying", err.Error())
// Just op and msg, no error and no code
err = &Err{Op: "cache.Get", Msg: "miss"}
assert.Equal(t, "cache.Get: miss", err.Error())
}
func TestErr_Unwrap_Good(t *testing.T) {
// --- Err.Unwrap ---
func TestErrors_ErrUnwrap_Good(t *testing.T) {
underlying := errors.New("underlying error")
err := &Err{Op: "test", Msg: "wrapped", Err: underlying}
@ -52,28 +56,50 @@ func TestErr_Unwrap_Good(t *testing.T) {
assert.True(t, errors.Is(err, underlying))
}
// --- Error Creation Function Tests ---
func TestErrors_ErrUnwrap_Bad(t *testing.T) {
// No underlying error — Unwrap returns nil
err := &Err{Op: "op", Msg: "no cause"}
assert.Nil(t, errors.Unwrap(err))
}
func TestE_Good(t *testing.T) {
func TestErrors_ErrUnwrap_Ugly(t *testing.T) {
// Deeply nested — errors.Is still traverses the chain
root := errors.New("root")
level1 := &Err{Op: "l1", Msg: "level1", Err: root}
level2 := &Err{Op: "l2", Msg: "level2", Err: level1}
assert.True(t, errors.Is(level2, root))
}
// --- E ---
func TestErrors_E_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)
var typedError *Err
assert.True(t, errors.As(err, &typedError))
assert.Equal(t, "op.Name", typedError.Op)
assert.Equal(t, "something failed", typedError.Msg)
assert.Equal(t, underlying, typedError.Err)
}
func TestE_Good_NilError(t *testing.T) {
// E creates an error even with nil underlying - useful for errors without causes
func TestErrors_E_Bad(t *testing.T) {
// E with nil underlying error still creates an error
err := E("op.Name", "message", nil)
assert.NotNil(t, err)
assert.Equal(t, "op.Name: message", err.Error())
}
func TestWrap_Good(t *testing.T) {
func TestErrors_E_Ugly(t *testing.T) {
// E with empty op produces no leading colon
err := E("", "bare message", nil)
assert.Equal(t, "bare message", err.Error())
}
// --- Wrap ---
func TestErrors_Wrap_Good(t *testing.T) {
underlying := errors.New("base")
err := Wrap(underlying, "handler.Process", "processing failed")
@ -83,11 +109,15 @@ func TestWrap_Good(t *testing.T) {
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")
func TestErrors_Wrap_Bad(t *testing.T) {
// Wrap nil returns nil
err := Wrap(nil, "op", "msg")
assert.Nil(t, err)
}
// Wrap it - should preserve the code
func TestErrors_Wrap_Ugly(t *testing.T) {
// Wrap preserves Code from the inner *Err
inner := WrapCode(errors.New("base"), "VALIDATION_ERROR", "inner.Op", "validation failed")
outer := Wrap(inner, "outer.Op", "outer context")
assert.NotNil(t, outer)
@ -95,69 +125,135 @@ func TestWrap_PreservesCode_Good(t *testing.T) {
assert.Contains(t, outer.Error(), "[VALIDATION_ERROR]")
}
func TestWrap_NilError_Good(t *testing.T) {
err := Wrap(nil, "op", "msg")
assert.Nil(t, err)
}
// --- WrapCode ---
func TestWrapCode_Good(t *testing.T) {
func TestErrors_WrapCode_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)
var typedError *Err
assert.True(t, errors.As(err, &typedError))
assert.Equal(t, "INVALID_INPUT", typedError.Code)
assert.Equal(t, "api.Validate", typedError.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
func TestErrors_WrapCode_Bad(t *testing.T) {
// 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")
func TestErrors_WrapCode_Ugly(t *testing.T) {
// nil error AND empty code — only then returns nil
err := WrapCode(nil, "", "op", "msg")
assert.Nil(t, err)
}
func TestNewCode_Good(t *testing.T) {
// --- NewCode ---
func TestErrors_NewCode_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)
var typedError *Err
assert.True(t, errors.As(err, &typedError))
assert.Equal(t, "NOT_FOUND", typedError.Code)
assert.Equal(t, "resource not found", typedError.Msg)
assert.Nil(t, typedError.Err)
}
// --- Standard Library Wrapper Tests ---
func TestErrors_NewCode_Bad(t *testing.T) {
// Empty code is preserved as-is
err := NewCode("", "no code error")
assert.NotNil(t, err)
assert.Equal(t, "no code error", err.Error())
}
func TestIs_Good(t *testing.T) {
func TestErrors_NewCode_Ugly(t *testing.T) {
// NewCode result can be used as a sentinel value
sentinel := NewCode("SENTINEL", "sentinel error")
wrapped := Wrap(sentinel, "caller.Op", "something went wrong")
assert.True(t, Is(wrapped, sentinel))
}
// --- Is ---
func TestErrors_Is_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) {
func TestErrors_Is_Bad(t *testing.T) {
// Different errors are not equal
assert.False(t, Is(errors.New("a"), errors.New("b")))
}
func TestErrors_Is_Ugly(t *testing.T) {
// nil target
assert.False(t, Is(errors.New("something"), nil))
// nil err
assert.False(t, Is(nil, errors.New("something")))
// both nil
assert.True(t, Is(nil, nil))
}
// --- As ---
func TestErrors_As_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)
var typedError *Err
assert.True(t, As(err, &typedError))
assert.Equal(t, "test.Op", typedError.Op)
}
func TestNewError_Good(t *testing.T) {
func TestErrors_As_Bad(t *testing.T) {
// As returns false for non-matching types
err := errors.New("plain")
var typedError *Err
assert.False(t, As(err, &typedError))
}
func TestErrors_As_Ugly(t *testing.T) {
// As traverses the chain to find *Err
plain := errors.New("base")
wrapped := Wrap(plain, "op", "msg")
doubleWrapped := fmt.Errorf("fmt wrapper: %w", wrapped)
var typedError *Err
assert.True(t, As(doubleWrapped, &typedError))
assert.Equal(t, "op", typedError.Op)
}
// --- NewError ---
func TestErrors_NewError_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) {
func TestErrors_NewError_Bad(t *testing.T) {
// Two NewError calls with same text are distinct values
a := NewError("same text")
b := NewError("same text")
assert.False(t, Is(a, b), "two NewError values with same text must not match via Is")
}
func TestErrors_NewError_Ugly(t *testing.T) {
// Empty text produces an error with empty message
err := NewError("")
assert.NotNil(t, err)
assert.Equal(t, "", err.Error())
}
// --- Join ---
func TestErrors_Join_Good(t *testing.T) {
err1 := errors.New("error 1")
err2 := errors.New("error 2")
joined := Join(err1, err2)
@ -166,52 +262,78 @@ func TestJoin_Good(t *testing.T) {
assert.True(t, errors.Is(joined, err2))
}
// --- Helper Function Tests ---
func TestErrors_Join_Bad(t *testing.T) {
// All nil — returns nil
assert.Nil(t, Join(nil, nil))
}
func TestOp_Good(t *testing.T) {
func TestErrors_Join_Ugly(t *testing.T) {
// Mix of nil and non-nil — non-nil are preserved
err := errors.New("only error")
joined := Join(nil, err, nil)
assert.True(t, errors.Is(joined, err))
}
// --- Op ---
func TestErrors_Op_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) {
func TestErrors_Op_Bad(t *testing.T) {
// Plain error has no op
err := errors.New("plain error")
assert.Equal(t, "", Op(err))
}
func TestErrCode_Good(t *testing.T) {
func TestErrors_Op_Ugly(t *testing.T) {
// Outer op is returned, not inner
inner := E("inner.Op", "inner", nil)
outer := Wrap(inner, "outer.Op", "outer")
assert.Equal(t, "outer.Op", Op(outer))
}
// --- ErrCode ---
func TestErrors_ErrCode_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) {
func TestErrors_ErrCode_Bad(t *testing.T) {
// No code on a plain *Err
err := E("op", "msg", errors.New("base"))
assert.Equal(t, "", ErrCode(err))
}
func TestErrCode_Good_PlainError(t *testing.T) {
err := errors.New("plain error")
assert.Equal(t, "", ErrCode(err))
}
func TestErrCode_Good_Nil(t *testing.T) {
func TestErrors_ErrCode_Ugly(t *testing.T) {
// Nil and plain errors both return empty string
assert.Equal(t, "", ErrCode(nil))
assert.Equal(t, "", ErrCode(errors.New("plain")))
}
func TestMessage_Good(t *testing.T) {
// --- Message ---
func TestErrors_Message_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) {
func TestErrors_Message_Bad(t *testing.T) {
// Plain error — falls back to Error() string
err := errors.New("plain message")
assert.Equal(t, "plain message", Message(err))
}
func TestMessage_Good_Nil(t *testing.T) {
func TestErrors_Message_Ugly(t *testing.T) {
// Nil returns empty string
assert.Equal(t, "", Message(nil))
}
func TestRoot_Good(t *testing.T) {
// --- Root ---
func TestErrors_Root_Good(t *testing.T) {
root := errors.New("root cause")
level1 := Wrap(root, "level1", "wrapped once")
level2 := Wrap(level1, "level2", "wrapped twice")
@ -219,19 +341,88 @@ func TestRoot_Good(t *testing.T) {
assert.Equal(t, root, Root(level2))
}
func TestRoot_Good_SingleError(t *testing.T) {
func TestErrors_Root_Bad(t *testing.T) {
// Single unwrapped error returns itself
err := errors.New("single")
assert.Equal(t, err, Root(err))
}
func TestRoot_Good_Nil(t *testing.T) {
func TestErrors_Root_Ugly(t *testing.T) {
// Nil returns nil
assert.Nil(t, Root(nil))
}
// --- Log-and-Return Helper Tests ---
// --- StackTrace / FormatStackTrace ---
func TestLogError_Good(t *testing.T) {
// Capture log output
func TestErrors_StackTrace_Good(t *testing.T) {
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)
formatted := FormatStackTrace(err)
assert.Equal(t, "op3 -> op2 -> op1", formatted)
}
func TestErrors_StackTrace_Bad(t *testing.T) {
// Plain error has no ops in the stack
err := errors.New("plain error")
assert.Empty(t, StackTrace(err))
assert.Empty(t, FormatStackTrace(err))
}
func TestErrors_StackTrace_Ugly(t *testing.T) {
// Nil and *Err with no Op both yield empty stack
assert.Empty(t, StackTrace(nil))
assert.Empty(t, FormatStackTrace(nil))
assert.Empty(t, StackTrace(&Err{Msg: "no op"}))
// Mixed chain: fmt.Errorf wrapper in the middle — ops on both sides still appear
inner := E("inner", "msg", nil)
wrapped := fmt.Errorf("fmt wrapper: %w", inner)
outer := Wrap(wrapped, "outer", "msg")
stack := StackTrace(outer)
assert.Equal(t, []string{"outer", "inner"}, stack)
}
// --- AllOps ---
func TestErrors_AllOps_Good(t *testing.T) {
err := E("op1", "msg1", nil)
err = Wrap(err, "op2", "msg2")
var ops []string
for op := range AllOps(err) {
ops = append(ops, op)
}
assert.Equal(t, []string{"op2", "op1"}, ops)
}
func TestErrors_AllOps_Bad(t *testing.T) {
// Plain error yields no ops
err := errors.New("plain")
var ops []string
for op := range AllOps(err) {
ops = append(ops, op)
}
assert.Empty(t, ops)
}
func TestErrors_AllOps_Ugly(t *testing.T) {
// Nil error — iterator yields nothing, no panic
var ops []string
for op := range AllOps(nil) {
ops = append(ops, op)
}
assert.Empty(t, ops)
}
// --- LogError ---
func TestErrors_LogError_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
@ -240,20 +431,19 @@ func TestLogError_Good(t *testing.T) {
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) {
func TestErrors_LogError_Bad(t *testing.T) {
// nil error — returns nil, no log output
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
@ -261,10 +451,27 @@ func TestLogError_Good_NilError(t *testing.T) {
err := LogError(nil, "op", "msg")
assert.Nil(t, err)
assert.Empty(t, buf.String()) // No log output for nil error
assert.Empty(t, buf.String())
}
func TestLogWarn_Good(t *testing.T) {
func TestErrors_LogError_Ugly(t *testing.T) {
// LogError on an already-wrapped *Err — error chain preserved
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
defer SetDefault(New(Options{Level: LevelInfo}))
root := errors.New("root")
inner := E("inner.Op", "inner failed", root)
err := LogError(inner, "outer.Op", "outer context")
assert.True(t, errors.Is(err, root))
assert.Contains(t, buf.String(), "[ERR]")
}
// --- LogWarn ---
func TestErrors_LogWarn_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
@ -275,13 +482,12 @@ func TestLogWarn_Good(t *testing.T) {
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")
assert.Contains(t, buf.String(), "[WRN]")
assert.Contains(t, buf.String(), "falling back to db")
}
func TestLogWarn_Good_NilError(t *testing.T) {
func TestErrors_LogWarn_Bad(t *testing.T) {
// nil error — returns nil, no log output
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
@ -292,14 +498,28 @@ func TestLogWarn_Good_NilError(t *testing.T) {
assert.Empty(t, buf.String())
}
func TestMust_Good_NoError(t *testing.T) {
// Should not panic when error is nil
func TestErrors_LogWarn_Ugly(t *testing.T) {
// LogWarn at LevelError — [WRN] is suppressed since Warn < Error threshold
var buf bytes.Buffer
logger := New(Options{Level: LevelError, Output: &buf})
SetDefault(logger)
defer SetDefault(New(Options{Level: LevelInfo}))
LogWarn(errors.New("warn level"), "op", "msg")
assert.Empty(t, buf.String(), "expected warn suppressed at LevelError")
}
// --- Must ---
func TestErrors_Must_Good(t *testing.T) {
// nil error — no panic
assert.NotPanics(t, func() {
Must(nil, "test", "should not panic")
})
}
func TestMust_Ugly_Panics(t *testing.T) {
func TestErrors_Must_Bad(t *testing.T) {
// Non-nil error — panics with wrapped error
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
@ -309,47 +529,21 @@ func TestMust_Ugly_Panics(t *testing.T) {
Must(errors.New("fatal error"), "startup", "initialization failed")
})
// Verify error was logged before panic
output := buf.String()
assert.True(t, core.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")
func TestErrors_Must_Ugly(t *testing.T) {
// Panic value is a wrapped *Err, not the raw error
var panicValue any
func() {
defer func() { panicValue = recover() }()
Must(errors.New("root cause"), "init.Op", "startup failed")
}()
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_Good(t *testing.T) {
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)
assert.NotNil(t, panicValue)
panicErr, ok := panicValue.(error)
assert.True(t, ok, "panic value must be an error")
assert.Contains(t, panicErr.Error(), "init.Op")
assert.Contains(t, panicErr.Error(), "startup failed")
}

60
log.go
View file

@ -109,6 +109,9 @@ type Options struct {
var RotationWriterFactory func(RotationOptions) goio.WriteCloser
// New creates a new Logger with the given options.
//
// logger := log.New(log.Options{Level: log.LevelInfo, Output: os.Stderr})
// logger := log.New(log.Options{Level: log.LevelDebug, RedactKeys: []string{"password"}})
func New(opts Options) *Logger {
output := opts.Output
if opts.Rotation != nil && opts.Rotation.Filename != "" && RotationWriterFactory != nil {
@ -185,33 +188,33 @@ 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 {
originalLength := len(keyvals)
for i := 0; i < originalLength; i += 2 {
if i+1 < originalLength {
if err, ok := keyvals[i+1].(error); ok {
if op := Op(err); op != "" {
// Check if op is already in keyvals
hasOp := false
hasOperationKey := false
for j := 0; j < len(keyvals); j += 2 {
if k, ok := keyvals[j].(string); ok && k == "op" {
hasOp = true
hasOperationKey = true
break
}
}
if !hasOp {
if !hasOperationKey {
keyvals = append(keyvals, "op", op)
}
}
if stack := FormatStackTrace(err); stack != "" {
// Check if stack is already in keyvals
hasStack := false
hasStackKey := false
for j := 0; j < len(keyvals); j += 2 {
if k, ok := keyvals[j].(string); ok && k == "stack" {
hasStack = true
hasStackKey = true
break
}
}
if !hasStack {
if !hasStackKey {
keyvals = append(keyvals, "stack", stack)
}
}
@ -220,12 +223,12 @@ func (l *Logger) log(level Level, prefix, msg string, keyvals ...any) {
}
// Format key-value pairs
var kvStr string
var keyValueString string
if len(keyvals) > 0 {
kvStr = " "
keyValueString = " "
for i := 0; i < len(keyvals); i += 2 {
if i > 0 {
kvStr += " "
keyValueString += " "
}
key := keyvals[i]
var val any
@ -241,14 +244,14 @@ func (l *Logger) log(level Level, prefix, msg string, keyvals ...any) {
// Secure formatting to prevent log injection
if s, ok := val.(string); ok {
kvStr += core.Sprintf("%v=%q", key, s)
keyValueString += core.Sprintf("%v=%q", key, s)
} else {
kvStr += core.Sprintf("%v=%v", key, val)
keyValueString += core.Sprintf("%v=%v", key, val)
}
}
}
_, _ = fmt.Fprintf(output, "%s %s %s%s\n", timestamp, prefix, msg, kvStr)
_, _ = fmt.Fprintf(output, "%s %s %s%s\n", timestamp, prefix, msg, keyValueString)
}
// Debug logs a debug message with optional key-value pairs.
@ -299,7 +302,8 @@ func (l *Logger) Security(msg string, keyvals ...any) {
}
// Username returns the current system username.
// It uses os/user for reliability and falls back to environment variables.
//
// owner := log.Username() // e.g. "deploy", "www-data"
func Username() string {
if u, err := user.Current(); err == nil {
return u.Username
@ -330,36 +334,50 @@ func SetDefault(l *Logger) {
}
// SetLevel sets the default logger's level.
//
// log.SetLevel(log.LevelDebug)
func SetLevel(level Level) {
defaultLogger.SetLevel(level)
}
// SetRedactKeys sets the default logger's redaction keys.
//
// log.SetRedactKeys("password", "token", "api_key")
func SetRedactKeys(keys ...string) {
defaultLogger.SetRedactKeys(keys...)
}
// Debug logs to the default logger.
// Debug logs a debug message to the default logger.
//
// log.Debug("cache lookup", "key", "user:42", "hit", false)
func Debug(msg string, keyvals ...any) {
defaultLogger.Debug(msg, keyvals...)
}
// Info logs to the default logger.
// Info logs an informational message to the default logger.
//
// log.Info("server started", "port", 8080)
func Info(msg string, keyvals ...any) {
defaultLogger.Info(msg, keyvals...)
}
// Warn logs to the default logger.
// Warn logs a warning message to the default logger.
//
// log.Warn("retrying", "attempt", 2, "max", 3)
func Warn(msg string, keyvals ...any) {
defaultLogger.Warn(msg, keyvals...)
}
// Error logs to the default logger.
// Error logs an error message to the default logger.
//
// log.Error("request failed", "err", err, "path", r.URL.Path)
func Error(msg string, keyvals ...any) {
defaultLogger.Error(msg, keyvals...)
}
// Security logs to the default logger.
// Security logs a security event to the default logger.
//
// log.Security("login failed", "ip", remoteAddr, "user", username)
func Security(msg string, keyvals ...any) {
defaultLogger.Security(msg, keyvals...)
}

756
log_test.go
View file

@ -16,61 +16,348 @@ func substringCount(s, substr string) int {
return len(core.Split(s, substr)) - 1
}
func TestLogger_Levels(t *testing.T) {
tests := []struct {
name string
// --- Level.String ---
func TestLog_LevelString_Good(t *testing.T) {
cases := []struct {
level Level
logFunc func(*Logger, string, ...any)
expected bool
expected string
}{
{"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},
{LevelQuiet, "quiet"},
{LevelError, "error"},
{LevelWarn, "warn"},
{LevelInfo, "info"},
{LevelDebug, "debug"},
}
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)
for _, tc := range cases {
t.Run(tc.expected, func(t *testing.T) {
if got := tc.level.String(); got != tc.expected {
t.Errorf("expected %q, got %q", tc.expected, got)
}
})
}
}
func TestLogger_KeyValues(t *testing.T) {
var buf bytes.Buffer
l := New(Options{Level: LevelDebug, Output: &buf})
func TestLog_LevelString_Bad(t *testing.T) {
// Invalid level value returns "unknown"
if got := Level(99).String(); got != "unknown" {
t.Errorf("expected \"unknown\" for out-of-range level, got %q", got)
}
}
l.Info("test message", "key1", "value1", "key2", 42)
func TestLog_LevelString_Ugly(t *testing.T) {
// Negative level value also returns "unknown"
if got := Level(-1).String(); got != "unknown" {
t.Errorf("expected \"unknown\" for negative level, got %q", got)
}
}
// --- New ---
func TestLog_New_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf})
if logger == nil {
t.Fatal("expected non-nil logger")
}
if logger.Level() != LevelInfo {
t.Errorf("expected LevelInfo, got %v", logger.Level())
}
}
func TestLog_New_Bad(t *testing.T) {
// No output specified — should default to stderr (not nil or panic)
logger := New(Options{Level: LevelInfo})
if logger.output == nil {
t.Error("expected non-nil output when no Output specified")
}
}
func TestLog_New_Ugly(t *testing.T) {
// Rotation factory set but no filename — should fall back to Output
var buf bytes.Buffer
original := RotationWriterFactory
defer func() { RotationWriterFactory = original }()
called := false
RotationWriterFactory = func(opts RotationOptions) goio.WriteCloser {
called = true
return nopWriteCloser{&buf}
}
// Rotation with empty Filename — factory must NOT be called
logger := New(Options{
Level: LevelInfo,
Output: &buf,
Rotation: &RotationOptions{Filename: ""},
})
if called {
t.Error("expected rotation factory NOT called when Filename is empty")
}
if logger.output == nil {
t.Error("expected non-nil output")
}
}
// --- New with RotationWriterFactory ---
func TestLog_NewRotationFactory_Good(t *testing.T) {
var buf bytes.Buffer
original := RotationWriterFactory
defer func() { RotationWriterFactory = original }()
RotationWriterFactory = func(opts RotationOptions) goio.WriteCloser {
return nopWriteCloser{&buf}
}
logger := New(Options{
Level: LevelInfo,
Rotation: &RotationOptions{Filename: "test.log"},
})
logger.Info("rotated message")
if buf.Len() == 0 {
t.Error("expected output via rotation writer")
}
}
func TestLog_NewRotationFactory_Bad(t *testing.T) {
// Rotation requested but RotationWriterFactory is nil — should fall back to Output
var buf bytes.Buffer
original := RotationWriterFactory
defer func() { RotationWriterFactory = original }()
RotationWriterFactory = nil
logger := New(Options{
Level: LevelInfo,
Output: &buf,
Rotation: &RotationOptions{Filename: "test.log"},
})
logger.Info("fallback message")
if buf.Len() == 0 {
t.Error("expected fallback to Output when RotationWriterFactory is nil")
}
}
func TestLog_NewRotationFactory_Ugly(t *testing.T) {
// Both Output and Rotation provided — Rotation wins when factory is set
var rotationBuf, outputBuf bytes.Buffer
original := RotationWriterFactory
defer func() { RotationWriterFactory = original }()
RotationWriterFactory = func(opts RotationOptions) goio.WriteCloser {
return nopWriteCloser{&rotationBuf}
}
logger := New(Options{
Level: LevelInfo,
Output: &outputBuf,
Rotation: &RotationOptions{Filename: "test.log"},
})
logger.Info("which writer?")
if rotationBuf.Len() == 0 {
t.Error("expected rotation writer to be used")
}
if outputBuf.Len() != 0 {
t.Error("expected Output to be ignored when Rotation is set")
}
}
// --- SetLevel / Level ---
func TestLog_SetLevel_Good(t *testing.T) {
logger := New(Options{Level: LevelInfo})
if logger.Level() != LevelInfo {
t.Error("expected initial level to be Info")
}
logger.SetLevel(LevelDebug)
if logger.Level() != LevelDebug {
t.Error("expected level to be Debug after SetLevel")
}
}
func TestLog_SetLevel_Bad(t *testing.T) {
// SetLevel to Quiet suppresses all output
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
logger.SetLevel(LevelQuiet)
logger.Error("should be suppressed")
if buf.Len() != 0 {
t.Error("expected no output at LevelQuiet")
}
}
func TestLog_SetLevel_Ugly(t *testing.T) {
// SetLevel with an out-of-range value — should not panic, level stored as-is
logger := New(Options{Level: LevelInfo})
logger.SetLevel(Level(99))
if logger.Level() != Level(99) {
t.Errorf("expected level 99, got %v", logger.Level())
}
}
// --- SetOutput ---
func TestLog_SetOutput_Good(t *testing.T) {
var buf1, buf2 bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf1})
logger.Info("first")
if buf1.Len() == 0 {
t.Error("expected output in first buffer")
}
logger.SetOutput(&buf2)
logger.Info("second")
if buf2.Len() == 0 {
t.Error("expected output in second buffer after SetOutput")
}
}
func TestLog_SetOutput_Bad(t *testing.T) {
// Output switched mid-stream — first buffer must not receive later messages
var buf1, buf2 bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf1})
logger.Info("first")
first1Len := buf1.Len()
logger.SetOutput(&buf2)
logger.Info("second")
if buf1.Len() != first1Len {
t.Error("first buffer must not receive messages after SetOutput")
}
}
func TestLog_SetOutput_Ugly(t *testing.T) {
// SetOutput to goio.Discard — no panic, just silently discarded
logger := New(Options{Level: LevelInfo})
logger.SetOutput(goio.Discard)
logger.Info("discarded message") // must not panic
}
// --- SetRedactKeys ---
func TestLog_SetRedactKeys_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf})
// No redaction initially
logger.Info("msg", "secret", "visible")
if !core.Contains(buf.String(), "secret=\"visible\"") {
t.Errorf("expected visible value, got %q", buf.String())
}
buf.Reset()
logger.SetRedactKeys("secret")
logger.Info("msg", "secret", "hidden")
if !core.Contains(buf.String(), "secret=\"[REDACTED]\"") {
t.Errorf("expected redacted value, got %q", buf.String())
}
}
func TestLog_SetRedactKeys_Bad(t *testing.T) {
// Calling SetRedactKeys with empty list clears all redaction
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf, RedactKeys: []string{"token"}})
logger.SetRedactKeys() // clear all
logger.Info("msg", "token", "visible-now")
if !core.Contains(buf.String(), "token=\"visible-now\"") {
t.Errorf("expected token to be visible after clearing redact keys, got %q", buf.String())
}
}
func TestLog_SetRedactKeys_Ugly(t *testing.T) {
// Redact key that doesn't appear in log — no effect, no panic
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf})
logger.SetRedactKeys("nonexistent_key")
logger.Info("msg", "other", "value")
output := buf.String()
if !core.Contains(output, "other=\"value\"") {
t.Errorf("expected other to appear normally, got %q", output)
}
}
// --- Debug / Info / Warn / Error / Security ---
func TestLog_Levels_Good(t *testing.T) {
cases := []struct {
name string
level Level
logFunc func(*Logger, string, ...any)
expect bool
}{
{"debug at debug", LevelDebug, (*Logger).Debug, true},
{"info at info", LevelInfo, (*Logger).Info, true},
{"warn at warn", LevelWarn, (*Logger).Warn, true},
{"error at error", LevelError, (*Logger).Error, true},
{"security at error", LevelError, (*Logger).Security, true},
}
for _, tc := range cases {
t.Run(tc.name, func(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: tc.level, Output: &buf})
tc.logFunc(logger, "test message")
if buf.Len() == 0 {
t.Errorf("expected output for %s", tc.name)
}
})
}
}
func TestLog_Levels_Bad(t *testing.T) {
// Messages below the active level are suppressed
cases := []struct {
name string
level Level
logFunc func(*Logger, string, ...any)
}{
{"debug at info", LevelInfo, (*Logger).Debug},
{"debug at warn", LevelWarn, (*Logger).Debug},
{"info at warn", LevelWarn, (*Logger).Info},
{"debug at error", LevelError, (*Logger).Debug},
{"info at error", LevelError, (*Logger).Info},
{"warn at error", LevelError, (*Logger).Warn},
{"debug at quiet", LevelQuiet, (*Logger).Debug},
{"info at quiet", LevelQuiet, (*Logger).Info},
{"warn at quiet", LevelQuiet, (*Logger).Warn},
{"error at quiet", LevelQuiet, (*Logger).Error},
}
for _, tc := range cases {
t.Run(tc.name, func(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: tc.level, Output: &buf})
tc.logFunc(logger, "test message")
if buf.Len() != 0 {
t.Errorf("expected no output for %s, got %q", tc.name, buf.String())
}
})
}
}
func TestLog_Levels_Ugly(t *testing.T) {
// Security always uses LevelError threshold — even at LevelWarn it should appear
var buf bytes.Buffer
logger := New(Options{Level: LevelWarn, Output: &buf})
logger.Security("intrusion attempt", "ip", "10.0.0.1")
if buf.Len() == 0 {
t.Error("expected security log output at LevelWarn (security uses LevelError threshold)")
}
if !core.Contains(buf.String(), "[SEC]") {
t.Errorf("expected [SEC] prefix, got %q", buf.String())
}
}
// --- Key-value formatting ---
func TestLog_KeyValues_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
logger.Info("test message", "key1", "value1", "key2", 42)
output := buf.String()
if !core.Contains(output, "test message") {
@ -84,33 +371,76 @@ func TestLogger_KeyValues(t *testing.T) {
}
}
func TestLogger_ErrorContext(t *testing.T) {
func TestLog_KeyValues_Bad(t *testing.T) {
// Odd number of keyvals — last key has no value, rendered as <nil>
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 !core.Contains(got, "op=\"outer.Op\"") {
t.Errorf("expected output to contain op=\"outer.Op\", got %q", got)
}
if !core.Contains(got, "stack=\"outer.Op -> test.Op\"") {
t.Errorf("expected output to contain stack=\"outer.Op -> test.Op\", got %q", got)
logger := New(Options{Level: LevelInfo, Output: &buf})
logger.Info("msg", "lonely_key")
output := buf.String()
if !core.Contains(output, "lonely_key=<nil>") {
t.Errorf("expected lonely_key=<nil>, got %q", output)
}
}
func TestLogger_Redaction(t *testing.T) {
func TestLog_KeyValues_Ugly(t *testing.T) {
// No keyvals at all — message alone, no trailing space
var buf bytes.Buffer
l := New(Options{
logger := New(Options{Level: LevelInfo, Output: &buf})
logger.Info("just a message")
output := buf.String()
if !core.Contains(output, "just a message") {
t.Errorf("expected message in output, got %q", output)
}
}
// --- Log injection prevention ---
func TestLog_InjectionPrevention_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf})
logger.Info("message", "key", "value\n[SEC] injected message")
output := buf.String()
if !core.Contains(output, "key=\"value\\n[SEC] injected message\"") {
t.Errorf("expected escaped newline, got %q", output)
}
}
func TestLog_InjectionPrevention_Bad(t *testing.T) {
// Embedded carriage return also escaped
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf})
logger.Info("message", "key", "value\r\ninjected")
output := buf.String()
// The value must be quoted (escaped), so it remains one log line
lines := core.Split(core.Trim(output), "\n")
if len(lines) != 1 {
t.Errorf("expected 1 line after injection attempt, got %d: %q", len(lines), output)
}
}
func TestLog_InjectionPrevention_Ugly(t *testing.T) {
// Tab and null bytes in value — must be quoted, no panic
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf})
logger.Info("message", "key", "val\t\x00ue")
if buf.Len() == 0 {
t.Error("expected output even with unusual characters in value")
}
}
// --- Redaction ---
func TestLog_Redaction_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{
Level: LevelInfo,
Output: &buf,
RedactKeys: []string{"password", "token"},
})
l.Info("login", "user", "admin", "password", "secret123", "token", "abc-123")
logger.Info("login", "user", "admin", "password", "secret123", "token", "abc-123")
output := buf.String()
if !core.Contains(output, "user=\"admin\"") {
@ -124,63 +454,92 @@ func TestLogger_Redaction(t *testing.T) {
}
}
func TestLogger_InjectionPrevention(t *testing.T) {
func TestLog_Redaction_Bad(t *testing.T) {
// Non-string value under a redacted key is also masked
var buf bytes.Buffer
l := New(Options{Level: LevelInfo, Output: &buf})
l.Info("message", "key", "value\n[SEC] injected message")
logger := New(Options{
Level: LevelInfo,
Output: &buf,
RedactKeys: []string{"pin"},
})
logger.Info("auth", "pin", 1234)
if !core.Contains(buf.String(), "pin=\"[REDACTED]\"") {
t.Errorf("expected numeric pin to be redacted, got %q", buf.String())
}
}
func TestLog_Redaction_Ugly(t *testing.T) {
// Redact key that appears multiple times — all occurrences masked
var buf bytes.Buffer
logger := New(Options{
Level: LevelInfo,
Output: &buf,
RedactKeys: []string{"x"},
})
logger.Info("msg", "x", "first", "y", "plain", "x", "second")
output := buf.String()
if !core.Contains(output, "key=\"value\\n[SEC] injected message\"") {
t.Errorf("expected escaped newline, got %q", output)
}
// Ensure it's still a single line (excluding trailing newline)
lines := core.Split(core.Trim(output), "\n")
if len(lines) != 1 {
t.Errorf("expected 1 line, got %d", len(lines))
count := substringCount(output, "[REDACTED]")
if count != 2 {
t.Errorf("expected 2 redactions, got %d in %q", count, output)
}
}
func TestLogger_SetLevel(t *testing.T) {
l := New(Options{Level: LevelInfo})
// --- Error context auto-extraction ---
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) {
func TestLog_ErrorContext_Good(t *testing.T) {
var buf bytes.Buffer
l := New(Options{Level: LevelError, Output: &buf})
logger := New(Options{Output: &buf, Level: LevelInfo})
l.Security("unauthorized access", "user", "admin")
err := E("test.Op", "failed", NewError("root cause"))
err = Wrap(err, "outer.Op", "outer failed")
logger.Error("something failed", "err", err)
got := buf.String()
if !core.Contains(got, "op=\"outer.Op\"") {
t.Errorf("expected output to contain op=\"outer.Op\", got %q", got)
}
if !core.Contains(got, "stack=\"outer.Op -> test.Op\"") {
t.Errorf("expected output to contain stack=\"outer.Op -> test.Op\", got %q", got)
}
}
func TestLog_ErrorContext_Bad(t *testing.T) {
// Plain error (not *Err) — no op or stack injected
var buf bytes.Buffer
logger := New(Options{Output: &buf, Level: LevelInfo})
logger.Error("plain error", "err", NewError("plain"))
output := buf.String()
if core.Contains(output, "op=") {
t.Errorf("expected no op= for plain error, got %q", output)
}
if core.Contains(output, "stack=") {
t.Errorf("expected no stack= for plain error, got %q", output)
}
}
func TestLog_ErrorContext_Ugly(t *testing.T) {
// Caller provides op explicitly — must not duplicate
var buf bytes.Buffer
logger := New(Options{Level: LevelInfo, Output: &buf})
err := E("inner.Op", "failed", NewError("cause"))
logger.Error("failed", "op", "explicit.Op", "err", err)
output := buf.String()
if substringCount(output, "op=") != 1 {
t.Errorf("expected exactly one op= in output, got %q", output)
}
if !core.Contains(output, "op=\"explicit.Op\"") {
t.Errorf("expected explicit op, got %q", output)
}
}
// --- Security ---
func TestLog_Security_Good(t *testing.T) {
var buf bytes.Buffer
logger := New(Options{Level: LevelError, Output: &buf})
logger.Security("unauthorized access", "user", "admin")
output := buf.String()
if !core.Contains(output, "[SEC]") {
@ -194,135 +553,66 @@ func TestLogger_Security(t *testing.T) {
}
}
func TestLogger_SetOutput_Good(t *testing.T) {
var buf1, buf2 bytes.Buffer
l := New(Options{Level: LevelInfo, Output: &buf1})
l.Info("first")
if buf1.Len() == 0 {
t.Error("expected output in first buffer")
}
l.SetOutput(&buf2)
l.Info("second")
if buf2.Len() == 0 {
t.Error("expected output in second buffer after SetOutput")
}
}
func TestLogger_SetRedactKeys_Good(t *testing.T) {
func TestLog_Security_Bad(t *testing.T) {
// Security is suppressed at LevelQuiet
var buf bytes.Buffer
l := New(Options{Level: LevelInfo, Output: &buf})
// No redaction initially
l.Info("msg", "secret", "visible")
if !core.Contains(buf.String(), "secret=\"visible\"") {
t.Errorf("expected visible value, got %q", buf.String())
}
buf.Reset()
l.SetRedactKeys("secret")
l.Info("msg", "secret", "hidden")
if !core.Contains(buf.String(), "secret=\"[REDACTED]\"") {
t.Errorf("expected redacted value, got %q", buf.String())
logger := New(Options{Level: LevelQuiet, Output: &buf})
logger.Security("suppressed", "ip", "1.2.3.4")
if buf.Len() != 0 {
t.Error("expected security log suppressed at LevelQuiet")
}
}
func TestLogger_OddKeyvals_Good(t *testing.T) {
func TestLog_Security_Ugly(t *testing.T) {
// Security message with no key-value pairs — no panic, correct prefix
var buf bytes.Buffer
l := New(Options{Level: LevelInfo, Output: &buf})
// Odd number of keyvals — last key should have no value
l.Info("msg", "lonely_key")
output := buf.String()
if !core.Contains(output, "lonely_key=<nil>") {
t.Errorf("expected lonely_key=<nil>, got %q", output)
logger := New(Options{Level: LevelInfo, Output: &buf})
logger.Security("bare security event")
if !core.Contains(buf.String(), "[SEC]") {
t.Errorf("expected [SEC] prefix even with no kvs, got %q", buf.String())
}
}
func TestLogger_ExistingOpNotDuplicated_Good(t *testing.T) {
var buf bytes.Buffer
l := New(Options{Level: LevelInfo, Output: &buf})
// --- Username ---
err := E("inner.Op", "failed", NewError("cause"))
// Pass op explicitly — should not duplicate
l.Error("failed", "op", "explicit.Op", "err", err)
output := buf.String()
if substringCount(output, "op=") != 1 {
t.Errorf("expected exactly one op= in output, got %q", output)
}
if !core.Contains(output, "op=\"explicit.Op\"") {
t.Errorf("expected explicit op, got %q", output)
}
}
func TestLogger_ExistingStackNotDuplicated_Good(t *testing.T) {
var buf bytes.Buffer
l := New(Options{Level: LevelInfo, Output: &buf})
err := E("inner.Op", "failed", NewError("cause"))
// Pass stack explicitly — should not duplicate
l.Error("failed", "stack", "custom.Stack", "err", err)
output := buf.String()
if substringCount(output, "stack=") != 1 {
t.Errorf("expected exactly one stack= in output, got %q", output)
}
if !core.Contains(output, "stack=\"custom.Stack\"") {
t.Errorf("expected custom stack, got %q", output)
}
}
func TestNew_RotationFactory_Good(t *testing.T) {
var buf bytes.Buffer
// Set up a mock rotation writer factory
original := RotationWriterFactory
defer func() { RotationWriterFactory = original }()
RotationWriterFactory = func(opts RotationOptions) goio.WriteCloser {
return nopWriteCloser{&buf}
}
l := New(Options{
Level: LevelInfo,
Rotation: &RotationOptions{Filename: "test.log"},
})
l.Info("rotated message")
if buf.Len() == 0 {
t.Error("expected output via rotation writer")
}
}
func TestNew_DefaultOutput_Good(t *testing.T) {
// No output or rotation — should default to stderr (not nil)
l := New(Options{Level: LevelInfo})
if l.output == nil {
t.Error("expected non-nil output when no Output specified")
}
}
func TestUsername_Good(t *testing.T) {
func TestLog_Username_Good(t *testing.T) {
name := Username()
if name == "" {
t.Error("expected Username to return a non-empty string")
}
}
func TestDefault_Good(t *testing.T) {
func TestLog_Username_Bad(t *testing.T) {
// Username must not contain a newline (common mistake from raw /etc/passwd reads)
name := Username()
if core.Contains(name, "\n") {
t.Errorf("Username must not contain newline, got %q", name)
}
}
func TestLog_Username_Ugly(t *testing.T) {
// Username is idempotent — two calls return the same value
first := Username()
second := Username()
if first != second {
t.Errorf("Username not idempotent: %q vs %q", first, second)
}
}
// --- Default logger and package-level proxies ---
func TestLog_Default_Good(t *testing.T) {
if Default() == nil {
t.Error("expected default logger to exist")
}
// All package-level proxy functions
var buf bytes.Buffer
l := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(l)
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
defer SetDefault(New(Options{Level: LevelInfo}))
SetLevel(LevelDebug)
if l.Level() != LevelDebug {
if logger.Level() != LevelDebug {
t.Error("expected package-level SetLevel to work")
}
@ -341,3 +631,35 @@ func TestDefault_Good(t *testing.T) {
}
}
}
func TestLog_Default_Bad(t *testing.T) {
// SetDefault(nil) must not panic immediately — panics only on use
// Test that Default() returns the newly set logger
var buf bytes.Buffer
custom := New(Options{Level: LevelWarn, Output: &buf})
SetDefault(custom)
defer SetDefault(New(Options{Level: LevelInfo}))
if Default() != custom {
t.Error("expected Default() to return the custom logger after SetDefault")
}
}
func TestLog_Default_Ugly(t *testing.T) {
// Stack de-duplication via package-level proxy
var buf bytes.Buffer
logger := New(Options{Level: LevelDebug, Output: &buf})
SetDefault(logger)
defer SetDefault(New(Options{Level: LevelInfo}))
err := E("inner.Op", "failed", NewError("cause"))
Error("failed", "stack", "custom.Stack", "err", err)
output := buf.String()
if substringCount(output, "stack=") != 1 {
t.Errorf("expected exactly one stack= in output, got %q", output)
}
if !core.Contains(output, "stack=\"custom.Stack\"") {
t.Errorf("expected custom stack, got %q", output)
}
}