Overriding the default 'type' command and then calling the default 'type' command results in significantly slower execution time

[samueltlg]

• VSCode Version: 1.27.1
• OS Version: Windows 10 1809
• Machine processor: AMD A8-4555M APU Quad core clocked at 1.6GHz
• Graphics card: AMD Radeon HD 7600G

Does this issue occur when all extensions are disabled?: Yes (Aside from VSCodeVim - where the potential problem in the extensions API has been detected)

Steps to Reproduce:

1. Override the 'type' command with vscode.commands.registerCommand
2. Call the default 'type' command instead of the custom command
3. Note the difference in execution time in calling vscode.commands.executeCommand('type', ...) when no custom type command has been registered, vs. calling vscode.commands.executeCommand('default: type', ...) (when a custom command has been registered/is overriding the default 'type' command). On my machine, the difference in execution time is consistently an order of magnitude (roughly 20ms vs 200ms) larger every time the executeCommand('default: type', ...) is called after overriding.

I have included some of my machine details here just-in-case - although I do doubt that they play any part in the issue here.

One of VSCode's most popular plugins, VSCodeVim/Vim, has an issue experienced by a fair share of the VSCodeVim community, as can be seen in an issue raised over a year ago in their repo - VSCodeVim/Vim#2021. Typing in an editor window whilst this plugin is enabled results in an unbearably slow character render time, for a range of slower (and perhaps sometimes slighty-faster-than-slow) machines. During a screen-share a little while ago with @shawnaxsom, a contributor to the VSCodeVim community, we boiled the problem down to the 'type' command being overridden, and then having the default type command executed afterwards. For example, from my understanding of the VSCodeVim extension, the 'type' command is overridden like so:

vscode.commands.registerCommand('type', async ...

The default 'type' command is then called when needed, with code like this:

await vscode.commands.executeCommand('default:type', { text });

We measured the time taken for an ordinary (non-overridden) execution of the type command (which was roughly 20ms on my machine), vs. then calling 'default: type' command, which was always roughly 10x slower. Even though I am not familiar with the extensions API, this is puzzling, since these two calls should be doing exactly the same thing, yet calling executeCommand('default: type', ...) results in a much slower execution time of the default type command. I guess it has been an assumption that the source code in the VSCodeVim extension has been responsible for the severe typing slowness (or, it has only been occurring on slow machines, since it does not occur for everyone using the extension), but our screenshare led us to the conclusion that it appears to be this part of the extensions API which seems to be responsible. I imagine, also, that the much-slower execution time also occurs on faster machines, but it is simply not noticeable due to the fact that the faster processing/graphical power prevents the comparably slower call to the 'type' command being made visible rendering-wise. Even though it shouldn't matter, It is perhaps worth mentioning too, that even if the overridden (type) command is doing minimal work, as far as I know (I think we also tested this), the significant execution time difference still occurs.

[alexdima]

@samueltlg I still believe this is an issue with the VSCodeVim extension. Here is the experiment I have conducted.

Create a minimal extension:

• package.json:

{
    "name": "65876",
    "publisher": "alex",
    "version": "0.0.0",
    "engines": {
        "vscode": "^1.31.0"
    },
    "main": "index.js",
    "activationEvents": [
        "*"
    ]
}

• index.js:

const vscode = require('vscode');

exports.activate = function() {
    console.log(`I am active!`);
    vscode.commands.registerCommand('type', (args) => {
        console.log(`type with args`, args);
        return vscode.commands.executeCommand('default:type', args);
    });
}

---

The above extension makes it that typing in any editor will end up always going through the extension and only then going to the default typing. This feels snappy and good for me:

[samueltlg]

Hi @alexandrudima, thanks for testing that out. A few things I feel worth mentioning:

1. When @shawnaxsom and I performed a screenshare, we had commented out all of the code inside of vscode.commands.registerCommand aside from (await) vscode.commands.executeCommand('default:type', { text }) - and the problem was still occurring. It was essentially a minimal amount of code, as in your example.
2. I should have mentioned that the slowdown does not just occur for typing events - but also clipboard events, and in some cases cursor motion events (cursor being moved up and down lines) - different users tend to have different issues here.
3. The problem does not occur for everyone using VSCodeVim - but still a large number of users. From looking at the posts in the aforementioned issue, it also does seem to occur on a large range of machines - notably in particular on machines with Intel i5 processors and maybe a (few) families of video card. But it still does seem to occur on some faster machines too.

On that last point, did you happen to measure the time for a call to ..executeCommand('default:type') within ..registerCommand vs measuring a standard call to ..executeCommand('type') - even though no problem is visible rendering-wise, perhaps a time measurement will tell a different story.

Later today or tomorrow, I could look into trying out a minimal extension like yourself, and try to reproduce the issue. I will report back. Thanks!

[alexdima]

@samueltlg I also wondered what is the overhead of going through the extension host for typing, so I applied the following diff to vscode to measure it:

diff --git a/src/vs/editor/browser/controller/textAreaInput.ts b/src/vs/editor/browser/controller/textAreaInput.ts
index 7ccf0e99d2..4700cba17f 100644
--- a/src/vs/editor/browser/controller/textAreaInput.ts
+++ b/src/vs/editor/browser/controller/textAreaInput.ts
@@ -54,6 +54,8 @@ const enum TextAreaInputEventType {
 	blur
 }
 
+export let lastKeyDownTime: number;
+
 /**
  * Writes screen reader content to the textarea and is able to analyze its input events to generate:
  *  - onCut
@@ -125,6 +127,8 @@ export class TextAreaInput extends Disposable {
 		this._nextCommand = ReadFromTextArea.Type;
 
 		this._register(dom.addStandardDisposableListener(textArea.domNode, 'keydown', (e: IKeyboardEvent) => {
+
+			lastKeyDownTime = Date.now();
 			if (this._isDoingComposition &&
 				(e.keyCode === KeyCode.KEY_IN_COMPOSITION || e.keyCode === KeyCode.Backspace)) {
 				// Stop propagation for keyDown events if the IME is processing key input
diff --git a/src/vs/editor/browser/viewParts/lines/viewLine.ts b/src/vs/editor/browser/viewParts/lines/viewLine.ts
index 1467d539a3..b17998876e 100644
--- a/src/vs/editor/browser/viewParts/lines/viewLine.ts
+++ b/src/vs/editor/browser/viewParts/lines/viewLine.ts
@@ -16,6 +16,7 @@ import { CharacterMapping, ForeignElementType, RenderLineInput, renderViewLine }
 import { ViewportData } from 'vs/editor/common/viewLayout/viewLinesViewportData';
 import { InlineDecorationType } from 'vs/editor/common/viewModel/viewModel';
 import { HIGH_CONTRAST, ThemeType } from 'vs/platform/theme/common/themeService';
+import { lastKeyDownTime } from 'vs/editor/browser/controller/textAreaInput';
 
 const canUseFastRenderedViewLine = (function () {
 	if (platform.isNative) {
@@ -213,6 +214,8 @@ export class ViewLine implements IVisibleLine {
 			return false;
 		}
 
+		console.log(`${Date.now() - lastKeyDownTime}ms since last input -- ${renderLineInput.lineContent}`);
+
 		sb.appendASCIIString('<div style="top:');
 		sb.appendASCIIString(String(deltaTop));
 		sb.appendASCIIString('px;height:');

Please note that the rendering occurs at the next animation frame, so it is delayed until Electron considers it would be a good idea for us to render, i.e. the times below do not indicate the time it takes to interpret the typing, but indicate the elapsed time from when the keydown was first received until a line was painted:

• typing "hello world" without the extension:

38ms since last input -- h
7ms since last input -- he
7ms since last input -- hel
5ms since last input -- hell
4ms since last input -- hello
5ms since last input -- hello 
5ms since last input -- hello w
5ms since last input -- hello wo
4ms since last input -- hello wor
3ms since last input -- hello worl
10ms since last input -- hello world

• typing "hello world" with the extension:

27ms since last input -- h
15ms since last input -- he
15ms since last input -- hel
11ms since last input -- hell
19ms since last input -- hello
29ms since last input -- hello 
20ms since last input -- hello w
24ms since last input -- hello wo
12ms since last input -- hello wor
27ms since last input -- hello worl
12ms since last input -- hello world

Although non-negligible, the latency of going to the extension host process and back is somewhere in the 10-15ms ballpark, which is still fast enough to make typing feel buttery smooth.

TL;DR I don't think there is an issue with VS Code here...

[alexdima]

I was curious to dig a bit deeper. The larger times are mostly because the frame is missed and the painting occurs at the next frame (and the times above measure the elapsed time from keypress until the paint occurs), not due to latency. To validate this, I have built an action that tests the latency of going to the extension host process, as well as the throughput. It will come out with tomorrow's insiders

e.g. Developer: Measure Extension Host Latency

Roundtrip latency: 0.690ms
Up: 586.9 Mbps
Down: 487.2 Mbps

[samueltlg]

Thanks @alexandrudima, I will use that feature in tomorrow’s insider build to see the result; and wil emulate your prior vs code build and simple extension.

[shawnaxsom]

Slower devices will have more delay, for one, but not enough for one character to be slow. The problem is that VSCodeVim handles keys one at a time, since any string of keys can be mapped to an action. Those 15ms might become 65ms on a slow machine, and the delays add up quickly if pressing a string of characters.

…

On Wed, Jan 16, 2019, 11:26 AM Li Yiming ***@***.*** wrote: Markdown All in One <https://github.com/neilsustc/vscode-markdown/> also overrides the default type command, when we edit large markdown files, the delay is very obvious. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#65876 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAlGwg_tLKj-qNQOnobKpdQigzsn5duMks5vD1K4gaJpZM4Zlv4r> .

[samueltlg]

I apologise profusely for letting this issue go dead by not responding a couple of months ago; I had a prolonged emergency situation and never got round to testing and reporting back on the effects of the provided minimal extension. I was reminded by the issue reference yesterday and have got round to trying it out.

Big surprise. The simple extension provided incurs very-almost the same performance penalty as VSCodeVim (with Vim and all other extensions disabled, of course). This came as a shock to me, because I did think that perhaps it was VSCodeVim after all. I have made extra sure that there is nothing else interfering. The basic 'hello world' predictably has no effect on typing, but simply adding the few lines of code to override the type command and execute the default type command within, has a very large effect on rendering/performance. As you say @alexandrudima, it is perhaps due to the frame being missed and the rendering occurring at the next frame.

I have not attempted to apply the diff to vscode for measuring typing (rendering) latency via going through the extension host; if this would be helpful, I could report back on this. Unremarkably, too, the measured extension host latency is around 2-3ms. Quite the shock indeed.. if there is anything I can do to assist and test, please do let me know.

[xconverge]

Is there anything I can do to assist with this?

[johnfn]

The number of thumbs up on this issue is deceptive. It's the second most highly upvoted issue for VSCodeVim: VSCodeVim/Vim#2021

[ishammahajan]

This particular issue is affecting many extensions. Those of us who like the excellent auto-completion on vscode and the powerful features of a modal editor like vim find this a deal breaker :(

Please give this issue some love ❤️
Thanks!

[alexdima]

In our latest Insiders Build, we have added a new experimental setting that would allow to execute the vim extension in a dedicated extension host process.

Configure the following in your settings.json and then reload window or restart:

"extensions.experimental.affinity": {
	"vscodevim.vim": 1,
	"asvetliakov.vscode-neovim": 1
},

---

You can double check that vim is loaded in a separate process using F1 > Developer: Show Running Extensions:

[vscodenpa]

This feature request is now a candidate for our backlog. The community has 60 days to upvote the issue. If it receives 20 upvotes we will move it to our backlog. If not, we will close it. To learn more about how we handle feature requests, please see our documentation.

Happy Coding!

[vscodenpa]

🙂 This feature request received a sufficient number of community upvotes and we moved it to our backlog. To learn more about how we handle feature requests, please see our documentation.

Happy Coding!

[JuanQuiro]

I came to this comment by suggestion from the extension documentation and I don't understand anything... How can I configure VSCodeVim with Jump?

[wenfangdu]

@JuanQuiro Hi, Jump's author here, you can paste the following config into your VSCode settings.json:

{
  "extensions.experimental.affinity": {
    "wenfangdu.jump": 1
  }
}

[max-sixty]

In our latest Insiders Build, we have added a new experimental setting that would allow to execute the vim extension in a dedicated extension host process.

FWIW:

• I tried this, for vscode-vim
• It seemed worse — typing lots of characters quickly on opening VS Code caused some to end up in front of the cursor
• Removing the setting from settings.json didn't seem to remove it — changing the vim extensions' settings in settings.json didn't seem to impact its behavior. I was still seeing output in Output -> Window that vim was in a different process after running "Reload Window" (also after quitting and restarting VS Code)
• I ended up wiping ~/Library/Application Support/Code, which then took a while to restore settings
  • Possibly I should have tried restarting the machine, if it was in a process outside VS Code?

So — I wouldn't recommend trying this unless you really need it.

If this is wrong, very happy to be corrected by someone knowledgeable about the code — clearly one person having a bad experience shouldn't be weighed that much.