notify-rs / notify

🔭 Cross-platform filesystem notification library for Rust.
https://docs.rs/notify
2.67k stars 213 forks source link

FS operations performed by blender yield confusing order of events from the debouncer #587

Open Sorseg opened 4 months ago

Sorseg commented 4 months ago

System details

notify-debouncer-full v0.3.1
    ├── crossbeam-channel v0.5.12
    │   └── crossbeam-utils v0.8.19
    ├── file-id v0.2.1
    ├── log v0.4.21
    ├── notify v6.1.1
    │   ├── crossbeam-channel v0.5.12 (*)
    │   ├── filetime v0.2.23
    │   │   ├── cfg-if v1.0.0
    │   │   └── libc v0.2.153
    │   ├── inotify v0.9.6
    │   │   ├── bitflags v1.3.2
    │   │   ├── inotify-sys v0.1.5
    │   │   │   └── libc v0.2.153
    │   │   └── libc v0.2.153
    │   ├── libc v0.2.153
    │   ├── log v0.4.21
    │   ├── mio v0.8.11
    │   │   ├── libc v0.2.153
    │   │   └── log v0.4.21
    │   └── walkdir v2.5.0
    │       └── same-file v1.0.6
    ├── parking_lot v0.12.1
    │   ├── lock_api v0.4.11
    │   │   └── scopeguard v1.2.0
    │   │   [build-dependencies]
    │   │   └── autocfg v1.2.0
    │   └── parking_lot_core v0.9.9
    │       ├── cfg-if v1.0.0
    │       ├── libc v0.2.153
    │       └── smallvec v1.13.2
    └── walkdir v2.5.0 (*)

What you did (as detailed as you can)

Run the example code, then open an existing file test.blend in blender and overwrite it with a new version.

What I ran ```rust use std::path::Path; use std::time::Duration; use notify_debouncer_full::{DebounceEventResult, new_debouncer}; use notify_debouncer_full::notify::{RecursiveMode, Watcher}; fn main() { println!("Hello, world!"); // Select recommended watcher for debouncer. // Using a callback here, could also be a channel. let mut debouncer = new_debouncer(Duration::from_secs(2), None, |result: DebounceEventResult| { match result { Ok(events) => events.iter().for_each(|event| println!("{event:?}")), Err(errors) => errors.iter().for_each(|error| println!("{error:?}")), } }).unwrap(); // Add a path to be watched. All files and directories at that path and // below will be monitored for changes. debouncer.watcher().watch(Path::new("."), RecursiveMode::Recursive).unwrap(); // Add the same path to the file ID cache. The cache uses unique file IDs // provided by the file system and is used to stich together rename events // in case the notification back-end doesn't emit rename cookies. debouncer.cache().add_root(Path::new("."), RecursiveMode::Recursive); std::thread::sleep(Duration::from_secs(100000000)); } ```

What you expected

I expected to read a series of events that would indicate that the test.blend now contains the new data, as this is what bevy relies upon to reload the assets.

What happened

strace of blender saving a file ``` 20:45:43.021143 openat(AT_FDCWD, "<...>/test.blend@", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 28 20:45:43.023758 unlink("<...>/test.blend1") = 0 20:45:43.024196 rename("<...>/test.blend", "<...>/test.blend1") = 0 20:45:43.024412 rename("<...>/test.blend@", "<...>/test.blend") = 0 ```
Result ``` DebouncedEvent { event: Event { kind: Create(File), paths: ["<...>/./test.blend"], attr:tracker: None, attr:flag: None, attr:info: None, attr:source: None }, time: Instant { tv_sec: 28469, tv_nsec: 182994437 } } DebouncedEvent { event: Event { kind: Access(Close(Write)), paths: ["<...>/./test.blend"], attr:tracker: None, attr:flag: None, attr:info: None, attr:source: None }, time: Instant { tv_sec: 28469, tv_nsec: 185258534 } } DebouncedEvent { event: Event { kind: Remove(Any), paths: ["<...>/./test.blend1"], attr:tracker: None, attr:flag: None, attr:info: None, attr:source: None }, time: Instant { tv_sec: 28469, tv_nsec: 185991873 } } DebouncedEvent { event: Event { kind: Modify(Name(Both)), paths: ["<...>/./test.blend", "<...>/./test.blend1"], attr:tracker: Some(10280), attr:flag: None, attr:info: None, attr:source: None }, time: Instant { tv_sec: 28469, tv_nsec: 185991873 } } ```

The resulting list of events confuses bevy into thinking there is only the .blend1 file, as the last event returned is the rename. Which is not what actually happens to the filesystem.

Thank you for maintaining this :heart: !

0xpr03 commented 4 months ago

Maybe @dfaust has a faster answer what the debouncer logic does here. Would have to dig around first how we flatten this joyride of renames to have backups, especially with the timing here.

create test.blend@ (new content)
delete test.blend1 (delete backup)
rename test.blend -> test.blend1 (move current to backup)
rename test.blend@ -> test.blend (move new to current)

Hard to say what you would even want to get reported here. Delete test.blend1, Rename test.blend -> test.blend1, Modify test.blend in that succession would probably be the closest to the truth. Even though modify test.blend, test.blend1 would be true too - in the spirit of what blender really does at the end for the asset recompilation.

dfaust commented 4 months ago

I'll have a look at it. My first thought is that the reported events should be:

(maybe) delete test.blend1
rename test.blend -> test.blend1
create test.blend
dfaust commented 4 months ago

Looks like the problem here is the order in which the events are emitted. The create event happens at first, but must be emitted after the rename event.

@Sorseg can you please try #590 and tell me if it fixes your problem?

Sorseg commented 4 months ago

Thank you! I'll be able to test it next week

Sorseg commented 4 months ago

Unfortunately it does not seem to help. Here's the output with the patched version (save happened around 08:28:27) https://gist.github.com/Sorseg/47563fa04552fe11a9f2dd31aef26b6a I cannot say if this is an issue on bevy or notify side. I am also worried about the lack of these log lines. I wonder if it has something to do with it being run in a different thread.

My repro repo