Merge pull request #40921 from cpuguy83/19.03_log_rotate_error_handling

19.03: logfile: Check if log is closed on close error during rotate
Upstream-commit: c4c6cf6b6a353d7bdcd1e2f92eebec0d2c0b8cd9
Component: engine

Author: thaJeztah

components/engine/daemon/logger/loggerutils/logfile.go

@@ -175,8 +175,11 @@ func (w *LogFile) checkCapacityAndRotate() error {
 		w.rotateMu.Lock()
 		fname := w.f.Name()
 		if err := w.f.Close(); err != nil {
-			w.rotateMu.Unlock()
-			return errors.Wrap(err, "error closing file")
+			// if there was an error during a prior rotate, the file could already be closed
+			if !errors.Is(err, os.ErrClosed) {
+				w.rotateMu.Unlock()
+				return errors.Wrap(err, "error closing file")
+			}
 		}
 		if err := rotate(fname, w.maxFiles, w.compress); err != nil {
 			w.rotateMu.Unlock()

components/engine/daemon/logger/loggerutils/logfile_test.go

@@ -11,6 +11,7 @@ import (
 	"time"
 
 	"github.com/docker/docker/daemon/logger"
+	"github.com/docker/docker/pkg/pubsub"
 	"github.com/docker/docker/pkg/tailfile"
 	"gotest.tools/assert"
 )
@@ -201,3 +202,66 @@ func TestFollowLogsProducerGone(t *testing.T) {
 	default:
 	}
 }
+
+func TestCheckCapacityAndRotate(t *testing.T) {
+	dir, err := ioutil.TempDir("", t.Name())
+	assert.NilError(t, err)
+	defer os.RemoveAll(dir)
+
+	f, err := ioutil.TempFile(dir, "log")
+	assert.NilError(t, err)
+
+	l := &LogFile{
+		f:            f,
+		capacity:     5,
+		maxFiles:     3,
+		compress:     true,
+		notifyRotate: pubsub.NewPublisher(0, 1),
+		perms:        0600,
+		marshal: func(msg *logger.Message) ([]byte, error) {
+			return msg.Line, nil
+		},
+	}
+	defer l.Close()
+
+	assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")}))
+
+	dStringer := dirStringer{dir}
+
+	_, err = os.Stat(f.Name() + ".1")
+	assert.Assert(t, os.IsNotExist(err), dStringer)
+
+	assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")}))
+	_, err = os.Stat(f.Name() + ".1")
+	assert.NilError(t, err, dStringer)
+
+	assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")}))
+	_, err = os.Stat(f.Name() + ".1")
+	assert.NilError(t, err, dStringer)
+	_, err = os.Stat(f.Name() + ".2.gz")
+	assert.NilError(t, err, dStringer)
+
+	// Now let's simulate a failed rotation where the file was able to be closed but something else happened elsewhere
+	// down the line.
+	// We want to make sure that we can recover in the case that `l.f` was closed while attempting a rotation.
+	l.f.Close()
+	assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")}))
+}
+
+type dirStringer struct {
+	d string
+}
+
+func (d dirStringer) String() string {
+	ls, err := ioutil.ReadDir(d.d)
+	if err != nil {
+		return ""
+	}
+	var s strings.Builder
+	s.WriteString("\n")
+
+	for _, fi := range ls {
+		s.WriteString(fi.Name() + "\n")
+	}
+	return s.String()
+}

components/engine/vendor.conf

@@ -149,7 +149,7 @@ github.com/prometheus/client_model                  6f3806018612930941127f2a7c6c
 github.com/prometheus/common                        7600349dcfe1abd18d72d3a1770870d9800a7801
 github.com/prometheus/procfs                        7d6f385de8bea29190f15ba9931442a0eaef9af7
 github.com/matttproud/golang_protobuf_extensions    c12348ce28de40eed0136aa2b644d0ee0650e56c # v1.0.1
-github.com/pkg/errors                               ba968bfe8b2f7e042a574c888954fccecfa385b4 # v0.8.1
+github.com/pkg/errors                               614d223910a179a466c1767a985424175c39b465 # v0.9.1
 github.com/grpc-ecosystem/go-grpc-prometheus        c225b8c3b01faf2899099b768856a9e916e5087b # v1.2.0
 
 # cli