Skip to content

NVDA freezes in locks due to COM object releases triggered by Python garbage collection  #11398

@michaelDCurran

Description

@michaelDCurran

NVDA has been freezing quite often for some users, especially when using Microsoft word with Braille.

There are two particular scenarios that users are seeing:

  1. Typing very fast in Microsoft Word causes a freeze.
  2. Arrowing up and down rapidly in a complex Word document opened in Protected View causes a freeze.

Technically, the general pattern that causes this is:

  1. An NVDA thread (other than the main thread) acquires a lock (such as in GetAppModuleFromProcessID, or in Queue.put.
  2. While inside the lock, Python's garbage collector happens to run (in the same thread), and causes comtypes to try and release a COM object.
  3. The COM object's Release call never returnes because Either:
    3.1. The original thread was actually an incoming rpc call from the app who owned the COM object (such as for speaking typed characters). This causes a deadlock in that thread. If NVDA's main thread was to then try to also acquire the same lock, NVDA would completely freeze.
    3.2. Or, NVDA's main thread was currently making an rpc call to the app who owned the COM object (such as nvdaInprocUtils_winword_getTextInRange). This would mean that both the thread doing the Release and NVDA's main thread would both deadlock, and NVDA is then frozen.

NVDA's watchdog feature does have a mechanism to try and cancel outgoing COM calls. However, it seems that it is impossible to cancel a call to IUnknown::Release.

The following thread stacks illustrate a freeze due to the steps leading up to and including 3.2:

ERROR - watchdog._watcher (08:35:06.623) - watchdog (16112):
Core frozen in stack!
INFO - watchdog._watcher (08:35:06.792) - watchdog (16112):
Listing stacks for Python threads:
Python stack for thread 16328 (nvwave.playWaveFile(error.wav)):
  File "threading.pyc", line 890, in _bootstrap
  File "threading.pyc", line 926, in _bootstrap_inner
  File "threading.pyc", line 870, in run
  File "nvwave.pyc", line 276, in idle
  File "nvwave.pyc", line 284, in _idleUnbuffered
  File "nvwave.pyc", line 236, in sync
  File "winKernel.pyc", line 225, in waitForSingleObject

Python stack for thread 12744 (Unknown):
  File "comtypes\_comobject.pyc", line 147, in call_without_this
  File "_UIAHandler.pyc", line 558, in IUIAutomationPropertyChangedEventHandler_HandlePropertyChangedEvent
  File "appModuleHandler.pyc", line 113, in getAppModuleFromProcessID

Python stack for thread 15592 (Unknown):
  File "comtypes\_comobject.pyc", line 147, in call_without_this
  File "_UIAHandler.pyc", line 450, in IUIAutomationEventHandler_HandleAutomationEvent
  File "_UIAHandler.pyc", line 758, in isNativeUIAElement
  File "_UIAHandler.pyc", line 727, in getNearestWindowHandle
  File "appModuleHandler.pyc", line 117, in getAppModuleFromProcessID
  File "appModuleHandler.pyc", line 95, in getAppNameFromProcessID
  File "importlib\__init__.pyc", line 127, in import_module
  File "<frozen importlib._bootstrap>", line 1006, in _gcd_import
  File "<frozen importlib._bootstrap>", line 980, in _find_and_load
  File "<frozen importlib._bootstrap>", line 148, in __enter__
  File "<frozen importlib._bootstrap>", line 163, in _get_module_lock

Python stack for thread 3680 (Dummy-3):
  File "NVDAHelper.pyc", line 138, in nvdaControllerInternal_logMessage
  File "appModuleHandler.pyc", line 95, in getAppNameFromProcessID
  File "importlib\__init__.pyc", line 127, in import_module
  File "<frozen importlib._bootstrap>", line 1006, in _gcd_import
  File "<frozen importlib._bootstrap>", line 983, in _find_and_load
  File "<frozen importlib._bootstrap>", line 953, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "<frozen importlib._bootstrap>", line 1006, in _gcd_import
  File "<frozen importlib._bootstrap>", line 983, in _find_and_load
  File "<frozen importlib._bootstrap>", line 963, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 906, in _find_spec
  File "<frozen importlib._bootstrap_external>", line 1280, in find_spec
  File "<frozen importlib._bootstrap_external>", line 1268, in _get_spec
  File "<frozen importlib._bootstrap>", line 371, in __init__
  File "comtypesMonkeyPatches.pyc", line 101, in newCpbDel
  File "comtypes\__init__.pyc", line 918, in __del__
  File "comtypes\__init__.pyc", line 1172, in Release
  File "comtypesMonkeyPatches.pyc", line 26, in __call__

Python stack for thread 4772 (watchdog.CancellableCallThread.execute(<CFunctionType object at 0x04F6EEB8>)):
  File "threading.pyc", line 890, in _bootstrap
  File "threading.pyc", line 926, in _bootstrap_inner
  File "watchdog.pyc", line 317, in run
  File "threading.pyc", line 552, in wait
  File "threading.pyc", line 296, in wait

Python stack for thread 16112 (watchdog):
  File "threading.pyc", line 890, in _bootstrap
  File "threading.pyc", line 926, in _bootstrap_inner
  File "threading.pyc", line 870, in run
  File "watchdog.pyc", line 127, in _watcher
  File "watchdog.pyc", line 62, in getFormattedStacksForAllThreads

Python stack for thread 12892 (winInputHook):
  File "threading.pyc", line 890, in _bootstrap
  File "threading.pyc", line 926, in _bootstrap_inner
  File "threading.pyc", line 870, in run
  File "winInputHook.pyc", line 79, in hookThreadFunc

Python stack for thread 14312 (_UIAHandler.UIAHandler.MTAThread):
  File "threading.pyc", line 890, in _bootstrap
  File "threading.pyc", line 926, in _bootstrap_inner
  File "threading.pyc", line 870, in run
  File "_UIAHandler.pyc", line 310, in MTAThreadFunc
  File "queue.pyc", line 170, in get
  File "threading.pyc", line 296, in wait

Python stack for thread 2972 (braille._BgThread):
  File "threading.pyc", line 890, in _bootstrap
  File "threading.pyc", line 926, in _bootstrap_inner
  File "threading.pyc", line 870, in run
  File "braille.pyc", line 2185, in func

Python stack for thread 11812 (synthDrivers._espeak.BgThread):
  File "threading.pyc", line 890, in _bootstrap
  File "threading.pyc", line 926, in _bootstrap_inner
  File "synthDrivers\_espeak.pyc", line 190, in run
  File "queue.pyc", line 170, in get
  File "threading.pyc", line 296, in wait

Python stack for thread 17212 (MainThread):
  File "nvda.pyw", line 215, in <module>
  File "core.pyc", line 545, in main
  File "wx\core.pyc", line 2134, in MainLoop
  File "gui\__init__.pyc", line 1049, in Notify
  File "core.pyc", line 515, in run
  File "queueHandler.pyc", line 83, in pumpAll
  File "queueHandler.pyc", line 50, in flushQueue
  File "scriptHandler.pyc", line 166, in _queueScriptCallback
  File "scriptHandler.pyc", line 208, in executeScript
  File "editableText.pyc", line 218, in script_caret_moveByLine
  File "editableText.pyc", line 163, in _caretMovementScriptHelper
  File "NVDAObjects\behaviors.pyc", line 175, in _caretScriptPostMovedHelper
  File "editableText.pyc", line 149, in _caretScriptPostMovedHelper
  File "speech\__init__.pyc", line 1087, in speakTextInfo
  File "speech\types.pyc", line 42, in __iter__
  File "speech\__init__.pyc", line 1127, in getTextInfoSpeech
  File "NVDAObjects\window\winword.pyc", line 717, in getTextWithFields

And for steps leading up to and including 3.1, see these thread stacks:

Python stack for thread 4108:
  File "C:\Users\mick\programming\git\nvda\source\NVDAHelper.py", line 401, in nvdaControllerInternal_typedCharacterNotify
    eventHandler.queueEvent("typedCharacter",focus,ch=ch)
  File "C:\Users\mick\programming\git\nvda\source\eventHandler.py", line 44, in queueEvent
    queueHandler.queueFunction(queueHandler.eventQueue,_queueEventCallback,eventName,obj,kwargs)
  File "C:\Users\mick\programming\git\nvda\source\queueHandler.py", line 37, in queueFunction
    queue.put_nowait((func,args,kwargs))
  File "C:\Program Files (x86)\Python37-32\lib\queue.py", line 190, in put_nowait
    return self.put(item, block=False)
  File "C:\Program Files (x86)\Python37-32\lib\queue.py", line 151, in put
    self.not_empty.notify()
  File "C:\Program Files (x86)\Python37-32\lib\threading.py", line 348, in notify
    waiters_to_notify = _deque(_islice(all_waiters, n))
  File "C:\Users\mick\programming\git\nvda\source\comtypesMonkeyPatches.py", line 101, in newCpbDel
    _cpbDel(self)
  File "C:\Users\mick\programming\git\nvda\include\comtypes\comtypes\__init__.py", line 918, in __del__
    self.Release()
  File "C:\Users\mick\programming\git\nvda\include\comtypes\comtypes\__init__.py", line 1172, in Release
    return self.__com_Release()
  File "C:\Users\mick\programming\git\nvda\source\comtypesMonkeyPatches.py", line 26, in __call__
    return super().__call__(*args,**kwargs)
Python stack for thread 7632:
 File "C:\Program Files (x86)\Python37-32\lib\threading.py", line 890, in _bootstrap
   self._bootstrap_inner()
 File "C:\Program Files (x86)\Python37-32\lib\threading.py", line 926, in _bootstrap_inner
   self.run()
 File "C:\Program Files (x86)\Python37-32\lib\threading.py", line 870, in run
   self._target(*self._args, **self._kwargs)
 File "C:\Users\mick\programming\git\nvda\source\winInputHook.py", line 79, in hookThreadFunc
   while windll.user32.GetMessageW(byref(msg),None,0,0):
 File "C:\Users\mick\programming\git\nvda\source\winInputHook.py", line 54, in keyboardHook
   if not keyDownCallback(kbd.vkCode,kbd.scanCode,bool(kbd.flags&LLKHF_EXTENDED),bool(kbd.flags&LLKHF_INJECTED)):
 File "C:\Users\mick\programming\git\nvda\source\keyboardHandler.py", line 199, in internal_keyDownEvent
   inputCore.manager.executeGesture(gesture)
 File "C:\Users\mick\programming\git\nvda\source\inputCore.py", line 442, in executeGesture
   queueHandler.queueFunction(queueHandler.eventQueue, speech.cancelSpeech)
 File "C:\Users\mick\programming\git\nvda\source\queueHandler.py", line 37, in queueFunction
   queue.put_nowait((func,args,kwargs))
 File "C:\Program Files (x86)\Python37-32\lib\queue.py", line 190, in put_nowait
   return self.put(item, block=False)
 File "C:\Program Files (x86)\Python37-32\lib\queue.py", line 132, in put
   with self.not_full:
 File "C:\Program Files (x86)\Python37-32\lib\threading.py", line 241, in __enter__
   return self._lock.__enter__()
Python stack for thread 1836:
  File "source/nvda.pyw", line 215, in <module>
  File "C:\Users\mick\programming\git\nvda\source\core.py", line 545, in main
    app.MainLoop()
  File "C:\Users\mick\programming\git\nvda\include\wxPython\wx\core.py", line 2134, in MainLoop
    rv = wx.PyApp.MainLoop(self)
  File "C:\Users\mick\programming\git\nvda\source\gui\__init__.py", line 1049, in Notify
    self.run()
  File "C:\Users\mick\programming\git\nvda\source\core.py", line 515, in run
    queueHandler.pumpAll()
  File "C:\Users\mick\programming\git\nvda\source\queueHandler.py", line 83, in pumpAll
    flushQueue(eventQueue)
  File "C:\Users\mick\programming\git\nvda\source\queueHandler.py", line 46, in flushQueue
    if not queue.empty():
  File "C:\Program Files (x86)\Python37-32\lib\queue.py", line 107, in empty
    with self.mutex:

We can mitigate some of the issues for 3.1 by switching from Queue.Queue to queue.SimpleQueue, see #11369 .
But then we still have the possibility NVDA will freeze within the lock for eventHandler.queueEvent.

The root issue here is that COM objects are trying to be released at random points in random threads due to Python's garbage collector.

A proposed fix would be to disable Python's automatic garbage collection in NVDA, and instead manually call gc.collect in predictable places; Possibly at the end of NvDA's core cycle in its main thread.

Disadvantages of this proposal could be:

  • If there is a lot of background thread activity but NVDA's core does not need to wake, the garbage collector will not be run as much as it used to. This could be mitigated by ensuring that the core does run at least once every few seconds.
  • If a COM object was created in a background thread, and is no longer referenced, it will now be cleaned up by the garbage collector in NVDA's main thread, not the background thread. But, I still think this is still better than it being completely unpredictable.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions