Browse code

Implement optional ring buffer for container logs

This allows the user to set a logging mode to "blocking" (default), or
"non-blocking", which uses the ring buffer as a proxy to the real log
driver.

This allows a container to never be blocked on stdio at the cost of
dropping log messages.

Introduces 2 new log-opts that works for all drivers, `log-mode` and
`log-size`. `log-mode` takes a value of "blocking", or "non-blocking"
I chose not to implement this as a bool since it is difficult to
determine if the mode was set to false vs just not set... especially
difficult when merging the default daemon config with the container config.
`log-size` takes a size string, e.g. `2MB`, which sets the max size
of the ring buffer. When the max size is reached, it will start
dropping log messages.

```
BenchmarkRingLoggerThroughputNoReceiver-8 2000000000 36.2 ns/op 856.35 MB/s 0 B/op 0 allocs/op
BenchmarkRingLoggerThroughputWithReceiverDelay0-8 300000000 156 ns/op 198.48 MB/s 32 B/op 0 allocs/op
BenchmarkRingLoggerThroughputConsumeDelay1-8 2000000000 36.1 ns/op 857.80 MB/s 0 B/op 0 allocs/op
BenchmarkRingLoggerThroughputConsumeDelay10-8 1000000000 36.2 ns/op 856.53 MB/s 0 B/op 0 allocs/op
BenchmarkRingLoggerThroughputConsumeDelay50-8 2000000000 34.7 ns/op 894.65 MB/s 0 B/op 0 allocs/op
BenchmarkRingLoggerThroughputConsumeDelay100-8 2000000000 35.1 ns/op 883.91 MB/s 0 B/op 0 allocs/op
BenchmarkRingLoggerThroughputConsumeDelay300-8 1000000000 35.9 ns/op 863.90 MB/s 0 B/op 0 allocs/op
BenchmarkRingLoggerThroughputConsumeDelay500-8 2000000000 35.8 ns/op 866.88 MB/s 0 B/op 0 allocs/op
```

Signed-off-by: Brian Goff <cpuguy83@gmail.com>

Brian Goff authored on 2016/11/23 11:55:27
Showing 11 changed files
... ...
@@ -223,6 +223,17 @@ func (rp *RestartPolicy) IsSame(tp *RestartPolicy) bool {
223 223
 	return rp.Name == tp.Name && rp.MaximumRetryCount == tp.MaximumRetryCount
224 224
 }
225 225
 
226
+// LogMode is a type to define the available modes for logging
227
+// These modes affect how logs are handled when log messages start piling up.
228
+type LogMode string
229
+
230
+// Available logging modes
231
+const (
232
+	LogModeUnset            = ""
233
+	LogModeBlocking LogMode = "blocking"
234
+	LogModeNonBlock LogMode = "non-blocking"
235
+)
236
+
226 237
 // LogConfig represents the logging configuration of the container.
227 238
 type LogConfig struct {
228 239
 	Type   string
... ...
@@ -37,6 +37,7 @@ import (
37 37
 	"github.com/docker/docker/runconfig"
38 38
 	"github.com/docker/docker/volume"
39 39
 	"github.com/docker/go-connections/nat"
40
+	"github.com/docker/go-units"
40 41
 	"github.com/docker/libnetwork"
41 42
 	"github.com/docker/libnetwork/netlabel"
42 43
 	"github.com/docker/libnetwork/options"
... ...
@@ -316,7 +317,7 @@ func (container *Container) CheckpointDir() string {
316 316
 // StartLogger starts a new logger driver for the container.
317 317
 func (container *Container) StartLogger() (logger.Logger, error) {
318 318
 	cfg := container.HostConfig.LogConfig
319
-	c, err := logger.GetLogDriver(cfg.Type)
319
+	initDriver, err := logger.GetLogDriver(cfg.Type)
320 320
 	if err != nil {
321 321
 		return nil, fmt.Errorf("failed to get logging factory: %v", err)
322 322
 	}
... ...
@@ -341,7 +342,23 @@ func (container *Container) StartLogger() (logger.Logger, error) {
341 341
 			return nil, err
342 342
 		}
343 343
 	}
344
-	return c(info)
344
+
345
+	l, err := initDriver(info)
346
+	if err != nil {
347
+		return nil, err
348
+	}
349
+
350
+	if containertypes.LogMode(cfg.Config["mode"]) == containertypes.LogModeNonBlock {
351
+		bufferSize := int64(-1)
352
+		if s, exists := cfg.Config["max-buffer-size"]; exists {
353
+			bufferSize, err = units.RAMInBytes(s)
354
+			if err != nil {
355
+				return nil, err
356
+			}
357
+		}
358
+		l = logger.NewRingLogger(l, info, bufferSize)
359
+	}
360
+	return l, nil
345 361
 }
346 362
 
347 363
 // GetProcessLabel returns the process label for the container.
... ...
@@ -204,7 +204,7 @@ func (l *logStream) Log(msg *logger.Message) error {
204 204
 	defer l.lock.RUnlock()
205 205
 	if !l.closed {
206 206
 		// buffer up the data, making sure to copy the Line data
207
-		l.messages <- logger.CopyMessage(msg)
207
+		l.messages <- msg
208 208
 	}
209 209
 	return nil
210 210
 }
... ...
@@ -47,7 +47,6 @@ func (c *Copier) copySrc(name string, src io.Reader) {
47 47
 	buf := make([]byte, bufSize)
48 48
 	n := 0
49 49
 	eof := false
50
-	msg := &Message{Source: name}
51 50
 
52 51
 	for {
53 52
 		select {
... ...
@@ -78,13 +77,16 @@ func (c *Copier) copySrc(name string, src io.Reader) {
78 78
 			// Break up the data that we've buffered up into lines, and log each in turn.
79 79
 			p := 0
80 80
 			for q := bytes.Index(buf[p:n], []byte{'\n'}); q >= 0; q = bytes.Index(buf[p:n], []byte{'\n'}) {
81
-				msg.Line = buf[p : p+q]
82
-				msg.Timestamp = time.Now().UTC()
83
-				msg.Partial = false
84 81
 				select {
85 82
 				case <-c.closed:
86 83
 					return
87 84
 				default:
85
+					msg := &Message{
86
+						Source:    name,
87
+						Timestamp: time.Now().UTC(),
88
+					}
89
+					msg.Line = append(msg.Line, buf[p:p+q]...)
90
+
88 91
 					if logErr := c.dst.Log(msg); logErr != nil {
89 92
 						logrus.Errorf("Failed to log msg %q for logger %s: %s", msg.Line, c.dst.Name(), logErr)
90 93
 					}
... ...
@@ -96,9 +98,14 @@ func (c *Copier) copySrc(name string, src io.Reader) {
96 96
 			// noting that it's a partial log line.
97 97
 			if eof || (p == 0 && n == len(buf)) {
98 98
 				if p < n {
99
-					msg.Line = buf[p:n]
100
-					msg.Timestamp = time.Now().UTC()
99
+					msg := &Message{
100
+						Source:    name,
101
+						Timestamp: time.Now().UTC(),
102
+						Partial:   true,
103
+					}
104
+					msg.Line = append(msg.Line, buf[p:n]...)
101 105
 					msg.Partial = true
106
+
102 107
 					if logErr := c.dst.Log(msg); logErr != nil {
103 108
 						logrus.Errorf("Failed to log msg %q for logger %s: %s", msg.Line, c.dst.Name(), logErr)
104 109
 					}
... ...
@@ -3,6 +3,10 @@ package logger
3 3
 import (
4 4
 	"fmt"
5 5
 	"sync"
6
+
7
+	containertypes "github.com/docker/docker/api/types/container"
8
+	units "github.com/docker/go-units"
9
+	"github.com/pkg/errors"
6 10
 )
7 11
 
8 12
 // Creator builds a logging driver instance with given context.
... ...
@@ -85,6 +89,11 @@ func GetLogDriver(name string) (Creator, error) {
85 85
 	return factory.get(name)
86 86
 }
87 87
 
88
+var builtInLogOpts = map[string]bool{
89
+	"mode":            true,
90
+	"max-buffer-size": true,
91
+}
92
+
88 93
 // ValidateLogOpts checks the options for the given log driver. The
89 94
 // options supported are specific to the LogDriver implementation.
90 95
 func ValidateLogOpts(name string, cfg map[string]string) error {
... ...
@@ -92,13 +101,35 @@ func ValidateLogOpts(name string, cfg map[string]string) error {
92 92
 		return nil
93 93
 	}
94 94
 
95
+	switch containertypes.LogMode(cfg["mode"]) {
96
+	case containertypes.LogModeBlocking, containertypes.LogModeNonBlock, containertypes.LogModeUnset:
97
+	default:
98
+		return fmt.Errorf("logger: logging mode not supported: %s", cfg["mode"])
99
+	}
100
+
101
+	if s, ok := cfg["max-buffer-size"]; ok {
102
+		if containertypes.LogMode(cfg["mode"]) != containertypes.LogModeNonBlock {
103
+			return fmt.Errorf("logger: max-buffer-size option is only supported with 'mode=%s'", containertypes.LogModeNonBlock)
104
+		}
105
+		if _, err := units.RAMInBytes(s); err != nil {
106
+			return errors.Wrap(err, "error parsing option max-buffer-size")
107
+		}
108
+	}
109
+
95 110
 	if !factory.driverRegistered(name) {
96 111
 		return fmt.Errorf("logger: no log driver named '%s' is registered", name)
97 112
 	}
98 113
 
114
+	filteredOpts := make(map[string]string, len(builtInLogOpts))
115
+	for k, v := range cfg {
116
+		if !builtInLogOpts[k] {
117
+			filteredOpts[k] = v
118
+		}
119
+	}
120
+
99 121
 	validator := factory.getLogOptValidator(name)
100 122
 	if validator != nil {
101
-		return validator(cfg)
123
+		return validator(filteredOpts)
102 124
 	}
103 125
 	return nil
104 126
 }
... ...
@@ -37,24 +37,6 @@ type Message struct {
37 37
 	Partial   bool
38 38
 }
39 39
 
40
-// CopyMessage creates a copy of the passed-in Message which will remain
41
-// unchanged if the original is changed.  Log drivers which buffer Messages
42
-// rather than dispatching them during their Log() method should use this
43
-// function to obtain a Message whose Line member's contents won't change.
44
-func CopyMessage(msg *Message) *Message {
45
-	m := new(Message)
46
-	m.Line = make([]byte, len(msg.Line))
47
-	copy(m.Line, msg.Line)
48
-	m.Source = msg.Source
49
-	m.Timestamp = msg.Timestamp
50
-	m.Partial = msg.Partial
51
-	m.Attrs = make(LogAttributes)
52
-	for k, v := range msg.Attrs {
53
-		m.Attrs[k] = v
54
-	}
55
-	return m
56
-}
57
-
58 40
 // LogAttributes is used to hold the extra attributes available in the log message
59 41
 // Primarily used for converting the map type to string and sorting.
60 42
 type LogAttributes map[string]string
61 43
deleted file mode 100644
... ...
@@ -1,26 +0,0 @@
1
-package logger
2
-
3
-import (
4
-	"reflect"
5
-	"testing"
6
-	"time"
7
-)
8
-
9
-func TestCopyMessage(t *testing.T) {
10
-	msg := &Message{
11
-		Line:      []byte("test line."),
12
-		Source:    "stdout",
13
-		Timestamp: time.Now(),
14
-		Attrs: LogAttributes{
15
-			"key1": "val1",
16
-			"key2": "val2",
17
-			"key3": "val3",
18
-		},
19
-		Partial: true,
20
-	}
21
-
22
-	m := CopyMessage(msg)
23
-	if !reflect.DeepEqual(m, msg) {
24
-		t.Fatalf("CopyMessage failed to copy message")
25
-	}
26
-}
27 1
new file mode 100644
... ...
@@ -0,0 +1,210 @@
0
+package logger
1
+
2
+import (
3
+	"errors"
4
+	"sync"
5
+	"sync/atomic"
6
+
7
+	"github.com/Sirupsen/logrus"
8
+)
9
+
10
+const (
11
+	defaultRingMaxSize = 1e6 // 1MB
12
+)
13
+
14
+// RingLogger is a ring buffer that implements the Logger interface.
15
+// This is used when lossy logging is OK.
16
+type RingLogger struct {
17
+	buffer    *messageRing
18
+	l         Logger
19
+	logInfo   Info
20
+	closeFlag int32
21
+}
22
+
23
+type ringWithReader struct {
24
+	*RingLogger
25
+}
26
+
27
+func (r *ringWithReader) ReadLogs(cfg ReadConfig) *LogWatcher {
28
+	reader, ok := r.l.(LogReader)
29
+	if !ok {
30
+		// something is wrong if we get here
31
+		panic("expected log reader")
32
+	}
33
+	return reader.ReadLogs(cfg)
34
+}
35
+
36
+func newRingLogger(driver Logger, logInfo Info, maxSize int64) *RingLogger {
37
+	l := &RingLogger{
38
+		buffer:  newRing(maxSize),
39
+		l:       driver,
40
+		logInfo: logInfo,
41
+	}
42
+	go l.run()
43
+	return l
44
+}
45
+
46
+// NewRingLogger creates a new Logger that is implemented as a RingBuffer wrapping
47
+// the passed in logger.
48
+func NewRingLogger(driver Logger, logInfo Info, maxSize int64) Logger {
49
+	if maxSize < 0 {
50
+		maxSize = defaultRingMaxSize
51
+	}
52
+	l := newRingLogger(driver, logInfo, maxSize)
53
+	if _, ok := driver.(LogReader); ok {
54
+		return &ringWithReader{l}
55
+	}
56
+	return l
57
+}
58
+
59
+// Log queues messages into the ring buffer
60
+func (r *RingLogger) Log(msg *Message) error {
61
+	if r.closed() {
62
+		return errClosed
63
+	}
64
+	return r.buffer.Enqueue(msg)
65
+}
66
+
67
+// Name returns the name of the underlying logger
68
+func (r *RingLogger) Name() string {
69
+	return r.l.Name()
70
+}
71
+
72
+func (r *RingLogger) closed() bool {
73
+	return atomic.LoadInt32(&r.closeFlag) == 1
74
+}
75
+
76
+func (r *RingLogger) setClosed() {
77
+	atomic.StoreInt32(&r.closeFlag, 1)
78
+}
79
+
80
+// Close closes the logger
81
+func (r *RingLogger) Close() error {
82
+	r.setClosed()
83
+	r.buffer.Close()
84
+	// empty out the queue
85
+	for _, msg := range r.buffer.Drain() {
86
+		if err := r.l.Log(msg); err != nil {
87
+			logrus.WithField("driver", r.l.Name()).WithField("container", r.logInfo.ContainerID).Errorf("Error writing log message: %v", r.l)
88
+			break
89
+		}
90
+	}
91
+	return r.l.Close()
92
+}
93
+
94
+// run consumes messages from the ring buffer and forwards them to the underling
95
+// logger.
96
+// This is run in a goroutine when the RingLogger is created
97
+func (r *RingLogger) run() {
98
+	for {
99
+		if r.closed() {
100
+			return
101
+		}
102
+		msg, err := r.buffer.Dequeue()
103
+		if err != nil {
104
+			// buffer is closed
105
+			return
106
+		}
107
+		if err := r.l.Log(msg); err != nil {
108
+			logrus.WithField("driver", r.l.Name()).WithField("container", r.logInfo.ContainerID).Errorf("Error writing log message: %v", r.l)
109
+		}
110
+	}
111
+}
112
+
113
+type messageRing struct {
114
+	mu sync.Mutex
115
+	// singals callers of `Dequeue` to wake up either on `Close` or when a new `Message` is added
116
+	wait *sync.Cond
117
+
118
+	sizeBytes int64 // current buffer size
119
+	maxBytes  int64 // max buffer size size
120
+	queue     []*Message
121
+	closed    bool
122
+}
123
+
124
+func newRing(maxBytes int64) *messageRing {
125
+	queueSize := 1000
126
+	if maxBytes == 0 || maxBytes == 1 {
127
+		// With 0 or 1 max byte size, the maximum size of the queue would only ever be 1
128
+		// message long.
129
+		queueSize = 1
130
+	}
131
+
132
+	r := &messageRing{queue: make([]*Message, 0, queueSize), maxBytes: maxBytes}
133
+	r.wait = sync.NewCond(&r.mu)
134
+	return r
135
+}
136
+
137
+// Enqueue adds a message to the buffer queue
138
+// If the message is too big for the buffer it drops the oldest messages to make room
139
+// If there are no messages in the queue and the message is still too big, it adds the message anyway.
140
+func (r *messageRing) Enqueue(m *Message) error {
141
+	mSize := int64(len(m.Line))
142
+
143
+	r.mu.Lock()
144
+	if r.closed {
145
+		r.mu.Unlock()
146
+		return errClosed
147
+	}
148
+	if mSize+r.sizeBytes > r.maxBytes && len(r.queue) > 0 {
149
+		r.wait.Signal()
150
+		r.mu.Unlock()
151
+		return nil
152
+	}
153
+
154
+	r.queue = append(r.queue, m)
155
+	r.sizeBytes += mSize
156
+	r.wait.Signal()
157
+	r.mu.Unlock()
158
+	return nil
159
+}
160
+
161
+// Dequeue pulls a message off the queue
162
+// If there are no messages, it waits for one.
163
+// If the buffer is closed, it will return immediately.
164
+func (r *messageRing) Dequeue() (*Message, error) {
165
+	r.mu.Lock()
166
+	for len(r.queue) == 0 && !r.closed {
167
+		r.wait.Wait()
168
+	}
169
+
170
+	if r.closed {
171
+		r.mu.Unlock()
172
+		return nil, errClosed
173
+	}
174
+
175
+	msg := r.queue[0]
176
+	r.queue = r.queue[1:]
177
+	r.sizeBytes -= int64(len(msg.Line))
178
+	r.mu.Unlock()
179
+	return msg, nil
180
+}
181
+
182
+var errClosed = errors.New("closed")
183
+
184
+// Close closes the buffer ensuring no new messages can be added.
185
+// Any callers waiting to dequeue a message will be woken up.
186
+func (r *messageRing) Close() {
187
+	r.mu.Lock()
188
+	if r.closed {
189
+		r.mu.Unlock()
190
+		return
191
+	}
192
+
193
+	r.closed = true
194
+	r.wait.Broadcast()
195
+	r.mu.Unlock()
196
+	return
197
+}
198
+
199
+// Drain drains all messages from the queue.
200
+// This can be used after `Close()` to get any remaining messages that were in queue.
201
+func (r *messageRing) Drain() []*Message {
202
+	r.mu.Lock()
203
+	ls := make([]*Message, 0, len(r.queue))
204
+	ls = append(ls, r.queue...)
205
+	r.sizeBytes = 0
206
+	r.queue = r.queue[:0]
207
+	r.mu.Unlock()
208
+	return ls
209
+}
0 210
new file mode 100644
... ...
@@ -0,0 +1,299 @@
0
+package logger
1
+
2
+import (
3
+	"context"
4
+	"strconv"
5
+	"testing"
6
+	"time"
7
+)
8
+
9
+type mockLogger struct{ c chan *Message }
10
+
11
+func (l *mockLogger) Log(msg *Message) error {
12
+	l.c <- msg
13
+	return nil
14
+}
15
+
16
+func (l *mockLogger) Name() string {
17
+	return "mock"
18
+}
19
+
20
+func (l *mockLogger) Close() error {
21
+	return nil
22
+}
23
+
24
+func TestRingLogger(t *testing.T) {
25
+	mockLog := &mockLogger{make(chan *Message)} // no buffer on this channel
26
+	ring := newRingLogger(mockLog, Info{}, 1)
27
+	defer ring.setClosed()
28
+
29
+	// this should never block
30
+	ring.Log(&Message{Line: []byte("1")})
31
+	ring.Log(&Message{Line: []byte("2")})
32
+	ring.Log(&Message{Line: []byte("3")})
33
+
34
+	select {
35
+	case msg := <-mockLog.c:
36
+		if string(msg.Line) != "1" {
37
+			t.Fatalf("got unexpected msg: %q", string(msg.Line))
38
+		}
39
+	case <-time.After(100 * time.Millisecond):
40
+		t.Fatal("timeout reading log message")
41
+	}
42
+
43
+	select {
44
+	case msg := <-mockLog.c:
45
+		t.Fatalf("expected no more messages in the queue, got: %q", string(msg.Line))
46
+	default:
47
+	}
48
+}
49
+
50
+func TestRingCap(t *testing.T) {
51
+	r := newRing(5)
52
+	for i := 0; i < 10; i++ {
53
+		// queue messages with "0" to "10"
54
+		// the "5" to "10" messages should be dropped since we only allow 5 bytes in the buffer
55
+		if err := r.Enqueue(&Message{Line: []byte(strconv.Itoa(i))}); err != nil {
56
+			t.Fatal(err)
57
+		}
58
+	}
59
+
60
+	// should have messages in the queue for "5" to "10"
61
+	for i := 0; i < 5; i++ {
62
+		m, err := r.Dequeue()
63
+		if err != nil {
64
+			t.Fatal(err)
65
+		}
66
+		if string(m.Line) != strconv.Itoa(i) {
67
+			t.Fatalf("got unexpected message for iter %d: %s", i, string(m.Line))
68
+		}
69
+	}
70
+
71
+	// queue a message that's bigger than the buffer cap
72
+	if err := r.Enqueue(&Message{Line: []byte("hello world")}); err != nil {
73
+		t.Fatal(err)
74
+	}
75
+
76
+	// queue another message that's bigger than the buffer cap
77
+	if err := r.Enqueue(&Message{Line: []byte("eat a banana")}); err != nil {
78
+		t.Fatal(err)
79
+	}
80
+
81
+	m, err := r.Dequeue()
82
+	if err != nil {
83
+		t.Fatal(err)
84
+	}
85
+	if string(m.Line) != "hello world" {
86
+		t.Fatalf("got unexpected message: %s", string(m.Line))
87
+	}
88
+	if len(r.queue) != 0 {
89
+		t.Fatalf("expected queue to be empty, got: %d", len(r.queue))
90
+	}
91
+}
92
+
93
+func TestRingClose(t *testing.T) {
94
+	r := newRing(1)
95
+	if err := r.Enqueue(&Message{Line: []byte("hello")}); err != nil {
96
+		t.Fatal(err)
97
+	}
98
+	r.Close()
99
+	if err := r.Enqueue(&Message{}); err != errClosed {
100
+		t.Fatalf("expected errClosed, got: %v", err)
101
+	}
102
+	if len(r.queue) != 1 {
103
+		t.Fatal("expected empty queue")
104
+	}
105
+	if m, err := r.Dequeue(); err == nil || m != nil {
106
+		t.Fatal("exepcted err on Dequeue after close")
107
+	}
108
+
109
+	ls := r.Drain()
110
+	if len(ls) != 1 {
111
+		t.Fatalf("expected one message: %v", ls)
112
+	}
113
+	if string(ls[0].Line) != "hello" {
114
+		t.Fatalf("got unexpected message: %s", string(ls[0].Line))
115
+	}
116
+}
117
+
118
+func TestRingDrain(t *testing.T) {
119
+	r := newRing(5)
120
+	for i := 0; i < 5; i++ {
121
+		if err := r.Enqueue(&Message{Line: []byte(strconv.Itoa(i))}); err != nil {
122
+			t.Fatal(err)
123
+		}
124
+	}
125
+
126
+	ls := r.Drain()
127
+	if len(ls) != 5 {
128
+		t.Fatal("got unexpected length after drain")
129
+	}
130
+
131
+	for i := 0; i < 5; i++ {
132
+		if string(ls[i].Line) != strconv.Itoa(i) {
133
+			t.Fatalf("got unexpected message at position %d: %s", i, string(ls[i].Line))
134
+		}
135
+	}
136
+	if r.sizeBytes != 0 {
137
+		t.Fatalf("expected buffer size to be 0 after drain, got: %d", r.sizeBytes)
138
+	}
139
+
140
+	ls = r.Drain()
141
+	if len(ls) != 0 {
142
+		t.Fatalf("expected 0 messages on 2nd drain: %v", ls)
143
+	}
144
+
145
+}
146
+
147
+type nopLogger struct{}
148
+
149
+func (nopLogger) Name() string       { return "nopLogger" }
150
+func (nopLogger) Close() error       { return nil }
151
+func (nopLogger) Log(*Message) error { return nil }
152
+
153
+func BenchmarkRingLoggerThroughputNoReceiver(b *testing.B) {
154
+	mockLog := &mockLogger{make(chan *Message)}
155
+	defer mockLog.Close()
156
+	l := NewRingLogger(mockLog, Info{}, -1)
157
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
158
+	b.SetBytes(int64(len(msg.Line)))
159
+
160
+	for i := 0; i < b.N; i++ {
161
+		if err := l.Log(msg); err != nil {
162
+			b.Fatal(err)
163
+		}
164
+	}
165
+}
166
+
167
+func BenchmarkRingLoggerThroughputWithReceiverDelay0(b *testing.B) {
168
+	l := NewRingLogger(nopLogger{}, Info{}, -1)
169
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
170
+	b.SetBytes(int64(len(msg.Line)))
171
+
172
+	for i := 0; i < b.N; i++ {
173
+		if err := l.Log(msg); err != nil {
174
+			b.Fatal(err)
175
+		}
176
+	}
177
+}
178
+
179
+func consumeWithDelay(delay time.Duration, c <-chan *Message) (cancel func()) {
180
+	started := make(chan struct{})
181
+	ctx, cancel := context.WithCancel(context.Background())
182
+	go func() {
183
+		close(started)
184
+		ticker := time.NewTicker(delay)
185
+		for range ticker.C {
186
+			select {
187
+			case <-ctx.Done():
188
+				ticker.Stop()
189
+				return
190
+			case <-c:
191
+			}
192
+		}
193
+	}()
194
+	<-started
195
+	return cancel
196
+}
197
+
198
+func BenchmarkRingLoggerThroughputConsumeDelay1(b *testing.B) {
199
+	mockLog := &mockLogger{make(chan *Message)}
200
+	defer mockLog.Close()
201
+	l := NewRingLogger(mockLog, Info{}, -1)
202
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
203
+	b.SetBytes(int64(len(msg.Line)))
204
+
205
+	cancel := consumeWithDelay(1*time.Millisecond, mockLog.c)
206
+	defer cancel()
207
+
208
+	for i := 0; i < b.N; i++ {
209
+		if err := l.Log(msg); err != nil {
210
+			b.Fatal(err)
211
+		}
212
+	}
213
+}
214
+
215
+func BenchmarkRingLoggerThroughputConsumeDelay10(b *testing.B) {
216
+	mockLog := &mockLogger{make(chan *Message)}
217
+	defer mockLog.Close()
218
+	l := NewRingLogger(mockLog, Info{}, -1)
219
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
220
+	b.SetBytes(int64(len(msg.Line)))
221
+
222
+	cancel := consumeWithDelay(10*time.Millisecond, mockLog.c)
223
+	defer cancel()
224
+
225
+	for i := 0; i < b.N; i++ {
226
+		if err := l.Log(msg); err != nil {
227
+			b.Fatal(err)
228
+		}
229
+	}
230
+}
231
+
232
+func BenchmarkRingLoggerThroughputConsumeDelay50(b *testing.B) {
233
+	mockLog := &mockLogger{make(chan *Message)}
234
+	defer mockLog.Close()
235
+	l := NewRingLogger(mockLog, Info{}, -1)
236
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
237
+	b.SetBytes(int64(len(msg.Line)))
238
+
239
+	cancel := consumeWithDelay(50*time.Millisecond, mockLog.c)
240
+	defer cancel()
241
+
242
+	for i := 0; i < b.N; i++ {
243
+		if err := l.Log(msg); err != nil {
244
+			b.Fatal(err)
245
+		}
246
+	}
247
+}
248
+
249
+func BenchmarkRingLoggerThroughputConsumeDelay100(b *testing.B) {
250
+	mockLog := &mockLogger{make(chan *Message)}
251
+	defer mockLog.Close()
252
+	l := NewRingLogger(mockLog, Info{}, -1)
253
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
254
+	b.SetBytes(int64(len(msg.Line)))
255
+
256
+	cancel := consumeWithDelay(100*time.Millisecond, mockLog.c)
257
+	defer cancel()
258
+
259
+	for i := 0; i < b.N; i++ {
260
+		if err := l.Log(msg); err != nil {
261
+			b.Fatal(err)
262
+		}
263
+	}
264
+}
265
+
266
+func BenchmarkRingLoggerThroughputConsumeDelay300(b *testing.B) {
267
+	mockLog := &mockLogger{make(chan *Message)}
268
+	defer mockLog.Close()
269
+	l := NewRingLogger(mockLog, Info{}, -1)
270
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
271
+	b.SetBytes(int64(len(msg.Line)))
272
+
273
+	cancel := consumeWithDelay(300*time.Millisecond, mockLog.c)
274
+	defer cancel()
275
+
276
+	for i := 0; i < b.N; i++ {
277
+		if err := l.Log(msg); err != nil {
278
+			b.Fatal(err)
279
+		}
280
+	}
281
+}
282
+
283
+func BenchmarkRingLoggerThroughputConsumeDelay500(b *testing.B) {
284
+	mockLog := &mockLogger{make(chan *Message)}
285
+	defer mockLog.Close()
286
+	l := NewRingLogger(mockLog, Info{}, -1)
287
+	msg := &Message{Line: []byte("hello humans and everyone else!")}
288
+	b.SetBytes(int64(len(msg.Line)))
289
+
290
+	cancel := consumeWithDelay(500*time.Millisecond, mockLog.c)
291
+	defer cancel()
292
+
293
+	for i := 0; i < b.N; i++ {
294
+		if err := l.Log(msg); err != nil {
295
+			b.Fatal(err)
296
+		}
297
+	}
298
+}
... ...
@@ -133,11 +133,11 @@ func TestDefault(t *testing.T) {
133 133
 	}
134 134
 
135 135
 	message1Time := time.Now()
136
-	if err := loggerDriver.Log(&logger.Message{[]byte("{\"a\":\"b\"}"), "stdout", message1Time, nil, false}); err != nil {
136
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("{\"a\":\"b\"}"), Source: "stdout", Timestamp: message1Time}); err != nil {
137 137
 		t.Fatal(err)
138 138
 	}
139 139
 	message2Time := time.Now()
140
-	if err := loggerDriver.Log(&logger.Message{[]byte("notajson"), "stdout", message2Time, nil, false}); err != nil {
140
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("notajson"), Source: "stdout", Timestamp: message2Time}); err != nil {
141 141
 		t.Fatal(err)
142 142
 	}
143 143
 
... ...
@@ -262,7 +262,7 @@ func TestInlineFormatWithNonDefaultOptions(t *testing.T) {
262 262
 	}
263 263
 
264 264
 	messageTime := time.Now()
265
-	if err := loggerDriver.Log(&logger.Message{[]byte("1"), "stdout", messageTime, nil, false}); err != nil {
265
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("1"), Source: "stdout", Timestamp: messageTime}); err != nil {
266 266
 		t.Fatal(err)
267 267
 	}
268 268
 
... ...
@@ -361,11 +361,11 @@ func TestJsonFormat(t *testing.T) {
361 361
 	}
362 362
 
363 363
 	message1Time := time.Now()
364
-	if err := loggerDriver.Log(&logger.Message{[]byte("{\"a\":\"b\"}"), "stdout", message1Time, nil, false}); err != nil {
364
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("{\"a\":\"b\"}"), Source: "stdout", Timestamp: message1Time}); err != nil {
365 365
 		t.Fatal(err)
366 366
 	}
367 367
 	message2Time := time.Now()
368
-	if err := loggerDriver.Log(&logger.Message{[]byte("notjson"), "stdout", message2Time, nil, false}); err != nil {
368
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("notjson"), Source: "stdout", Timestamp: message2Time}); err != nil {
369 369
 		t.Fatal(err)
370 370
 	}
371 371
 
... ...
@@ -478,11 +478,11 @@ func TestRawFormat(t *testing.T) {
478 478
 	}
479 479
 
480 480
 	message1Time := time.Now()
481
-	if err := loggerDriver.Log(&logger.Message{[]byte("{\"a\":\"b\"}"), "stdout", message1Time, nil, false}); err != nil {
481
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("{\"a\":\"b\"}"), Source: "stdout", Timestamp: message1Time}); err != nil {
482 482
 		t.Fatal(err)
483 483
 	}
484 484
 	message2Time := time.Now()
485
-	if err := loggerDriver.Log(&logger.Message{[]byte("notjson"), "stdout", message2Time, nil, false}); err != nil {
485
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("notjson"), Source: "stdout", Timestamp: message2Time}); err != nil {
486 486
 		t.Fatal(err)
487 487
 	}
488 488
 
... ...
@@ -592,11 +592,11 @@ func TestRawFormatWithLabels(t *testing.T) {
592 592
 	}
593 593
 
594 594
 	message1Time := time.Now()
595
-	if err := loggerDriver.Log(&logger.Message{[]byte("{\"a\":\"b\"}"), "stdout", message1Time, nil, false}); err != nil {
595
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("{\"a\":\"b\"}"), Source: "stdout", Timestamp: message1Time}); err != nil {
596 596
 		t.Fatal(err)
597 597
 	}
598 598
 	message2Time := time.Now()
599
-	if err := loggerDriver.Log(&logger.Message{[]byte("notjson"), "stdout", message2Time, nil, false}); err != nil {
599
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("notjson"), Source: "stdout", Timestamp: message2Time}); err != nil {
600 600
 		t.Fatal(err)
601 601
 	}
602 602
 
... ...
@@ -705,11 +705,11 @@ func TestRawFormatWithoutTag(t *testing.T) {
705 705
 	}
706 706
 
707 707
 	message1Time := time.Now()
708
-	if err := loggerDriver.Log(&logger.Message{[]byte("{\"a\":\"b\"}"), "stdout", message1Time, nil, false}); err != nil {
708
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("{\"a\":\"b\"}"), Source: "stdout", Timestamp: message1Time}); err != nil {
709 709
 		t.Fatal(err)
710 710
 	}
711 711
 	message2Time := time.Now()
712
-	if err := loggerDriver.Log(&logger.Message{[]byte("notjson"), "stdout", message2Time, nil, false}); err != nil {
712
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("notjson"), Source: "stdout", Timestamp: message2Time}); err != nil {
713 713
 		t.Fatal(err)
714 714
 	}
715 715
 
... ...
@@ -790,7 +790,7 @@ func TestBatching(t *testing.T) {
790 790
 	}
791 791
 
792 792
 	for i := 0; i < defaultStreamChannelSize*4; i++ {
793
-		if err := loggerDriver.Log(&logger.Message{[]byte(fmt.Sprintf("%d", i)), "stdout", time.Now(), nil, false}); err != nil {
793
+		if err := loggerDriver.Log(&logger.Message{Line: []byte(fmt.Sprintf("%d", i)), Source: "stdout", Timestamp: time.Now()}); err != nil {
794 794
 			t.Fatal(err)
795 795
 		}
796 796
 	}
... ...
@@ -856,7 +856,7 @@ func TestFrequency(t *testing.T) {
856 856
 	}
857 857
 
858 858
 	for i := 0; i < 10; i++ {
859
-		if err := loggerDriver.Log(&logger.Message{[]byte(fmt.Sprintf("%d", i)), "stdout", time.Now(), nil, false}); err != nil {
859
+		if err := loggerDriver.Log(&logger.Message{Line: []byte(fmt.Sprintf("%d", i)), Source: "stdout", Timestamp: time.Now()}); err != nil {
860 860
 			t.Fatal(err)
861 861
 		}
862 862
 		time.Sleep(15 * time.Millisecond)
... ...
@@ -937,7 +937,7 @@ func TestOneMessagePerRequest(t *testing.T) {
937 937
 	}
938 938
 
939 939
 	for i := 0; i < 10; i++ {
940
-		if err := loggerDriver.Log(&logger.Message{[]byte(fmt.Sprintf("%d", i)), "stdout", time.Now(), nil, false}); err != nil {
940
+		if err := loggerDriver.Log(&logger.Message{Line: []byte(fmt.Sprintf("%d", i)), Source: "stdout", Timestamp: time.Now()}); err != nil {
941 941
 			t.Fatal(err)
942 942
 		}
943 943
 	}
... ...
@@ -1045,7 +1045,7 @@ func TestSkipVerify(t *testing.T) {
1045 1045
 	}
1046 1046
 
1047 1047
 	for i := 0; i < defaultStreamChannelSize*2; i++ {
1048
-		if err := loggerDriver.Log(&logger.Message{[]byte(fmt.Sprintf("%d", i)), "stdout", time.Now(), nil, false}); err != nil {
1048
+		if err := loggerDriver.Log(&logger.Message{Line: []byte(fmt.Sprintf("%d", i)), Source: "stdout", Timestamp: time.Now()}); err != nil {
1049 1049
 			t.Fatal(err)
1050 1050
 		}
1051 1051
 	}
... ...
@@ -1057,7 +1057,7 @@ func TestSkipVerify(t *testing.T) {
1057 1057
 	hec.simulateServerError = false
1058 1058
 
1059 1059
 	for i := defaultStreamChannelSize * 2; i < defaultStreamChannelSize*4; i++ {
1060
-		if err := loggerDriver.Log(&logger.Message{[]byte(fmt.Sprintf("%d", i)), "stdout", time.Now(), nil, false}); err != nil {
1060
+		if err := loggerDriver.Log(&logger.Message{Line: []byte(fmt.Sprintf("%d", i)), Source: "stdout", Timestamp: time.Now()}); err != nil {
1061 1061
 			t.Fatal(err)
1062 1062
 		}
1063 1063
 	}
... ...
@@ -1127,7 +1127,7 @@ func TestBufferMaximum(t *testing.T) {
1127 1127
 	}
1128 1128
 
1129 1129
 	for i := 0; i < 11; i++ {
1130
-		if err := loggerDriver.Log(&logger.Message{[]byte(fmt.Sprintf("%d", i)), "stdout", time.Now(), nil, false}); err != nil {
1130
+		if err := loggerDriver.Log(&logger.Message{Line: []byte(fmt.Sprintf("%d", i)), Source: "stdout", Timestamp: time.Now()}); err != nil {
1131 1131
 			t.Fatal(err)
1132 1132
 		}
1133 1133
 	}
... ...
@@ -1216,7 +1216,7 @@ func TestServerAlwaysDown(t *testing.T) {
1216 1216
 	}
1217 1217
 
1218 1218
 	for i := 0; i < 5; i++ {
1219
-		if err := loggerDriver.Log(&logger.Message{[]byte(fmt.Sprintf("%d", i)), "stdout", time.Now(), nil, false}); err != nil {
1219
+		if err := loggerDriver.Log(&logger.Message{Line: []byte(fmt.Sprintf("%d", i)), Source: "stdout", Timestamp: time.Now()}); err != nil {
1220 1220
 			t.Fatal(err)
1221 1221
 		}
1222 1222
 	}
... ...
@@ -1269,7 +1269,7 @@ func TestCannotSendAfterClose(t *testing.T) {
1269 1269
 		t.Fatal(err)
1270 1270
 	}
1271 1271
 
1272
-	if err := loggerDriver.Log(&logger.Message{[]byte("message1"), "stdout", time.Now(), nil, false}); err != nil {
1272
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("message1"), Source: "stdout", Timestamp: time.Now()}); err != nil {
1273 1273
 		t.Fatal(err)
1274 1274
 	}
1275 1275
 
... ...
@@ -1278,7 +1278,7 @@ func TestCannotSendAfterClose(t *testing.T) {
1278 1278
 		t.Fatal(err)
1279 1279
 	}
1280 1280
 
1281
-	if err := loggerDriver.Log(&logger.Message{[]byte("message2"), "stdout", time.Now(), nil, false}); err == nil {
1281
+	if err := loggerDriver.Log(&logger.Message{Line: []byte("message2"), Source: "stdout", Timestamp: time.Now()}); err == nil {
1282 1282
 		t.Fatal("Driver should not allow to send messages after close")
1283 1283
 	}
1284 1284
 
... ...
@@ -82,6 +82,8 @@ keywords: "API, Docker, rcli, REST, documentation"
82 82
 * `GET /secrets/{id}` returns information on the secret `id`.
83 83
 * `POST /secrets/{id}/update` updates the secret `id`.
84 84
 * `POST /services/(id or name)/update` now accepts service name or prefix of service id as a parameter.
85
+* `POST /containers/create` added 2 built-in log-opts that work on all logging drivers,
86
+`mode` (`blocking`|`non-blocking`), and `max-buffer-size` (e.g. `2m`) which enables a non-blocking log buffer.
85 87
 
86 88
 ## v1.24 API changes
87 89