diff --git a/daemon/logger/jsonfilelog/read.go b/daemon/logger/jsonfilelog/read.go index fd695c83dc..0c8fb5e5cd 100644 --- a/daemon/logger/jsonfilelog/read.go +++ b/daemon/logger/jsonfilelog/read.go @@ -54,7 +54,6 @@ func (l *JSONFileLogger) readLogs(logWatcher *logger.LogWatcher, config logger.R } continue } - defer f.Close() files = append(files, f) } @@ -63,15 +62,19 @@ func (l *JSONFileLogger) readLogs(logWatcher *logger.LogWatcher, config logger.R logWatcher.Err <- err return } - defer latestFile.Close() - - files = append(files, latestFile) - tailer := ioutils.MultiReadSeeker(files...) if config.Tail != 0 { + tailer := ioutils.MultiReadSeeker(append(files, latestFile)...) tailFile(tailer, logWatcher, config.Tail, config.Since) } + // close all the rotated files + for _, f := range files { + if err := f.(io.Closer).Close(); err != nil { + logrus.WithField("logger", "json-file").Warnf("error closing tailed log file: %v", err) + } + } + if !config.Follow { return } @@ -129,7 +132,23 @@ func followLogs(f *os.File, logWatcher *logger.LogWatcher, notifyRotate chan int if err != nil { logWatcher.Err <- err } - defer fileWatcher.Close() + defer func() { + f.Close() + fileWatcher.Close() + }() + name := f.Name() + + if err := fileWatcher.Add(name); err != nil { + logrus.WithField("logger", "json-file").Warnf("falling back to file poller due to error: %v", err) + fileWatcher.Close() + fileWatcher = filenotify.NewPollingWatcher() + + if err := fileWatcher.Add(name); err != nil { + logrus.Debugf("error watching log file for modifications: %v", err) + logWatcher.Err <- err + return + } + } var retries int for { @@ -153,42 +172,42 @@ func followLogs(f *os.File, logWatcher *logger.LogWatcher, notifyRotate chan int retries++ continue } - logWatcher.Err <- err + return } - logrus.WithField("logger", "json-file").Debugf("waiting for events") - if err := fileWatcher.Add(f.Name()); err != nil { - logrus.WithField("logger", "json-file").Warn("falling back to file poller") - fileWatcher.Close() - fileWatcher = filenotify.NewPollingWatcher() - if err := fileWatcher.Add(f.Name()); err != nil { - logrus.Errorf("error watching log file for modifications: %v", err) - logWatcher.Err <- err - } - } select { case <-fileWatcher.Events(): dec = json.NewDecoder(f) - fileWatcher.Remove(f.Name()) continue case <-fileWatcher.Errors(): - fileWatcher.Remove(f.Name()) logWatcher.Err <- err return case <-logWatcher.WatchClose(): - fileWatcher.Remove(f.Name()) + fileWatcher.Remove(name) return case <-notifyRotate: - f, err = os.Open(f.Name()) + f.Close() + fileWatcher.Remove(name) + + // retry when the file doesn't exist + for retries := 0; retries <= 5; retries++ { + f, err = os.Open(name) + if err == nil || !os.IsNotExist(err) { + break + } + } + + if err = fileWatcher.Add(name); err != nil { + logWatcher.Err <- err + return + } if err != nil { logWatcher.Err <- err return } dec = json.NewDecoder(f) - fileWatcher.Remove(f.Name()) - fileWatcher.Add(f.Name()) continue } } diff --git a/daemon/logger/loggerutils/rotatefilewriter.go b/daemon/logger/loggerutils/rotatefilewriter.go index de7112896c..99e0964aea 100644 --- a/daemon/logger/loggerutils/rotatefilewriter.go +++ b/daemon/logger/loggerutils/rotatefilewriter.go @@ -87,33 +87,17 @@ func rotate(name string, maxFiles int) error { for i := maxFiles - 1; i > 1; i-- { toPath := name + "." + strconv.Itoa(i) fromPath := name + "." + strconv.Itoa(i-1) - if err := backup(fromPath, toPath); err != nil && !os.IsNotExist(err) { + if err := os.Rename(fromPath, toPath); err != nil && !os.IsNotExist(err) { return err } } - if err := backup(name, name+".1"); err != nil { + if err := os.Rename(name, name+".1"); err != nil && !os.IsNotExist(err) { return err } return nil } -// backup renames a file from fromPath to toPath -func backup(fromPath, toPath string) error { - if _, err := os.Stat(fromPath); os.IsNotExist(err) { - return err - } - - if _, err := os.Stat(toPath); !os.IsNotExist(err) { - err := os.Remove(toPath) - if err != nil { - return err - } - } - - return os.Rename(fromPath, toPath) -} - // LogPath returns the location the given writer logs to. func (w *RotateFileWriter) LogPath() string { return w.f.Name() diff --git a/integration-cli/docker_cli_logs_bench_test.go b/integration-cli/docker_cli_logs_bench_test.go new file mode 100644 index 0000000000..eeb008de70 --- /dev/null +++ b/integration-cli/docker_cli_logs_bench_test.go @@ -0,0 +1,32 @@ +package main + +import ( + "fmt" + "strings" + "time" + + "github.com/go-check/check" +) + +func (s *DockerSuite) BenchmarkLogsCLIRotateFollow(c *check.C) { + out, _ := dockerCmd(c, "run", "-d", "--log-opt", "max-size=1b", "--log-opt", "max-file=10", "busybox", "sh", "-c", "while true; do usleep 50000; echo hello; done") + id := strings.TrimSpace(out) + ch := make(chan error, 1) + go func() { + ch <- nil + out, _, _ := dockerCmdWithError("logs", "-f", id) + // if this returns at all, it's an error + ch <- fmt.Errorf(out) + }() + + <-ch + select { + case <-time.After(30 * time.Second): + // ran for 30 seconds with no problem + return + case err := <-ch: + if err != nil { + c.Fatal(err) + } + } +}