Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Terminal scrolling regression in application with alternative screen buffer #204769

Closed
jaminthorns opened this issue Feb 8, 2024 · 14 comments
Closed
Assignees
Labels
bug Issue identified by VS Code Team member as probable bug perf terminal-input Relating to typing in the terminal not doing the right thing, IMEs not working, etc.
Milestone

Comments

@jaminthorns
Copy link

jaminthorns commented Feb 8, 2024

Does this issue occur when all extensions are disabled?: Yes

Version: 1.86.1 (Universal)
Commit: 31c37ee
Date: 2024-02-07T09:09:01.236Z
Electron: 27.2.3
ElectronBuildId: 26495564
Chromium: 118.0.5993.159
Node.js: 18.17.1
V8: 11.8.172.18-electron.0
OS: Darwin arm64 23.2.0

Steps to Reproduce:

  1. Open a program that uses the alternate screen buffer (like less).
  2. Scroll really fast.
  3. Observe that:
  • The terminal doesn't stop scrolling immediately when you stop scrolling.
  • Changing scroll direction quickly is delayed.

I noticed this regression in the January update (1.86). It's very noticeable when flicking a MacBook's trackpad or flinging a scroll wheel that supports fast scroll (like my Logitech mouse). Here's a video that demonstrates the issue:

IMG_0684_converted.mp4

VS Code is on the left, and WezTerm (which doesn't have the issue and behaves similarly to VS Code pre-1.86) is on the right.

@jaminthorns
Copy link
Author

Clarification: the issue occurs only when the application using the alt screen buffer does not use mouse events for scrolling. When an application uses mouse events, everything seems fine. So, while running this has the issue:

man ls

This does not:

PAGER="$PAGER --mouse" man ls

@eddyb
Copy link

eddyb commented Mar 4, 2024

(on 1.86.2 / 903b1e9, but also tested 1.88.0-insider / 61187a0 and it behaves identically)

I can confirm both the original issue, and that --mouse works around it, though it's weirder than that.

With --mouse, the frustrating delayed behavior goes away, but it's still much slower than a terminal should be in terms of the maximum scrolling speed (past which physically scrolling faster doesn't change anything), and it's really noticeable with an unlocked scroll wheel (Logitech G502 Hero in my case, as in the air duster memes, tho that would be way overkill for this bug).

I suppose the difference is that with --mouse, less only waits for a mouse input after after each line it scrolls, guaranteeing a very slow-scrolling terminal will have finished before any new inputs are processed.

Whereas by default (mouse scroll events turning into down/up key presses), the inputs still get collected while the slow-scrolling terminal is taking its time, and can easily pile up.


(click to open first, less reliable, benchmarking attempt)

Using --mouse and -e (exit when reaching the end), I was able to benchmark the VSCode Terminal:

$ date -Ins; seq -w 1000 | less --mouse -e; date -Ins
2024-03-05T00:08:36,110989866+02:00
2024-03-05T00:08:43,803949975+02:00

That's almost 8 seconds, during which I had to keep flinging my scroll wheel.

By comparison, Konsole (my main terminal outside of VSCode), with the same setup, can get as fast as:

2024-03-04T23:46:49,615374333+02:00
2024-03-04T23:46:49,777998377+02:00

That's ~160ms, or 50x faster than VSCode's Terminal. In part that's because I was had already gotten the scroll wheel up to speed before pressing Enter, but that was also the case for the VSCode run.

Initially I thought reducing the VSCode Terminal height was making it faster, but I got ~8 seconds again after shrinking the height to the minimum allowed (6 lines), so it likely only feels faster.


Sadly, at some point I stopped being able to reproduce those numbers, so I'm less sure of them now.
(And instead started getting 16-18 seconds in VSCode, so it's not like it was in a positive direction)

However, the mouse/human factor can be automated away if we assume that the problem has to do with scrolling performance, and we start benchmarking that, directly:

$ date -Ins; tput smcup; seq -w 100000 | sed 's/$/\x1b[10S/'; tput rmcup; date -Ins
2024-03-05T00:22:50,639432483+02:00
2024-03-05T00:23:00,216516418+02:00

So a bit over 10 seconds for VSCode's Terminal. My Konsole seems to handle that in about 0.6s.

Shrinking the VSCode Terminal's width and/or height doesn't appear to have an effect on timings.


However, looking at an old version of VSCode I could easily get (1.78.2), it's not any faster according to the automated benchmark, it just seems to somehow combine what less is doing (whether explicit scrolling or something else) and only visually update every few frames, resulting in choppy scrolling, and the status line at the bottom flashing a lot.

So this regression may have been caused by trying to make the terminal look better, without having the throughput to actually handle all the necessary updates as fast as other implementations.


EDIT: just realized all my weird date -Ins usage could've been using time instead, I think I was expecting a weirder interactive situation but in retrospect I should've switched to time before posting.

@eddyb
Copy link

eddyb commented Mar 5, 2024

This is confusing: I tried coming up with a way to benchmark scrollwheel speed (it starts timing after the first 3-byte sequence - \e[B for scrolling down - and expects 1000 of them):

  • Konsole:
$ bash -c 'tput smcup; saved="$(stty -g)"; stty cbreak -echo; dd bs=3 count=1 of=/dev/null; report="$(dd bs=3 count=1000 of=/dev/null 2>&1)"; stty "$saved"; tput rmcup; echo "$report" >&2'
1000+0 records in
1000+0 records out
3000 bytes (3.0 kB, 2.9 KiB) copied, 1.06856 s, 2.8 kB/s
  • VSCode 1.78.2:
$ bash -c 'tput smcup; saved="$(stty -g)"; stty cbreak -echo; dd bs=3 count=1 of=/dev/null; report="$(dd bs=3 count=1000 of=/dev/null 2>&1)"; stty "$saved"; tput rmcup; echo "$report" >&2'
dd: warning: partial read (2 bytes); suggest iflag=fullblock
941+59 records in
941+59 records out
2922 bytes (2.9 kB, 2.9 KiB) copied, 0.50047 s, 5.8 kB/s
  • VSCode 1.86.2:
$ bash -c 'tput smcup; saved="$(stty -g)"; stty cbreak -echo; dd bs=3 count=1 of=/dev/null; report="$(dd bs=3 count=1000 of=/dev/null 2>&1)"; stty "$saved"; tput rmcup; echo "$report" >&2'
1000+0 records in
1000+0 records out
3000 bytes (3.0 kB, 2.9 KiB) copied, 5.16949 s, 0.6 kB/s

What happened, was VSCode dropping input events before? (the partial read itself is a bit suspicious)

This change seems independent of scrolling performance, because nothing should be written during the test, and in fact the "alternative screen buffer" feature is only used to enable inputting arrow keys with the mouse scrollwheel.


EDIT: by setting the log level to Debug, it seems xterm.js' scrollwheel handler is trying to send 7 or 14 \e[B (down arrow) every 7ms or so, matching Konsole, but the BELs from overscrolling take forever to come back, so I'm starting to suspect something goes wrong in between onData firing and the pty.

@eddyb
Copy link

eddyb commented Mar 5, 2024

Oh no, this a fix for a cursed bug: d92c1a8

By setting the log level to Trace, I could see this:

2024-03-05 11:26:01.325 [debug] [1709593] sending data "␛[B␛[B␛[B␛[B␛[B␛[B␛[B" [[27,91,66,27,91,66,27,91,66,27,91,66,27,91,66,27,91,66,27,91,66]]
2024-03-05 11:26:01.334 [trace] node-pty.IPty#write ␛[B
2024-03-05 11:26:01.339 [trace] node-pty.IPty#write ␛[B
2024-03-05 11:26:01.343 [trace] node-pty.IPty#write ␛[B
2024-03-05 11:26:01.349 [trace] node-pty.IPty#write ␛[B

(and a lot more single-escape-sequence trace logs)

This explains everything I've been seeing (and why it's unusably bad for me): for most smooth scrolling inputs, the 5ms delay can easily slow everything down by 5x, and e.g. scrolling for 10 seconds could take 50 seconds to finish writing.

Write queue logic:

private _startWrite(): void {
// Don't write if it's already queued of is there is nothing to write
if (this._writeTimeout !== undefined || this._writeQueue.length === 0) {
return;
}
this._doWrite();
// Don't queue more writes if the queue is empty
if (this._writeQueue.length === 0) {
this._writeTimeout = undefined;
return;
}
// Queue the next write
this._writeTimeout = setTimeout(() => {
this._writeTimeout = undefined;
this._startWrite();
}, Constants.WriteInterval);
}
private _doWrite(): void {
const object = this._writeQueue.shift()!;
this._logService.trace('node-pty.IPty#write', object.data);
if (object.isBinary) {
this._ptyProcess!.write(Buffer.from(object.data, 'binary') as any);
} else {
this._ptyProcess!.write(object.data);
}
this._childProcessMonitor?.handleInput();
}

Chunking logic:

/**
* Splits incoming pty data into chunks to try prevent data corruption that could occur when pasting
* large amounts of data.
*/
export function chunkInput(data: string): string[] {
const chunks: string[] = [];
let nextChunkStartIndex = 0;
for (let i = 0; i < data.length - 1; i++) {
if (
// If the max chunk size is reached
i - nextChunkStartIndex + 1 >= Constants.WriteMaxChunkSize ||
// If the next character is ESC, send the pending data to avoid splitting the escape
// sequence.
data[i + 1] === '\x1b'
) {
chunks.push(data.substring(nextChunkStartIndex, i + 1));
nextChunkStartIndex = i + 1;
// Skip the next character as the chunk would be a single character
i++;
}
}
// Push final chunk
if (nextChunkStartIndex !== data.length) {
chunks.push(data.substring(nextChunkStartIndex));
}
return chunks;
}


@Tyriar I'm amazed it took this long to become a problem, one escape sequence every 5ms is really bad throughput, I guess it's just hard to hit with keyboard, only scroll wheel in pager-managed altbufs (or TUI mouse cursor?).

I would suggest decreasing the delay to 1ms, but there is another more immediate problem/solution: the chunking stops just before the 2nd \e, but it could stop just before the last \e in the chunk, which in my case would send e.g. 7x \e[B at once (as decided by xterm.js), and 5ms is then fast enough to keep up.

EDIT: honestly simplest fix might be to always return one chunk if data.length <= Constants.WriteMaxChunkSize, instead of even scanning it (maybe add data.length - nextChunkStartIndex <= Constants.WriteMaxChunkSize as an extra loop exit condition?).

@eddyb
Copy link

eddyb commented Mar 7, 2024

I was able to test changing the timeout to 0, using:

env -C $(mktemp -d) $(nix-build --no-out-link -E "with import <nixpkgs> {}; vscode.overrideAttrs (orig: { postFixup = orig.postFixup + ''
  sed -E -i 's/(setTimeout)\((\(\)=>\{[^{}]+\}),5\)/\1(\2,0)/' \$out/lib/vscode/resources/app/out/vs/platform/terminal/node/ptyHostMain.js
''; })")/bin/code --user-data-dir ./vscode-data --disable-extensions

(i.e. patching the single use of Constants.WriteInterval from 5 to 0 - you can ignore the Nix-specific lines, the important thing is I'm running sed -i ... $out/..., operating on the downloaded VSCode build)

And medium-speed scrolling (i.e. the kind of "7 \e[B in 7ms" scenario I previously described) now feels real-time, but it's not enough: over-scrolling past the end of a pager, especially at higher speed, can still incur a second or two of waiting, so the chunking is the bigger problem/solution.


env -C $(mktemp -d) $(nix-build --no-out-link -E "with import <nixpkgs> {}; vscode.overrideAttrs (orig: { postFixup = orig.postFixup + ''
  sed -E -i 's/(\+1\]===.).x1B(.)/\1\2/' \$out/lib/vscode/resources/app/out/vs/platform/terminal/node/ptyHostMain.js
''; })")/bin/code --user-data-dir ./vscode-data --disable-extensions

This second attempt disables the special \e (\x1B here) handling in chunking, not a correct fix by any stretch of the imagination, but I'll take whatever weird bugs it may cause with e.g. pasting, over not being able to use pagers with a mouse scroll wheel.

And testing this version, I can't make it fall behind noticeably, even when trying really hard, so it always feels real-time (even if the hacky chunking workaround means it could theoretically fall behind 5-10ms etc.).

@Tyriar
Copy link
Member

Tyriar commented Mar 7, 2024

@eddyb thanks a bunch for looking into this 👏. Do you want to make a PR with your condition so you get credit?

I'm amazed it took this long to become a problem

Looks like this specifically was introduced relatively recently: #201157


I think we can also disable the chunking logic outright unless we're on Windows here:

this._writeQueue.push(...chunkInput(data).map(e => {
return { isBinary, data: e };
}));

I'm pretty sure it was only to workaround a weird Windows issue where text was truncated randomly. The chunk logic improvement in #201157 was a general improvement to that workaround which was only needed for Windows to avoid cutting sequences in half.

@Tyriar Tyriar added bug Issue identified by VS Code Team member as probable bug perf terminal-input Relating to typing in the terminal not doing the right thing, IMEs not working, etc. labels Mar 7, 2024
@Tyriar Tyriar added this to the March 2024 milestone Mar 7, 2024
@Tyriar
Copy link
Member

Tyriar commented Mar 7, 2024

Actually looking into it more I remembered wrong apparently, the chunking was required on macOS 🙁 #38137. Any optimizations to the chunking algorithm are definitely welcome

@Tyriar Tyriar modified the milestones: March 2024, April 2024 Mar 22, 2024
@Tyriar Tyriar modified the milestones: April 2024, Backlog Apr 22, 2024
@jaminthorns
Copy link
Author

This seems to be fixed in the latest release, version 1.92.0! I'll leave it up to a maintainer to close, since it would be good to identify the code change that contributed to the fix, but regardless the issue with scrolling after input has been stopped is no longer present.

@Tyriar
Copy link
Member

Tyriar commented Aug 2, 2024

@jaminthorns brand new scroll bar implementation in v1.92 so it makes sense this behavior would have changed 👍 https://code.visualstudio.com/updates/v1_92#_new-scroll-bar

@Tyriar Tyriar closed this as completed Aug 2, 2024
@eddyb
Copy link

eddyb commented Aug 8, 2024

Do you want to make a PR with your condition so you get credit?

Sorry, I've been swamped and only originally looked into this as it was increasingly impacting my work at the time, I didn't get to spend time on it after I found the workaround.


brand new scroll bar implementation in v1.92 so it makes sense this behavior would have changed

Not 100% sure I understand the connection, but I guess one way they could interact is that the scroll wheel could be ignoring hardware events while previous events' chunks have not been sent yet, instead of accumulating them at the same time?

The new behavior in e.g. less feels similar to less --mouse --wheel-lines=1, in that it's still orders of magnitude slower than the new terminal scrollbar outside of the alternate-screen mode (or pagers in other terminal emulators, like Konsole), and also it doesn't even respect the "hold Alt to modify speed" (or it does respect it but something else neuters it regardless?).

The benchmark I described in #204769 (comment) is still disappointing in VSCode (in fact it takes 16.6s for me now, instead of 5s, whereas for Konsole I can take it down to 2ms depending on the scrollwheel speed).

And this is with my chunking patch applied still, which is a bit surprising.


image

I had to go back to confirm but that's 1.91.1 doing 0.4s somewhat consistently (and you can tell it has my patch because the escapes get truncated/corrupted, which is why the chunking is needed AFAIK, but ideally it should allow keeping multiple escape sequences in the same chunk).

Meanwhile 1.92.0, both with and without chunking patches, does 16.6s, and never seems to show any truncation/corruption of escapes even with the chunking patch.


Anyway, the summary is that the jarring "scroll event buffering" is gone, but whatever changes were made result in a "lockstep" slowdown instead - it's not as bad, and e.g. less --mouse --wheel-lines=5 is arguably usable, but there's still a massive discrepancy between regular scrolling (in the terminal backscroll or in a regular editor, etc.) and using a pager.

@eddyb
Copy link

eddyb commented Aug 8, 2024

@Tyriar wait, I made the mistake again of not tracking down the relevant changes first, it looks like you just removed the scroll amount? xtermjs/xterm.js@721d483

This explains what we're seeing, the deltaY absolute value was usually around 7 in my testing - so the only "fix" here was making scrolling 7x slower, which means the chunking can keep up even without my patches.

Was this only done because the correct value was hard to compute?

@Tyriar
Copy link
Member

Tyriar commented Aug 8, 2024

@eddyb I pulled that out since the old viewport is gone and with it the ability to translate events into lines scrolled. Created xtermjs/xterm.js#5123 to bring that back

@eddyb
Copy link

eddyb commented Aug 8, 2024

... is gone and with it the ability to translate events into lines scrolled

Makes sense, I was hoping it was something like that.

Created xtermjs/xterm.js#5123 to bring that back

Thanks! As a reference, if that does happen, here's a quick chunking improvement:

// equivalent to today's logic, but iterating whole chunks not chars:
// (could even use data = data.substring(chunk.length); and remove chunkStartIndex)
export function chunkInput(data: string): string[] {
	const chunks: string[] = [];
	let chunkStartIndex = 0;
	while (chunkStartIndex < data.length) {
		let chunk = data.substring(chunkStartIndex, chunkStartIndex + Constants.WriteMaxChunkSize);

		// End the chunk before first non-initial ESC, to avoid splitting its escape sequence
		const firstEscInChunk = chunk.indexOf('\x1b');
		if (firstEscInChunk >= 1)
			chunk = chunk.substring(0, firstEscInChunk);

		chunks.push(chunk);
		chunkStartIndex += chunk.length;
	}
	return chunks;
}
// same as above but "last" instead of "first":
export function chunkInput(data: string): string[] {
	const chunks: string[] = [];
	let chunkStartIndex = 0;
	while (chunkStartIndex < data.length) {
		let chunk = data.substring(chunkStartIndex, chunkStartIndex + Constants.WriteMaxChunkSize);

		// End the chunk before last non-initial ESC, to avoid splitting its escape sequence
		const lastEscInChunk = chunk.lastIndexOf('\x1b');
		if (lastEscInChunk >= 1)
			chunk = chunk.substring(0, lastEscInChunk);

		chunks.push(chunk);
		chunkStartIndex += chunk.length;
	}
	return chunks;
}

There's a good chance not iterating characters might also improve performance in edge cases (but most likely it will just slightly reduce CPU usage, there are other things linear over the data with larger constant factors AFAIK).

@Tyriar
Copy link
Member

Tyriar commented Aug 12, 2024

@eddyb did you want to submit a PR with the chunk improvements?

@vs-code-engineering vs-code-engineering bot locked and limited conversation to collaborators Sep 16, 2024
# for free to subscribe to this conversation on GitHub. Already have an account? #.
Labels
bug Issue identified by VS Code Team member as probable bug perf terminal-input Relating to typing in the terminal not doing the right thing, IMEs not working, etc.
Projects
None yet
Development

No branches or pull requests

5 participants