Scrollback buffer gets slightly corrupted

How easily can you reproduce this?

Hi George,

I can't reproduce it at will, but it happens to me several times a day.

Thanks. Ted

Please see if you can reproduce it with this build:

https://iterm2.com/misc/iTerm2-f2529218bce51b4a795dbe3dc93e2376b4eb8382-asan.tgz

It's not signed so after untarring it right click and select open.

Hopefully it will crash with an informative bunch of messages logged to Console.app when the corruption occurs. Please send me those messages.

Hi George,

I had the issue happen today with the test build: [cid:image001.png@01D35EDE.0A25B3B0] and [cid:image002.png@01D35EDE.0A25B3B0]

[cid:image003.png@01D35EDE.0A25B3B0]

It did not crash. There are some bits of this in the Console logs: default 13:15:27.383961 -0500 iTerm2 126 draws of 14320 pixels

But the timestamps are all several minutes after the corruption happened.

Let me know if you have any questions.

Thanks. Ted

Does it always turn into the question mark in a diamond?

The other thing that's interesting is that it's always the first character on a line. Is that what you've always observed?

changed milestone to %Next Beta

Hi George,

Yes, it's always the first character on a line, and always the diamond question mark. It seems like the fuller the buffer gets (I run iterm for days, multiple tabs, 1million lines per tab) the more often it happens.

Thanks for looking into it. I appreciate it.

Ted

Please install tomorrow's nightly build from https://iterm2.com/nightly/latest

The next time this happens, turn on Prefs > Advanced > Show line buffer block boundaries (issue 6207). Then click in the iTerm2 window and let me know if the line with the diamond question mark turns into a row of Xes.

If this occurs, it confirms the issue happens with the first character of a LineBlock. That's the only lead I have to go on so far, but it would help to narrow the field of possibilities a bit.

Hi George,

I had it happen again today, and turned on the 6207 function. It did not change the output: [cid:image001.png@01D36CFC.59EFC300]

Also note that it seems to have removed the first two characters of the line above it. I know it did work, because other lines did turn into lines of X's.

I'm using Build 3.1.20171130-nightly, if that's the right version.

Thanks. Ted

Can you copy paste the start of the two affected lines into here? I want to know what those characters became.

Hi George,

Here is an example:

I think gitlab must have eaten it. I don't see anything there. Can you put it through hexdump -C?

Hi George,

I really appreciate you continuing to look at this!

That's odd that the data was cut.

Here's the hexdump -C:

00000000  6d 66 72 65 56 20 2d 20  31 33 34 64 62 38 66 30  |mfreV - 134db8f0|
00000010  2e 38 2e 31 2e 35 3a 20  35 0a 20 20 72 65 56 20  |.8.1.5: 5.  reV |
00000020  2d 20 31 33 34 64 62 38  66 30 2e 38 2e 31 2e 35  |- 134db8f0.8.1.5|
00000030  3a 20 31 0a ef bf bd 66  72 65 56 20 2d 20 31 33  |: 1....freV - 13|
00000040  34 64 62 38 66 30 2e 38  2e 31 2e 35 3a 20 38 0a  |4db8f0.8.1.5: 8.|
00000050  6d 66 72 65 56 20 2d 20  31 33 34 64 62 38 66 30  |mfreV - 134db8f0|
00000060  2e 38 2e 31 2e 35 3a 20  31 33 34 64 62 38 66 30  |.8.1.5: 134db8f0|
00000070  0a 52 65 74 75 72 6e 69  6e 67 20 31 33 34 64 62  |.Returning 134db|
00000080  38 66 30 0a                                       |8f0.|
00000084

And another example:

00000000  20 20 20 72 65 74 75 72  6e 20 69 66 0a ef bf bd  |   return if....|
00000010  46 69 65 6c 64 73 3a 20  64 61 74 65 0a 20 20 20  |Fields: date.   |
00000020  24 66 69 65 6c 64 73 5b  32 5d 0a                 |$fields[2].|
0000002b

Basically it looks like the characters get changed to "ef bf bd" in the buffer.

Here's a screen shot of the same line output twice, where one was clobbered:

[cid:image001.png@01D38481.D974BB70]

And the hexdump of it:

00000000  0a ef bf bd 6f 75 72 20  68 6f 6d 65 20 64 69 72  |....our home dir|
00000010  65 63 74 6f 72 79 20 69  73 20 33 39 25 20 66 75  |ectory is 39% fu|
00000020  6c 6c 20 28 31 35 35 36  36 36 36 38 2f 34 30 33  |ll (15566668/403|
00000030  37 39 30 37 34 20 4b 42  29 0a 0a 0a 59 6f 75 72  |79074 KB)...Your|
00000040  20 68 6f 6d 65 20 64 69  72 65 63 74 6f 72 79 20  | home directory |
00000050  69 73 20 33 39 25 20 66  75 6c 6c 20 28 31 35 35  |is 39% full (155|
00000060  36 36 36 36 38 2f 34 30  33 37 39 30 37 34 20 4b  |66668/40379074 K|
00000070  42 29 0a                                          |B).|
00000073

Thanks again! Ted

That's the unicode replacement character. That's really interesting because there are only a few places in the app where we would produce those, and it's all in input handling. Either we're getting a replacement character as input or there is memory corruption that just happens to plop a replacement character in history. Please try this build, which will log a critical error any time a replacement character is touched. When you run it and the problem occurs, it may show a dialog telling you it made a debug log. If it does, send me the debug log. If you still get the replacement character but no dialog box saying there was a critical error, let me know—that's interesting too.

Link to special build: http://iterm2.com/adhocbuilds/iTerm2-3_1_20180111_223642-adhoc.zip

Hi George,

Thanks for the build. I ran it, and almost right away got the dialog about the debug output. But when I went back through the buffer I didn't see anything. It may be because of the session it restored.

It hasn't done it again yet, but sometimes it takes a while. I will send another one if it happens again.

Thanks. Ted

debuglog.txt

Hi George,

I just had this happen again. It happened when I tried to launch vi.

When I went back in the buffer after that, I could see the corruption: [cid:image001.png@01D38BAC.C460F280] and [cid:image002.png@01D38BAC.C460F280]

I went into another tab and went into vi there, but did not get the pop-up. But when I rolled back in the buffer there was corruption.

I was able to reproduce this a few times.

My terminal is set to xterm-256color. I am using vim in vi compatibility mode: VIM - Vi IMproved 7.4 (2013 Aug 10, compiled Nov 30 2016 20:54:06) Included patches: 1-52

When I start vi, it does this stuff:

^[[?1049h^[[?1h^[=^[[1;45r^[[?12;25h^[[?12l^[[?25h^[[27m^[[m^[[H^[[2J^[[?25l^[[2;1H^[[94m~
... a bunch of ^[[16;1H~ with different values
^[[m^[[45;183H0,0-1^[[9CAll^[[1;1H^[[?12l^[[?25h^[[?25l^[[45;1H^[[K^[[45;1H:q!^M^[[45;1H^[[K^[[45;1H^[[?1l^[>^[[?12l^[[?25h^[[?1049l

I was also able to reproduce the issue with my terminal set to vt220. When I have that, vi does:

^[[1;45r^[[27m^[[24m^[[0m^[[H^[[J^[[45;1H"xxxx" [New File]^[[2;1H^[[1m~

~^[[0m^[[45;183H0,0-1^[[9CAll^[[1;1H^[[45;1H^[[K^[[45;1H:q!^M^[[45;1H^[[K^[[45;1H

I can reproduce the issue reliably now. In Bash:

$ for i in {100..1}; do echo $i; done
... number print
$ vi xxx
:q!

Scroll back, and lines 42 and 43 are clobbered. Note my screen size is 45x200:

$ stty -a
speed 38400 baud; rows 45; columns 200; line = 0;
intr = ^C; quit = ^\; erase = ^?; kill = ^U; eof = ^D; eol = M-^?; eol2 = M-^?; swtch = <undef>; start = ^Q; stop = ^S; susp = ^Z; rprnt = ^R; werase = ^W; lnext = ^V; flush = ^O; min = 1; time = 0;
-parenb -parodd cs8 -hupcl -cstopb cread -clocal -crtscts
-ignbrk -brkint -ignpar -parmrk -inpck -istrip -inlcr -igncr icrnl ixon -ixoff -iuclc ixany imaxbel -iutf8
opost -olcuc -ocrnl onlcr -onocr -onlret -ofill -ofdel nl0 cr0 tab0 bs0 vt0 ff0
isig icanon iexten echo echoe echok -echonl -noflsh -xcase -tostop -echoprt echoctl echoke

Let me know if you have any questions.

Thanks. Ted

debuglog.txt

It looks to me like you received some invalid sequence which created the replacement character. That's based on this in the log:

1515781438.855774 VT100StringParser.m:351 (ParseString): Critical error NO from:
(
        0   iTerm2                              0x000000010f4f6eb8 ParseString + 1919
        1   iTerm2                              0x000000010f6ac15b -[VT100Parser addNextParsedTokensToVector:] + 1220
        2   iTerm2                              0x000000010f6ac7a5 -[VT100Parser addParsedTokensToVector:] + 48
        3   iTerm2                              0x000000010f61bb53 -[PTYSession threadedReadTask:length:] + 187
        4   iTerm2                              0x000000010f5f4578 -[PTYTask readTask:length:] + 69
        5   iTerm2                              0x000000010f5f430c -[PTYTask processRead] + 161
        6   iTerm2                              0x000000010f5af202 -[TaskNotifier handleReadOnFileDescriptor:task:fdSet:] + 85
        7   iTerm2                              0x000000010f5b0166 -[TaskNotifier run] + 3320
        8   Foundation                          0x00007fffc4e188ad __NSThread__start__ + 1243
        9   libsystem_pthread.dylib             0x00007fffd8d9693b _pthread_body + 180
        10  libsystem_pthread.dylib             0x00007fffd8d96887 _pthread_body + 0
        11  libsystem_pthread.dylib             0x00007fffd8d9608d thread_start + 13
)
1515781438.858864 VT100StringParser.m:351 (ParseString): Parsed an invalid sequence ?^[[6n^[[1;1H  ^[[1;1H

The only thing I don't understand is why that particular sequence would be considered invalid since it starts with an ASCII character.

I think one more debug log will settle it for good now that you have a consistently reproducible case: do this:

Turn on debug logging
Reproduce the issue with vim as described before
Turn off debug logging
Attach log here.

Hi George,

I started a typescript and used vi, then edited the typescript. the "?" in the output you pasted shows up in reverse video for me.

I've attached the debug log here as well.

Thanks! Ted

debuglog.txt.zip

Hi George,

Just confirming that you received my previous email and that it didn't get eaten by a spam filter.

Thanks. Ted

Hey, sorry for the delay in getting back to you. I've been super backlogged this week.

It looks like vim is sending some malformed UTF-8. Unfortunately the debug log does not capture such codes (I thought it did, sorry!). At any rate, it should be simple enough to track down its cause. I expect it's probably a vim extension, so try going back to a default vim setup and see if it goes away, then add things back slowly until the issue recurs.

To verify that it's actually bogus UTF-8 (vs a bug in iTerm2 that misidentifies correct UTF-8 as malformed), you can create a log of the session by following these steps:

Select the menu item Session > Log > Start
Reproduce the problem
Select the menu item Session > Log > Stop
Validate the UTF-8 with iconv -f UTF-8 logfile.txt > /dev/null && echo ok || echo fail

Hi George,

No worries at all, I am sure you're busy. I created a session log and got: $ iconv -f UTF-8 vim\ repro > /dev/null && echo ok || echo fail

iconv: vim repro:2:17: cannot convert fail

Here's that line. The ½ is probably the culprit.

[cid:image001.png@01D39EB6.1F5CAC80]

I don't use any extensions in vim, but when I start vim with "-u NONE", the problem doesn't happen. I'll have to dig to figure out what is doing it.

Thanks. Ted

So far it sounds like it's not corruption, but just occasional bogus UTF-8 inputs. Let me know if you can find an instance where that's not the case and I'll be glad to look into it some more. That special build (here) is useful for testing the hypothesis since it'll give you a critical error on such input.

Closing this until more info comes to light.

closed

Scrollback buffer gets slightly corrupted

Designs

Child items 0

Activity