Upstream logging changes from Enterprise Edition by SamWhited · Pull Request #40543 · moby/moby

SamWhited · 2020-02-19T18:00:07Z

- What I did

Got permission from Mirantis to upstream logging changes.
Downloaded the patch from GitHub
git am ee-engine-pr-125.patch

ee-engine-pr-125.patch

From 949cb8a820903bbc80b548ac20f5b61a8c3f6f26 Mon Sep 17 00:00:00 2001
From: Brian Goff <cpuguy83@gmail.com>
Date: Thu, 5 Apr 2018 12:42:31 -0400
Subject: [PATCH 1/2] Support reads for all log drivers.

This supplements any log driver which does not support reads with a
custom read implementation that uses a local file cache.

Signed-off-by: Brian Goff <cpuguy83@gmail.com>
(cherry picked from commit d675e2bf2b75865915c7a4552e00802feeb0847f)
Signed-off-by: Madhu Venugopal <madhu@docker.com>
---
 container/container.go                        | 26 +++++-
 .../logger/loggerutils/cache/local_cache.go   | 62 ++++++++++++++
 .../plugin/logging/cmd/discard/driver.go      | 85 +++++++++++++++++++
 .../plugin/logging/cmd/discard/main.go        | 22 +++++
 .../plugin/logging/cmd/discard/main_test.go   |  1 +
 integration/plugin/logging/main_test.go       |  3 +
 integration/plugin/logging/read_test.go       | 73 ++++++++++++++++
 7 files changed, 270 insertions(+), 2 deletions(-)
 create mode 100644 daemon/logger/loggerutils/cache/local_cache.go
 create mode 100644 integration/plugin/logging/cmd/discard/driver.go
 create mode 100644 integration/plugin/logging/cmd/discard/main.go
 create mode 100644 integration/plugin/logging/cmd/discard/main_test.go
 create mode 100644 integration/plugin/logging/read_test.go

diff --git a/container/container.go b/container/container.go
index 6a5907c34b..4d79d65aa5 100644
--- a/container/container.go
+++ b/container/container.go
@@ -23,6 +23,7 @@ import (
 	"github.com/docker/docker/daemon/logger"
 	"github.com/docker/docker/daemon/logger/jsonfilelog"
 	"github.com/docker/docker/daemon/logger/local"
+	"github.com/docker/docker/daemon/logger/loggerutils/cache"
 	"github.com/docker/docker/daemon/network"
 	"github.com/docker/docker/errdefs"
 	"github.com/docker/docker/image"
@@ -104,8 +105,13 @@ type Container struct {
 	NoNewPrivileges bool
 
 	// Fields here are specific to Windows
-	NetworkSharedContainerID string   `json:"-"`
-	SharedEndpointList       []string `json:"-"`
+	NetworkSharedContainerID string            `json:"-"`
+	SharedEndpointList       []string          `json:"-"`
+	LocalLogCacheMeta        localLogCacheMeta `json:",omitempty"`
+}
+
+type localLogCacheMeta struct {
+	HaveNotifyEnabled bool
 }
 
 // NewBaseContainer creates a new container with its
@@ -415,6 +421,22 @@ func (container *Container) StartLogger() (logger.Logger, error) {
 		}
 		l = logger.NewRingLogger(l, info, bufferSize)
 	}
+
+	if _, ok := l.(logger.LogReader); !ok {
+		logPath, err := container.GetRootResourcePath("container-cached.log")
+		if err != nil {
+			return nil, err
+		}
+		info.LogPath = logPath
+
+		if !container.LocalLogCacheMeta.HaveNotifyEnabled {
+			logrus.WithField("container", container.ID).Info("Configured log driver does not support reads, enabling local file cache for container logs")
+		}
+		l, err = cache.WithLocalCache(l, info)
+		if err != nil {
+			return nil, errors.Wrap(err, "error setting up local container log cache")
+		}
+	}
 	return l, nil
 }
 
