Bug on adding/removing descriptors

[mauricioabreu]

I found a bug using the code in the example.go file.
I think the library is not handling addition/removal of descriptors very well.

My case is:

• I start watching one folder like /foo
• Some directories inside foo may be removed/moved
• These same directories can be recreated
• Removed again
• Moved
• And so on...

I created a python script that simulates random creation of directories:

import random
from subprocess import call
import time


commands = [
    "mkdir watcher/foo",
    "rm -r watcher/foo",
    "mkdir watcher/lol",
    "rm -r watcher/lol"
]


while True:
    for command in commands:
        print(command)
        try:
            call(command, shell=True)
        except Exception:
            pass
    time.sleep(1)

And then I start the example file:

go run example/example.go watcher

I am receiving the panic: descriptor not found right after a directory removal. Here is some log:

2018/12/18 00:16:21 Event Name: foo Event Path: watcher/foo
2018/12/18 00:16:21 Watcher watcher event watcher/foo
2018/12/18 00:16:21 Directory created: watcher/foo
2018/12/18 00:16:21 Watch descriptor created and started for watcher/foo
2018/12/18 00:16:21 Event Name: lol Event Path: watcher/lol
2018/12/18 00:16:21 Watcher watcher event watcher/lol
2018/12/18 00:16:21 Directory created: watcher/lol
2018/12/18 00:16:21 Watch descriptor created and started for watcher/lol
2018/12/18 00:16:21 Event Name:  Event Path:
2018/12/18 00:16:21 Watcher watcher event
2018/12/18 00:16:21 Event Name:  Event Path:
2018/12/18 00:16:21 Watcher watcher event
2018/12/18 00:16:21 Event Name: foo Event Path: watcher/foo
2018/12/18 00:16:21 Watcher watcher event watcher/foo
2018/12/18 00:16:21 Directory removed: watcher/foo
2018/12/18 00:16:21 Removing descriptor for path watcher/foo
2018/12/18 00:16:21 Watch descriptor removed for watcher/foo
2018/12/18 00:16:24 Event Name:  Event Path:
2018/12/18 00:16:24 Watcher watcher event
2018/12/18 00:16:24 Event Name:  Event Path:
2018/12/18 00:16:24 Watcher watcher event
2018/12/18 00:16:24 Event Name: lol Event Path: watcher/lol
2018/12/18 00:16:24 Watcher watcher event watcher/lol
2018/12/18 00:16:24 Directory removed: watcher/lol
2018/12/18 00:16:24 Removing descriptor for path watcher/lol
2018/12/18 00:16:24 Watch descriptor removed for watcher/lol
2018/12/18 00:16:24 Event Name: foo Event Path: watcher/foo
2018/12/18 00:16:24 Watcher watcher event watcher/foo
2018/12/18 00:16:24 Directory created: watcher/foo
2018/12/18 00:16:24 Watch descriptor created and started for watcher/foo
2018/12/18 00:16:27 Event Name:  Event Path:
2018/12/18 00:16:27 Watcher watcher event
2018/12/18 00:16:27 Event Name:  Event Path:
2018/12/18 00:16:27 Watcher watcher event
2018/12/18 00:16:27 Event Name: foo Event Path: watcher/foo
2018/12/18 00:16:27 Watcher watcher event watcher/foo
2018/12/18 00:16:27 Directory removed: watcher/foo
2018/12/18 00:16:27 Removing descriptor for path watcher/foo
2018/12/18 00:16:27 Watch descriptor removed for watcher/foo
2018/12/18 00:16:27 Event Name: lol Event Path: watcher/lol
2018/12/18 00:16:27 Watcher watcher event watcher/lol
2018/12/18 00:16:27 Directory created: watcher/lol
2018/12/18 00:16:27 Watch descriptor created and started for watcher/lol
2018/12/18 00:16:30 Event Name: foo Event Path: watcher/foo
2018/12/18 00:16:30 Watcher watcher event watcher/foo
2018/12/18 00:16:30 Directory created: watcher/foo
2018/12/18 00:16:30 Watch descriptor created and started for watcher/foo
2018/12/18 00:16:30 Event Name:  Event Path:
2018/12/18 00:16:30 Watcher watcher event
2018/12/18 00:16:30 Event Name:  Event Path:
2018/12/18 00:16:30 Watcher watcher event
2018/12/18 00:16:30 Event Name: foo Event Path: watcher/foo
2018/12/18 00:16:30 Watcher watcher event watcher/foo
2018/12/18 00:16:30 Directory removed: watcher/foo
2018/12/18 00:16:30 Removing descriptor for path watcher/foo
2018/12/18 00:16:30 Watch descriptor removed for watcher/foo
2018/12/18 00:16:30 Event Name:  Event Path:
2018/12/18 00:16:30 Watcher watcher event
2018/12/18 00:16:30 Event Name:  Event Path:
2018/12/18 00:16:30 Watcher watcher event
2018/12/18 00:16:30 Event Name: lol Event Path: watcher/lol
2018/12/18 00:16:30 Watcher watcher event watcher/lol
2018/12/18 00:16:30 Directory removed: watcher/lol
2018/12/18 00:16:30 Removing descriptor for path watcher/lol
2018/12/18 00:16:30 Watch descriptor removed for watcher/lol
2018/12/18 00:16:34 Event Name: foo Event Path: watcher/foo
2018/12/18 00:16:34 Watcher watcher event watcher/foo
2018/12/18 00:16:34 Directory created: watcher/foo
2018/12/18 00:16:34 Watch descriptor created and started for watcher/foo
2018/12/18 00:16:34 Event Name:  Event Path:
2018/12/18 00:16:34 Watcher watcher event
2018/12/18 00:16:34 Event Name:  Event Path:
2018/12/18 00:16:34 Watcher watcher event
2018/12/18 00:16:34 Directory removed:
2018/12/18 00:16:34 Removing descriptor for path
panic: descriptor not found

It is strange that some events have empty names and empty paths. Don't you think?

Any ideias on why it is happening?

[mauricioabreu]

I guess it is something related to the directory being used. /tmp may have some unwanted effects leading the library to fail handling these events.

[mauricioabreu]

It looks like a concurrency bug, no? After a descriptor is started (for a path that was removed) it prints Events with null values.

[mauricioabreu]

Do you want me to create a test for it? Or a reproducible container.

[mauricioabreu]

One of the problems lives inside the read buffer loop: https://github.com/tywkeene/go-fsevents/blob/master/fsevents.go#L442
It continues the code with the very same offset, making the code enter in a loop. I can create a pull request to fix it but it still won't solve my problem, unfortunately.

[tywkeene]

Sorry about the insanely late reply. I was swamped with work.

I'm going to write some unit and behavior driven tests, I'll see if I can replicate this behavior and get a test in for it.

[tywkeene]

I can't seem to reproduce this bug. I'm gonna go ahead and close this for now, until I run into it in the future.