Optimize editor for input latency

[Tyriar]

I recently did an exploration into input latency and found it can get pretty bad on slower machines. A lot of the problem is related to how we use synchronous event emitters/listeners work, performing their work after keypress but before the animation frame.

My proposal to improve is:

1. Review the most time consuming event listeners. If they are clearly safe to be performed at a later time without worrying about race conditions being introduced., move them to use an asynchronous event listener to be performed after the animation frame. For example UI updates like activity bar badge and tab indicator when an editor becomes dirty
2. Review all events and their listeners, defer as much as possible to after the animation frame. One way of doing this is for each important event to have both a sync and an async event. It's unclear how much we can move exactly, but when we do this we need to be extremely careful to not introduce text buffer-related race conditions as there are some assumptions made that we may be breaking by doing this
3. Setup development tools and/or telemetry to easily track measuring latency, I created https://github.com/microsoft/vscode/tree/tyriar/measure_latency to demonstrate a technique to approximate input latency
4. Come up with a plan for how we can prevent regressions for this critical path code

Tentatively assigning to October

[bpasero]

The core listener for text editors to react on content changes is:

• https://github.com/microsoft/vscode/blob/da506e9b8d86a7265d53255ef8a8603d792d74f5/src/vs/workbench/services/textfile/common/textFileEditorModel.ts#L565
• https://github.com/microsoft/vscode/blob/da506e9b8d86a7265d53255ef8a8603d792d74f5/src/vs/workbench/services/untitled/common/untitledTextEditorModel.ts#L361

These drive a ton of things on top such as:

• dirty state indication throughout the UI (only when dirty state changes, not on every content change)
• editor auto save
• editor backups
• etc (anyone using onDidChangeDirty and friends)

I wonder how an async emitter would help here: yes, it would take away lag from the first character typing when the editor transitions into being dirty, but eventually we have to pay the price, so the lag would just happen later? Or is the idea to delay the event literally on idle time?

[Tyriar]

@bpasero oh I missed the question there. The idea is to delay it until shortly after via setTimeout, so the text change should appear asap and the dirty indicator (as an example) would appear 1 or 2 frames later. ie:

Current:

• keypress task:
  • handle dirty change
  • schedule various things (backup, auto save, etc.)
  • other less critical updates (bracket pair parsing?)
  • render

Desired:

• keypress task:
  • handle dirty change
  • render
• following task:
  • schedule various things (backup, auto save, etc.)
  • other less critical updates (bracket pair parsing?)
  • render (whatever changed in this task)

There's some nuance here in what should be handled in the keypress task. For example currently the suggest widget is moved and updated in the keypress task. What we probably want is for the suggest widget to move in the keypress task but defer updating as it can be very expensive. Things like this we'll need to experiment with to see if splitting it up ends up with a worse UX and should be on the critical path.

We may be able to optimize the list's splice method as well to help here, haven't looked at the impl yet but it seems to do a lot of work and also affects search performance/ui responsiveness I saw last week.

[Tyriar]

Realized one of my laptops has a CPU similar to the average users (though a better GPU). Here's a screenshot of typing this into TerminalInstance.ctor which validates my assumptions that latency is pretty terrible on lower hardware (up to 100ms in this case):

This is with a i7-8750H @ 2.2 GHz, didn't turn off turbo boost which can push it up to 4.10 GHz. Not entirely sure how that works but I think I can disable it in BIOS if needed.

Though I haven't tested thoroughly on the laptop, I'm quite surprised that it seems to actually perform much worse than 4x CPU throttle on my primary machine (i7-12700KF @ 3.61 GHz, boost 5.00 GHz). I was expecting it to be the other way around.

[Tyriar]

I drilled into a profile on my macbook to understand some parts a little more. Here are the details

TLDR: An enormous amount of work seems to be spent just scheduling things, Event.defer will probably be an easy solution to those.

Latency

• Keydown to character on screen ~30.52ms
• Keydown to suggest on screen ~106.6ms

High level parts

• Critical path 30.52ms
  • Key down 1.85ms (6%)
  • Key press 15.43ms (51%)
  • Render animation frame 6.91ms (23%)
  • Render to composite 4.56ms (15%)
• Suggest
  • Waiting for suggestions from extension host 37.1ms
  • Suggest widget setup/adding 30.87ms
  • Suggest widget rendering 8.37ms

Key press

15.43ms (51% of critical path)

Most expensive bottom up parts

