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

When an event occurs, watchdog will always execute function 2 times #1003

Open
timelessnesses opened this issue Aug 20, 2023 · 4 comments
Open

Comments

@timelessnesses
Copy link

Here's my module reloader implemented with watchdog:

class FileHandler(FileSystemEventHandler):
    def on_modified(self, event):
        log.info(f"File changed: {event.src_path}")
        if event.src_path.endswith(".py"):
            log.info("Reloading...")
            path = event.src_path.replace("\\", "/").replace("/", ".")[:-3]
            try:
                asyncio.run(bot.reload_extension(path))
                log.info(f"Reloaded {path}")
            except Exception as e:
                log.error(f"Failed to reload {path}")
                log.error(e)
                log.error(traceback.format_exc())

And when the on_modified event occurs, watchdog will execute the function 2 times.
Logs:

[2023/08/20 10:49:37] - [INFO] [lavalinking.bot] File changed: src/music.py
[2023/08/20 10:49:37] - [INFO] [lavalinking.bot] Reloading...
[2023/08/20 10:49:37] - [DEBUG] [asyncio] Using selector: EpollSelector
[2023/08/20 10:49:37] - [INFO] [lavalinking.src.music] Unloaded
[2023/08/20 10:49:37] - [INFO] [lavalinking.bot] Reloaded src.music
[2023/08/20 10:49:37] - [INFO] [lavalinking.bot] File changed: src/music.py
[2023/08/20 10:49:37] - [INFO] [lavalinking.bot] Reloading...
[2023/08/20 10:49:37] - [DEBUG] [asyncio] Using selector: EpollSelector
[2023/08/20 10:49:37] - [INFO] [lavalinking.src.music] Unloaded
[2023/08/20 10:49:37] - [INFO] [lavalinking.bot] Reloaded src.music
@erlete
Copy link

erlete commented Aug 22, 2023

Are you, by any chance, using Visual Studio Code to edit your programs?

I have noticed that saving the file through VSC editor will trigger two modification events at once, not exactly at the same time (few miliseconds of difference). Saving the file using another editor (for example, Windows Notepad) will trigger a single one, so maybe the issue is related to the editor itself and not watchdog.

I have come up with a simple (thus not fully reliable) solution:

from time import perf_counter as pc
from typing import Any

import watchdog.events


class _DuplicateEventLimiter:
    """Duplicate event limiter.

    This class is responsible for limiting duplicated event detection. It works
    by comparing the timestamp of the previous event (if existent) to the
    current one, as well as the event itself. If the difference between the
    timestamps is less than a threshold and the events are the same, the event
    is considered a duplicate.
    """

    _DUPLICATE_THRESHOLD: float = 0.05

    def __init__(self) -> None:
        """Initialize a _DuplicateEventLimiter instance."""
        # Dummy event:
        self._last_event: dict[str, Any] = {
            "time": 0,
            "event": None
        }

    def _is_duplicate(self, event: watchdog.events.FileSystemEvent) -> bool:
        """Determine if an event is a duplicate.

        Args:
            event (watchdog.events.FileSystemEvent): event to check.

        Returns:
            bool: True if the event is a duplicate, False otherwise.
        """
        is_duplicate = (
            pc() - self._last_event["time"] < self._DUPLICATE_THRESHOLD
            and self._last_event["event"] == event
        )

        self._last_event = {
            "time": pc(),
            "event": event
        }

        return is_duplicate

That class should then be inherited by your event handler, for example:

class YourEventHandler(
            watchdog.events.RegexMatchingEventHandler,
            _DuplicateEventLimiter  # Inherit the class from the child.
        ):

    def __init__(self, ...):
        ...
        # Add _DuplicateEventLimiter init call on child init:
        _DuplicateEventLimiter.__init__(self)
        ...

    def on_modified(self, event):
        # Add this block at the top of the event handler method body:
        if self._is_duplicate(event):
            # Do whatever if event is duplicate.
            return  # Or just stop execution of the method.

In my experience, the duplicate event took place at a 30ms delay from the original one, so I chose to set the _DUPLICATE_THRESHOLD to 50ms (0.05s). You can customize that as you wish, although it be strictly reliable on the power of the device you are using, number of available threads, etc.

