Merge pull request moby#40920 from cpuguy83/log_rotate_error_handling

cpuguy83 · web-flow · commit 75d655320e2a · 2020-05-07T14:45:42.000-07:00
logfile: Check if log is closed on close error during rotate
diff --git a/daemon/logger/loggerutils/logfile.go b/daemon/logger/loggerutils/logfile.go
@@ -188,8 +188,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()
diff --git a/daemon/logger/loggerutils/logfile_test.go b/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/v3/assert"
 )
@@ -235,3 +236,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()
+}
