Watchdog error on startup: "inotify watch limit reached", #238

bollwyvl · 2021-01-25T00:05:50Z

Describe the bug

Thanks for this tool! Over on https://github.com/krassowski/jupyterlab-lsp/pull/493 we're trying to add robotframework_ls 0.7.1 to our tested language servers, and use it for development.

When trying to start robotframework_ls in either:

a large development environment (node_modules with 1000s of files, a few hundred lines of robot)
a completely empty test enviornment (e.g. empty directory, overloaded $HOME)
... in jupyterlab-lsp, the language server does not start/stay running

To Reproduce
Steps to reproduce the behavior:

Open file with representative contents in jupyter-lsp (master)
See full log errors below, but crucially:

  File "~/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 424, in _raise_error
    raise OSError(errno.ENOSPC, "inotify watch limit reached")
OSError: [Errno 28] inotify watch limit reached

then

  File "~/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/python_ls.py", line 318, in m_text_document__did_change
    self.workspace.update_document(
AttributeError: 'NoneType' object has no attribute 'update_document'
lsp: 2021-01-24 15:14:18 UTC pid: 159268 - MainThread - EXCEPTION - robocorp_ls_core.python_ls

Expected behavior

robotframework_ls should continue to run... and/or return LSP log messages

Screenshots
Nothing much to see... all logging appears in terminal

Versions:

OS: Ubuntu 20.04.1
Robot Framework Version 3.2.2
Robot Framework Language Server Version [e.g. 0.2.3]
Client Version jupyterlab-lsp master

jupyterlab_robotmode      0.2.0              pyhd8ed1ab_0    conda-forge
robotframework            3.2.2              pyh9f0ad1d_0    conda-forge
robotframework-lint       1.1                pyh9f0ad1d_0    conda-forge
robotframework-lsp        0.7.1              pyhd8ed1ab_0    conda-forge
robotframework-pythonlibcore 2.2.0              pyhd8ed1ab_0    conda-forge
robotframework-seleniumlibrary 4.5.0              pyh9f0ad1d_0    conda-forge
robotkernel               1.4.0                      py_0    conda-forge

Logs
Add the logs obtained when reproducing the issue.
See: https://github.com/robocorp/robotframework-lsp/blob/master/robotframework-ls/docs/reporting_issues.md for details on how to collect the logs.

lsp: 2021-01-24 15:14:18 UTC pid: 159268 - MainThread - EXCEPTION - robocorp_ls_core.jsonrpc.endpoint
Failed to handle request 0

Traceback (most recent call last):
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/jsonrpc/endpoint.py", line 142, in consume
self._handle_request(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/jsonrpc/endpoint.py", line 278, in _handle_request
handler_result = handler(params)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/jsonrpc/dispatchers.py", line 38, in handler
return method(**(params or {}))
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/python_ls.py", line 261, in m_initialize
self.workspace = self._create_workspace(rootUri, workspaceFolders or [])
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/server.py", line 83, in _create_workspace
return RobotWorkspace(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/robot_workspace.py", line 18, in init
Workspace.init(self, root_uri, workspace_folders=workspace_folders)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/workspace.py", line 265, in init
self.add_folder(folder)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/robot_workspace.py", line 24, in add_folder
self.libspec_manager.add_workspace_folder(folder.uri)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 544, in add_workspace_folder
folder_info.start_watch(self._observer, self._file_changes_notifier)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 260, in start_watch
self._watch = observer.notify_on_any_change(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/watchdog_wrapper.py", line 223, in notify_on_any_change
self._observer.schedule(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/api.py", line 301, in schedule
emitter.start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/utils/init.py", line 110, in start
self.on_thread_start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify.py", line 121, in on_thread_start
self._inotify = InotifyBuffer(path, self.watch.is_recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_buffer.py", line 35, in init
self._inotify = Inotify(path, recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 201, in init
self._add_dir_watch(path, recursive, event_mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 398, in _add_dir_watch
self._add_watch(full_path, mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 412, in _add_watch
Inotify._raise_error()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 424, in _raise_error
raise OSError(errno.ENOSPC, "inotify watch limit reached")
OSError: [Errno 28] inotify watch limit reached
lsp: 2021-01-24 15:14:18 UTC pid: 159268 - MainThread - EXCEPTION - robocorp_ls_core.python_ls
Error updating document: {'uri': 'file:///jupyterlab-lsp/atest/examples/example.robot', 'version': 0} with changes: [{'text': '*** Settings \nLibrary SeleniumLibrary\nLibrary Builtin\n\n Variables \n${ABC} abc\n\n Keywords \nSpecial Log\n [Arguments] ${log}\n [Documentation] a special log\n Log ${log.upper()}!\n\n Test Cases ***\nLog Something\n Special Log ${ABC}\n\n'}]

Traceback (most recent call last):
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/python_ls.py", line 318, in m_text_document__did_change
self.workspace.update_document(
AttributeError: 'NoneType' object has no attribute 'update_document'
lsp: 2021-01-24 15:14:18 UTC pid: 159268 - MainThread - EXCEPTION - robocorp_ls_core.python_ls
Error updating document: {'uri': 'file:///jupyterlab-lsp/atest/examples/example.robot', 'version': 1} with changes: [{'text': '*** Settings \nLibrary SeleniumLibrary\nLibrary Builtin\n\n Variables \n${ABC} abc\n\n Keywords \nSpecial Log\n [Arguments] ${log}\n [Documentation] a special log\n Log ${log.upper()}!\n\n Test Cases ***\nLog Something\n Special Log ${ABC}\n\n'}]

with -v:

204 PUT /lab/api/workspaces/default?1611533040122 (127.0.0.1) 0.89ms lsp: 2021-01-24 19:04:00 UTC pid: 178449 - MainThread - INFO - robocorp_ls_core.python_ls Starting RobotFrameworkServerApi IO language server. pid: 178449

lsp: 2021-01-24 19:04:00 UTC pid: 178449 - MainThread - INFO - robotframework_ls.impl.libspec_manager
Finished creating builtin libraries.

lsp: 2021-01-24 19:04:00 UTC pid: 178449 - MainThread - INFO - robotframework_ls.impl.libspec_manager
Tracking folder for changes: ~/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api

lsp: 2021-01-24 19:04:00 UTC pid: 178449 - MainThread - EXCEPTION - robotframework_ls.server_api.server
Unable to properly initialize the LibspecManager.

Traceback (most recent call last):
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/server.py", line 26, in init
libspec_manager = LibspecManager()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 471, in init
self._synchronize()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 666, in _synchronize
self.synchronize_pythonpath_folders()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 644, in synchronize_pythonpath_folders
folder_info.start_watch(self._observer, self._file_changes_notifier)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 260, in start_watch
self._watch = observer.notify_on_any_change(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/watchdog_wrapper.py", line 228, in notify_on_any_change
self._start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/watchdog_wrapper.py", line 124, in _start
self._observer.start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/api.py", line 260, in start
emitter.start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/utils/init.py", line 110, in start
self.on_thread_start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify.py", line 121, in on_thread_start
self._inotify = InotifyBuffer(path, self.watch.is_recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_buffer.py", line 35, in init
self._inotify = Inotify(path, recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 201, in init
self._add_dir_watch(path, recursive, event_mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 391, in _add_dir_watch
self._add_watch(path, mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 412, in _add_watch
Inotify._raise_error()
File "~/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 424, in _raise_error
raise OSError(errno.ENOSPC, "inotify watch limit reached")
OSError: [Errno 28] inotify watch limit reached
lsp: 2021-01-24 19:04:00 UTC pid: 178449 - MainThread - EXCEPTION - main
Error initializing RobotFrameworkServerApi.

Traceback (most recent call last):
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/server__main__.py", line 113, in main
main.main(language_server_class=RobotFrameworkServerApi)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/main.py", line 129, in main
start_io_lang_server(stdin, stdout, language_server_class)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/python_ls.py", line 175, in start_io_lang_server
server = handler_class(rfile, wfile)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/server.py", line 26, in init
libspec_manager = LibspecManager()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 471, in init
self._synchronize()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 666, in _synchronize
self.synchronize_pythonpath_folders()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 644, in synchronize_pythonpath_folders
folder_info.start_watch(self._observer, self._file_changes_notifier)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 260, in start_watch
self._watch = observer.notify_on_any_change(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/watchdog_wrapper.py", line 228, in notify_on_any_change
self._start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/watchdog_wrapper.py", line 124, in _start
self._observer.start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/api.py", line 260, in start
emitter.start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/utils/init.py", line 110, in start
self.on_thread_start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify.py", line 121, in on_thread_start
self._inotify = InotifyBuffer(path, self.watch.is_recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_buffer.py", line 35, in init
self._inotify = Inotify(path, recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 201, in init
self._add_dir_watch(path, recursive, event_mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 391, in _add_dir_watch
self.add_watch(path, mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 412, in _add_watch
Inotify._raise_error()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 424, in raise_error
raise OSError(errno.ENOSPC, "inotify watch limit reached")
OSError: [Errno 28] inotify watch limit reached
Traceback (most recent call last):
File "~/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/server__main.py", line 113, in main
main.main(language_server_class=RobotFrameworkServerApi)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/main.py", line 129, in main
start_io_lang_server(stdin, stdout, language_server_class)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/python_ls.py", line 175, in start_io_lang_server
server = handler_class(rfile, wfile)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/server.py", line 26, in init
libspec_manager = LibspecManager()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 471, in init
self._synchronize()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 666, in _synchronize
self.synchronize_pythonpath_folders()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 644, in synchronize_pythonpath_folders
folder_info.start_watch(self._observer, self._file_changes_notifier)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/impl/libspec_manager.py", line 260, in start_watch
self._watch = observer.notify_on_any_change(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/watchdog_wrapper.py", line 228, in notify_on_any_change
self._start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/watchdog_wrapper.py", line 124, in _start
self._observer.start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/api.py", line 260, in start
emitter.start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/utils/init.py", line 110, in start
self.on_thread_start()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify.py", line 121, in on_thread_start
self._inotify = InotifyBuffer(path, self.watch.is_recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_buffer.py", line 35, in init
self._inotify = Inotify(path, recursive)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 201, in init
self._add_dir_watch(path, recursive, event_mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 391, in _add_dir_watch
self._add_watch(path, mask)
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 412, in _add_watch
Inotify._raise_error()
File "~/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/libs/watchdog_lib/watchdog/observers/inotify_c.py", line 424, in _raise_error
raise OSError(errno.ENOSPC, "inotify watch limit reached")
OSError: [Errno 28] inotify watch limit reached
lsp: 2021-01-24 19:04:00 UTC pid: 178409 - MainThread - EXCEPTION - robotframework_ls.server_manager
Error starting robotframework server api. Exit code: 0 Base exception: Process has already exited. Stderr: b''. Stderr:

Traceback (most recent call last):
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_manager.py", line 284, in get_robotframework_api_client
api.forward(
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/client.py", line 89, in forward
self._check_process_alive()
File "/envs/default/lib/python3.8/site-packages/robotframework_ls/server_api/client.py", line 22, in _check_process_alive
raise SubprocessDiedError(
robotframework_ls.server_api.client.SubprocessDiedError: Process has already exited. Stderr: b''
lsp: 2021-01-24 19:04:00 UTC pid: 178413 - MainThread - EXCEPTION - robocorp_ls_core.python_ls
Error updating document: {'uri': 'file:///jupyterlab-lsp/atest/examples/example.robot', 'version': 1} with changes: [{'text': '*** Settings \nLibrary SeleniumLibrary\nForce Tags atest:example\n\n Variables \n${ABC} abc\n\n Keywords \nSpecial Log\n [Arguments] ${log}\n [Documentation] a special log\n Log ${log.upper()}!\n\n Test Cases ***\nLog Something\n Special Log ${ABC}\n\n'}]

Traceback (most recent call last):
File "~/envs/default/lib/python3.8/site-packages/robotframework_ls/vendored/robocorp_ls_core/python_ls.py", line 318, in m_text_document__did_change
self.workspace.update_document(
AttributeError: 'NoneType' object has no attribute 'update_document'
lsp: 2021-01-24 19:04:00 UTC pid: 178413 - ThreadPoolExecutor-1_0 - INFO - robotframework_ls.server_api.server
Workspace still not initialized.

lsp: 2021-01-24 19:04:00 UTC pid: 178413 - ThreadPoolExecutor-1_0 - INFO - robotframework_ls.server_api.server
Workspace still not initialized.

The text was updated successfully, but these errors were encountered:

bollwyvl · 2021-01-25T00:15:57Z

I also tried rolling back to the 0.6 line...

Locally bumping the inotify watches to a very large number made this work locally, but seems infeasible to tell every user to do:

sudo sysctl fs.inotify.max_user_watches=100000

Are there ways to configure which folders it won't watch by default? Can they be specified by environment variable or command line switch?

When faced with some similar issues, i accepted some less-than-optimal performance for some simpler APIs with watchgod.

fabioz · 2021-01-26T13:31:35Z

It's unfortunate that when the native file watchers would be most useful (with a huge number of files), they can't be used.

It's not currently possible to ignore folders because watchdog itself doesn't have an API for that.

I'll have to think about how to go here... maybe the approach on watchgod would be reasonable (I took a look and the implementation could probably be improved a bit by checking the mtime of directories instead of always iterating through all files).

fabioz · 2021-03-03T16:45:29Z

By default this will still use watchdog, but now it's also possible to set an environment variable:

ROBOTFRAMEWORK_LS_WATCH_IMPL=fsnotify

to force the usage of polling.

bollwyvl added bug Something isn't working robotframework-ls labels Jan 25, 2021

fabioz added a commit that referenced this issue Mar 3, 2021

Allow using fsnotify to watch for filesystem changes. Fixes #238

06f30d6

fabioz added a commit that referenced this issue Mar 3, 2021

Allow using fsnotify to watch for filesystem changes. Fixes #238

39100ce

fabioz closed this as completed in 22d7fcc Mar 3, 2021

fabioz mentioned this issue Mar 18, 2021

Robotframework LS keeps a lot of files open when vendored watchdog is used #190

Closed

bollwyvl mentioned this issue Apr 1, 2021

Robotframework-lsp do not find keywords imported relatively jupyter-lsp/jupyterlab-lsp#573

Open

ian-h-chamberlain mentioned this issue Jul 15, 2021

Allow ignoring some directories (or specifying a "root directory") for language server #398

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Watchdog error on startup: "inotify watch limit reached", #238

Watchdog error on startup: "inotify watch limit reached", #238

bollwyvl commented Jan 25, 2021

bollwyvl commented Jan 25, 2021

fabioz commented Jan 26, 2021

fabioz commented Mar 3, 2021

Watchdog error on startup: "inotify watch limit reached", #238

Watchdog error on startup: "inotify watch limit reached", #238

Comments

bollwyvl commented Jan 25, 2021

bollwyvl commented Jan 25, 2021

fabioz commented Jan 26, 2021

fabioz commented Mar 3, 2021