From: Joe Tsai Date: Thu, 2 Feb 2023 02:18:57 +0000 (-0800) Subject: log: make use of fmt.Append functionality X-Git-Tag: go1.21rc1~1644 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=2da8a55584aa65ce1b67431bb8ecebf66229d462;p=gostls13.git log: make use of fmt.Append functionality Since log is already responsible for managing its own buffers it is unfortunate that it calls fmt.Sprintf, which allocates, only to append that intermediate string to another buffer. Instead, use the new fmt.Append variants and avoid the allocation. We modify Logger.Output to wrap an internal Logger.output, which can be configured to use a particular append function. Logger.output is called from all the other functionality instead. This has the further advantage of simplifying the isDiscard check, which occurs to avoid the costly fmt.Print call. We coalesce all 6 checks as just 1 check in Logger.output. Also, swap the declaration order of Logger.Print and Logger.Printf to match the ordering elsewhere in the file. Performance: name old time/op new time/op delta Println 188ns ± 2% 172ns ± 4% -8.39% (p=0.000 n=10+10) PrintlnNoFlags 139ns ± 1% 116ns ± 1% -16.71% (p=0.000 n=9+9) name old allocs/op new allocs/op delta Println 1.00 ± 0% 0.00 -100.00% (p=0.000 n=10+10) PrintlnNoFlags 1.00 ± 0% 0.00 -100.00% (p=0.000 n=10+10) Change-Id: I79d0ee404df848beb3626fe863ccc73a3e2eb325 Reviewed-on: https://go-review.googlesource.com/c/go/+/464345 Reviewed-by: Rob Pike Reviewed-by: Ian Lance Taylor Reviewed-by: Bryan Mills Run-TryBot: Joseph Tsai TryBot-Result: Gopher Robot --- diff --git a/src/log/log.go b/src/log/log.go index 9e38b6ed69..78458c19f3 100644 --- a/src/log/log.go +++ b/src/log/log.go @@ -190,6 +190,17 @@ func putBuffer(p *[]byte) { // provided for generality, although at the moment on all pre-defined // paths it will be 2. func (l *Logger) Output(calldepth int, s string) error { + calldepth++ // +1 for this frame. + return l.output(calldepth, func(b []byte) []byte { + return append(b, s...) + }) +} + +func (l *Logger) output(calldepth int, appendOutput func([]byte) []byte) error { + if l.isDiscard.Load() { + return nil + } + now := time.Now() // get this early. // Load prefix and flag once so that their value is consistent within @@ -211,7 +222,9 @@ func (l *Logger) Output(calldepth int, s string) error { buf := getBuffer() defer putBuffer(buf) formatHeader(buf, now, prefix, flag, file, line) - *buf = append(*buf, s...) + headerLen := len(*buf) + *buf = appendOutput(*buf) + s := (*buf)[headerLen:] if len(s) == 0 || s[len(s)-1] != '\n' { *buf = append(*buf, '\n') } @@ -222,31 +235,28 @@ func (l *Logger) Output(calldepth int, s string) error { return err } -// Printf calls l.Output to print to the logger. -// Arguments are handled in the manner of fmt.Printf. -func (l *Logger) Printf(format string, v ...any) { - if l.isDiscard.Load() { - return - } - l.Output(2, fmt.Sprintf(format, v...)) -} - // Print calls l.Output to print to the logger. // Arguments are handled in the manner of fmt.Print. func (l *Logger) Print(v ...any) { - if l.isDiscard.Load() { - return - } - l.Output(2, fmt.Sprint(v...)) + l.output(2, func(b []byte) []byte { + return fmt.Append(b, v...) + }) +} + +// Printf calls l.Output to print to the logger. +// Arguments are handled in the manner of fmt.Printf. +func (l *Logger) Printf(format string, v ...any) { + l.output(2, func(b []byte) []byte { + return fmt.Appendf(b, format, v...) + }) } // Println calls l.Output to print to the logger. // Arguments are handled in the manner of fmt.Println. func (l *Logger) Println(v ...any) { - if l.isDiscard.Load() { - return - } - l.Output(2, fmt.Sprintln(v...)) + l.output(2, func(b []byte) []byte { + return fmt.Appendln(b, v...) + }) } // Fatal is equivalent to l.Print() followed by a call to os.Exit(1). @@ -357,28 +367,25 @@ func Writer() io.Writer { // Print calls Output to print to the standard logger. // Arguments are handled in the manner of fmt.Print. func Print(v ...any) { - if std.isDiscard.Load() { - return - } - std.Output(2, fmt.Sprint(v...)) + std.output(2, func(b []byte) []byte { + return fmt.Append(b, v...) + }) } // Printf calls Output to print to the standard logger. // Arguments are handled in the manner of fmt.Printf. func Printf(format string, v ...any) { - if std.isDiscard.Load() { - return - } - std.Output(2, fmt.Sprintf(format, v...)) + std.output(2, func(b []byte) []byte { + return fmt.Appendf(b, format, v...) + }) } // Println calls Output to print to the standard logger. // Arguments are handled in the manner of fmt.Println. func Println(v ...any) { - if std.isDiscard.Load() { - return - } - std.Output(2, fmt.Sprintln(v...)) + std.output(2, func(b []byte) []byte { + return fmt.Appendln(b, v...) + }) } // Fatal is equivalent to Print() followed by a call to os.Exit(1). diff --git a/src/log/log_test.go b/src/log/log_test.go index c212b60554..ea7e7917b8 100644 --- a/src/log/log_test.go +++ b/src/log/log_test.go @@ -217,6 +217,7 @@ func BenchmarkPrintln(b *testing.B) { const testString = "test" var buf bytes.Buffer l := New(&buf, "", LstdFlags) + b.ReportAllocs() for i := 0; i < b.N; i++ { buf.Reset() l.Println(testString) @@ -227,6 +228,7 @@ func BenchmarkPrintlnNoFlags(b *testing.B) { const testString = "test" var buf bytes.Buffer l := New(&buf, "", 0) + b.ReportAllocs() for i := 0; i < b.N; i++ { buf.Reset() l.Println(testString) @@ -255,3 +257,11 @@ func BenchmarkConcurrent(b *testing.B) { } group.Wait() } + +func BenchmarkDiscard(b *testing.B) { + l := New(io.Discard, "", LstdFlags|Lshortfile) + b.ReportAllocs() + for i := 0; i < b.N; i++ { + l.Printf("processing %d objects from bucket %q", 1234, "fizzbuzz") + } +}