Hope this helped!

@timelessnesses
Copy link
Author

timelessnesses commented Aug 23, 2023

i tested this theory with nano and i found that nano also saves it more than 2 times?
is this nano's fault?
yes i also use vscode but i didn't think it would trigger saving 2 times.

[2023/08/23 00:29:05] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src', wd=1, mask=IN_ISDIR|IN_OPEN, cookie=0, name=''>
[2023/08/23 00:29:07] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src', wd=1, mask=IN_ISDIR|IN_OPEN, cookie=0, name=''>
[2023/08/23 00:29:07] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src', wd=1, mask=IN_ISDIR|IN_OPEN, cookie=0, name=''>
[2023/08/23 00:29:10] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_CREATE, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:10] - [INFO] [AlphabetBot] File changed: src
[2023/08/23 00:29:10] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_OPEN, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:10] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_MODIFY, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:10] - [INFO] [AlphabetBot] File changed: src/.event.py.swp
[2023/08/23 00:29:10] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_CLOSE_WRITE, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:10] - [INFO] [AlphabetBot] File changed: src
[2023/08/23 00:29:10] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/event.py', wd=1, mask=IN_OPEN, cookie=0, name='event.py'>
[2023/08/23 00:29:15] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_DELETE, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:15] - [INFO] [AlphabetBot] File changed: src
[2023/08/23 00:29:15] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_CREATE, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:15] - [INFO] [AlphabetBot] File changed: src
[2023/08/23 00:29:15] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_OPEN, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:15] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_MODIFY, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:15] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_CLOSE_WRITE, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:15] - [INFO] [AlphabetBot] File changed: src/.event.py.swp
[2023/08/23 00:29:15] - [INFO] [AlphabetBot] File changed: src
[2023/08/23 00:29:17] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/event.py', wd=1, mask=IN_MODIFY, cookie=0, name='event.py'>
[2023/08/23 00:29:17] - [INFO] [AlphabetBot] File changed: src/event.py
[2023/08/23 00:29:17] - [INFO] [AlphabetBot] Reloading...
[2023/08/23 00:29:17] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/event.py', wd=1, mask=IN_OPEN, cookie=0, name='event.py'>
[2023/08/23 00:29:17] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/event.py', wd=1, mask=IN_MODIFY, cookie=0, name='event.py'>
[2023/08/23 00:29:17] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src', wd=1, mask=IN_ISDIR|IN_OPEN, cookie=0, name=''>
[2023/08/23 00:29:17] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/event.py', wd=1, mask=IN_OPEN, cookie=0, name='event.py'>
[2023/08/23 00:29:17] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/event.py', wd=1, mask=IN_CLOSE_WRITE, cookie=0, name='event.py'>
[2023/08/23 00:29:17] - [INFO] [AlphabetBot] Reloaded src.event
[2023/08/23 00:29:17] - [INFO] [AlphabetBot] File changed: src/event.py
[2023/08/23 00:29:17] - [INFO] [AlphabetBot] Reloading...
[2023/08/23 00:29:17] - [INFO] [AlphabetBot] Reloaded src.event
[2023/08/23 00:29:17] - [INFO] [AlphabetBot] File changed: src
[2023/08/23 00:29:18] - [DEBUG] [watchdog.observers.inotify_buffer] in-event <InotifyEvent: src_path=b'src/.event.py.swp', wd=1, mask=IN_DELETE, cookie=0, name='.event.py.swp'>
[2023/08/23 00:29:18] - [INFO] [AlphabetBot] File changed: src

@erlete
Copy link

erlete commented Aug 29, 2023

Honestly, I do not have a clue about how nano saves files, but seems sort of strange that it does it twice. Could you make sure to test it out with a couple more editors and share your feedback? It will probably help developers if the issue needs to be properly addressed.

In my case, as I said before, VSC saved the file twice, but Notepad did not. Seems like an editor issue more than a watchdog one.

@dfidler
Copy link

dfidler commented Oct 26, 2023

I suspect this has less to do with vscode/nano and more to do with the fact that you're probably working on windows. This appears to be a problem with windows in general as the windows kernel will often fire two kernel events for every change.

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

3 participants