• setTimeout 3.4ms (22%)
  • Async timeouts are definitely disabled
  • A lot of this is due to the sheer amount of timeouts, a shared timeout like in Event.defer will improve
• Recalculate style and layout 1.8ms (12%)
  • This is done because of the text input event from the keypress, nothing we can do if we're using an /</li> </ul></li> <li>clearTimeout 0.7ms (5%) <ul> <li>We may be able to avoid clearing some?</li> </ul></li> <li>requestAnimationFrame 0.2ms (1.5%)</li> <li>requestIdleCallback 0.2ms (1.5%)</li> <li>setInterval 0.2ms (1.5%)</li> </ul> <h3>What is it doing?</h3> <p>Legend:</p> <p>:bulb: We can probably improve or defer this fairly easily :question: We can maybe improve this, needs more investigation/validation</p> <ul> <li>_type @ codeEditorWidget.ts 11.54ms <ul> <li>_executeCursorEdit 10.57ms (69%)</li> <li>_executeEdit 2.99ms <ul> <li>pushEditOperation @ editStack.ts 0.96ms</li> <li>:bulb: parseDocumentFromTextBuffer @ bracketPairsTree.ts 0.12ms (can be merged with below occurrence)</li> <li>endDeferredEmit</li> <li>onDidChangeContentOrInjectedText @ viewModelImpl.ts 0.39ms</li> <li>modelService scheduling 0.16ms <ul> <li>:bulb: Consolidate scheduling?</li> </ul></li> <li>scheduleBackup 0.5ms <ul> <li>:bulb: Cancels and restarts a timeout</li> </ul></li> <li>triggerDiff @ dirtyDiffDecorator.ts 0.13ms <ul> <li>:bulb: Consolidate scheduling?</li> </ul></li> <li>Schedule syncing with ext host 0.5ms <ul> <li>:bulb: Stringify and multiple setTimeouts</li> <li>This is already async, perfect for Event.defer</li> </ul></li> <li>setSelections @ cursorCollection.ts 0.11ms</li> </ul></li> <li>endEmitViewEvents <ul> <li>_emitMany @ viewModelEventDispatcher.ts</li> <li>_scheduleRender @ view.ts 0.24ms <ul> <li>:question: Mainly just requests an animation frame</li> </ul></li> <li>writeScreenReaderContent @ textAreaInput.ts 1.41ms <ul> <li>This is a result of setting value on textarea, triggers a recalc style, layout, scroll which is a little weird?</li> <li>:bulb: Defer to after render when accessibility mode is off?</li> </ul></li> <li>onLinesChanged @ viewLayer.ts 0.13ms</li> <li>onCursorStateChanged 0.62ms <ul> <li>:question: Updates the cursor blinking; on input the interval gets reset</li> </ul></li> <li>_emitOutgoingEvents @ viewModelEventDispatcher.ts</li> <li>:bulb: Bracket pair matching scheduling 0.11ms</li> <li>computeLinks @ links.ts0.35ms <ul> <li>_updateScores @ languageFeatureRegistry.ts 0.11ms</li> <li>:bulb: Schedules language detection?</li> <li>:bulb: More unknown scheduling 0.24ms</li> </ul></li> <li>Schedule tokenize viewport 0.11ms <ul> <li>:question: This is done even though tokenize if cheap runs?</li> </ul></li> <li>:bulb: Schedule multicursor selection highlighter 0.13ms</li> <li>:bulb: Schedule updateInlineValuesScheduler @ debugEditorContribution.ts 0.38ms</li> <li>notifyNavigation @ historyService.ts 0.13ms <ul> <li>This is keeping the history stack up to date, probably needed</li> </ul></li> <li>triggerFolderingModelChanged @ folding.ts 0.24ms <ul> <li>:bulb: Schedules folding changes</li> <li>:bulb: This creates a new function each trigger? Extra time is probably spent in V8 compiling/optimising</li> </ul></li> <li>beginComputeCommentingRanges @ commentsEditorContribution.ts 0.11ms <ul> <li>:bulb: Just schedules</li> </ul></li> <li>onDidChangeModelContent @ lightBulbWidget.ts 0.12ms <ul> <li>:bulb: This just gets the editor model and hides the light bulb widget if needed, good candidate for deferral</li> </ul></li> <li>unicodeHighlighter.ts 0.13ms <ul> <li>:bulb: Just schedules</li> </ul></li> <li>inlayHintsController.ts 0.38ms <ul> <li>:bulb: Just schedules and debounces for 1250ms</li> </ul></li> <li>documentSymbolsOutline.ts 0.11ms <ul> <li>:bulb: Just schedules/debounces</li> </ul></li> <li>_onModelChange @ codeLensController.ts 2.87ms <ul> <li>:bulb: This is a lot of time devoted to code lenses, could all these be deferred?</li> <li>changeDecorations @ codeEditorWidget.ts 2.74ms</li> <li>Creating a changeAccessor object ~0.15ms – :bulb: Could be optimized</li> <li>endDeferredEmit 2.61ms</li> <li>languageDetection.contribution.ts 0.37ms – :bulb: Just scheduling</li> <li>inlineCompletionsModel.ts 0.25ms – Update ranges, updateFilteredInlineCompletions – :bulb: Schedule auto update</li> <li>bracketMatching.ts 0.40ms – :bulb: Just scheduling for 50ms</li> <li>suggestWidgetPreviewModel.ts 0.61ms – :question: Updates and schedules</li> <li>onSelectionChange @ editorStatus.ts 0.13ms – :question: Update</li> <li>_onCursorChange @ codeActionModel.ts 0.25ms – :bulb: Just scheduling</li> <li>inlineCompletionsModel.ts 0.13ms – :question: Updating – Is this doing duplicate work as above? Can this be debounced to a microtask?</li> <li>onDidChangeCursorPosition @ documentSymbolsOutline.ts 0.11ms – :bulb: Just scheduling</li> <li>_onCursorChange @ suggestModel.ts 0.26ms – :question: Schedules based on some state and the selection</li> <li>mainThreadEditor.ts 0.11ms – :question: Generates a delta of the editor and fires properties change (to sync with ext host?) – :question: <code>_readVisibleRangesFromCodeEditor</code> which calls codeEditor.getVisibleRanges() is the most expensive thing here</li> <li>Schedule asking for all references 0.13ms</li> <li>Not sure we could defer this but we could probably optimize</li> </ul></li> </ul></li> <li>_type @ codeEditorWidget.ts 0.97ms</li> <li>onDidType @ parameterHintsModel.ts 0.1ms</li> <li>handleUserInput @inlineCompletionsModel.ts 0.14ms <ul> <li>Just hides or schedules</li> </ul></li> <li>checkTriggerCharacter @ suggestModel.ts 0.73ms <ul> <li>tokenizeIfCheap 0.49ms</li> <li>parseDocumentFromTextBuffer @ bracketPairsTree.ts 0.13ms (! This is much worse on my Windows machine?)</li> <li>provideSuggestionItems</li> </ul></li> </ul></li> <li>Microtasks 0.31ms <ul> <li>? @ defaultWorkerFactory.ts 0.15ms</li> <li>Not sure what triggers this</li> </ul></li> </ul> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>The methodology, using the "Performance" tab was flawed, it exagerates timeouts (even when async stacks are disabled) and the overhead slows it by around 4x. A profile in the JavaScript Profiler tab is much more accurate and you can also perform the operation many times and then look as the slow parts in terms of the percentage of time they take up. By looking at the percentage instead of actual milliseconds it's much more reliable to get a good sample as it consolidates all calls.</p> <p>For example I recorded typing many bunch of characters, in top down you can now see a more accurate view of the function. This <code>fn</code> is the keypress handler and it shows it took up 17.85% of the CPU time:</p> <img width="426" alt="Screen Shot 2022-10-14 at 8 38 51 am" src="https://user-images.githubusercontent.com/2193314/195886303-68dd0d8b-d621-44e9-9227-acc634607c47.png"> <p>Now focusing on that function shows the breakdown of the call stack as a percentage of the total <code>fn</code> time. One of the suspected functions contributing to the slow down is the bracket pair parsing which you can see takes up 1% of the time after cheap tokenization:</p> <img width="924" alt="Screen Shot 2022-10-14 at 8 40 50 am" src="https://user-images.githubusercontent.com/2193314/195886694-e109c59b-211d-4d6a-9ee7-ca799a0b749b.png"> <p>And 8.39% of the time after the model content changes:</p> <img width="934" alt="Screen Shot 2022-10-14 at 8 43 14 am" src="https://user-images.githubusercontent.com/2193314/195887201-d5a5dae4-da11-4ea6-822c-b25c6973d6e1.png"> <p>Looking into this some more now.</p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>Here's a breakdown of the CPU profile when typing a bunch of characters (~50, random), the suggest widget didn't show most of the time. This tree isn't complete, a lot is omitted here to remove noise vs just looking at the profile in devtools. The children of a node are not ordered and not necessarily directly below the parent or siblings of other children.</p> <p>❌ = Too risky to touch</p> <p>This is a living document for now:</p> <ul> <li>100%: fn - keypress handler <ul> <li>94.53%: _type</li> <li>11.55%: onWillType <ul> <li>10.75%: checkTriggerCharacter - suggestModel.ts</li> <li>0.30%: provideSuggestionItems - suggest.ts</li> <li>0.68%: getWordAtPosition - textModel.ts</li> <li>9.30%: tokenizeIfCheap - tokenizationTextModelPart.ts</li> </ul></li> <li>82.76%: type <ul> <li>52.68%: endEmitViewEvents - viewModelEventDispatcher.ts</li> <li>44.59%: emitOutgoingEvents <ul> <li>onDidChangeModelContent</li> <li>0.87%: editorStatus.ts <ul> <li>[ ] <a href="https://github.com/microsoft/vscode/pull/163836">https://github.com/microsoft/vscode/pull/163836</a></li> </ul></li> <li>27.16%: suggestModel.ts - refilters items <ul> <li>[ ] This is a lot of time devoted to suggest when it's barely shown</li> <li>21.12% showSuggestions - suggestWidget.ts</li> <li>[ ] Drill into this</li> <li>2.51%: cancel - suggestModel.ts</li> <li>[ ] 2.51% to cancel?</li> <li>1.33%: shouldAutoTrigger - suggestModel.ts</li> </ul></li> <li>0.23%: inlayHintsController.ts</li> <li>0.27%: clickLinkGesture.ts</li> <li>0.57%: links.ts</li> <li>0.34%: unicodeHighlighter.ts</li> <li>0.30%: commentsEditorContribution.ts</li> <li>1.67%: lightBulbWidget.ts <ul> <li>1.37%: _updateLightBulbTitleAndIcon</li> <li>[x] <a href="https://github.com/microsoft/vscode/pull/163848">https://github.com/microsoft/vscode/pull/163848</a></li> </ul></li> <li>1.56%: textEditor.ts <ul> <li>1.52%: handleActiveEditorSelectionChangeEvent - historyService.ts - Records navigation for back/forward</li> <li>[ ] <a href="https://github.com/microsoft/vscode/pull/163845">https://github.com/microsoft/vscode/pull/163845</a></li> </ul></li> <li>0.27%: viewPortSemanticTokens.ts</li> <li>0.57%: folding.ts - Reschedules and makes minor changes to hiddenRangeModel</li> <li>0.27%: documentSymbolsOutline.ts <ul> <li>[ ] Does sharing a timeout help?</li> </ul></li> <li>8.58%: codelensController.ts <ul> <li>8.36%: changeDecorations - textModel.ts</li> <li>0.38%: emitMany - viewModelEventDispatcher.ts</li> <li>7.44%: _emitOutgoingEvents - viewModelEventDispatcher.ts <ul> <li>0.23%: multicursor.ts</li> <li>0.84%: suggestWidgetPreviewModel.ts</li> <li>0.46%: inlineCompletionsModel.ts</li> <li>0.61%: textEditor.ts</li> <li>0.57%: historyService.ts - records navigation <ul> <li>[ ] This happens multiple times</li> </ul></li> <li>0.27%: suggestModel.ts</li> <li>1.41%: editorStatus.ts - Updating the status bar lines/cols</li> <li>[ ] <a href="https://github.com/microsoft/vscode/pull/163836">https://github.com/microsoft/vscode/pull/163836</a></li> <li>0.27%: languageDetectionContribution.ts</li> <li>0.15%: bracketMatching.ts</li> <li>0.57%: inlineCompletionsModel.ts</li> <li>1.71%: mainThreadEditor.ts</li> <li>❌ Syncing with ext host? Risky to change</li> <li>0.19%: codeActionModel.ts</li> </ul></li> </ul></li> <li>0.49%: testingDecorations.ts</li> </ul></li> <li>8.01%: emitMany <ul> <li>6.96%: handleEvents - viewEventHandler.ts</li> <li>0.68%: onRevealRangeRequest - viewLines.ts</li> <li>0.84%: onCursorStateChange - viewCursors.ts</li> <li>0.19%: onCursorStateChange - currentLineHighlight.ts</li> <li>4.18%: onCursorStateChange - textAreaHandler.ts - writeScreenReaderContent <ul> <li>[x] <a href="https://github.com/microsoft/vscode/pull/163677">https://github.com/microsoft/vscode/pull/163677</a></li> </ul></li> <li>0.72%: handleEvents - view.ts</li> <li>0.46%: _scheduleRender - view.ts <ul> <li>[ ] Investigate</li> </ul></li> </ul></li> <li>30.08%: type</li> <li>25.29%: _executeEditOperation <ul> <li>23.59%: pushEditOperations</li> <li>14.28%: _pushEditOperations <ul> <li>1.71%: applyEdits</li> <li>0.49%: acceptEdit</li> <li>0.76%: acceptReplace</li> <li>8.93%: _emitContentChangedEvent</li> <li>8.05%: parseDocumentFromTextBuffer - bracketPairsTree.ts <ul> <li>[ ] <a href="https://github.com/microsoft/vscode/pull/163958">https://github.com/microsoft/vscode/pull/163958</a></li> </ul></li> <li>0.42%: _beginBackgroundTokenization</li> </ul></li> <li>8.51%: endDeferredEmit <ul> <li>1.60%: onDidChangeContentOrInjectedText - viewModelImpl.ts</li> <li>6.42%: onDidChangeContent - textModel.ts</li> <li>3.04%: onDidChangeContent - mainThreadDocuments.ts - Syncing model changes with ext host</li> <li>0.42%: onDidChangeContent - dirtydiffDecorator.ts</li> <li>2.70%: onDidChangeContent - textFileEditorModel.ts <ul> <li>1.82%: onDidChangeContent - workingCopyService.ts</li> <li>[ ] <a href="https://github.com/microsoft/vscode/pull/163687">https://github.com/microsoft/vscode/pull/163687</a> (deferred to November)</li> <li>0.87%: workingCopyHistoryTracker.ts</li> <li>0.76%: workingCopyBackupTracker.ts</li> </ul></li> </ul></li> </ul></li> </ul></li> </ul></li> </ul> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>Profile when typing <code>.</code> after this and backspace repeatedly to measure high-level impact of suggest widget.</p> <ul> <li>96.19% <code>_type</code> - codeEditorWidget.ts <ul> <li>5.32% <code>checkTriggerCharacter</code> suggestModel.ts </li> <li>72.37% <code>_insertSuggestion</code> - suggestWidget.ts</li> <li>63.53% <code>insert</code> - snippetController2.ts <ul> <li>[ ] Snippet leading to show suggest?</li> <li>61.15% <code>insert</code> - snippetSession.ts</li> <li>58.85% <code>executeEdits</code> - codeEditorWidget.ts</li> <li>[ ] What's being executed? Is this just in an unexpected spot in the stack trace?</li> <li>48.99% <code>endEmitViewEvents</code></li> <li>43.74% <code>_refilterCompletionItems</code> - suggestModel.ts <ul> <li>43.31 _onNewContext (firing event) - suggestModel.ts</li> <li>42.73% <code>showSuggestions</code> - suggestWidget.ts <ul> <li>37.12% <code>_layout</code> - suggestWidget.ts</li> <li>Double rendering</li> <li>[ ] <a href="https://github.com/microsoft/vscode/pull/163947">https://github.com/microsoft/vscode/pull/163947</a></li> <li>30.00% <code>getScrolledVisiblePosition</code> codeEditorWidget.ts <ul> <li>[ ] No scrolling was happening in either the editor or the suggest widget</li> </ul></li> <li>29.71% <code>_renderNow</code> - view.ts</li> <li>5.68% render - minimap.ts <ul> <li>[ ] Minimap shouldn't block text rendering?</li> </ul></li> <li>4.60% render - contentWidgets.ts <ul> <li>4.6% afterRender - suggestWidget.ts</li> <li>[ ] Investigate</li> </ul></li> <li>2.01% prepareRender - viewOverlays.ts <ul> <li>1.44% prepareRender - indentGuides.ts</li> <li>[ ] Investigate</li> </ul></li> <li>7.34% prepareRender - textAreaHandler.ts <ul> <li>7.34% _readPixelOffset - viewLine.ts</li> <li>[ ] DOM access?</li> </ul></li> <li>5.54% renderText - viewLines.ts <ul> <li>Double rendering of text buffer!</li> </ul></li> <li>5.61% getDomNodePagePosition - dom.ts <ul> <li>[ ] DOM access?</li> </ul></li> </ul></li> <li>4.96% <code>splice</code> - listWidget.ts</li> </ul></li> <li>9.50% <code>(</code>anonymous) - viewModelImpl.ts <ul> <li>8.63% <code>pushEditOperations</code> - TextModel.ts</li> </ul></li> </ul></li> <li>1.08% <code>memorize</code> - suggestMemory.ts</li> <li>6.12% <code>cancel</code> - suggestModel.ts <ul> <li>6.04% <code>hideWidget</code> - suggestWidget.ts</li> <li>~Hiding is 6% when it shouldn't be getting hidden?~ It does hide it briefly before showing new results from exthost? Most of the time is spent in list splice</li> </ul></li> <li>3.02% <code>splice</code> - listWidget.ts</li> <li>17.77% <code>type</code> - viewModelImpl.ts</li> <li>Similar to the profile above</li> <li>4.46% <code>typeWithInterceptors</code> - cursorTypeOperations.ts <ul> <li>4.17% <code>_runAutoIndentType</code> - cursorTypeOperations.ts</li> </ul></li> <li>6.04%_<code>executeEditOperation</code></li> </ul></li> </ul> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>The big revelation above is that there's a full render in both the keypress and the animation frame events, triggered by the suggest widget 🤯:</p> <p><img src="https://user-images.githubusercontent.com/2193314/196268849-7ad8cf37-0a20-416c-b720-5471b5baef89.png" alt="image" /></p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>Here's a breakdown of the list <code>splice</code> calls made when filtering suggest. This is a general area I've noticed is a little slow in other areas like search. This particular profile ("c", backspace, repeat to refilter on both) showed <code>ListWidget.splice</code> taking up 11.28% of the total keypress task.</p> <p><img src="https://user-images.githubusercontent.com/2193314/196492047-dd2d51db-e727-4032-9212-26e3251d62b1.png" alt="image" /></p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>After digging through how List.splice and in particular <code>HighlightedLabel.render</code>, nothing's sticking out in list's splice as an obvious way to improve performance unfortunately.</p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>After pulling all the proposed changes into a single branch (<a href="https://github.com/Microsoft/vscode/tree/tyriar/all_latency_changes">tyriar/all_latency_changes</a>) this is what pressing <code>.</code> after a <code>this</code> looks like. The red will mostly go away if we implemented the GPU-based renderer (<a href="https://github.com/microsoft/vscode/issues/162445">https://github.com/microsoft/vscode/issues/162445</a>), the blue part is minimap rendering which could be significantly sped up by moving to webgl.</p> <p><img src="https://user-images.githubusercontent.com/2193314/196552761-fd6b2dbe-4e0e-4448-b1b5-4f48b0a3dbe2.png" alt="image" /></p> <p>Current main: <details> <img src="https://user-images.githubusercontent.com/2193314/196554587-28bf3030-3a8e-4c47-a069-74cc1c7b3621.png" alt="image" /> </details></p> <p>After the completion response comes back from the exthost this happens:</p> <p><img src="https://user-images.githubusercontent.com/2193314/196553613-d7aad928-d44d-42d7-b624-d4cc6caa5a34.png" alt="image" /></p> <p>Current main: <details> <img src="https://user-images.githubusercontent.com/2193314/196554707-42778e92-a70a-48a8-8d44-abce2b5fa67d.png" alt="image" /> </details></p> <p>I couldn't find many more wins here, most of it is bound by list splice and fetching the position of elements from the DOM (maybe something here could improve?). There are wins from moving to webgl as well but it would probably be more effort than it's worth to maintain.</p> <hr /> <p>Here is a look at re-filtering the already visible suggest widget:</p> <p><img src="https://user-images.githubusercontent.com/2193314/196553995-0e57a40d-7f54-457d-8e87-a9d9839869d6.png" alt="image" /></p> <p>Current main: <details> <img src="https://user-images.githubusercontent.com/2193314/196554790-232c5456-28b5-4951-8506-0314025142fb.png" alt="image" /> </details></p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>Just discovered this issue: <a href="https://github.com/Microsoft/vscode/issues/27378">https://github.com/Microsoft/vscode/issues/27378</a></p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>Using typometer, here are the results for xterm.js, with a few changes to get it closer to what we could expect as the upper bound of adopting the webgl renderer:</p> <p><img src="https://user-images.githubusercontent.com/2193314/197283594-026e2662-afe4-4c95-ac42-9062dba984dd.png" alt="image" /></p> <p>Those are some pretty nice numbers 🙂, of course the model updates/events in bare xterm.js aren't nearly as costly as in vscode's editor though. The viewport is also quite small in xterm.js' demo which affects the time it takes to fill in the webgl buffers.</p> <p>Interestingly, those 2 ones that are very low with 8.2-8.3 averages are when I was taking a devtools performance profile. My theory is it's related to performance vs efficiency cores in my i12 CPU. They are also far more consistent during the performance profile:</p> <img width="580" alt="image" src="https://user-images.githubusercontent.com/2193314/197283884-0d89f8c4-6f1a-468f-b5f9-0a92d52d3048.png"> <p>Compared to the other 3:</p> <img width="579" alt="image" src="https://user-images.githubusercontent.com/2193314/197283930-0b1ca32a-5f8a-44c4-870e-c8a8ad68b72b.png"> <p>Another thing I noticed are the big spikes that sometimes occur. This is actually why I did the performance profile to have a look at them. Here's an example (edited the screenshot as the iterations part was giant and couldn't be collapsed):</p> <p><img src="https://user-images.githubusercontent.com/2193314/197284401-ba0c70f0-39d4-47e7-b28d-2a5db674b05c.png" alt="image" /></p> <p>I can't explain this as the work appears to be done right at the start, like all the other frames. Perhaps it's another application eating more CPU time? Or Chromium doing something and deciding to drop those frames? I tried to set process affinity/priority which didn't change the results. Also the processes are not marks as "efficiency mode" in task manager regardless of what task manager said, I think this doesn't map to efficiency cores though.</p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>~Ok I'm pretty sure it is efficiency vs performance cores. I disabled all efficiency cores in BIOS and I get the good numbers of about 8ms average~ - I tried later and even with efficiency cores disabled I get the different set of numbers.</p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/max-sixty"><img src="https://avatars.githubusercontent.com/u/5635139?v=4" />max-sixty</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>@Tyriar I don't want to add noise to this issue, but I'm excited to see you working on this. I've kept an eye on latency and though I could give some comparisons for context:</p> <p>I found VSCode quite good — a lower min/max/mean that emacs & vim — at least on a high-spec Macbook Pro. Specifically, from a couple of years ago, typometer got 9.7/27.1/16.8 for min/max/mean; relative to 48/77/60 for vim and 29/48/38 for emacs.</p> <p>I just reran it a couple of times now and got higher max & means in VSCode 1.72.2: 9.7/66.2/23.1 & 7.4/49.6/21.9. So maybe something has got slightly worse, or maybe the setups a different. Min is still impressively low!</p> <p>To the extent we get a few ms saving, that's appreciated — I think I can notice a difference when there's more immediate feedback; even small amounts of latency or jitter feel worse (maybe needs a blind test though :) )</p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>@max-sixty good to hear, I've been trying to squeeze out ms here and there for the past month or so, a lot of the changes are still in review though 🙂 </p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>For the unexplained xterm.js numbers, it appears to be related to extensions, incognito fixes the problem. Perhaps it waits on some extension APIs when not profiling?</p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>Looking at the spikes in the profiles again I think I can explain it now:</p> <img width="414" alt="image" src="https://user-images.githubusercontent.com/2193314/197296507-73bc38a8-7ec4-46fd-ab6e-071ad62c6f00.png"> <p>There is a task that does <code>Compute Intersections</code> where this happens:</p> <p><img src="https://user-images.githubusercontent.com/2193314/197296495-11a4aaf9-e79d-444a-a672-b6e1c45932ce.png" alt="image" /></p> <p>These are for intersection observers which xterm.js <a href="https://github.com/Tyriar/xterm.js/blob/8d4d5bd54ba76a12d25995cc47ab6f9808bfb390/src/browser/services/RenderService.ts#L118-L122">does indeed use</a>. <a href="https://developer.chrome.com/en/blog/new-in-devtools-92/#computed-intersections">https://developer.chrome.com/en/blog/new-in-devtools-92/#computed-intersections</a></p> <p>There are other places where <code>Compute Intersections</code> happens that don't have a spike, but all spikes contain a <code>Compute Intersections</code>.</p> <p>I disabled the textarea syncing to avoid intersection needing to be recomputed and the results seem to be better. There are still the occasional spikes:</p> <img width="479" alt="image" src="https://user-images.githubusercontent.com/2193314/197297307-c92076b5-19c0-49db-a34f-944e8251e126.png"> <p>Zooming into this one, it's happening because the <code>requestAnimationFrame</code> doesn't fire for a long time, normally these 2 tasks are very close together:</p> <p><img src="https://user-images.githubusercontent.com/2193314/197297400-206cda63-0044-4df8-a310-264e811d3685.png" alt="image" /></p> <p>It's not clear why, but if Chromium doesn't fire it there isn't much we can do about it. It does appear to be a longer interaction but I'm guessing that's because something's blocking so it delays processing the keyup event:</p> <p><img src="https://user-images.githubusercontent.com/2193314/197297603-13d76662-2cd3-470b-bed7-ba1181b582e6.png" alt="image" /></p> <p>I also tried a JavaScript profile and it didn't reveal anything for the spikes.</p> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>The impact of disabling v-sync and unlocking the frame limit is that it's slightly slower by average but much more variable as you would expect. It doesn't lower the minimum though.</p> <img width="382" alt="image" src="https://user-images.githubusercontent.com/2193314/197298790-9c792618-0611-47db-b5e5-931a8f8228d3.png"> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 2 years ago</strong> </div> <div class="markdown-body"> <p>Here are some results of measuring latency in VS Code and other similar projects:</p> <p><img src="https://user-images.githubusercontent.com/2193314/197304156-40b6de50-5451-4025-aa5c-a06aede5e389.png" alt="image" /></p> <p>Some thoughts:</p> <ul> <li>It's not a totally fair comparison, since the latency tool is a bit finnicky, some of these could only be measured when the app was either very wide or narrow and certain font sizes, and how large glyphs and the viewport are will likely have a direct relationship with render time. These are not all called out in the image above, I think it was Sublime and all VS Codes that needed to be narrow with a large font size. Inversely the vim tests are in very wide terminals so it's unfair that way too.</li> <li>This isn't representative of real world typing as it's period <code>.</code> characters into a text file, so it ignores autocomplete for example, or just actual coding in general (varying glyphs, scrolling when typing, wrapping, files with a lot of content, etc.)</li> <li>The numbers varied a fair bit in different runs and it's not clear why. For example I did VS Code v1.73.0-insider fairly early on and it was 18ms average, I did another Sublime Text profile just now and it was 14ms average. A more thorough comparison should probably have more individual runs and/or more than 200 characters</li> <li>The Insiders ones included my set of extensions</li> <li>Electron/Chromium typically had a large maximum as spikes could occur for unknown reasons.</li> <li>xterm.js' webgl renderer is super fast which is evident when you conpty from the picture. This used the barebones demo connected to the "fake pty" which basically just prints what you type. So it represents potential of where we could get if the typing did nearly nothing except render, that's unrealistic though as a lot of things need to happen in the editor.</li> </ul> <p>Hardware used:</p> <ul> <li>CPU: 12th Gen Intel Core i7-12700KF 3.61 GHz (efficiency cores disabled in BIOS)</li> <li>GPU: RTX 2070 Super</li> <li>Monitor: 240Hz, 3840x2160 resolution, 150% scale</li> </ul> </div> </div> <div class="comment"> <div class="user"> <a rel="noreferrer nofollow" target="_blank" href="https://github.com/Tyriar"><img src="https://avatars.githubusercontent.com/u/2193314?v=4" />Tyriar</a> commented <strong> 1 year ago</strong> </div> <div class="markdown-body"> <p>I'm going to call this done for now, here are the outcomes:</p> <ul> <li>In depth look at the major things that happen when typing</li> <li>Deferred a bunch of stuff when typing</li> <li>Setup a telemetry event which will let us track our input latency goals over time and ensure we don't regress</li> <li>Learned a lot above</li> </ul> </div> </div> <div class="page-bar-simple"> </div> <div class="footer"> <ul class="body"> <li>© <script> document.write(new Date().getFullYear()) </script> Githubissues.</li> <li>Githubissues is a development platform for aggregating issues.</li> </ul> </div> <script src="https://cdn.jsdelivr.net/npm/jquery@3.5.1/dist/jquery.min.js"></script> <script src="/githubissues/assets/js.js"></script> <script src="/githubissues/assets/markdown.js"></script> <script src="https://cdn.jsdelivr.net/gh/highlightjs/cdn-release@11.4.0/build/highlight.min.js"></script> <script src="https://cdn.jsdelivr.net/gh/highlightjs/cdn-release@11.4.0/build/languages/go.min.js"></script> <script> hljs.highlightAll(); </script> </body> </html>