buffer: use sync.Pool

This simplifies the code. Instead of different instances, the package now
maintains a global pool. This makes the text logger struct a bit smaller and
thus cheaper to copy in the With* functions.

Performance is about the same as before:

name              old time/op    new time/op    delta
Header-36           1.68µs ± 7%    1.62µs ± 6%   ~     (p=0.246 n=5+5)
HeaderWithDir-36    1.63µs ± 6%    1.59µs ± 6%   ~     (p=0.690 n=5+5)

name              old alloc/op   new alloc/op   delta
Header-36             216B ± 0%      216B ± 0%   ~     (all equal)
HeaderWithDir-36      216B ± 0%      216B ± 0%   ~     (all equal)

name              old allocs/op  new allocs/op  delta
Header-36             2.00 ± 0%      2.00 ± 0%   ~     (all equal)
HeaderWithDir-36      2.00 ± 0%      2.00 ± 0%   ~     (all equal)

The text logger didn't actually return the buffer. Now it does.

Author: pohly

internal/buffer/buffer.go

@@ -40,44 +40,22 @@ type Buffer struct {
 	next *Buffer
 }
 
-// Buffers manages the reuse of individual buffer instances. It is thread-safe.
-type Buffers struct {
-	// mu protects the free list. It is separate from the main mutex
-	// so buffers can be grabbed and printed to without holding the main lock,
-	// for better parallelization.
-	mu sync.Mutex
-
-	// freeList is a list of byte buffers, maintained under mu.
-	freeList *Buffer
+var buffers = sync.Pool{
+	New: func() interface{} {
+		return new(Buffer)
+	},
 }
 
 // GetBuffer returns a new, ready-to-use buffer.
-func (bl *Buffers) GetBuffer() *Buffer {
-	bl.mu.Lock()
-	b := bl.freeList
-	if b != nil {
-		bl.freeList = b.next
-	}
-	bl.mu.Unlock()
-	if b == nil {
-		b = new(Buffer)
-	} else {
-		b.next = nil
-		b.Reset()
-	}
+func GetBuffer() *Buffer {
+	b := buffers.Get().(*Buffer)
+	b.Reset()
 	return b
 }
 
 // PutBuffer returns a buffer to the free list.
-func (bl *Buffers) PutBuffer(b *Buffer) {
-	if b.Len() >= 256 {
-		// Let big buffers die a natural death.
-		return
-	}
-	bl.mu.Lock()
-	b.next = bl.freeList
-	bl.freeList = b
-	bl.mu.Unlock()
+func PutBuffer(b *Buffer) {
+	buffers.Put(b)
 }
 
 // Some custom tiny helper functions to print the log header efficiently.

klog.go

@@ -532,11 +532,6 @@ func (s settings) deepCopy() settings {
 type loggingT struct {
 	settings
 
-	// bufferCache maintains the free list. It uses its own mutex
-	// so buffers can be grabbed and printed to without holding the main lock,
-	// for better parallelization.
-	bufferCache buffer.Buffers
-
 	// flushD holds a flushDaemon that frequently flushes log file buffers.
 	// Uses its own mutex.
 	flushD *flushDaemon
@@ -664,7 +659,7 @@ func (l *loggingT) header(s severity.Severity, depth int) (*buffer.Buffer, strin
 
 // formatHeader formats a log header using the provided file name and line number.
 func (l *loggingT) formatHeader(s severity.Severity, file string, line int) *buffer.Buffer {
-	buf := l.bufferCache.GetBuffer()
+	buf := buffer.GetBuffer()
 	if l.skipHeaders {
 		return buf
 	}
@@ -682,8 +677,8 @@ func (l *loggingT) printlnDepth(s severity.Severity, logger *logr.Logger, filter
 	// if logger is set, we clear the generated header as we rely on the backing
 	// logger implementation to print headers
 	if logger != nil {
-		l.bufferCache.PutBuffer(buf)
-		buf = l.bufferCache.GetBuffer()
+		buffer.PutBuffer(buf)
+		buf = buffer.GetBuffer()
 	}
 	if filter != nil {
 		args = filter.Filter(args)
@@ -701,8 +696,8 @@ func (l *loggingT) printDepth(s severity.Severity, logger *logr.Logger, filter L
 	// if logr is set, we clear the generated header as we rely on the backing
 	// logr implementation to print headers
 	if logger != nil {
-		l.bufferCache.PutBuffer(buf)
-		buf = l.bufferCache.GetBuffer()
+		buffer.PutBuffer(buf)
+		buf = buffer.GetBuffer()
 	}
 	if filter != nil {
 		args = filter.Filter(args)
@@ -723,8 +718,8 @@ func (l *loggingT) printfDepth(s severity.Severity, logger *logr.Logger, filter
 	// if logr is set, we clear the generated header as we rely on the backing
 	// logr implementation to print headers
 	if logger != nil {
-		l.bufferCache.PutBuffer(buf)
-		buf = l.bufferCache.GetBuffer()
+		buffer.PutBuffer(buf)
+		buf = buffer.GetBuffer()
 	}
 	if filter != nil {
 		format, args = filter.FilterF(format, args)
@@ -744,8 +739,8 @@ func (l *loggingT) printWithFileLine(s severity.Severity, logger *logr.Logger, f
 	// if logr is set, we clear the generated header as we rely on the backing
 	// logr implementation to print headers
 	if logger != nil {
-		l.bufferCache.PutBuffer(buf)
-		buf = l.bufferCache.GetBuffer()
+		buffer.PutBuffer(buf)
+		buf = buffer.GetBuffer()
 	}
 	if filter != nil {
 		args = filter.Filter(args)
@@ -785,7 +780,7 @@ func (l *loggingT) infoS(logger *logr.Logger, filter LogFilter, depth int, msg s
 // set log severity by s
 func (l *loggingT) printS(err error, s severity.Severity, depth int, msg string, keysAndValues ...interface{}) {
 	// Only create a new buffer if we don't have one cached.
-	b := l.bufferCache.GetBuffer()
+	b := buffer.GetBuffer()
 	// The message is always quoted, even if it contains line breaks.
 	// If developers want multi-line output, they should use a small, fixed
 	// message and put the multi-line output into a value.
@@ -796,7 +791,7 @@ func (l *loggingT) printS(err error, s severity.Severity, depth int, msg string,
 	serialize.KVListFormat(&b.Buffer, keysAndValues...)
 	l.printDepth(s, logging.logger, nil, depth+1, &b.Buffer)
 	// Make the buffer available for reuse.
-	l.bufferCache.PutBuffer(b)
+	buffer.PutBuffer(b)
 }
 
 // redirectBuffer is used to set an alternate destination for the logs
@@ -948,7 +943,7 @@ func (l *loggingT) output(s severity.Severity, log *logr.Logger, buf *buffer.Buf
 		timeoutFlush(ExitFlushTimeout)
 		OsExit(255) // C++ uses -1, which is silly because it's anded with 255 anyway.
 	}
-	l.bufferCache.PutBuffer(buf)
+	buffer.PutBuffer(buf)
 
 	if stats := severityStats[s]; stats != nil {
 		atomic.AddInt64(&stats.lines, 1)

klog_test.go

@@ -623,15 +623,15 @@ func TestLogBacktraceAt(t *testing.T) {
 func BenchmarkHeader(b *testing.B) {
 	for i := 0; i < b.N; i++ {
 		buf, _, _ := logging.header(severity.InfoLog, 0)
-		logging.bufferCache.PutBuffer(buf)
+		buffer.PutBuffer(buf)
 	}
 }
 
 func BenchmarkHeaderWithDir(b *testing.B) {
 	logging.addDirHeader = true
 	for i := 0; i < b.N; i++ {
 		buf, _, _ := logging.header(severity.InfoLog, 0)
-		logging.bufferCache.PutBuffer(buf)
+		buffer.PutBuffer(buf)
 	}
 }
 

textlogger/textlogger.go

@@ -56,19 +56,17 @@ var (
 // later release. The behavior of the returned Logger may change.
 func NewLogger(c *Config) logr.Logger {
 	return logr.New(&tlogger{
-		prefix:      "",
-		values:      nil,
-		config:      c,
-		bufferCache: &buffer.Buffers{},
+		prefix: "",
+		values: nil,
+		config: c,
 	})
 }
 
 type tlogger struct {
-	callDepth   int
-	prefix      string
-	values      []interface{}
-	config      *Config
-	bufferCache *buffer.Buffers
+	callDepth int
+	prefix    string
+	values    []interface{}
+	config    *Config
 }
 
 func copySlice(in []interface{}) []interface{} {
@@ -103,7 +101,8 @@ func (l *tlogger) Error(err error, msg string, kvList ...interface{}) {
 
 func (l *tlogger) print(err error, s severity.Severity, msg string, kvList []interface{}) {
 	// Only create a new buffer if we don't have one cached.
-	b := l.bufferCache.GetBuffer()
+	b := buffer.GetBuffer()
+	defer buffer.PutBuffer(b)
 
 	// Determine caller.
 	// +1 for this frame, +1 for Info/Error.