Skip to content

nvwave: Fix occasional exception related to close timer.#11505

Closed
jcsteh wants to merge 1 commit into
nvaccess:masterfrom
jcsteh:nvwaveCloseException
Closed

nvwave: Fix occasional exception related to close timer.#11505
jcsteh wants to merge 1 commit into
nvaccess:masterfrom
jcsteh:nvwaveCloseException

Conversation

@jcsteh

@jcsteh jcsteh commented Aug 17, 2020

Copy link
Copy Markdown
Contributor

Link to issue number:

Fixes #11482. Fixes #11490.

Summary of the issue:

Occasional exceptions from nvwave, particularly when switching synthesisers.

Description of how this pull request fixes the issue:

The idle close timer must be started on the main thread.
However, it's possible that the player might be closed while the timer start call is waiting to run.
Previously, this would cause an exception when the timer expired because we'd try to close when we were already closed.
To fix this, we now check (on the main thread) if the player is closed, and if it is, we don't start the timer.

Testing performed:

  1. Ensured that the device is still being closed on idle as expected by adding a debugging beep to _close().
  2. Switched synthesisers as described in Traceback occurs when switching synths in latest alpha #11482. No exception. However, I was never able to reproduce the original problem, so this doesn't count for much. We should probably have someone who experiences this verify the fix in a try build.

The idle close timer must be started on the main thread.
However, it's possible that the player might be closed while the timer start call is waiting to run.
Previously, this would cause an exception when the timer expired because we'd try to close when we were already closed.
To fix this, we now check (on the main thread) if the player is closed, and if it is, we don't start the timer.
@jcsteh jcsteh requested a review from feerrenrut August 17, 2020 11:16
@Mohamed00

Copy link
Copy Markdown

I was unable to reproduce the issue with the try build. #11490 is fixed as well.

@jcsteh

jcsteh commented Aug 17, 2020

Copy link
Copy Markdown
Contributor Author

Oh fascinating. I didn't expect it to fix #11490. I'll update the PR description. Thanks for testing.

@feerrenrut

Copy link
Copy Markdown
Contributor

@jcsteh I would like your opinion on the following:

Given that keeping the audio device "open" (or at least the audio API initialized) results in a significant performance improvement. Or at least the inverse, opening and closing the device results in a noticeable delay. I propose that we no longer close the device at all (except for changing output / shutdown etc).

The reasons for this:

  • Performance is improved in more situations. Eg after 12 seconds of non-usage, or 15, 30 etc
  • Simplify the code
  • Less potential for bugs, I believe there are still race conditions existing with the current timer approach.
  • Make exploring the idea of prepending or appending silence easier

I'm aware we will have to work around disconnected / reconnected devices. But other than that, do you have any specific concerns about keeping the device open, since you have a lot of background in this area of the code.

I'm surprised this fixes #11490, perhaps there was already 10 seconds after the last speech before the device was disconnected? I think this will need specific testing.

@jcsteh

jcsteh commented Aug 17, 2020

Copy link
Copy Markdown
Contributor Author

The original closeWhenIdle change was implemented in 03ae3f6:

Introduce a closeWhenIdle option to the constructor to close the output device when idle. This facilitates switching devices when the default audio output device changes. It also allows audio to finish playing correctly when playing to a Remote Desktop client.

I don't know how much we care about Remote Desktop audio now. The performance is pretty bad anyway, and we now have solutions like NVDA Remote and Unicorn which offer a far better experience. In addition, the delay in #11024 will break this anyway.

I'm aware we will have to work around disconnected / reconnected devices.

This is going to be the trickiest part of this proposal. I'm not sure how this can be managed. We do have a way of watching for hardware notifications now, but I believe changing the default device might also need us to take action, and that's not going to fire a hardware notification. (There are specific APIs to get audio device notifications, but we don't have code to watch for those yet, plus they don't map well to the old winmm API we're using.) In addition, you'll need to close all WavePlayers, but only when they're idle, since you can't close them while they're playing without losing audio.

* Less potential for bugs, I believe there are still race conditions existing with the current timer approach.

I'm not aware of any further race conditions, but I guess it's possible. On the other hand, safely closing all devices when audio devices change is likely to introduce a whole new set of bugs.

  • Make exploring the idea of prepending or appending silence easier

I don't really see how getting rid of closeWhenIdle makes this easier. On the contrary, you'll potentially need similar timer code to handle appending of silence (unless you just throw out a massive buffer of audio). Still, this doesn't really impact my overall opinion.

But other than that, do you have any specific concerns about keeping the device open, since you have a lot of background in this area of the code.

It's worth noting that we actually keep the audio device open once a tone is played by the tones module, until the next tone is played. This is because tones never calls WavePlayer.idle. So, we can pretty much eliminate any concerns about non-audible impacts of keeping the device open.

One thing to check is whether this breaks automatic system sleep, and that'll need to be checked on Windows 7 as well. If it does, that would have been true before if at least one tone was played, but the concern is that removing this code will make it impossible to fix that bug (if it exists).

@jcsteh

jcsteh commented Aug 17, 2020

Copy link
Copy Markdown
Contributor Author

I believe changing the default device might also need us to take action, and that's not going to fire a hardware notification.

Note that there are two cases that need to be tested here:

  1. Changing the system's default output device while NVDA is set to use the default output device.
  2. Changing the system's default output device while NVDA is set to use a specific output device (not the default). The reason for this test is that I vaguely recall that changing the system's default output device might renumber the other devices on the system. I'm not sure, though.

@feerrenrut

Copy link
Copy Markdown
Contributor

Thanks for all the information @jcsteh.

Perhaps we should merge this approach, while we look into removing the timer and fixing #11490 more generally.

I'm not aware of any further race conditions

I haven't gone through it with a fine comb, but the case I specifically noticed was:
When trying to open the device, if there is a pending close timer then cancelling the close timer is queued to the main thread. There is then a race between the timer being triggered and the timer being cancelled.

There also is a potential deadlock here. Open acquires the _waveout_lock, if there is a close timer pending, and we are already on the main thread, close is called immediately, it can't acquire the _waveout_lock. Though now I notice it is an RLock.

https://github.com/nvaccess/nvda/pull/11505/files#diff-ea1b000a4d25ba3adfccce3616353820R179

I don't really see how getting rid of closeWhenIdle makes this easier.

Only because more asynchronous shared state makes code harder to reason about. There will be a dependence between pushing silence and the device being open, if they both need async code, there are more variations in execution sequence.

@beqabeqa473

beqabeqa473 commented Aug 18, 2020 via email

Copy link
Copy Markdown
Contributor

@dpy013

dpy013 commented Aug 18, 2020

Copy link
Copy Markdown
Contributor

not fully related to this pr, but as discussion is going to way about improving performance, what do you think, won't it be better to change audio subsystem to wasapi? for example in reaper, and such software, wasapi has much less latency compared to other audio subsystems windows have.

On 8/18/20, Leonard de Ruijter @.***> wrote: @LeonarddeR approved this pull request. -- You are receiving this because you are subscribed to this thread. Reply to this email directly or view it on GitHub: #11505 (review)
-- with best regards beqa

I support switching from NVDA to WASAPI because this is the latest audio API (Windows 7/8/10/Vista).
thanks

feerrenrut added a commit that referenced this pull request Aug 20, 2020
This reverts commit 633435d.
Instead of using a timer to close the audio device we will keep it open.
The initial requirement for keeping the device open no longer applies
see #11505 (comment)
@LeonarddeR

Copy link
Copy Markdown
Collaborator

I've seen another interesting bug when running from source, probably a timing issue:

INFO - core.main (19:27:02.302) - MainThread (5052):
Using Windows version 10.0.20197 workstation
INFO - core.main (19:27:02.302) - MainThread (5052):
Using Python version 3.7.8 (tags/v3.7.8:4b47a5b6ba, Jun 28 2020, 07:55:33) [MSC v.1916 32 bit (Intel)]
INFO - core.main (19:27:02.302) - MainThread (5052):
Using comtypes version 1.1.7
INFO - core.main (19:27:02.302) - MainThread (5052):
Using configobj version 5.1.0 with validate version 1.0.1
ERROR - stderr (19:27:03.354) - nvwave.playWaveFile(start.wav) (9880):
Exception in thread nvwave.playWaveFile(start.wav):
Traceback (most recent call last):
  File "C:\Python37\lib\threading.py", line 926, in _bootstrap_inner
    self.run()
  File "C:\Python37\lib\threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "D:\Development\nvda\source\nvwave.py", line 292, in idle
    return self._idleUnbuffered()
  File "D:\Development\nvda\source\nvwave.py", line 307, in _idleUnbuffered
    self._closeTimer = wx.PyTimer(self._close)
  File "D:\Development\nvda\include\wxPython\wx\core.py", line 2191, in __init__
    Timer.__init__(self)
wx._core.PyNoAppError: The wx.App object must be created first!

This is explainable when the start sound plays before the wx app is actually there. Not a big issue but may be it's something you can look into as part of this pr?

feerrenrut added a commit that referenced this pull request Sep 1, 2020
Fixes #5172
Fixes #10721
Fixes #11482
Fixes #11490

### History
#5172
Some audio drivers/hardware take a long time to open the device and/or truncate the start/end of the audio.

#10721
Calling WaveOutOpen in the OneCore synth callback mysteriously blocks (and thus lags) for ~100 ms. Because we close the audio device on idle, we can trigger this problem. Although PR #11023 mostly fixed this, it's impossible (or at least very difficult) to resolve this completely from within the OneCore driver.

PR #11024 attempted to fix these issues by waiting 10 seconds before closing the audio device"

### Problem to solve
Subsequent to #11024, there are occasional exceptions from nvwave, particularly when switching synthesisers. In particular the following cases need to be handled smoothly:
- When using Microsoft Sound Mapper, NVDA should use the Windows default device (even if it changes)
- When the NVDA configured devices becomes invalid, nvWave should fall back to Microsoft Sound Mapper
- When the NVDA configured device becomes available again, NVDA should switch back to using it.
- Handle no audio device at all.

Since these issues needed to be fixed, and also:
- Closing and opening the audio device was originally introduced to support Remote Desktop audio, this is now better served by other solutions. 
- Performance is improved by keeping it open, using a timeout means that the lag is more rare, but will still occur.

### How it is solved
Instead, now don't close the device at all. As per the discussion:
#11505 (comment)

To fix issues with current / preferred device:
- nvWave now saves the preferred device when it is constructed.
- If using a device fails, it is considered unavailable, nvWave attempts to fall back to "Microsoft Sound Mapper".
- From my testing, using "Microsoft Sound Mapper" correctly handled changing the default device (Win 10 2004). It would be helpful if others could confirm, especially on different OS versions.
- During `_idleUnbuffered`
  - The current device is checked to see if it matches the preferred device.
  - The available devices are polled to see if the preferred device is available, if so it switches.
@feerrenrut

Copy link
Copy Markdown
Contributor

I'm going to close this given PR #11531 was merged.

@feerrenrut feerrenrut closed this Sep 1, 2020
@jcsteh jcsteh deleted the nvwaveCloseException branch May 25, 2026 04:04
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

NVDA seems to have lost the ability to recover from a lost audio device Traceback occurs when switching synths in latest alpha

6 participants