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

NVDA freezes when using wasapi #15752

Closed
beqabeqa473 opened this issue Nov 7, 2023 · 28 comments · Fixed by #15754
Closed

NVDA freezes when using wasapi #15752

beqabeqa473 opened this issue Nov 7, 2023 · 28 comments · Fixed by #15754
Milestone

Comments

@beqabeqa473
Copy link
Contributor

beqabeqa473 commented Nov 7, 2023

cc @jcsteh

Steps to reproduce:

There is a way of reproducing this when using Newfon or RHVoice synth drivers
install one of the listed addons.
enter the following code in NVDA console
import synthDriverHandler; [synthDriverHandler.setSynth(synthDriverHandler.getSynth().name) for i in range(20)]

Actual behavior:

NVDA is freezing and logging lots of errors.
Player is becoming None and idle cannot be called

Expected behavior:

NVDA should be stable.

NVDA logs, crash dumps and other attachments:

System configuration

NVDA installed/portable/running from source:

Running from source, but reproduceable on 2023.3 Release version

NVDA version:

Master

Windows version:

Windows 10 22h2

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

Other information about your system:

Other questions

Does the issue still occur after restarting your computer?

Yes

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

Yes, 2023.3 behaves the same

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

Yes, but easily reproduceable with Newfon or RHVoice synth

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

Yes

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

A log would be helpful.

When are you seeing this in real usage? I accept that this shouldn't happen, but the code you've provided (while perhaps helpful to reproduce) is pretty extreme and that situation would never actually occur in real usage.

@beqabeqa473
Copy link
Contributor Author

It is happening in real usage, but is not always reproduceable. This is a way to 100% reproduce an issue

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

Sure. Can you give an example of when this has happened in real usage and how often? It's difficult to prioritise without being able to assess the actual user impact.

@beqabeqa473
Copy link
Contributor Author

It is randomly reproduceable, for example i was talking and didn't touching a keyboard, some large text came to nvda and this bug was reproduced. I cannot give a specific steps when it can be 100% reproduced. But This way is causing the same set of exceptions.

@beqabeqa473
Copy link
Contributor Author

nvda.log

@beqabeqa473
Copy link
Contributor Author

Imagine a situation, You are not near the computer, This bug happened, because of something bad in wasapi when speaking large text, you are returning and your disk drive is full of logs caused by this bug.

@a11cf0
Copy link

a11cf0 commented Nov 7, 2023

It is randomly reproduceable, for example i was talking and didn't touching a keyboard, some large text came to nvda and this bug was reproduced. I cannot give a specific steps when it can be 100% reproduced. But This way is causing the same set of exceptions.

I can confirm this. On my system this happens a lot when working with long passages of text, especially when navigating or quickly interrupting speech. The errors are the same. All synths including eSpeak NG are affected. However, I don't now any other ways to predictably reproduce this, except that described above.

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

Player is becoming None and idle cannot be called

I don't see this anywhere in your log. Also, this sounds more like #15681, which is now fixed. Do you have another log showing this?

@beqabeqa473
Copy link
Contributor Author

It was only once, when somehow i was able to keep synthesizer talking while logging errors, and with these errors, i discovered a place where None type object has no attribute idle, but now it is not reproduceable anymore. i tried lots of times but no result. It maybe was from another log snippet, but it still was in latest master.
You were saying in your last pr that "Verified that everything still works with this change. I can't reproduce this reliably enough to actually test the workaround in practice." This issue is also very hard to reproduce when you want to do it, but it is reproduceable very often when getting large texts, just navigating through interface. I just found a way, where you could reproduce this issue yourself.

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

Sure. I'm not suggesting your issue is not valid. I just want as much information as I can get, because at this point, I have no idea what is causing it.

Note that my other pull request is marked as draft until I can verify the fix, just in case you feel I'm not applying the same rigor to your issues as I am to my own.

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

If you find some way of reproducing this in core, even with Python console code, please let me know. I'd really rather not dabble with add-ons here, partly because it adds another entire piece to an already very complicated puzzle i have to try to understand in order to diagnose the problem.

@beqabeqa473
Copy link
Contributor Author

ok, i was able to reproduce it without addons, but it is still not real usage example. I don't know what to do to ensure this is reproduceable everytime i want.

import speech
from time import sleep

def test(amount):
for i in range(amount):
speech.speak(["dsfsfsfdbvcbcvxbcvdfgfdgdfgertretereethghfghbcvb"])
sleep(0.5)
speech.cancelSpeech()

test(50)

It is happening with espeak also.

I have no idea for now how to reproduce it with another way, but it is really boring seeing this.

I was not opening an issue, because there were some of them already, and i was hoping this would be fixed with these bugs, but no.

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

I wasn't able to reproduce with that snippet unfortunately. Thank you for your efforts, though.

I guess you can disable WASAPI for now, since the toggle is still present. If we continue to see more regressions, it might be worth considering flipping this off by default again in the next release or maybe even reverting it altogether.

@zstanecic
Copy link
Contributor

zstanecic commented Nov 7, 2023 via email

