Browse code

Support configuration of log cacher.

Configuration over the API per container is intentionally left out for
the time being, but is supported to configure the default from the
daemon config.

Signed-off-by: Brian Goff <cpuguy83@gmail.com>
(cherry picked from commit cbecf48bc352e680a5390a7ca9cff53098cd16d7)
Signed-off-by: Madhu Venugopal <madhu@docker.com>

Brian Goff authored on 2018/04/10 04:35:24
Showing 11 changed files
... ...
@@ -423,18 +423,21 @@ func (container *Container) StartLogger() (logger.Logger, error) {
423 423
 	}
424 424
 
425 425
 	if _, ok := l.(logger.LogReader); !ok {
426
-		logPath, err := container.GetRootResourcePath("container-cached.log")
427
-		if err != nil {
428
-			return nil, err
429
-		}
430
-		info.LogPath = logPath
426
+		if cache.ShouldUseCache(cfg.Config) {
427
+			logPath, err := container.GetRootResourcePath("container-cached.log")
428
+			if err != nil {
429
+				return nil, err
430
+			}
431 431
 
432
-		if !container.LocalLogCacheMeta.HaveNotifyEnabled {
433
-			logrus.WithField("container", container.ID).Info("Configured log driver does not support reads, enabling local file cache for container logs")
434
-		}
435
-		l, err = cache.WithLocalCache(l, info)
436
-		if err != nil {
437
-			return nil, errors.Wrap(err, "error setting up local container log cache")
432
+			if !container.LocalLogCacheMeta.HaveNotifyEnabled {
433
+				logrus.WithField("container", container.ID).WithField("driver", container.HostConfig.LogConfig.Type).Info("Configured log driver does not support reads, enabling local file cache for container logs")
434
+				container.LocalLogCacheMeta.HaveNotifyEnabled = true
435
+			}
436
+			info.LogPath = logPath
437
+			l, err = cache.WithLocalCache(l, info)
438
+			if err != nil {
439
+				return nil, errors.Wrap(err, "error setting up local container log cache")
440
+			}
438 441
 		}
439 442
 	}
440 443
 	return l, nil
... ...
@@ -11,6 +11,7 @@ import (
11 11
 	_ "github.com/docker/docker/daemon/logger/jsonfilelog"
12 12
 	_ "github.com/docker/docker/daemon/logger/local"
13 13
 	_ "github.com/docker/docker/daemon/logger/logentries"
14
+	_ "github.com/docker/docker/daemon/logger/loggerutils/cache"
14 15
 	_ "github.com/docker/docker/daemon/logger/splunk"
15 16
 	_ "github.com/docker/docker/daemon/logger/syslog"
16 17
 )
... ...
@@ -10,6 +10,7 @@ import (
10 10
 	_ "github.com/docker/docker/daemon/logger/gelf"
11 11
 	_ "github.com/docker/docker/daemon/logger/jsonfilelog"
12 12
 	_ "github.com/docker/docker/daemon/logger/logentries"
13
+	_ "github.com/docker/docker/daemon/logger/loggerutils/cache"
13 14
 	_ "github.com/docker/docker/daemon/logger/splunk"
14 15
 	_ "github.com/docker/docker/daemon/logger/syslog"
15 16
 )
... ...
@@ -143,6 +143,10 @@ func ValidateLogOpts(name string, cfg map[string]string) error {
143 143
 		}
144 144
 	}
145 145
 
146
+	if err := validateExternal(cfg); err != nil {
147
+		return err
148
+	}
149
+
146 150
 	if !factory.driverRegistered(name) {
147 151
 		return fmt.Errorf("logger: no log driver named '%s' is registered", name)
148 152
 	}
149 153
new file mode 100644
... ...
@@ -0,0 +1,29 @@
0
+package logger
1
+
2
+var externalValidators []LogOptValidator
3
+
4
+// RegisterExternalValidator adds the validator to the list of external validators.
5
+// External validators are used by packages outside this package that need to add their own validation logic.
6
+// This should only be called on package initialization.
7
+func RegisterExternalValidator(v LogOptValidator) {
8
+	externalValidators = append(externalValidators, v)
9
+}
10
+
11
+// AddBuiltinLogOpts updates the list of built-in log opts. This allows other packages to supplement additional log options
12
+// without having to register an actual log driver. This is used by things that are more proxy log drivers and should
13
+// not be exposed as a usable log driver to the API.
14
+// This should only be called on package initialization.
15
+func AddBuiltinLogOpts(opts map[string]bool) {
16
+	for k, v := range opts {
17
+		builtInLogOpts[k] = v
18
+	}
19
+}
20
+
21
+func validateExternal(cfg map[string]string) error {
22
+	for _, v := range externalValidators {
23
+		if err := v(cfg); err != nil {
24
+			return err
25
+		}
26
+	}
27
+	return nil
28
+}
... ...
@@ -1,22 +1,55 @@
1 1
 package cache // import "github.com/docker/docker/daemon/logger/loggerutils/cache"
2 2
 
3 3
 import (
4
+	"strconv"
5
+
6
+	"github.com/docker/docker/api/types/container"
4 7
 	"github.com/docker/docker/daemon/logger"
5 8
 	"github.com/docker/docker/daemon/logger/local"
9
+	units "github.com/docker/go-units"
10
+	"github.com/pkg/errors"
6 11
 	"github.com/sirupsen/logrus"
7 12
 )
8 13
 
14
+const (
15
+	// DriverName is the name of the driver used for local log caching
16
+	DriverName = local.Name
17
+
18
+	cachePrefix      = "cache-"
19
+	cacheDisabledKey = cachePrefix + "disabled"
20
+)
21
+
22
+var builtInCacheLogOpts = map[string]bool{
23
+	cacheDisabledKey: true,
24
+}
25
+
9 26
 // WithLocalCache wraps the passed in logger with a logger caches all writes locally
10 27
 // in addition to writing to the passed in logger.
11
-func WithLocalCache(l logger.Logger, logInfo logger.Info) (logger.Logger, error) {
12
-	localLogger, err := local.New(logInfo)
28
+func WithLocalCache(l logger.Logger, info logger.Info) (logger.Logger, error) {
29
+	initLogger, err := logger.GetLogDriver(DriverName)
13 30
 	if err != nil {
14 31
 		return nil, err
15 32
 	}
33
+
34
+	cacher, err := initLogger(info)
35
+	if err != nil {
36
+		return nil, errors.Wrap(err, "error initializing local log cache driver")
37
+	}
38
+
39
+	if info.Config["mode"] == container.LogModeUnset || container.LogMode(info.Config["mode"]) == container.LogModeNonBlock {
40
+		var size int64 = -1
41
+		if s, exists := info.Config["max-buffer-size"]; exists {
42
+			size, err = units.RAMInBytes(s)
43
+			if err != nil {
44
+				return nil, err
45
+			}
46
+		}
47
+		cacher = logger.NewRingLogger(cacher, info, size)
48
+	}
49
+
16 50
 	return &loggerWithCache{
17
-		l: l,
18
-		// TODO(@cpuguy83): Should this be configurable?
19
-		cache: logger.NewRingLogger(localLogger, logInfo, -1),
51
+		l:     l,
52
+		cache: cacher,
20 53
 	}, nil
21 54
 }
22 55
 
... ...
@@ -26,9 +59,10 @@ type loggerWithCache struct {
26 26
 }
27 27
 
28 28
 func (l *loggerWithCache) Log(msg *logger.Message) error {
29
-	// copy the message since the underlying logger will return the passed in message to the message pool
29
+	// copy the message as the original will be reset once the call to `Log` is complete
30 30
 	dup := logger.NewMessage()
31 31
 	dumbCopyMessage(dup, msg)
32
+
32 33
 	if err := l.l.Log(msg); err != nil {
33 34
 		return err
34 35
 	}
... ...
@@ -51,6 +85,19 @@ func (l *loggerWithCache) Close() error {
51 51
 	return err
52 52
 }
53 53
 
54
+// ShouldUseCache reads the log opts to determine if caching should be enabled
55
+func ShouldUseCache(cfg map[string]string) bool {
56
+	if cfg[cacheDisabledKey] == "" {
57
+		return true
58
+	}
59
+	b, err := strconv.ParseBool(cfg[cacheDisabledKey])
60
+	if err != nil {
61
+		// This shouldn't happen since the values are validated before hand.
62
+		return false
63
+	}
64
+	return !b
65
+}
66
+
54 67
 // dumbCopyMessage is a bit of a fake copy but avoids extra allocations which
55 68
 // are not necessary for this use case.
56 69
 func dumbCopyMessage(dst, src *logger.Message) {
... ...
@@ -59,5 +106,5 @@ func dumbCopyMessage(dst, src *logger.Message) {
59 59
 	dst.PLogMetaData = src.PLogMetaData
60 60
 	dst.Err = src.Err
61 61
 	dst.Attrs = src.Attrs
62
-	dst.Line = src.Line
62
+	dst.Line = append(dst.Line[:0], src.Line...)
63 63
 }
64 64
new file mode 100644
... ...
@@ -0,0 +1,81 @@
0
+package cache
1
+
2
+import (
3
+	"context"
4
+	"testing"
5
+
6
+	"time"
7
+
8
+	"bytes"
9
+
10
+	"github.com/docker/docker/daemon/logger"
11
+	"gotest.tools/v3/assert"
12
+	"gotest.tools/v3/assert/cmp"
13
+)
14
+
15
+type fakeLogger struct {
16
+	messages chan logger.Message
17
+	close    chan struct{}
18
+}
19
+
20
+func (l *fakeLogger) Log(msg *logger.Message) error {
21
+	select {
22
+	case l.messages <- *msg:
23
+	case <-l.close:
24
+	}
25
+	logger.PutMessage(msg)
26
+	return nil
27
+}
28
+
29
+func (l *fakeLogger) Name() string {
30
+	return "fake"
31
+}
32
+
33
+func (l *fakeLogger) Close() error {
34
+	close(l.close)
35
+	return nil
36
+}
37
+
38
+func TestLog(t *testing.T) {
39
+	cacher := &fakeLogger{make(chan logger.Message), make(chan struct{})}
40
+	l := &loggerWithCache{
41
+		l:     &fakeLogger{make(chan logger.Message, 100), make(chan struct{})},
42
+		cache: cacher,
43
+	}
44
+	defer l.Close()
45
+
46
+	var messages []logger.Message
47
+	for i := 0; i < 100; i++ {
48
+		messages = append(messages, logger.Message{
49
+			Timestamp: time.Now(),
50
+			Line:      append(bytes.Repeat([]byte("a"), 100), '\n'),
51
+		})
52
+	}
53
+
54
+	ctx, cancel := context.WithTimeout(context.Background(), 60*time.Second)
55
+	defer cancel()
56
+
57
+	go func() {
58
+		for _, msg := range messages {
59
+			select {
60
+			case <-ctx.Done():
61
+				return
62
+			default:
63
+			}
64
+
65
+			m := logger.NewMessage()
66
+			dumbCopyMessage(m, &msg)
67
+			l.Log(m)
68
+		}
69
+	}()
70
+
71
+	for _, m := range messages {
72
+		var msg logger.Message
73
+		select {
74
+		case <-ctx.Done():
75
+			t.Fatal("timed out waiting for messages... this is probably a test implementation error")
76
+		case msg = <-cacher.messages:
77
+			assert.Assert(t, cmp.DeepEqual(msg, m))
78
+		}
79
+	}
80
+}
0 81
new file mode 100644
... ...
@@ -0,0 +1,40 @@
0
+package cache
1
+
2
+import (
3
+	"strconv"
4
+
5
+	"github.com/docker/docker/daemon/logger"
6
+	"github.com/docker/docker/daemon/logger/local"
7
+	"github.com/pkg/errors"
8
+)
9
+
10
+func init() {
11
+	for k, v := range local.LogOptKeys {
12
+		builtInCacheLogOpts[cachePrefix+k] = v
13
+	}
14
+	logger.AddBuiltinLogOpts(builtInCacheLogOpts)
15
+	logger.RegisterExternalValidator(validateLogCacheOpts)
16
+}
17
+
18
+func validateLogCacheOpts(cfg map[string]string) error {
19
+	if v := cfg[cacheDisabledKey]; v != "" {
20
+		_, err := strconv.ParseBool(v)
21
+		if err != nil {
22
+			return errors.Errorf("invalid value for option %s: %s", cacheDisabledKey, cfg[cacheDisabledKey])
23
+		}
24
+	}
25
+	return nil
26
+}
27
+
28
+// MergeDefaultLogConfig reads the default log opts and makes sure that any caching related keys that exist there are
29
+// added to dst.
30
+func MergeDefaultLogConfig(dst, defaults map[string]string) {
31
+	for k, v := range defaults {
32
+		if !builtInCacheLogOpts[k] {
33
+			continue
34
+		}
35
+		if _, exists := dst[k]; !exists {
36
+			dst[k] = v
37
+		}
38
+	}
39
+}
... ...
@@ -11,6 +11,7 @@ import (
11 11
 	timetypes "github.com/docker/docker/api/types/time"
12 12
 	"github.com/docker/docker/container"
13 13
 	"github.com/docker/docker/daemon/logger"
14
+	logcache "github.com/docker/docker/daemon/logger/loggerutils/cache"
14 15
 	"github.com/docker/docker/errdefs"
15 16
 	"github.com/pkg/errors"
16 17
 	"github.com/sirupsen/logrus"
... ...
@@ -190,6 +191,8 @@ func (daemon *Daemon) mergeAndVerifyLogConfig(cfg *containertypes.LogConfig) err
190 190
 		}
191 191
 	}
192 192
 
193
+	logcache.MergeDefaultLogConfig(cfg.Config, daemon.defaultLogConfig.Config)
194
+
193 195
 	return logger.ValidateLogOpts(cfg.Type, cfg.Config)
194 196
 }
195 197
 
... ...
@@ -204,6 +207,7 @@ func (daemon *Daemon) setupDefaultLogConfig() error {
204 204
 		Type:   config.LogConfig.Type,
205 205
 		Config: config.LogConfig.Config,
206 206
 	}
207
+
207 208
 	logrus.Debugf("Using default logging driver %s", daemon.defaultLogConfig.Type)
208 209
 	return nil
209 210
 }
