Add a few more debug prints

internal/model/model.go

@@ -439,6 +439,9 @@ func (m *Model) Index(deviceID protocol.DeviceID, folder string, fs []protocol.F
 	for i := 0; i < len(fs); {
 		lamport.Default.Tick(fs[i].Version)
 		if ignores != nil && ignores.Match(fs[i].Name) {
+			if debug{
+				l.Debugln("dropping update for ignored",fs[i])
+			}
 			fs[i] = fs[len(fs)-1]
 			fs = fs[:len(fs)-1]
 		} else {
@@ -480,6 +483,7 @@ func (m *Model) IndexUpdate(deviceID protocol.DeviceID, folder string, fs []prot
 	for i := 0; i < len(fs); {
 		lamport.Default.Tick(fs[i].Version)
 		if ignores != nil && ignores.Match(fs[i].Name) {
+				l.Debugln("dropping update for ignored",fs[i])
 			fs[i] = fs[len(fs)-1]
 			fs = fs[:len(fs)-1]
 		} else {
@@ -878,6 +882,7 @@ func sendIndexTo(initial bool, minLocalVer uint64, conn protocol.Connection, fol
 		}
 
 		if ignores != nil && ignores.Match(f.Name) {
+				l.Debugln("not sending update for ignored",f)
 			return true
 		}
 
@@ -1079,6 +1084,7 @@ func (m *Model) ScanFolderSub(folder, sub string) error {
 
 			if ignores != nil && ignores.Match(f.Name) {
 				// File has been ignored. Set invalid bit.
+				l.Debugln("setting invalid bit on ignored",f)
 				nf := protocol.FileInfo{
 					Name:     f.Name,
 					Flags:    f.Flags | protocol.FlagInvalid,

internal/model/puller.go

@@ -163,6 +163,9 @@ loop:
 						curVer = lv
 					}
 					prevVer = curVer
+					if debug {
+						l.Debugln(p, "next pull in", nextPullIntv)
+					}
 					pullTimer.Reset(nextPullIntv)
 					break
 				}
@@ -173,6 +176,9 @@ loop:
 					// errors preventing us. Flag this with a warning and
 					// wait a bit longer before retrying.
 					l.Warnf("Folder %q isn't making progress - check logs for possible root cause. Pausing puller for %v.", p.folder, pauseIntv)
+					if debug {
+						l.Debugln(p, "next pull in", pauseIntv)
+					}
 					pullTimer.Reset(pauseIntv)
 					break
 				}
@@ -193,12 +199,16 @@ loop:
 			}
 			p.model.setState(p.folder, FolderIdle)
 			if p.scanIntv > 0 {
+				if debug {
+					l.Debugln(p, "next rescan in", p.scanIntv)
+				}
 				scanTimer.Reset(p.scanIntv)
 			}
 			if !initialScanCompleted {
 				l.Infoln("Completed initial scan (rw) of folder", p.folder)
 				initialScanCompleted = true
 			}
+
 		// Clean out old temporaries
 		case <-cleanTimer.C:
 			p.clean()

internal/scanner/walk.go

@@ -152,7 +152,7 @@ func (w *Walker) walkAndHashFiles(fchan chan protocol.FileInfo) filepath.WalkFun
 				Modified: info.ModTime().Unix(),
 			}
 			if debug {
-				l.Debugln("dir:", f)
+				l.Debugln("dir:", p, f)
 			}
 			fchan <- f
 			return nil
@@ -176,12 +176,16 @@ func (w *Walker) walkAndHashFiles(fchan chan protocol.FileInfo) filepath.WalkFun
 				flags = protocol.FlagNoPermBits | 0666
 			}
 
-			fchan <- protocol.FileInfo{
+			f := protocol.FileInfo{
 				Name:     rn,
 				Version:  lamport.Default.Tick(0),
 				Flags:    flags,
 				Modified: info.ModTime().Unix(),
 			}
+			if debug {
+				l.Debugln("to hash:", p, f)
+			}
+			fchan <- f
 		}
 
 		return nil