How to prevent deadlocks when reload_on_save is enabled

[brupelo]

@randy3k Randy, hi there, nice to meet you. Yesterday I was facing a nasty bug while reloading some code of mine using your package and after a lot of researching I've discovered in some edge-case a deadlock will be created. I've come up with a little reproducer and added some details here.

Right now I'd like to come up with some way to reproduce the deadlock much faster... I was thinking maybe spawning "Package reloading" in a loop intensively would do, I'll test it out later.

Anyway, in case you're also interested, please let me know your thoughts, advices, ...

Thx in advance!

[randy3k]

Do you mean saving the document while the package is reloading?

[brupelo]

Yeah, put the focus on the start.py view and start pressing ctrl+s as fast as possible... I've already made the test of doing [window.run_command("save") for i in range(100)] on the console but unfortunately the deadlock won't show up this way.

Just for the record, with larger code using a similar pattern than the one exposed in my mcve (ie: global variables using sublime settings function) I won't need to press ctrl+s as fast as possible cos the deadlock shows up much more easily, tricky... I'll try to make a video to show you how I'm testing it right now

[brupelo]

@randy3k Here's the slow manual way I'm testing it right now... if you know a faster way to raise the deadlock I'd be glad to hear it :)

[randy3k]

[window.run_command("save") for i in range(100)] on the console but unfortunately the deadlock won't show up this way. ...

I thing it is because the execution is too “fast". It takes some time for the reloaded to kick in.

I guess the lesson to learn is to wait for the reloaded while reloading in progress.

[brupelo]

I guess the lesson to learn is to wait for the reloaded while reloading in progress. ... That sounds wise, but... not really ;)

With my above snippet is difficult to reproduce, that's why I think not waiting much time between savings is the "best" way to reproduce but with real larger code the deadlock will show up even if i save it in much slower pace (ie: waiting till the progress bar has finished and the message "package whatever reloaded" appears...

Tricky stuff :/ ... What do you mean by "it takes some time for the reloaded to kick in" ? Certainly the message "package whatever reloaded" in the status bar doesn't mean the package has kicked in ... So... :) . Asking you this cos if we knew the condition that a module has been "kicked in" not allowing to the users reloading would be cool

[brupelo]

More relevant info, here's a little snapshot once the deadlock happens:

2018-07-19 16:50:15.786994

# ThreadID: 4120
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Installed Packages\AutomaticPackageReloader.sublime-package\package_reloader.py", line 73, in <lambda>
  sublime.set_timeout_async(lambda: self.run_async(pkg_name))
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Installed Packages\AutomaticPackageReloader.sublime-package\package_reloader.py", line 92, in run_async
  reload_package(pkg_name, verbose=pr_settings.get('verbose'))
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Installed Packages\AutomaticPackageReloader.sublime-package\reloader/reloader.py", line 47, in reload_package
  reload_plugin(pkg_name)
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Installed Packages\AutomaticPackageReloader.sublime-package\reloader/reloader.py", line 118, in reload_plugin
  sublime_plugin.reload_plugin(plugin)
File: "D:\testcase\Sublime Text Build 3176 x64\sublime_plugin.py", line 116, in reload_plugin
  m = importlib.import_module(modulename)
File: "./python3.3/importlib/__init__.py", line 90, in import_module
File: "<frozen importlib._bootstrap>", line 1584, in _gcd_import
File: "<frozen importlib._bootstrap>", line 1565, in _find_and_load
File: "<frozen importlib._bootstrap>", line 1532, in _find_and_load_unlocked
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Installed Packages\AutomaticPackageReloader.sublime-package\reloader/reloader.py", line 175, in load_module
  return module.__loader__.load_module(name)
File: "<frozen importlib._bootstrap>", line 584, in _check_name_wrapper
File: "<frozen importlib._bootstrap>", line 1022, in load_module
File: "<frozen importlib._bootstrap>", line 1003, in load_module
File: "<frozen importlib._bootstrap>", line 560, in module_for_loader_wrapper
File: "<frozen importlib._bootstrap>", line 868, in _load_module
File: "<frozen importlib._bootstrap>", line 313, in _call_with_frames_removed
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Packages\foo\a.py", line 14, in <module>
  global_a = A()
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Packages\foo\a.py", line 8, in __init__
  somekey = global_b.load().get("somekey", [])
File: "D:\testcase\Sublime Text Build 3176 x64\sublime.py", line 1161, in get
  return sublime_api.settings_get_default(self.settings_id, key, default)

# ThreadID: 5592
File: "D:\testcase\Sublime Text Build 3176 x64\sublime_plugin.py", line 116, in reload_plugin
  m = importlib.import_module(modulename)
