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

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

Open Adriani90 opened this issue 1 year ago • 1 comments

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

Adriani90 avatar Apr 25 '24 18:04 Adriani90

Probably a duplicate of #16233

Neurrone avatar Apr 26 '24 16:04 Neurrone

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

  • we open the attached pdf document in the description and read information on several pages, jumping back and forth with NVDA find functionality.
  • At some point, the system focus does not move because the pdf document contains text which cannot be focused.
  • It might be that, while using the virtual cursor, the screen doesn't scroll properly while navigating in browse mode. Maybe related to #904, especially when navigating on pages 200+ or so.
  • There might be a moment where the screen doesn't scroll as fast as the movement of the virtual cursor, so the virtual cursor is at a position on a text that is not visible on the screen
  • If switching to another window while the virtual cursor focuses invisible text, and then switching back to the pdf document window, NVDA tries to restore the previous position of the virtual cursor, but it might fail because the screen doesn't scroll to the position of the virtual cursor
  • NVDA then falls back to report everything on the screen within a single speech uterance, but it fails and it cancels the speech while freezing.

Adriani90 avatar May 25 '24 13:05 Adriani90