Repository: syncthing/syncthing (language: go)

Issue:
Filesystem watching (kqueue) is enabled … with a lot of files
Running: v1.25.0, FreeBSD (64-bit Intel/AMD)
Browser: Chrome 119.0.6045.33 (Official Build) beta (64-bit)

I see the "usual" warning, but on folders with very little files:

> 2023-10-25 09:23:57: Filesystem watching (kqueue) is enabled on "Default Folder" (default) with a lot of files/directories, and that requires a lot of resources and might slow down your system significantly
> 2023-10-25 09:23:57: Filesystem watching (kqueue) is enabled on "Documenti privati" (lapo-documenti) with a lot of files/directories, and that requires a lot of resources and might slow down your system significantly

<img width="409" alt="image" src="https://github.com/syncthing/syncthing/assets/420454/eced8d8a-a930-405b-a4f1-28df1336b2bf">
<img width="408" alt="image" src="https://github.com/syncthing/syncthing/assets/420454/60236178-ef5d-4e62-9094-271728de51cc">

(this is a similar bug to https://github.com/syncthing/syncthing/issues/7855#issuecomment-1153094832)

I'm running on `-verbose` but I see nothing strange… what shouldI look for? How else can I help debug?


Discussion / hints:
If you're running with `-verbose` you should get an occasional line with `Summary for folder ...` (at least, when something has changed in the folder and you have the GUI up). That line contains the numbers that are the basis for triggering the warning in question, so would be interesting to see.

```
[I6KAH] 2023/10/25 11:03:02 VERBOSE: Summary for folder "default" is &{Errors:0 PullErrors:0 Invalid: GlobalFiles:8078 GlobalDirectories:9538 GlobalSymlinks:0 GlobalDeleted:0 GlobalBytes:8443669097 GlobalTotalItems:17616 LocalFiles:8078 LocalDirectories:9538 LocalSymlinks:0 LocalDeleted:0 LocalBytes:8443669097 LocalTotalItems:17616 NeedFiles:0 NeedDirectories:0 NeedSymlinks:0 NeedDeletes:0 NeedBytes:0 NeedTotalItems:0 ReceiveOnlyChangedFiles:0 ReceiveOnlyChangedDirectories:0 ReceiveOnlyChangedSymlinks:0 ReceiveOnlyChangedDeletes:0 ReceiveOnlyChangedBytes:0 ReceiveOnlyTotalItems:0 InSyncFiles:8078 InSyncBytes:8443669097 State:scanning 11:02:42 +0200 CEST Error: Version:17616 Sequence:17616 WatchError:}
```

Those two shares gave the following summary:
```
Summary for folder "default" is &{Errors:0 PullErrors:0 Invalid: GlobalFiles:3 GlobalDirectories:0 GlobalSymlinks:0 GlobalDeleted:0 GlobalBytes:21 GlobalTotalItems:3 LocalFiles:3 LocalDirectories:0 LocalSymlinks:0 LocalDeleted:0 LocalBytes:21 LocalTotalItems:3 NeedFiles:0 NeedDirectories:0 NeedSymlinks:0 NeedDeletes:0 NeedBytes:0 NeedTotalItems:0 ReceiveOnlyChangedFiles:0 ReceiveOnlyChangedDirectories:0 ReceiveOnlyChangedSymlinks:0 ReceiveOnlyChangedDeletes:0 ReceiveOnlyChangedBytes:0 ReceiveOnlyTotalItems:0 InSyncFiles:3 InSyncBytes:21 State:idle 15:43:19 +0100 CET Error: Version:10 Sequence:10 WatchError:}
Summary for folder "lapo-documenti" is &{Errors:0 PullErrors:0 Invalid: GlobalFiles:54 GlobalDirectories:8 GlobalSymlinks:0 GlobalDeleted:1 GlobalBytes:27881826 GlobalTotalItems:63 LocalFiles:54 LocalDirectories:8 LocalSymlinks:0 LocalDeleted:1 LocalBytes:27881826 LocalTotalItems:63 NeedFiles:0 NeedDirectories:0 NeedSymlinks:0 NeedDeletes:0 NeedBytes:0 NeedTotalItems:0 ReceiveOnlyChangedFiles:0 ReceiveOnlyChangedDirectories:0 ReceiveOnlyChangedSymlinks:0 ReceiveOnlyChangedDeletes:0 ReceiveOnlyChangedBytes:0 ReceiveOnlyTotalItems:0 InSyncFiles:54 InSyncBytes:27881826 State:idle 15:43:19 +0100 CET Error: Version:75 Sequence:75 WatchError:}
```
Fascinating. I have no idea how that could trigger the warning. I mean, the code is here:

https://github.com/syncthing/syncthing/blob/935a28c9612b4134d49e13a57e15aaa432f031a3/lib/model/folder.go#L1068-L1073

The values are in your log lines; it's nowhere near

https://github.com/syncthing/syncthing/blob/935a28c9612b4134d49e13a57e15aaa432f031a3/lib/model/folder.go#L36-L37
Thanks for the pointer… I know no Go myself, but I should be able to add some "more verbose" debug to it.
```go
l.Warnf("XXX Filesystem watching, LocalTotalItems=%v LocalDeleted=%v kqueueItemCountThreshold=%v", data.Summary.LocalTotalItems, data.Summary.LocalDeleted, kqueueItemCountThreshold)
```
gives this:
```log
2023/12/12 16:59:00 WARNING: XXX Filesystem watching, LocalTotalItems=16406 LocalDeleted=24 kqueueItemCountThreshold=10000
2023/12/12 16:59:00 WARNING: XXX Filesystem watching, LocalTotalItems=16406 LocalDeleted=24 kqueueItemCountThreshold=10000
```
… so I guess that's a global total, not a folder-specific total.
(yes, I have some 10k files, in other folders with kqueue already disabled)
Interesting. I tried to reproduce it, successfully. Here it seems to be caused by the un-watched folder's periodic scan handling a change (a folder with >10k files). As soon as that happens, a summary containing >10k local files is tossed and the óther folder (only a handful files, with the watcher enabled) triggers the error.

Seems like we don't verify if the summary actually belongs to the folder we watch it for and/or that the folder it's about actually has the watcher enabled?

Fix patch:
diff --git a/lib/model/folder.go b/lib/model/folder.go
index e69025d7420..108861f16a7 100644
--- a/lib/model/folder.go
+++ b/lib/model/folder.go
@@ -1065,7 +1065,7 @@ func (f *folder) monitorWatch(ctx context.Context) {
 		case ev := <-summaryChan:
 			if data, ok := ev.Data.(FolderSummaryEventData); !ok {
 				f.evLogger.Log(events.Failure, "Unexpected type of folder-summary event in folder.monitorWatch")
-			} else if data.Summary.LocalTotalItems-data.Summary.LocalDeleted > kqueueItemCountThreshold {
+			} else if data.Folder == f.folderID && data.Summary.LocalTotalItems-data.Summary.LocalDeleted > kqueueItemCountThreshold {
 				f.warnedKqueue = true
 				summarySub.Unsubscribe()
 				summaryChan = nil


Test patch: