diff --git a/README.md b/README.md index 78f5f76..ff332da 100644 --- a/README.md +++ b/README.md @@ -2,12 +2,17 @@ Zapr :zap: ========== A [logr](https://github.com/go-logr/logr) implementation using -[Zap](https://github.com/uber-go/zap). +[Zap](https://github.com/uber-go/zap). Can also be used as +[slog](https://pkg.go.dev/log/slog) handler. Usage ----- +Via logr: + ```go +package main + import ( "fmt" @@ -29,6 +34,33 @@ func main() { } ``` +Via slog: + +``` +package main + +import ( + "fmt" + "log/slog" + + "github.com/go-logr/logr/slogr" + "github.com/go-logr/zapr" + "go.uber.org/zap" +) + +func main() { + var log *slog.Logger + + zapLog, err := zap.NewDevelopment() + if err != nil { + panic(fmt.Sprintf("who watches the watchmen (%v)?", err)) + } + log = slog.New(slogr.NewSlogHandler(zapr.NewLogger(zapLog))) + + log.Info("Logr in action!", "the answer", 42) +} +``` + Increasing Verbosity -------------------- @@ -68,3 +100,8 @@ For the most part, concepts in Zap correspond directly with those in logr. Unlike Zap, all fields *must* be in the form of sugared fields -- it's illegal to pass a strongly-typed Zap field in a key position to any of the logging methods (`Log`, `Error`). + +The zapr `logr.LogSink` implementation also implements `logr.SlogHandler`. That +enables `slogr.NewSlogHandler` to provide a `slog.Handler` which just passes +parameters through to zapr. zapr handles special slog values (Group, +LogValuer), regardless of which front-end API is used. diff --git a/slog_test.go b/slog_test.go new file mode 100644 index 0000000..78d84b3 --- /dev/null +++ b/slog_test.go @@ -0,0 +1,181 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package zapr_test + +import ( + "bytes" + "context" + "encoding/json" + "log/slog" + "strings" + "testing" + "testing/slogtest" + + "github.com/go-logr/logr/slogr" + "github.com/go-logr/zapr" + "github.com/stretchr/testify/require" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +func TestSlogHandler(t *testing.T) { + var buffer bytes.Buffer + encoder := zapcore.NewJSONEncoder(zapcore.EncoderConfig{ + MessageKey: slog.MessageKey, + TimeKey: slog.TimeKey, + LevelKey: slog.LevelKey, + EncodeLevel: func(level zapcore.Level, encoder zapcore.PrimitiveArrayEncoder) { + encoder.AppendInt(int(level)) + }, + }) + core := zapcore.NewCore(encoder, zapcore.AddSync(&buffer), zapcore.Level(0)) + zl := zap.New(core) + logger := zapr.NewLogger(zl) + handler := slogr.NewSlogHandler(logger) + + err := slogtest.TestHandler(handler, func() []map[string]any { + _ = zl.Sync() + return parseOutput(t, buffer.Bytes()) + }) + t.Logf("Log output:\n%s\nAs JSON:\n%v\n", buffer.String(), parseOutput(t, buffer.Bytes())) + // Correlating failures with individual test cases is hard with the current API. + // See https://github.com/golang/go/issues/61758 + if err != nil { + if err, ok := err.(interface { + Unwrap() []error + }); ok { + for _, err := range err.Unwrap() { + if !containsOne(err.Error(), + "a Handler should ignore a zero Record.Time", // zapr always writes a time field. + "a Handler should not output groups for an empty Record", // Relies on WithGroup and that always opens a group. Text may change, see https://go.dev/cl/516155 + ) { + t.Errorf("Unexpected error: %v", err) + } + } + return + } + // Shouldn't be reached, errors from errors.Join can be split up. + t.Errorf("Unexpected errors:\n%v", err) + } +} + +func containsOne(hay string, needles ...string) bool { + for _, needle := range needles { + if strings.Contains(hay, needle) { + return true + } + } + return false +} + +// TestSlogCases covers some gaps in the coverage we get from +// slogtest.TestHandler (empty and invalud PC, see +// https://github.com/golang/go/issues/62280) and verbosity handling in +// combination with V(). +func TestSlogCases(t *testing.T) { + for name, tc := range map[string]struct { + record slog.Record + v int + expected string + }{ + "empty": { + expected: `{"msg":"", "level":"info", "v":0}`, + }, + "invalid-pc": { + record: slog.Record{PC: 1}, + expected: `{"msg":"", "level":"info", "v":0}`, + }, + "debug": { + record: slog.Record{Level: slog.LevelDebug}, + expected: `{"msg":"", "level":"Level(-4)", "v":4}`, + }, + "warn": { + record: slog.Record{Level: slog.LevelWarn}, + expected: `{"msg":"", "level":"warn", "v":0}`, + }, + "error": { + record: slog.Record{Level: slog.LevelError}, + expected: `{"msg":"", "level":"error"}`, + }, + "debug-v1": { + v: 1, + record: slog.Record{Level: slog.LevelDebug}, + expected: `{"msg":"", "level":"Level(-5)", "v":5}`, + }, + "warn-v1": { + v: 1, + record: slog.Record{Level: slog.LevelWarn}, + expected: `{"msg":"", "level":"info", "v":0}`, + }, + "error-v1": { + v: 1, + record: slog.Record{Level: slog.LevelError}, + expected: `{"msg":"", "level":"error"}`, + }, + "debug-v4": { + v: 4, + record: slog.Record{Level: slog.LevelDebug}, + expected: `{"msg":"", "level":"Level(-8)", "v":8}`, + }, + "warn-v4": { + v: 4, + record: slog.Record{Level: slog.LevelWarn}, + expected: `{"msg":"", "level":"info", "v":0}`, + }, + "error-v4": { + v: 4, + record: slog.Record{Level: slog.LevelError}, + expected: `{"msg":"", "level":"error"}`, + }, + } { + t.Run(name, func(t *testing.T) { + var buffer bytes.Buffer + encoder := zapcore.NewJSONEncoder(zapcore.EncoderConfig{ + MessageKey: slog.MessageKey, + LevelKey: slog.LevelKey, + EncodeLevel: func(level zapcore.Level, encoder zapcore.PrimitiveArrayEncoder) { + encoder.AppendString(level.String()) + }, + }) + core := zapcore.NewCore(encoder, zapcore.AddSync(&buffer), zapcore.Level(-10)) + zl := zap.New(core) + logger := zapr.NewLoggerWithOptions(zl, zapr.LogInfoLevel("v")) + handler := slogr.NewSlogHandler(logger.V(tc.v)) + require.NoError(t, handler.Handle(context.Background(), tc.record)) + _ = zl.Sync() + require.JSONEq(t, tc.expected, buffer.String()) + }) + } +} + +func parseOutput(t *testing.T, output []byte) []map[string]any { + var ms []map[string]any + for _, line := range bytes.Split(output, []byte{'\n'}) { + if len(line) == 0 { + continue + } + var m map[string]any + if err := json.Unmarshal(line, &m); err != nil { + t.Fatal(err) + } + ms = append(ms, m) + } + return ms +} diff --git a/slogzapr.go b/slogzapr.go new file mode 100644 index 0000000..84f56e4 --- /dev/null +++ b/slogzapr.go @@ -0,0 +1,183 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package zapr + +import ( + "context" + "log/slog" + "runtime" + + "github.com/go-logr/logr/slogr" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +var _ slogr.SlogSink = &zapLogger{} + +func (zl *zapLogger) Handle(_ context.Context, record slog.Record) error { + zapLevel := zap.InfoLevel + intLevel := 0 + isError := false + switch { + case record.Level >= slog.LevelError: + zapLevel = zap.ErrorLevel + isError = true + case record.Level >= slog.LevelWarn: + zapLevel = zap.WarnLevel + case record.Level >= 0: + // Already set above -> info. + default: + zapLevel = zapcore.Level(record.Level) + intLevel = int(-zapLevel) + } + + if checkedEntry := zl.l.Check(zapLevel, record.Message); checkedEntry != nil { + checkedEntry.Time = record.Time + checkedEntry.Caller = pcToCallerEntry(record.PC) + var fieldsBuffer [2]zap.Field + fields := fieldsBuffer[:0] + if !isError && zl.numericLevelKey != "" { + // Record verbosity for info entries. + fields = append(fields, zap.Int(zl.numericLevelKey, intLevel)) + } + // Inline all attributes. + fields = append(fields, zap.Inline(zapcore.ObjectMarshalerFunc(func(enc zapcore.ObjectEncoder) error { + record.Attrs(func(attr slog.Attr) bool { + encodeSlog(enc, attr) + return true + }) + return nil + }))) + checkedEntry.Write(fields...) + } + return nil +} + +func encodeSlog(enc zapcore.ObjectEncoder, attr slog.Attr) { + if attr.Equal(slog.Attr{}) { + // Ignore empty attribute. + return + } + + // Check in order of expected frequency, most common ones first. + // + // Usage statistics for parameters from Kubernetes 152876a3e, + // calculated with k/k/test/integration/logs/benchmark: + // + // kube-controller-manager -v10: + // strings: 10043 (85%) + // with API objects: 2 (0% of all arguments) + // types and their number of usage: NodeStatus:2 + // numbers: 792 (6%) + // ObjectRef: 292 (2%) + // others: 595 (5%) + // + // kube-scheduler -v10: + // strings: 1325 (40%) + // with API objects: 109 (3% of all arguments) + // types and their number of usage: PersistentVolume:50 PersistentVolumeClaim:59 + // numbers: 473 (14%) + // ObjectRef: 1305 (39%) + // others: 176 (5%) + + kind := attr.Value.Kind() + switch kind { + case slog.KindString: + enc.AddString(attr.Key, attr.Value.String()) + case slog.KindLogValuer: + // This includes klog.KObj. + encodeSlog(enc, slog.Attr{ + Key: attr.Key, + Value: attr.Value.Resolve(), + }) + case slog.KindInt64: + enc.AddInt64(attr.Key, attr.Value.Int64()) + case slog.KindUint64: + enc.AddUint64(attr.Key, attr.Value.Uint64()) + case slog.KindFloat64: + enc.AddFloat64(attr.Key, attr.Value.Float64()) + case slog.KindBool: + enc.AddBool(attr.Key, attr.Value.Bool()) + case slog.KindDuration: + enc.AddDuration(attr.Key, attr.Value.Duration()) + case slog.KindTime: + enc.AddTime(attr.Key, attr.Value.Time()) + case slog.KindGroup: + attrs := attr.Value.Group() + if attr.Key == "" { + // Inline group. + for _, attr := range attrs { + encodeSlog(enc, attr) + } + return + } + if len(attrs) == 0 { + // Ignore empty group. + return + } + _ = enc.AddObject(attr.Key, marshalAttrs(attrs)) + default: + // We have to go through reflection in zap.Any to get support + // for e.g. fmt.Stringer. + zap.Any(attr.Key, attr.Value.Any()).AddTo(enc) + } +} + +type marshalAttrs []slog.Attr + +func (attrs marshalAttrs) MarshalLogObject(enc zapcore.ObjectEncoder) error { + for _, attr := range attrs { + encodeSlog(enc, attr) + } + return nil +} + +var _ zapcore.ObjectMarshaler = marshalAttrs(nil) + +func pcToCallerEntry(pc uintptr) zapcore.EntryCaller { + if pc == 0 { + return zapcore.EntryCaller{} + } + // Same as https://cs.opensource.google/go/x/exp/+/642cacee:slog/record.go;drc=642cacee5cc05231f45555a333d07f1005ffc287;l=70 + fs := runtime.CallersFrames([]uintptr{pc}) + f, _ := fs.Next() + if f.File == "" { + return zapcore.EntryCaller{} + } + return zapcore.EntryCaller{ + Defined: true, + PC: pc, + File: f.File, + Line: f.Line, + Function: f.Function, + } +} + +func (zl *zapLogger) WithAttrs(attrs []slog.Attr) slogr.SlogSink { + newLogger := *zl + newLogger.l = newLogger.l.With(zap.Inline(marshalAttrs(attrs))) + return &newLogger +} + +func (zl *zapLogger) WithGroup(name string) slogr.SlogSink { + newLogger := *zl + newLogger.l = newLogger.l.With(zap.Namespace(name)) + return &newLogger +} diff --git a/zapr.go b/zapr.go index 1dadd0d..c8503ab 100644 --- a/zapr.go +++ b/zapr.go @@ -168,15 +168,6 @@ func (zl *zapLogger) handleFields(lvl int, args []interface{}, additional ...zap return append(fields, additional...) } -func zapIt(field string, val interface{}) zap.Field { - // Handle types that implement logr.Marshaler: log the replacement - // object instead of the original one. - if marshaler, ok := val.(logr.Marshaler); ok { - field, val = invokeMarshaler(field, marshaler) - } - return zap.Any(field, val) -} - func invokeMarshaler(field string, m logr.Marshaler) (f string, ret interface{}) { defer func() { if r := recover(); r != nil { diff --git a/zapr_noslog.go b/zapr_noslog.go new file mode 100644 index 0000000..ec8517b --- /dev/null +++ b/zapr_noslog.go @@ -0,0 +1,34 @@ +//go:build !go1.21 +// +build !go1.21 + +/* +Copyright 2023 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package zapr + +import ( + "github.com/go-logr/logr" + "go.uber.org/zap" +) + +func zapIt(field string, val interface{}) zap.Field { + // Handle types that implement logr.Marshaler: log the replacement + // object instead of the original one. + if marshaler, ok := val.(logr.Marshaler); ok { + field, val = invokeMarshaler(field, marshaler) + } + return zap.Any(field, val) +} diff --git a/zapr_noslog_test.go b/zapr_noslog_test.go new file mode 100644 index 0000000..6fb36df --- /dev/null +++ b/zapr_noslog_test.go @@ -0,0 +1,63 @@ +//go:build !go1.21 && !go1.21 +// +build !go1.21,!go1.21 + +/* +Copyright 2023 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package zapr_test + +import ( + "fmt" + + "github.com/go-logr/logr" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +// These implementations only exist to allow the tests to compile. Test cases +// that depend on slog support get skipped at runtime. + +func hasSlog() bool { + return false +} + +func slogInt(key string, value int) zap.Field { + return zap.Int(key, value) +} + +func slogString(key string, value string) zap.Field { + return zap.String(key, value) +} + +func slogGroup(key string, values ...zap.Field) zap.Field { + return zap.Object(key, zapcore.ObjectMarshalerFunc(func(encoder zapcore.ObjectEncoder) error { + for _, value := range values { + value.AddTo(encoder) + } + return nil + })) +} + +func slogValue(value interface{}) string { + return fmt.Sprintf("%v", value) +} + +func slogValuer(value interface{}) interface{} { + return value +} + +func logWithSlog(_ logr.Logger, _ string, _, _ []interface{}) { +} diff --git a/zapr_slog.go b/zapr_slog.go new file mode 100644 index 0000000..f072036 --- /dev/null +++ b/zapr_slog.go @@ -0,0 +1,48 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package zapr + +import ( + "log/slog" + + "github.com/go-logr/logr" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +func zapIt(field string, val interface{}) zap.Field { + switch valTyped := val.(type) { + case logr.Marshaler: + // Handle types that implement logr.Marshaler: log the replacement + // object instead of the original one. + field, val = invokeMarshaler(field, valTyped) + case slog.LogValuer: + // The same for slog.LogValuer. We let slog.Value handle + // potential panics and recursion. + val = slog.AnyValue(val).Resolve() + } + if slogValue, ok := val.(slog.Value); ok { + return zap.Inline(zapcore.ObjectMarshalerFunc(func(enc zapcore.ObjectEncoder) error { + encodeSlog(enc, slog.Attr{Key: field, Value: slogValue}) + return nil + })) + } + return zap.Any(field, val) +} diff --git a/zapr_slog_test.go b/zapr_slog_test.go new file mode 100644 index 0000000..0663a28 --- /dev/null +++ b/zapr_slog_test.go @@ -0,0 +1,79 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package zapr_test + +import ( + "log/slog" + + "github.com/go-logr/logr" + "github.com/go-logr/logr/slogr" +) + +func hasSlog() bool { + return true +} + +func (m *marshaler) LogValue() slog.Value { + if m == nil { + // TODO: simulate crash once slog handles it. + return slog.StringValue("msg=") + } + return slog.StringValue("msg=" + m.msg) +} + +var _ slog.LogValuer = &marshaler{} + +func slogInt(key string, value int) slog.Attr { + return slog.Int(key, value) +} + +func slogString(key string, value string) slog.Attr { + return slog.String(key, value) +} + +func slogGroup(key string, values ...interface{}) slog.Attr { + return slog.Group(key, values...) +} + +func slogValue(value interface{}) slog.Value { + return slog.AnyValue(value) +} + +func slogValuer(value interface{}) slog.LogValuer { + return valuer{value: value} +} + +type valuer struct { + value interface{} +} + +func (v valuer) LogValue() slog.Value { + return slog.AnyValue(v.value) +} + +var _ slog.LogValuer = valuer{} + +func logWithSlog(l logr.Logger, msg string, withKeysValues, keysValues []interface{}) { + logger := slog.New(slogr.NewSlogHandler(l)) + if withKeysValues != nil { + logger = logger.With(withKeysValues...) + } + logger.Info(msg, keysValues...) +} diff --git a/zapr_test.go b/zapr_test.go index 1d870e4..131638a 100644 --- a/zapr_test.go +++ b/zapr_test.go @@ -102,11 +102,13 @@ func newZapLogger(lvl zapcore.Level, w zapcore.WriteSyncer) *zap.Logger { func TestInfo(t *testing.T) { type testCase struct { msg string - format string + format string // If empty, only formatting with slog as API is supported. + formatSlog string // If empty, formatting with slog as API yields the same result as logr. names []string withKeysValues []interface{} keysValues []interface{} wrapper func(logr.Logger, string, ...interface{}) + needSlog bool } var testDataInfo = []testCase{ { @@ -139,8 +141,8 @@ func TestInfo(t *testing.T) { names: []string{"hello", "world"}, }, { - msg: "key/value pairs", - format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"key/value pairs","v":0,"ns":"default","podnum":2} + msg: "key-value pairs", + format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"key-value pairs","v":0,"ns":"default","podnum":2} `, keysValues: []interface{}{"ns", "default", "podnum", 2}, }, @@ -168,6 +170,8 @@ func TestInfo(t *testing.T) { msg: "invalid WithValues", format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"non-string key argument passed to logging, ignoring all later arguments","invalid key":200} {"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"invalid WithValues","ns":"default","podnum":2,"v":0} +`, + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"invalid WithValues","ns":"default","podnum":2,"!BADKEY":200,"replica":"Running","!BADKEY":10,"v":0} `, withKeysValues: []interface{}{"ns", "default", "podnum", 2, 200, "replica", "Running", 10}, }, @@ -175,6 +179,8 @@ func TestInfo(t *testing.T) { msg: "strongly typed Zap field", format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"strongly-typed Zap Field passed to logr","zap field":{"Key":"zap-field-attempt","Type":11,"Integer":3,"String":"","Interface":null}} {"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"strongly typed Zap field","v":0,"ns":"default","podnum":2,"zap-field-attempt":3,"Running":10} +`, + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"strongly typed Zap field","v":0,"ns":"default","podnum":2,"!BADKEY":{"Key":"zap-field-attempt","Type":11,"Integer":3,"String":"","Interface":null},"Running":10} `, keysValues: []interface{}{"ns", "default", "podnum", 2, zap.Int("zap-field-attempt", 3), "Running", 10}, }, @@ -182,6 +188,8 @@ func TestInfo(t *testing.T) { msg: "non-string key argument", format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"non-string key argument passed to logging, ignoring all later arguments","invalid key":200} {"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"non-string key argument","v":0,"ns":"default","podnum":2} +`, + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"non-string key argument","v":0,"ns":"default","podnum":2,"!BADKEY":200,"replica":"Running","!BADKEY":10} `, keysValues: []interface{}{"ns", "default", "podnum", 2, 200, "replica", "Running", 10}, }, @@ -189,6 +197,8 @@ func TestInfo(t *testing.T) { msg: "missing value", format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"odd number of arguments passed as key-value pairs for logging","ignored key":"no-value"} {"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"missing value","v":0,"ns":"default","podnum":2} +`, + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"missing value","v":0,"ns":"default","podnum":2,"!BADKEY":"no-value"} `, keysValues: []interface{}{"ns", "default", "podnum", 2, "no-value"}, }, @@ -208,6 +218,8 @@ func TestInfo(t *testing.T) { msg: "nil marshaler", // Handled by our code: it just formats the error. format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"nil marshaler","v":0,"objError":"PANIC=runtime error: invalid memory address or nil pointer dereference"} +`, + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"nil marshaler","v":0,"obj":"msg="} `, keysValues: []interface{}{"obj", (*marshaler)(nil)}, }, @@ -225,9 +237,54 @@ func TestInfo(t *testing.T) { `, keysValues: []interface{}{"obj", &stringerPanic{}}, }, + { + msg: "slog values", + format: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"slog values","v":0,"valuer":"some string","str":"another string","int64":-1,"uint64":2,"float64":3.124,"bool":true,"duration":"1s","timestamp":123.456789,"struct":{"SomeValue":42}} +`, + keysValues: []interface{}{"valuer", slogValuer("some string"), "str", slogValue("another string"), + "int64", slogValue(int64(-1)), "uint64", slogValue(uint64(2)), + "float64", slogValue(float64(3.124)), "bool", slogValue(true), + "duration", slogValue(time.Second), "timestamp", slogValue(time.Time{} /* replaced by custom formatter */), + "struct", slogValue(struct{ SomeValue int }{SomeValue: 42}), + }, + needSlog: true, + }, + { + msg: "group with empty key", + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"group with empty key","v":0,"int":1,"string":"hello"} +`, + keysValues: []interface{}{slogGroup("", slogInt("int", 1), slogString("string", "hello"))}, + needSlog: true, + }, + { + msg: "empty group", + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"empty group","v":0} +`, + keysValues: []interface{}{slogGroup("obj")}, + needSlog: true, + }, + { + msg: "group with key", + formatSlog: `{"ts":%f,"caller":"zapr/zapr_test.go:%d","msg":"group with key","v":0,"obj":{"int":1,"string":"hello"}} +`, + keysValues: []interface{}{slogGroup("obj", slogInt("int", 1), slogString("string", "hello"))}, + needSlog: true, + }, } - test := func(t *testing.T, logNumeric *string, enablePanics *bool, allowZapFields *bool, data testCase) { + test := func(t *testing.T, logNumeric *string, enablePanics *bool, allowZapFields *bool, useSlog bool, data testCase) { + if (data.needSlog || useSlog) && !hasSlog() { + t.Skip("slog is not supported") + } + if allowZapFields != nil && *allowZapFields && useSlog { + t.Skip("zap fields not supported by slog") + } + if (enablePanics == nil || *enablePanics) && useSlog { + t.Skip("printing additional log messages not supported by slog") + } + if !useSlog && data.format == "" { + t.Skip("test case only supported for slog") + } var buffer bytes.Buffer writer := bufio.NewWriter(&buffer) var sampleInfoLogger logr.Logger @@ -248,16 +305,27 @@ func TestInfo(t *testing.T) { } sampleInfoLogger = zapr.NewLoggerWithOptions(zl, opts...) } - if data.withKeysValues != nil { - sampleInfoLogger = sampleInfoLogger.WithValues(data.withKeysValues...) - } - for _, name := range data.names { - sampleInfoLogger = sampleInfoLogger.WithName(name) - } - if data.wrapper != nil { - data.wrapper(sampleInfoLogger, data.msg, data.keysValues...) + if useSlog { + if len(data.names) > 0 { + t.Skip("WithName not supported for slog") + // logger = logger.WithName(name) + } + if data.wrapper != nil { + t.Skip("slog does not support WithCallDepth") + } + logWithSlog(sampleInfoLogger, data.msg, data.withKeysValues, data.keysValues) } else { - sampleInfoLogger.Info(data.msg, data.keysValues...) + if data.withKeysValues != nil { + sampleInfoLogger = sampleInfoLogger.WithValues(data.withKeysValues...) + } + for _, name := range data.names { + sampleInfoLogger = sampleInfoLogger.WithName(name) + } + if data.wrapper != nil { + data.wrapper(sampleInfoLogger, data.msg, data.keysValues...) + } else { + sampleInfoLogger.Info(data.msg, data.keysValues...) + } } if err := writer.Flush(); err != nil { t.Fatalf("unexpected error from Flush: %v", err) @@ -268,22 +336,26 @@ func TestInfo(t *testing.T) { var dataFormatLines []string noPanics := enablePanics != nil && !*enablePanics withZapFields := allowZapFields != nil && *allowZapFields - for _, line := range strings.Split(data.format, "\n") { + format := data.format + if data.formatSlog != "" && useSlog { + format = data.formatSlog + } + for _, line := range strings.Split(format, "\n") { // Potentially filter out all or some panic // message. We can recognize them based on the // expected special keys. if strings.Contains(line, "invalid key") || strings.Contains(line, "ignored key") { - if noPanics { + if noPanics || useSlog { continue } } else if strings.Contains(line, "zap field") { - if noPanics || withZapFields { + if noPanics || withZapFields || useSlog { continue } } haveZapField := strings.Index(line, `"zap-field`) - if haveZapField != -1 && !withZapFields && !strings.Contains(line, "zap field") { + if haveZapField != -1 && !withZapFields && !strings.Contains(line, "zap field") && !useSlog { // When Zap fields are not allowed, output gets truncated at the first Zap field. line = line[0:haveZapField-1] + "}" } @@ -291,6 +363,7 @@ func TestInfo(t *testing.T) { } if !assert.Equal(t, len(logStrLines), len(dataFormatLines)) { t.Errorf("Info has wrong format: no. of lines in log is incorrect \n expected: %s\n got: %s", dataFormatLines, logStrLines) + return } for i := range logStrLines { @@ -300,15 +373,20 @@ func TestInfo(t *testing.T) { var ts float64 var lineNo int format := dataFormatLines[i] + actual := logStrLines[i] + // TODO: as soon as all supported Go versions have log/slog, + // the code from slogzapr_test.go can be moved into zapr_test.go + // and this Replace can get removed. + actual = strings.ReplaceAll(actual, "zapr_slog_test.go", "zapr_test.go") if logNumeric == nil || *logNumeric == "" { format = regexp.MustCompile(`,"v":-?\d`).ReplaceAllString(format, "") } - n, err := fmt.Sscanf(logStrLines[i], format, &ts, &lineNo) + n, err := fmt.Sscanf(actual, format, &ts, &lineNo) if n != 2 || err != nil { - t.Errorf("log format error: %d elements, error %s:\n%s", n, err, logStrLines[i]) + t.Errorf("log format error: %d elements, error %s:\n%s", n, err, actual) } expected := fmt.Sprintf(format, fixedTime, lineNo) - require.JSONEq(t, expected, logStrLines[i]) + require.JSONEq(t, expected, actual) } } @@ -325,7 +403,11 @@ func TestInfo(t *testing.T) { t.Run(fmt.Sprintf("allow zap fields %s", name), func(t *testing.T) { for _, data := range testDataInfo { t.Run(data.msg, func(t *testing.T) { - test(t, logNumeric, panicMessages, allowZapFields, data) + for name, useSlog := range map[string]bool{"with-logr": false, "with-slog": true} { + t.Run(name, func(t *testing.T) { + test(t, logNumeric, panicMessages, allowZapFields, useSlog, data) + }) + } }) } })