diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index a77e245..fc61a9f 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -56,33 +56,34 @@ func reset(w io.Writer, termW io.Writer) { } } -func formatValue(v interface{}) string { +func formatValue(v interface{}) (string, error) { if vr, ok := v.(driver.Valuer); ok { var err error v, err = vr.Value() if err != nil { - return fmt.Sprintf("error calling Value: %v", err) + return "", xerrors.Errorf("error calling Value: %w", err) } } if v == nil { - return "" + return "", nil } typ := reflect.TypeOf(v) switch typ.Kind() { case reflect.Struct, reflect.Map: byt, err := json.Marshal(v) if err != nil { - panic(err) + // don't panic + return "", xerrors.Errorf("error marshalling value: %w", err) } - return string(byt) + return string(byt), nil case reflect.Slice: // Byte slices are optimistically readable. if typ.Elem().Kind() == reflect.Uint8 { - return fmt.Sprintf("%q", v) + return fmt.Sprintf("%q", v), nil } fallthrough default: - return quote(fmt.Sprintf("%+v", v)) + return quote(fmt.Sprintf("%+v", v)), nil } } @@ -174,6 +175,10 @@ func writeValueFast(w io.Writer, v interface{}) (bool, error) { } } +type Formatter struct { + ErrorCallback func(slog.Field, error) +} + // Fmt returns a human readable format for ent. Assumes we have a bytes.Buffer // which we will more easily be able to assume underlying reallocation of it's size is possible // if necessary than for an arbitrary io.Writer/io.StringWriter @@ -187,6 +192,10 @@ func writeValueFast(w io.Writer, v interface{}) (bool, error) { // for extra lines in a log so if we did it here, the fields would be indented // twice in test logs. So the Stderr logger indents all the fields itself. func Fmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { + Formatter{}.Fmt(buf, termW, ent) +} + +func (f Formatter) Fmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { reset(buf, termW) // Timestamp + space @@ -238,12 +247,12 @@ func Fmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { // Find a multiline field without mutating ent.Fields. multiIdx := -1 - for i, f := range ent.Fields { + for i, fld := range ent.Fields { if multilineVal != "" { break } var s string - switch v := f.Value.(type) { + switch v := fld.Value.(type) { case string: s = v case error, xerrors.Formatter: @@ -254,13 +263,13 @@ func Fmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { continue } multiIdx = i - multilineKey = f.Name + multilineKey = fld.Name multilineVal = s break } // Print fields (skip multiline field index). - for i, f := range ent.Fields { + for i, fld := range ent.Fields { if i == multiIdx { continue } @@ -268,13 +277,21 @@ func Fmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { buf.WriteString(tab) } - buf.WriteString(render(termW, keyStyle, quoteKey(f.Name))) + buf.WriteString(render(termW, keyStyle, quoteKey(fld.Name))) buf.WriteString(render(termW, equalsStyle, "=")) - if ok, err := writeValueFast(buf, f.Value); err != nil { - // return err + if ok, err := writeValueFast(buf, fld.Value); err != nil && f.ErrorCallback != nil { + f.ErrorCallback(fld, err) } else if !ok { - buf.WriteString(formatValue(f.Value)) + s, err := formatValue(fld.Value) + if err != nil { + if f.ErrorCallback != nil { + f.ErrorCallback(fld, err) + } + buf.WriteString(err.Error()) + continue + } + buf.WriteString(s) } } @@ -334,7 +351,8 @@ func levelStyle(level slog.Level) lipgloss.Style { case slog.LevelError, slog.LevelFatal, slog.LevelCritical: return levelErrorStyle default: - panic("unknown level") + // don't panic + return levelErrorStyle } } diff --git a/slog.go b/slog.go index a3b705c..375c5e9 100644 --- a/slog.go +++ b/slog.go @@ -80,67 +80,40 @@ func Make(sinks ...Sink) Logger { } // Debug logs the msg and fields at LevelDebug. -// See Info for information on the fields argument. -func (l Logger) Debug(ctx context.Context, msg string, fields ...any) { +func (l Logger) Debug(ctx context.Context, msg string, fields ...Field) { l.log(ctx, LevelDebug, msg, fields) } // Info logs the msg and fields at LevelInfo. -// Fields may contain any combination of key value pairs, Field, and Map. -// For example: -// -// log.Info(ctx, "something happened", "user", "alex", slog.F("age", 20)) -// -// is equivalent to: -// -// log.Info(ctx, "something happened", slog.F("user", "alex"), slog.F("age", 20)) -// -// is equivalent to: -// -// log.Info(ctx, "something happened", slog.M( -// slog.F("user", "alex"), -// slog.F("age", 20), -// )) -// -// is equivalent to: -// -// log.Info(ctx, "something happened", "user", "alex", "age", 20) -// -// In general, prefer using key value pairs over Field and Map, as that is how -// the standard library's slog package works. -func (l Logger) Info(ctx context.Context, msg string, fields ...any) { +func (l Logger) Info(ctx context.Context, msg string, fields ...Field) { l.log(ctx, LevelInfo, msg, fields) } // Warn logs the msg and fields at LevelWarn. -// See Info() for information on the fields argument. -func (l Logger) Warn(ctx context.Context, msg string, fields ...any) { +func (l Logger) Warn(ctx context.Context, msg string, fields ...Field) { l.log(ctx, LevelWarn, msg, fields) } // Error logs the msg and fields at LevelError. -// See Info() for information on the fields argument. // // It will then Sync(). -func (l Logger) Error(ctx context.Context, msg string, fields ...any) { +func (l Logger) Error(ctx context.Context, msg string, fields ...Field) { l.log(ctx, LevelError, msg, fields) l.Sync() } // Critical logs the msg and fields at LevelCritical. -// See Info() for information on the fields argument. // // It will then Sync(). -func (l Logger) Critical(ctx context.Context, msg string, fields ...any) { +func (l Logger) Critical(ctx context.Context, msg string, fields ...Field) { l.log(ctx, LevelCritical, msg, fields) l.Sync() } // Fatal logs the msg and fields at LevelFatal. -// See Info() for information on the fields argument. // // It will then Sync() and os.Exit(1). -func (l Logger) Fatal(ctx context.Context, msg string, fields ...any) { +func (l Logger) Fatal(ctx context.Context, msg string, fields ...Field) { l.log(ctx, LevelFatal, msg, fields) l.Sync() @@ -182,32 +155,7 @@ func (l Logger) AppendSinks(s ...Sink) Logger { return l } -func (l Logger) log(ctx context.Context, level Level, msg string, rawFields []any) { - fields := make(Map, 0, len(rawFields)) - var wipField Field - for i, f := range rawFields { - if wipField.Name != "" { - wipField.Value = f - fields = append(fields, wipField) - wipField = Field{} - continue - } - switch f := f.(type) { - case Field: - fields = append(fields, f) - case Map: - fields = append(fields, f...) - case string: - wipField.Name = f - default: - panic(fmt.Sprintf("unexpected field type %T at index %v (does it have a key?)", f, i)) - } - } - - if wipField.Name != "" { - panic(fmt.Sprintf("field %q has no value", wipField.Name)) - } - +func (l Logger) log(ctx context.Context, level Level, msg string, fields []Field) { ent := l.entry(ctx, level, msg, fields) l.Log(ctx, ent) } diff --git a/slog_test.go b/slog_test.go index 277a9c3..4e41767 100644 --- a/slog_test.go +++ b/slog_test.go @@ -2,7 +2,6 @@ package slog_test import ( "context" - "fmt" "io" "runtime" "testing" @@ -76,7 +75,7 @@ func TestLogger(t *testing.T) { File: slogTestFile, Func: "cdr.dev/slog_test.TestLogger.func2", - Line: 68, + Line: 67, Fields: slog.M( slog.F("ctx", 1024), @@ -113,7 +112,7 @@ func TestLogger(t *testing.T) { File: slogTestFile, Func: "cdr.dev/slog_test.TestLogger.func3", - Line: 103, + Line: 102, SpanContext: span.SpanContext(), @@ -154,36 +153,6 @@ func TestLogger(t *testing.T) { assert.Equal(t, "level", slog.LevelFatal, s.entries[5].Level) assert.Equal(t, "exits", 1, exits) }) - - t.Run("kv", func(t *testing.T) { - s := &fakeSink{} - l := slog.Make(s) - - // All of these formats should be equivalent. - formats := [][]any{ - {"animal", "cat", "weight", 15}, - {slog.F("animal", "cat"), "weight", 15}, - {slog.M( - slog.F("animal", "cat"), - slog.F("weight", 15), - )}, - {slog.F("animal", "cat"), slog.F("weight", 15)}, - } - - for _, format := range formats { - l.Info(bg, "msg", format...) - } - - assert.Len(t, "entries", 4, s.entries) - - for i := range s.entries { - assert.Equal( - t, fmt.Sprintf("%v", i), - s.entries[0].Fields, - s.entries[i].Fields, - ) - } - }) } func TestLevel_String(t *testing.T) { diff --git a/sloggers/slogtest/t.go b/sloggers/slogtest/t.go index 8c0f328..a898025 100644 --- a/sloggers/slogtest/t.go +++ b/sloggers/slogtest/t.go @@ -99,7 +99,12 @@ func (ts *testSink) LogEntry(_ context.Context, ent slog.SinkEntry) { var sb bytes.Buffer // The testing package logs to stdout and not stderr. - entryhuman.Fmt(&sb, os.Stdout, ent) + f := entryhuman.Formatter{ + ErrorCallback: func(field slog.Field, err error) { + ts.tb.Errorf("failed to log field %q: %v", field.Name, err) + }, + } + f.Fmt(&sb, os.Stdout, ent) switch ent.Level { case slog.LevelDebug, slog.LevelInfo, slog.LevelWarn: @@ -146,25 +151,25 @@ func l(t testing.TB) slog.Logger { } // Debug logs the given msg and fields to t via t.Log at the debug level. -func Debug(t testing.TB, msg string, fields ...any) { +func Debug(t testing.TB, msg string, fields ...slog.Field) { slog.Helper() l(t).Debug(ctx, msg, fields...) } // Info logs the given msg and fields to t via t.Log at the info level. -func Info(t testing.TB, msg string, fields ...any) { +func Info(t testing.TB, msg string, fields ...slog.Field) { slog.Helper() l(t).Info(ctx, msg, fields...) } // Error logs the given msg and fields to t via t.Error at the error level. -func Error(t testing.TB, msg string, fields ...any) { +func Error(t testing.TB, msg string, fields ...slog.Field) { slog.Helper() l(t).Error(ctx, msg, fields...) } // Fatal logs the given msg and fields to t via t.Fatal at the fatal level. -func Fatal(t testing.TB, msg string, fields ...any) { +func Fatal(t testing.TB, msg string, fields ...slog.Field) { slog.Helper() l(t).Fatal(ctx, msg, fields...) } diff --git a/sloggers/slogtest/t_test.go b/sloggers/slogtest/t_test.go index 2aa09d5..93c71f5 100644 --- a/sloggers/slogtest/t_test.go +++ b/sloggers/slogtest/t_test.go @@ -3,6 +3,7 @@ package slogtest_test import ( "context" "fmt" + "strings" "testing" "golang.org/x/xerrors" @@ -175,6 +176,23 @@ func TestSkipCleanup(t *testing.T) { assert.Len(t, "no cleanups", 0, tb.cleanups) } +func TestUnmarshalable(t *testing.T) { + t.Parallel() + tb := &fakeTB{} + l := slogtest.Make(tb, &slogtest.Options{}) + s := &selfRef{} + s.Ref = s + s2 := selfRef{Ref: s} // unmarshalable because it contains a cyclic ref + l.Info(bg, "hello", slog.F("self", s2)) + assert.Equal(t, "errors", 1, tb.errors) + assert.Len(t, "len errorfs", 1, tb.errorfs) + assert.True(t, "errorfs", strings.Contains(tb.errorfs[0], "failed to log field \"self\":")) +} + +type selfRef struct { + Ref *selfRef +} + var bg = context.Background() type fakeTB struct { @@ -182,6 +200,7 @@ type fakeTB struct { logs int errors int + errorfs []string fatals int cleanups []func() } @@ -196,6 +215,11 @@ func (tb *fakeTB) Error(v ...interface{}) { tb.errors++ } +func (tb *fakeTB) Errorf(msg string, v ...interface{}) { + tb.errors++ + tb.errorfs = append(tb.errorfs, fmt.Sprintf(msg, v...)) +} + func (tb *fakeTB) Fatal(v ...interface{}) { tb.fatals++ panic("")