diff --git a/daemon/logger/loggerutils/cache/local_cache.go b/daemon/logger/loggerutils/cache/local_cache.go
new file mode 100644
index 0000000000..cf27b3e6c4
--- /dev/null
+++ b/daemon/logger/loggerutils/cache/local_cache.go
@@ -0,0 +1,62 @@
+package cache // import "github.com/docker/docker/daemon/logger/loggerutils/cache"
+
+import (
+	"github.com/docker/docker/daemon/logger"
+	"github.com/docker/docker/daemon/logger/local"
+	"github.com/sirupsen/logrus"
+)
+
+// WithLocalCache wraps the passed in logger with a logger caches all writes locally
+// in addition to writing to the passed in logger.
+func WithLocalCache(l logger.Logger, logInfo logger.Info) (logger.Logger, error) {
+	localLogger, err := local.New(logInfo)
+	if err != nil {
+		return nil, err
+	}
+	return &loggerWithCache{
+		l: l,
+		// TODO(@cpuguy83): Should this be configurable?
+		cache: logger.NewRingLogger(localLogger, logInfo, -1),
+	}, nil
+}
+
+type loggerWithCache struct {
+	l     logger.Logger
+	cache logger.Logger
+}
+
+func (l *loggerWithCache) Log(msg *logger.Message) error {
+	// copy the message since the underlying logger will return the passed in message to the message pool
+	dup := logger.NewMessage()
+	dumbCopyMessage(dup, msg)
+	if err := l.l.Log(msg); err != nil {
+		return err
+	}
+	return l.cache.Log(dup)
+}
+
+func (l *loggerWithCache) Name() string {
+	return l.l.Name()
+}
+
+func (l *loggerWithCache) ReadLogs(config logger.ReadConfig) *logger.LogWatcher {
+	return l.cache.(logger.LogReader).ReadLogs(config)
+}
+
+func (l *loggerWithCache) Close() error {
+	err := l.l.Close()
+	if err := l.cache.Close(); err != nil {
+		logrus.WithError(err).Warn("error while shutting cache logger")
+	}
+	return err
+}
+
+// dumbCopyMessage is a bit of a fake copy but avoids extra allocations which are not neccessary for this use case.
+func dumbCopyMessage(dst, src *logger.Message) {
+	dst.Source = src.Source
+	dst.Timestamp = src.Timestamp
+	dst.PLogMetaData = src.PLogMetaData
+	dst.Err = src.Err
+	dst.Attrs = src.Attrs
+	dst.Line = src.Line
+}
diff --git a/integration/plugin/logging/cmd/discard/driver.go b/integration/plugin/logging/cmd/discard/driver.go
new file mode 100644
index 0000000000..ccf2849cca
--- /dev/null
+++ b/integration/plugin/logging/cmd/discard/driver.go
@@ -0,0 +1,85 @@
+package main
+
+import (
+	"encoding/json"
+	"io"
+	"io/ioutil"
+	"net/http"
+	"os"
+	"sync"
+	"syscall"
+)
+
+type startLoggingRequest struct {
+	File string
+}
+
+type capabilitiesResponse struct {
+	Cap struct {
+		ReadLogs bool
+	}
+}
+
+type driver struct {
+	mu   sync.Mutex
+	logs map[string]io.Closer
+}
+
+type stopLoggingRequest struct {
+	File string
+}
+
+func handle(mux *http.ServeMux) {
+	d := &driver{logs: make(map[string]io.Closer)}
+	mux.HandleFunc("/LogDriver.StartLogging", func(w http.ResponseWriter, r *http.Request) {
+		var req startLoggingRequest
+		if err := json.NewDecoder(r.Body).Decode(&req); err != nil {
+			http.Error(w, err.Error(), http.StatusBadRequest)
+			return
+		}
+
+		f, err := os.OpenFile(req.File, syscall.O_RDONLY, 0700)
+		if err != nil {
+			respond(err, w)
+		}
+
+		d.mu.Lock()
+		d.logs[req.File] = f
+		d.mu.Unlock()
+
+		go io.Copy(ioutil.Discard, f)
+		respond(err, w)
+	})
+
+	mux.HandleFunc("/LogDriver.StopLogging", func(w http.ResponseWriter, r *http.Request) {
+		var req stopLoggingRequest
+		if err := json.NewDecoder(r.Body).Decode(&req); err != nil {
+			http.Error(w, err.Error(), http.StatusBadRequest)
+			return
+		}
+
+		d.mu.Lock()
+		if f := d.logs[req.File]; f != nil {
+			f.Close()
+		}
+		respond(nil, w)
+	})
+
+	mux.HandleFunc("/LogDriver.Capabilities", func(w http.ResponseWriter, r *http.Request) {
+		json.NewEncoder(w).Encode(&capabilitiesResponse{
+			Cap: struct{ ReadLogs bool }{ReadLogs: false},
+		})
+	})
+}
+
+type response struct {
+	Err string
+}
+
+func respond(err error, w io.Writer) {
+	var res response
+	if err != nil {
+		res.Err = err.Error()
+	}
+	json.NewEncoder(w).Encode(&res)
+}
diff --git a/integration/plugin/logging/cmd/discard/main.go b/integration/plugin/logging/cmd/discard/main.go
new file mode 100644
index 0000000000..15577ca0a9
--- /dev/null
+++ b/integration/plugin/logging/cmd/discard/main.go
@@ -0,0 +1,22 @@
+package main
+
+import (
+	"net"
+	"net/http"
+)
+
+func main() {
+	l, err := net.Listen("unix", "/run/docker/plugins/plugin.sock")
+	if err != nil {
+		panic(err)
+	}
+
+	mux := http.NewServeMux()
+	handle(mux)
+
+	server := http.Server{
+		Addr:    l.Addr().String(),
+		Handler: mux,
+	}
+	server.Serve(l)
+}
diff --git a/integration/plugin/logging/cmd/discard/main_test.go b/integration/plugin/logging/cmd/discard/main_test.go
new file mode 100644
index 0000000000..06ab7d0f9a
--- /dev/null
+++ b/integration/plugin/logging/cmd/discard/main_test.go
@@ -0,0 +1 @@
+package main
diff --git a/integration/plugin/logging/main_test.go b/integration/plugin/logging/main_test.go
index e1292a5718..f384f53730 100644
--- a/integration/plugin/logging/main_test.go
+++ b/integration/plugin/logging/main_test.go
@@ -19,6 +19,9 @@ func TestMain(m *testing.M) {
 		fmt.Println(err)
 		os.Exit(1)
 	}
+	if testEnv.OSType != "linux" {
+		os.Exit(0)
+	}
 	err = environment.EnsureFrozenImagesLinux(testEnv)
 	if err != nil {
 		fmt.Println(err)
diff --git a/integration/plugin/logging/read_test.go b/integration/plugin/logging/read_test.go
new file mode 100644
index 0000000000..f764e7809a
--- /dev/null
+++ b/integration/plugin/logging/read_test.go
@@ -0,0 +1,73 @@
+package logging
+
+import (
+	"bytes"
+	"testing"
+
+	"context"
+
+	"time"
+
+	"strings"
+
+	"github.com/docker/docker/api/types"
+	"github.com/docker/docker/api/types/container"
+	"github.com/docker/docker/internal/test/daemon"
+	"github.com/docker/docker/pkg/stdcopy"
+	"gotest.tools/assert"
+)
+
+// TestReadPluginNoRead tests that reads are supported even if the plugin isn't capable.
+func TestReadPluginNoRead(t *testing.T) {
+	t.Parallel()
+	d := daemon.New(t)
+	d.StartWithBusybox(t, "--iptables=false")
+	defer d.Stop(t)
+
+	client, err := d.NewClient()
+	assert.Assert(t, err)
+	createPlugin(t, client, "test", "discard", asLogDriver)
+
+	ctx := context.Background()
+	defer func() {
+		err = client.PluginRemove(ctx, "test", types.PluginRemoveOptions{Force: true})
+		assert.Check(t, err)
+	}()
+
+	err = client.PluginEnable(ctx, "test", types.PluginEnableOptions{Timeout: 30})
+	assert.Check(t, err)
+
+	c, err := client.ContainerCreate(ctx,
+		&container.Config{
+			Image: "busybox",
+			Cmd:   []string{"/bin/echo", "hello world"},
+		},
+		&container.HostConfig{LogConfig: container.LogConfig{Type: "test"}},
+		nil,
+		"",
+	)
+	assert.Assert(t, err)
+
+	err = client.ContainerStart(ctx, c.ID, types.ContainerStartOptions{})
+	assert.Assert(t, err)
+
+	logs, err := client.ContainerLogs(ctx, c.ID, types.ContainerLogsOptions{ShowStdout: true})
+	assert.Assert(t, err)
+	defer logs.Close()
+
+	buf := bytes.NewBuffer(nil)
+
+	errCh := make(chan error)
+	go func() {
+		_, err := stdcopy.StdCopy(buf, buf, logs)
+		errCh <- err
+	}()
+
+	select {
+	case <-time.After(60 * time.Second):
+		t.Fatal("timeout waiting for IO to complete")
+	case err := <-errCh:
+		assert.Assert(t, err)
+	}
+	assert.Assert(t, strings.TrimSpace(buf.String()) == "hello world", buf.Bytes())
+}

From ec432cda4be140457bbc433b1b25f6d04dafa286 Mon Sep 17 00:00:00 2001
From: Brian Goff <cpuguy83@gmail.com>
Date: Mon, 9 Apr 2018 15:35:24 -0400
Subject: [PATCH 2/2] 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>
---
 container/container.go                        | 25 +++---
 daemon/logdrivers_linux.go                    |  1 +
 daemon/logdrivers_windows.go                  |  1 +
 daemon/logger/factory.go                      |  4 +
 daemon/logger/log_cache_opts.go               | 29 +++++++
 .../logger/loggerutils/cache/local_cache.go   | 61 ++++++++++++--
 .../loggerutils/cache/log_cache_test.go       | 81 +++++++++++++++++++
 daemon/logger/loggerutils/cache/validate.go   | 40 +++++++++
 daemon/logs.go                                |  4 +
 .../plugin/logging/cmd/discard/driver.go      |  1 +
 integration/plugin/logging/read_test.go       | 79 +++++++++++-------
 11 files changed, 277 insertions(+), 49 deletions(-)
 create mode 100644 daemon/logger/log_cache_opts.go
 create mode 100644 daemon/logger/loggerutils/cache/log_cache_test.go
 create mode 100644 daemon/logger/loggerutils/cache/validate.go

diff --git a/container/container.go b/container/container.go
index 4d79d65aa5..8ae89bc98b 100644
--- a/container/container.go
+++ b/container/container.go
@@ -423,18 +423,21 @@ func (container *Container) StartLogger() (logger.Logger, error) {
 	}
 
 	if _, ok := l.(logger.LogReader); !ok {
-		logPath, err := container.GetRootResourcePath("container-cached.log")
-		if err != nil {
-			return nil, err
-		}
-		info.LogPath = logPath
+		if cache.ShouldUseCache(cfg.Config) {
+			logPath, err := container.GetRootResourcePath("container-cached.log")
+			if err != nil {
+				return nil, err
+			}
 
-		if !container.LocalLogCacheMeta.HaveNotifyEnabled {
-			logrus.WithField("container", container.ID).Info("Configured log driver does not support reads, enabling local file cache for container logs")
-		}
-		l, err = cache.WithLocalCache(l, info)
-		if err != nil {
-			return nil, errors.Wrap(err, "error setting up local container log cache")
+			if !container.LocalLogCacheMeta.HaveNotifyEnabled {
+				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")
+				container.LocalLogCacheMeta.HaveNotifyEnabled = true
+			}
+			info.LogPath = logPath
+			l, err = cache.WithLocalCache(l, info)
+			if err != nil {
+				return nil, errors.Wrap(err, "error setting up local container log cache")
+			}
 		}
 	}
 	return l, nil
diff --git a/daemon/logdrivers_linux.go b/daemon/logdrivers_linux.go
index 67154a7a98..425f412b20 100644
--- a/daemon/logdrivers_linux.go
+++ b/daemon/logdrivers_linux.go
@@ -11,6 +11,7 @@ import (
 	_ "github.com/docker/docker/daemon/logger/jsonfilelog"
 	_ "github.com/docker/docker/daemon/logger/local"
 	_ "github.com/docker/docker/daemon/logger/logentries"
+	_ "github.com/docker/docker/daemon/logger/loggerutils/cache"
 	_ "github.com/docker/docker/daemon/logger/splunk"
 	_ "github.com/docker/docker/daemon/logger/syslog"
 )
diff --git a/daemon/logdrivers_windows.go b/daemon/logdrivers_windows.go
index 62e7a6f95b..62dd1ecb86 100644
--- a/daemon/logdrivers_windows.go
+++ b/daemon/logdrivers_windows.go
@@ -9,6 +9,7 @@ import (
 	_ "github.com/docker/docker/daemon/logger/gelf"
 	_ "github.com/docker/docker/daemon/logger/jsonfilelog"
 	_ "github.com/docker/docker/daemon/logger/logentries"
+	_ "github.com/docker/docker/daemon/logger/loggerutils/cache"
 	_ "github.com/docker/docker/daemon/logger/splunk"
 	_ "github.com/docker/docker/daemon/logger/syslog"
 )
diff --git a/daemon/logger/factory.go b/daemon/logger/factory.go
index 84b54b2794..52e0a91f21 100644
--- a/daemon/logger/factory.go
+++ b/daemon/logger/factory.go
@@ -143,6 +143,10 @@ func ValidateLogOpts(name string, cfg map[string]string) error {
 		}
 	}
 
+	if err := validateExternal(cfg); err != nil {
+		return err
+	}
+
 	if !factory.driverRegistered(name) {
 		return fmt.Errorf("logger: no log driver named '%s' is registered", name)
 	}
diff --git a/daemon/logger/log_cache_opts.go b/daemon/logger/log_cache_opts.go
new file mode 100644
index 0000000000..8d09c489ed
--- /dev/null
+++ b/daemon/logger/log_cache_opts.go
@@ -0,0 +1,29 @@
+package logger
+
+var externalValidators []LogOptValidator
+
+// RegisterExternalValidator adds the validator to the list of external validators.
+// External validators are used by packages outside this package that need to add their own validation logic.
+// This should only be called on package initialization.
+func RegisterExternalValidator(v LogOptValidator) {
+	externalValidators = append(externalValidators, v)
+}
+
+// AddBuiltinLogOpts updates the list of built-in log opts. This allows other packages to supplement additional log options
+// without having to register an actual log driver. This is used by things that are more proxy log drivers and should
+// not be exposed as a usable log driver to the API.
+// This should only be called on package initialization.
+func AddBuiltinLogOpts(opts map[string]bool) {
+	for k, v := range opts {
+		builtInLogOpts[k] = v
+	}
+}
+
+func validateExternal(cfg map[string]string) error {
+	for _, v := range externalValidators {
+		if err := v(cfg); err != nil {
+			return err
+		}
+	}
+	return nil
+}
diff --git a/daemon/logger/loggerutils/cache/local_cache.go b/daemon/logger/loggerutils/cache/local_cache.go
index cf27b3e6c4..8f2047bc93 100644
--- a/daemon/logger/loggerutils/cache/local_cache.go
+++ b/daemon/logger/loggerutils/cache/local_cache.go
@@ -1,22 +1,55 @@
 package cache // import "github.com/docker/docker/daemon/logger/loggerutils/cache"
 
 import (
+	"strconv"
+
+	"github.com/docker/docker/api/types/container"
 	"github.com/docker/docker/daemon/logger"
 	"github.com/docker/docker/daemon/logger/local"
+	units "github.com/docker/go-units"
+	"github.com/pkg/errors"
 	"github.com/sirupsen/logrus"
 )
 
+const (
+	// DriverName is the name of the driver used for local log caching
+	DriverName = local.Name
+
+	cachePrefix      = "cache-"
+	cacheDisabledKey = cachePrefix + "disabled"
+)
+
+var builtInCacheLogOpts = map[string]bool{
+	cacheDisabledKey: true,
+}
+
 // WithLocalCache wraps the passed in logger with a logger caches all writes locally
 // in addition to writing to the passed in logger.
-func WithLocalCache(l logger.Logger, logInfo logger.Info) (logger.Logger, error) {
-	localLogger, err := local.New(logInfo)
+func WithLocalCache(l logger.Logger, info logger.Info) (logger.Logger, error) {
+	initLogger, err := logger.GetLogDriver(DriverName)
 	if err != nil {
 		return nil, err
 	}
+
+	cacher, err := initLogger(info)
+	if err != nil {
+		return nil, errors.Wrap(err, "error initializing local log cache driver")
+	}
+
+	if info.Config["mode"] == container.LogModeUnset || container.LogMode(info.Config["mode"]) == container.LogModeNonBlock {
+		var size int64 = -1
+		if s, exists := info.Config["max-buffer-size"]; exists {
+			size, err = units.RAMInBytes(s)
+			if err != nil {
+				return nil, err
+			}
+		}
+		cacher = logger.NewRingLogger(cacher, info, size)
+	}
+
 	return &loggerWithCache{
-		l: l,
-		// TODO(@cpuguy83): Should this be configurable?
-		cache: logger.NewRingLogger(localLogger, logInfo, -1),
+		l:     l,
+		cache: cacher,
 	}, nil
 }
 
@@ -26,9 +59,10 @@ type loggerWithCache struct {
 }
 
 func (l *loggerWithCache) Log(msg *logger.Message) error {
-	// copy the message since the underlying logger will return the passed in message to the message pool
+	// copy the message as the original will be reset once the call to `Log` is complete
 	dup := logger.NewMessage()
 	dumbCopyMessage(dup, msg)
+
 	if err := l.l.Log(msg); err != nil {
 		return err
 	}
@@ -51,6 +85,19 @@ func (l *loggerWithCache) Close() error {
 	return err
 }
 
+// ShouldUseCache reads the log opts to determine if caching should be enabled
+func ShouldUseCache(cfg map[string]string) bool {
+	if cfg[cacheDisabledKey] == "" {
+		return true
+	}
+	b, err := strconv.ParseBool(cfg[cacheDisabledKey])
+	if err != nil {
+		// This shouldn't happen since the values are validated before hand.
+		return false
+	}
+	return !b
+}
+
 // dumbCopyMessage is a bit of a fake copy but avoids extra allocations which are not neccessary for this use case.
 func dumbCopyMessage(dst, src *logger.Message) {
 	dst.Source = src.Source
@@ -58,5 +105,5 @@ func dumbCopyMessage(dst, src *logger.Message) {
 	dst.PLogMetaData = src.PLogMetaData
 	dst.Err = src.Err
 	dst.Attrs = src.Attrs
-	dst.Line = src.Line
+	dst.Line = append(dst.Line[:0], src.Line...)
 }
diff --git a/daemon/logger/loggerutils/cache/log_cache_test.go b/daemon/logger/loggerutils/cache/log_cache_test.go
new file mode 100644
index 0000000000..b7580ffc2f
--- /dev/null
+++ b/daemon/logger/loggerutils/cache/log_cache_test.go
@@ -0,0 +1,81 @@
+package cache
+
+import (
+	"context"
+	"testing"
+
+	"time"
+
+	"bytes"
+
+	"github.com/docker/docker/daemon/logger"
+	"gotest.tools/assert"
+	"gotest.tools/assert/cmp"
+)
+
+type fakeLogger struct {
+	messages chan logger.Message
+	close    chan struct{}
+}
+
+func (l *fakeLogger) Log(msg *logger.Message) error {
+	select {
+	case l.messages <- *msg:
+	case <-l.close:
+	}
+	logger.PutMessage(msg)
+	return nil
+}
+
+func (l *fakeLogger) Name() string {
+	return "fake"
+}
+
+func (l *fakeLogger) Close() error {
+	close(l.close)
+	return nil
+}
+
+func TestLog(t *testing.T) {
+	cacher := &fakeLogger{make(chan logger.Message), make(chan struct{})}
+	l := &loggerWithCache{
+		l:     &fakeLogger{make(chan logger.Message, 100), make(chan struct{})},
+		cache: cacher,
+	}
+	defer l.Close()
+
+	var messages []logger.Message
+	for i := 0; i < 100; i++ {
+		messages = append(messages, logger.Message{
+			Timestamp: time.Now(),
+			Line:      append(bytes.Repeat([]byte("a"), 100), '\n'),
+		})
+	}
+
+	ctx, cancel := context.WithTimeout(context.Background(), 60*time.Second)
+	defer cancel()
+
+	go func() {
+		for _, msg := range messages {
+			select {
+			case <-ctx.Done():
+				return
+			default:
+			}
+
+			m := logger.NewMessage()
+			dumbCopyMessage(m, &msg)
+			l.Log(m)
+		}
+	}()
+
+	for _, m := range messages {
+		var msg logger.Message
+		select {
+		case <-ctx.Done():
+			t.Fatal("timed out waiting for messages... this is probably a test implementation error")
+		case msg = <-cacher.messages:
+			assert.Assert(t, cmp.DeepEqual(msg, m))
+		}
+	}
+}
diff --git a/daemon/logger/loggerutils/cache/validate.go b/daemon/logger/loggerutils/cache/validate.go
new file mode 100644
index 0000000000..70bd8810d0
--- /dev/null
+++ b/daemon/logger/loggerutils/cache/validate.go
@@ -0,0 +1,40 @@
+package cache
+
+import (
+	"strconv"
+
+	"github.com/docker/docker/daemon/logger"
+	"github.com/docker/docker/daemon/logger/local"
+	"github.com/pkg/errors"
+)
+
+func init() {
+	for k, v := range local.LogOptKeys {
+		builtInCacheLogOpts[cachePrefix+k] = v
+	}
+	logger.AddBuiltinLogOpts(builtInCacheLogOpts)
+	logger.RegisterExternalValidator(validateLogCacheOpts)
+}
+
+func validateLogCacheOpts(cfg map[string]string) error {
+	if v := cfg[cacheDisabledKey]; v != "" {
+		_, err := strconv.ParseBool(v)
+		if err != nil {
+			return errors.Errorf("invalid value for option %s: %s", cacheDisabledKey, cfg[cacheDisabledKey])
+		}
+	}
+	return nil
+}
+
+// MergeDefaultLogConfig reads the default log opts and makes sure that any caching related keys that exist there are
+// added to dst.
+func MergeDefaultLogConfig(dst, defaults map[string]string) {
+	for k, v := range defaults {
+		if !builtInCacheLogOpts[k] {
+			continue
+		}
+		if _, exists := dst[k]; !exists {
+			dst[k] = v
+		}
+	}
+}
diff --git a/daemon/logs.go b/daemon/logs.go
index 37ca4caf63..a4b62175f3 100644
--- a/daemon/logs.go
+++ b/daemon/logs.go
@@ -11,6 +11,7 @@ import (
 	timetypes "github.com/docker/docker/api/types/time"
 	"github.com/docker/docker/container"
 	"github.com/docker/docker/daemon/logger"
+	logcache "github.com/docker/docker/daemon/logger/loggerutils/cache"
 	"github.com/docker/docker/errdefs"
 	"github.com/pkg/errors"
 	"github.com/sirupsen/logrus"
@@ -190,6 +191,8 @@ func (daemon *Daemon) mergeAndVerifyLogConfig(cfg *containertypes.LogConfig) err
 		}
 	}
 
+	logcache.MergeDefaultLogConfig(cfg.Config, daemon.defaultLogConfig.Config)
+
 	return logger.ValidateLogOpts(cfg.Type, cfg.Config)
 }
 
@@ -204,6 +207,7 @@ func (daemon *Daemon) setupDefaultLogConfig() error {
 		Type:   config.LogConfig.Type,
 		Config: config.LogConfig.Config,
 	}
+
 	logrus.Debugf("Using default logging driver %s", daemon.defaultLogConfig.Type)
 	return nil
 }
diff --git a/integration/plugin/logging/cmd/discard/driver.go b/integration/plugin/logging/cmd/discard/driver.go
index ccf2849cca..e02b56e88f 100644
--- a/integration/plugin/logging/cmd/discard/driver.go
+++ b/integration/plugin/logging/cmd/discard/driver.go
@@ -62,6 +62,7 @@ func handle(mux *http.ServeMux) {
 		if f := d.logs[req.File]; f != nil {
 			f.Close()
 		}
+		d.mu.Unlock()
 		respond(nil, w)
 	})
 
diff --git a/integration/plugin/logging/read_test.go b/integration/plugin/logging/read_test.go
index f764e7809a..a43310b2dc 100644
--- a/integration/plugin/logging/read_test.go
+++ b/integration/plugin/logging/read_test.go
@@ -29,45 +29,62 @@ func TestReadPluginNoRead(t *testing.T) {
 	createPlugin(t, client, "test", "discard", asLogDriver)
 
 	ctx := context.Background()
-	defer func() {
-		err = client.PluginRemove(ctx, "test", types.PluginRemoveOptions{Force: true})
-		assert.Check(t, err)
-	}()
 
 	err = client.PluginEnable(ctx, "test", types.PluginEnableOptions{Timeout: 30})
 	assert.Check(t, err)
+	d.Stop(t)
 
-	c, err := client.ContainerCreate(ctx,
-		&container.Config{
-			Image: "busybox",
-			Cmd:   []string{"/bin/echo", "hello world"},
-		},
-		&container.HostConfig{LogConfig: container.LogConfig{Type: "test"}},
-		nil,
-		"",
-	)
-	assert.Assert(t, err)
+	cfg := &container.Config{
+		Image: "busybox",
+		Cmd:   []string{"/bin/echo", "hello world"},
+	}
+	for desc, test := range map[string]struct {
+		dOpts         []string
+		logsSupported bool
+	}{
+		"default":                    {logsSupported: true},
+		"disabled caching":           {[]string{"--log-opt=cache-disabled=true"}, false},
+		"explicitly enabled caching": {[]string{"--log-opt=cache-disabled=false"}, true},
+	} {
+		t.Run(desc, func(t *testing.T) {
+			d.Start(t, append([]string{"--iptables=false"}, test.dOpts...)...)
+			defer d.Stop(t)
+			c, err := client.ContainerCreate(ctx,
+				cfg,
+				&container.HostConfig{LogConfig: container.LogConfig{Type: "test"}},
+				nil,
+				"",
+			)
+			assert.Assert(t, err)
+			defer client.ContainerRemove(ctx, c.ID, types.ContainerRemoveOptions{Force: true})
 
-	err = client.ContainerStart(ctx, c.ID, types.ContainerStartOptions{})
-	assert.Assert(t, err)
+			err = client.ContainerStart(ctx, c.ID, types.ContainerStartOptions{})
+			assert.Assert(t, err)
 
-	logs, err := client.ContainerLogs(ctx, c.ID, types.ContainerLogsOptions{ShowStdout: true})
-	assert.Assert(t, err)
-	defer logs.Close()
+			logs, err := client.ContainerLogs(ctx, c.ID, types.ContainerLogsOptions{ShowStdout: true})
+			if !test.logsSupported {
+				assert.Assert(t, err != nil)
+				return
+			}
+			assert.Assert(t, err)
+			defer logs.Close()
 
-	buf := bytes.NewBuffer(nil)
+			buf := bytes.NewBuffer(nil)
 
-	errCh := make(chan error)
-	go func() {
-		_, err := stdcopy.StdCopy(buf, buf, logs)
-		errCh <- err
-	}()
+			errCh := make(chan error)
+			go func() {
+				_, err := stdcopy.StdCopy(buf, buf, logs)
+				errCh <- err
+			}()
 
-	select {
-	case <-time.After(60 * time.Second):
-		t.Fatal("timeout waiting for IO to complete")
-	case err := <-errCh:
-		assert.Assert(t, err)
+			select {
+			case <-time.After(60 * time.Second):
+				t.Fatal("timeout waiting for IO to complete")
+			case err := <-errCh:
+				assert.Assert(t, err)
+			}
+			assert.Assert(t, strings.TrimSpace(buf.String()) == "hello world", buf.Bytes())
+		})
 	}
-	assert.Assert(t, strings.TrimSpace(buf.String()) == "hello world", buf.Bytes())
+
 }

thaJeztah · 2020-02-19T21:26:48Z

Nice!!

Looks like you need to update the import path for gotest.tools (which now has a /v3 path);

Z] 
[2020-02-19T18:23:16.269Z] 
[2020-02-19T18:23:16.269Z] === Errors
[2020-02-19T18:23:16.269Z] package github.com/docker/docker/daemon/logger/loggerutils/cache (test)
[2020-02-19T18:23:16.269Z] 	imports gotest.tools/assert: cannot find package "gotest.tools/assert" in any of:
[2020-02-19T18:23:16.269Z] 	/go/src/github.com/docker/docker/vendor/gotest.tools/assert (vendor tree)
[2020-02-19T18:23:16.269Z] 	/usr/local/go/src/gotest.tools/assert (from $GOROOT)
[2020-02-19T18:23:16.269Z] 	/go/src/gotest.tools/assert (from $GOPATH)

SamWhited · 2020-02-19T21:35:23Z

Rebased with the import path change; waiting on CI to run again.

integration/plugin/logging/main_test.go

This supplements any log driver which does not support reads with a custom read implementation that uses a local file cache. Signed-off-by: Brian Goff <cpuguy83@gmail.com> (cherry picked from commit d675e2bf2b75865915c7a4552e00802feeb0847f) Signed-off-by: Madhu Venugopal <madhu@docker.com>

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>

SamWhited · 2020-02-19T22:05:55Z

Done. Also pushed a few linter / other package import fixes. Waiting on CI again to see if any tests actually need to be skipped.

thaJeztah · 2020-02-20T00:28:44Z

looks like it's mostly green; for Windows, I think we need an explicit "skip" in the integration test

cpuguy83 · 2020-02-21T17:54:05Z

Interesting failure on ppc64

[2020-02-20T05:10:10.105Z] --- FAIL: TestTemplatedConfig (2.24s)

[2020-02-20T05:10:10.105Z] panic: reflect: call of reflect.Value.IsNil on struct Value [recovered]

[2020-02-20T05:10:10.105Z] 	panic: reflect: call of reflect.Value.IsNil on struct Value

[2020-02-20T05:10:10.105Z] 

[2020-02-20T05:10:10.105Z] goroutine 99 [running]:

[2020-02-20T05:10:10.105Z] testing.tRunner.func1(0xc00081a000)

[2020-02-20T05:10:10.105Z] 	/usr/local/go/src/testing/testing.go:874 +0x380

[2020-02-20T05:10:10.105Z] panic(0x534840, 0xc0007df2c0)

[2020-02-20T05:10:10.105Z] 	/usr/local/go/src/runtime/panic.go:679 +0x1bc

[2020-02-20T05:10:10.105Z] reflect.Value.IsNil(...)

[2020-02-20T05:10:10.105Z] 	/usr/local/go/src/reflect/value.go:1073

[2020-02-20T05:10:10.105Z] github.com/docker/docker/vendor/gotest.tools/v3/assert.assert(0x6b7980, 0xc00081a000, 0xc0008874d8, 0x604268, 0x57b180, 0xc0007f48e0, 0xc000887638, 0x1, 0x1, 0x0)

[2020-02-20T05:10:10.105Z] 	/go/src/github.com/docker/docker/vendor/gotest.tools/v3/assert/assert.go:123 +0x6d0

[2020-02-20T05:10:10.105Z] github.com/docker/docker/vendor/gotest.tools/v3/assert.NilError(0x6b7980, 0xc00081a000, 0x6abf20, 0xc0007f48e0,

cpuguy83

LGTM

Except I wrote the original code, so 🤷‍♂

See issue #40193 Signed-off-by: Sam Whited <sam@samwhited.com>

integration/plugin/logging/cmd/discard/main_test.go

thaJeztah · 2020-02-27T12:53:31Z

After this is merged, we need some update to the documentation

update the requirements (currently listing as "ee only"); https://github.com/docker/docker.github.io/blob/master/config/containers/logging/dual-logging.md
update the Limitations of logging drivers section
perhaps combine the two pages above
docker logs reference
- update the "Note: this command is only functional for containers that are started with the json-file or journald logging driver." (mention which versions no longer require this, or remove the note)

thaJeztah

LGTM

jraby · 2021-01-15T01:01:35Z

Note for future users who might be surprised to find a ~~huge~~ container-cached.log in /var/lib/docker/containers/<cid> when the logging driver is set to syslog:

it is possible to avoid the local copy of the logs by passing the cache-disabled=true log-opt.

(the file is rotated and a limit of 4 older files are kept, gzipped, so they're not huge)

cpuguy83 · 2021-01-15T01:02:50Z

@jraby Huge? How big?

jraby · 2021-01-15T01:09:34Z

I guess I spoke too soon, the file doesn't grow above ~20something mb before getting rotated and gzipped.

ChristianCiach · 2021-01-19T10:51:06Z

* update the requirements (currently listing as "ee only")

@thaJeztah This documentation still claims that dual-logging is not available in Docker CE: https://docs.docker.com/config/containers/logging/configure/#limitations-of-logging-drivers

EDIT: This documentation also says that this is an enterprise-only feature: https://docs.docker.com/config/containers/logging/dual-logging/

I am so confused. This blog post doesn't mention anything about being enterprise-only: https://www.docker.com/blog/introducing-docker-engine-20-10/

Is the documentation outdated or is this still an enterprise-only feature?

leanlaufer · 2021-03-17T09:44:55Z

After this is merged, we need some update to the documentation

update the requirements (currently listing as "ee only"); https://github.com/docker/docker.github.io/blob/master/config/containers/logging/dual-logging.md

update the Limitations of logging drivers section

perhaps combine the two pages above

docker logs reference

update the "Note: this command is only functional for containers that are started with the json-file or journald logging driver." (mention which versions no longer require this, or remove the note)

@thaJeztah
so now if I use some logging driver, how can I configure the default json-file driver that is enabled by default ( like max-size,max_file, disable ) because now there is container-cached.log file that can explode the file system.
maybe this should be also in the new documentation.

thaJeztah · 2021-03-17T10:13:13Z

so now if I use some logging driver, how can I configure the default json-file driver that is enabled by default ( like max-size,max_file, disable ) because now there is container-cached.log file that can explode the file system.
maybe this should be also in the new documentation.

Hmm. not sure I fully understand your comment;

If you were/are using the default (json-file) logging driver, nothing changed (everything is the same as before, which includes: no limit/rotating by default)
If you were/are using the local logging driver, nothing changed (everything is the same as before, and the local logging driver comes with limit/rotation by default: max 5 files of 20MB each (per container))
same for other logging drivers that already were supported by docker logs (i.e., allowed reading back logs using the docker logs command)
If you were/are using a logging driver was not supported by docker logs, in that case, the "dual logging" feature will be used, and the local logging driver is also enabled, to act as a "ring buffer" to allow reading back the logs (size should be limited by the local logging driver). You can disable the feature through the cache-disabled=true log-opt (looks like that's not documented, so should be added to the docs)

leanlaufer · 2021-03-17T11:59:16Z

@thaJeztah , sorry that I wasn't so clear.
as you said, I was talking about the third scenario.
if I use a logging driver that was not supported by docker logs, there is no documentation about how to configure the default local logging driver that also runs.
I mean that there is no documentation about "dual-logging" daemon.json, with this new feature.

wojons · 2021-04-07T01:44:32Z

I have questions about the 3rd case also. (Using a remote driver). I wanted to tune or configure the "log cache" settings to fit system better.

Also I have docker swarm. Will this allow me to still call docker service logs from a manager when the log driver of the service is "remote" and use the "log cache"

holycheater · 2021-04-16T09:35:36Z

Is there an undocumented option to turn this off globally?
I wonder why this is an opt-out feature, not an opt-in.

cpuguy83 · 2021-04-16T12:38:35Z

You can set --log-opt cache=disabled on the daemon.

cpuguy83 · 2021-04-16T13:43:21Z

Sorry, --log-opt cache-disabled=1

thaJeztah · 2021-04-17T13:16:43Z

@cpuguy83 I opened docker/cli#3052 and docker/cli#3052 - ptal (please double check if they can indeed be configured in combination with driver-specific options for the configured driver)

thaJeztah added area/logging docs/revisit impact/changelog impact/documentation kind/feature Functionality or other elements that the project doesn't currently have. Features are new and shiny status/2-code-review labels Feb 19, 2020

thaJeztah added this to the 20.03.0 milestone Feb 19, 2020

thaJeztah reviewed Feb 19, 2020

View reviewed changes

integration/plugin/logging/main_test.go Outdated Show resolved Hide resolved

cpuguy83 added 2 commits February 19, 2020 17:01

cpuguy83 approved these changes Feb 21, 2020

View reviewed changes

Always execute tests and skip in tests themselves

a6f9923

See issue #40193 Signed-off-by: Sam Whited <sam@samwhited.com>

AkihiroSuda reviewed Feb 26, 2020

View reviewed changes

integration/plugin/logging/cmd/discard/main_test.go Show resolved Hide resolved

AkihiroSuda approved these changes Feb 26, 2020

View reviewed changes

thaJeztah approved these changes Feb 27, 2020

View reviewed changes

thaJeztah merged commit 3967999 into moby:master Feb 27, 2020

cpuguy83 mentioned this pull request Mar 2, 2020

[Proposal] Enhance local logging / remote logging #33475

Closed

2 tasks

thaJeztah mentioned this pull request Apr 8, 2020

container config section: various markdown fixes docker/docs#10599

Merged

thaJeztah mentioned this pull request Jul 23, 2020

journald log driver send timestamp to systemd, doubles timestamp #41243

Closed

thaJeztah mentioned this pull request Aug 4, 2020

Add 'local' to list of logging drivers that support docker-compose logs docker/compose#7425

Merged

thaJeztah mentioned this pull request Sep 10, 2020

docker logs should be able to provide some amount of logs regardless of 3rd party logging driver #30887

Closed

This was referenced Nov 3, 2020

Allow multiple log drivers #32429

Closed

Send log to multiple log drivers #17910

Closed

SamWhited deleted the upstream_logging branch January 15, 2021 12:22

thaJeztah mentioned this pull request Jan 20, 2021

Rewrite logging section for dual logging (engine 20.10), and update post-install docker/docs#12139

Merged

thaJeztah removed the docs/revisit label Jan 20, 2021

thaJeztah mentioned this pull request Jan 28, 2021

Remove local check for log-driver read support docker/compose#8082

Merged

This was referenced Apr 17, 2021

logging: document dual-logging cache options docker/docs#12696

Merged

docs: document log-opts for "dual logging" cache docker/cli#3052

Merged

thaJeztah mentioned this pull request Nov 28, 2023

docs: refactor cli run reference docker/cli#4615

Merged

Conversation

SamWhited commented Feb 19, 2020 • edited by thaJeztah Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

thaJeztah commented Feb 19, 2020

Uh oh!

SamWhited commented Feb 19, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

SamWhited commented Feb 19, 2020

Uh oh!

thaJeztah commented Feb 20, 2020

Uh oh!

cpuguy83 commented Feb 21, 2020

Uh oh!

cpuguy83 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

thaJeztah commented Feb 27, 2020

Uh oh!

thaJeztah left a comment

Choose a reason for hiding this comment

Uh oh!

jraby commented Jan 15, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

cpuguy83 commented Jan 15, 2021

Uh oh!

jraby commented Jan 15, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ChristianCiach commented Jan 19, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

leanlaufer commented Mar 17, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

thaJeztah commented Mar 17, 2021

Uh oh!

leanlaufer commented Mar 17, 2021

Uh oh!

wojons commented Apr 7, 2021

Uh oh!

holycheater commented Apr 16, 2021

Uh oh!

cpuguy83 commented Apr 16, 2021

Uh oh!

cpuguy83 commented Apr 16, 2021

Uh oh!

thaJeztah commented Apr 17, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

9 participants

SamWhited commented Feb 19, 2020 •

edited by thaJeztah

Loading

SamWhited commented Feb 19, 2020 •

edited

Loading

jraby commented Jan 15, 2021 •

edited

Loading

jraby commented Jan 15, 2021 •

edited

Loading

ChristianCiach commented Jan 19, 2021 •

edited

Loading

leanlaufer commented Mar 17, 2021 •

edited

Loading