Merge pull request #43662 from vvoland/fix-logs-regression2

daemon/logger: Driver-scope buffer pools, bigger buffers

daemon/logger/jsonfilelog/jsonfilelog.go

@@ -20,12 +20,18 @@ import (
 // Name is the name of the file that the jsonlogger logs to.
 const Name = "json-file"
 
+// Every buffer will have to store the same constant json structure with the message
+// len(`{"log":"","stream:"stdout","time":"2000-01-01T00:00:00.000000000Z"}\n`) = 68.
+// So let's start with a buffer bigger than this.
+const initialBufSize = 256
+
+var buffersPool = sync.Pool{New: func() interface{} { return bytes.NewBuffer(make([]byte, 0, initialBufSize)) }}
+
 // JSONFileLogger is Logger implementation for default Docker logging.
 type JSONFileLogger struct {
-	writer      *loggerutils.LogFile
-	tag         string // tag values requested by the user to log
-	extra       json.RawMessage
-	buffersPool sync.Pool
+	writer *loggerutils.LogFile
+	tag    string // tag values requested by the user to log
+	extra  json.RawMessage
 }
 
 func init() {
@@ -104,34 +110,27 @@ func New(info logger.Info) (logger.Logger, error) {
 	}
 
 	return &JSONFileLogger{
-		writer:      writer,
-		tag:         tag,
-		extra:       extra,
-		buffersPool: makePool(),
+		writer: writer,
+		tag:    tag,
+		extra:  extra,
 	}, nil
 }
 
-func makePool() sync.Pool {
-	// Every buffer will have to store the same constant json structure and the message
-	// len(`{"log":"","stream:"stdout","time":"2000-01-01T00:00:00.000000000Z"}\n`) = 68
-	// So let's start with a buffer bigger than this
-	const initialBufSize = 128
-
-	return sync.Pool{New: func() interface{} { return bytes.NewBuffer(make([]byte, 0, initialBufSize)) }}
-}
-
 // Log converts logger.Message to jsonlog.JSONLog and serializes it to file.
 func (l *JSONFileLogger) Log(msg *logger.Message) error {
-	defer logger.PutMessage(msg)
-	buf := l.buffersPool.Get().(*bytes.Buffer)
+	buf := buffersPool.Get().(*bytes.Buffer)
 	buf.Reset()
-	defer l.buffersPool.Put(buf)
+	defer buffersPool.Put(buf)
+
+	timestamp := msg.Timestamp
+	err := marshalMessage(msg, l.extra, buf)
+	logger.PutMessage(msg)
 
-	if err := marshalMessage(msg, l.extra, buf); err != nil {
+	if err != nil {
 		return err
 	}
 
-	return l.writer.WriteLogEntry(msg.Timestamp, buf.Bytes())
+	return l.writer.WriteLogEntry(timestamp, buf.Bytes())
 }
 
 func marshalMessage(msg *logger.Message, extra json.RawMessage, buf *bytes.Buffer) error {

daemon/logger/local/local.go

@@ -3,6 +3,7 @@ package local // import "github.com/docker/docker/daemon/logger/local"
 import (
 	"encoding/binary"
 	"io"
+	"math/bits"
 	"strconv"
 	"sync"
 	"time"
@@ -29,6 +30,11 @@ const (
 	defaultCompressLogs       = true
 )
 
+var buffersPool = sync.Pool{New: func() interface{} {
+	b := make([]byte, initialBufSize)
+	return &b
+}}
+
 // LogOptKeys are the keys names used for log opts passed in to initialize the driver.
 var LogOptKeys = map[string]bool{
 	"max-file": true,
@@ -56,8 +62,7 @@ func init() {
 }
 
 type driver struct {
-	logfile     *loggerutils.LogFile
-	buffersPool sync.Pool
+	logfile *loggerutils.LogFile
 }
 
 // New creates a new local logger
@@ -106,7 +111,11 @@ func marshal(m *logger.Message, buffer *[]byte) error {
 
 	buf := *buffer
 	if writeLen > cap(buf) {
-		buf = make([]byte, writeLen)
+		// If we already need to reallocate the buffer, make it larger to be more reusable.
+		// Round to the next power of two.
+		capacity := 1 << (bits.Len(uint(writeLen)) + 1)
+
+		buf = make([]byte, writeLen, capacity)
 	} else {
 		buf = buf[:writeLen]
 	}
@@ -135,10 +144,6 @@ func newDriver(logPath string, cfg *CreateConfig) (logger.Logger, error) {
 	}
 	return &driver{
 		logfile: lf,
-		buffersPool: sync.Pool{New: func() interface{} {
-			b := make([]byte, initialBufSize)
-			return &b
-		}},
 	}, nil
 }
 
@@ -147,15 +152,17 @@ func (d *driver) Name() string {
 }
 
 func (d *driver) Log(msg *logger.Message) error {
-	defer logger.PutMessage(msg)
-	buf := d.buffersPool.Get().(*[]byte)
-	defer d.buffersPool.Put(buf)
+	buf := buffersPool.Get().(*[]byte)
+	defer buffersPool.Put(buf)
 
+	timestamp := msg.Timestamp
 	err := marshal(msg, buf)
+	logger.PutMessage(msg)
+
 	if err != nil {
 		return errors.Wrap(err, "error marshalling logger.Message")
 	}
-	return d.logfile.WriteLogEntry(msg.Timestamp, *buf)
+	return d.logfile.WriteLogEntry(timestamp, *buf)
 }
 
 func (d *driver) Close() error {