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

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()

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()
+}

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

vendor/github.com/pkg/errors/README.md

@@ -41,11 +41,18 @@ default:
 
 [Read the package documentation for more information](https://godoc.org/github.com/pkg/errors).
 
+## Roadmap
+
+With the upcoming [Go2 error proposals](https://go.googlesource.com/proposal/+/master/design/go2draft.md) this package is moving into maintenance mode. The roadmap for a 1.0 release is as follows:
+
+- 0.9. Remove pre Go 1.9 and Go 1.10 support, address outstanding pull requests (if possible)
+- 1.0. Final release.
+
 ## Contributing
 
-We welcome pull requests, bug fixes and issue reports. With that said, the bar for adding new symbols to this package is intentionally set high.
+Because of the Go2 errors changes, this package is not accepting proposals for new functionality. With that said, we welcome pull requests, bug fixes and issue reports. 
 
-Before proposing a change, please discuss your change by raising an issue.
+Before sending a PR, please discuss your change by raising an issue.
 
 ## License
 

vendor/github.com/pkg/errors/errors.go

@@ -82,7 +82,7 @@
 //
 //     if err, ok := err.(stackTracer); ok {
 //             for _, f := range err.StackTrace() {
-//                     fmt.Printf("%+s:%d", f)
+//                     fmt.Printf("%+s:%d\n", f, f)
 //             }
 //     }
 //
@@ -159,6 +159,9 @@ type withStack struct {
 
 func (w *withStack) Cause() error { return w.error }
 
+// Unwrap provides compatibility for Go 1.13 error chains.
+func (w *withStack) Unwrap() error { return w.error }
+
 func (w *withStack) Format(s fmt.State, verb rune) {
 	switch verb {
 	case 'v':
@@ -241,6 +244,9 @@ type withMessage struct {
 func (w *withMessage) Error() string { return w.msg + ": " + w.cause.Error() }
 func (w *withMessage) Cause() error  { return w.cause }
 
+// Unwrap provides compatibility for Go 1.13 error chains.
+func (w *withMessage) Unwrap() error { return w.cause }
+
 func (w *withMessage) Format(s fmt.State, verb rune) {
 	switch verb {
 	case 'v':

vendor/github.com/pkg/errors/go113.go

@@ -0,0 +1,38 @@
+// +build go1.13
+
+package errors
+
+import (
+	stderrors "errors"
+)
+
+// Is reports whether any error in err's chain matches target.
+//
+// The chain consists of err itself followed by the sequence of errors obtained by
+// repeatedly calling Unwrap.
+//
+// An error is considered to match a target if it is equal to that target or if
+// it implements a method Is(error) bool such that Is(target) returns true.
+func Is(err, target error) bool { return stderrors.Is(err, target) }
+
+// As finds the first error in err's chain that matches target, and if so, sets
+// target to that error value and returns true.
+//
+// The chain consists of err itself followed by the sequence of errors obtained by
+// repeatedly calling Unwrap.
+//
+// An error matches target if the error's concrete value is assignable to the value
+// pointed to by target, or if the error has a method As(interface{}) bool such that
+// As(target) returns true. In the latter case, the As method is responsible for
+// setting target.
+//
+// As will panic if target is not a non-nil pointer to either a type that implements
+// error, or to any interface type. As returns false if err is nil.
+func As(err error, target interface{}) bool { return stderrors.As(err, target) }
+
+// Unwrap returns the result of calling the Unwrap method on err, if err's
+// type contains an Unwrap method returning error.
+// Otherwise, Unwrap returns nil.
+func Unwrap(err error) error {
+	return stderrors.Unwrap(err)
+}

vendor/github.com/pkg/errors/stack.go

@@ -5,10 +5,13 @@ import (
 	"io"
 	"path"
 	"runtime"
+	"strconv"
 	"strings"
 )
 
 // Frame represents a program counter inside a stack frame.
+// For historical reasons if Frame is interpreted as a uintptr
+// its value represents the program counter + 1.
 type Frame uintptr
 
 // pc returns the program counter for this frame;
@@ -37,6 +40,15 @@ func (f Frame) line() int {
 	return line
 }
 
+// name returns the name of this function, if known.
+func (f Frame) name() string {
+	fn := runtime.FuncForPC(f.pc())
+	if fn == nil {
+		return "unknown"
+	}
+	return fn.Name()
+}
+
 // Format formats the frame according to the fmt.Formatter interface.
 //
 //    %s    source file
@@ -54,22 +66,16 @@ func (f Frame) Format(s fmt.State, verb rune) {
 	case 's':
 		switch {
 		case s.Flag('+'):
-			pc := f.pc()
-			fn := runtime.FuncForPC(pc)
-			if fn == nil {
-				io.WriteString(s, "unknown")
-			} else {
-				file, _ := fn.FileLine(pc)
-				fmt.Fprintf(s, "%s\n\t%s", fn.Name(), file)
-			}
+			io.WriteString(s, f.name())
+			io.WriteString(s, "\n\t")
+			io.WriteString(s, f.file())
 		default:
 			io.WriteString(s, path.Base(f.file()))
 		}
 	case 'd':
-		fmt.Fprintf(s, "%d", f.line())
+		io.WriteString(s, strconv.Itoa(f.line()))
 	case 'n':
-		name := runtime.FuncForPC(f.pc()).Name()
-		io.WriteString(s, funcname(name))
+		io.WriteString(s, funcname(f.name()))
 	case 'v':
 		f.Format(s, 's')
 		io.WriteString(s, ":")
@@ -77,6 +83,16 @@ func (f Frame) Format(s fmt.State, verb rune) {
 	}
 }
 
+// MarshalText formats a stacktrace Frame as a text string. The output is the
+// same as that of fmt.Sprintf("%+v", f), but without newlines or tabs.
+func (f Frame) MarshalText() ([]byte, error) {
+	name := f.name()
+	if name == "unknown" {
+		return []byte(name), nil
+	}
+	return []byte(fmt.Sprintf("%s %s:%d", name, f.file(), f.line())), nil
+}
+
 // StackTrace is stack of Frames from innermost (newest) to outermost (oldest).
 type StackTrace []Frame
 
@@ -94,16 +110,30 @@ func (st StackTrace) Format(s fmt.State, verb rune) {
 		switch {
 		case s.Flag('+'):
 			for _, f := range st {
-				fmt.Fprintf(s, "\n%+v", f)
+				io.WriteString(s, "\n")
+				f.Format(s, verb)
 			}
 		case s.Flag('#'):
 			fmt.Fprintf(s, "%#v", []Frame(st))
 		default:
-			fmt.Fprintf(s, "%v", []Frame(st))
+			st.formatSlice(s, verb)
 		}
 	case 's':
-		fmt.Fprintf(s, "%s", []Frame(st))
+		st.formatSlice(s, verb)
+	}
+}
+
+// formatSlice will format this StackTrace into the given buffer as a slice of
+// Frame, only valid when called with '%s' or '%v'.
+func (st StackTrace) formatSlice(s fmt.State, verb rune) {
+	io.WriteString(s, "[")
+	for i, f := range st {
+		if i > 0 {
+			io.WriteString(s, " ")
+		}
+		f.Format(s, verb)
 	}
+	io.WriteString(s, "]")
 }
 
 // stack represents a stack of program counters.