Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Wrong error message is printed when inotify event queue overflows #191

Closed
unphased opened this issue Nov 26, 2017 · 30 comments
Closed

Wrong error message is printed when inotify event queue overflows #191

unphased opened this issue Nov 26, 2017 · 30 comments
Assignees
Milestone

Comments

@unphased
Copy link

unphased commented Nov 26, 2017

update: Much of this issue is explained by realizing that FSEvents monitor works recursively even if you do not specify -r, whereas inotify monitor does not function this way. Sorry! The issue still stands. The behavior is extremely different, not only in the output but in the treatment of flags.

=======================

I have a workflow which uses fswatch which works very well on os x. Any time a file tracked in git changes I trigger some steps to run (build, show diff, etc) in the terminal.

This works great by piping fswatch output to drive some scripting when new lines of output are produced.

On OS X with FSEvents, fswatch produces a clean format and only one event for files that have been modified. Perfect.

On Linux with inotify_monitor (fswatch .) it produces a useless spew of directories and rarely contains a file that is opened for reading. I am using Vim, so I would expect the 4913 file to at least show up in here (as a sanity check) it never does! I'd be fine if what I got was MORE events and I have to simply filter out the file modified events, but even when I use the -x flag, I do not ever consistently get file modified events.

On Linux with poll_monitor, no output is ever produced!

So I'm clearly missing something here because this software is supposed to be a drop-in solution that produces the same outward facing interface on these two different platforms, but what I am seeing are completely different and irreconcilable behavior. So I think that I have some configuration problem. Is my kernel too old? Am I using an incompatible filesystem format? This is Centos 7 3.10.0-514.10.2.el7.x86_64

I can also report that on this system if I simply use inotifywait -rme modify . I get reliable output, although sometimes with multiple events when I save a file...

@malthe
Copy link

malthe commented Dec 11, 2017

I definitely also see different behavior on Linux and Mac OS.

fswatch --batch-marker -0 <path> | while read -d "" event; do
   ...
done;

On the Mac – this works reasonably well, while on Linux, this generates an endless event stream.

What gives?

@emcrisostomo
Copy link
Owner

Hi @unphased, could you please put an example invocation?

@emcrisostomo
Copy link
Owner

Hi @malthe, what kind of changes arrive on path? Could you please paste a fragment of the endless event stream? I'm interested at seeing which kind of events we're talking about.

@emcrisostomo
Copy link
Owner

Hi @unphased, just to clarify: fswatch is a common interface towards different file system change event APIs. Linux and macOS are very different and fswatch won't yield the same results. As a matter of fact, one of the examples you cite (a notification when a file is read will not work on macOS). To go further, I think you're conflating multiple things. You say:

On OS X with FSEvents, fswatch produces a clean format and only one event for files that have been modified. Perfect.

And then:

On Linux with inotify_monitor (fswatch .) it produces a useless spew of directories and rarely contains a file that is opened for reading.

If the problem is how chatty fswatch is on linux when compared to macOS, then it's true, when events are non-filtered. You should be able to filter events based on type and get the ones you're interested in.

@emcrisostomo
Copy link
Owner

@malthe,

I just tried to run fswatch on Debian 9 and I see no problems. As an example, I tried creating files, modifying them and then deleting them and I see no issues.

If you receive a lot of events at the beginning of the session, that's because the hierarchy is scanned recursively and that operation performs events as well. These events are of type IsDir and PlatformSpecific (I have to improve this mapping because it's too generic)

@unphased
Copy link
Author

unphased commented Dec 11, 2017

@emcrisostomo the behavior that i saw on Centos 7, and now Ubuntu 14.04, is that I get an unreasonably large stream of lines that just have a directory path. I will actually save a file in Vim and see NOTHING reported. Yes you are correct in that my language was not very specific, but the point is that the software does not function with any real utility, so what I would like to get to the bottom of is why it works for you but not for us.

I will provide you an example soon.

@unphased
Copy link
Author

unphased commented Dec 11, 2017

I think the difference may be accounted for by taking into account:

  • inotify for whatever reason provides way too many events. they can be filtered, this is okay.
  • FSevents monitor does not appear to require the recursive flag, which means that my tests on linux using the same interface to fswatch yield totally different behavior. this seems less okay, but also means that my issue was not described accurately at all. I've updated my original issue description, but the overall utility of fswatch is impacted by its inability to truly wrap the behavior of the monitors' implementation.

@emcrisostomo
Copy link
Owner

@unphased, as I already asked, you should please add a full example if you want to help us discover what's going on. Not only fswatch is working for me in the machines where I used: I just made a test, as stated above, and I could always see the change events (on Debian 9). I've just made another test on Debian and Alpine and I get the same results:

[invoking vim to create test.txt]
/root/temp/.test.txt.swp Created
/root/temp/.test.txt.swp PlatformSpecific
/root/temp/.test.txt.swx Created
/root/temp/.test.txt.swx PlatformSpecific
/root/temp/.test.txt.swx Updated
/root/temp/.test.txt.swx Removed
/root/temp/.test.txt.swp Updated
/root/temp/.test.txt.swp Removed
/root/temp/.test.txt.swp Created
/root/temp/.test.txt.swp PlatformSpecific
/root/temp/.test.txt.swp Updated
[writing something, saving the file and exiting]
/root/temp/.test.txt.swp Updated
/root/temp/.test.txt.swp Updated
/root/temp/.test.txt.swp Updated
/root/temp/test.txt Created
/root/temp/test.txt PlatformSpecific
/root/temp/test.txt Updated
/root/temp/test.txt Updated
/root/temp/.test.txt.swp Updated
/root/temp/.test.txt.swp Updated
/root/temp/.test.txt.swp Removed

What happens in your case, I still don't know. Make a test and dump the output for us to examine, specifying exactly how fswatch was invoked and all the details that may impact the result.

@emcrisostomo
Copy link
Owner

@unphased:

inotify for whatever reason provides way too many events. they can be filtered, this is okay.

fswatch makes no attempt at filtering any notifications. What inotify sends, we forward.

FSevents monitor does not appear to require the recursive flag, which means that my tests on linux using the same interface to fswatch yield totally different behavior. this seems less okay [...]

The fsevents_monitor is inherently recursive, as it is the API it uses (FSEvents). There is no promise about getting the same behaviour anywhere. On the contrary, if you read the manual you'll notice that I tried to describe the differences. To rephrase: getting the same results using the same command on different operating systems is not a feature offered by fswatch (such a feature couldn't possibly be offered, given the differences between the supported OSs). If the documentation states otherwise, please send me a pointer to it to promptly amend it.

but the overall utility of fswatch is impacted by its inability to truly wrap the behavior of the monitors' implementation.

That's exactly the opposite. fswatch just shows you what the underlying APIs are sending out. The monitors are very slim, by design. The only thing they do is asking the OS to provide whatever kind of events it can provide, and forward it. Hence, the difference.

@unphased
Copy link
Author

unphased commented Dec 11, 2017

Cool, yes I'd like to make it clear (it's hard) that I'm not complaining about how this software isnt doing what it promises to do, but I do believe that way in which the readme is written led me to believe that I can use the tool and expect the same output across the different monitors and this is not the case here, as you've explained.

It is only because I formed this expectation that it was particularly frustrating to find that it does not work that way.

At any rate, the output IS consistent in several regards: it provides what appears to be an absolute path to the file, and (if -x is used) followed by flags, the important ones of which are consistent, at least for simple needs.

Because the difference in monitor behaviors is a limitation in my mind, I feel that it should be called out in that limitations section, in addition to those other limitations already listed which are not immediately encountered. Or another section near the top that highlights this.

@valignatev
Copy link

Hi there, just jumped into the same issue. I have an Arch Linux and fswatch 1.12.0.
I did some tests, and it seems that fswatch ignores Created, Updated and Removed events.

