From 486230768e5bea25fc758c119f9b9a9c6d529af3 Mon Sep 17 00:00:00 2001 From: Simon Frei Date: Sat, 25 May 2019 21:08:26 +0200 Subject: [PATCH] lib/fs, lib/model: Add error channel to Watch to avoid panics (fixes #5697) (#5734) * lib/fs, lib/model: Add error channel to Watch to avoid panics (fixes #5697) * forgot unsupported watch * and more non(-standard)-unixy fixes * and windows test * review --- lib/fs/basicfs.go | 11 +++ lib/fs/basicfs_unix.go | 11 ++- lib/fs/basicfs_watch.go | 32 ++++++--- lib/fs/basicfs_watch_test.go | 47 ++++++------ lib/fs/basicfs_watch_unsupported.go | 4 +- lib/fs/basicfs_windows.go | 10 +-- lib/fs/basicfs_windows_test.go | 22 +++--- lib/fs/errorfs.go | 4 +- lib/fs/fakefs.go | 4 +- lib/fs/filesystem.go | 5 +- lib/fs/logfs.go | 6 +- lib/model/folder.go | 107 ++++++++++++++++++---------- 12 files changed, 158 insertions(+), 105 deletions(-) diff --git a/lib/fs/basicfs.go b/lib/fs/basicfs.go index 82269be98..30fb223cc 100644 --- a/lib/fs/basicfs.go +++ b/lib/fs/basicfs.go @@ -8,6 +8,7 @@ package fs import ( "errors" + "fmt" "os" "path/filepath" "runtime" @@ -334,3 +335,13 @@ func longFilenameSupport(path string) string { } return path } + +type ErrWatchEventOutsideRoot struct{ msg string } + +func (e *ErrWatchEventOutsideRoot) Error() string { + return e.msg +} + +func (f *BasicFilesystem) newErrWatchEventOutsideRoot(absPath, root string) *ErrWatchEventOutsideRoot { + return &ErrWatchEventOutsideRoot{fmt.Sprintf("Watching for changes encountered an event outside of the filesystem root: f.root==%v, root==%v, path==%v. This should never happen, please report this message to forum.syncthing.net.", f.root, root, absPath)} +} diff --git a/lib/fs/basicfs_unix.go b/lib/fs/basicfs_unix.go index edbbff086..9c4477334 100644 --- a/lib/fs/basicfs_unix.go +++ b/lib/fs/basicfs_unix.go @@ -9,7 +9,6 @@ package fs import ( - "fmt" "os" "path/filepath" "strings" @@ -58,17 +57,17 @@ func (f *BasicFilesystem) Roots() ([]string, error) { } // unrootedChecked returns the path relative to the folder root (same as -// unrooted). It panics if the given path is not a subpath and handles the +// unrooted) or an error if the given path is not a subpath and handles the // special case when the given path is the folder root without a trailing // pathseparator. -func (f *BasicFilesystem) unrootedChecked(absPath, root string) string { +func (f *BasicFilesystem) unrootedChecked(absPath, root string) (string, *ErrWatchEventOutsideRoot) { if absPath+string(PathSeparator) == root { - return "." + return ".", nil } if !strings.HasPrefix(absPath, root) { - panic(fmt.Sprintf("bug: Notify backend is processing a change outside of the filesystem root: f.root==%v, root==%v, path==%v", f.root, root, absPath)) + return "", f.newErrWatchEventOutsideRoot(absPath, root) } - return rel(absPath, root) + return rel(absPath, root), nil } func rel(path, prefix string) string { diff --git a/lib/fs/basicfs_watch.go b/lib/fs/basicfs_watch.go index 796025273..d89d6904b 100644 --- a/lib/fs/basicfs_watch.go +++ b/lib/fs/basicfs_watch.go @@ -20,10 +20,10 @@ import ( // Not meant to be changed, but must be changeable for tests var backendBuffer = 500 -func (f *BasicFilesystem) Watch(name string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, error) { +func (f *BasicFilesystem) Watch(name string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, <-chan error, error) { watchPath, root, err := f.watchPaths(name) if err != nil { - return nil, err + return nil, nil, err } outChan := make(chan Event) @@ -36,7 +36,11 @@ func (f *BasicFilesystem) Watch(name string, ignore Matcher, ctx context.Context if ignore.SkipIgnoredDirs() { absShouldIgnore := func(absPath string) bool { - return ignore.ShouldIgnore(f.unrootedChecked(absPath, root)) + rel, err := f.unrootedChecked(absPath, root) + if err != nil { + return true + } + return ignore.ShouldIgnore(rel) } err = notify.WatchWithFilter(watchPath, backendChan, absShouldIgnore, eventMask) } else { @@ -47,15 +51,16 @@ func (f *BasicFilesystem) Watch(name string, ignore Matcher, ctx context.Context if reachedMaxUserWatches(err) { err = errors.New("failed to setup inotify handler. Please increase inotify limits, see https://docs.syncthing.net/users/faq.html#inotify-limits") } - return nil, err + return nil, nil, err } - go f.watchLoop(name, root, backendChan, outChan, ignore, ctx) + errChan := make(chan error) + go f.watchLoop(name, root, backendChan, outChan, errChan, ignore, ctx) - return outChan, nil + return outChan, errChan, nil } -func (f *BasicFilesystem) watchLoop(name, evalRoot string, backendChan chan notify.EventInfo, outChan chan<- Event, ignore Matcher, ctx context.Context) { +func (f *BasicFilesystem) watchLoop(name, evalRoot string, backendChan chan notify.EventInfo, outChan chan<- Event, errChan chan<- error, ignore Matcher, ctx context.Context) { for { // Detect channel overflow if len(backendChan) == backendBuffer { @@ -74,7 +79,18 @@ func (f *BasicFilesystem) watchLoop(name, evalRoot string, backendChan chan noti select { case ev := <-backendChan: - relPath := f.unrootedChecked(ev.Path(), evalRoot) + relPath, err := f.unrootedChecked(ev.Path(), evalRoot) + if err != nil { + select { + case errChan <- err: + l.Debugln(f.Type(), f.URI(), "Watch: Sending error", err) + case <-ctx.Done(): + } + notify.Stop(backendChan) + l.Debugln(f.Type(), f.URI(), "Watch: Stopped due to", err) + return + } + if ignore.ShouldIgnore(relPath) { l.Debugln(f.Type(), f.URI(), "Watch: Ignoring", relPath) continue diff --git a/lib/fs/basicfs_watch_test.go b/lib/fs/basicfs_watch_test.go index 939098e59..1a1b40f01 100644 --- a/lib/fs/basicfs_watch_test.go +++ b/lib/fs/basicfs_watch_test.go @@ -159,6 +159,7 @@ func TestWatchWinRoot(t *testing.T) { outChan := make(chan Event) backendChan := make(chan notify.EventInfo, backendBuffer) + errChan := make(chan error) ctx, cancel := context.WithCancel(context.Background()) @@ -177,7 +178,7 @@ func TestWatchWinRoot(t *testing.T) { } cancel() }() - fs.watchLoop(".", root, backendChan, outChan, fakeMatcher{}, ctx) + fs.watchLoop(".", root, backendChan, outChan, errChan, fakeMatcher{}, ctx) }() // filepath.Dir as watch has a /... suffix @@ -192,6 +193,8 @@ func TestWatchWinRoot(t *testing.T) { if ev.Name != name { t.Errorf("Unexpected event %v, expected %v", ev.Name, name) } + case err := <-errChan: + t.Error("Received fatal watch error:", err) case <-ctx.Done(): } } @@ -200,32 +203,22 @@ func TestWatchWinRoot(t *testing.T) { func TestWatchOutside(t *testing.T) { outChan := make(chan Event) backendChan := make(chan notify.EventInfo, backendBuffer) + errChan := make(chan error) ctx, cancel := context.WithCancel(context.Background()) // testFs is Filesystem, but we need BasicFilesystem here fs := newBasicFilesystem(testDirAbs) - go func() { - defer func() { - if recover() == nil { - select { - case <-ctx.Done(): // timed out - default: - t.Fatalf("Watch did not panic on receiving event outside of folder") - } - } - cancel() - }() - fs.watchLoop(".", testDirAbs, backendChan, outChan, fakeMatcher{}, ctx) - }() + go fs.watchLoop(".", testDirAbs, backendChan, outChan, errChan, fakeMatcher{}, ctx) backendChan <- fakeEventInfo(filepath.Join(filepath.Dir(testDirAbs), "outside")) select { case <-time.After(10 * time.Second): cancel() - t.Errorf("Timed out before panicing") + t.Errorf("Timed out before receiving error") + case <-errChan: case <-ctx.Done(): } } @@ -233,6 +226,7 @@ func TestWatchOutside(t *testing.T) { func TestWatchSubpath(t *testing.T) { outChan := make(chan Event) backendChan := make(chan notify.EventInfo, backendBuffer) + errChan := make(chan error) ctx, cancel := context.WithCancel(context.Background()) @@ -240,7 +234,7 @@ func TestWatchSubpath(t *testing.T) { fs := newBasicFilesystem(testDirAbs) abs, _ := fs.rooted("sub") - go fs.watchLoop("sub", testDirAbs, backendChan, outChan, fakeMatcher{}, ctx) + go fs.watchLoop("sub", testDirAbs, backendChan, outChan, errChan, fakeMatcher{}, ctx) backendChan <- fakeEventInfo(filepath.Join(abs, "file")) @@ -253,6 +247,8 @@ func TestWatchSubpath(t *testing.T) { if ev.Name != filepath.Join("sub", "file") { t.Errorf("While watching a subfolder, received an event with unexpected path %v", ev.Name) } + case err := <-errChan: + t.Error("Received fatal watch error:", err) } cancel() @@ -337,7 +333,7 @@ func TestWatchSymlinkedRoot(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) defer cancel() - if _, err := linkedFs.Watch(".", fakeMatcher{}, ctx, false); err != nil { + if _, _, err := linkedFs.Watch(".", fakeMatcher{}, ctx, false); err != nil { panic(err) } @@ -350,14 +346,10 @@ func TestWatchSymlinkedRoot(t *testing.T) { } func TestUnrootedChecked(t *testing.T) { - var unrooted string - defer func() { - if recover() == nil { - t.Fatal("unrootedChecked did not panic on outside path, but returned", unrooted) - } - }() fs := newBasicFilesystem(testDirAbs) - unrooted = fs.unrootedChecked("/random/other/path", testDirAbs) + if unrooted, err := fs.unrootedChecked("/random/other/path", testDirAbs); err == nil { + t.Error("unrootedChecked did not return an error on outside path, but returned", unrooted) + } } func TestWatchIssue4877(t *testing.T) { @@ -428,7 +420,7 @@ func testScenario(t *testing.T, name string, testCase func(), expectedEvents, al ctx, cancel := context.WithCancel(context.Background()) defer cancel() - eventChan, err := testFs.Watch(name, fm, ctx, false) + eventChan, errChan, err := testFs.Watch(name, fm, ctx, false) if err != nil { panic(err) } @@ -439,8 +431,9 @@ func testScenario(t *testing.T, name string, testCase func(), expectedEvents, al select { case <-time.After(10 * time.Second): - t.Errorf("Timed out before receiving all expected events") - + t.Error("Timed out before receiving all expected events") + case err := <-errChan: + t.Error("Received fatal watch error:", err) case <-ctx.Done(): } } diff --git a/lib/fs/basicfs_watch_unsupported.go b/lib/fs/basicfs_watch_unsupported.go index 77000a3fd..1bb37dd0c 100644 --- a/lib/fs/basicfs_watch_unsupported.go +++ b/lib/fs/basicfs_watch_unsupported.go @@ -10,6 +10,6 @@ package fs import "context" -func (f *BasicFilesystem) Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, error) { - return nil, ErrWatchNotSupported +func (f *BasicFilesystem) Watch(name string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, <-chan error, error) { + return nil, nil, ErrWatchNotSupported } diff --git a/lib/fs/basicfs_windows.go b/lib/fs/basicfs_windows.go index 66a3c75b7..d33b41a1a 100644 --- a/lib/fs/basicfs_windows.go +++ b/lib/fs/basicfs_windows.go @@ -153,20 +153,20 @@ func (f *BasicFilesystem) Roots() ([]string, error) { } // unrootedChecked returns the path relative to the folder root (same as -// unrooted). It panics if the given path is not a subpath and handles the +// unrooted) or an error if the given path is not a subpath and handles the // special case when the given path is the folder root without a trailing // pathseparator. -func (f *BasicFilesystem) unrootedChecked(absPath, root string) string { +func (f *BasicFilesystem) unrootedChecked(absPath, root string) (string, error) { absPath = f.resolveWin83(absPath) lowerAbsPath := UnicodeLowercase(absPath) lowerRoot := UnicodeLowercase(root) if lowerAbsPath+string(PathSeparator) == lowerRoot { - return "." + return ".", nil } if !strings.HasPrefix(lowerAbsPath, lowerRoot) { - panic(fmt.Sprintf("bug: Notify backend is processing a change outside of the filesystem root: f.root==%v, root==%v (lower), path==%v (lower)", f.root, lowerRoot, lowerAbsPath)) + return "", f.newErrWatchEventOutsideRoot(lowerAbsPath, lowerRoot) } - return rel(absPath, root) + return rel(absPath, root), nil } func rel(path, prefix string) string { diff --git a/lib/fs/basicfs_windows_test.go b/lib/fs/basicfs_windows_test.go index 8a753491f..343a5d75f 100644 --- a/lib/fs/basicfs_windows_test.go +++ b/lib/fs/basicfs_windows_test.go @@ -127,19 +127,15 @@ func TestRelUnrootedCheckedWindows(t *testing.T) { } // unrootedChecked really just wraps rel, and does not care about - // the actual root of that filesystem, but should not panic on these - // test cases. - fs := BasicFilesystem{root: tc.root} - if res := fs.unrootedChecked(tc.abs, tc.root); res != tc.expectedRel { - t.Errorf(`unrootedChecked("%v", "%v") == "%v", expected "%v"`, tc.abs, tc.root, res, tc.expectedRel) - } - fs = BasicFilesystem{root: strings.ToLower(tc.root)} - if res := fs.unrootedChecked(tc.abs, tc.root); res != tc.expectedRel { - t.Errorf(`unrootedChecked("%v", "%v") == "%v", expected "%v"`, tc.abs, tc.root, res, tc.expectedRel) - } - fs = BasicFilesystem{root: strings.ToUpper(tc.root)} - if res := fs.unrootedChecked(tc.abs, tc.root); res != tc.expectedRel { - t.Errorf(`unrootedChecked("%v", "%v") == "%v", expected "%v"`, tc.abs, tc.root, res, tc.expectedRel) + // the actual root of that filesystem, but should not return an error + // on these test cases. + for _, root := range []string{tc.root, strings.ToLower(tc.root), strings.ToUpper(tc.root)} { + fs := BasicFilesystem{root: root} + if res, err := fs.unrootedChecked(tc.abs, tc.root); err != nil { + t.Errorf(`Unexpected error from unrootedChecked("%v", "%v"): %v (fs.root: %v)`, tc.abs, tc.root, err, root) + } else if res != tc.expectedRel { + t.Errorf(`unrootedChecked("%v", "%v") == "%v", expected "%v" (fs.root: %v)`, tc.abs, tc.root, res, tc.expectedRel, root) + } } } } diff --git a/lib/fs/errorfs.go b/lib/fs/errorfs.go index 02c6bf4cc..787aa9a96 100644 --- a/lib/fs/errorfs.go +++ b/lib/fs/errorfs.go @@ -44,6 +44,6 @@ func (fs *errorFilesystem) Usage(name string) (Usage, error) func (fs *errorFilesystem) Type() FilesystemType { return fs.fsType } func (fs *errorFilesystem) URI() string { return fs.uri } func (fs *errorFilesystem) SameFile(fi1, fi2 FileInfo) bool { return false } -func (fs *errorFilesystem) Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, error) { - return nil, fs.err +func (fs *errorFilesystem) Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, <-chan error, error) { + return nil, nil, fs.err } diff --git a/lib/fs/fakefs.go b/lib/fs/fakefs.go index dbfced694..40beb6fe6 100644 --- a/lib/fs/fakefs.go +++ b/lib/fs/fakefs.go @@ -466,8 +466,8 @@ func (fs *fakefs) Walk(name string, walkFn WalkFunc) error { return errors.New("not implemented") } -func (fs *fakefs) Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, error) { - return nil, ErrWatchNotSupported +func (fs *fakefs) Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, <-chan error, error) { + return nil, nil, ErrWatchNotSupported } func (fs *fakefs) Hide(name string) error { diff --git a/lib/fs/filesystem.go b/lib/fs/filesystem.go index 91dcb1f2d..928c52e61 100644 --- a/lib/fs/filesystem.go +++ b/lib/fs/filesystem.go @@ -36,7 +36,10 @@ type Filesystem interface { Stat(name string) (FileInfo, error) SymlinksSupported() bool Walk(name string, walkFn WalkFunc) error - Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, error) + // If setup fails, returns non-nil error, and if afterwards a fatal (!) + // error occurs, sends that error on the channel. Afterwards this watch + // can be considered stopped. + Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, <-chan error, error) Hide(name string) error Unhide(name string) error Glob(pattern string) ([]string, error) diff --git a/lib/fs/logfs.go b/lib/fs/logfs.go index f74b3a57c..8e8716a1a 100644 --- a/lib/fs/logfs.go +++ b/lib/fs/logfs.go @@ -128,10 +128,10 @@ func (fs *logFilesystem) Walk(root string, walkFn WalkFunc) error { return err } -func (fs *logFilesystem) Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, error) { - evChan, err := fs.Filesystem.Watch(path, ignore, ctx, ignorePerms) +func (fs *logFilesystem) Watch(path string, ignore Matcher, ctx context.Context, ignorePerms bool) (<-chan Event, <-chan error, error) { + evChan, errChan, err := fs.Filesystem.Watch(path, ignore, ctx, ignorePerms) l.Debugln(getCaller(), fs.Type(), fs.URI(), "Watch", path, ignore, ignorePerms, err) - return evChan, err + return evChan, errChan, err } func (fs *logFilesystem) Unhide(name string) error { diff --git a/lib/model/folder.go b/lib/model/folder.go index 087286127..517cf9819 100644 --- a/lib/model/folder.go +++ b/lib/model/folder.go @@ -173,9 +173,6 @@ func (f *folder) Serve() { pullFailTimer.Reset(pause) } - // The reason for running the scanner from within the puller is that - // this is the easiest way to make sure we are not doing both at the - // same time. case <-f.scanTimer.C: l.Debugln(f, "Scanning subdirectories") f.scanTimerFired() @@ -611,53 +608,91 @@ func (f *folder) startWatch() { f.watchChan = make(chan []string) f.watchCancel = cancel f.watchMut.Unlock() - go f.startWatchAsync(ctx) + go f.monitorWatch(ctx) } -// startWatchAsync tries to start the filesystem watching and retries every minute on failure. -// It is a convenience function that should not be used except in startWatch. -func (f *folder) startWatchAsync(ctx context.Context) { - timer := time.NewTimer(0) +// monitorWatch starts the filesystem watching and retries every minute on failure. +// It should not be used except in startWatch. +func (f *folder) monitorWatch(ctx context.Context) { + failTimer := time.NewTimer(0) + aggrCtx, aggrCancel := context.WithCancel(ctx) + var err error + var eventChan <-chan fs.Event + var errChan <-chan error + warnedOutside := false for { select { - case <-timer.C: - eventChan, err := f.Filesystem().Watch(".", f.ignores, ctx, f.IgnorePerms) - f.watchMut.Lock() - prevErr := f.watchErr - f.watchErr = err - f.watchMut.Unlock() - if err != prevErr { - data := map[string]interface{}{ - "folder": f.ID, - } - if prevErr != nil { - data["from"] = prevErr.Error() - } - if err != nil { - data["to"] = err.Error() - } - events.Default.Log(events.FolderWatchStateChanged, data) - } + case <-failTimer.C: + eventChan, errChan, err = f.Filesystem().Watch(".", f.ignores, ctx, f.IgnorePerms) + // We do this at most once per minute which is the + // default rescan time without watcher. + f.scanOnWatchErr() + f.setWatchError(err) if err != nil { - if prevErr == errWatchNotStarted { - l.Infof("Error while trying to start filesystem watcher for folder %s, trying again in 1min: %v", f.Description(), err) - } else { - l.Debugf("Repeat error while trying to start filesystem watcher for folder %s, trying again in 1min: %v", f.Description(), err) - } - timer.Reset(time.Minute) + failTimer.Reset(time.Minute) continue } - f.watchMut.Lock() - defer f.watchMut.Unlock() - watchaggregator.Aggregate(eventChan, f.watchChan, f.FolderConfiguration, f.model.cfg, ctx) + watchaggregator.Aggregate(eventChan, f.watchChan, f.FolderConfiguration, f.model.cfg, aggrCtx) l.Debugln("Started filesystem watcher for folder", f.Description()) - return + case err = <-errChan: + f.setWatchError(err) + // This error was previously a panic and should never occur, so generate + // a warning, but don't do it repetitively. + if !warnedOutside { + if _, ok := err.(*fs.ErrWatchEventOutsideRoot); ok { + l.Warnln(err) + warnedOutside = true + return + } + } + aggrCancel() + errChan = nil + aggrCtx, aggrCancel = context.WithCancel(ctx) + failTimer.Reset(time.Minute) case <-ctx.Done(): return } } } +// setWatchError sets the current error state of the watch and should be called +// regardless of whether err is nil or not. +func (f *folder) setWatchError(err error) { + f.watchMut.Lock() + prevErr := f.watchErr + f.watchErr = err + f.watchMut.Unlock() + if err != prevErr { + data := map[string]interface{}{ + "folder": f.ID, + } + if prevErr != nil { + data["from"] = prevErr.Error() + } + if err != nil { + data["to"] = err.Error() + } + events.Default.Log(events.FolderWatchStateChanged, data) + } + if err == nil { + return + } + if prevErr == errWatchNotStarted { + l.Infof("Error while trying to start filesystem watcher for folder %s, trying again in 1min: %v", f.Description(), err) + return + } + l.Debugf("Repeat error while trying to start filesystem watcher for folder %s, trying again in 1min: %v", f.Description(), err) +} + +// scanOnWatchErr schedules a full scan immediately if an error occurred while watching. +func (f *folder) scanOnWatchErr() { + f.watchMut.Lock() + if f.watchErr != nil && f.watchErr != errWatchNotStarted { + f.Delay(0) + } + f.watchMut.Unlock() +} + func (f *folder) setError(err error) { select { case <-f.ctx.Done():