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

Infrequent crash in Firefox #11169

Closed
MarcoZehe opened this issue May 15, 2020 · 22 comments
Closed

Infrequent crash in Firefox #11169

MarcoZehe opened this issue May 15, 2020 · 22 comments

Comments

@MarcoZehe
Copy link
Contributor

Steps to reproduce:

There are no steps to reproduce. Sometimes, when working in Firefox, NVDA just falls silent, and braille stops outputting something. This is different from the RPC hang @jcsteh and I have been chasing for two years now. This is just NVDA suddenly going away. So there are no exact steps. But this is in the old log.

WARNING - watchdog._watcher (13:40:21.007) - watchdog (16560):
Core frozen in stack:
  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 1052, in Notify
  File "core.pyc", line 515, in run
  File "queueHandler.pyc", line 83, in pumpAll
  File "queueHandler.pyc", line 50, in flushQueue
  File "eventHandler.pyc", line 64, in _queueEventCallback
  File "eventHandler.pyc", line 208, in executeEvent
  File "eventHandler.pyc", line 241, in doPreGainFocus
  File "browseMode.pyc", line 1255, in event_treeInterceptor_gainFocus
  File "browseMode.pyc", line 56, in reportPassThrough
  File "nvwave.pyc", line 396, in playWaveFile
  File "nvwave.pyc", line 311, in stop
  File "nvwave.pyc", line 283, in _idleUnbuffered

Actual behavior:

Crash.

Expected behavior:

No crash.

System configuration

NVDA installed/portable/running from source:

Installed.

NVDA version:

version alpha-20206,dba33431

Windows version:

10 19H2.

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

Firefox Nightly 78, or Beta 77.

Other information about your system:

Focus Braille Display 5th generation connected.

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.

2020.1, same result after some time.

If addons are disabled, is your problem still occuring?

Yes.

Did you try to run the COM registry fixing tool in NVDA menu / tools?

Yes, but since all is working normally until the crash, nothing changed.

Info for @jcsteh , this also happened before the very last COM fix you put into Nightly this week. So it is not a side effect of that. The log suggests rather that something makes NVDA freeze.

@jcsteh
Copy link
Contributor

jcsteh commented May 15, 2020 via email

@Neurrone
Copy link

The freeze that I still see about once a week is the one that we discussed before where NVDA would appear to hang (taking away the ability to properly control the computer via keyboard) until Firefox is entirely closed before it goes back to normal.

@gregjozk
Copy link
Contributor

same problem.
sometimes I can recover NVDA but usually I must restart a computer.
It happens after computer is running 1+ days without a restart. I suspect, that combination of NVDA and firefox is a problem, because I have not meet this problem, when I continuously used other programs and browsers with firefox closed.
next time will paste a log.
just an observation: it happens quicker, if a computer went to sleep or to hybernate during the actual session.

@jcsteh
Copy link
Contributor

jcsteh commented May 18, 2020

The freeze that I still see about once a week is the one that we discussed before where NVDA would appear to hang (taking away the ability to properly control the computer via keyboard) until Firefox is entirely closed before it goes back to normal.

That's the "RPC hang" marco referred to here:
You can track and discuss that here: https://bugzilla.mozilla.org/show_bug.cgi?id=1572915

@gregjozk, I suspect you're seeing the RPC hang as well, rather than this audio issue... unless you're seeing the nvwave freeze in your log file as well.

@gregjozk
Copy link
Contributor

gregjozk commented May 18, 2020 via email

@Adriani90
Copy link
Collaborator

@MarcoZehe did you by chance sleep and unsleep your machine shortly before reproducing this issue?

@MarcoZehe
Copy link
Contributor Author

No, I had it running for at least 1 hour or so.

@bhavyashah
Copy link

When Firefox stops responding, NVDA always goes silent. I need to take sighted help to close Firefox or click the NVDA Desktop icon and after a few minutes of waiting and doing that and pressing Ctrl+Alt+N, I get everything back to normal. Is that the same as the crash being referred to in this ticket? Also, on an unrelated note, the Crash Hero add-on served me well in the past in gathering crash logs. It is unfortunate that it has not been updated to be Python 3 compatible.

@XLTechie
Copy link
Contributor

XLTechie commented Jun 20, 2020 via email

@jcsteh
Copy link
Contributor

jcsteh commented Jul 28, 2020

