From 299a80d3280c984867ac8daf25a7ae0a30d62527 Mon Sep 17 00:00:00 2001 From: Simon Frei Date: Wed, 26 Feb 2020 13:49:03 +0100 Subject: [PATCH] cmd/syncthing: Do not truncate/rotate logs at start (#6359) --- cmd/syncthing/monitor.go | 99 +++++++++++++++++++---------------- cmd/syncthing/monitor_test.go | 22 +++++--- 2 files changed, 69 insertions(+), 52 deletions(-) diff --git a/cmd/syncthing/monitor.go b/cmd/syncthing/monitor.go index f8ed38baf..403e75404 100644 --- a/cmd/syncthing/monitor.go +++ b/cmd/syncthing/monitor.go @@ -55,28 +55,32 @@ func monitorMain(runtimeOptions RuntimeOptions) { logFile = expanded } var fileDst io.Writer + var err error + open := func(name string) (io.WriteCloser, error) { + return newAutoclosedFile(name, logFileAutoCloseDelay, logFileMaxOpenTime) + } if runtimeOptions.logMaxSize > 0 { - open := func(name string) (io.WriteCloser, error) { - return newAutoclosedFile(name, logFileAutoCloseDelay, logFileMaxOpenTime), nil - } - fileDst = newRotatedFile(logFile, open, int64(runtimeOptions.logMaxSize), runtimeOptions.logMaxFiles) + fileDst, err = newRotatedFile(logFile, open, int64(runtimeOptions.logMaxSize), runtimeOptions.logMaxFiles) } else { - fileDst = newAutoclosedFile(logFile, logFileAutoCloseDelay, logFileMaxOpenTime) + fileDst, err = open(logFile) } - - if runtime.GOOS == "windows" { - // Translate line breaks to Windows standard - fileDst = osutil.ReplacingWriter{ - Writer: fileDst, - From: '\n', - To: []byte{'\r', '\n'}, + if err != nil { + l.Warnln("Failed to setup logging to file, proceeding with logging to stdout only:", err) + } else { + if runtime.GOOS == "windows" { + // Translate line breaks to Windows standard + fileDst = osutil.ReplacingWriter{ + Writer: fileDst, + From: '\n', + To: []byte{'\r', '\n'}, + } } + + // Log to both stdout and file. + dst = io.MultiWriter(dst, fileDst) + + l.Infof(`Log output saved to file "%s"`, logFile) } - - // Log to both stdout and file. - dst = io.MultiWriter(dst, fileDst) - - l.Infof(`Log output saved to file "%s"`, logFile) } args := os.Args @@ -353,16 +357,30 @@ type rotatedFile struct { currentSize int64 } -// the createFn should act equivalently to os.Create type createFn func(name string) (io.WriteCloser, error) -func newRotatedFile(name string, create createFn, maxSize int64, maxFiles int) *rotatedFile { - return &rotatedFile{ - name: name, - create: create, - maxSize: maxSize, - maxFiles: maxFiles, +func newRotatedFile(name string, create createFn, maxSize int64, maxFiles int) (*rotatedFile, error) { + var size int64 + if info, err := os.Lstat(name); err != nil { + if !os.IsNotExist(err) { + return nil, err + } + size = 0 + } else { + size = info.Size() } + writer, err := create(name) + if err != nil { + return nil, err + } + return &rotatedFile{ + name: name, + create: create, + maxSize: maxSize, + maxFiles: maxFiles, + currentFile: writer, + currentSize: size, + }, nil } func (r *rotatedFile) Write(bs []byte) (int, error) { @@ -370,19 +388,13 @@ func (r *rotatedFile) Write(bs []byte) (int, error) { // file so we'll start on a new one. if r.currentSize+int64(len(bs)) > r.maxSize { r.currentFile.Close() - r.currentFile = nil r.currentSize = 0 - } - - // If we have no current log, rotate old files out of the way and create - // a new one. - if r.currentFile == nil { r.rotate() - fd, err := r.create(r.name) + f, err := r.create(r.name) if err != nil { return 0, err } - r.currentFile = fd + r.currentFile = f } n, err := r.currentFile.Write(bs) @@ -435,7 +447,7 @@ type autoclosedFile struct { mut sync.Mutex } -func newAutoclosedFile(name string, closeDelay, maxOpenTime time.Duration) *autoclosedFile { +func newAutoclosedFile(name string, closeDelay, maxOpenTime time.Duration) (*autoclosedFile, error) { f := &autoclosedFile{ name: name, closeDelay: closeDelay, @@ -444,8 +456,13 @@ func newAutoclosedFile(name string, closeDelay, maxOpenTime time.Duration) *auto closed: make(chan struct{}), closeTimer: time.NewTimer(time.Minute), } + f.mut.Lock() + defer f.mut.Unlock() + if err := f.ensureOpenLocked(); err != nil { + return nil, err + } go f.closerLoop() - return f + return f, nil } func (f *autoclosedFile) Write(bs []byte) (int, error) { @@ -453,7 +470,7 @@ func (f *autoclosedFile) Write(bs []byte) (int, error) { defer f.mut.Unlock() // Make sure the file is open for appending - if err := f.ensureOpen(); err != nil { + if err := f.ensureOpenLocked(); err != nil { return 0, err } @@ -483,22 +500,14 @@ func (f *autoclosedFile) Close() error { } // Must be called with f.mut held! -func (f *autoclosedFile) ensureOpen() error { +func (f *autoclosedFile) ensureOpenLocked() error { if f.fd != nil { // File is already open return nil } // We open the file for write only, and create it if it doesn't exist. - flags := os.O_WRONLY | os.O_CREATE - if f.opened.IsZero() { - // This is the first time we are opening the file. We should truncate - // it to better emulate an os.Create() call. - flags |= os.O_TRUNC - } else { - // The file was already opened once, so we should append to it. - flags |= os.O_APPEND - } + flags := os.O_WRONLY | os.O_CREATE | os.O_APPEND fd, err := os.OpenFile(f.name, flags, 0644) if err != nil { diff --git a/cmd/syncthing/monitor_test.go b/cmd/syncthing/monitor_test.go index b53620885..345a9a06c 100644 --- a/cmd/syncthing/monitor_test.go +++ b/cmd/syncthing/monitor_test.go @@ -33,7 +33,10 @@ func TestRotatedFile(t *testing.T) { maxSize := int64(len(testData) + len(testData)/2) // We allow the log file plus two rotated copies. - rf := newRotatedFile(logName, open, maxSize, 2) + rf, err := newRotatedFile(logName, open, maxSize, 2) + if err != nil { + t.Fatal(err) + } // Write some bytes. if _, err := rf.Write(testData); err != nil { @@ -140,7 +143,10 @@ func TestAutoClosedFile(t *testing.T) { data := []byte("hello, world\n") // An autoclosed file that closes very quickly - ac := newAutoclosedFile(file, time.Millisecond, time.Millisecond) + ac, err := newAutoclosedFile(file, time.Millisecond, time.Millisecond) + if err != nil { + t.Fatal(err) + } // Write some data. if _, err := ac.Write(data); err != nil { @@ -182,21 +188,23 @@ func TestAutoClosedFile(t *testing.T) { } // Open the file again. - ac = newAutoclosedFile(file, time.Second, time.Second) + ac, err = newAutoclosedFile(file, time.Second, time.Second) + if err != nil { + t.Fatal(err) + } // Write something if _, err := ac.Write(data); err != nil { t.Fatal(err) } - // It should now contain only one write, because the first open - // should be a truncate. + // It should now contain three writes, as the file is always opened for appending bs, err = ioutil.ReadFile(file) if err != nil { t.Fatal(err) } - if len(bs) != len(data) { - t.Fatalf("Write failed, expected %d bytes, not %d", len(data), len(bs)) + if len(bs) != 3*len(data) { + t.Fatalf("Write failed, expected %d bytes, not %d", 3*len(data), len(bs)) } // Close.