nvda icon indicating copy to clipboard operation
nvda copied to clipboard
verified publisher icon nvaccess

Access violation whenever WasapiWavePlayer._idleCheck function is called every few seconds

Open Neurrone opened this issue 2 years ago • 21 comments

/Cc @jcsteh

Steps to reproduce:

Unknown, I was using NVDA randomly. I noticed I was reading something on Discord though, in case that is significant.

Actual behavior:

Error sounds play continually and the following is logged every few seconds:

ERROR - queueHandler.flushQueue (23:17:03.837) - MainThread (12112):
Error in func WasapiWavePlayer._idleCheck
Traceback (most recent call last):
  File "queueHandler.pyc", line 64, in flushQueue
  File "nvwave.pyc", line 1032, in _idleCheck
OSError: exception: access violation reading 0x00140021
ERROR - queueHandler.flushQueue (23:17:08.871) - MainThread (12112):
Error in func WasapiWavePlayer._idleCheck
Traceback (most recent call last):
  File "queueHandler.pyc", line 64, in flushQueue
  File "nvwave.pyc", line 1032, in _idleCheck
OSError: exception: access violation reading 0x00140021

This keeps happening, with the memory address being different each time.

Switching away from Discord to the desktop didn't resolve it.

Restarting NVDA resolved the issue.

Expected behavior:

The function should work normally without errors. The error sounds won't play in a stable build but this doesn't seem good.

NVDA logs, crash dumps and other attachments:

System configuration

NVDA installed/portable/running from source:

Installed

NVDA version:

alpha-30811,e71916d0 (2024.2.0.30811)

Windows version:

Windows 11 23H2 (OS Build 22631.3007)

Name and version of other software in use when reproducing the issue:

Other information about your system:

I'm using a laptop with Shadow Stack mitigations enabled, a ThinkPad P16s Gen 2 AMD with a Ryzen pro 7840U.

Other questions

Does the issue still occur after restarting your computer?

Unknown, haven't observed this happening a second time

Have you tried any other versions of NVDA? If so, please report their behaviors.

Not yet, only seen this happen once so far

If NVDA add-ons are disabled, is your problem still occurring?

Unknown

Does the issue still occur after you run the COM Registration Fixing Tool in NVDA's tools menu?

Unknown

Neurrone avatar Feb 02 '24 15:02 Neurrone

I will leave this issue open until #16099 is merged. Can you test it? I believe the pull request I mentioned will fix this issue.

CC: @mltony

OzancanKaratas avatar Feb 02 '24 17:02 OzancanKaratas

It is difficult for me to reproduce this, so I might just wait for the fix to be merged and report back if it happens even after the PR is merged.

I'm good to close the issue once it is merged.

Neurrone avatar Feb 04 '24 15:02 Neurrone

I doubt #16099 will fix this. I see this very rarely, but I don't understand what's causing it yet.

jcsteh avatar Feb 04 '24 23:02 jcsteh

I'll leave this issue open then.

Neurrone avatar Feb 05 '24 13:02 Neurrone

I just saw this again and tried to debug it.

  1. Calling .close() on the problematic WasapiWavePlayer instance threw an AUDCLNT_E_DEVICE_INVALIDATED exception, but the errors every 10 seconds stopped. This suggests that close() reached the point where it set _lastActiveTime to None, so I guess _setVolumeFromConfig failed.
  2. AUDCLNT_E_DEVICE_INVALIDATED suggests that we got into this state because a device got disconnected or changed state while it was becoming idle. I didn't disconnect or connect any devices when this happened, so I don't really follow this. Unless this instance was from a long time ago, but then I don't understand why it wasn't cleaned up back then.
  3. Calling wasPlay_stop directly on the _instance pointer didn't throw an exception. This suggests that the C++ WasapiPlayer instance is still alive, which means that the access violation isn't caused by us holding on to a dead WavePlayer instance. That is good; I was somewhat worried about that possibility because I just couldn't understand how it could be possible.
  4. wasPlay_idle calls WasapiPlayer::sync and then stop. Per 1), we know that stop is fine, so I tried calling wasPlay_sync directly. It threw an access violation. So, something weird is going on in WasapiPlayer::sync. Looking at the code, I can't imagine what that could be.
  5. I tried to poke at this in WinDBG, but because of the difficulties and instability associated with debugging a screen reader with another screen reader (I even ran WinDBG as admin and used Narrator), I eventually lost my session and thus my Python console history. So, everything above is from memory, which means there might be some inaccuracy.

This does give us some more info, but it isn't enough to come up with a fix. I think WasapiPlayer::sync is the place to start looking, but we really need to know exactly where that method fails, which means catching this in WinDBG when it happens. Given how rare this is and how difficult it is to run WinDBG against NVDA as an NVDA user without some really careful multi-machine setup, I don't hold out much hope of being able to manage this any time soon.

jcsteh avatar Apr 11 '24 01:04 jcsteh

  1. AUDCLNT_E_DEVICE_INVALIDATED suggests that we got into this state because a device got disconnected or changed state while it was becoming idle.

I just tried:

  1. Connecting my headset.
  2. Calling tones.beep.
  3. Disconnecting my headset before 10 seconds elapsed.
  4. Confirming that tones.player._lastActiveTime was not None before 10 seconds elapsed.
  5. Confirming that tones.player._lastActiveTime became None (due to idle check) after a few seconds.

So, this isn't as simple as a device being invalidated while it is becoming idle. :(

jcsteh avatar Apr 11 '24 01:04 jcsteh

Saw this again and managed to get a bit further with WinDBG. Unfortunately, because of the usual problems with debugging, I couldn't copy/paste the debugging session before I lost everything. I was able to discover that it is indeed WasapiPlayer::sync that is crashing, but specifically this line of WasapiPlayer::getPlayPos:

HRESULT hr = clock->GetPosition(&pos, nullptr);

That suggests that clock is a dangling pointer, but that just shouldn't happen. clock is a CComPtr, which means we can't have accidentally released it without it being null. There is nowhere in our code which calls clock->Release() directly. Even if we have a reference to an old IAudioClock instance which Windows has discarded (e.g. because the device was invalidated), COM rules dictate that Windows isn't allowed to delete that object until we've released our reference.

jcsteh avatar Apr 12 '24 23:04 jcsteh

@jcsteh , I found that before debugging NVDA I need to do watchdog.terminate() - otherwise watchdog thinks the process is stuck and does something that interferes with COM objects. But I was debugging python side of NVDA, not sure whether this would apply to this case. But I thought since you observed dead COM objects - maybe watchdog is to blame?

mltony avatar Apr 13 '24 00:04 mltony

Thanks for the thought. watchdog will try to cancel COM calls, true, but that can only impact cross-process COM proxies. WASAPI COM objects aren't COM proxies as far as I'm aware. But also, this failure had already occurred before I started debugging; I only started debugging because the idle check errors began.

jcsteh avatar Apr 13 '24 00:04 jcsteh

Was this fixed by #16909? Can you reproduce this on master still?

seanbudd avatar Aug 12 '24 23:08 seanbudd

The exception no longer gets logged every 10 seconds when it occurs. It just gets logged once. However, the underlying problem still exists, and given that it's an access violation, it really should be fixed properly if/when the real cause can be tracked down. #16909 is a very hacky bandaid, not a real fix.

jcsteh avatar Aug 13 '24 05:08 jcsteh

Just had this issue again:

  • NVDA version: source of one of the last alphas, i.e.: source-master-4de8af7 x86
  • NVDA went completely frozen; just watchdog error sound about each 10 seconds; I have had to restart NVDA with control+alt+n.
  • NVDA was run with add-ons enabled.

The error is the following:

ERROR - nvwave.WasapiWavePlayer._idleCheck (09:33:52.945) - MainThread (12140):
Error calling wasPlay_idle
Traceback (most recent call last):
  File "nvwave.py", line 1085, in _idleCheck
    NVDAHelper.localLib.wasPlay_idle(player._player)
OSError: exception: access violation reading 0x00140010

The watchdog produces the following stack information:

INFO - watchdog.waitForFreezeRecovery (09:33:58.968) - watchdog (11108):
Starting freeze recovery after 6.013612700000522 seconds.
DEBUGWARNING - watchdog.waitForFreezeRecovery (09:33:59.012) - watchdog (11108):
Listing stacks for Python threads:
Python stack for thread 9596 (nvwave.playWaveFile(suggestionsClosed.wav)):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 744, in play
    fileWavePlayer = None
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 884, in __del__
    NVDAHelper.localLib.wasPlay_destroy(self._player)

Python stack for thread 12032 (nvwave.playWaveFile(suggestionsOpened.wav)):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 744, in play
    fileWavePlayer = None
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 884, in __del__
    NVDAHelper.localLib.wasPlay_destroy(self._player)

Python stack for thread 18036 (Dummy-2950):
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\.venv\Lib\site-packages\comtypes\_comobject.py", line 190, in call_without_this
    _error(
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\logging\__init__.py", line 1518, in error
    self._log(ERROR, msg, args, **kwargs)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\logging\__init__.py", line 1634, in _log
    self.handle(record)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\logging\__init__.py", line 1644, in handle
    self.callHandlers(record)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\logging\__init__.py", line 1706, in callHandlers
    hdlr.handle(record)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\userConfig\addons\nvdaDevTestToolbox\globalPlugins\ndtt\beepError.py", line 74, in myHandle
    return builtinHandle(fh, record, *args, **kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\logHandler.py", line 401, in handle
    getOnErrorSoundRequested().notify()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\extensionPoints\__init__.py", line 56, in notify
    callWithSupportedKwargs(handler, **kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\extensionPoints\util.py", line 216, in callWithSupportedKwargs
    return func(*boundArguments.args, **boundArguments.kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 1150, in playErrorSound
    playWaveFile(os.path.join(globalVars.appDir, "waves", "error.wav"))
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 721, in playWaveFile
    fileWavePlayer.stop()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 884, in __del__
    NVDAHelper.localLib.wasPlay_destroy(self._player)

Python stack for thread 6816 (Thread-1658):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\userConfig\addons\outlookExtended\appModules\outlook\__init__.py", line 477, in run
    sleep(0.5)

Python stack for thread 7556 (ThreadPoolExecutor-1_0):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\concurrent\futures\thread.py", line 81, in _worker
    work_item = work_queue.get(block=True)

Python stack for thread 5852 (Thread-769):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\userConfig\addons\IBMTTS\synthDrivers\_ibmeci.py", line 382, in run
    func, args, kwargs = callbackQueue.get()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\queue.py", line 171, in get
    self.not_empty.wait()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 327, in wait
    waiter.acquire()

Python stack for thread 18104 (Thread-768):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\userConfig\addons\IBMTTS\synthDrivers\_ibmeci.py", line 180, in run
    user32.GetMessageA(byref(msg), 0, 0, 0)

Python stack for thread 18396 (hwIo.ioThread.IoThread):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\hwIo\ioThread.py", line 264, in run
    ctypes.windll.kernel32.SleepEx(winKernel.INFINITE, True)

Python stack for thread 10740 (watchdog.CancellableCallThread.execute(<_FuncPtr object at 0x00EFDD50>)):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\watchdog.py", line 428, in run
    self._executeEvent.wait()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 629, in wait
    signaled = self._cond.wait(timeout)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 327, in wait
    waiter.acquire()

Python stack for thread 11108 (watchdog):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\watchdog.py", line 163, in _watcher
    waitForFreezeRecovery(waitedSince)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\watchdog.py", line 170, in waitForFreezeRecovery
    stacks = logHandler.getFormattedStacksForAllThreads()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\logHandler.py", line 64, in getFormattedStacksForAllThreads
    stack = "".join(traceback.format_stack(frame))

Python stack for thread 11416 (winInputHook):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\winInputHook.py", line 108, in hookThreadFunc
    while windll.user32.GetMessageW(byref(msg), None, 0, 0):  # noqa: F405

Python stack for thread 13968 (UIAHandler.UIAHandler.MTAThread):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 982, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\UIAHandler\__init__.py", line 546, in MTAThreadFunc
    func = self.MTAThreadQueue.get()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\queue.py", line 171, in get
    self.not_empty.wait()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 327, in wait
    waiter.acquire()

Python stack for thread 8432 (ScheduleThread):
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1002, in _bootstrap
    self._bootstrap_inner()
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\utils\schedule.py", line 84, in run
    time.sleep(cls.SLEEP_INTERVAL_SECS)

Python stack for thread 12140 (MainThread):
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvda.pyw", line 526, in <module>
    core.main()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\core.py", line 1021, in main
    app.MainLoop()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\.venv\Lib\site-packages\wx\core.py", line 2262, in MainLoop
    rv = wx.PyApp.MainLoop(self)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\core.py", line 964, in Notify
    queueHandler.pumpAll()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\queueHandler.py", line 102, in pumpAll
    flushQueue(eventQueue)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\queueHandler.py", line 69, in flushQueue
    log.exception(f"Error in func {func.__qualname__}")
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\logHandler.py", line 332, in exception
    self._log(level, msg, (), exc_info=exc_info, **kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\logHandler.py", line 262, in _log
    res = super()._log(level, msg, args, exc_info, extra)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\logging\__init__.py", line 1634, in _log
    self.handle(record)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\logging\__init__.py", line 1644, in handle
    self.callHandlers(record)
  File "C:\Users\Cyrille\AppData\Local\Programs\Python\Python311-32\Lib\logging\__init__.py", line 1706, in callHandlers
    hdlr.handle(record)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\userConfig\addons\nvdaDevTestToolbox\globalPlugins\ndtt\beepError.py", line 74, in myHandle
    return builtinHandle(fh, record, *args, **kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\logHandler.py", line 401, in handle
    getOnErrorSoundRequested().notify()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\extensionPoints\__init__.py", line 56, in notify
    callWithSupportedKwargs(handler, **kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\extensionPoints\util.py", line 216, in callWithSupportedKwargs
    return func(*boundArguments.args, **boundArguments.kwargs)
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 1150, in playErrorSound
    playWaveFile(os.path.join(globalVars.appDir, "waves", "error.wav"))
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 721, in playWaveFile
    fileWavePlayer.stop()
  File "C:\Users\Cyrille\Documents\DevP\GIT\nvda\source\nvwave.py", line 884, in __del__
    NVDAHelper.localLib.wasPlay_destroy(self._player)

CyrilleB79 avatar Oct 11 '24 07:10 CyrilleB79

@seanbudd given the freeze, could the priority be raised up to:

  • P2 - Crash, freeze, instability or performance issue that affects a small subset of users. It may be uncommon or difficult to reproduce
  • Or P3 - Crash, freeze, instability or performance issue that affects one user, i.e. it cannot be reproduced by anyone else?

I do not know if other people experimenting this issue have also experimented the freeze.

CyrilleB79 avatar Oct 11 '24 08:10 CyrilleB79

I still see it sometimes, so it affects more than one person.

Neurrone avatar Oct 11 '24 08:10 Neurrone

@Neurrone, do you also experiment the freeze or only the logged error?

CyrilleB79 avatar Oct 11 '24 08:10 CyrilleB79

I see the logged error, which indicates a freeze. I'll have to wait till this happens again to see, its been a while since I had this happen to me.

Neurrone avatar Oct 11 '24 08:10 Neurrone

@Neurrone, the wasPlay_idle error doesn't necessarily indicate a freeze. If you aren't experiencing a freeze when you see the error, there isn't a freeze.

@CyrilleB79, it's difficult to be sure whether the error and the freeze were related. In your log, I see the main thread is frozen in wasPlay_destroy, but the error is related to wasPlay_idle. I guess it's possible that the player failing to idle is the fileWavePlayer that we subsequently freeze while trying to destroy, but honestly, if the access violation were the cause of the freeze, I'd expect a crash, not a freeze. The short of it is that obviously, this is a valid freeze bug that ideally needs to be fixed, but I'm not entirely convinced it isn't a different bug.

jcsteh avatar Oct 11 '24 09:10 jcsteh

@CyrilleB79 have you seen the freeze accompanying this specific error more than once?

jcsteh avatar Oct 11 '24 09:10 jcsteh

@CyrilleB79 have you seen the freeze accompanying this specific error more than once?

Yes, a second time today. But it was on the same machine, still with with add-ons enabled and again with NVDA run from source. Anyway, I have still had the error related to wasPlay_idle, followed by the freeze showing the main thread frozen in wasPlay_destroy, as well as other audio threads in the same function.

I'll let you know if I encounter the freeze either on another machine, or with add-ons disabled, or when running installed NVDA.

CyrilleB79 avatar Oct 11 '24 20:10 CyrilleB79

Okay. The fact that you've seen these two things correlated more than once would seem to suggest that it was not a coincidence and that they are likely to be related. This certainly isn't impossible: an access violation definitely spells unpredictable trouble, which is why I didn't want this bug closed after I worked around the continual errors.

jcsteh avatar Oct 13 '24 23:10 jcsteh

Changed to P3 as this is a freeze that is extremely hard to reproduce

seanbudd avatar Oct 14 '24 03:10 seanbudd

Just saw this stack trace with version alpha-34551,05aeb3d1 (2025.1.0.34551). Not sure if this is related to the ones posted earlier.

I gave up and restarted NVDA after around 20 seconds after it never recovered from this freeze.

ERROR - nvwave.WasapiWavePlayer._idleCheck (20:10:54.846) - MainThread (11180):
Error calling wasPlay_idle
Traceback (most recent call last):
  File "nvwave.pyc", line 1085, in _idleCheck
OSError: exception: access violation writing 0x00000014
ERROR - queueHandler.flushQueue (20:10:54.855) - MainThread (11180):
Error in func WasapiWavePlayer._idleCheck
Traceback (most recent call last):
  File "queueHandler.pyc", line 67, in flushQueue
  File "nvwave.pyc", line 1078, in _idleCheck
  File "weakref.pyc", line 247, in values
RuntimeError: dictionary changed size during iteration
ERROR - logHandler._threadExceptHook (20:28:13.031) - Thread-3 (11804):
Exception in thread Thread-3:
Traceback (most recent call last):
  File "threading.pyc", line 1045, in _bootstrap_inner
  File "C:\Users\Dickson\AppData\Roaming\nvda\addons\IBMTTS\synthDrivers\_ibmeci.py", line 195, in run
    player.stop()
  File "nvwave.pyc", line 978, in stop
  File "_ctypes/callproc.c", line 1000, in GetResult
OSError: [WinError -2004287477] Windows Error 0x8889000b
INFO - watchdog.waitForFreezeRecovery (20:28:15.037) - watchdog (12052):
Starting freeze recovery after 2.0022337000000334 seconds.

Neurrone avatar Nov 29 '24 12:11 Neurrone

@CyrilleB79, @Neurrone, @OzancanKaratas are you still seeing this issue in NVDA 2025.3.1 or in the last 64bit alpha on Windows 11 25 H2?

Adriani90 avatar Nov 18 '25 23:11 Adriani90

@Adriani90 I do not remember to have seen this recently. I'll pay attention to it in the next days / weeks and report back if it occurs again. Note that I am not running Windows 11 25H2, but 24H2 or 23H2 (depending on the used computer).

CyrilleB79 avatar Nov 19 '25 07:11 CyrilleB79