From 74c8d3480592feadb34bd8a925baed8545cf8a86 Mon Sep 17 00:00:00 2001 From: Audrius Butkevicius Date: Sat, 23 Sep 2017 15:22:26 +0100 Subject: [PATCH] lib/model: Centralize error reporting, modified files are errors (fixes #4392) --- lib/model/rwfolder.go | 64 +++++++++++++--------------------- lib/model/sharedpullerstate.go | 11 +++--- 2 files changed, 30 insertions(+), 45 deletions(-) diff --git a/lib/model/rwfolder.go b/lib/model/rwfolder.go index acb3348d..4d92d479 100644 --- a/lib/model/rwfolder.go +++ b/lib/model/rwfolder.go @@ -251,9 +251,6 @@ func (f *sendReceiveFolder) Serve() { // errors preventing us. Flag this with a warning and // wait a bit longer before retrying. if folderErrors := f.currentErrors(); len(folderErrors) > 0 { - for _, fileError := range folderErrors { - l.Infof("Puller (folder %v, dir %q): %v", f.Description(), fileError.Path, fileError.Err) - } events.Default.Log(events.FolderErrors, map[string]interface{}{ "folder": f.folderID, "errors": folderErrors, @@ -369,7 +366,7 @@ func (f *sendReceiveFolder) pullerIteration(ignores *ignore.Matcher) int { if err := fileValid(intf); err != nil { // The file isn't valid so we can't process it. Pretend that we // tried and set the error for the file. - f.newError(intf.FileName(), err) + f.newError("need", intf.FileName(), err) changed++ return true } @@ -418,7 +415,7 @@ func (f *sendReceiveFolder) pullerIteration(ignores *ignore.Matcher) int { // Verify that the thing we are handling lives inside a directory, // and not a symlink or empty space. if err := osutil.TraversesSymlink(f.fs, filepath.Dir(fi.Name)); err != nil { - f.newError(fi.Name, err) + f.newError("traverses d", fi.Name, err) continue } @@ -507,7 +504,7 @@ nextFile: // Verify that the thing we are handling lives inside a directory, // and not a symlink or empty space. if err := osutil.TraversesSymlink(f.fs, filepath.Dir(fi.Name)); err != nil { - f.newError(fi.Name, err) + f.newError("traverses q", fi.Name, err) continue } @@ -611,8 +608,7 @@ func (f *sendReceiveFolder) handleDir(file protocol.FileInfo) { case err == nil && (!info.IsDir() || info.IsSymlink()): err = osutil.InWritableDir(f.fs.Remove, f.fs, file.Name) if err != nil { - l.Debugf("Puller (folder %q, dir %q): %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("dir replace", file.Name, err) return } fallthrough @@ -642,15 +638,13 @@ func (f *sendReceiveFolder) handleDir(file protocol.FileInfo) { if err = osutil.InWritableDir(mkdir, f.fs, file.Name); err == nil { f.dbUpdates <- dbUpdateJob{file, dbUpdateHandleDir} } else { - l.Debugf("Puller (folder %q, dir %q): %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("dir mkdir", file.Name, err) } return // Weird error when stat()'ing the dir. Probably won't work to do // anything else with it if we can't even stat() it. case err != nil: - l.Debugf("Puller (folder %q, dir %q): %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("dir stat", file.Name, err) return } @@ -662,8 +656,7 @@ func (f *sendReceiveFolder) handleDir(file protocol.FileInfo) { } else if err := f.fs.Chmod(file.Name, mode|(fs.FileMode(info.Mode())&retainBits)); err == nil { f.dbUpdates <- dbUpdateJob{file, dbUpdateHandleDir} } else { - l.Debugf("Puller (folder %q, dir %q): %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("dir chmod", file.Name, err) } } @@ -699,8 +692,7 @@ func (f *sendReceiveFolder) handleSymlink(file protocol.FileInfo) { // Index entry from a Syncthing predating the support for including // the link target in the index entry. We log this as an error. err = errors.New("incompatible symlink entry; rescan with newer Syncthing on source") - l.Debugf("Puller (folder %q, dir %q): %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("symlink", file.Name, err) return } @@ -710,8 +702,7 @@ func (f *sendReceiveFolder) handleSymlink(file protocol.FileInfo) { // path. err = osutil.InWritableDir(f.fs.Remove, f.fs, file.Name) if err != nil { - l.Debugf("Puller (folder %q, dir %q): %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("symlink remove", file.Name, err) return } } @@ -725,8 +716,7 @@ func (f *sendReceiveFolder) handleSymlink(file protocol.FileInfo) { if err = osutil.InWritableDir(createLink, f.fs, file.Name); err == nil { f.dbUpdates <- dbUpdateJob{file, dbUpdateHandleSymlink} } else { - l.Debugf("Puller (folder %q, dir %q): %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("symlink create", file.Name, err) } } @@ -774,8 +764,7 @@ func (f *sendReceiveFolder) deleteDir(file protocol.FileInfo, matcher *ignore.Ma // file and not a directory etc) and that the delete is handled. f.dbUpdates <- dbUpdateJob{file, dbUpdateDeleteDir} } else { - l.Debugf("Puller (folder %q, dir %q): delete: %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("delete dir", file.Name, err) } } @@ -827,8 +816,7 @@ func (f *sendReceiveFolder) deleteFile(file protocol.FileInfo) { // not a directory etc) and that the delete is handled. f.dbUpdates <- dbUpdateJob{file, dbUpdateDeleteFile} } else { - l.Debugf("Puller (folder %q, file %q): delete: %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("delete file", file.Name, err) } } @@ -894,8 +882,8 @@ func (f *sendReceiveFolder) renameFile(source, target protocol.FileInfo) { err = f.shortcutFile(target) if err != nil { - l.Debugf("Puller (folder %q, file %q): rename from %q metadata: %v", f.folderID, target.Name, source.Name, err) - f.newError(target.Name, err) + err = fmt.Errorf("from %s: %s", source.Name, err.Error()) + f.newError("rename shortcut", target.Name, err) return } @@ -907,8 +895,8 @@ func (f *sendReceiveFolder) renameFile(source, target protocol.FileInfo) { err = osutil.InWritableDir(f.fs.Remove, f.fs, source.Name) if err != nil { - l.Debugf("Puller (folder %q, file %q): delete %q after failed rename: %v", f.folderID, target.Name, source.Name, err) - f.newError(target.Name, err) + err = fmt.Errorf("from %s: %s", source.Name, err.Error()) + f.newError("rename delete", target.Name, err) return } @@ -982,8 +970,7 @@ func (f *sendReceiveFolder) handleFile(file protocol.FileInfo, copyChan chan<- c }) if err != nil { - l.Debugln("Puller: shortcut:", err) - f.newError(file.Name, err) + f.newError("shortcut", file.Name, err) } else { f.dbUpdates <- dbUpdateJob{file, dbUpdateShortcutFile} } @@ -1040,7 +1027,7 @@ func (f *sendReceiveFolder) handleFile(file protocol.FileInfo, copyChan chan<- c if f.MinDiskFree.BaseValue() > 0 { if usage, err := f.fs.Usage("."); err == nil && usage.Free < blocksSize { l.Warnf(`Folder "%s": insufficient disk space in %s for %s: have %.2f MiB, need %.2f MiB`, f.folderID, f.fs.URI(), file.Name, float64(usage.Free)/1024/1024, float64(blocksSize)/1024/1024) - f.newError(file.Name, errors.New("insufficient space")) + f.newError("disk space", file.Name, errors.New("insufficient space")) return } } @@ -1093,8 +1080,7 @@ func (f *sendReceiveFolder) handleFile(file protocol.FileInfo, copyChan chan<- c func (f *sendReceiveFolder) shortcutFile(file protocol.FileInfo) error { if !f.ignorePermissions(file) { if err := f.fs.Chmod(file.Name, fs.FileMode(file.Permissions&0777)); err != nil { - l.Debugf("Puller (folder %q, file %q): shortcut: chmod: %v", f.folderID, file.Name, err) - f.newError(file.Name, err) + f.newError("shortcut chmod", file.Name, err) return err } } @@ -1384,7 +1370,7 @@ func (f *sendReceiveFolder) performFinish(state *sharedPullerState) error { // for this file up to ten times, but the last nine of those // scans will be cheap... go f.Scan([]string{state.curFile.Name}) - return nil + return fmt.Errorf("file modified but not rescanned; will try again later") } switch { @@ -1452,8 +1438,7 @@ func (f *sendReceiveFolder) finisherRoutine(in <-chan *sharedPullerState) { } if err != nil { - l.Debugln("Puller: final:", err) - f.newError(state.file.Name, err) + f.newError("finisher", state.file.Name, err) } else { f.blockStatsMut.Lock() f.blockStats["total"] += state.reused + state.copyTotal + state.pullTotal @@ -1464,6 +1449,7 @@ func (f *sendReceiveFolder) finisherRoutine(in <-chan *sharedPullerState) { f.blockStats["copyElsewhere"] += state.copyTotal - state.copyOrigin f.blockStatsMut.Unlock() } + events.Default.Log(events.ItemFinished, map[string]interface{}{ "folder": f.folderID, "item": state.file.Name, @@ -1665,7 +1651,7 @@ func (f *sendReceiveFolder) moveForConflict(name string, lastModBy string) error return err } -func (f *sendReceiveFolder) newError(path string, err error) { +func (f *sendReceiveFolder) newError(context, path string, err error) { f.errorsMut.Lock() defer f.errorsMut.Unlock() @@ -1675,8 +1661,8 @@ func (f *sendReceiveFolder) newError(path string, err error) { if _, ok := f.errors[path]; ok { return } - - f.errors[path] = err.Error() + l.Infof("Puller (folder %q, file %q): %s: %v", f.Description(), path, context, err) + f.errors[path] = fmt.Sprintf("%s: %s", context, err.Error()) } func (f *sendReceiveFolder) clearErrors() { diff --git a/lib/model/sharedpullerstate.go b/lib/model/sharedpullerstate.go index e8165e9e..e3446fe5 100644 --- a/lib/model/sharedpullerstate.go +++ b/lib/model/sharedpullerstate.go @@ -7,6 +7,7 @@ package model import ( + "fmt" "io" "path/filepath" "time" @@ -204,9 +205,8 @@ func (s *sharedPullerState) sourceFile() (fs.File, error) { return fd, nil } -// earlyClose prints a warning message composed of the context and -// error, and marks the sharedPullerState as failed. Is a no-op when called on -// an already failed state. +// fail sets the error on the puller state compose of error, and marks the +// sharedPullerState as failed. Is a no-op when called on an already failed state. func (s *sharedPullerState) fail(context string, err error) { s.mut.Lock() defer s.mut.Unlock() @@ -215,12 +215,11 @@ func (s *sharedPullerState) fail(context string, err error) { } func (s *sharedPullerState) failLocked(context string, err error) { - if s.err != nil { + if s.err != nil || err == nil { return } - l.Infof("Puller (folder %q, file %q): %s: %v", s.folder, s.file.Name, context, err) - s.err = err + s.err = fmt.Errorf("%s: %s", context, err.Error()) } func (s *sharedPullerState) failed() error {