lib/scanner: More sensible debug output (#8596)

Previous debug input didn't really give enough info to show what was
happening, while it also printed full block lists which are enormously
verbose. Now it consistently prints 1. what it sees on disk, 2. what it
got from CurrentFile (without blocks), 3. the action taken on that file.

3 files changed, 14 insertions, 7 deletions

diff --git a/lib/protocol/bep_extensions.go b/lib/protocol/bep_extensions.go
index 5a835e976f..d2a0cad35c 100644
--- a/lib/protocol/bep_extensions.go
+++ b/lib/protocol/bep_extensions.go
@@ -58,8 +58,8 @@ func (f FileInfo) String() string {
 		return fmt.Sprintf("Directory{Name:%q, Sequence:%d, Permissions:0%o, ModTime:%v, Version:%v, VersionHash:%x, Deleted:%v, Invalid:%v, LocalFlags:0x%x, NoPermissions:%v, Platform:%v, InodeChangeTime:%v}",
 			f.Name, f.Sequence, f.Permissions, f.ModTime(), f.Version, f.VersionHash, f.Deleted, f.RawInvalid, f.LocalFlags, f.NoPermissions, f.Platform, f.InodeChangeTime())
 	case FileInfoTypeFile:
-		return fmt.Sprintf("File{Name:%q, Sequence:%d, Permissions:0%o, ModTime:%v, Version:%v, VersionHash:%x, Length:%d, Deleted:%v, Invalid:%v, LocalFlags:0x%x, NoPermissions:%v, BlockSize:%d, Blocks:%v, BlocksHash:%x, Platform:%v, InodeChangeTime:%v}",
-			f.Name, f.Sequence, f.Permissions, f.ModTime(), f.Version, f.VersionHash, f.Size, f.Deleted, f.RawInvalid, f.LocalFlags, f.NoPermissions, f.RawBlockSize, f.Blocks, f.BlocksHash, f.Platform, f.InodeChangeTime())
+		return fmt.Sprintf("File{Name:%q, Sequence:%d, Permissions:0%o, ModTime:%v, Version:%v, VersionHash:%x, Length:%d, Deleted:%v, Invalid:%v, LocalFlags:0x%x, NoPermissions:%v, BlockSize:%d, NumBlocks:%d, BlocksHash:%x, Platform:%v, InodeChangeTime:%v}",
+			f.Name, f.Sequence, f.Permissions, f.ModTime(), f.Version, f.VersionHash, f.Size, f.Deleted, f.RawInvalid, f.LocalFlags, f.NoPermissions, f.RawBlockSize, len(f.Blocks), f.BlocksHash, f.Platform, f.InodeChangeTime())
 	case FileInfoTypeSymlink, FileInfoTypeSymlinkDirectory, FileInfoTypeSymlinkFile:
 		return fmt.Sprintf("Symlink{Name:%q, Type:%v, Sequence:%d, Version:%v, VersionHash:%x, Deleted:%v, Invalid:%v, LocalFlags:0x%x, NoPermissions:%v, SymlinkTarget:%q, Platform:%v, InodeChangeTime:%v}",
 			f.Name, f.Type, f.Sequence, f.Version, f.VersionHash, f.Deleted, f.RawInvalid, f.LocalFlags, f.NoPermissions, f.SymlinkTarget, f.Platform, f.InodeChangeTime())
diff --git a/lib/scanner/blockqueue.go b/lib/scanner/blockqueue.go
index 7eaa60307d..4e45176287 100644
--- a/lib/scanner/blockqueue.go
+++ b/lib/scanner/blockqueue.go
@@ -98,6 +98,8 @@ func (ph *parallelHasher) hashFiles(ctx context.Context) {
 				return
 			}
 
+			l.Debugln("started hashing:", f)
+
 			if f.IsDirectory() || f.IsDeleted() {
 				panic("Bug. Asked to hash a directory or a deleted file.")
 			}
@@ -120,6 +122,7 @@ func (ph *parallelHasher) hashFiles(ctx context.Context) {
 				f.Size += int64(b.Size)
 			}
 
+			l.Debugln("completed hashing:", f)
 			select {
 			case ph.outbox <- ScanResult{File: f}:
 			case <-ctx.Done():
diff --git a/lib/scanner/walk.go b/lib/scanner/walk.go
index 7a782a21a9..b155925cad 100644
--- a/lib/scanner/walk.go
+++ b/lib/scanner/walk.go
@@ -399,6 +399,7 @@ func (w *walker) walkRegular(ctx context.Context, relPath string, info fs.FileIn
 	f = w.updateFileInfo(f, curFile)
 	f.NoPermissions = w.IgnorePerms
 	f.RawBlockSize = blockSize
+	l.Debugln(w, "checking:", f)
 
 	if hasCurFile {
 		if curFile.IsEquivalentOptional(f, protocol.FileInfoComparison{
@@ -409,7 +410,7 @@ func (w *walker) walkRegular(ctx context.Context, relPath string, info fs.FileIn
 			IgnoreOwnership: !w.ScanOwnership,
 			IgnoreXattrs:    !w.ScanXattrs,
 		}) {
-			l.Debugln(w, "unchanged:", curFile, info.ModTime().Unix(), info.Mode()&fs.ModePerm)
+			l.Debugln(w, "unchanged:", curFile)
 			return nil
 		}
 		if curFile.ShouldConflict() {
@@ -420,7 +421,7 @@ func (w *walker) walkRegular(ctx context.Context, relPath string, info fs.FileIn
 			// conflict.
 			f.Version = f.Version.DropOthers(w.ShortID)
 		}
-		l.Debugln(w, "rescan:", curFile, info.ModTime().Unix(), info.Mode()&fs.ModePerm)
+		l.Debugln(w, "rescan:", curFile)
 	}
 
 	l.Debugln(w, "to hash:", relPath, f)
@@ -443,6 +444,7 @@ func (w *walker) walkDir(ctx context.Context, relPath string, info fs.FileInfo,
 	}
 	f = w.updateFileInfo(f, curFile)
 	f.NoPermissions = w.IgnorePerms
+	l.Debugln(w, "checking:", f)
 
 	if hasCurFile {
 		if curFile.IsEquivalentOptional(f, protocol.FileInfoComparison{
@@ -453,7 +455,7 @@ func (w *walker) walkDir(ctx context.Context, relPath string, info fs.FileInfo,
 			IgnoreOwnership: !w.ScanOwnership,
 			IgnoreXattrs:    !w.ScanXattrs,
 		}) {
-			l.Debugln(w, "unchanged:", curFile, info.ModTime().Unix(), info.Mode()&fs.ModePerm)
+			l.Debugln(w, "unchanged:", curFile)
 			return nil
 		}
 		if curFile.ShouldConflict() {
@@ -464,6 +466,7 @@ func (w *walker) walkDir(ctx context.Context, relPath string, info fs.FileInfo,
 			// conflict.
 			f.Version = f.Version.DropOthers(w.ShortID)
 		}
+		l.Debugln(w, "rescan:", curFile)
 	}
 
 	l.Debugln(w, "dir:", relPath, f)
@@ -493,8 +496,8 @@ func (w *walker) walkSymlink(ctx context.Context, relPath string, info fs.FileIn
 	}
 
 	curFile, hasCurFile := w.CurrentFiler.CurrentFile(relPath)
-
 	f = w.updateFileInfo(f, curFile)
+	l.Debugln(w, "checking:", f)
 
 	if hasCurFile {
 		if curFile.IsEquivalentOptional(f, protocol.FileInfoComparison{
@@ -516,9 +519,10 @@ func (w *walker) walkSymlink(ctx context.Context, relPath string, info fs.FileIn
 			// conflict.
 			f.Version = f.Version.DropOthers(w.ShortID)
 		}
+		l.Debugln(w, "rescan:", curFile)
 	}
 
-	l.Debugln(w, "symlink changedb:", relPath, f)
+	l.Debugln(w, "symlink:", relPath, f)
 
 	select {
 	case finishedChan <- ScanResult{File: f}: