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 Laggs a lot in Visual Studio Code editor while typing and reading the code #11533

Closed
akash07k opened this issue Aug 30, 2020 · 101 comments · Fixed by #11656
Closed

NVDA Laggs a lot in Visual Studio Code editor while typing and reading the code #11533

akash07k opened this issue Aug 30, 2020 · 101 comments · Fixed by #11656

Comments

@akash07k
Copy link

akash07k commented Aug 30, 2020

Steps to reproduce:

  1. Open Visual studio code.
  2. Open a file or directory containing any text files in it such as a javascript/python project.
  3. Go to the editor.
  4. try navigating the text/code via arrow keys.
  5. Now try typing some code in the editor quickly.
  6. It will be observed that in both 4th and 5th point, NVDA laggs a lot while navigating and typing the code in the editor.
  7. Now repeat the same thing with Notepad plus plus or another text editor.
  8. It will be observed that NVDA doesn't lag there at all and responds very snappily.

Actual behavior:

When we navigate/read and type the text/code in visual studio code editor, NVDA laggs a lot and responds very slowly.
For example, If we navigate/read the code in notepad NVDA responds/reads every line quickly but in VS Code, it doesn't happen like this.
Also, If we quickly type the code, most of the times, NVDA announces the typed characters after a delay which is very annoying and problematic.
It doesn't happen with other applications.

Expected behavior:

NVDA should not lag in VS Code editor and should be responsive like it is with other editors.

System configuration

NVDA installed/portable/running from source:

Installed

NVDA version:

NVDA version alpha-20793,9a4074bc

Windows version:

Tried with multiple Windows builds:
Windows 10 2004, 19041.450,
and latest insider too.

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

Visual Studio Code both insider and stable.

Other information about your system:

I7 processor, 8 GB ram, Samsung SSD and also tried with multiple other systems. Same issue persists.

Other questions

Does the issue still occur after restarting your computer?

Yes, always and even after reformatting the system too.

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

Yes, NVDA stable versions, and the same issue is being observed since months.

If addons are disabled, is your problem still occuring?

Yes, always.

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

Yes, but no luck

@akash07k akash07k changed the title NVDA responds very slow/with a lag in Visual Studio Code editor NVDA Laggs a lot in Visual Studio Code editor while typing and reading the code Aug 30, 2020
@akash07k
Copy link
Author

akash07k commented Aug 31, 2020

@feerrenrut
Bro, your views/comments on this?

@feerrenrut
Copy link
Member

feerrenrut commented Aug 31, 2020

Can you turn on "time since input" logging in the advanced settings panel, with add-ons disabled, do a short test with vsCode and post the debug level log please?

@prajwalkeny22

This comment has been minimized.

@leonardder
Copy link
Collaborator

leonardder commented Aug 31, 2020

cc @isidorn

@akash07k
Copy link
Author

akash07k commented Aug 31, 2020

Can you turn on "time since input" logging in the advanced settings panel, with add-ons disabled, do a short test with vsCode and post the debug level log please?

Sure @feerrenrut
I'll attach log soon after my office hours.

@Neurrone
Copy link

Neurrone commented Aug 31, 2020

I can confirm that I've also been experiencing this on my work machine, though its a really old Dell XPS 13 from 2016.

Soome other things that might be related:

  • I'm working primarily with TypeScript and JavaScript, about 100,000 lines of code for the folders that I'm trying to open
  • Even while typing normally in a blank document or in a .md file and arrowing around on my more powerful personal machine feels laggier than on notepad

@akash07k
Copy link
Author

akash07k commented Aug 31, 2020

@feerrenrut
Please find the log attached with this comment.
Please let me know if anything more is needed.

Can you turn on "time since input" logging in the advanced settings panel, with add-ons disabled, do a short test with vsCode and post the debug level log please?

NVDA_Log.txt

@akash07k
Copy link
Author

akash07k commented Aug 31, 2020

Absolutely, same here as well.
Notepad, notepad plus plus, android studio, all other editors etc are absolutely fine and feel very snappier.
I've tried VS Code with JAWS yesterday and it was not lagging at all, hence it seems that this problem is NVDA specific.
But, I don't want to leave NVDA at any cost now.
Don't want to go back to JAWS at any cost.

I can confirm that I've also been experiencing this on my work machine, though its a really old Dell XPS 13 from 2016.

Soome other things that might be related:

* I'm working primarily with TypeScript and JavaScript, about 100,000 lines of code for the folders that I'm trying to open

* Even while typing normally in a blank document or in a .md file and arrowing around on my more powerful personal machine feels laggier than on notepad

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

@feerrenrut
Today I tried it with another system which was having 16 GB ram, and I7 10th generation processor, but same laggyness was observed there.
It was my friends computer.
This lag is really painful and completely prevents me for using VS Code

@feerrenrut
Copy link
Member

feerrenrut commented Sep 1, 2020

Since it is a long log, I picked a random part to inspect where I was sure you were using vsCode:

Input: kb(laptop):upArrow
DEBUG - editableText.EditableText._hasCaretMoved (23:41:10.127) - MainThread (8528):
Caret move detected using bookmarks. Elapsed: 20 ms
IO - inputCore.logTimeSinceInput (23:41:10.130) - MainThread (8528):
0.109 sec since input
IO - speech.speak (23:41:10.130) - MainThread (8528):
Speaking ['let test2 = "test2";\n']
IO - inputCore.InputManager.executeGesture (23:41:10.428) - winInputHook (1656):
Input: kb(laptop):upArrow
DEBUG - editableText.EditableText._hasCaretMoved (23:41:10.552) - MainThread (8528):
Caret move detected using bookmarks. Elapsed: 20 ms
IO - inputCore.logTimeSinceInput (23:41:10.557) - MainThread (8528):
0.128 sec since input
IO - speech.speak (23:41:10.557) - MainThread (8528):
Speaking ['let test1 = "this is a test";\n']
IO - inputCore.InputManager.executeGesture (23:41:11.902) - winInputHook (1656):
Input: kb(laptop):upArrow
DEBUG - editableText.EditableText._hasCaretMoved (23:41:12.033) - MainThread (8528):
Caret move detected using bookmarks. Elapsed: 30 ms
IO - inputCore.logTimeSinceInput (23:41:12.039) - MainThread (8528):
0.136 sec since input
IO - speech.speak (23:41:12.039) - MainThread (8528):
Speaking ['blank']
IO - inputCore.InputManager.executeGesture (23:41:12.414) - winInputHook (1656):
Input: kb(laptop):upArrow
DEBUG - editableText.EditableText._hasCaretMoved (23:41:12.524) - MainThread (8528):
Caret move detected using bookmarks. Elapsed: 20 ms
IO - inputCore.logTimeSinceInput (23:41:12.529) - MainThread (8528):
0.114 sec since input
IO - speech.speak (23:41:12.529) - MainThread (8528):
Speaking ["//I'm testing the slowness with visual studio code.\n"]
IO - inputCore.InputManager.executeGesture (23:41:12.855) - winInputHook (1656):
Input: kb(laptop):upArrow
DEBUG - editableText.EditableText._hasCaretMoved (23:41:13.060) - MainThread (8528):
Caret didn't move before timeout. Elapsed: 100 ms
IO - inputCore.logTimeSinceInput (23:41:13.069) - MainThread (8528):
0.214 sec since input
IO - speech.speak (23:41:13.070) - MainThread (8528):
Speaking ["//I'm testing the slowness with visual studio code.\n"]

This indicates an average of 140 ms from input to speech. It would be interesting to compare these values to another application that does not have lag for you such as notepad, keeping all other configuration and test approach the same.

For future reference, Espeak was used for this test.

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

So, Should I provide the logs while typing/interacting with notepad too?

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

I can confirm that I've also been experiencing this on my work machine, though its a really old Dell XPS 13 from 2016.

Soome other things that might be related:

* I'm working primarily with TypeScript and JavaScript, about 100,000 lines of code for the folders that I'm trying to open

* Even while typing normally in a blank document or in a .md file and arrowing around on my more powerful personal machine feels laggier than on notepad

Bro, can you also provide your logs for the easier pin pointing of the problem

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

Actually I used VS code many times only for generating the log,
Can you please look at other parts too for the more better insights on this?
Currently you've picked the logs where I've only navigated the code.
Typing is much more pain.

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

@feerrenrut
I see that you've picked the part where I've only navigated the code.
Typing the code is more laggier.

@Neurrone
Copy link

Neurrone commented Sep 1, 2020

here're some logs of just using the arrow keys, but this on the machine where I'm not suffering from this.

Btw, do I need to choose the "restart with debug logging" option to have the timing logs show up? They wouldn't show up for me otherwise.

Input: kb(laptop):control+home
DEBUGWARNING - Python warning (21:36:15.569) - MainThread (26636):
C:\Program Files (x86)\NVDA\library.zip\keyboardHandler.py:549: DeprecationWarning: Yield() is deprecated
DEBUGWARNING - Python warning (21:36:15.569) - MainThread (26636):
C:\Program Files (x86)\NVDA\library.zip\api.py:287: DeprecationWarning: Yield() is deprecated
DEBUG - editableText.EditableText._hasCaretMoved (21:36:15.588) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:15.591) - MainThread (26636):
0.056 sec since input
IO - speech.speak (21:36:15.591) - MainThread (26636):
Speaking ['# Espresso Extraction\n']
IO - inputCore.InputManager.executeGesture (21:36:16.445) - winInputHook (28992):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:16.510) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:16.513) - MainThread (26636):
0.068 sec since input
IO - speech.speak (21:36:16.513) - MainThread (26636):
Speaking ['blank']
IO - inputCore.InputManager.executeGesture (21:36:16.823) - winInputHook (28992):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:16.879) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:16.881) - MainThread (26636):
0.058 sec since input
IO - speech.speak (21:36:16.881) - MainThread (26636):
Speaking ['## Extraction\n']
IO - inputCore.InputManager.executeGesture (21:36:17.785) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:17.813) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (21:36:17.815) - MainThread (26636):
0.030 sec since input
IO - speech.speak (21:36:17.815) - MainThread (26636):
Speaking ['number', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:18.126) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:18.188) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:18.190) - MainThread (26636):
0.064 sec since input
IO - speech.speak (21:36:18.190) - MainThread (26636):
Speaking ['space', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:18.439) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:18.492) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:18.494) - MainThread (26636):
0.055 sec since input
IO - speech.speak (21:36:18.494) - MainThread (26636):
Speaking [PitchCommand(offset=30), CharacterModeCommand(True), 'E', PitchCommand(), EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:18.766) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:18.799) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (21:36:18.801) - MainThread (26636):
0.035 sec since input
IO - speech.speak (21:36:18.801) - MainThread (26636):
Speaking [CharacterModeCommand(True), 'x', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:19.006) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:19.067) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:19.070) - MainThread (26636):
0.064 sec since input
IO - speech.speak (21:36:19.070) - MainThread (26636):
Speaking [CharacterModeCommand(True), 't', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:19.269) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:19.293) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (21:36:19.296) - MainThread (26636):
0.027 sec since input
IO - speech.speak (21:36:19.296) - MainThread (26636):
Speaking [CharacterModeCommand(True), 'r', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:19.524) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:19.585) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:19.588) - MainThread (26636):
0.064 sec since input
IO - speech.speak (21:36:19.588) - MainThread (26636):
Speaking [CharacterModeCommand(True), 'a', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:19.794) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:19.830) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:19.832) - MainThread (26636):
0.038 sec since input
IO - speech.speak (21:36:19.832) - MainThread (26636):
Speaking [CharacterModeCommand(True), 'c', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:20.044) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:20.084) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (21:36:20.086) - MainThread (26636):
0.042 sec since input
IO - speech.speak (21:36:20.087) - MainThread (26636):
Speaking [CharacterModeCommand(True), 't', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:20.339) - winInputHook (28992):
Input: kb(laptop):rightArrow
DEBUG - editableText.EditableText._hasCaretMoved (21:36:20.382) - MainThread (26636):
Caret move detected using bookmarks. Elapsed: 10 ms
IO - inputCore.logTimeSinceInput (21:36:20.385) - MainThread (26636):
0.046 sec since input
IO - speech.speak (21:36:20.385) - MainThread (26636):
Speaking [CharacterModeCommand(True), 'i', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (21:36:20.608) - winInputHook (28992):

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

Hi bro,
Just choose "Restart with addons disabled" in the NVDA exit dialogue box.
Then, once NVDA restarts, go to NVDA settings>General Settings>Logging level combo box.
Choose debug from there.
After it, Go to NVDA Settings>Advanced>Check the checkbox for revealing the advanced settings,
Now, tab to the debug "Debug logging" group and do right arrow there and find the option of "Time since input", check it nd hit ok.
You'll be good to go

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

@feerrenrut
Please find the log attached where I've tested with notepad.
It is not laggy at all and works wonderfully.
NVDA_Logs_Notepad.txt

@Neurrone
Copy link

Neurrone commented Sep 1, 2020

Thanks @akash07k, I'll try this on my machine which always has this issue tomorrow at work.

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

Ok. :-)

Thanks @akash07k, I'll try this on my machine which always has this issue tomorrow at work.

@feerrenrut
Copy link
Member

feerrenrut commented Sep 1, 2020

Thanks @akash07k, here is the section of the log I have compared:

Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:33.133) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:33.141) - MainThread (816):
0.060 sec since input
IO - speech.speak (20:23:33.142) - MainThread (816):
Speaking ["I'm testing with notepad\r\n"]
IO - inputCore.InputManager.executeGesture (20:23:34.176) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:34.213) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:34.222) - MainThread (816):
0.046 sec since input
IO - speech.speak (20:23:34.223) - MainThread (816):
Speaking ["It's not laagy at all\r\n"]
IO - inputCore.InputManager.executeGesture (20:23:35.198) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:35.247) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:35.256) - MainThread (816):
0.058 sec since input
IO - speech.speak (20:23:35.256) - MainThread (816):
Speaking ["It's not laggy at all.\r\n"]
IO - inputCore.InputManager.executeGesture (20:23:36.171) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:36.209) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:36.217) - MainThread (816):
0.046 sec since input
IO - speech.speak (20:23:36.218) - MainThread (816):
Speaking ['Wow\r\n']
IO - inputCore.InputManager.executeGesture (20:23:36.767) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:36.808) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:36.818) - MainThread (816):
0.051 sec since input
IO - speech.speak (20:23:36.818) - MainThread (816):
Speaking ['What a wonderful expereience!\r\n']

This seems to average about 50 ms between input and speaking.

@akash07k
Copy link
Author

akash07k commented Sep 1, 2020

Hmm, Don't you find VS Code very laggy as compared to Notepad?
Have you checked the section of the VS Code log section where I've typed the code?
If you want, then I can generate a new log also
I don't know what is causing this lag in VS Code in many machines.
Are you also able to reproduce it?

Thanks @akash07k, here is the section of the log I have compared:

Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:33.133) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:33.141) - MainThread (816):
0.060 sec since input
IO - speech.speak (20:23:33.142) - MainThread (816):
Speaking ["I'm testing with notepad\r\n"]
IO - inputCore.InputManager.executeGesture (20:23:34.176) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:34.213) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:34.222) - MainThread (816):
0.046 sec since input
IO - speech.speak (20:23:34.223) - MainThread (816):
Speaking ["It's not laagy at all\r\n"]
IO - inputCore.InputManager.executeGesture (20:23:35.198) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:35.247) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:35.256) - MainThread (816):
0.058 sec since input
IO - speech.speak (20:23:35.256) - MainThread (816):
Speaking ["It's not laggy at all.\r\n"]
IO - inputCore.InputManager.executeGesture (20:23:36.171) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:36.209) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:36.217) - MainThread (816):
0.046 sec since input
IO - speech.speak (20:23:36.218) - MainThread (816):
Speaking ['Wow\r\n']
IO - inputCore.InputManager.executeGesture (20:23:36.767) - winInputHook (5208):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (20:23:36.808) - MainThread (816):
Caret move detected using event. Elapsed: 0 ms
IO - inputCore.logTimeSinceInput (20:23:36.818) - MainThread (816):
0.051 sec since input
IO - speech.speak (20:23:36.818) - MainThread (816):
Speaking ['What a wonderful expereience!\r\n']

This seems to average about 50 ms between input and speaking.

@Neurrone
Copy link

Neurrone commented Sep 2, 2020

Found the section of @akash07k's log that demonstrates this horrendous lag, starting from line 220.

Input: kb(laptop):e
IO - inputCore.logTimeSinceInput (23:40:12.471) - MainThread (8528):
0.151 sec since input
IO - speech.speak (23:40:12.471) - MainThread (8528):
Speaking ['Suggest', 'list']
IO - inputCore.logTimeSinceInput (23:40:12.479) - MainThread (8528):
0.159 sec since input
IO - speech.speak (23:40:12.479) - MainThread (8528):
Speaking ['list item']
DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IA2States (23:40:12.533) - MainThread (8528):
could not get IAccessible2 states
Traceback (most recent call last):
  File "NVDAObjects\IAccessible\__init__.pyc", line 1626, in _get_IA2States
  File "comtypesMonkeyPatches.pyc", line 26, in __call__
_ctypes.COMError: (-2147467259, 'Unspecified error', (None, None, None, 0, None))
DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IA2Attributes (23:40:12.534) - MainThread (8528):
IAccessibleObject.attributes COMError (-2147467259, 'Unspecified error', (None, None, None, 0, None))
DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IAccessibleRole (23:40:12.535) - MainThread (8528):
accRole failed: (-2147467259, 'Unspecified error', (None, None, None, 0, None))
IO - inputCore.logTimeSinceInput (23:40:12.536) - MainThread (8528):
0.216 sec since input
IO - speech.speak (23:40:12.536) - MainThread (8528):
Speaking [CharacterModeCommand(True), 'e', EndUtteranceCommand()]
IO - inputCore.logTimeSinceInput (23:40:12.544) - MainThread (8528):
0.224 sec since input
IO - speech.speak (23:40:12.545) - MainThread (8528):
Speaking ['testing', '1 of 2']
DEBUG - speech.manager.SpeechManager._handleIndex (23:40:12.545) - MainThread (8528):
Unknown index 187, speech probably cancelled from main thread.
IO - inputCore.InputManager.executeGesture (23:40:12.772) - winInputHook (1656):
Input: kb(laptop):s
DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IA2States (23:40:12.947) - MainThread (8528):
could not get IAccessible2 states
Traceback (most recent call last):
  File "NVDAObjects\IAccessible\__init__.pyc", line 1626, in _get_IA2States
  File "comtypesMonkeyPatches.pyc", line 26, in __call__
_ctypes.COMError: (-2147467259, 'Unspecified error', (None, None, None, 0, None))
DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IA2Attributes (23:40:12.948) - MainThread (8528):
IAccessibleObject.attributes COMError (-2147467259, 'Unspecified error', (None, None, None, 0, None))
DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IAccessibleRole (23:40:12.950) - MainThread (8528):
accRole failed: (-2147467259, 'Unspecified error', (None, None, None, 0, None))
IO - inputCore.logTimeSinceInput (23:40:12.950) - MainThread (8528):
0.178 sec since input
IO - speech.speak (23:40:12.950) - MainThread (8528):
Speaking [CharacterModeCommand(True), 's', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (23:40:12.951) - MainThread (8528):
Unknown index 191, speech probably cancelled from main thread.
IO - inputCore.logTimeSinceInput (23:40:12.960) - MainThread (8528):
0.188 sec since input
IO - speech.speak (23:40:12.960) - MainThread (8528):
Speaking ['testing', '1 of 1']
IO - inputCore.InputManager.executeGesture (23:40:13.189) - winInputHook (1656):

@leonardder
Copy link
Collaborator

leonardder commented Sep 2, 2020

@akash07k before going any further with this, are you able to reproduce this on the insider preview of VS Code? It switched from Electron 7 to ELectron 9, with a way newer version of chromium under the hood.
Also, are you able to share a code snippet that causes this horrendous lag?

@akash07k
Copy link
Author

akash07k commented Sep 2, 2020

@leonardder
I'm able to reproduce this painful lag on both, the stable and the insider builds of VS Code.
Also, there's no specific code snippet which causes the lag.
In fact, every code with every programming language causes this.
No matter it is typing the code or navigating.
Although, typing is much more laggy.
Currently, I've tried it on various machines with both, the stable and insider builds of VS code as well as Stable and Alpha builds of NVDA.

@akash07k before going any further with this, are you able to reproduce this on the insider preview of VS Code? It switched from Electron 7 to ELectron 9, with a way newer version of chromium under the hood.
Also, are you able to share a code snippet that causes this horrendous lag?

@Neurrone
Copy link

Neurrone commented Sep 2, 2020

Some logs on my machine which reproduce this.

Typing enter, then pressing the up arrow key to review the text:

Input: kb(laptop):enter
DEBUG - editableText.EditableText._hasCaretMoved (17:10:56.650) - MainThread (1724):
Caret move detected using bookmarks. Elapsed: 50 ms
IO - inputCore.InputManager.executeGesture (17:10:58.104) - winInputHook (10728):
Input: kb(laptop):upArrow
DEBUG - editableText.EditableText._hasCaretMoved (17:10:58.320) - MainThread (1724):
Caret move detected using bookmarks. Elapsed: 20 ms
IO - inputCore.logTimeSinceInput (17:10:58.326) - MainThread (1724):
0.222 sec since input
IO - speech.speak (17:10:58.326) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), '// must return empty object here\n']
IO - inputCore.InputManager.executeGesture (17:10:59.119) - winInputHook (10728):
Input: kb(laptop):downArrow
DEBUG - editableText.EditableText._hasCaretMoved (17:10:59.185) - MainThread (1724):
Caret move detected using bookmarks. Elapsed: 20 ms
IO - inputCore.logTimeSinceInput (17:10:59.192) - MainThread (1724):
0.073 sec since input
IO - speech.speak (17:10:59.192) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), 'blank']

Typing "// this is laggy" in Vs Code, notice some of the spikes which are over half a second!

IO - inputCore.InputManager.executeGesture (17:11:00.229) - winInputHook (10728):
Input: kb(laptop):/
IO - inputCore.logTimeSinceInput (17:11:00.257) - MainThread (1724):
0.029 sec since input
IO - speech.speak (17:11:00.257) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), 'slash', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:02.326) - winInputHook (10728):
Input: kb(laptop):/
IO - inputCore.InputManager.executeGesture (17:11:03.262) - winInputHook (10728):
Input: kb(laptop):/
IO - inputCore.logTimeSinceInput (17:11:03.292) - MainThread (1724):
0.030 sec since input
IO - speech.speak (17:11:03.292) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), 'slash', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:03.657) - winInputHook (10728):
Input: kb(laptop):space
IO - inputCore.logTimeSinceInput (17:11:03.673) - MainThread (1724):
0.016 sec since input
IO - speech.speak (17:11:03.674) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), 'slash', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (17:11:03.674) - MainThread (1724):
Unknown index 3163, speech probably cancelled from main thread.
IO - inputCore.logTimeSinceInput (17:11:03.984) - MainThread (1724):
0.327 sec since input
IO - speech.speak (17:11:03.984) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), 'space', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (17:11:03.985) - MainThread (1724):
Unknown index 3165, speech probably cancelled from main thread.
IO - inputCore.InputManager.executeGesture (17:11:04.768) - winInputHook (10728):
Input: kb(laptop):t
IO - inputCore.logTimeSinceInput (17:11:04.807) - MainThread (1724):
0.039 sec since input
IO - speech.speak (17:11:04.807) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 't', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (17:11:04.808) - MainThread (1724):
Unknown index 3168, speech probably cancelled from main thread.
IO - inputCore.InputManager.executeGesture (17:11:05.431) - winInputHook (10728):
Input: kb(laptop):h
IO - inputCore.logTimeSinceInput (17:11:06.122) - MainThread (1724):
0.691 sec since input
IO - speech.speak (17:11:06.122) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'h', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:06.793) - winInputHook (10728):
Input: kb(laptop):i
IO - inputCore.logTimeSinceInput (17:11:07.198) - MainThread (1724):
0.405 sec since input
IO - speech.speak (17:11:07.198) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'i', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (17:11:07.199) - MainThread (1724):
Unknown index 3172, speech probably cancelled from main thread.
IO - inputCore.InputManager.executeGesture (17:11:07.795) - winInputHook (10728):
Input: kb(laptop):s
IO - inputCore.logTimeSinceInput (17:11:07.818) - MainThread (1724):
0.023 sec since input
IO - speech.speak (17:11:07.818) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 's', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:08.361) - winInputHook (10728):
Input: kb(laptop):space
IO - speech.speakTypedCharacters (17:11:08.407) - MainThread (1724):
typed word: this
IO - inputCore.logTimeSinceInput (17:11:08.408) - MainThread (1724):
0.047 sec since input
IO - speech.speak (17:11:08.408) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), 'space', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:08.722) - winInputHook (10728):
Input: kb(laptop):i
IO - inputCore.logTimeSinceInput (17:11:08.736) - MainThread (1724):
0.014 sec since input
IO - speech.speak (17:11:08.736) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'i', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:09.492) - winInputHook (10728):
Input: kb(laptop):s
IO - inputCore.logTimeSinceInput (17:11:09.737) - MainThread (1724):
0.245 sec since input
IO - speech.speak (17:11:09.738) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 's', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:10.178) - winInputHook (10728):
Input: kb(laptop):space
IO - speech.speakTypedCharacters (17:11:10.869) - MainThread (1724):
typed word: is
IO - inputCore.logTimeSinceInput (17:11:10.869) - MainThread (1724):
0.691 sec since input
IO - speech.speak (17:11:10.869) - MainThread (1724):
Speaking [LangChangeCommand ('en_US'), 'space', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (17:11:10.870) - MainThread (1724):
Unknown index 3182, speech probably cancelled from main thread.
IO - inputCore.InputManager.executeGesture (17:11:11.265) - winInputHook (10728):
Input: kb(laptop):l
IO - inputCore.logTimeSinceInput (17:11:11.678) - MainThread (1724):
0.413 sec since input
IO - speech.speak (17:11:11.679) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'l', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (17:11:11.679) - MainThread (1724):
Unknown index 3184, speech probably cancelled from main thread.
IO - inputCore.InputManager.executeGesture (17:11:12.043) - winInputHook (10728):
Input: kb(laptop):a
IO - inputCore.logTimeSinceInput (17:11:12.787) - MainThread (1724):
0.744 sec since input
IO - speech.speak (17:11:12.787) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'a', EndUtteranceCommand()]
DEBUG - speech.manager.SpeechManager._handleIndex (17:11:12.788) - MainThread (1724):
Unknown index 3186, speech probably cancelled from main thread.
IO - inputCore.InputManager.executeGesture (17:11:13.117) - winInputHook (10728):
Input: kb(laptop):g
IO - inputCore.logTimeSinceInput (17:11:13.130) - MainThread (1724):
0.013 sec since input
IO - speech.speak (17:11:13.130) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'g', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:13.464) - winInputHook (10728):
Input: kb(laptop):g
IO - inputCore.logTimeSinceInput (17:11:13.467) - MainThread (1724):
0.003 sec since input
IO - speech.speak (17:11:13.467) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'g', EndUtteranceCommand()]
IO - inputCore.InputManager.executeGesture (17:11:13.753) - winInputHook (10728):
Input: kb(laptop):y
IO - inputCore.logTimeSinceInput (17:11:13.812) - MainThread (1724):
0.059 sec since input
IO - speech.speak (17:11:13.812) - MainThread (1724):
Speaking [CharacterModeCommand(True), LangChangeCommand ('en_US'), 'y', EndUtteranceCommand()]

@akash07k
Copy link
Author

akash07k commented Sep 2, 2020

Hmm, I noticed the maximum delay of 744 MS in your log at one place which is really really a lot and is very painful.
I wish this issue could be fixed soon as it is preventing me from effectively coding my projects.

@akash07k
Copy link
Author

akash07k commented Sep 2, 2020

@MarcoZehe
Bro, sorry to ping you on this issue, but I think that you also use VS Code with NVDA?
Do you also come across to this problem/Do you also face the same laggyness?
Please give your views if possible.

@akash07k
Copy link
Author

akash07k commented Sep 13, 2020

So, I tested with 2019.2 also, but the same lag persists. sadly.

@akash07k
Copy link
Author

akash07k commented Sep 13, 2020

Seems that this issue is quite complex to fix as well as track down.
Losing the hope for the fix anytime soon 😢😢😭😭

@akash07k
Copy link
Author

akash07k commented Sep 13, 2020

@leonardder
I experimented with try build little bit more, and I feel that it may give promising results.
The lag is reduced.
May be the work can be continued in #11437 in order to fix it.

Could you also have a try with this try build as a portable copy? This is the build associated with pr #11437. You should enable the Only process MSAA/IA2 &events for specific objects (focus, etc.) option in NVDA"s advanced settings.

@ahicks92
Copy link
Contributor

ahicks92 commented Sep 13, 2020

I just got the 1.49 VSCode update and still can't duplicate this against 2020.1. @akash07k , where do you fall on the spectrum from netbook to workstation, and have you tried disabling all extensions in VSCode yet?

Someone more qualified than me will probably have better questions, but in terms of a bug functioning like the most typical regression scenario ever, this one does: happens perfectly reliably in 2020.2, happens never in 2020.1.

@leonardder
Copy link
Collaborator

leonardder commented Sep 14, 2020

@leonardder
@feerrenrut
Any updates on this?

It is under investigation. Could you please refrain from asking for updates? We'll provide them when appropriate.

@akash07k
Copy link
Author

akash07k commented Sep 14, 2020

@camlorn
Not at all, may be your issue was different and mine is different.
I can reproduce my issue with 2019.2 even.
I don't think that your issue was regarding the laggyness of editor. I.E: typing and navigating the code.
I'm on laptop.
Tried with 8 GB I7, and 16 GB I7 10th gen processor.
I've tried everything, done every troubleshooting disabled everything and done whatever I could do.
Please go through whole thread for the complete understanding of this issue.
Only then you'll be able to understand that what I've done or what not.
I've tried the clean installation of everything.
Not only this, I've tried with multiple laptops and same issue persists, even with or without SSD.

I just got the 1.49 VSCode update and still can't duplicate this against 2020.1. @akash07k , where do you fall on the spectrum from netbook to workstation, and have you tried disabling all extensions in VSCode yet?

Someone more qualified than me will probably have better questions, but in terms of a bug functioning like the most typical regression scenario ever, this one does: happens perfectly reliably in 2020.2, happens never in 2020.1.

@akash07k
Copy link
Author

akash07k commented Sep 14, 2020

Ok, let's see.

@leonardder
@feerrenrut
Any updates on this?

It is under investigation. Could you please refrain from asking for updates? We'll provide them when appropriate.

@leonardder
@feerrenrut
Any updates on this?

It is under investigation. Could you please refrain from asking for updates? We'll provide them when appropriate.

@ahicks92
Copy link
Contributor

ahicks92 commented Sep 14, 2020

I'll see if I can find the time to set up to run from source and bisect this weekend. I suspect there's two causes of lag. I'm not the only person I know for whom 2020.1 works fine.

I have read the thread. @akash07k, your comments are hard to follow because you have been splitting up what you've tried across multiple comments back to back so it is possible I missed the answers to my questions. Sorry.

@akash07k
Copy link
Author

akash07k commented Sep 14, 2020

@camlorn
You are right, I've splitted my comments, but, actually it happens sometime. 😂😂 I can understand that you may have missed some of them. Actually sometimes when we write something and submit, afterwards, something more comes in our mind to add and instead of editing the previous comment, we add the fresh comment. 😂😂
Regarding lag, I've tried the editor thing with many machines and used even 2019.2 (As I sad earlier) but same issue reproduces. I dont know what can be the cause of it.
Which causes you are suspecting on lag?
If you work on something, then I'll be happy to try your build.
Have you tried that build which @leonardder provided some comments before?

I'll see if I can find the time to set up to run from source and bisect this weekend. I suspect there's two causes of lag. I'm not the only person I know for whom 2020.1 works fine.

I have read the thread. @akash07k, your comments are hard to follow because you have been splitting up what you've tried across multiple comments back to back so it is possible I missed the answers to my questions. Sorry.

@akash07k
Copy link
Author

akash07k commented Sep 18, 2020

Finally,
Losing the hope that this bug will be fixed soon. As per other issues/bugs, it may take years to get fixed. and It's very unproductive to wait for years.
It is also possible that this bug gets ignored for several years and it doesn't get the attension to get it fixed on priority basis.
I think I should move back to JAWS. only it will be better for me if I want to code with Visual Studio Code.

@ahicks92
Copy link
Contributor

ahicks92 commented Sep 19, 2020

I bisected and this gets weird. The lag is introduced for me and the other person I know who is experiencing this by the rollback of the app module in commit e095f81. And, per the directions in that commit, unchecking enable browse mode on page load gets rid of it for me and massively improves it for him.

Notably, entering and leaving browse mode after VSCode loads doesn't reintroduce the lag, either. It's specifically that setting.

The NVDA snapshot with the selective event subscription setting doesn't matter for me because there's too little lag left, but for my friend it didn't help.

So I think the next thing for this issue is anyone else trying that. Note that configuration profiles are a thing for anyone who doesn't know that already. You can work around it (if this workaround works) by using a configuration profile to selectively toggle the setting rather than gain a responsive VSCode at the cost of a terrible browsing experience.

@akash07k
Copy link
Author

akash07k commented Sep 20, 2020

@camlorn
Thanks a lot for your work around bro.
I'll just try it and will let you know whether it improves the performance for me or not.
If it improves, then I'll be extremely happy because it's very painful for me.
Will create the configuration profile for VS Code itself. that's a better and productive idea.

I bisected and this gets weird. The lag is introduced for me and the other person I know who is experiencing this by the rollback of the app module in commit e095f81. And, per the directions in that commit, unchecking enable browse mode on page load gets rid of it for me and massively improves it for him.

Notably, entering and leaving browse mode after VSCode loads doesn't reintroduce the lag, either. It's specifically that setting.

The NVDA snapshot with the selective event subscription setting doesn't matter for me because there's too little lag left, but for my friend it didn't help.

So I think the next thing for this issue is anyone else trying that. Note that configuration profiles are a thing for anyone who doesn't know that already. You can work around it (if this workaround works) by using a configuration profile to selectively toggle the setting rather than gain a responsive VSCode at the cost of a terrible browsing experience.

@lpintes
Copy link

lpintes commented Sep 20, 2020

Hello all,

I tested the workaround and it works for me.

Currently I am working on one Go project and was not able to use VSCode. I already had a configuration profile to have spoken indentation, it is helping me a lot while reading the code.

Now I switched the mentioned setting and the lag disappeared.

@leonardder
Copy link
Collaborator

leonardder commented Sep 21, 2020

Wow, this workaround also imposes a huge performance increase on my system. This is really one of the ways to go.

This issue is currently scattered with lots of comments, making it very hard to follow the line of the issue. Therefore, I'm thinking about opening a new issue that describes the problem more technically.

@MarcoZehe
Copy link
Contributor

MarcoZehe commented Sep 21, 2020

Wow, this workaround also imposes a huge performance increase on my system. This is really one of the ways to go.

Confirmed, and I am really surprised by this.

This issue is currently scattered with lots of comments, making it very hard to follow the line of the issue. Therefore, I'm thinking about opening a new issue that describes the problem more technically.

Please do. As someone who advocated to remove the original app module that forced application mode in VS Code, so the transitions between actual interactions and pieces that were appropriate for reading mode, I am interested in why NVDA suffers so badly if reading mode is involved.

@akash07k
Copy link
Author

akash07k commented Sep 21, 2020

Seriously, it's amazing! It works flawlessly and drastically improves the performance of VS code as well completely eliminates the lag on my 16 GB memory stick and I7 10th gen system.
@camlorn
Thanks a lot buddy, you really solved one of my biggest problem.
Although with my 8GB laptop, the lag is still, however it is minor.

@akash07k
Copy link
Author

akash07k commented Sep 21, 2020

Really, same here.
Please create the issue it will be great.

Wow, this workaround also imposes a huge performance increase on my system. This is really one of the ways to go.

This issue is currently scattered with lots of comments, making it very hard to follow the line of the issue. Therefore, I'm thinking about opening a new issue that describes the problem more technically.

@leonardder
Copy link
Collaborator

leonardder commented Sep 21, 2020

Here is a new try build that should allow enabling the browse mode on page load setting again.
@akash07k, @MarcoZehe, @lpintes and @camlorn , could you have a test please?

@MarcoZehe
Copy link
Contributor

MarcoZehe commented Sep 21, 2020

Yes, this seems to be both loading browse mode on documents, such as release notes or similar, as well as have better performance when editing files. But let's wait for confirmation from @akash07k since he can more reliably reproduce the sluggishness than I can.

@akash07k
Copy link
Author

akash07k commented Sep 21, 2020

@leonardder
Yes, Agreed with @MarcoZehe
Try build works well even though the "enable browse mode upon page load" check box is checked and there's no lag.
However, I'll test more in order to verify the performance aspect accurately.

@lpintes
Copy link

lpintes commented Sep 21, 2020

@leonardder,
I Tested the try build and can confirm that the lag disappeared.

@ahicks92
Copy link
Contributor

ahicks92 commented Sep 21, 2020

I'll test this weekend if there aren't enough other confirms from people. Bit limited on time this week.

@brunoprietog
Copy link

brunoprietog commented Sep 21, 2020

This is great! It solves VS Code's slowness, although it introduced a bug in Microsoft Edge Chromium. The controls announce them twice and sometimes three times. Does the same thing happen to anyone else?

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