FreeBSD: Create new file does not generate a fs event.

[jsm222]

Syncthing Version: v0.14.52-rc.3, FreeBSD (64 bit)
OS Version: 11.2-RELEASE-p4
Reproduce:
export STTRACE=watchaggregator
syncthing
touch ~/Sync/newfile

Expected:
an file create event triggered and the file is synced
Actual:
aggregator.go:305: DEBUG: aggregator/"Default Folder" (default): No tracked events, waiting for new event And the new file is not synced

It is related to #9 and https://forum.syncthing.net/t/directory-watcher-on-freebsd-issue/11561 (Both closed).

[tokred]

I can confirm the issue and have an addition: File/dir creations do not get detected, but deletions do.

Test environment:

• Syncthing is running as syncthing user with the command
  STTRACE="scanner,fs,events,walkfs,watchaggregator" syncthing -home="/usr/local/etc/syncthing/"
• Files and directories are created on the FreeBSD box:

$ cd /tank/syncthing/default  # configured default folder
$ touch testfile
$ mkdir testdir
$ touch testdir/testfile2

• Debug log shows no events (neither after several minutes), besides DEBUG: poll 1m0s
• rm testfile, debug log shows (note the 'no such file or directory')

[M3P65] 2019/02/17 21:02:20.755604 basicfs_watch.go:91: DEBUG: basic /tank/syncthing/default Watch: Sending testfile remove
[M3P65] 2019/02/17 21:02:20.755778 aggregator.go:280: DEBUG: aggregator/"Default Folder" (default): Tracking (type remove): testfile
[M3P65] 2019/02/17 21:02:20.755848 aggregator.go:299: DEBUG: aggregator/"Default Folder" (default): Resetting notifyTimer to 10s

[M3P65] 2019/02/17 21:02:30.782853 aggregator.go:331: DEBUG: aggregator/"Default Folder" (default): Notifying about 1 fs events
[M3P65] 2019/02/17 21:02:30.782893 aggregator.go:299: DEBUG: aggregator/"Default Folder" (default): Resetting notifyTimer to 10s
[M3P65] 2019/02/17 21:02:30.783025 logfs.go:115: DEBUG: folderconfiguration.go:151 basic /tank/syncthing/default Stat . {0xc0005fa0b0} <nil>
[M3P65] 2019/02/17 21:02:30.783080 logfs.go:115: DEBUG: folderconfiguration.go:169 basic /tank/syncthing/default Stat .stfolder {0xc0005fa160} <nil>
[M3P65] 2019/02/17 21:02:30.783112 logfs.go:163: DEBUG: wrapper.go:504 basic /usr/local/etc/syncthing Usage . {3865804800 6977892352} <nil>
[M3P65] 2019/02/17 21:02:30.783158 logfs.go:115: DEBUG: ignore.go:544 basic /tank/syncthing/default Stat .stignore {0xc0005fa210} <nil>
[M3P65] 2019/02/17 21:02:30.783678 walk.go:101: DEBUG: Walk [testfile] Matcher/[]@0xc0001e8240
[M3P65] 2019/02/17 21:02:30.783772 events.go:297: DEBUG: log 11 StateChanged map[folder:default to:scan-waiting from:idle duration:483.876703152]
[M3P65] 2019/02/17 21:02:30.783826 events.go:297: DEBUG: log 12 StateChanged map[folder:default to:scanning from:scan-waiting duration:3.6459e-05]
[M3P65] 2019/02/17 21:02:30.783936 logfs.go:61: DEBUG: walkfs.go:89 basic /tank/syncthing/default Lstat testfile <nil> lstat /tank/syncthing/default/testfile: no such file or directory
[M3P65] 2019/02/17 21:02:30.783949 walk.go:539: INFO: Scanner (folder default, file "testfile"): scan: lstat /tank/syncthing/default/testfile: no such file or directory
[M3P65] 2019/02/17 21:02:30.784191 walk.go:164: DEBUG: Walk progress done default [testfile] Matcher/[]@0xc0001e8240
[M3P65] 2019/02/17 21:02:30.784265 events.go:297: DEBUG: log 13 StateChanged map[folder:default to:idle from:scanning duration:0.000974606]

[M3P65] 2019/02/17 21:02:40.851540 aggregator.go:307: DEBUG: aggregator/"Default Folder" (default): No tracked events, waiting for new event.

I would be happy to help tracking this down! Unfortunately, this considerably reduces the usefulness of Syncthing on FreeBSD. Lowering the rescan time is no ideal solution.

Syncthing Version: v1.0.0, FreeBSD (64 bit), with ZFS pool
OS Version: 11.2-RELEASE-p9

[AudriusButkevicius]

We've already established that kqueue implementation is broken on non-OSX, sadly we just use a library.

We know that mkdir + touch in the same dir in quick succession does not get noticed, which is reported as:
rjeczalik/notify#172

See if using https://godoc.org/github.com/rjeczalik/cmd/notify shows any events.

If you want it fixed, it's probably best if you do the legwork yourself.

[ariselseng]

@AudriusButkevicius @tokred I just tried with https://godoc.org/github.com/rjeczalik/cmd/notify and it works with that command so it is probably something that could be downstreamed to the vendored notify.

[AudriusButkevicius]

Does our fork of inotify not report it?

[ariselseng]

In Syncthing both 1.1.4 and 1.2.1rc3 only deletes are detected as first mentioned by @tokred.
Not sure how I would test the fork with github.com/rjeczalik/cmd/notify
Do I just change out the import statement in the main.go and rebuild?

[ariselseng]

Update: I just checked version v1.0.1 and v0.14.48 now too. With the same problem.

[ariselseng]

@AudriusButkevicius I changed out ""github.com/rjeczalik/notify" with "github.com/syncthing/notify" in https://github.com/rjeczalik/cmd/blob/master/notify/main.go and ran go get "github.com/syncthing/notify" and built it with gox -osarch "freebsd/amd64"

It still worked and reported changes done to my test folder.

[imsodin]

The problem might related to this comment (https://github.com/rjeczalik/notify/blob/master/watcher_kqueue.go#L157):

		// Create event is not supported by kqueue. Instead NoteWrite event will
		// be registered for a directory. If this event will be reported on dir
		// which is to be monitored for Create, dir will be rescanned
		// and Create events will be generated and returned for new files.
		// In case of files, if not requested NoteRename event is reported,
		// it will be ignored.

We use platform specific events, not the cross-platform notify.Create which is created "synthetically" according to this comment. I'll investigate whether it's fine to mix both.

Can you confirm that file changes (as opposed to creations) do get picked up?

[AudriusButkevicius]

I feep someone from the bsd community needs to step up their game, add a bunch of debug prints, understand the issue and open a pr fixing it.

We can't fix issues on platforms we don't use.

[ariselseng]

@imsodin You are correct. touch testfile.txt does not work, but echo 123 >> already_scanned_file.txt does. Renaming already_scanned_file.txt to something else deletes (!) it from the other machine.

[ariselseng]

@imsodin @AudriusButkevicius
#5885 fixes this issue.