Fail the Finder in case of unexpected fs error

Permissions errors are ignored
Errors on pruned dirs are also ignored

Bug: 62455338
Test: m -j blueprint_tools # which runs unit tests
Change-Id: I8ba85fdd0295deb7dc374a851212e7c850e76b75

finder/cmd/finder.go

@@ -127,9 +127,13 @@ func run() error {
 		usage()
 		return errors.New("Param 'db' must be nonempty")
 	}
+
 	matches := []string{}
 	for i := 0; i < numIterations; i++ {
-		matches = runFind(params, logger)
+		matches, err = runFind(params, logger)
+		if err != nil {
+			return err
+		}
 	}
 	findDuration := time.Since(startTime)
 	logger.Printf("Found these %v inodes in %v :\n", len(matches), findDuration)
@@ -142,8 +146,11 @@ func run() error {
 	return nil
 }
 
-func runFind(params finder.CacheParams, logger *log.Logger) (paths []string) {
+func runFind(params finder.CacheParams, logger *log.Logger) (paths []string, err error) {
-	service := finder.New(params, fs.OsFs, logger, dbPath)
+	service, err := finder.New(params, fs.OsFs, logger, dbPath)
+	if err != nil {
+		return []string{}, err
+	}
 	defer service.Shutdown()
-	return service.FindAll()
+	return service.FindAll(), nil
 }

finder/finder.go

@@ -150,6 +150,8 @@ type Finder struct {
 	// temporary state
 	threadPool *threadPool
 	mutex      sync.Mutex
+	fsErrs     []fsErr
+	errlock    sync.Mutex
 
 	// non-temporary state
 	modifiedFlag int32
@@ -158,7 +160,7 @@ type Finder struct {
 
 // New creates a new Finder for use
 func New(cacheParams CacheParams, filesystem fs.FileSystem,
-	logger Logger, dbPath string) *Finder {
+	logger Logger, dbPath string) (f *Finder, err error) {
 
 	numThreads := runtime.NumCPU() * 2
 	numDbLoadingThreads := numThreads
@@ -172,7 +174,7 @@ func New(cacheParams CacheParams, filesystem fs.FileSystem,
 		},
 	}
 
-	finder := &Finder{
+	f = &Finder{
 		numDbLoadingThreads: numDbLoadingThreads,
 		numSearchingThreads: numSearchingThreads,
 		cacheMetadata:       metadata,
@@ -183,10 +185,23 @@ func New(cacheParams CacheParams, filesystem fs.FileSystem,
 		DbPath: dbPath,
 	}
 
-	finder.loadFromFilesystem()
+	f.loadFromFilesystem()
 
-	finder.verbosef("Done parsing db\n")
+	// check for any filesystem errors
-	return finder
+	err = f.getErr()
+	if err != nil {
+		return nil, err
+	}
+
+	// confirm that every path mentioned in the CacheConfig exists
+	for _, path := range cacheParams.RootDirs {
+		node := f.nodes.GetNode(filepath.Clean(path), false)
+		if node == nil || node.ModTime == 0 {
+			return nil, fmt.Errorf("%v does not exist\n", path)
+		}
+	}
+
+	return f, nil
 }
 
 // FindNamed searches for every cached file
@@ -338,10 +353,6 @@ func (f *Finder) loadFromFilesystem() {
 		f.startWithoutExternalCache()
 	}
 
-	startTime := time.Now()
-	f.verbosef("Waiting for pending requests to complete\n")
-	f.threadPool.Wait()
-	f.verbosef("Is idle after %v\n", time.Now().Sub(startTime))
 	f.threadPool = nil
 }
 
@@ -598,6 +609,15 @@ func (p *threadPool) Wait() {
 	p.receivedRequests.Wait()
 }
 
+type fsErr struct {
+	path string
+	err  error
+}
+
+func (e fsErr) String() string {
+	return e.path + ": " + e.err.Error()
+}
+
 func (f *Finder) serializeCacheEntry(dirInfos []dirFullInfo) ([]byte, error) {
 	// group each dirFullInfo by its Device, to avoid having to repeat it in the output
 	dirsByDevice := map[uint64][]PersistedDirInfo{}
@@ -943,13 +963,17 @@ func (f *Finder) startFromExternalCache() (err error) {
 	for i := range nodesToWalk {
 		f.listDirsAsync(nodesToWalk[i])
 	}
-	f.verbosef("Loaded db and statted its contents in %v\n", time.Since(startTime))
+	f.verbosef("Loaded db and statted known dirs in %v\n", time.Since(startTime))
+	f.threadPool.Wait()
+	f.verbosef("Loaded db and statted all dirs in %v\n", time.Now().Sub(startTime))
+
 	return err
 }
 
 // startWithoutExternalCache starts scanning the filesystem according to the cache config
 // startWithoutExternalCache should be called if startFromExternalCache is not applicable
 func (f *Finder) startWithoutExternalCache() {
+	startTime := time.Now()
 	configDirs := f.cacheMetadata.Config.RootDirs
 
 	// clean paths
@@ -977,6 +1001,10 @@ func (f *Finder) startWithoutExternalCache() {
 		f.verbosef("Starting find of %v\n", path)
 		f.startFind(path)
 	}
+
+	f.threadPool.Wait()
+
+	f.verbosef("Scanned filesystem (not using cache) in %v\n", time.Now().Sub(startTime))
 }
 
 // isInfoUpToDate tells whether <new> can confirm that results computed at <old> are still valid
@@ -1114,6 +1142,79 @@ func (f *Finder) dumpDb() error {
 
 	f.verbosef("Wrote db in %v\n", time.Now().Sub(serializeDate))
 	return nil
+
+}
+
+// canIgnoreFsErr checks for certain classes of filesystem errors that are safe to ignore
+func (f *Finder) canIgnoreFsErr(err error) bool {
+	pathErr, isPathErr := err.(*os.PathError)
+	if !isPathErr {
+		// Don't recognize this error
+		return false
+	}
+	if pathErr.Err == os.ErrPermission {
+		// Permission errors are ignored:
+		// https://issuetracker.google.com/37553659
+		// https://github.com/google/kati/pull/116
+		return true
+	}
+	if pathErr.Err == os.ErrNotExist {
+		// If a directory doesn't exist, that generally means the cache is out-of-date
+		return true
+	}
+	// Don't recognize this error
+	return false
+}
+
+// onFsError should be called whenever a potentially fatal error is returned from a filesystem call
+func (f *Finder) onFsError(path string, err error) {
+	if !f.canIgnoreFsErr(err) {
+		// We could send the errors through a channel instead, although that would cause this call
+		// to block unless we preallocated a sufficient buffer or spawned a reader thread.
+		// Although it wouldn't be too complicated to spawn a reader thread, it's still slightly
+		// more convenient to use a lock. Only in an unusual situation should this code be
+		// invoked anyway.
+		f.errlock.Lock()
+		f.fsErrs = append(f.fsErrs, fsErr{path: path, err: err})
+		f.errlock.Unlock()
+	}
+}
+
+// discardErrsForPrunedPaths removes any errors for paths that are no longer included in the cache
+func (f *Finder) discardErrsForPrunedPaths() {
+	// This function could be somewhat inefficient due to being single-threaded,
+	// but the length of f.fsErrs should be approximately 0, so it shouldn't take long anyway.
+	relevantErrs := make([]fsErr, 0, len(f.fsErrs))
+	for _, fsErr := range f.fsErrs {
+		path := fsErr.path
+		node := f.nodes.GetNode(path, false)
+		if node != nil {
+			// The path in question wasn't pruned due to a failure to process a parent directory.
+			// So, the failure to process this path is important
+			relevantErrs = append(relevantErrs, fsErr)
+		}
+	}
+	f.fsErrs = relevantErrs
+}
+
+// getErr returns an error based on previous calls to onFsErr, if any
+func (f *Finder) getErr() error {
+	f.discardErrsForPrunedPaths()
+
+	numErrs := len(f.fsErrs)
+	if numErrs < 1 {
+		return nil
+	}
+
+	maxNumErrsToInclude := 10
+	message := ""
+	if numErrs > maxNumErrsToInclude {
+		message = fmt.Sprintf("finder encountered %v errors: %v...", numErrs, f.fsErrs[:maxNumErrsToInclude])
+	} else {
+		message = fmt.Sprintf("finder encountered %v errors: %v", numErrs, f.fsErrs)
+	}
+
+	return errors.New(message)
 }
 
 func (f *Finder) statDirAsync(dir *pathMap) {
@@ -1145,6 +1246,8 @@ func (f *Finder) statDirSync(path string) statResponse {
 
 	var stats statResponse
 	if err != nil {
+		// possibly record this error
+		f.onFsError(path, err)
 		// in case of a failure to stat the directory, treat the directory as missing (modTime = 0)
 		return stats
 	}
@@ -1248,6 +1351,8 @@ func (f *Finder) listDirSync(dir *pathMap) {
 	children, err := f.filesystem.ReadDir(path)
 
 	if err != nil {
+		// possibly record this error
+		f.onFsError(path, err)
 		// if listing the contents of the directory fails (presumably due to
 		// permission denied), then treat the directory as empty
 		children = []os.FileInfo{}

finder/finder_test.go

@@ -16,18 +16,17 @@ package finder
 
 import (
 	"fmt"
+	"io/ioutil"
 	"log"
+	"os"
 	"path/filepath"
 	"reflect"
-	"testing"
-
 	"sort"
-
+	"testing"
-	"io/ioutil"
+	"time"
 
 	"android/soong/fs"
 	"runtime/debug"
-	"time"
 )
 
 // some utils for tests to use
@@ -36,6 +35,14 @@ func newFs() *fs.MockFs {
 }
 
 func newFinder(t *testing.T, filesystem *fs.MockFs, cacheParams CacheParams) *Finder {
+	f, err := newFinderAndErr(t, filesystem, cacheParams)
+	if err != nil {
+		fatal(t, err.Error())
+	}
+	return f
+}
+
+func newFinderAndErr(t *testing.T, filesystem *fs.MockFs, cacheParams CacheParams) (*Finder, error) {
 	cachePath := "/finder/finder-db"
 	cacheDir := filepath.Dir(cachePath)
 	filesystem.MkDirs(cacheDir)
@@ -44,16 +51,25 @@ func newFinder(t *testing.T, filesystem *fs.MockFs, cacheParams CacheParams) *Fi
 	}
 
 	logger := log.New(ioutil.Discard, "", 0)
-	finder := New(cacheParams, filesystem, logger, cachePath)
+	f, err := New(cacheParams, filesystem, logger, cachePath)
-	return finder
+	return f, err
 }
 
 func finderWithSameParams(t *testing.T, original *Finder) *Finder {
-	return New(
+	f, err := finderAndErrorWithSameParams(t, original)
+	if err != nil {
+		fatal(t, err.Error())
+	}
+	return f
+}
+
+func finderAndErrorWithSameParams(t *testing.T, original *Finder) (*Finder, error) {
+	f, err := New(
 		original.cacheMetadata.Config.CacheParams,
 		original.filesystem,
 		original.logger,
 		original.DbPath)
+	return f, err
 }
 
 func write(t *testing.T, path string, content string, filesystem *fs.MockFs) {
@@ -61,7 +77,7 @@ func write(t *testing.T, path string, content string, filesystem *fs.MockFs) {
 	filesystem.MkDirs(parent)
 	err := filesystem.WriteFile(path, []byte(content), 0777)
 	if err != nil {
-		t.Fatal(err.Error())
+		fatal(t, err.Error())
 	}
 }
 
@@ -72,21 +88,21 @@ func create(t *testing.T, path string, filesystem *fs.MockFs) {
 func delete(t *testing.T, path string, filesystem *fs.MockFs) {
 	err := filesystem.Remove(path)
 	if err != nil {
-		t.Fatal(err.Error())
+		fatal(t, err.Error())
 	}
 }
 
 func removeAll(t *testing.T, path string, filesystem *fs.MockFs) {
 	err := filesystem.RemoveAll(path)
 	if err != nil {
-		t.Fatal(err.Error())
+		fatal(t, err.Error())
 	}
 }
 
 func move(t *testing.T, oldPath string, newPath string, filesystem *fs.MockFs) {
 	err := filesystem.Rename(oldPath, newPath)
 	if err != nil {
-		t.Fatal(err.Error())
+		fatal(t, err.Error())
 	}
 }
 
@@ -98,7 +114,7 @@ func link(t *testing.T, newPath string, oldPath string, filesystem *fs.MockFs) {
 	}
 	err = filesystem.Symlink(oldPath, newPath)
 	if err != nil {
-		t.Fatal(err.Error())
+		fatal(t, err.Error())
 	}
 }
 func read(t *testing.T, path string, filesystem *fs.MockFs) string {
@@ -125,11 +141,20 @@ func setReadable(t *testing.T, path string, readable bool, filesystem *fs.MockFs
 		t.Fatal(err.Error())
 	}
 }
+
+func setReadErr(t *testing.T, path string, readErr error, filesystem *fs.MockFs) {
+	err := filesystem.SetReadErr(path, readErr)
+	if err != nil {
+		t.Fatal(err.Error())
+	}
+}
+
 func fatal(t *testing.T, message string) {
 	t.Error(message)
 	debug.PrintStack()
 	t.FailNow()
 }
+
 func assertSameResponse(t *testing.T, actual []string, expected []string) {
 	sort.Strings(actual)
 	sort.Strings(expected)
@@ -280,11 +305,11 @@ func TestFilesystemRoot(t *testing.T) {
 	assertSameResponse(t, foundPaths, []string{createdPath})
 }
 
-func TestNonexistentPath(t *testing.T) {
+func TestNonexistentDir(t *testing.T) {
 	filesystem := newFs()
 	create(t, "/tmp/findme.txt", filesystem)
 
-	finder := newFinder(
+	_, err := newFinderAndErr(
 		t,
 		filesystem,
 		CacheParams{
@@ -292,11 +317,9 @@ func TestNonexistentPath(t *testing.T) {
 			IncludeFiles: []string{"findme.txt", "skipme.txt"},
 		},
 	)
-	defer finder.Shutdown()
+	if err == nil {
-
+		fatal(t, "Did not fail when given a nonexistent root directory")
-	foundPaths := finder.FindNamedAt("/tmp/IAlsoDontExist", "findme.txt")
+	}
-
-	assertSameResponse(t, foundPaths, []string{})
 }
 
 func TestExcludeDirs(t *testing.T) {
@@ -392,7 +415,7 @@ func TestUncachedDir(t *testing.T) {
 		t,
 		filesystem,
 		CacheParams{
-			RootDirs:     []string{"/IDoNotExist"},
+			RootDirs:     []string{"/tmp/b"},
 			IncludeFiles: []string{"findme.txt"},
 		},
 	)
@@ -483,7 +506,7 @@ func TestRootDirsContainedInOtherRootDirs(t *testing.T) {
 		t,
 		filesystem,
 		CacheParams{
-			RootDirs:     []string{"/", "/a/b/c", "/a/b/c/d/e/f", "/a/b/c/d/e/f/g/h/i"},
+			RootDirs:     []string{"/", "/tmp/a/b/c", "/tmp/a/b/c/d/e/f", "/tmp/a/b/c/d/e/f/g/h/i"},
 			IncludeFiles: []string{"findme.txt"},
 		},
 	)
@@ -1571,3 +1594,33 @@ func TestFileNotPermitted(t *testing.T) {
 	// check results
 	assertSameResponse(t, foundPaths, []string{"/tmp/hi.txt"})
 }
+
+func TestCacheEntryPathUnexpectedError(t *testing.T) {
+	// setup filesystem
+	filesystem := newFs()
+	create(t, "/tmp/a/hi.txt", filesystem)
+
+	// run the first finder
+	finder := newFinder(
+		t,
+		filesystem,
+		CacheParams{
+			RootDirs:     []string{"/tmp"},
+			IncludeFiles: []string{"hi.txt"},
+		},
+	)
+	foundPaths := finder.FindAll()
+	filesystem.Clock.Tick()
+	finder.Shutdown()
+	// check results
+	assertSameResponse(t, foundPaths, []string{"/tmp/a/hi.txt"})
+
+	// make the directory not readable
+	setReadErr(t, "/tmp/a", os.ErrInvalid, filesystem)
+
+	// run the second finder
+	_, err := finderAndErrorWithSameParams(t, finder)
+	if err == nil {
+		fatal(t, "Failed to detect unexpected filesystem error")
+	}
+}

fs/fs.go

@@ -159,7 +159,7 @@ type mockInode struct {
 	permTime    time.Time
 	sys         interface{}
 	inodeNumber uint64
-	readable    bool
+	readErr     error
 }
 
 func (m mockInode) ModTime() time.Time {
@@ -221,11 +221,11 @@ func (m *MockFs) followLinks(path string, followLastLink bool, count int) (canon
 	if err != nil {
 		return "", err
 	}
-	if !parentNode.readable {
+	if parentNode.readErr != nil {
 		return "", &os.PathError{
 			Op:   "read",
 			Path: path,
-			Err:  os.ErrPermission,
+			Err:  parentNode.readErr,
 		}
 	}
 
@@ -240,11 +240,11 @@ func (m *MockFs) followLinks(path string, followLastLink bool, count int) (canon
 			}
 		}
 
-		if !link.readable {
+		if link.readErr != nil {
 			return "", &os.PathError{
 				Op:   "read",
 				Path: path,
-				Err:  os.ErrPermission,
+				Err:  link.readErr,
 			}
 		}
 
@@ -277,11 +277,11 @@ func (m *MockFs) getFile(parentDir *mockDir, fileName string) (file *mockFile, e
 			Err:  os.ErrNotExist,
 		}
 	}
-	if !file.readable {
+	if file.readErr != nil {
 		return nil, &os.PathError{
 			Op:   "open",
 			Path: fileName,
-			Err:  os.ErrPermission,
+			Err:  file.readErr,
 		}
 	}
 	return file, nil
@@ -491,11 +491,11 @@ func (m *MockFs) ReadDir(path string) (contents []os.FileInfo, err error) {
 	if err != nil {
 		return nil, err
 	}
-	if !dir.readable {
+	if dir.readErr != nil {
 		return nil, &os.PathError{
 			Op:   "read",
 			Path: path,
-			Err:  os.ErrPermission,
+			Err:  dir.readErr,
 		}
 	}
 	// describe its contents
@@ -532,11 +532,11 @@ func (m *MockFs) Rename(sourcePath string, destPath string) error {
 			Err:  os.ErrNotExist,
 		}
 	}
-	if !sourceParentDir.readable {
+	if sourceParentDir.readErr != nil {
 		return &os.PathError{
 			Op:   "move",
 			Path: sourcePath,
-			Err:  os.ErrPermission,
+			Err:  sourceParentDir.readErr,
 		}
 	}
 
@@ -554,11 +554,11 @@ func (m *MockFs) Rename(sourcePath string, destPath string) error {
 			Err:  os.ErrNotExist,
 		}
 	}
-	if !destParentDir.readable {
+	if destParentDir.readErr != nil {
 		return &os.PathError{
 			Op:   "move",
 			Path: destParentPath,
-			Err:  os.ErrPermission,
+			Err:  destParentDir.readErr,
 		}
 	}
 	// check the source and dest themselves
@@ -648,11 +648,11 @@ func (m *MockFs) WriteFile(filePath string, data []byte, perm os.FileMode) error
 			Err:  os.ErrNotExist,
 		}
 	}
-	if !parentDir.readable {
+	if parentDir.readErr != nil {
 		return &os.PathError{
 			Op:   "write",
 			Path: parentPath,
-			Err:  os.ErrPermission,
+			Err:  parentDir.readErr,
 		}
 	}
 
@@ -662,11 +662,12 @@ func (m *MockFs) WriteFile(filePath string, data []byte, perm os.FileMode) error
 		parentDir.modTime = m.Clock.Time()
 		parentDir.files[baseName] = m.newFile()
 	} else {
-		if !parentDir.files[baseName].readable {
+		readErr := parentDir.files[baseName].readErr
+		if readErr != nil {
 			return &os.PathError{
 				Op:   "write",
 				Path: filePath,
-				Err:  os.ErrPermission,
+				Err:  readErr,
 			}
 		}
 	}
@@ -681,7 +682,6 @@ func (m *MockFs) newFile() *mockFile {
 	newFile.inodeNumber = m.newInodeNumber()
 	newFile.modTime = m.Clock.Time()
 	newFile.permTime = newFile.modTime
-	newFile.readable = true
 	return newFile
 }
 
@@ -694,7 +694,6 @@ func (m *MockFs) newDir() *mockDir {
 	newDir.inodeNumber = m.newInodeNumber()
 	newDir.modTime = m.Clock.Time()
 	newDir.permTime = newDir.modTime
-	newDir.readable = true
 	return newDir
 }
 
@@ -705,7 +704,6 @@ func (m *MockFs) newLink(target string) *mockLink {
 	newLink.inodeNumber = m.newInodeNumber()
 	newLink.modTime = m.Clock.Time()
 	newLink.permTime = newLink.modTime
-	newLink.readable = true
 
 	return newLink
 }
@@ -729,11 +727,11 @@ func (m *MockFs) getDir(path string, createIfMissing bool) (dir *mockDir, err er
 	if err != nil {
 		return nil, err
 	}
-	if !parent.readable {
+	if parent.readErr != nil {
 		return nil, &os.PathError{
 			Op:   "stat",
 			Path: path,
-			Err:  os.ErrPermission,
+			Err:  parent.readErr,
 		}
 	}
 	childDir, dirExists := parent.subdirs[leaf]
@@ -781,11 +779,11 @@ func (m *MockFs) Remove(path string) (err error) {
 			Err:  os.ErrNotExist,
 		}
 	}
-	if !parentDir.readable {
+	if parentDir.readErr != nil {
 		return &os.PathError{
 			Op:   "remove",
 			Path: path,
-			Err:  os.ErrPermission,
+			Err:  parentDir.readErr,
 		}
 	}
 	_, isDir := parentDir.subdirs[leaf]
@@ -822,11 +820,11 @@ func (m *MockFs) Symlink(oldPath string, newPath string) (err error) {
 
 	newParentPath, leaf := pathSplit(newPath)
 	newParentDir, err := m.getDir(newParentPath, false)
-	if !newParentDir.readable {
+	if newParentDir.readErr != nil {
 		return &os.PathError{
 			Op:   "link",
 			Path: newPath,
-			Err:  os.ErrPermission,
+			Err:  newParentDir.readErr,
 		}
 	}
 	if err != nil {
@@ -856,11 +854,11 @@ func (m *MockFs) RemoveAll(path string) (err error) {
 			Err:  os.ErrNotExist,
 		}
 	}
-	if !parentDir.readable {
+	if parentDir.readErr != nil {
 		return &os.PathError{
 			Op:   "removeAll",
 			Path: path,
-			Err:  os.ErrPermission,
+			Err:  parentDir.readErr,
 		}
 
 	}
@@ -886,6 +884,14 @@ func (m *MockFs) RemoveAll(path string) (err error) {
 }
 
 func (m *MockFs) SetReadable(path string, readable bool) error {
+	var readErr error
+	if !readable {
+		readErr = os.ErrPermission
+	}
+	return m.SetReadErr(path, readErr)
+}
+
+func (m *MockFs) SetReadErr(path string, readErr error) error {
 	path, err := m.resolve(path, false)
 	if err != nil {
 		return err
@@ -895,11 +901,11 @@ func (m *MockFs) SetReadable(path string, readable bool) error {
 	if err != nil {
 		return err
 	}
-	if !parentDir.readable {
+	if parentDir.readErr != nil {
 		return &os.PathError{
 			Op:   "chmod",
 			Path: parentPath,
-			Err:  os.ErrPermission,
+			Err:  parentDir.readErr,
 		}
 	}
 
@@ -907,7 +913,7 @@ func (m *MockFs) SetReadable(path string, readable bool) error {
 	if err != nil {
 		return err
 	}
-	inode.readable = readable
+	inode.readErr = readErr
 	inode.permTime = m.Clock.Time()
 	return nil
 }