... ...
@@ -62,6 +62,7 @@ func handle(mux *http.ServeMux) {
62 62
 		if f := d.logs[req.File]; f != nil {
63 63
 			f.Close()
64 64
 		}
65
+		d.mu.Unlock()
65 66
 		respond(nil, w)
66 67
 	})
67 68
 
... ...
@@ -29,45 +29,62 @@ func TestReadPluginNoRead(t *testing.T) {
29 29
 	createPlugin(t, client, "test", "discard", asLogDriver)
30 30
 
31 31
 	ctx := context.Background()
32
-	defer func() {
33
-		err = client.PluginRemove(ctx, "test", types.PluginRemoveOptions{Force: true})
34
-		assert.Check(t, err)
35
-	}()
36 32
 
37 33
 	err = client.PluginEnable(ctx, "test", types.PluginEnableOptions{Timeout: 30})
38 34
 	assert.Check(t, err)
35
+	d.Stop(t)
39 36
 
40
-	c, err := client.ContainerCreate(ctx,
41
-		&container.Config{
42
-			Image: "busybox",
43
-			Cmd:   []string{"/bin/echo", "hello world"},
44
-		},
45
-		&container.HostConfig{LogConfig: container.LogConfig{Type: "test"}},
46
-		nil,
47
-		"",
48
-	)
49
-	assert.Assert(t, err)
37
+	cfg := &container.Config{
38
+		Image: "busybox",
39
+		Cmd:   []string{"/bin/echo", "hello world"},
40
+	}
41
+	for desc, test := range map[string]struct {
42
+		dOpts         []string
43
+		logsSupported bool
44
+	}{
45
+		"default":                    {logsSupported: true},
46
+		"disabled caching":           {[]string{"--log-opt=cache-disabled=true"}, false},
47
+		"explicitly enabled caching": {[]string{"--log-opt=cache-disabled=false"}, true},
48
+	} {
49
+		t.Run(desc, func(t *testing.T) {
50
+			d.Start(t, append([]string{"--iptables=false"}, test.dOpts...)...)
51
+			defer d.Stop(t)
52
+			c, err := client.ContainerCreate(ctx,
53
+				cfg,
54
+				&container.HostConfig{LogConfig: container.LogConfig{Type: "test"}},
55
+				nil,
56
+				"",
57
+			)
58
+			assert.Assert(t, err)
59
+			defer client.ContainerRemove(ctx, c.ID, types.ContainerRemoveOptions{Force: true})
50 60
 
51
-	err = client.ContainerStart(ctx, c.ID, types.ContainerStartOptions{})
52
-	assert.Assert(t, err)
61
+			err = client.ContainerStart(ctx, c.ID, types.ContainerStartOptions{})
62
+			assert.Assert(t, err)
53 63
 
54
-	logs, err := client.ContainerLogs(ctx, c.ID, types.ContainerLogsOptions{ShowStdout: true})
55
-	assert.Assert(t, err)
56
-	defer logs.Close()
64
+			logs, err := client.ContainerLogs(ctx, c.ID, types.ContainerLogsOptions{ShowStdout: true})
65
+			if !test.logsSupported {
66
+				assert.Assert(t, err != nil)
67
+				return
68
+			}
69
+			assert.Assert(t, err)
70
+			defer logs.Close()
57 71
 
58
-	buf := bytes.NewBuffer(nil)
72
+			buf := bytes.NewBuffer(nil)
59 73
 
60
-	errCh := make(chan error)
61
-	go func() {
62
-		_, err := stdcopy.StdCopy(buf, buf, logs)
63
-		errCh <- err
64
-	}()
74
+			errCh := make(chan error)
75
+			go func() {
76
+				_, err := stdcopy.StdCopy(buf, buf, logs)
77
+				errCh <- err
78
+			}()
65 79
 
66
-	select {
67
-	case <-time.After(60 * time.Second):
68
-		t.Fatal("timeout waiting for IO to complete")
69
-	case err := <-errCh:
70
-		assert.Assert(t, err)
80
+			select {
81
+			case <-time.After(60 * time.Second):
82
+				t.Fatal("timeout waiting for IO to complete")
83
+			case err := <-errCh:
84
+				assert.Assert(t, err)
85
+			}
86
+			assert.Assert(t, strings.TrimSpace(buf.String()) == "hello world", buf.Bytes())
87
+		})
71 88
 	}
72
-	assert.Assert(t, strings.TrimSpace(buf.String()) == "hello world", buf.Bytes())
89
+
73 90
 }