search

syncthing / syncthing

Open Source Continuous File Synchronization
https://syncthing.net/
Mozilla Public License 2.0
65.51k stars 4.31k forks source link

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

Closed jsm222 closed 5 years ago

jsm222 commented 6 years ago

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 https://github.com/syncthing/syncthing/issues/9 and https://forum.syncthing.net/t/directory-watcher-on-freebsd-issue/11561 (Both closed).

tokred commented 5 years ago

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

Test environment:

[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} [M3P65] 2019/02/17 21:02:30.783080 logfs.go:115: DEBUG: folderconfiguration.go:169 basic /tank/syncthing/default Stat .stfolder {0xc0005fa160} [M3P65] 2019/02/17 21:02:30.783112 logfs.go:163: DEBUG: wrapper.go:504 basic /usr/local/etc/syncthing Usage . {3865804800 6977892352} [M3P65] 2019/02/17 21:02:30.783158 logfs.go:115: DEBUG: ignore.go:544 basic /tank/syncthing/default Stat .stignore {0xc0005fa210} [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 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 commented 5 years ago

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: https://github.com/rjeczalik/notify/issues/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 commented 5 years ago

@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 commented 5 years ago

Does our fork of inotify not report it?

ariselseng commented 5 years ago

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 commented 5 years ago

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

ariselseng commented 5 years ago

@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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

@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 commented 5 years ago

@imsodin @AudriusButkevicius https://github.com/syncthing/syncthing/pull/5885 fixes this issue.