@cyrmax
Copy link

cyrmax commented Nov 7, 2023

Hello there!
I was able to reproduce the issue twice: the first time with this oneliner from @beqabeqa473
import synthDriverHandler; [synthDriverHandler.setSynth(synthDriverHandler.getSynth().name) for i in range(20)]
And the second time when reading his comment with another code to reproduce the bug.
Here is my NVDA log.
NVDA was freezed not for several seconds but for a minute or so.
This is critical I think.
nvda.log

@cyrmax
Copy link

cyrmax commented Nov 7, 2023

@jcsteh reverting or disabling wasapi is not a good solution at all.
It looks like ignoring the problem and not solving it.
For me wasapi is essential because of faster response time and because of an ability to set sounds volume separately from TTS volume.
I think that for most part of users situation is the same or similar.

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

It's not ignoring the problem at all. If WASAPI is causing too many critical issues, no one other than me can fix them, and I don't have sufficient time to diagnose and fix them, it's not really a sustainable situation.

@beqabeqa473
Copy link
Contributor Author

Adjusting volume of sounds is the only thing because of that I am using wasapi. I would be happy to use winmm, if there would be such possibility in winmm player.

Lots of users were waiting to implement of #1409 and reverting of that or continuing to experience this issue is not good at all.

@cyrmax
Copy link

cyrmax commented Nov 7, 2023

Another successfull reproduction of this issue. Now with Espeak-NG. Looks like it could be reproduced when typing text or reading text by characters at very fast speed.
Here is another NVDA log, now with all debug messages.
I was just trying to type a command in WSL terminal and NVDA freezed for aprox 5 seconds with the same error.
nvda2.log

@zstanecic
Copy link
Contributor

zstanecic commented Nov 7, 2023 via email

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

Well, for now, I cannot fathom how the code can end up in this state. So, until I or someone else can figure it out, we either need to live with this issue or turn it off/revert it so users don't experience the problem. There is literally no other choice.

From what I can see:

  1. We put the player into the instances dict as soon as it is created. There can't be an exception between those two points.
  2. In the destructor, we remove the player from the instances dict as soon as we destroy it.
  3. As soon as we do that, we set the player handle to None. We also return early in the destructor if the handle is None. That means this is not caused by the destructor running twice.

@zstanecic
Copy link
Contributor

zstanecic commented Nov 7, 2023 via email

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

It looks like a weakref callback might run before __del__ in some cases; e.g. if the object is garbage collected rather than being destroyed immediately due to its ref count dropping to 0. I don't know why we would garbage collect a WasapiWavePlayer; there shouldn't be any cycles. Still, if I'm correct about the cause of the issue, it's not unreasonable to just ignore the exception.

@beqabeqa473
Copy link
Contributor Author

Then it shouldn't be garbage collected.

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

Actually, the correct fix is to just not explicitly remove the key, since it will be implicitly removed by WeakValueDictionary. That's assuming this is the real problem and not just a symptom of some other problem that isn't obvious from these logs.

@jcsteh
Copy link
Contributor

jcsteh commented Nov 7, 2023

I've just pushed a try build which should be done in about an hour. (You'll want to download the .exe file from that page when it appears.) Please test and let me know if that fixes the issue... or what else it does.

@beqabeqa473
Copy link
Contributor Author

I will checkout your branch now

@beqabeqa473
Copy link
Contributor Author

Thanks @jcsteh. I can confirm, that bug is not reproduceable anymore with the way i've provided in the issue description

seanbudd pushed a commit that referenced this issue Nov 7, 2023
…nces map in the destructor. (#15754)

Fixes #15752.

Summary of the issue:
Some users sometimes see errors like this in their logs, accompanied by long freezes:

ERROR - stderr (15:18:17.518) - MainThread (29504):
Exception ignored in:
ERROR - stderr (15:18:17.529) - MainThread (29504):
<function WasapiWavePlayer.__del__ at 0x0467A6B8>
ERROR - stderr (15:18:17.950) - MainThread (29504):
Traceback (most recent call last):
ERROR - stderr (15:18:18.392) - MainThread (29504):
  File "nvwave.pyc", line 843, in __del__
ERROR - stderr (15:18:18.830) - MainThread (29504):
  File "weakref.pyc", line 145, in __delitem__
ERROR - stderr (15:18:18.843) - MainThread (29504):
KeyError
ERROR - stderr (15:18:18.855) - MainThread (29504):
:
ERROR - stderr (15:18:19.283) - MainThread (29504):
80057872
Description of user facing changes
NVDA no longer sometimes freezes when speaking a large amount of text.

Description of development approach
Previously, WasapiWavePlayer's __del__ method removed itself from the _instances map. However, a WeakValueDictionary actually removes the reference itself when the object dies. A weakref callback can run before __del__ in some cases, which would mean that the item was already removed, resulting in this KeyError.

To fix this, we just don't explicitly remove the item and rely entirely on WeakValueDictionary to do this.
@nvaccessAuto nvaccessAuto modified the milestone: 2024.1 Nov 7, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
6 participants