It yields IsDir and PlatformSpecific though. Also, after initial scanning and reporting with a long stream of IsDir and PlatformSpecific it just exists.
Inotifywatch directly is working good though.

@emcrisostomo
Copy link
Owner

@valentjedi Since this seems tricky to reproduce, would you please provide all the information you have:

  • What is the exit code?
  • Is the behaviour consistent?
  • What happens if you try in a single directory with just a bunch of files?

I'll try to fire a VM when I can.

@unphased
Copy link
Author

@valentjedi does fswatch include the created, updated, and removed events as you expect when you use the recursive flag?

@valignatev
Copy link

Hi all, sorry for a delay :)
@unphased no, the recursive flag doesn't make any difference.

@emcrisostomo
I did a lot of experiments on both MacOs and Linux, and I think I've reduced the scope of the issue to the number of files in the watchable directory.

So here's the example of the command which works great on MacOs:

fswatch -rx --event Created --event Updated --event Removed .

On Arch it seems to do nothing at first glance, but only if the number of files in the directory is huge. For example, some project root with a big node_modules in it. If I repeat the experiment on a folder with a few files, fswatch seems to work fine on both MacOs and Linux.

After I've noticed this, I've repeated the experiment on the initial big directory. I decided to wait longer until fswatch recognizes something. And it does! But after a long, long time :)

My guess is that fswatch does some heavy lifting scanning in the background and it takes a long time to recognize desirable effect. And if I remove --event filters I see exactly this - huge and long scan at first execution, and then rescan on every file modification.

Hope it'll help somehow

P.S. I wasn't able to reproduce existing behavior, maybe I overlooked it in the first place.

@emcrisostomo
Copy link
Owner

Thanks @valignatev, yes, you're right on macOS creating the event stream is basically a effortless operation. On Linux, however, inotify only watches for events on first-level children of a directory. To watch a directory recursively fswatch has to scan the tree and add a watch for each directory in the tree.

I'm closing the issue for now because I have no improvements to suggest. Could you give some figures about the number of files and directories in the tree when you experienced these problems?

@valignatev
Copy link

Thanks for the response! Interesting. Pure inotifywait works great for me while fswatch chokes on this project.
The project has seven directories at the root level, and the deepest ones go maybe five-six levels deep. It usually has 2-10 files, rarely more. node_module is an outlier, but it's in ignore patterns.

Here's commands I use, both inotifywait and fswatch.

# inotifywait
inotifywait -mr --exclude ignore_patterns_here \
 -e modify,create,delete path/to/project/root \
 --format "'%w%f'"

#fswatch
fswatch -r0 --event Created --event Updated --event Removed \
 --event Renamed \ --event MovedFrom --event MovedTo \
 --format '%p' \
 ignore_patterns_here -l 0.11 path/to/project/root

Also, these calls are wrapped in if [ "$(uname)" = "Linux" ]; then ... fi and in if [ "$(uname)" = "Darwin" ]; then ... fi accordingly so both Linux and macos users can be happy :)

Hope it'll help somehow

@emcrisostomo emcrisostomo reopened this May 2, 2018
@emcrisostomo
Copy link
Owner

Thanks for the information @valignatev. I have a gut feeling that what's happening is that the ignored directories may contain a huge number of files. fswatch does not skip a directory scanning even if its path is matched by an ignore pattern, so that its children are scanned. Could you give me some figures about how many files are contained in the ignored directories?

@valignatev
Copy link

valignatev commented May 3, 2018

Oh yeah they contain a huge number of files. In my particular case node_modules only contains 49733 files. And here also .git dir, and a couple more.

I used this command for counting files: find DIR_NAME -type f | wc -l

@valignatev
Copy link

And this not considered that big for node_modules dir :) Other projects might have much bigger ones.

@emcrisostomo
Copy link
Owner

Hi @valignatev, I've updated fswatch so that it does not scan a directory if the directory path is to be excluded, according to the filters. Would you be so kind to test the latest master and give me some feedback? Please find attached a release tarball here.
fswatch-1.12.0-develop.tar.gz

@valignatev
Copy link

Thanks! Sure I'll test it and report back to you!

@valignatev
Copy link

Hi again, just tried it. If node_modules are already in place, fswatch refuses to even run, it crashes with An error occurred and the program will be terminatedand then 3-4 random symbols message (btw, 1.11 has the same behavior).

I also tried to first run fswatch without huge node_modules (so I can add it while fswatch is already running). And it worked. So I run fswatch while there are only 3500 files, it runs, then I build node dependencies, now here's almost 60k files, and fswatch works great.

So it seems that it still scans everything upon initial execution (and chokes with a crash), and only then stops to listen for ignored files.

I feel we're getting close, thanks a lot for the step in right direction!

@emcrisostomo
Copy link
Owner

Thank you very much @valignatev. Are you able to replicate the crash? If you are, I'd like you to give me the following information:

  • OS you're running.
  • A dump of the watched directory contents. Something like:
$ find watched-directory -type d -print0 > directories.txt
$ find watched-directory -type f -print0 > files.txt

This way I should be able to quickly recreate your directory structure and replicate the crash.

@valignatev
Copy link

valignatev commented May 10, 2018

Can't give you a directory tree of an actual project, but I could replicate something similar with one opensource project, which is reactjs.
Here's the output:
files.txt
directories.txt

My OS is Arch Linux, also, I've tried this on several terminal emulators.
Also, I've noticed that -l flag somehow affects the result. Here's command which crashed:

fswatch -r0 --event Created --event Updated --event Removed \
    --event Renamed --event MovedFrom --event MovedTo \
    --format '%p' -l 0.11 ./
# output is
a&U  # Here can be any 3 symbols, even ones which can't be printed
Status code: 1

Here's command which works:

fswatch -r0 --event Created --event Updated --event Removed \
    --event Renamed --event MovedFrom --event MovedTo \
    --format '%p' ./

Also, it works if I ignore node_modules and leave -l inplace:

fswatch -r0 --event Created --event Updated --event Removed \
    --event Renamed --event MovedFrom --event MovedTo \
    --format '%p' -e node_modules -l 11 ./

@emcrisostomo
Copy link
Owner

Thank you very much @valignatev

@emcrisostomo emcrisostomo added this to the 1.12.0 milestone May 10, 2018
@emcrisostomo emcrisostomo self-assigned this May 10, 2018
@emcrisostomo emcrisostomo changed the title completely different behavior in os x and linux Wrong error message is printed when inotify event queue overflows Jun 23, 2018
@emcrisostomo
Copy link
Owner

Hi @valignatev, I fixed the bug in develop and a release will be prepared soon. Basically, inotify event queue can overflow , and that's consistently happening in this case because we're scanning a huge filesystem hierarchy. Since event queue overflow may lead to event losses, I decided that by default fswatch would exit with an error if that happened. You can tell fswatch not to exit and emit an overflow event if you decide to manually handle them (in this case it's just safe to ignore them). In retrospect the most sensible default appears to be to let fswatch run and add an option to force a failure if desired. I'll think about the implications.

Finally, you're getting a random output simply because the error handling code in that path is broken.

Thanks for your help troubleshooting this issue. If you liked to test it on the master branch I'd be grateful: here's a release tarball in case you're willing to.

fswatch-1.12.0-develop.tar.gz

@valignatev
Copy link

@emcrisostomo Hi! Thanks a lot for the fixes, I'll try them out and let you know

@valignatev
Copy link

Brief testing shows that fswatch works well in this case now. Am I right that you've changed the behavior, so now fswatch ignores such overflows? Also, I've noticed --allow-overflow flag, but I don't remeber if it was here in previous releases :)

@valignatev
Copy link

Ok, four days in and still works great for me. Can't wait for the release ;)

@emcrisostomo
Copy link
Owner

Hi @valignatev, yes to all your questions. Thanks for finding the bug and for testing fswatch. I'll release it in a few hours.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants