nvaccess / nvda

NVDA, the free and open source Screen Reader for Microsoft Windows
Other
2.01k stars 623 forks source link

NVDA hangs for at least 8 seconds while trying to construct a huge speech uterance everytime when keyboard focus lands on a browser window with a large pdf loaded #16451

Open Adriani90 opened 2 months ago

Adriani90 commented 2 months ago

Steps to reproduce:

  1. Open a large pdf in your browser (e.g. Edge or Chrome), the attached PDF document should work for this.
  2. Open multiple windows with several other apps, pdf documents, browser windows etc.
  3. Work for a longer time in different windows
  4. After a while try to switch to the window with the large pdf, and navigate with arrow keys, open the NVDA find dialog, search for a string etc. Note: I am reproducing this issue regularly, and more often on a virtual environment with NVDA installed on the virtual machine. After exiting the NVDA session on the local machine so that only the NVDA session in the VM is running, the issue is still reproducible.

Actual behavior:

According to my investigation it seems NVDA tries to construct a huge speech uterance but it cannot speak it. So the speech is canceled from the main thread. NVDA hangs for at least 8-10 seconds every time I land on the window. Even when opening the NVDA find dialog and pressing escape triggers this issue. Sometime the freeze is very long. Note: the log is huge, NVDA tries to construct a speech uterance with more than 500k characters. Most important things from the log seem to be as follows:

IO - inputCore.InputManager.executeGesture (14:52:05.007) - winInputHook (784):
Input: kb(laptop):upArrow
IO - speech.speech.speak (14:52:05.015) - MainThread (9944):
Speaking ['Non-specialized loans 1,232,252,837 51,541,377 47,353,064 19,204,925\n']
IO - inputCore.InputManager.executeGesture (14:52:07.991) - winInputHook (784):
Input: kb(laptop):NVDA+control+f
DEBUG - gui.contextHelp.bindHelpEvent (14:52:08.008) - MainThread (9944):
Did context help binding for FindDialog
DEBUG - config.ConfigManager._triggerProfileExit (14:52:08.165) - MainThread (9944):
Deactivating triggered profile msedge
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.166) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: ReviewRoutingMovesSystemCaretFlag, behaviorOfDefault: NEVER
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.166) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.167) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.167) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.167) - MainThread (9944):
Validating feature flag: ENABLED, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.168) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.169) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.169) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: WindowsTerminalStrategyFlag, behaviorOfDefault: DIFFING
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:08.170) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: ParagraphNavigationFlag, behaviorOfDefault: APPLICATION
DEBUG - synthDriverHandler.SynthDriver.loadSettings (14:52:08.171) - MainThread (9944):
Loaded changed settings for SynthDriver espeak
DEBUG - braille.BrailleHandler._switchDisplay (14:52:08.173) - MainThread (9944):
Reinitializing 'noBraille' braille display
DEBUG - autoSettingsUtils.autoSettings.AutoSettings._registerConfigSaveAction (14:52:08.173) - MainThread (9944):
registering pre_configSave action: <class 'brailleDisplayDrivers.noBraille.BrailleDisplayDriver'>
DEBUG - autoSettingsUtils.autoSettings.AutoSettings._loadSpecificSettings (14:52:08.181) - MainThread (9944):
loading braille noBraille
INFO - braille.BrailleHandler._setDisplay (14:52:08.181) - MainThread (9944):
Loaded braille display driver 'noBraille', current display has 0 cells.
IO - speech.speech.speak (14:52:08.210) - MainThread (9944):
Speaking ['Suchen', 'Dialogfeld', CancellableSpeech (still valid)]
IO - speech.speech.speak (14:52:08.227) - MainThread (9944):
Speaking ['Geben Sie den zu suchenden Text ein', 'Eingabefeld', CancellableSpeech (still valid), 'hello ausgewählt']
IO - inputCore.InputManager.executeGesture (14:52:11.569) - winInputHook (784):
Input: kb(laptop):leftArrow
DEBUG - editableText.EditableText._hasCaretMoved (14:52:11.575) - MainThread (9944):
Caret move detected using event. Elapsed 0 sec, retries 0
IO - speech.speech.speak (14:52:11.579) - MainThread (9944):
Speaking [CharacterModeCommand(True), 'h', EndUtteranceCommand()]
IO - speech.speech.speak (14:52:11.584) - MainThread (9944):
Speaking ['hello nicht ausgewählt']
IO - inputCore.InputManager.executeGesture (14:52:11.986) - winInputHook (784):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (14:52:11.994) - MainThread (9944):
Caret move detected using event. Elapsed 0 sec, retries 0
IO - speech.speech.speak (14:52:11.996) - MainThread (9944):
Speaking [CharacterModeCommand(True), 'e', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (14:52:13.276) - winInputHook (784):
Input: kb(laptop):enter
DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IAccessibleRole (14:52:13.383) - MainThread (9944):
accRole failed: (-2147024809, 'Falscher Parameter.', (None, None, None, 0, None))
DEBUGWARNING - RPC process 12096 (msedge.exe) (14:52:13.387) - Dummy-6 (16720):
Thread 11504, build\x86_64\vbufBackends\gecko_ia2\gecko_ia2.cpp, GeckoVBufBackend_t::render, 1442:
Could not get IAccessible2, returning

DEBUGWARNING - RPC process 12096 (msedge.exe) (14:52:13.441) - Dummy-6 (16720):
Thread 11504, build\x86_64\vbufBackends\gecko_ia2\gecko_ia2.cpp, GeckoVBufBackend_t::render, 1442:
Could not get IAccessible2, returning

DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._getIA2RelationFirstTarget (14:52:13.504) - MainThread (9944):
Unable to use _getIA2TargetsForRelationsOfType, fallback to _IA2Relations.
DEBUG - NVDAObjects.IAccessible.IAccessible._get__IA2Relations (14:52:13.504) - MainThread (9944):
Not an IA2.IAccessible2
DEBUG - NVDAObjects.IAccessible.IAccessible._getIA2RelationFirstTarget (14:52:13.504) - MainThread (9944):
Unable to fetch _IA2Relations
Traceback (most recent call last):
  File "NVDAObjects\IAccessible\__init__.pyc", line 1616, in _getIA2RelationFirstTarget
  File "baseObject.pyc", line 62, in __get__
  File "baseObject.pyc", line 168, in _getPropertyViaCache
  File "NVDAObjects\IAccessible\__init__.pyc", line 1531, in _get__IA2Relations
NotImplementedError
DEBUG - config.ConfigManager._triggerProfileEnter (14:52:13.541) - MainThread (9944):
Activating triggered profile msedge
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.542) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: ReviewRoutingMovesSystemCaretFlag, behaviorOfDefault: NEVER
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.542) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.543) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.543) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.544) - MainThread (9944):
Validating feature flag: ENABLED, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.545) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.545) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: BoolFlag, behaviorOfDefault: ENABLED
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.546) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: WindowsTerminalStrategyFlag, behaviorOfDefault: DIFFING
DEBUG - config.featureFlag._validateConfig_featureFlag (14:52:13.547) - MainThread (9944):
Validating feature flag: DEFAULT, optionsEnum: ParagraphNavigationFlag, behaviorOfDefault: APPLICATION
DEBUG - synthDriverHandler.SynthDriver.loadSettings (14:52:13.547) - MainThread (9944):
Loaded changed settings for SynthDriver espeak
DEBUG - braille.BrailleHandler._switchDisplay (14:52:13.549) - MainThread (9944):
Reinitializing 'noBraille' braille display
DEBUG - autoSettingsUtils.autoSettings.AutoSettings._registerConfigSaveAction (14:52:13.550) - MainThread (9944):
registering pre_configSave action: <class 'brailleDisplayDrivers.noBraille.BrailleDisplayDriver'>
DEBUG - autoSettingsUtils.autoSettings.AutoSettings._loadSpecificSettings (14:52:13.557) - MainThread (9944):
loading braille noBraille
INFO - braille.BrailleHandler._setDisplay (14:52:13.557) - MainThread (9944):
Loaded braille display driver 'noBraille', current display has 0 cells.
IO - speech.speech.speak (14:52:13.572) - MainThread (9944):
Speaking ['isbnk31122023cons.pdf und 4 weitere Seiten - Geschäftlich – Microsoft\u200b Edge', 'Fenster', CancellableSpeech (still valid)]
IO - speech.speech.speak (14:52:13.577) - MainThread (9944):
Speaking ['Dokument', CancellableSpeech (still valid)]
IO - speech.speech.speak (14:52:13.584) - MainThread (9944):
Speaking ['Non-specialized loans 1,232,252,837 51,541,377 47,353,064 19,204,925\n']
DEBUG - watchdog._waitUntilNormalCoreAliveTimeout (14:52:14.043) - watchdog (11476):
Potential freeze, waiting up to 10 seconds.
IO - speech.speech.speak (14:52:15.388) - MainThread (9944):
Speaking """ xxx the 500k characters" ... NVDA is silent """
IO - inputCore.InputManager.executeGesture (14:52:33.283) - winInputHook (784):
Input: kb(laptop):upArrow
IO - inputCore.InputManager.executeGesture (14:52:33.783) - winInputHook (784):
Input: kb(laptop):downArrow
IO - inputCore.InputManager.executeGesture (14:52:34.004) - winInputHook (784):
Input: kb(laptop):upArrow
IO - inputCore.InputManager.executeGesture (14:52:34.316) - winInputHook (784):
Input: kb(laptop):downArrow
IO - inputCore.InputManager.executeGesture (14:52:34.622) - winInputHook (784):
Input: kb(laptop):leftArrow
IO - inputCore.InputManager.executeGesture (14:52:34.766) - winInputHook (784):
Input: kb(laptop):rightArrow
IO - inputCore.InputManager.executeGesture (14:52:34.910) - winInputHook (784):
Input: kb(laptop):downArrow
IO - inputCore.InputManager.executeGesture (14:52:35.113) - winInputHook (784):
Input: kb(laptop):upArrow
IO - inputCore.InputManager.executeGesture (14:52:37.152) - winInputHook (784):
Input: kb(laptop):downArrow
DEBUG - speech.manager.SpeechManager._handleIndex (14:52:39.482) - MainThread (9944):
Unknown index 6573, speech probably cancelled from main thread.
IO - speech.speech.speak (14:52:39.486) - MainThread (9944):
Speaking ['Überschrift', 'Ebene 2', 'NOTES TO THE CONSOLIDATED FINANCIAL STATEMENTS\n']
IO - speech.speech.speak (14:52:39.493) - MainThread (9944):
Speaking ['Überschrift', 'Ebene 2', 'TÜRKİYE İŞ BANKASI A.Ş.\n']
IO - speech.speech.speak (14:52:39.499) - MainThread (9944):
Speaking ['Überschrift', 'Ebene 2', 'NOTES TO THE CONSOLIDATED FINANCIAL STATEMENTS\n']
IO - speech.speech.speak (14:52:39.503) - MainThread (9944):
Speaking ['Zeilenumbruch', EndUtteranceCommand()]
IO - speech.speech.speak (14:52:39.506) - MainThread (9944):
Speaking [PitchCommand(offset=30), CharacterModeCommand(True), 'N', PitchCommand(), EndUtteranceCommand()]
IO - speech.speech.speak (14:52:39.512) - MainThread (9944):
Speaking ['Überschrift', 'Ebene 2', 'FOR THE YEAR ENDED DECEMBER 31, 2023\n']
IO - speech.speech.speak (14:52:39.519) - MainThread (9944):
Speaking ['Überschrift', 'Ebene 2', 'NOTES TO THE CONSOLIDATED FINANCIAL STATEMENTS\n']
IO - speech.speech.speak (14:52:39.526) - MainThread (9944):
Speaking ['Überschrift', 'Ebene 2', 'FOR THE YEAR ENDED DECEMBER 31, 2023\n']
IO - speech.speech.speak (14:52:39.625) - MainThread (9944):
Speaking ['Loans Extended to Financial Sector ', 'Link']
DEBUG - watchdog._waitUntilNormalCoreAliveTimeout (14:52:39.704) - watchdog (11476):
Recovered from potential freeze after 8.738841100013815 seconds.

Expected behavior:

No freeze and NVDA cancels the construction of the huge speech uterance after a while, maybe reading the first characters and then the number of characters or so.

NVDA logs, crash dumps and other attachments:

Freez in pdf.txt

System configuration

NVDA installed/portable/running from source:

Installed

NVDA version:

2024.1

Windows version:

Windows 10 last update

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

Edge and Chrome 124

Other information about your system:

Reproducing both locally and on the virtual machine

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, testing back until 2022.1, the issue is still occuring.

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

yes

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

yes isbnk31122023cons.pdf

Neurrone commented 2 months ago

Probably a duplicate of #16233

Adriani90 commented 1 month ago

It seems sometimes reloading the virtual document with nvda+f5 makes NVDA work pplain roperly again. I wonder whether this occurs because the screen doesn't scroll while moving to the website window, and NVDA tries to put the virtual cursor in browse mode to the same position as it was befor leaving the window? cc: @jcsteh

So I try to ilustrate my use case, let's say