File: "./python3.3/importlib/__init__.py", line 90, in import_module
File: "<frozen importlib._bootstrap>", line 1584, in _gcd_import
File: "<frozen importlib._bootstrap>", line 1565, in _find_and_load
File: "<frozen importlib._bootstrap>", line 1532, in _find_and_load_unlocked
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Installed Packages\AutomaticPackageReloader.sublime-package\reloader/reloader.py", line 175, in load_module
  return module.__loader__.load_module(name)
File: "<frozen importlib._bootstrap>", line 584, in _check_name_wrapper
File: "<frozen importlib._bootstrap>", line 1022, in load_module
File: "<frozen importlib._bootstrap>", line 1003, in load_module
File: "<frozen importlib._bootstrap>", line 560, in module_for_loader_wrapper
File: "<frozen importlib._bootstrap>", line 868, in _load_module
File: "<frozen importlib._bootstrap>", line 313, in _call_with_frames_removed
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Packages\foo\start.py", line 1, in <module>
  from foo.a import A
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Installed Packages\AutomaticPackageReloader.sublime-package\reloader/reloader.py", line 138, in __import__
  module = orig___import__(name, globals, locals, fromlist, level)
File: "<frozen importlib._bootstrap>", line 295, in _lock_unlock_module
File: "<frozen importlib._bootstrap>", line 221, in acquire

# ThreadID: 7620
File: "./python3.3/threading.py", line 878, in _bootstrap
File: "./python3.3/threading.py", line 901, in _bootstrap_inner
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Packages\deadlocks\commands.py", line 56, in run
  self.stacktraces()
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Packages\deadlocks\commands.py", line 69, in stacktraces
  f.write(stacktraces())
File: "D:\testcase\Sublime Text Build 3176 x64\Data\Packages\deadlocks\commands.py", line 22, in stacktraces
  for filename, lineno, name, line in traceback.extract_stack(stack):

[randy3k]

What do you mean by "it takes some time for the reloaded to kick in" ?

if you save the file in a row 10 times without a pause in between, the on_post_save hook won’t be triggered.

[brupelo]

if you save the file in a row 10 times without a pause in between, the on_post_save hook won’t be triggered.

That's interesting... ok, let me ask you something, how would you make the bug show up programatically? Said otherwise, which snippet could emulate the human behaviour of "saving the file in a row N times without a pause in between" to reproduce the bug consistently?

Asking you this cos at this point thanks to the snapshots I know basically the piece of code which causes the deadlocks, yeah... global variables trying to access settings files are definitely not cool. But I'd like to know for sure once I've fixed that the deadlock won't appear again.

Summing up, at this point I don't understand the real difference between doing [window.run_command("save") for i in range(10)] and saving manually the file 10 times.

Thanks and sorry for posting that many posts but this problem has been bothering me already for a while... although it's quite interesting one as I've learned quite a lot of cool stuff in the road :)

[randy3k]

I didn’t test this, but try

[sublime.set_timeout(lambda: window.run_command("save"), i) for i in range(10)]

[brupelo]

Thx, let me try, right now I was playing with the below one and I was getting +/- consistent crashes after spawning it 1 or 2 times:

class SaveAutomaticallyCommand(sublime_plugin.WindowCommand):

    def run(self, **kwargs):
        for i in range(50):
            sublime.set_timeout(lambda: self.window.run_command("save"), 100*i)

[randy3k]

If you run the command [window.run_command("save") for i in range(10)], you don’t give the event handler enough time to respond. Note that the event handler runs on a different thread that the sublime main thread.

[brupelo]

You're absolutely right... btw, I'd also tried with set_timeout_async and it wasn't making any difference, just for the record, the below with the hardcoded values seems to crash ST quite consistently \o/ (although sometimes you need to spawn it couple of times):

[sublime.set_timeout(lambda: window.run_command("save"), i*100) for i in range(50)]

[randy3k]

I guess a fix would be setting a global flag which indicates loading is in progress. Any subsequential save command won’t trigger the reloader if the flag is set.

[brupelo]

That'd be indeed a great fix, but I guess the question here is... is there any way to know whether the loading has been completed (including async code) or not?

Maybe this one https://github.com/python/cpython/blob/master/Lib/importlib/_bootstrap.py#L194 could help? dunno... :/

[randy3k]

We can tell when the plugin has finish reloading https://github.com/randy3k/AutomaticPackageReloader/blob/master/package_reloader.py#L99. It would be the developer responsibility to handle the loading of asynchronous code.

[brupelo]

Fair enough, sounds like an easy and decent solution to me. I think that'd be a good default behaviour of the plugin... On the other hand, being able to stress test and reloading a package could be also quite interesting to check packages are robust enough and find possible issues. So I guess a settings bool variable such as reload_on_package_ready with true as a default (or a more descriptive name) could be a more versatile option.

Btw, I see a lot of hardcoded numbers in this piece of code, guess coming up with a more robust solution wouldn't be straightforward?

Regards