From b05c3fd0172ee12ebb54322103b1ccb50fd55b22 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Fri, 7 Nov 2025 16:44:31 -0800 Subject: [PATCH 1/8] add benchmarks Signed-off-by: Callum Styan --- sloggers/sloghuman/sloghuman_bench_test.go | 238 +++++++++++++++++++++ 1 file changed, 238 insertions(+) create mode 100644 sloggers/sloghuman/sloghuman_bench_test.go diff --git a/sloggers/sloghuman/sloghuman_bench_test.go b/sloggers/sloghuman/sloghuman_bench_test.go new file mode 100644 index 0000000..0e18115 --- /dev/null +++ b/sloggers/sloghuman/sloghuman_bench_test.go @@ -0,0 +1,238 @@ +package sloghuman_test + +import ( + "bytes" + "context" + "io" + "strconv" + "strings" + "testing" + "time" + + "cdr.dev/slog" + "cdr.dev/slog/internal/entryhuman" + "cdr.dev/slog/sloggers/sloghuman" + "go.opentelemetry.io/otel/trace" +) + +func multiline(n int) string { + var b strings.Builder + b.Grow(n * 8) + for i := 0; i < n; i++ { + b.WriteString("line-") + b.WriteString(strconv.Itoa(i)) + b.WriteByte('\n') + } + return b.String() +} + +// Benchmarks target the human sink path: humanSink.LogEntry -> entryhuman.Fmt -> bufio.Scanner indent. + +func BenchmarkHumanSinkLogEntry_SingleLine(b *testing.B) { + s := sloghuman.Sink(io.Discard) + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "hello world", + Fields: slog.M( + slog.F("k1", "v1"), + slog.F("k2", 123), + ), + } + ctx := context.Background() + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + s.LogEntry(ctx, ent) + } +} + +func BenchmarkHumanSinkLogEntry_MultilineField_Small(b *testing.B) { + s := sloghuman.Sink(io.Discard) + ml := multiline(10) + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", ml), // forces multiline field handling in Fmt + ), + } + ctx := context.Background() + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + s.LogEntry(ctx, ent) + } +} + +func BenchmarkHumanSinkLogEntry_MultilineField_Large(b *testing.B) { + s := sloghuman.Sink(io.Discard) + ml := multiline(1000) // many short lines; avoids Scanner token limit + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", ml), + ), + } + ctx := context.Background() + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + s.LogEntry(ctx, ent) + } +} + +func BenchmarkHumanSinkLogEntry_MultilineMessage(b *testing.B) { + s := sloghuman.Sink(io.Discard) + msg := "line1\nline2\nline3\nline4\nline5" + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: msg, // triggers multiline message handling in Fmt + Fields: nil, + } + ctx := context.Background() + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + s.LogEntry(ctx, ent) + } +} + +func bmMultiline(n int) string { + var b strings.Builder + b.Grow(n * 8) + for i := 0; i < n; i++ { + b.WriteString("line-") + b.WriteString(strconv.Itoa(i)) + b.WriteByte('\n') + } + return b.String() +} + +func BenchmarkFmt_SingleLine(b *testing.B) { + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "hello world", + Fields: slog.M( + slog.F("k1", "v1"), + slog.F("k2", 123), + ), + } + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + } +} + +func BenchmarkFmt_MultilineField_Small(b *testing.B) { + ml := bmMultiline(10) + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", ml), + ), + } + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + } +} + +func BenchmarkFmt_MultilineField_Large(b *testing.B) { + ml := bmMultiline(1000) + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", ml), + ), + } + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + } +} + +func BenchmarkFmt_MultilineMessage(b *testing.B) { + msg := "line1\nline2\nline3\nline4\nline5" + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: msg, + } + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + } +} + +func BenchmarkFmt_WithNames(b *testing.B) { + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "msg", + LoggerNames: []string{"svc", "sub", "component"}, + Fields: slog.M(slog.F("k", "v")), + } + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + } +} + +func BenchmarkFmt_WithSpan(b *testing.B) { + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "msg", + Fields: slog.M(slog.F("k", "v")), + } + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + } +} + +func BenchmarkFmt_WithValidSpan(b *testing.B) { + ent := slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "msg", + Fields: slog.M(slog.F("k", "v")), + } + // Create a valid SpanContext + tid := trace.TraceID{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16} + sid := trace.SpanID{1, 2, 3, 4, 5, 6, 7, 8} + ent.SpanContext = trace.NewSpanContext(trace.SpanContextConfig{ + TraceID: tid, + SpanID: sid, + TraceFlags: trace.FlagsSampled, + }) + + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + } +} From 873ed3530ead2d4a0d6fe8d677a799b056e8f8c2 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Fri, 7 Nov 2025 16:58:39 -0800 Subject: [PATCH 2/8] optimizations to entryhuman Fmt and sloghuman LogEntry Signed-off-by: Callum Styan --- internal/entryhuman/entry.go | 177 ++++++++++++++++++++++++++++------- 1 file changed, 141 insertions(+), 36 deletions(-) diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index 8af4d82..1f17911 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -88,6 +88,88 @@ func formatValue(v interface{}) string { const tab = " " +func bracketedLevel(l slog.Level) string { + switch l { + case slog.LevelDebug: + return "[debu]" + case slog.LevelInfo: + return "[info]" + case slog.LevelWarn: + return "[warn]" + case slog.LevelError: + return "[erro]" + case slog.LevelCritical: + return "[crit]" + case slog.LevelFatal: + return "[fata]" + default: + return "[unkn]" + } +} + +// returns true if handled without using formatValue +func writeValueFast(w io.Writer, v interface{}) bool { + switch x := v.(type) { + case bool: + if x { + io.WriteString(w, "true") + } else { + io.WriteString(w, "false") + } + return true + case int: + var a [20]byte + _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true + case int8: + var a [20]byte + _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true + case int16: + var a [20]byte + _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true + case int32: + var a [20]byte + _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true + case int64: + var a [20]byte + _, _ = w.Write(strconv.AppendInt(a[:0], x, 10)) + return true + case uint: + var a [20]byte + _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true + case uint8: + var a [20]byte + _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true + case uint16: + var a [20]byte + _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true + case uint32: + var a [20]byte + _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true + case uint64: + var a [20]byte + _, _ = w.Write(strconv.AppendUint(a[:0], x, 10)) + return true + case float32: + var a [32]byte + _, _ = w.Write(strconv.AppendFloat(a[:0], float64(x), 'f', -1, 32)) + return true + case float64: + var a [32]byte + _, _ = w.Write(strconv.AppendFloat(a[:0], x, 'f', -1, 64)) + return true + default: + return false + } +} + // Fmt returns a human readable format for ent. // // We never return with a trailing newline because Go's testing framework adds one @@ -103,20 +185,21 @@ func Fmt( ) { reset(buf, termW) ts := ent.Time.Format(TimeFormat) - buf.WriteString(render(termW, timeStyle, ts+" ")) + buf.WriteString(render(termW, timeStyle, ts)) + buf.WriteString(" ") - level := ent.Level.String() - level = strings.ToLower(level) - if len(level) > 4 { - level = level[:4] - } - level = "[" + level + "]" - buf.WriteString(render(termW, levelStyle(ent.Level), level)) + lvl := bracketedLevel(ent.Level) + buf.WriteString(render(termW, levelStyle(ent.Level), lvl)) buf.WriteString(" ") if len(ent.LoggerNames) > 0 { - loggerName := quoteKey(strings.Join(ent.LoggerNames, ".")) + ": " - buf.WriteString(loggerName) + for i, name := range ent.LoggerNames { + if i > 0 { + buf.WriteString(".") + } + buf.WriteString(quoteKey(name)) + } + buf.WriteString(": ") } var multilineKey string @@ -130,18 +213,27 @@ func Fmt( } buf.WriteString(msg) + keyStyle := timeStyle + // Help users distinguish logs by keeping some color in the equal signs. + equalsStyle := timeStyle + if ent.SpanContext.IsValid() { - ent.Fields = append(slog.M( - slog.F("trace", ent.SpanContext.TraceID), - slog.F("span", ent.SpanContext.SpanID), - ), ent.Fields...) + buf.WriteString(tab) + buf.WriteString(render(termW, keyStyle, quoteKey("trace"))) + buf.WriteString(render(termW, equalsStyle, "=")) + buf.WriteString(ent.SpanContext.TraceID().String()) + + buf.WriteString(tab) + buf.WriteString(render(termW, keyStyle, quoteKey("span"))) + buf.WriteString(render(termW, equalsStyle, "=")) + buf.WriteString(ent.SpanContext.SpanID().String()) } + multiIdx := -1 for i, f := range ent.Fields { if multilineVal != "" { break } - var s string switch v := f.Value.(type) { case string: @@ -153,25 +245,24 @@ func Fmt( if !strings.Contains(s, "\n") { continue } - - // Remove this field. - ent.Fields = append(ent.Fields[:i], ent.Fields[i+1:]...) + multiIdx = i multilineKey = f.Name multilineVal = s + break } - keyStyle := timeStyle - // Help users distinguish logs by keeping some color in the equal signs. - equalsStyle := timeStyle - for i, f := range ent.Fields { + if i == multiIdx { + continue + } if i < len(ent.Fields) { buf.WriteString(tab) } buf.WriteString(render(termW, keyStyle, quoteKey(f.Name))) buf.WriteString(render(termW, equalsStyle, "=")) - valueStr := formatValue(f.Value) - buf.WriteString(valueStr) + if !writeValueFast(buf, f.Value) { + buf.WriteString(formatValue(f.Value)) + } } if multilineVal != "" { @@ -179,20 +270,34 @@ func Fmt( buf.WriteString(" ...") } - // Proper indentation. - lines := strings.Split(multilineVal, "\n") - for i, line := range lines[1:] { - if line != "" { - lines[i+1] = strings.Repeat(" ", len(multilineKey)+2) + line - } - } - multilineVal = strings.Join(lines, "\n") - - multilineKey = render(termW, keyStyle, multilineKey) + // Proper indentation without allocations. buf.WriteString("\n") - buf.WriteString(multilineKey) + mKey := render(termW, keyStyle, multilineKey) + buf.WriteString(mKey) buf.WriteString("= ") - buf.WriteString(multilineVal) + + b := []byte(multilineVal) + if n := bytes.IndexByte(b, '\n'); n >= 0 { + buf.Write(b[:n]) + b = b[n+1:] + } else { + buf.Write(b) + b = nil + } + indent := strings.Repeat(" ", len(multilineKey)+2) + for len(b) > 0 { + buf.WriteString("\n") + if b[0] != '\n' { + buf.WriteString(indent) + } + if n := bytes.IndexByte(b, '\n'); n >= 0 { + buf.Write(b[:n]) + b = b[n+1:] + } else { + buf.Write(b) + break + } + } } } From 581621895e34770593c6bdec92e97a454fb97ba0 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Fri, 7 Nov 2025 18:00:24 -0800 Subject: [PATCH 3/8] cleanup + leave option of keeping existing non-optimized version since the optimized version should return an error Signed-off-by: Callum Styan --- internal/entryhuman/entry.go | 352 +++++++++++++++++++++++------- internal/entryhuman/entry_test.go | 189 +++++++++++++++- sloggers/sloghuman/sloghuman.go | 44 ++-- 3 files changed, 489 insertions(+), 96 deletions(-) diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index 1f17911..d11db4f 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -88,6 +88,8 @@ func formatValue(v interface{}) string { const tab = " " +// bracketedLevel is an optimization to avoid extra allocations and calls to strings.ToLower +// when we want to translate/print the lowercase version of a log level. func bracketedLevel(l slog.Level) string { switch l { case slog.LevelDebug: @@ -107,76 +109,76 @@ func bracketedLevel(l slog.Level) string { } } -// returns true if handled without using formatValue -func writeValueFast(w io.Writer, v interface{}) bool { +// Optimization to avoid allocation of heap allocations/temporary strings via formatValue when dealing with primitive types. +// It returns (handled, error). When handled is false, the caller should fall back to formatValue. +func writeValueFast(w io.Writer, v interface{}) (bool, error) { switch x := v.(type) { case bool: if x { - io.WriteString(w, "true") - } else { - io.WriteString(w, "false") + _, err := w.Write([]byte("true")) + return true, err } - return true + _, err := w.Write([]byte("false")) + return true, err + + // signed ints case int: var a [20]byte - _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) - return true + _, err := w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true, err case int8: var a [20]byte - _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) - return true + _, err := w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true, err case int16: var a [20]byte - _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) - return true + _, err := w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true, err case int32: var a [20]byte - _, _ = w.Write(strconv.AppendInt(a[:0], int64(x), 10)) - return true + _, err := w.Write(strconv.AppendInt(a[:0], int64(x), 10)) + return true, err case int64: var a [20]byte - _, _ = w.Write(strconv.AppendInt(a[:0], x, 10)) - return true + _, err := w.Write(strconv.AppendInt(a[:0], x, 10)) + return true, err + + // unsigned ints case uint: var a [20]byte - _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) - return true + _, err := w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true, err case uint8: var a [20]byte - _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) - return true + _, err := w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true, err case uint16: var a [20]byte - _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) - return true + _, err := w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true, err case uint32: var a [20]byte - _, _ = w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) - return true + _, err := w.Write(strconv.AppendUint(a[:0], uint64(x), 10)) + return true, err case uint64: var a [20]byte - _, _ = w.Write(strconv.AppendUint(a[:0], x, 10)) - return true + _, err := w.Write(strconv.AppendUint(a[:0], x, 10)) + return true, err + + // floats: prefer 'g' to keep output bounded (matches fmt default) case float32: var a [32]byte - _, _ = w.Write(strconv.AppendFloat(a[:0], float64(x), 'f', -1, 32)) - return true + _, err := w.Write(strconv.AppendFloat(a[:0], float64(x), 'g', -1, 32)) + return true, err case float64: var a [32]byte - _, _ = w.Write(strconv.AppendFloat(a[:0], x, 'f', -1, 64)) - return true + _, err := w.Write(strconv.AppendFloat(a[:0], x, 'g', -1, 64)) + return true, err default: - return false + return false, nil } } -// Fmt returns a human readable format for ent. -// -// We never return with a trailing newline because Go's testing framework adds one -// automatically and if we include one, then we'll get two newlines. -// We also do not indent the fields as go's test does that automatically -// 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 interface { io.StringWriter @@ -185,21 +187,20 @@ func Fmt( ) { reset(buf, termW) ts := ent.Time.Format(TimeFormat) - buf.WriteString(render(termW, timeStyle, ts)) - buf.WriteString(" ") + buf.WriteString(render(termW, timeStyle, ts+" ")) - lvl := bracketedLevel(ent.Level) - buf.WriteString(render(termW, levelStyle(ent.Level), lvl)) + level := ent.Level.String() + level = strings.ToLower(level) + if len(level) > 4 { + level = level[:4] + } + level = "[" + level + "]" + buf.WriteString(render(termW, levelStyle(ent.Level), level)) buf.WriteString(" ") if len(ent.LoggerNames) > 0 { - for i, name := range ent.LoggerNames { - if i > 0 { - buf.WriteString(".") - } - buf.WriteString(quoteKey(name)) - } - buf.WriteString(": ") + loggerName := quoteKey(strings.Join(ent.LoggerNames, ".")) + ": " + buf.WriteString(loggerName) } var multilineKey string @@ -213,22 +214,173 @@ func Fmt( } buf.WriteString(msg) + if ent.SpanContext.IsValid() { + ent.Fields = append(slog.M( + slog.F("trace", ent.SpanContext.TraceID), + slog.F("span", ent.SpanContext.SpanID), + ), ent.Fields...) + } + + for i, f := range ent.Fields { + if multilineVal != "" { + break + } + + var s string + switch v := f.Value.(type) { + case string: + s = v + case error, xerrors.Formatter: + s = fmt.Sprintf("%+v", v) + } + s = strings.TrimSpace(s) + if !strings.Contains(s, "\n") { + continue + } + + // Remove this field. + ent.Fields = append(ent.Fields[:i], ent.Fields[i+1:]...) + multilineKey = f.Name + multilineVal = s + } + keyStyle := timeStyle // Help users distinguish logs by keeping some color in the equal signs. equalsStyle := timeStyle - if ent.SpanContext.IsValid() { - buf.WriteString(tab) - buf.WriteString(render(termW, keyStyle, quoteKey("trace"))) + for i, f := range ent.Fields { + if i < len(ent.Fields) { + buf.WriteString(tab) + } + buf.WriteString(render(termW, keyStyle, quoteKey(f.Name))) buf.WriteString(render(termW, equalsStyle, "=")) - buf.WriteString(ent.SpanContext.TraceID().String()) + valueStr := formatValue(f.Value) + buf.WriteString(valueStr) + } - buf.WriteString(tab) - buf.WriteString(render(termW, keyStyle, quoteKey("span"))) - buf.WriteString(render(termW, equalsStyle, "=")) - buf.WriteString(ent.SpanContext.SpanID().String()) + if multilineVal != "" { + if msg != "..." { + buf.WriteString(" ...") + } + + // Proper indentation. + lines := strings.Split(multilineVal, "\n") + for i, line := range lines[1:] { + if line != "" { + lines[i+1] = strings.Repeat(" ", len(multilineKey)+2) + line + } + } + multilineVal = strings.Join(lines, "\n") + + multilineKey = render(termW, keyStyle, multilineKey) + buf.WriteString("\n") + buf.WriteString(multilineKey) + buf.WriteString("= ") + buf.WriteString(multilineVal) + } +} + +// OptimizedFmt 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 neceesary than for an arbitrary io.Writer/io.StringWriter +// +// We never return with a trailing newline because Go's testing framework adds one +// automatically and if we include one, then we'll get two newlines. +// We also do not indent the fields as go's test does that automatically +// 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 OptimizedFmt( + buf *bytes.Buffer, + termW io.Writer, + ent slog.SinkEntry, +) error { + writeString := func(s string) error { + _, err := buf.WriteString(s) + return err + } + + reset(buf, termW) + + // Timestamp + space + if err := writeString(render(termW, timeStyle, ent.Time.Format(TimeFormat))); err != nil { + return err + } + if err := writeString(" "); err != nil { + return err + } + + // Level label + two spaces + lvl := bracketedLevel(ent.Level) // e.g. "[debu]", "[info]" + if err := writeString(render(termW, levelStyle(ent.Level), lvl)); err != nil { + return err + } + if err := writeString(" "); err != nil { + return err + } + + // Logger names: name1.name2.name3: (no strings.Join allocation) + if len(ent.LoggerNames) > 0 { + for i, name := range ent.LoggerNames { + if i > 0 { + if err := writeString("."); err != nil { + return err + } + } + if err := writeString(quoteKey(name)); err != nil { + return err + } + } + if err := writeString(": "); err != nil { + return err + } + } + + // Message (detect multiline) + var multilineKey string + var multilineVal string + msg := strings.TrimSpace(ent.Message) + if strings.Contains(msg, "\n") { + multilineKey = "msg" + multilineVal = msg + msg = quote("...") + } + if err := writeString(msg); err != nil { + return err } + keyStyle := timeStyle + equalsStyle := timeStyle + + // Write trace/span directly (do not mutate ent.Fields) + if ent.SpanContext.IsValid() { + if err := writeString(tab); err != nil { + return err + } + if err := writeString(render(termW, keyStyle, quoteKey("trace"))); err != nil { + return err + } + if err := writeString(render(termW, equalsStyle, "=")); err != nil { + return err + } + if err := writeString(ent.SpanContext.TraceID().String()); err != nil { + return err + } + + if err := writeString(tab); err != nil { + return err + } + if err := writeString(render(termW, keyStyle, quoteKey("span"))); err != nil { + return err + } + if err := writeString(render(termW, equalsStyle, "=")); err != nil { + return err + } + if err := writeString(ent.SpanContext.SpanID().String()); err != nil { + return err + } + } + + // Find a multiline field without mutating ent.Fields. multiIdx := -1 for i, f := range ent.Fields { if multilineVal != "" { @@ -251,54 +403,90 @@ func Fmt( break } + // Print fields (skip multiline field index). for i, f := range ent.Fields { if i == multiIdx { continue } if i < len(ent.Fields) { - buf.WriteString(tab) + if err := writeString(tab); err != nil { + return err + } } - buf.WriteString(render(termW, keyStyle, quoteKey(f.Name))) - buf.WriteString(render(termW, equalsStyle, "=")) - if !writeValueFast(buf, f.Value) { - buf.WriteString(formatValue(f.Value)) + if err := writeString(render(termW, keyStyle, quoteKey(f.Name))); err != nil { + return err + } + if err := writeString(render(termW, equalsStyle, "=")); err != nil { + return err + } + + if ok, err := writeValueFast(buf, f.Value); err != nil { + return err + } else if !ok { + if err := writeString(formatValue(f.Value)); err != nil { + return err + } } } + // Multiline value block if multilineVal != "" { if msg != "..." { - buf.WriteString(" ...") + if err := writeString(" ..."); err != nil { + return err + } } - // Proper indentation without allocations. - buf.WriteString("\n") - mKey := render(termW, keyStyle, multilineKey) - buf.WriteString(mKey) - buf.WriteString("= ") + if err := writeString("\n"); err != nil { + return err + } + if err := writeString(render(termW, keyStyle, multilineKey)); err != nil { + return err + } + if err := writeString("= "); err != nil { + return err + } - b := []byte(multilineVal) - if n := bytes.IndexByte(b, '\n'); n >= 0 { - buf.Write(b[:n]) - b = b[n+1:] + // First line up to first newline + s := multilineVal + if n := strings.IndexByte(s, '\n'); n >= 0 { + if err := writeString(s[:n]); err != nil { + return err + } + s = s[n+1:] } else { - buf.Write(b) - b = nil + if err := writeString(s); err != nil { + return err + } + s = "" } + indent := strings.Repeat(" ", len(multilineKey)+2) - for len(b) > 0 { - buf.WriteString("\n") - if b[0] != '\n' { - buf.WriteString(indent) + for len(s) > 0 { + if err := writeString("\n"); err != nil { + return err } - if n := bytes.IndexByte(b, '\n'); n >= 0 { - buf.Write(b[:n]) - b = b[n+1:] + // Only indent non-empty lines. + if s[0] != '\n' { + if err := writeString(indent); err != nil { + return err + } + } + if n := strings.IndexByte(s, '\n'); n >= 0 { + if err := writeString(s[:n]); err != nil { + return err + } + s = s[n+1:] } else { - buf.Write(b) + if err := writeString(s); err != nil { + return err + } break } } } + + return nil } var ( diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go index 45a885a..7adb26d 100644 --- a/internal/entryhuman/entry_test.go +++ b/internal/entryhuman/entry_test.go @@ -208,6 +208,193 @@ func TestEntry(t *testing.T) { }) } +// we can remove this if we are okay with removing the existing Fmt function and replacing it with OptimizedFmt (can return an error) +func TestEntry_Optimized(t *testing.T) { + t.Parallel() + + type tcase struct { + name string + ent slog.SinkEntry + } + + ents := []tcase{ + { + "simpleNoFields", + slog.SinkEntry{ + Message: "wowowow\tizi", + Time: kt, + Level: slog.LevelDebug, + + File: "myfile", + Line: 100, + Func: "mypkg.ignored", + }, + }, + { + "multilineMessage", + slog.SinkEntry{ + Message: "line1\nline2", + Level: slog.LevelInfo, + }, + }, + { + "multilineField", + slog.SinkEntry{ + Message: "msg", + Level: slog.LevelInfo, + Fields: slog.M(slog.F("field", "line1\nline2")), + }, + }, + { + "named", + slog.SinkEntry{ + Level: slog.LevelWarn, + LoggerNames: []string{"some", "cat"}, + Message: "meow", + Fields: slog.M( + slog.F("breath", "stinky"), + ), + }, + }, + { + "funky", + slog.SinkEntry{ + Level: slog.LevelWarn, + Fields: slog.M( + slog.F("funky^%&^&^key", "value"), + slog.F("funky^%&^&^key2", "@#\t \t \n"), + ), + }, + }, + { + "spacey", + slog.SinkEntry{ + Level: slog.LevelWarn, + Fields: slog.M( + slog.F("space in my key", "value in my value"), + ), + }, + }, + { + "nil", + slog.SinkEntry{ + Level: slog.LevelWarn, + Fields: slog.M( + slog.F("nan", nil), + ), + }, + }, + { + "bytes", + slog.SinkEntry{ + Level: slog.LevelWarn, + Fields: slog.M( + slog.F("somefile", []byte("blah bla\x01h blah")), + ), + }, + }, + { + "driverValue", + slog.SinkEntry{ + Level: slog.LevelWarn, + Fields: slog.M( + slog.F("val", sql.NullString{String: "dog", Valid: true}), + slog.F("inval", sql.NullString{String: "cat", Valid: false}), + ), + }, + }, + { + "object", + slog.SinkEntry{ + Level: slog.LevelWarn, + Fields: slog.M( + slog.F("obj", slog.M( + slog.F("obj1", testObj{ + foo: 1, + bar: 2, + dra: []byte("blah"), + }), + slog.F("obj2", testObj{ + foo: 3, + bar: 4, + dra: []byte("blah"), + }), + )), + slog.F("map", map[string]string{ + "key1": "value1", + }), + ), + }, + }, + } + if *updateGoldenFiles { + ents, err := os.ReadDir("testdata") + if err != nil { + t.Fatal(err) + } + for _, ent := range ents { + os.Remove("testdata/" + ent.Name()) + } + } + + for _, tc := range ents { + tc := tc + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + goldenPath := fmt.Sprintf("testdata/%s.golden", tc.name) + + var gotBuf bytes.Buffer + err := entryhuman.OptimizedFmt(&gotBuf, io.Discard, tc.ent) + if err != nil { + t.Fatal(err) + } + + if *updateGoldenFiles { + err := os.WriteFile(goldenPath, gotBuf.Bytes(), 0o644) + if err != nil { + t.Fatal(err) + } + return + } + + wantByt, err := os.ReadFile(goldenPath) + if err != nil { + t.Fatal(err) + } + + assert.Equal(t, "entry matches", string(wantByt), gotBuf.String()) + }) + } + + t.Run("isTTY during file close", func(t *testing.T) { + t.Parallel() + + tmpdir := t.TempDir() + f, err := os.CreateTemp(tmpdir, "slog") + if err != nil { + t.Fatal(err) + } + defer f.Close() + + done := make(chan struct{}, 2) + go func() { + entryhuman.Fmt(new(bytes.Buffer), f, slog.SinkEntry{ + Level: slog.LevelCritical, + Fields: slog.M( + slog.F("hey", "hi"), + ), + }) + done <- struct{}{} + }() + go func() { + _ = f.Close() + done <- struct{}{} + }() + <-done + <-done + }) +} + func BenchmarkFmt(b *testing.B) { bench := func(b *testing.B, color bool) { nfs := []int{1, 4, 16} @@ -234,7 +421,7 @@ func BenchmarkFmt(b *testing.B) { b.ResetTimer() b.ReportAllocs() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, se) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, se) } }) } diff --git a/sloggers/sloghuman/sloghuman.go b/sloggers/sloghuman/sloghuman.go index 5247d17..8cc36ec 100644 --- a/sloggers/sloghuman/sloghuman.go +++ b/sloggers/sloghuman/sloghuman.go @@ -3,7 +3,6 @@ package sloghuman // import "cdr.dev/slog/sloggers/sloghuman" import ( - "bufio" "bytes" "context" "io" @@ -42,26 +41,45 @@ func (s humanSink) LogEntry(ctx context.Context, ent slog.SinkEntry) { buf1.Reset() defer bufPool.Put(buf1) + entryhuman.OptimizedFmt(buf1, s.w2, ent) + by := buf1.Bytes() + + // Prepare output buffer and indent lines after the first. buf2 := bufPool.Get().(*bytes.Buffer) buf2.Reset() defer bufPool.Put(buf2) - entryhuman.Fmt(buf1, s.w2, ent) + // Pre-grow: worst-case add 4 spaces per non-empty line after the first. + newlines := bytes.Count(by, []byte{'\n'}) + buf2.Grow(len(by) + newlines*4) - var ( - i int - sc = bufio.NewScanner(buf1) - ) + start := 0 + lineIdx := 0 + for { + idx := bytes.IndexByte(by[start:], '\n') + var line []byte + if idx >= 0 { + line = by[start : start+idx] + } else { + line = by[start:] + } - // We need to add 4 spaces before every field line for readability. - // humanfmt doesn't do it for us because the testSink doesn't want - // it as *testing.T automatically does it. - for ; sc.Scan(); i++ { - if i > 0 && len(sc.Bytes()) > 0 { - buf2.Write([]byte(" ")) + if lineIdx > 0 && len(line) > 0 { + buf2.WriteString(" ") } - buf2.Write(sc.Bytes()) + buf2.Write(line) buf2.WriteByte('\n') + + if idx < 0 { + break + } + start += idx + 1 + lineIdx++ + if start >= len(by) { + // The original logic always wrote a trailing newline + // even for an empty last line; we already wrote it. + break + } } s.w.Write("sloghuman", buf2.Bytes()) From 6d17803ee9bfd27fb6a16a310d9095cca38b6721 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Wed, 12 Nov 2025 16:10:01 -0800 Subject: [PATCH 4/8] fix/update tests Signed-off-by: Callum Styan --- internal/entryhuman/entry_test.go | 92 +++++++++++++++------- sloggers/sloghuman/sloghuman_bench_test.go | 15 ++-- 2 files changed, 72 insertions(+), 35 deletions(-) diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go index 7adb26d..3c34b83 100644 --- a/internal/entryhuman/entry_test.go +++ b/internal/entryhuman/entry_test.go @@ -208,7 +208,8 @@ func TestEntry(t *testing.T) { }) } -// we can remove this if we are okay with removing the existing Fmt function and replacing it with OptimizedFmt (can return an error) +// Verifies that OptimizedFmt returtns the same result as Fmt. +// We can remove this if we are okay with removing the existing Fmt function and replacing it with OptimizedFmt (can return an error). func TestEntry_Optimized(t *testing.T) { t.Parallel() @@ -326,43 +327,80 @@ func TestEntry_Optimized(t *testing.T) { ), }, }, - } - if *updateGoldenFiles { - ents, err := os.ReadDir("testdata") - if err != nil { - t.Fatal(err) - } - for _, ent := range ents { - os.Remove("testdata/" + ent.Name()) - } + { + "primitiveTypes", + slog.SinkEntry{ + Level: slog.LevelInfo, + Message: "primitives", + Time: kt, + Fields: slog.M( + slog.F("bool_true", true), + slog.F("bool_false", false), + slog.F("int", 42), + slog.F("int8", int8(-8)), + slog.F("int16", int16(-16)), + slog.F("int32", int32(-32)), + slog.F("int64", int64(-64)), + slog.F("uint", uint(42)), + slog.F("uint8", uint8(8)), + slog.F("uint16", uint16(16)), + slog.F("uint32", uint32(32)), + slog.F("uint64", uint64(64)), + slog.F("float32", float32(3.14)), + slog.F("float64", 2.71828), + ), + }, + }, + { + "primitiveEdgeCases", + slog.SinkEntry{ + Level: slog.LevelWarn, + Message: "edge cases", + Time: kt, + Fields: slog.M( + slog.F("zero_int", 0), + slog.F("neg_int", -999), + slog.F("max_int64", int64(9223372036854775807)), + slog.F("min_int64", int64(-9223372036854775808)), + slog.F("max_uint64", uint64(18446744073709551615)), + slog.F("zero_float", 0.0), + slog.F("neg_float", -123.456), + ), + }, + }, + { + "mixedPrimitiveAndComplex", + slog.SinkEntry{ + Level: slog.LevelDebug, + Message: "mixed types", + Time: kt, + Fields: slog.M( + slog.F("count", 100), + slog.F("name", "test"), + slog.F("enabled", true), + slog.F("ratio", 0.95), + slog.F("data", []byte("bytes")), + slog.F("nil_val", nil), + ), + }, + }, } for _, tc := range ents { tc := tc t.Run(tc.name, func(t *testing.T) { t.Parallel() - goldenPath := fmt.Sprintf("testdata/%s.golden", tc.name) - - var gotBuf bytes.Buffer - err := entryhuman.OptimizedFmt(&gotBuf, io.Discard, tc.ent) - if err != nil { - t.Fatal(err) - } - if *updateGoldenFiles { - err := os.WriteFile(goldenPath, gotBuf.Bytes(), 0o644) - if err != nil { - t.Fatal(err) - } - return - } + var fmtBuf bytes.Buffer + var optBuf bytes.Buffer - wantByt, err := os.ReadFile(goldenPath) + entryhuman.Fmt(&fmtBuf, io.Discard, tc.ent) + err := entryhuman.OptimizedFmt(&optBuf, io.Discard, tc.ent) if err != nil { t.Fatal(err) } - assert.Equal(t, "entry matches", string(wantByt), gotBuf.String()) + assert.Equal(t, "outputs match", fmtBuf.String(), optBuf.String()) }) } @@ -378,7 +416,7 @@ func TestEntry_Optimized(t *testing.T) { done := make(chan struct{}, 2) go func() { - entryhuman.Fmt(new(bytes.Buffer), f, slog.SinkEntry{ + entryhuman.OptimizedFmt(new(bytes.Buffer), f, slog.SinkEntry{ Level: slog.LevelCritical, Fields: slog.M( slog.F("hey", "hi"), diff --git a/sloggers/sloghuman/sloghuman_bench_test.go b/sloggers/sloghuman/sloghuman_bench_test.go index 0e18115..971372d 100644 --- a/sloggers/sloghuman/sloghuman_bench_test.go +++ b/sloggers/sloghuman/sloghuman_bench_test.go @@ -27,7 +27,6 @@ func multiline(n int) string { } // Benchmarks target the human sink path: humanSink.LogEntry -> entryhuman.Fmt -> bufio.Scanner indent. - func BenchmarkHumanSinkLogEntry_SingleLine(b *testing.B) { s := sloghuman.Sink(io.Discard) ent := slog.SinkEntry{ @@ -127,7 +126,7 @@ func BenchmarkFmt_SingleLine(b *testing.B) { b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) } } @@ -145,7 +144,7 @@ func BenchmarkFmt_MultilineField_Small(b *testing.B) { b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) } } @@ -163,7 +162,7 @@ func BenchmarkFmt_MultilineField_Large(b *testing.B) { b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) } } @@ -178,7 +177,7 @@ func BenchmarkFmt_MultilineMessage(b *testing.B) { b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) } } @@ -194,7 +193,7 @@ func BenchmarkFmt_WithNames(b *testing.B) { b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) } } @@ -209,7 +208,7 @@ func BenchmarkFmt_WithSpan(b *testing.B) { b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) } } @@ -233,6 +232,6 @@ func BenchmarkFmt_WithValidSpan(b *testing.B) { b.ReportAllocs() b.ResetTimer() for i := 0; i < b.N; i++ { - entryhuman.Fmt(bytes.NewBuffer(nil), w, ent) + entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) } } From 0ca41ccfa63069ebe45da590b8b9e8fcbe9f6d46 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Wed, 12 Nov 2025 16:51:52 -0800 Subject: [PATCH 5/8] 2 more test cases Signed-off-by: Callum Styan --- internal/entryhuman/entry_test.go | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go index 3c34b83..b791b6d 100644 --- a/internal/entryhuman/entry_test.go +++ b/internal/entryhuman/entry_test.go @@ -384,6 +384,22 @@ func TestEntry_Optimized(t *testing.T) { ), }, }, + { + "allLogLevels", + slog.SinkEntry{ + Level: slog.LevelCritical, // Test Critical + Message: "critical", + Time: kt, + }, + }, + { + "fatalLevel", + slog.SinkEntry{ + Level: slog.LevelFatal, // Test Fatal + Message: "fatal", + Time: kt, + }, + }, } for _, tc := range ents { From bbd432ed3cb1b25e134873b5552158e153e83daf Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Wed, 12 Nov 2025 18:58:43 -0800 Subject: [PATCH 6/8] simplify OptimizedFmt, in reality a bytes.Buffer will only error in one very specific case that should never happen if we're actually going to OOM via logging it would panic Signed-off-by: Callum Styan --- internal/entryhuman/entry.go | 141 ++++++++---------------------- internal/entryhuman/entry_test.go | 5 +- 2 files changed, 38 insertions(+), 108 deletions(-) diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index d11db4f..f194ac2 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -282,57 +282,37 @@ func Fmt( // OptimizedFmt 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 neceesary than for an arbitrary io.Writer/io.StringWriter +// if necessary than for an arbitrary io.Writer/io.StringWriter +// Note that while bytes.Buffer can in theory return an error for writes, it only does so if the buffer size will +// exceed our architectures max integer size. If the system is actually OOM and more memory cannot be allocated +// it will panic instead. // // We never return with a trailing newline because Go's testing framework adds one // automatically and if we include one, then we'll get two newlines. // We also do not indent the fields as go's test does that automatically // 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 OptimizedFmt( - buf *bytes.Buffer, - termW io.Writer, - ent slog.SinkEntry, -) error { - writeString := func(s string) error { - _, err := buf.WriteString(s) - return err - } - +func OptimizedFmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { reset(buf, termW) // Timestamp + space - if err := writeString(render(termW, timeStyle, ent.Time.Format(TimeFormat))); err != nil { - return err - } - if err := writeString(" "); err != nil { - return err - } + buf.WriteString(render(termW, timeStyle, ent.Time.Format(TimeFormat))) + buf.WriteString(" ") // Level label + two spaces lvl := bracketedLevel(ent.Level) // e.g. "[debu]", "[info]" - if err := writeString(render(termW, levelStyle(ent.Level), lvl)); err != nil { - return err - } - if err := writeString(" "); err != nil { - return err - } + buf.WriteString(render(termW, levelStyle(ent.Level), lvl)) + buf.WriteString(" ") // Logger names: name1.name2.name3: (no strings.Join allocation) if len(ent.LoggerNames) > 0 { for i, name := range ent.LoggerNames { if i > 0 { - if err := writeString("."); err != nil { - return err - } - } - if err := writeString(quoteKey(name)); err != nil { - return err + buf.WriteString(".") } + buf.WriteString(quoteKey(name)) } - if err := writeString(": "); err != nil { - return err - } + buf.WriteString(": ") } // Message (detect multiline) @@ -344,40 +324,22 @@ func OptimizedFmt( multilineVal = msg msg = quote("...") } - if err := writeString(msg); err != nil { - return err - } + buf.WriteString(msg) keyStyle := timeStyle equalsStyle := timeStyle // Write trace/span directly (do not mutate ent.Fields) if ent.SpanContext.IsValid() { - if err := writeString(tab); err != nil { - return err - } - if err := writeString(render(termW, keyStyle, quoteKey("trace"))); err != nil { - return err - } - if err := writeString(render(termW, equalsStyle, "=")); err != nil { - return err - } - if err := writeString(ent.SpanContext.TraceID().String()); err != nil { - return err - } + buf.WriteString(tab) - if err := writeString(tab); err != nil { - return err - } - if err := writeString(render(termW, keyStyle, quoteKey("span"))); err != nil { - return err - } - if err := writeString(render(termW, equalsStyle, "=")); err != nil { - return err - } - if err := writeString(ent.SpanContext.SpanID().String()); err != nil { - return err - } + buf.WriteString(render(termW, keyStyle, quoteKey("trace"))) + buf.WriteString(render(termW, equalsStyle, "=")) + buf.WriteString(ent.SpanContext.TraceID().String()) + buf.WriteString(tab) + buf.WriteString(render(termW, keyStyle, quoteKey("span"))) + buf.WriteString(render(termW, equalsStyle, "=")) + buf.WriteString(ent.SpanContext.SpanID().String()) } // Find a multiline field without mutating ent.Fields. @@ -409,84 +371,55 @@ func OptimizedFmt( continue } if i < len(ent.Fields) { - if err := writeString(tab); err != nil { - return err - } - } - if err := writeString(render(termW, keyStyle, quoteKey(f.Name))); err != nil { - return err - } - if err := writeString(render(termW, equalsStyle, "=")); err != nil { - return err + buf.WriteString(tab) } + buf.WriteString(render(termW, keyStyle, quoteKey(f.Name))) + buf.WriteString(render(termW, equalsStyle, "=")) + if ok, err := writeValueFast(buf, f.Value); err != nil { - return err + // return err } else if !ok { - if err := writeString(formatValue(f.Value)); err != nil { - return err - } + buf.WriteString(formatValue(f.Value)) } } // Multiline value block if multilineVal != "" { if msg != "..." { - if err := writeString(" ..."); err != nil { - return err - } + buf.WriteString(" ...") } - if err := writeString("\n"); err != nil { - return err - } - if err := writeString(render(termW, keyStyle, multilineKey)); err != nil { - return err - } - if err := writeString("= "); err != nil { - return err - } + buf.WriteString("\n") + buf.WriteString(render(termW, keyStyle, multilineKey)) + buf.WriteString("= ") // First line up to first newline s := multilineVal if n := strings.IndexByte(s, '\n'); n >= 0 { - if err := writeString(s[:n]); err != nil { - return err - } + buf.WriteString(s[:n]) s = s[n+1:] } else { - if err := writeString(s); err != nil { - return err - } + buf.WriteString(s) s = "" } indent := strings.Repeat(" ", len(multilineKey)+2) for len(s) > 0 { - if err := writeString("\n"); err != nil { - return err - } + buf.WriteString("\n") // Only indent non-empty lines. if s[0] != '\n' { - if err := writeString(indent); err != nil { - return err - } + buf.WriteString(indent) } if n := strings.IndexByte(s, '\n'); n >= 0 { - if err := writeString(s[:n]); err != nil { - return err - } + buf.WriteString(s[:n]) s = s[n+1:] } else { - if err := writeString(s); err != nil { - return err - } + buf.WriteString(s) break } } } - - return nil } var ( diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go index b791b6d..87e3435 100644 --- a/internal/entryhuman/entry_test.go +++ b/internal/entryhuman/entry_test.go @@ -411,10 +411,7 @@ func TestEntry_Optimized(t *testing.T) { var optBuf bytes.Buffer entryhuman.Fmt(&fmtBuf, io.Discard, tc.ent) - err := entryhuman.OptimizedFmt(&optBuf, io.Discard, tc.ent) - if err != nil { - t.Fatal(err) - } + entryhuman.OptimizedFmt(&optBuf, io.Discard, tc.ent) assert.Equal(t, "outputs match", fmtBuf.String(), optBuf.String()) }) From ab9bf95d4ec42fbabf0cd4e7c4adde2b50db3058 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Thu, 13 Nov 2025 11:29:32 -0800 Subject: [PATCH 7/8] clean up; don't keep original Fmt, consolidate tests, generate golden files for new test cases Signed-off-by: Callum Styan --- internal/entryhuman/entry.go | 105 +----- internal/entryhuman/entry_test.go | 219 ++---------- internal/entryhuman/new_entry | 66 ++++ internal/entryhuman/orig_entry | 66 ++++ internal/entryhuman/out.txt | 241 +++++++++++++ .../entryhuman/testdata/allLogLevels.golden | 1 + .../entryhuman/testdata/fatalLevel.golden | 1 + .../testdata/mixedPrimitiveAndComplex.golden | 1 + .../testdata/primitiveEdgeCases.golden | 1 + .../entryhuman/testdata/primitiveTypes.golden | 1 + sloggers/sloghuman/sloghuman.go | 2 +- sloggers/sloghuman/sloghuman_bench_test.go | 335 ++++++++---------- sloggers/slogtest/t.go | 4 +- 13 files changed, 554 insertions(+), 489 deletions(-) create mode 100644 internal/entryhuman/new_entry create mode 100644 internal/entryhuman/orig_entry create mode 100644 internal/entryhuman/out.txt create mode 100644 internal/entryhuman/testdata/allLogLevels.golden create mode 100644 internal/entryhuman/testdata/fatalLevel.golden create mode 100644 internal/entryhuman/testdata/mixedPrimitiveAndComplex.golden create mode 100644 internal/entryhuman/testdata/primitiveEdgeCases.golden create mode 100644 internal/entryhuman/testdata/primitiveTypes.golden diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index f194ac2..6708fc3 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -179,108 +179,7 @@ func writeValueFast(w io.Writer, v interface{}) (bool, error) { } } -func Fmt( - buf interface { - io.StringWriter - io.Writer - }, termW io.Writer, ent slog.SinkEntry, -) { - reset(buf, termW) - ts := ent.Time.Format(TimeFormat) - buf.WriteString(render(termW, timeStyle, ts+" ")) - - level := ent.Level.String() - level = strings.ToLower(level) - if len(level) > 4 { - level = level[:4] - } - level = "[" + level + "]" - buf.WriteString(render(termW, levelStyle(ent.Level), level)) - buf.WriteString(" ") - - if len(ent.LoggerNames) > 0 { - loggerName := quoteKey(strings.Join(ent.LoggerNames, ".")) + ": " - buf.WriteString(loggerName) - } - - var multilineKey string - var multilineVal string - msg := strings.TrimSpace(ent.Message) - if strings.Contains(msg, "\n") { - multilineKey = "msg" - multilineVal = msg - msg = "..." - msg = quote(msg) - } - buf.WriteString(msg) - - if ent.SpanContext.IsValid() { - ent.Fields = append(slog.M( - slog.F("trace", ent.SpanContext.TraceID), - slog.F("span", ent.SpanContext.SpanID), - ), ent.Fields...) - } - - for i, f := range ent.Fields { - if multilineVal != "" { - break - } - - var s string - switch v := f.Value.(type) { - case string: - s = v - case error, xerrors.Formatter: - s = fmt.Sprintf("%+v", v) - } - s = strings.TrimSpace(s) - if !strings.Contains(s, "\n") { - continue - } - - // Remove this field. - ent.Fields = append(ent.Fields[:i], ent.Fields[i+1:]...) - multilineKey = f.Name - multilineVal = s - } - - keyStyle := timeStyle - // Help users distinguish logs by keeping some color in the equal signs. - equalsStyle := timeStyle - - for i, f := range ent.Fields { - if i < len(ent.Fields) { - buf.WriteString(tab) - } - buf.WriteString(render(termW, keyStyle, quoteKey(f.Name))) - buf.WriteString(render(termW, equalsStyle, "=")) - valueStr := formatValue(f.Value) - buf.WriteString(valueStr) - } - - if multilineVal != "" { - if msg != "..." { - buf.WriteString(" ...") - } - - // Proper indentation. - lines := strings.Split(multilineVal, "\n") - for i, line := range lines[1:] { - if line != "" { - lines[i+1] = strings.Repeat(" ", len(multilineKey)+2) + line - } - } - multilineVal = strings.Join(lines, "\n") - - multilineKey = render(termW, keyStyle, multilineKey) - buf.WriteString("\n") - buf.WriteString(multilineKey) - buf.WriteString("= ") - buf.WriteString(multilineVal) - } -} - -// OptimizedFmt returns a human readable format for ent. Assumes we have a bytes.Buffer +// 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 // Note that while bytes.Buffer can in theory return an error for writes, it only does so if the buffer size will @@ -292,7 +191,7 @@ func Fmt( // We also do not indent the fields as go's test does that automatically // 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 OptimizedFmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { +func Fmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { reset(buf, termW) // Timestamp + space diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go index 87e3435..221ad7f 100644 --- a/internal/entryhuman/entry_test.go +++ b/internal/entryhuman/entry_test.go @@ -142,191 +142,6 @@ func TestEntry(t *testing.T) { ), }, }, - } - if *updateGoldenFiles { - ents, err := os.ReadDir("testdata") - if err != nil { - t.Fatal(err) - } - for _, ent := range ents { - os.Remove("testdata/" + ent.Name()) - } - } - - for _, tc := range ents { - tc := tc - t.Run(tc.name, func(t *testing.T) { - t.Parallel() - goldenPath := fmt.Sprintf("testdata/%s.golden", tc.name) - - var gotBuf bytes.Buffer - entryhuman.Fmt(&gotBuf, io.Discard, tc.ent) - - if *updateGoldenFiles { - err := os.WriteFile(goldenPath, gotBuf.Bytes(), 0o644) - if err != nil { - t.Fatal(err) - } - return - } - - wantByt, err := os.ReadFile(goldenPath) - if err != nil { - t.Fatal(err) - } - - assert.Equal(t, "entry matches", string(wantByt), gotBuf.String()) - }) - } - - t.Run("isTTY during file close", func(t *testing.T) { - t.Parallel() - - tmpdir := t.TempDir() - f, err := os.CreateTemp(tmpdir, "slog") - if err != nil { - t.Fatal(err) - } - defer f.Close() - - done := make(chan struct{}, 2) - go func() { - entryhuman.Fmt(new(bytes.Buffer), f, slog.SinkEntry{ - Level: slog.LevelCritical, - Fields: slog.M( - slog.F("hey", "hi"), - ), - }) - done <- struct{}{} - }() - go func() { - _ = f.Close() - done <- struct{}{} - }() - <-done - <-done - }) -} - -// Verifies that OptimizedFmt returtns the same result as Fmt. -// We can remove this if we are okay with removing the existing Fmt function and replacing it with OptimizedFmt (can return an error). -func TestEntry_Optimized(t *testing.T) { - t.Parallel() - - type tcase struct { - name string - ent slog.SinkEntry - } - - ents := []tcase{ - { - "simpleNoFields", - slog.SinkEntry{ - Message: "wowowow\tizi", - Time: kt, - Level: slog.LevelDebug, - - File: "myfile", - Line: 100, - Func: "mypkg.ignored", - }, - }, - { - "multilineMessage", - slog.SinkEntry{ - Message: "line1\nline2", - Level: slog.LevelInfo, - }, - }, - { - "multilineField", - slog.SinkEntry{ - Message: "msg", - Level: slog.LevelInfo, - Fields: slog.M(slog.F("field", "line1\nline2")), - }, - }, - { - "named", - slog.SinkEntry{ - Level: slog.LevelWarn, - LoggerNames: []string{"some", "cat"}, - Message: "meow", - Fields: slog.M( - slog.F("breath", "stinky"), - ), - }, - }, - { - "funky", - slog.SinkEntry{ - Level: slog.LevelWarn, - Fields: slog.M( - slog.F("funky^%&^&^key", "value"), - slog.F("funky^%&^&^key2", "@#\t \t \n"), - ), - }, - }, - { - "spacey", - slog.SinkEntry{ - Level: slog.LevelWarn, - Fields: slog.M( - slog.F("space in my key", "value in my value"), - ), - }, - }, - { - "nil", - slog.SinkEntry{ - Level: slog.LevelWarn, - Fields: slog.M( - slog.F("nan", nil), - ), - }, - }, - { - "bytes", - slog.SinkEntry{ - Level: slog.LevelWarn, - Fields: slog.M( - slog.F("somefile", []byte("blah bla\x01h blah")), - ), - }, - }, - { - "driverValue", - slog.SinkEntry{ - Level: slog.LevelWarn, - Fields: slog.M( - slog.F("val", sql.NullString{String: "dog", Valid: true}), - slog.F("inval", sql.NullString{String: "cat", Valid: false}), - ), - }, - }, - { - "object", - slog.SinkEntry{ - Level: slog.LevelWarn, - Fields: slog.M( - slog.F("obj", slog.M( - slog.F("obj1", testObj{ - foo: 1, - bar: 2, - dra: []byte("blah"), - }), - slog.F("obj2", testObj{ - foo: 3, - bar: 4, - dra: []byte("blah"), - }), - )), - slog.F("map", map[string]string{ - "key1": "value1", - }), - ), - }, - }, { "primitiveTypes", slog.SinkEntry{ @@ -401,19 +216,39 @@ func TestEntry_Optimized(t *testing.T) { }, }, } + if *updateGoldenFiles { + ents, err := os.ReadDir("testdata") + if err != nil { + t.Fatal(err) + } + for _, ent := range ents { + os.Remove("testdata/" + ent.Name()) + } + } for _, tc := range ents { tc := tc t.Run(tc.name, func(t *testing.T) { t.Parallel() + goldenPath := fmt.Sprintf("testdata/%s.golden", tc.name) + + var gotBuf bytes.Buffer + entryhuman.Fmt(&gotBuf, io.Discard, tc.ent) - var fmtBuf bytes.Buffer - var optBuf bytes.Buffer + if *updateGoldenFiles { + err := os.WriteFile(goldenPath, gotBuf.Bytes(), 0o644) + if err != nil { + t.Fatal(err) + } + return + } - entryhuman.Fmt(&fmtBuf, io.Discard, tc.ent) - entryhuman.OptimizedFmt(&optBuf, io.Discard, tc.ent) + wantByt, err := os.ReadFile(goldenPath) + if err != nil { + t.Fatal(err) + } - assert.Equal(t, "outputs match", fmtBuf.String(), optBuf.String()) + assert.Equal(t, "entry matches", string(wantByt), gotBuf.String()) }) } @@ -429,7 +264,7 @@ func TestEntry_Optimized(t *testing.T) { done := make(chan struct{}, 2) go func() { - entryhuman.OptimizedFmt(new(bytes.Buffer), f, slog.SinkEntry{ + entryhuman.Fmt(new(bytes.Buffer), f, slog.SinkEntry{ Level: slog.LevelCritical, Fields: slog.M( slog.F("hey", "hi"), @@ -472,7 +307,7 @@ func BenchmarkFmt(b *testing.B) { b.ResetTimer() b.ReportAllocs() for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, se) + entryhuman.Fmt(bytes.NewBuffer(nil), w, se) } }) } diff --git a/internal/entryhuman/new_entry b/internal/entryhuman/new_entry new file mode 100644 index 0000000..562143e --- /dev/null +++ b/internal/entryhuman/new_entry @@ -0,0 +1,66 @@ +goos: darwin +goarch: arm64 +pkg: cdr.dev/slog/internal/entryhuman +cpu: Apple M4 Pro +BenchmarkFmt/Colored-nf=1-12 269846 4442 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 279056 4421 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 266496 4414 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 269301 4373 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 275001 4399 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 274089 4504 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 259311 4450 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 272248 4437 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 272348 4420 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=1-12 271333 4406 ns/op 1994 B/op 119 allocs/op +BenchmarkFmt/Colored-nf=4-12 111796 10667 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 113119 10787 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 109360 10920 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 109830 10845 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 110982 10928 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 109868 10828 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 111752 10993 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 110218 10928 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 111771 11054 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=4-12 109627 11004 ns/op 4669 B/op 300 allocs/op +BenchmarkFmt/Colored-nf=16-12 32572 36878 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 32392 37065 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 31656 36563 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 32716 36595 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 32643 36689 ns/op 14344 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 33141 36715 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 32709 36536 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 32095 37598 ns/op 14344 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 32638 36983 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/Colored-nf=16-12 32463 36885 ns/op 14345 B/op 1021 allocs/op +BenchmarkFmt/nf=1-12 3690738 323.5 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3740504 322.6 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3741657 322.0 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3716818 321.0 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3765878 320.6 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3714015 321.4 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3722384 321.4 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3746545 318.7 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3775784 321.2 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=1-12 3700758 322.1 ns/op 184 B/op 9 allocs/op +BenchmarkFmt/nf=4-12 1418212 836.5 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1450852 824.9 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1456974 831.9 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1432821 831.1 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1444159 836.3 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1368248 850.0 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1419829 843.4 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1432812 840.5 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1440943 833.4 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=4-12 1432062 843.1 ns/op 456 B/op 28 allocs/op +BenchmarkFmt/nf=16-12 426823 2811 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 427839 2799 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 429816 2799 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 439380 2779 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 434738 2842 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 391664 2908 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 423054 2835 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 423688 2843 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 416474 2863 ns/op 1288 B/op 101 allocs/op +BenchmarkFmt/nf=16-12 421389 2803 ns/op 1288 B/op 101 allocs/op +PASS +ok cdr.dev/slog/internal/entryhuman 90.528s diff --git a/internal/entryhuman/orig_entry b/internal/entryhuman/orig_entry new file mode 100644 index 0000000..b542b67 --- /dev/null +++ b/internal/entryhuman/orig_entry @@ -0,0 +1,66 @@ +goos: darwin +goarch: arm64 +pkg: cdr.dev/slog/internal/entryhuman +cpu: Apple M4 Pro +BenchmarkFmt/Colored-nf=1-12 269304 4448 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 273135 4448 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 267333 4455 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 272311 4458 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 268456 4489 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 266517 4489 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 268579 4481 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 263763 4487 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 265862 4460 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=1-12 264967 4464 ns/op 2034 B/op 122 allocs/op +BenchmarkFmt/Colored-nf=4-12 112771 10783 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 111157 10915 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 110229 10892 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 109729 10922 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 108057 10865 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 111726 10717 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 111646 10732 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 107232 10950 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 111188 10845 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=4-12 109567 10868 ns/op 4709 B/op 303 allocs/op +BenchmarkFmt/Colored-nf=16-12 33309 36225 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 33093 37350 ns/op 14384 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 32305 37010 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 32649 37053 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 33194 36146 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 33139 36181 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 33471 39460 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 32377 36778 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 32793 36540 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/Colored-nf=16-12 33226 36042 ns/op 14385 B/op 1024 allocs/op +BenchmarkFmt/nf=1-12 3228714 366.9 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3217460 374.9 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3219823 370.4 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3256626 367.3 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3231498 368.7 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3286234 369.1 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3221338 370.1 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3158478 375.5 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3192966 374.9 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=1-12 3212212 372.8 ns/op 224 B/op 12 allocs/op +BenchmarkFmt/nf=4-12 1334484 921.6 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1316500 903.2 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1330128 897.0 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1333930 898.4 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1331115 892.0 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1345486 900.4 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1352221 880.5 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1356229 897.1 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1341136 885.3 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=4-12 1344148 905.6 ns/op 496 B/op 31 allocs/op +BenchmarkFmt/nf=16-12 415588 2850 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 417280 2866 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 424370 2876 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 421772 2836 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 424786 2883 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 407095 2856 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 429909 2840 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 427279 2921 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 403155 2945 ns/op 1328 B/op 104 allocs/op +BenchmarkFmt/nf=16-12 419020 2878 ns/op 1328 B/op 104 allocs/op +PASS +ok cdr.dev/slog/internal/entryhuman 91.606s diff --git a/internal/entryhuman/out.txt b/internal/entryhuman/out.txt new file mode 100644 index 0000000..189af87 --- /dev/null +++ b/internal/entryhuman/out.txt @@ -0,0 +1,241 @@ +diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go +index d11db4f..14bb884 100644 +--- a/internal/entryhuman/entry.go ++++ b/internal/entryhuman/entry.go +@@ -282,57 +282,37 @@ func Fmt( + + // OptimizedFmt 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 neceesary than for an arbitrary io.Writer/io.StringWriter ++// if necessary than for an arbitrary io.Writer/io.StringWriter ++// Note that while bytes.Buffer can in theory return an error for writes, it only does so if the buffer size will ++// exceed our architectures max integer size. If the system is actually OOM and more memory cannot be allocated ++// it will panic instead. + // + // We never return with a trailing newline because Go's testing framework adds one + // automatically and if we include one, then we'll get two newlines. + // We also do not indent the fields as go's test does that automatically + // 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 OptimizedFmt( +- buf *bytes.Buffer, +- termW io.Writer, +- ent slog.SinkEntry, +-) error { +- writeString := func(s string) error { +- _, err := buf.WriteString(s) +- return err +- } +- ++func OptimizedFmt(buf *bytes.Buffer, termW io.Writer, ent slog.SinkEntry) { + reset(buf, termW) + + // Timestamp + space +- if err := writeString(render(termW, timeStyle, ent.Time.Format(TimeFormat))); err != nil { +- return err +- } +- if err := writeString(" "); err != nil { +- return err +- } ++ buf.WriteString(render(termW, timeStyle, ent.Time.Format(TimeFormat)+" ")) ++ buf.WriteString("") + + // Level label + two spaces + lvl := bracketedLevel(ent.Level) // e.g. "[debu]", "[info]" +- if err := writeString(render(termW, levelStyle(ent.Level), lvl)); err != nil { +- return err +- } +- if err := writeString(" "); err != nil { +- return err +- } ++ buf.WriteString(render(termW, levelStyle(ent.Level), lvl)) ++ buf.WriteString("") + + // Logger names: name1.name2.name3: (no strings.Join allocation) + if len(ent.LoggerNames) > 0 { + for i, name := range ent.LoggerNames { + if i > 0 { +- if err := writeString("."); err != nil { +- return err +- } +- } +- if err := writeString(quoteKey(name)); err != nil { +- return err ++ buf.WriteString(".") + } ++ buf.WriteString(quoteKey(name)) + } +- if err := writeString(": "); err != nil { +- return err +- } ++ buf.WriteString(": ") + } + + // Message (detect multiline) +@@ -344,40 +324,22 @@ func OptimizedFmt( + multilineVal = msg + msg = quote("...") + } +- if err := writeString(msg); err != nil { +- return err +- } ++ buf.WriteString(msg) + + keyStyle := timeStyle + equalsStyle := timeStyle + + // Write trace/span directly (do not mutate ent.Fields) + if ent.SpanContext.IsValid() { +- if err := writeString(tab); err != nil { +- return err +- } +- if err := writeString(render(termW, keyStyle, quoteKey("trace"))); err != nil { +- return err +- } +- if err := writeString(render(termW, equalsStyle, "=")); err != nil { +- return err +- } +- if err := writeString(ent.SpanContext.TraceID().String()); err != nil { +- return err +- } ++ buf.WriteString(tab) + +- if err := writeString(tab); err != nil { +- return err +- } +- if err := writeString(render(termW, keyStyle, quoteKey("span"))); err != nil { +- return err +- } +- if err := writeString(render(termW, equalsStyle, "=")); err != nil { +- return err +- } +- if err := writeString(ent.SpanContext.SpanID().String()); err != nil { +- return err +- } ++ buf.WriteString(render(termW, keyStyle, quoteKey("trace"))) ++ buf.WriteString(render(termW, equalsStyle, "=")) ++ buf.WriteString(ent.SpanContext.TraceID().String()) ++ buf.WriteString(tab) ++ buf.WriteString(render(termW, keyStyle, quoteKey("span"))) ++ buf.WriteString(render(termW, equalsStyle, "=")) ++ buf.WriteString(ent.SpanContext.SpanID().String()) + } + + // Find a multiline field without mutating ent.Fields. +@@ -409,84 +371,55 @@ func OptimizedFmt( + continue + } + if i < len(ent.Fields) { +- if err := writeString(tab); err != nil { +- return err +- } +- } +- if err := writeString(render(termW, keyStyle, quoteKey(f.Name))); err != nil { +- return err +- } +- if err := writeString(render(termW, equalsStyle, "=")); err != nil { +- return err ++ buf.WriteString(tab) + } + ++ buf.WriteString(render(termW, keyStyle, quoteKey(f.Name))) ++ buf.WriteString(render(termW, equalsStyle, "=")) ++ + if ok, err := writeValueFast(buf, f.Value); err != nil { +- return err ++ // return err + } else if !ok { +- if err := writeString(formatValue(f.Value)); err != nil { +- return err +- } ++ buf.WriteString(formatValue(f.Value)) + } + } + + // Multiline value block + if multilineVal != "" { + if msg != "..." { +- if err := writeString(" ..."); err != nil { +- return err +- } ++ buf.WriteString(" ...") + } + +- if err := writeString("\n"); err != nil { +- return err +- } +- if err := writeString(render(termW, keyStyle, multilineKey)); err != nil { +- return err +- } +- if err := writeString("= "); err != nil { +- return err +- } ++ buf.WriteString("\n") ++ buf.WriteString(render(termW, keyStyle, multilineKey)) ++ buf.WriteString("= ") + + // First line up to first newline + s := multilineVal + if n := strings.IndexByte(s, '\n'); n >= 0 { +- if err := writeString(s[:n]); err != nil { +- return err +- } ++ buf.WriteString(s[:n]) + s = s[n+1:] + } else { +- if err := writeString(s); err != nil { +- return err +- } ++ buf.WriteString(s) + s = "" + } + + indent := strings.Repeat(" ", len(multilineKey)+2) + for len(s) > 0 { +- if err := writeString("\n"); err != nil { +- return err +- } ++ buf.WriteString("\n") + // Only indent non-empty lines. + if s[0] != '\n' { +- if err := writeString(indent); err != nil { +- return err +- } ++ buf.WriteString(indent) + } + if n := strings.IndexByte(s, '\n'); n >= 0 { +- if err := writeString(s[:n]); err != nil { +- return err +- } ++ buf.WriteString(s[:n]) + s = s[n+1:] + } else { +- if err := writeString(s); err != nil { +- return err +- } ++ buf.WriteString(s) + break + } + } + } +- +- return nil + } + + var ( +diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go +index b791b6d..87e3435 100644 +--- a/internal/entryhuman/entry_test.go ++++ b/internal/entryhuman/entry_test.go +@@ -411,10 +411,7 @@ func TestEntry_Optimized(t *testing.T) { + var optBuf bytes.Buffer + + entryhuman.Fmt(&fmtBuf, io.Discard, tc.ent) +- err := entryhuman.OptimizedFmt(&optBuf, io.Discard, tc.ent) +- if err != nil { +- t.Fatal(err) +- } ++ entryhuman.OptimizedFmt(&optBuf, io.Discard, tc.ent) + + assert.Equal(t, "outputs match", fmtBuf.String(), optBuf.String()) + }) diff --git a/internal/entryhuman/testdata/allLogLevels.golden b/internal/entryhuman/testdata/allLogLevels.golden new file mode 100644 index 0000000..2745e93 --- /dev/null +++ b/internal/entryhuman/testdata/allLogLevels.golden @@ -0,0 +1 @@ +2000-02-05 04:04:04.000 [crit] critical \ No newline at end of file diff --git a/internal/entryhuman/testdata/fatalLevel.golden b/internal/entryhuman/testdata/fatalLevel.golden new file mode 100644 index 0000000..20ab42d --- /dev/null +++ b/internal/entryhuman/testdata/fatalLevel.golden @@ -0,0 +1 @@ +2000-02-05 04:04:04.000 [fata] fatal \ No newline at end of file diff --git a/internal/entryhuman/testdata/mixedPrimitiveAndComplex.golden b/internal/entryhuman/testdata/mixedPrimitiveAndComplex.golden new file mode 100644 index 0000000..bc456ce --- /dev/null +++ b/internal/entryhuman/testdata/mixedPrimitiveAndComplex.golden @@ -0,0 +1 @@ +2000-02-05 04:04:04.000 [debu] mixed types count=100 name=test enabled=true ratio=0.95 data="bytes" nil_val= \ No newline at end of file diff --git a/internal/entryhuman/testdata/primitiveEdgeCases.golden b/internal/entryhuman/testdata/primitiveEdgeCases.golden new file mode 100644 index 0000000..6a07d08 --- /dev/null +++ b/internal/entryhuman/testdata/primitiveEdgeCases.golden @@ -0,0 +1 @@ +2000-02-05 04:04:04.000 [warn] edge cases zero_int=0 neg_int=-999 max_int64=9223372036854775807 min_int64=-9223372036854775808 max_uint64=18446744073709551615 zero_float=0 neg_float=-123.456 \ No newline at end of file diff --git a/internal/entryhuman/testdata/primitiveTypes.golden b/internal/entryhuman/testdata/primitiveTypes.golden new file mode 100644 index 0000000..cb68693 --- /dev/null +++ b/internal/entryhuman/testdata/primitiveTypes.golden @@ -0,0 +1 @@ +2000-02-05 04:04:04.000 [info] primitives bool_true=true bool_false=false int=42 int8=-8 int16=-16 int32=-32 int64=-64 uint=42 uint8=8 uint16=16 uint32=32 uint64=64 float32=3.14 float64=2.71828 \ No newline at end of file diff --git a/sloggers/sloghuman/sloghuman.go b/sloggers/sloghuman/sloghuman.go index 8cc36ec..f6754c5 100644 --- a/sloggers/sloghuman/sloghuman.go +++ b/sloggers/sloghuman/sloghuman.go @@ -41,7 +41,7 @@ func (s humanSink) LogEntry(ctx context.Context, ent slog.SinkEntry) { buf1.Reset() defer bufPool.Put(buf1) - entryhuman.OptimizedFmt(buf1, s.w2, ent) + entryhuman.Fmt(buf1, s.w2, ent) by := buf1.Bytes() // Prepare output buffer and indent lines after the first. diff --git a/sloggers/sloghuman/sloghuman_bench_test.go b/sloggers/sloghuman/sloghuman_bench_test.go index 971372d..0601320 100644 --- a/sloggers/sloghuman/sloghuman_bench_test.go +++ b/sloggers/sloghuman/sloghuman_bench_test.go @@ -12,7 +12,6 @@ import ( "cdr.dev/slog" "cdr.dev/slog/internal/entryhuman" "cdr.dev/slog/sloggers/sloghuman" - "go.opentelemetry.io/otel/trace" ) func multiline(n int) string { @@ -27,81 +26,70 @@ func multiline(n int) string { } // Benchmarks target the human sink path: humanSink.LogEntry -> entryhuman.Fmt -> bufio.Scanner indent. -func BenchmarkHumanSinkLogEntry_SingleLine(b *testing.B) { +func BenchmarkHumanSinkLogEntry(b *testing.B) { s := sloghuman.Sink(io.Discard) - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Message: "hello world", - Fields: slog.M( - slog.F("k1", "v1"), - slog.F("k2", 123), - ), + testcases := []struct { + name string + entry slog.SinkEntry + }{ + { + "SingleLine", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "hello world", + Fields: slog.M( + slog.F("k1", "v1"), + slog.F("k2", 123), + ), + }, + }, + { + "MultiLineFieldSmall", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", multiline(10)), // forces multiline field handling in Fmt + ), + }, + }, + { + "MultilineMultifieldLarge", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", multiline(1000)), + ), + }, + }, + { + "MultilineMessage", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "line1\nline2\nline3\nline4\nline5", + Fields: nil, + }, + }, + } + for _, tc := range testcases { + b.Run(tc.name, func(b *testing.B) { + ctx := context.Background() + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + s.LogEntry(ctx, tc.entry) + } + }) } - ctx := context.Background() - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - s.LogEntry(ctx, ent) - } -} - -func BenchmarkHumanSinkLogEntry_MultilineField_Small(b *testing.B) { - s := sloghuman.Sink(io.Discard) - ml := multiline(10) - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Fields: slog.M( - slog.F("msg", "..."), - slog.F("stack", ml), // forces multiline field handling in Fmt - ), - } - ctx := context.Background() - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - s.LogEntry(ctx, ent) - } -} - -func BenchmarkHumanSinkLogEntry_MultilineField_Large(b *testing.B) { - s := sloghuman.Sink(io.Discard) - ml := multiline(1000) // many short lines; avoids Scanner token limit - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Fields: slog.M( - slog.F("msg", "..."), - slog.F("stack", ml), - ), - } - ctx := context.Background() - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - s.LogEntry(ctx, ent) - } -} -func BenchmarkHumanSinkLogEntry_MultilineMessage(b *testing.B) { - s := sloghuman.Sink(io.Discard) - msg := "line1\nline2\nline3\nline4\nline5" - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Message: msg, // triggers multiline message handling in Fmt - Fields: nil, - } - ctx := context.Background() - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - s.LogEntry(ctx, ent) - } } -func bmMultiline(n int) string { +func genMultiline(n int) string { var b strings.Builder b.Grow(n * 8) for i := 0; i < n; i++ { @@ -112,126 +100,91 @@ func bmMultiline(n int) string { return b.String() } -func BenchmarkFmt_SingleLine(b *testing.B) { - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Message: "hello world", - Fields: slog.M( - slog.F("k1", "v1"), - slog.F("k2", 123), - ), - } - w := io.Discard - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) - } -} - -func BenchmarkFmt_MultilineField_Small(b *testing.B) { - ml := bmMultiline(10) - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Fields: slog.M( - slog.F("msg", "..."), - slog.F("stack", ml), - ), - } - w := io.Discard - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) - } -} - -func BenchmarkFmt_MultilineField_Large(b *testing.B) { - ml := bmMultiline(1000) - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Fields: slog.M( - slog.F("msg", "..."), - slog.F("stack", ml), - ), - } - w := io.Discard - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) - } -} - -func BenchmarkFmt_MultilineMessage(b *testing.B) { - msg := "line1\nline2\nline3\nline4\nline5" - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Message: msg, - } - w := io.Discard - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) - } -} - -func BenchmarkFmt_WithNames(b *testing.B) { - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Message: "msg", - LoggerNames: []string{"svc", "sub", "component"}, - Fields: slog.M(slog.F("k", "v")), - } - w := io.Discard - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) - } -} - -func BenchmarkFmt_WithSpan(b *testing.B) { - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Message: "msg", - Fields: slog.M(slog.F("k", "v")), +func BenchmarkFmt(b *testing.B) { + testcases := []struct { + name string + entry slog.SinkEntry + }{ + { + "WithSpan", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "msg", + Fields: slog.M(slog.F("k", "v")), + }, + }, + { + "WithValidSpan", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "msg", + Fields: slog.M(slog.F("k", "v")), + }, + }, + { + "WithNames", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "msg", + LoggerNames: []string{"svc", "sub", "component"}, + Fields: slog.M(slog.F("k", "v")), + }, + }, + { + "SingleLine", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "hello world", + Fields: slog.M( + slog.F("k1", "v1"), + slog.F("k2", 123), + ), + }, + }, + { + "MultilineMsg", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Message: "line1\nline2\nline3\nline4\nline5", + }, + }, + { + "MultilineMultifieldSmall", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", genMultiline(10)), + ), + }, + }, + { + "MultilineMultifieldLarge", + slog.SinkEntry{ + Time: time.Unix(0, 0), + Level: slog.LevelInfo, + Fields: slog.M( + slog.F("msg", "..."), + slog.F("stack", genMultiline(1000)), + ), + }, + }, + } + for _, tc := range testcases { + b.Run(tc.name, func(b *testing.B) { + w := io.Discard + b.ReportAllocs() + b.ResetTimer() + for i := 0; i < b.N; i++ { + entryhuman.Fmt(bytes.NewBuffer(nil), w, tc.entry) + } + }) } - w := io.Discard - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) - } -} -func BenchmarkFmt_WithValidSpan(b *testing.B) { - ent := slog.SinkEntry{ - Time: time.Unix(0, 0), - Level: slog.LevelInfo, - Message: "msg", - Fields: slog.M(slog.F("k", "v")), - } - // Create a valid SpanContext - tid := trace.TraceID{1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16} - sid := trace.SpanID{1, 2, 3, 4, 5, 6, 7, 8} - ent.SpanContext = trace.NewSpanContext(trace.SpanContextConfig{ - TraceID: tid, - SpanID: sid, - TraceFlags: trace.FlagsSampled, - }) - - w := io.Discard - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - entryhuman.OptimizedFmt(bytes.NewBuffer(nil), w, ent) - } } diff --git a/sloggers/slogtest/t.go b/sloggers/slogtest/t.go index b1fbc86..8c0f328 100644 --- a/sloggers/slogtest/t.go +++ b/sloggers/slogtest/t.go @@ -6,11 +6,11 @@ package slogtest // import "cdr.dev/slog/sloggers/slogtest" import ( + "bytes" "context" "fmt" "log" "os" - "strings" "sync" "testing" @@ -97,7 +97,7 @@ func (ts *testSink) LogEntry(_ context.Context, ent slog.SinkEntry) { return } - var sb strings.Builder + var sb bytes.Buffer // The testing package logs to stdout and not stderr. entryhuman.Fmt(&sb, os.Stdout, ent) From 5838eb4b2232f3a52dfeebac656a98d580f75652 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Thu, 13 Nov 2025 11:41:42 -0800 Subject: [PATCH 8/8] fix ci fmt issue Signed-off-by: Callum Styan --- sloggers/sloghuman/sloghuman_bench_test.go | 2 -- 1 file changed, 2 deletions(-) diff --git a/sloggers/sloghuman/sloghuman_bench_test.go b/sloggers/sloghuman/sloghuman_bench_test.go index 0601320..b52e6ff 100644 --- a/sloggers/sloghuman/sloghuman_bench_test.go +++ b/sloggers/sloghuman/sloghuman_bench_test.go @@ -86,7 +86,6 @@ func BenchmarkHumanSinkLogEntry(b *testing.B) { } }) } - } func genMultiline(n int) string { @@ -186,5 +185,4 @@ func BenchmarkFmt(b *testing.B) { } }) } - }