I saw this myself today. After some discussion with Mick, it occurred to me that this might be a Python gc COM release deadlock due to nvwave's use of locks. If that's the case, it's worth testing with the latest alpha of NVDA for two reasons:

  1. Recent gc related fixes in NVDA might improve or eliminate this.
  2. If you do see this again (i.e. hang with nvwave in the log), recent builds of NVDA log the stacks of all threads instead of jus the main thread. That will tell us whether this is a deadlock (and what we're deadlocking on).

(Unfortunately, I was running an old build when I hit this, so I don't have that log info.)

@bhavyashah
Copy link

This issue still occurs for me and has the same crippling effect in terms of locking up NVDA and needing me to somehow close Firefox. Do others still experience this; if yes, how frequently and to what severity? Have there, by any chance, been any updates in NVDA or Firefox to address these crashes? Is there any additional information from the log or otherwise that may aid developers in understanding this issue? I would love to see discussion on this ticket resume.

@CyrilleB79
Copy link
Collaborator

Still happening for me from time to time. Frequency between once a day and once a week.

@jcsteh
Copy link
Contributor

jcsteh commented Sep 24, 2021

First, you should differentiate between this complete hang of NVDA vs the RPC hang discussed above (where CPU usage goes up quite high as well). Second, assuming this isn't the RPC hang, as I wrote in my last comment #11169 (comment), if someone is still experiencing this, it'd be useful if they could provide a log. Since this issue was first reported, NVDA now logs more info that might be useful in diagnosing this.

@bhavyashah
Copy link

@jcsteh Thanks for your response. Could you please clarify whose CPU usage we should be looking at - NVDA, Firefox, or the entire system's?

@bhavyashah
Copy link

@jcsteh Also, which level would you like log output at? I just replicated this and extracted the relevant portion of the log, but realized that the log level was Input/Output which may be inadequate.

@gregjozk
Copy link
Contributor

gregjozk commented Sep 26, 2021 via email

@jcsteh
Copy link
Contributor

jcsteh commented Sep 26, 2021

Could you please clarify whose CPU usage we should be looking at - NVDA, Firefox, or the entire system's?

I'd look at the entire system. The problematic process is actually a Windows RPC service running in side vchost.exe, but it can be tricky to pinpoint the exact service, so I think it's just easier to look for high CPU usage across the whole system.

Also, which level would you like log output at?

If NVDA freezes completely (which is the issue being discussed in this particular report), watchdog should log stack information after 15 seconds, which is what I'm interested in. That gets logged at level error. So, input/output should be fine, but you can go as high as info and you'll still get errors.

@bhavyashah
Copy link

bhavyashah commented Oct 22, 2021 via email

@jcsteh
Copy link
Contributor

jcsteh commented Oct 24, 2021 via email

@jcsteh
Copy link
Contributor

jcsteh commented Feb 7, 2022

I've been seeing this once every few days since I got a new machine with Windows 11. I see the freezes when trying to close the wave output from the old fileWavePlayer instance. There is no deadlock here; it happens when calling WaveOutClose. The original log in this issue is a bit different; it froze trying to acquire a lock, but I don't have the stacks from the other threads, so I don't know why it couldn't acquire the lock.

It occurs to me that we perhaps shouldn't keep the fileWavePlayer open after we're done playing. We create a new one whenever we play a file anyway, so we don't benefit at all from keeping the device open. However, it can be quite some time between playing sounds, which means we might have an open WaveOut handle hanging around for quite some time. While that shouldn't matter in theory, I do wonder whether Windows doesn't handle this properly if that handle gets closed a lot later, particularly when there are intervening device switches. Changing that should be as simple as setting closeWhenIdle to True when fileWavePlayer is constructed.

michaelDCurran pushed a commit that referenced this issue Apr 30, 2023
NVDA's existing audio output code (nvwave) is largely very old and uses WinMM, a very old legacy Windows audio API. It is also written in pure Python, contains quite a few threading locks necessitated by WinMM, and parts of it have become rather difficult to reason about. There are several known stability and audio glitching issues that are difficult to solve with the existing code.

Description of user facing changes
At the very least, this fixes audio glitches at the end of some utterances as described in #10185 and #11061.
I haven't noticed a significant improvement in responsiveness on my system, but my system is also very powerful. It's hard to know whether the stability issues (e.g. #11169) are fixed or not. Time will tell as I run with this more.

Description of development approach
1. The bulk of the WASAPI implementation is written in C++. The WASAPI interfaces are easy to access in C++ and difficult to access in Python. In addition, this allows for the best possible performance, given that we regularly and continually stream audio data.
2. The WinMM code fired callbacks by waiting for the previous chunk to finish playing before sending the next chunk, which could result in buffer underruns (glitches) if callbacks were close together (Python 3 versions of NVDA produce a scratch in the speech when finishing the end of a line #10185 and Texts with multiple line spacings are voiced with NVDA + down arrow and voices crack #11061). In contrast, the WASAPI code uses the audio playback clock to fire callbacks independent of data buffering, eliminating glitches caused by callbacks.
3. The WinMM WavePlayer class is renamed to WinmmWavePlayer. The WASAPI version is called WasapiWavePlayer. Rather than having a common base class, this relies on duck-typing. I figured it didn't make sense to have a base class given that WasapiWavePlayer will likely replace WinmmWavePlayer altogether at some point.
4. WavePlayer is set to one of these two classes during initialisation based on a new advanced configuration setting. WASAPI defaults to disabled.
5. WasapiWavePlayer.feed can take a ctypes pointer and size instead of a Python bytes object. This avoids the overhead of additional memory copying and Python objects in cases where we are given a direct pointer to memory anyway, which is true for most (if not all) speech synthesisers.
6. For compatibility, WinmmWavePlayer.feed supports a ctypes pointer as well, but it just converts it to a Python bytes object.
7. eSpeak and oneCore have been updated to pass a ctypes pointer to WavePlayer.feed.
8. When playWaveFile is used asynchronously, it now feeds audio on the background thread, rather than calling feed on the current thread. This is necessary because the WASAPI code blocks once the buffer (400 ms) is full, rather than having variable sized buffers. Even with the WinMM code, playWaveFile code could block for a short time (nvwave.playWaveFile not fully async #10413). This should improve that also.
9. WasapiWavePlayer supports associating a stream with a specific audio session, which allows that session to be separately configurable in the system Volume Mixer. NVDA tones and wave files have been split into a separate "NVDA sounds" session. WinmmWavePlayer has a new setSessionVolume method that can be used to set the volume of a session. This at least partially addresses Ability to adjust volume of sounds #1409.
@Adriani90
Copy link
Collaborator

@jcsteh how to proceed with this issue now that the Pull request referenced above is merged? I cannot reproduce any crash in Firefox, especially also now that cache is enabled.

@jcsteh
Copy link
Contributor

jcsteh commented Sep 5, 2023

I haven't seen this lately either. Let's close it and reopen if the problem reappears.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

9 participants