From dc42db444b17145b7de9a0d1c56a42b9d64f3dea Mon Sep 17 00:00:00 2001 From: Simon Frei Date: Tue, 24 Oct 2017 07:58:55 +0000 Subject: [PATCH] lib/model, lib/config: Refactor folder health/error handling (fixes #4445, fixes #4451) GitHub-Pull-Request: https://github.com/syncthing/syncthing/pull/4455 LGTM: AudriusButkevicius, calmh --- lib/config/folderconfiguration.go | 64 ++++++++----- lib/config/size.go | 23 +++++ lib/config/wrapper.go | 8 ++ lib/model/folder.go | 87 ++++++++++++++--- lib/model/folderstate.go | 59 +++++------- lib/model/model.go | 149 ++++-------------------------- lib/model/model_test.go | 7 +- lib/model/rofolder.go | 8 +- lib/model/rwfolder.go | 20 ++-- 9 files changed, 207 insertions(+), 218 deletions(-) diff --git a/lib/config/folderconfiguration.go b/lib/config/folderconfiguration.go index c3057ed7d..676d82b50 100644 --- a/lib/config/folderconfiguration.go +++ b/lib/config/folderconfiguration.go @@ -7,6 +7,7 @@ package config import ( + "errors" "fmt" "runtime" @@ -14,6 +15,11 @@ import ( "github.com/syncthing/syncthing/lib/protocol" ) +var ( + errPathMissing = errors.New("folder path missing") + errMarkerMissing = errors.New("folder marker missing") +) + type FolderConfiguration struct { ID string `xml:"id,attr" json:"id"` Label string `xml:"label,attr" json:"label"` @@ -82,32 +88,44 @@ func (f FolderConfiguration) Filesystem() fs.Filesystem { } func (f *FolderConfiguration) CreateMarker() error { - if !f.HasMarker() { - permBits := fs.FileMode(0777) - if runtime.GOOS == "windows" { - // Windows has no umask so we must chose a safer set of bits to - // begin with. - permBits = 0700 - } - fs := f.Filesystem() - err := fs.Mkdir(".stfolder", permBits) - if err != nil { - return err - } - if dir, err := fs.Open("."); err != nil { - l.Debugln("folder marker: open . failed:", err) - } else if err := dir.Sync(); err != nil { - l.Debugln("folder marker: fsync . failed:", err) - } - fs.Hide(".stfolder") + if err := f.CheckPath(); err != errMarkerMissing { + return err } + permBits := fs.FileMode(0777) + if runtime.GOOS == "windows" { + // Windows has no umask so we must chose a safer set of bits to + // begin with. + permBits = 0700 + } + fs := f.Filesystem() + err := fs.Mkdir(".stfolder", permBits) + if err != nil { + return err + } + if dir, err := fs.Open("."); err != nil { + l.Debugln("folder marker: open . failed:", err) + } else if err := dir.Sync(); err != nil { + l.Debugln("folder marker: fsync . failed:", err) + } + fs.Hide(".stfolder") + return nil } -func (f *FolderConfiguration) HasMarker() bool { - _, err := f.Filesystem().Stat(".stfolder") - return err == nil +// CheckPath returns nil if the folder root exists and contains the marker file +func (f *FolderConfiguration) CheckPath() error { + fi, err := f.Filesystem().Stat(".") + if err != nil || !fi.IsDir() { + return errPathMissing + } + + _, err = f.Filesystem().Stat(".stfolder") + if err != nil { + return errMarkerMissing + } + + return nil } func (f *FolderConfiguration) CreateRoot() (err error) { @@ -184,3 +202,7 @@ func (l FolderDeviceConfigurationList) Swap(a, b int) { func (l FolderDeviceConfigurationList) Len() int { return len(l) } + +func (f *FolderConfiguration) CheckFreeSpace() (err error) { + return checkFreeSpace(f.MinDiskFree, f.Filesystem()) +} diff --git a/lib/config/size.go b/lib/config/size.go index 1628b9b11..5c6fe5b7e 100644 --- a/lib/config/size.go +++ b/lib/config/size.go @@ -10,6 +10,8 @@ import ( "fmt" "strconv" "strings" + + "github.com/syncthing/syncthing/lib/fs" ) type Size struct { @@ -73,3 +75,24 @@ func (s Size) String() string { func (Size) ParseDefault(s string) (interface{}, error) { return ParseSize(s) } + +func checkFreeSpace(req Size, fs fs.Filesystem) error { + val := req.BaseValue() + if val <= 0 { + return nil + } + + usage, err := fs.Usage(".") + if req.Percentage() { + freePct := (float64(usage.Free) / float64(usage.Total)) * 100 + if err == nil && freePct < val { + return fmt.Errorf("insufficient space in %v %v: %f %% < %v", fs.Type(), fs.URI(), freePct, req) + } + } else { + if err == nil && float64(usage.Free) < val { + return fmt.Errorf("insufficient space in %v %v: %v < %v", fs.Type(), fs.URI(), usage.Free, req) + } + } + + return nil +} diff --git a/lib/config/wrapper.go b/lib/config/wrapper.go index 647ff8f8c..2a243dc14 100644 --- a/lib/config/wrapper.go +++ b/lib/config/wrapper.go @@ -8,9 +8,11 @@ package config import ( "os" + "path/filepath" "sync/atomic" "github.com/syncthing/syncthing/lib/events" + "github.com/syncthing/syncthing/lib/fs" "github.com/syncthing/syncthing/lib/osutil" "github.com/syncthing/syncthing/lib/protocol" "github.com/syncthing/syncthing/lib/rand" @@ -468,3 +470,9 @@ func (w *Wrapper) MyName() string { cfg, _ := w.Device(myID) return cfg.Name } + +// CheckHomeFreeSpace returns nil if the home disk has the required amount of +// free space, or if home disk free space checking is disabled. +func (w *Wrapper) CheckHomeFreeSpace() error { + return checkFreeSpace(w.Options().MinHomeDiskFree, fs.NewFilesystem(fs.FilesystemTypeBasic, filepath.Dir(w.ConfigPath()))) +} diff --git a/lib/model/folder.go b/lib/model/folder.go index b43bec8c3..f3874edc2 100644 --- a/lib/model/folder.go +++ b/lib/model/folder.go @@ -25,7 +25,7 @@ type folder struct { initialScanFinished chan struct{} watchCancel context.CancelFunc watchChan chan []string - ignoresUpdated chan struct{} // The ignores changed, we need to restart watcher + restartWatchChan chan struct{} } func newFolder(model *Model, cfg config.FolderConfiguration) folder { @@ -43,12 +43,25 @@ func newFolder(model *Model, cfg config.FolderConfiguration) folder { } } -func (f *folder) IndexUpdated() { -} +func (f *folder) BringToFront(string) {} + func (f *folder) DelayScan(next time.Duration) { f.scan.Delay(next) } +func (f *folder) IndexUpdated() { +} + +func (f *folder) IgnoresUpdated() { + if f.FSWatcherEnabled { + f.scheduleWatchRestart() + } +} + +func (f *folder) Jobs() ([]string, []string) { + return nil, nil +} + func (f *folder) Scan(subdirs []string) error { <-f.initialScanFinished return f.scan.Scan(subdirs) @@ -58,13 +71,34 @@ func (f *folder) Stop() { f.cancel() } -func (f *folder) Jobs() ([]string, []string) { - return nil, nil +func (f *folder) BlockStats() map[string]int { + return nil } -func (f *folder) BringToFront(string) {} +// CheckHealth checks the folder for common errors, updates the folder state +// and returns the current folder error, or nil if the folder is healthy. +func (f *folder) CheckHealth() error { + err := f.getHealthError() + f.setError(err) + return err +} + +func (f *folder) getHealthError() error { + // Check for folder errors, with the most serious and specific first and + // generic ones like out of space on the home disk later. + + if err := f.CheckPath(); err != nil { + return err + } + + if err := f.CheckFreeSpace(); err != nil { + return err + } + + if err := f.model.cfg.CheckHomeFreeSpace(); err != nil { + return err + } -func (f *folder) BlockStats() map[string]int { return nil } @@ -72,7 +106,7 @@ func (f *folder) scanSubdirs(subDirs []string) error { if err := f.model.internalScanFolderSubdirs(f.ctx, f.folderID, subDirs); err != nil { // Potentially sets the error twice, once in the scanner just // by doing a check, and once here, if the error returned is - // the same one as returned by CheckFolderHealth, though + // the same one as returned by CheckHealth, though // duplicate set is handled by setError. f.setError(err) return err @@ -97,7 +131,7 @@ func (f *folder) scanTimerFired() { f.scan.Reschedule() } -func (f *folder) startWatcher() { +func (f *folder) startWatch() { ctx, cancel := context.WithCancel(f.ctx) f.model.fmut.RLock() ignores := f.model.folderIgnores[f.folderID] @@ -113,18 +147,45 @@ func (f *folder) startWatcher() { } } -func (f *folder) restartWatcher() { +func (f *folder) restartWatch() { f.watchCancel() - f.startWatcher() + f.startWatch() f.Scan(nil) } -func (f *folder) IgnoresUpdated() { +func (f *folder) scheduleWatchRestart() { select { - case f.ignoresUpdated <- struct{}{}: + case f.restartWatchChan <- struct{}{}: default: // We might be busy doing a pull and thus not reading from this // channel. The channel is 1-buffered, so one notification will be // queued to ensure we recheck after the pull. } } + +func (f *folder) setError(err error) { + _, _, oldErr := f.getState() + if (err != nil && oldErr != nil && oldErr.Error() == err.Error()) || (err == nil && oldErr == nil) { + return + } + + if err != nil { + if oldErr == nil { + l.Warnf("Error on folder %s: %v", f.Description(), err) + } else { + l.Infof("Error on folder %s changed: %q -> %q", f.Description(), oldErr, err) + } + } else { + l.Infoln("Cleared error on folder", f.Description()) + } + + if f.FSWatcherEnabled { + if err != nil { + f.watchCancel() + } else { + f.scheduleWatchRestart() + } + } + + f.stateTracker.setError(err) +} diff --git a/lib/model/folderstate.go b/lib/model/folderstate.go index f8412384f..991e90cda 100644 --- a/lib/model/folderstate.go +++ b/lib/model/folderstate.go @@ -94,49 +94,32 @@ func (s *stateTracker) getState() (current folderState, changed time.Time, err e return } -// setError sets the folder state to FolderError with the specified error. +// setError sets the folder state to FolderError with the specified error or +// to FolderIdle if the error is nil func (s *stateTracker) setError(err error) { s.mut.Lock() - if s.current != FolderError || s.err.Error() != err.Error() { - eventData := map[string]interface{}{ - "folder": s.folderID, - "to": FolderError.String(), - "from": s.current.String(), - "error": err.Error(), - } + defer s.mut.Unlock() - if !s.changed.IsZero() { - eventData["duration"] = time.Since(s.changed).Seconds() - } + eventData := map[string]interface{}{ + "folder": s.folderID, + "from": s.current.String(), + } + if err != nil { + eventData["error"] = err.Error() s.current = FolderError - s.err = err - s.changed = time.Now() - - events.Default.Log(events.StateChanged, eventData) - } - s.mut.Unlock() -} - -// clearError sets the folder state to FolderIdle and clears the error -func (s *stateTracker) clearError() { - s.mut.Lock() - if s.current == FolderError { - eventData := map[string]interface{}{ - "folder": s.folderID, - "to": FolderIdle.String(), - "from": s.current.String(), - } - - if !s.changed.IsZero() { - eventData["duration"] = time.Since(s.changed).Seconds() - } - + } else { s.current = FolderIdle - s.err = nil - s.changed = time.Now() - - events.Default.Log(events.StateChanged, eventData) } - s.mut.Unlock() + + eventData["to"] = s.current.String() + + if !s.changed.IsZero() { + eventData["duration"] = time.Since(s.changed).Seconds() + } + + s.err = err + s.changed = time.Now() + + events.Default.Log(events.StateChanged, eventData) } diff --git a/lib/model/model.go b/lib/model/model.go index 1739b5e43..2f06b5b3a 100644 --- a/lib/model/model.go +++ b/lib/model/model.go @@ -54,10 +54,10 @@ type service interface { Serve() Stop() BlockStats() map[string]int + CheckHealth() error getState() (folderState, time.Time, error) setState(state folderState) - clearError() setError(err error) } @@ -107,14 +107,12 @@ var ( ) var ( - errFolderPathMissing = errors.New("folder path missing") - errFolderMarkerMissing = errors.New("folder marker missing") - errDeviceUnknown = errors.New("unknown device") - errDevicePaused = errors.New("device is paused") - errDeviceIgnored = errors.New("device is ignored") - errFolderPaused = errors.New("folder is paused") - errFolderMissing = errors.New("no such folder") - errNetworkNotAllowed = errors.New("network not allowed") + errDeviceUnknown = errors.New("unknown device") + errDevicePaused = errors.New("device is paused") + errDeviceIgnored = errors.New("device is ignored") + errFolderPaused = errors.New("folder is paused") + errFolderMissing = errors.New("no such folder") + errNetworkNotAllowed = errors.New("network not allowed") ) // NewModel creates and starts a new model. The model starts in read-only mode, @@ -1361,7 +1359,7 @@ func (m *Model) GetIgnores(folder string) ([]string, []string, error) { } } - if err := m.checkFolderPath(cfg); err != nil { + if err := cfg.CheckPath(); err != nil { return nil, nil, err } @@ -1791,7 +1789,7 @@ func (m *Model) ScanFolders() map[string]error { // Potentially sets the error twice, once in the scanner just // by doing a check, and once here, if the error returned is - // the same one as returned by CheckFolderHealth, though + // the same one as returned by CheckHealth, though // duplicate set is handled by setError. m.fmut.RLock() srv := m.folderRunners[folder] @@ -1871,16 +1869,13 @@ func (m *Model) internalScanFolderSubdirs(ctx context.Context, folder string, su return errFolderMissing } - if err := m.CheckFolderHealth(folder); err != nil { - runner.setError(err) - l.Infof("Stopping folder %s due to error: %s", folderCfg.Description(), err) + if err := runner.CheckHealth(); err != nil { return err } if err := ignores.Load(".stignore"); err != nil && !fs.IsNotExist(err) { err = fmt.Errorf("loading ignores: %v", err) runner.setError(err) - l.Infof("Stopping folder %s due to error: %s", folderCfg.Description(), err) return err } @@ -1914,7 +1909,7 @@ func (m *Model) internalScanFolderSubdirs(ctx context.Context, folder string, su // The error we get here is likely an OS level error, which might not be // as readable as our health check errors. Check if we can get a health // check error first, and use that if it's available. - if ferr := m.CheckFolderHealth(folder); ferr != nil { + if ferr := runner.CheckHealth(); ferr != nil { err = ferr } runner.setError(err) @@ -1926,8 +1921,8 @@ func (m *Model) internalScanFolderSubdirs(ctx context.Context, folder string, su for f := range fchan { if len(batch) == maxBatchSizeFiles || batchSizeBytes > maxBatchSizeBytes { - if err := m.CheckFolderHealth(folder); err != nil { - l.Infof("Stopping folder %s mid-scan due to folder error: %s", folderCfg.Description(), err) + if err := runner.CheckHealth(); err != nil { + l.Debugln("Stopping scan of folder %s due to: %s", folderCfg.Description(), err) return err } m.updateLocalsFromScanning(folder, batch) @@ -1938,8 +1933,8 @@ func (m *Model) internalScanFolderSubdirs(ctx context.Context, folder string, su batchSizeBytes += f.ProtoSize() } - if err := m.CheckFolderHealth(folder); err != nil { - l.Infof("Stopping folder %s mid-scan due to folder error: %s", folderCfg.Description(), err) + if err := runner.CheckHealth(); err != nil { + l.Debugln("Stopping scan of folder %s due to: %s", folderCfg.Description(), err) return err } else if len(batch) > 0 { m.updateLocalsFromScanning(folder, batch) @@ -1961,7 +1956,7 @@ func (m *Model) internalScanFolderSubdirs(ctx context.Context, folder string, su fset.WithPrefixedHaveTruncated(protocol.LocalDeviceID, sub, func(fi db.FileIntf) bool { f := fi.(db.FileInfoTruncated) if len(batch) == maxBatchSizeFiles || batchSizeBytes > maxBatchSizeBytes { - if err := m.CheckFolderHealth(folder); err != nil { + if err := runner.CheckHealth(); err != nil { iterError = err return false } @@ -2020,13 +2015,13 @@ func (m *Model) internalScanFolderSubdirs(ctx context.Context, folder string, su }) if iterError != nil { - l.Infof("Stopping folder %s mid-scan due to folder error: %s", folderCfg.Description(), iterError) + l.Debugln("Stopping scan of folder %s due to: %s", folderCfg.Description(), err) return iterError } } - if err := m.CheckFolderHealth(folder); err != nil { - l.Infof("Stopping folder %s mid-scan due to folder error: %s", folderCfg.Description(), err) + if err := runner.CheckHealth(); err != nil { + l.Debugln("Stopping scan of folder %s due to: %s", folderCfg.Description(), err) return err } else if len(batch) > 0 { m.updateLocalsFromScanning(folder, batch) @@ -2344,112 +2339,6 @@ func (m *Model) BringToFront(folder, file string) { } } -// CheckFolderHealth checks the folder for common errors and returns the -// current folder error, or nil if the folder is healthy. -func (m *Model) CheckFolderHealth(id string) error { - folder, ok := m.cfg.Folders()[id] - if !ok { - return errFolderMissing - } - - // Check for folder errors, with the most serious and specific first and - // generic ones like out of space on the home disk later. Note the - // inverted error flow (err==nil checks) here. - - err := m.checkFolderPath(folder) - if err == nil { - err = m.checkFolderFreeSpace(folder) - } - if err == nil { - err = m.checkHomeDiskFree() - } - - // Set or clear the error on the runner, which also does logging and - // generates events and stuff. - m.runnerExchangeError(folder, err) - - return err -} - -// checkFolderPath returns nil if the folder path exists and has the marker file. -func (m *Model) checkFolderPath(folder config.FolderConfiguration) error { - fs := folder.Filesystem() - - if fi, err := fs.Stat("."); err != nil || !fi.IsDir() { - return errFolderPathMissing - } - - if !folder.HasMarker() { - return errFolderMarkerMissing - } - - return nil -} - -// checkFolderFreeSpace returns nil if the folder has the required amount of -// free space, or if folder free space checking is disabled. -func (m *Model) checkFolderFreeSpace(folder config.FolderConfiguration) error { - return m.checkFreeSpace(folder.MinDiskFree, folder.Filesystem()) -} - -// checkHomeDiskFree returns nil if the home disk has the required amount of -// free space, or if home disk free space checking is disabled. -func (m *Model) checkHomeDiskFree() error { - fs := fs.NewFilesystem(fs.FilesystemTypeBasic, filepath.Dir(m.cfg.ConfigPath())) - return m.checkFreeSpace(m.cfg.Options().MinHomeDiskFree, fs) -} - -func (m *Model) checkFreeSpace(req config.Size, fs fs.Filesystem) error { - val := req.BaseValue() - if val <= 0 { - return nil - } - - usage, err := fs.Usage(".") - if req.Percentage() { - freePct := (float64(usage.Free) / float64(usage.Total)) * 100 - if err == nil && freePct < val { - return fmt.Errorf("insufficient space in %v %v: %f %% < %v", fs.Type(), fs.URI(), freePct, req) - } - } else { - if err == nil && float64(usage.Free) < val { - return fmt.Errorf("insufficient space in %v %v: %v < %v", fs.Type(), fs.URI(), usage.Free, req) - } - } - - return nil -} - -// runnerExchangeError sets the given error (which way be nil) on the folder -// runner. If the error differs from any previous error, logging and events -// happen. -func (m *Model) runnerExchangeError(folder config.FolderConfiguration, err error) { - m.fmut.RLock() - runner, runnerExists := m.folderRunners[folder.ID] - m.fmut.RUnlock() - - var oldErr error - if runnerExists { - _, _, oldErr = runner.getState() - } - - if err != nil { - if oldErr != nil && oldErr.Error() != err.Error() { - l.Infof("Folder %s error changed: %q -> %q", folder.Description(), oldErr, err) - } else if oldErr == nil { - l.Warnf("Stopping folder %s - %v", folder.Description(), err) - } - if runnerExists { - runner.setError(err) - } - } else if oldErr != nil { - l.Infof("Folder %q error is cleared, restarting", folder.ID) - if runnerExists { - runner.clearError() - } - } -} - func (m *Model) ResetFolder(folder string) { l.Infof("Cleaning data for folder %q", folder) db.DropFolder(m.db, folder) diff --git a/lib/model/model_test.go b/lib/model/model_test.go index 80a4cd64e..df3df0135 100644 --- a/lib/model/model_test.go +++ b/lib/model/model_test.go @@ -2028,7 +2028,7 @@ func TestScanNoDatabaseWrite(t *testing.T) { } func TestIssue2782(t *testing.T) { - // CheckFolderHealth should accept a symlinked folder, when using tilde-expanded path. + // CheckHealth should accept a symlinked folder, when using tilde-expanded path. if runtime.GOOS == "windows" { t.Skip("not reliable on Windows") @@ -2070,7 +2070,10 @@ func TestIssue2782(t *testing.T) { t.Error("scan error:", err) } - if err := m.CheckFolderHealth("default"); err != nil { + m.fmut.Lock() + runner, _ := m.folderRunners["default"] + m.fmut.Unlock() + if err := runner.CheckHealth(); err != nil { t.Error("health check error:", err) } } diff --git a/lib/model/rofolder.go b/lib/model/rofolder.go index 20023e8cd..7a665776e 100644 --- a/lib/model/rofolder.go +++ b/lib/model/rofolder.go @@ -35,7 +35,7 @@ func (f *sendOnlyFolder) Serve() { }() if f.FSWatcherEnabled { - f.startWatcher() + f.startWatch() } for { @@ -43,10 +43,8 @@ func (f *sendOnlyFolder) Serve() { case <-f.ctx.Done(): return - case <-f.ignoresUpdated: - if f.FSWatcherEnabled { - f.restartWatcher() - } + case <-f.restartWatchChan: + f.restartWatch() case <-f.scan.timer.C: l.Debugln(f, "Scanning subdirectories") diff --git a/lib/model/rwfolder.go b/lib/model/rwfolder.go index 060d0fa1d..793d6448b 100644 --- a/lib/model/rwfolder.go +++ b/lib/model/rwfolder.go @@ -165,7 +165,7 @@ func (f *sendReceiveFolder) Serve() { var prevIgnoreHash string if f.FSWatcherEnabled { - f.startWatcher() + f.startWatch() } for { @@ -178,12 +178,6 @@ func (f *sendReceiveFolder) Serve() { f.pullTimer.Reset(0) l.Debugln(f, "remote index updated, rescheduling pull") - case <-f.ignoresUpdated: - if f.FSWatcherEnabled { - f.restartWatcher() - } - f.IndexUpdated() - case <-f.pullTimer.C: select { case <-f.initialScanFinished: @@ -214,8 +208,8 @@ func (f *sendReceiveFolder) Serve() { continue } - if err := f.model.CheckFolderHealth(f.folderID); err != nil { - l.Infoln("Skipping pull of", f.Description(), "due to folder error:", err) + if err := f.CheckHealth(); err != nil { + l.Debugln("Skipping pull of", f.Description(), "due to folder error:", err) f.pullTimer.Reset(f.sleep) continue } @@ -292,6 +286,9 @@ func (f *sendReceiveFolder) Serve() { case fsEvents := <-f.watchChan: l.Debugln(f, "filesystem notification rescan") f.scanSubdirs(fsEvents) + + case <-f.restartWatchChan: + f.restartWatch() } } } @@ -1696,6 +1693,11 @@ func (f *sendReceiveFolder) currentErrors() []fileError { return errors } +func (f *sendReceiveFolder) IgnoresUpdated() { + f.folder.IgnoresUpdated() + f.IndexUpdated() +} + // A []fileError is sent as part of an event and will be JSON serialized. type fileError struct { Path string `json:"path"`