diff --git a/README.md b/README.md index b89b8e8..b76af18 100644 --- a/README.md +++ b/README.md @@ -34,6 +34,7 @@ package main import ( "fmt" "os" + "log/slog" "go.followtheprocess.codes/log" ) @@ -42,7 +43,11 @@ func main() { logger := log.New(os.Stderr) logger.Debug("Debug me") // By default this one won't show up, default log level is INFO - logger.Info("Some information here", "really", true) + logger.Info( + "Some information here", + // Yep! You use slog.Attrs for key value pairs, why reinvent the wheel? + slog.Bool("really", true), + ) logger.Warn("Uh oh!") logger.Error("Goodbye") } @@ -84,18 +89,24 @@ logger := log.New(os.Stderr, log.WithLevel(log.LevelDebug)) ### Key Value Pairs -`log` provides "semi structured" logs in that the message is free form text but you can attach arbitrary key value pairs to any of the log methods +`log` uses [slog.Attr] to provide "semi structured" logs. The message is free form text but you can attach arbitrary key, value pairs with any of the log methods ```go -logger.Info("Doing something", "cache", true, "duration", 30 * time.Second, "number", 42) +logger.Info( + "Doing something", + slog.Bool("cache", true), + slog.Duration("duration", 30 * time.Second), + slog.Int("number", 42), +) ``` You can also create a "sub logger" with persistent key value pairs applied to every message ```go -sub := logger.With("sub", true) +sub := logger.With(slog.Bool("sub", true)) -sub.Info("Hello from the sub logger", "subkey", "yes") // They can have their own per-method keys too! +// They can have their own per-method keys too! +sub.Info("Hello from the sub logger", slog.String("subkey", "yes")) ```

@@ -120,3 +131,5 @@ prefixed := logger.Prefixed("http")

demo

+ +[slog.Attr]: https://pkg.go.dev/log/slog#Attr diff --git a/docs/img/demo.gif b/docs/img/demo.gif index a5b2825..a88defd 100644 Binary files a/docs/img/demo.gif and b/docs/img/demo.gif differ diff --git a/docs/img/keys.gif b/docs/img/keys.gif index d9b02c4..5b49144 100644 Binary files a/docs/img/keys.gif and b/docs/img/keys.gif differ diff --git a/docs/img/prefix.gif b/docs/img/prefix.gif index 05a7efc..672a62b 100644 Binary files a/docs/img/prefix.gif and b/docs/img/prefix.gif differ diff --git a/examples/demo/main.go b/examples/demo/main.go index 9134b8d..83a00ef 100644 --- a/examples/demo/main.go +++ b/examples/demo/main.go @@ -1,6 +1,7 @@ package main import ( + "log/slog" "math/rand/v2" "os" "time" @@ -11,15 +12,23 @@ import ( func main() { logger := log.New(os.Stderr, log.WithLevel(log.LevelDebug)) - logger.Debug("Searing steak", "cook", "rare", "temp", "42°C", "time", 2*time.Minute) + logger.Debug( + "Searing steak", + slog.String("cook", "rare"), + slog.Int("temp", 42), + slog.Duration("time", 2*time.Minute), + ) sleep() - logger.Info("Choosing wine pairing", "choices", []string{"merlot", "malbec", "rioja"}) + logger.Info( + "Choosing wine pairing", + slog.Any("choices", []string{"merlot", "malbec", "rioja"}), + ) sleep() logger.Error("No malbec left!") sleep() - logger.Warn("Falling back to second choice", "fallback", "rioja") + logger.Warn("Falling back to second choice", slog.String("fallback", "rioja")) - logger.Info("Eating steak", "cut", "sirloin", "enjoying", true) + logger.Info("Eating steak", slog.String("cut", "sirloin"), slog.Bool("enjoying", true)) } func sleep() { diff --git a/examples/keys/main.go b/examples/keys/main.go index e42f549..e3b747b 100644 --- a/examples/keys/main.go +++ b/examples/keys/main.go @@ -1,6 +1,7 @@ package main import ( + "log/slog" "math/rand/v2" "os" "time" @@ -11,11 +12,16 @@ import ( func main() { logger := log.New(os.Stderr, log.WithLevel(log.LevelDebug)) - logger.Info("Doing something", "cache", true, "duration", 30*time.Second, "number", 42) + logger.Info( + "Doing something", + slog.Bool("cache", true), + slog.Duration("duration", 30*time.Second), + slog.Int("number", 42), + ) sleep() - sub := logger.With("sub", true) - sub.Info("Hello from the sub logger", "subkey", "yes") + sub := logger.With(slog.Bool("sub", true)) + sub.Info("Hello from the sub logger", slog.String("subkey", "yes")) } func sleep() { diff --git a/examples/prefix/main.go b/examples/prefix/main.go index 7ccde13..3600489 100644 --- a/examples/prefix/main.go +++ b/examples/prefix/main.go @@ -1,6 +1,7 @@ package main import ( + "log/slog" "math/rand/v2" "net/http" "os" @@ -13,14 +14,26 @@ func main() { logger := log.New(os.Stderr) prefixed := logger.Prefixed("http") - logger.Info("Calling GitHub API", "url", "https://api.github.com/") + logger.Info("Calling GitHub API", slog.String("url", "https://api.github.com/")) sleep() - prefixed.Warn("Slow endpoint", "endpoint", "users/slow", "duration", 10*time.Second) + prefixed.Warn( + "Slow endpoint", + slog.String("endpoint", "users/slow"), + slog.Duration("duration", 10*time.Second), + ) sleep() - prefixed.Info("Response from get repos", "status", http.StatusOK, "duration", 500*time.Millisecond) + prefixed.Info( + "Response from get repos", + slog.Int("status", http.StatusOK), + slog.Duration("duration", 500*time.Millisecond), + ) sleep() - prefixed.Error("Response from something else", "status", http.StatusBadRequest, "duration", 33*time.Millisecond) + prefixed.Error( + "Response from something else", + slog.Int("status", http.StatusBadRequest), + slog.Duration("duration", 33*time.Millisecond), + ) } func sleep() { diff --git a/level.go b/level.go index e1b36d8..1591972 100644 --- a/level.go +++ b/level.go @@ -29,7 +29,8 @@ const ( errorString = "ERROR" ) -func (l Level) styled() string { +// String returns the stylised representation of the log level. +func (l Level) String() string { switch l { case LevelDebug: return debugStyle.Text(debugString) diff --git a/log.go b/log.go index ffd4d7a..879d663 100644 --- a/log.go +++ b/log.go @@ -11,8 +11,8 @@ package log // import "go.followtheprocess.codes/log" import ( "bytes" "context" - "fmt" "io" + "log/slog" "os" "slices" "strconv" @@ -37,9 +37,6 @@ const ( errorStyle = hue.Red | hue.Bold ) -// missingValue is the placeholder text for a missing value in a log line's key value pair. -const missingValue = "" - // ctxKey is the unexported type used for context key so this key never collides with another. type ctxKey struct{} @@ -54,7 +51,7 @@ type Logger struct { mu *sync.Mutex // Protects w timeFormat string // The time format layout string, defaults to [time.RFC3339] prefix string // Optional prefix to prepend to all log messages - kv []any // Persistent key value pairs + attrs []slog.Attr // Persistent key value pairs level Level // The configured level of this logger, logs below this level are not shown isDiscard atomic.Bool // w == [io.Discard], cached } @@ -103,10 +100,10 @@ func FromContext(ctx context.Context) *Logger { // With returns a new [Logger] with the given persistent key value pairs. // // The returned logger is otherwise an exact clone of the caller. -func (l *Logger) With(kv ...any) *Logger { +func (l *Logger) With(attrs ...slog.Attr) *Logger { sub := l.clone() - sub.kv = slices.Concat(sub.kv, kv) + sub.attrs = slices.Concat(sub.attrs, attrs) return sub } @@ -123,27 +120,27 @@ func (l *Logger) Prefixed(prefix string) *Logger { } // Debug writes a debug level log line. -func (l *Logger) Debug(msg string, kv ...any) { - l.log(LevelDebug, msg, kv...) +func (l *Logger) Debug(msg string, attrs ...slog.Attr) { + l.log(LevelDebug, msg, attrs...) } // Info writes an info level log line. -func (l *Logger) Info(msg string, kv ...any) { - l.log(LevelInfo, msg, kv...) +func (l *Logger) Info(msg string, attrs ...slog.Attr) { + l.log(LevelInfo, msg, attrs...) } // Warn writes a warning level log line. -func (l *Logger) Warn(msg string, kv ...any) { - l.log(LevelWarn, msg, kv...) +func (l *Logger) Warn(msg string, attrs ...slog.Attr) { + l.log(LevelWarn, msg, attrs...) } // Error writes an error level log line. -func (l *Logger) Error(msg string, kv ...any) { - l.log(LevelError, msg, kv...) +func (l *Logger) Error(msg string, attrs ...slog.Attr) { + l.log(LevelError, msg, attrs...) } // log logs the given levelled message. -func (l *Logger) log(level Level, msg string, kv ...any) { +func (l *Logger) log(level Level, msg string, attrs ...slog.Attr) { if l.isDiscard.Load() || l.level > level { // Do as little work as possible return @@ -157,7 +154,7 @@ func (l *Logger) log(level Level, msg string, kv ...any) { buf.WriteString(timestampStyle.Text(l.timeFunc().Format(l.timeFormat))) buf.WriteByte(' ') - buf.WriteString(level.styled()) + buf.WriteString(level.String()) if l.prefix != "" { buf.WriteString(" " + prefixStyle.Text(l.prefix)) @@ -173,24 +170,14 @@ func (l *Logger) log(level Level, msg string, kv ...any) { buf.WriteString(strings.Repeat(" ", padding)) buf.WriteString(msg) - if numKVs := len(l.kv) + len(kv); numKVs != 0 { - kvs := make([]any, 0, numKVs) - - kvs = append(kvs, l.kv...) - if len(kvs)%2 != 0 { - kvs = append(kvs, missingValue) - } - - kvs = append(kvs, kv...) - if len(kvs)%2 != 0 { - kvs = append(kvs, missingValue) - } + if totalAttrs := len(l.attrs) + len(attrs); totalAttrs != 0 { + all := slices.Concat(l.attrs, attrs) - for i := 0; i < len(kvs); i += 2 { + for _, attr := range all { buf.WriteByte(' ') - key := keyStyle.Sprint(kvs[i]) - val := fmt.Sprintf("%+v", kvs[i+1]) + key := keyStyle.Text(attr.Key) + val := attr.Value.String() if needsQuotes(val) || val == "" { val = strconv.Quote(val) diff --git a/log_test.go b/log_test.go index b6b6812..fca512c 100644 --- a/log_test.go +++ b/log_test.go @@ -4,6 +4,7 @@ import ( "bytes" "fmt" "io" + "log/slog" "net/http" "os" "strings" @@ -28,8 +29,8 @@ func TestVisual(t *testing.T) { logger.Warn("Config file missing, falling back to defaults") logger.Error("File not found") - prefixed.Warn("Pizza is burning!", "flavour", "pepperoni") - prefixed.Info("Response from oven API", "status", http.StatusOK, "duration", 57*time.Millisecond) + prefixed.Warn("Pizza is burning!", slog.String("flavour", "pepperoni")) + prefixed.Info("Response from oven API", slog.Int("status", http.StatusOK), slog.Duration("duration", 57*time.Millisecond)) } func TestDebug(t *testing.T) { @@ -48,7 +49,7 @@ func TestDebug(t *testing.T) { tests := []struct { name string // Name of the test case msg string // Message to log - kv []any // Key value pairs to pass to the log method + attrs []slog.Attr // Additional attributes to pass to the log method want string // Expected log line options []log.Option // Options to customise the logger under test }{ @@ -78,40 +79,43 @@ func TestDebug(t *testing.T) { want: "[TIME] DEBUG building: Hello debug!\n", }, { - name: "with kv", + name: "with attrs", options: []log.Option{ log.WithLevel(log.LevelDebug), }, - msg: "Hello debug!", - kv: []any{"number", 12, "duration", 30 * time.Second, "enabled", true}, + msg: "Hello debug!", + attrs: []slog.Attr{ + slog.Int("number", 12), + slog.Duration("duration", 30*time.Second), + slog.Bool("enabled", true), + }, want: "[TIME] DEBUG: Hello debug! number=12 duration=30s enabled=true\n", }, { - name: "with kv quoted", + name: "with attrs quoted", options: []log.Option{ log.WithLevel(log.LevelDebug), }, - msg: "Hello debug!", - kv: []any{"number", 12, "duration", 30 * time.Second, "sentence", "this has spaces"}, + msg: "Hello debug!", + attrs: []slog.Attr{ + slog.Int("number", 12), + slog.Duration("duration", 30*time.Second), + slog.String("sentence", "this has spaces"), + }, want: `[TIME] DEBUG: Hello debug! number=12 duration=30s sentence="this has spaces"` + "\n", }, { - name: "with kv escape chars", + name: "with attrs escape chars", options: []log.Option{ log.WithLevel(log.LevelDebug), }, - msg: "Hello debug!", - kv: []any{"number", 12, "duration", 30 * time.Second, "sentence", "ooh\t\nstuff"}, - want: `[TIME] DEBUG: Hello debug! number=12 duration=30s sentence="ooh\t\nstuff"` + "\n", - }, - { - name: "with kv odd number", - options: []log.Option{ - log.WithLevel(log.LevelDebug), + msg: "Hello debug!", + attrs: []slog.Attr{ + slog.Int("number", 12), + slog.Duration("duration", 30*time.Second), + slog.String("sentence", "ooh\t\nstuff"), }, - msg: "One is missing", - kv: []any{"enabled", true, "file", "./file.txt", "elapsed"}, - want: "[TIME] DEBUG: One is missing enabled=true file=./file.txt elapsed=\n", + want: `[TIME] DEBUG: Hello debug! number=12 duration=30s sentence="ooh\t\nstuff"` + "\n", }, { name: "custom time format", @@ -133,7 +137,7 @@ func TestDebug(t *testing.T) { logger := log.New(buf, tt.options...) - logger.Debug(tt.msg, tt.kv...) + logger.Debug(tt.msg, tt.attrs...) got := buf.String() got = strings.ReplaceAll(got, fixedTimeString, "[TIME]") @@ -160,14 +164,17 @@ func TestWith(t *testing.T) { logger.Info("I'm an info message") - sub := logger.With("sub", true, "missing") + sub := logger.With( + slog.Bool("sub", true), + slog.String("hello", "world"), + ) sub.Info("I'm also an info message") got := buf.String() got = strings.TrimSpace(strings.ReplaceAll(got, fixedTimeString, "[TIME]")) + "\n" - want := "[TIME] INFO: I'm an info message\n[TIME] INFO: I'm also an info message sub=true missing=\n" + want := "[TIME] INFO: I'm an info message\n[TIME] INFO: I'm also an info message sub=true hello=world\n" test.Diff(t, got, want) }