Deno.watchFs looses events

[Nemo64]

I wrote this little test script:

import {ensureDir} from "https://deno.land/std@0.100.0/fs/ensure_dir.ts"; // importing fs/mod.ts requires --unstable

const FOLDER = 'test';
await ensureDir(FOLDER);

queueMicrotask(async () => {
    let count = 0;
    for await (const event of Deno.watchFs(FOLDER)) {
        console.log(`event`, ++count, event);
    }
});

queueMicrotask(async () => {
    await Promise.all([...Array(100)].map((_, index) => {
        return Deno.writeTextFile(`${FOLDER}/file${index}`, `content of file${index}`);
    }));
    console.log('written all files');
});

It creates a test directory and watches it for changes. Then, it creates 100 files in it.

What I would expect is 100 or 200 events (100 create and 100 modify). What I instead get is this:

event 1 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file0" ] }
event 2 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file1" ] }
event 3 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file2" ] }
written all files
event 4 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file3" ] }
event 5 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file4" ] }
event 6 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file5" ] }
event 7 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file6" ] }
event 8 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file7" ] }
event 9 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file8" ] }
event 10 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file9" ] }
event 11 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file10" ] }
event 12 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file11" ] }
event 13 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file12" ] }
event 14 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file13" ] }
event 15 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file14" ] }
event 16 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file15" ] }
event 17 { kind: "create", paths: [ "/Volumes/Workspace/replicator-db/test/file87" ] }
event 18 { kind: "modify", paths: [ "/Volumes/Workspace/replicator-db/test/file1" ] }
event 19 { kind: "access", paths: [ "/Volumes/Workspace/replicator-db/test/file89" ] }

Just 19 events.

To verify that this is not an os issue, I ran the test with inotifywatch test which outputs this result:

total  access  modify  close_write  close_nowrite  open  create  filename
404    2       100     100          1              101   100     test/

So basically the expected number of events.

On macOs, I used fswatch -r test and then copied the result into pbpaste|wc -l which showed 100 events, so nothing was lost on the os level either.

I ran this test on

• Ubuntu 20.04.2 LTS Linux 5.4.0-72-generic #80-Ubuntu SMP Mon Apr 12 17:35:00 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
• MacOS Darwin [hostname] 20.5.0 Darwin Kernel Version 20.5.0: Sat May 8 05:10:33 PDT 2021; root:xnu-7195.121.3~9/RELEASE_X86_64 x86_64

EDIT: with the currently newest stable deno version

deno 1.11.5 (release, x86_64-apple-darwin)
v8 9.1.269.35
typescript 4.3.2

[jsejcksn]

I can reproduce this.

I also get more events if I don't use queueMicrotask:

```ts // deno run --allow-read=test --allow-write=test watch_fs.ts import {ensureDir} from 'https://deno.land/std@0.101.0/fs/ensure_dir.ts'; // importing fs/mod.ts requires --unstable const FOLDER = 'test'; await ensureDir(FOLDER); const watcher = Deno.watchFs(FOLDER); (async () => { let count = 0; for await (const event of watcher) { console.log(`event`, ++count, event.kind, event.paths); } })(); for (let index = 1; index <= 100; index += 1) { Deno.writeTextFile(`${FOLDER}/file${index}`, `content of file${index}`); } console.log('All files written'); // stop watching after 3s setTimeout(watcher.close.bind(watcher), 3000); ```

[Nemo64]

I assume it's an internal queue that is overflowing if you don't consume the events quickly enough. If you write files sequentially, it mostly gets all events.

for (let index = 1; index <= 100; index += 1) {
    await Deno.writeTextFile(`${FOLDER}/file${index}`, `content of file${index}`);
}

If you let the watcher run and use a shell script in the test folder find . -name "file*"-print0 |xargs -0 -I {} mv {} {}_ then deno also gets about 80% of events (it looks like 2 modify and 1 create, no remove though). If you speed it up with find . -name "file*" -print0 |xargs -P8 -0 -I {} mv {} {}_, you get fewer events (about 50%).

These numbers vary strongly based on what your machine is doing.

[andykais]

so interestingly somewhat related. I discovered that Deno.watchFs cannot properly track neovim writes. I believe this comes down to the way neovim uses swap files. What's interesting is that this is a problem with the os. E.g. this is what a small test script produces:

for await (const event of Deno.watchFs('./bin/moon_phase.sh') {
  console.log({event})
}

{
  event: [Object: null prototype] {
    kind: "modify",
    paths: [ "/home/andrew/bin/moon_phase.sh" ],
    flag: null
  }
}
{
  event: [Object: null prototype] {
    kind: "modify",
    paths: [ "/home/andrew/bin/moon_phase.sh" ],
    flag: null
  }
}
{
  event: [Object: null prototype] {
    kind: "remove",
    paths: [ "/home/andrew/bin/moon_phase.sh" ],
    flag: null
  }
}

and this is what inotifywait -m ./bin/moon_phase.sh outputs:

Setting up watches.
Watches established.
/home/andrew/bin/moon_phase.sh MOVE_SELF
/home/andrew/bin/moon_phase.sh ATTRIB
/home/andrew/bin/moon_phase.sh DELETE_SELF

in both cases I updated and saved the file multiple times but only the very first event was captured. I don't know if this belongs under its own issue, I imagine the only thing deno would do is add some magic on top of the os watcher to see if files need to be watched under a new inode or something. I wanted to start here though and see if someone tells me this is issue worthy. I probably could solve this myself by reinstantiating the Deno.watchFs every time I see a remove event