microsoft / vscode

Visual Studio Code
https://code.visualstudio.com
MIT License
164.28k stars 29.31k forks source link

Terminal Command Truncation #233420

Open DehanLUO opened 4 days ago

DehanLUO commented 4 days ago

For a long time, my Visual Studio Code setup, along with its extensions, functioned flawlessly and significantly improved my workflow. However, at some point, I began experiencing issues with certain extensions. Notably, when debugging C++ code with CodeLLDB or CMake Tools, the commands sent to the terminal would occasionally be truncated, preventing the debugger from launching properly.

Recently, I discovered that setting "terminal.integrated.defaultProfile.osx": "bash" resolved the issue, while switching back to zsh caused it to resurface. Later, after transferring some conda and jenv initialization settings from .zshrc to .bash_profile, I found that the problem began to intermittently occur in bash as well. Interestingly, the more configuration scripts I added, the more consistently the issue appeared.

Recognizing a pattern, I decided to investigate further by reviewing discussions and documentation in the project’s GitHub repository.

Historical Discussions

An issue similar to what I am currently experiencing was first raised back in 2017 as #38137. Although it did not provide a direct solution to my problem and was eventually closed because it could not be reproduced, I would like to acknowledge @Tyriar for his extensive contributions in that discussion, where he referenced several related issues that offered valuable insights.

One notable comment came from @fabiospampinato, who mentioned that the command truncation only happens the first time text is sent to the terminal, but works properly afterwards.

The character limit at which commands are truncated seems to vary across different operating systems. According to #63613, commands exceeding 1568 characters are truncated on Windows. Meanwhile, issues such as #59135#87183#130736, and #134324 indicate that on macOS, this limit is 1024 characters, which aligns with my observations.

Additionally, issues #96973 and #61999 provided effective testing methods for the "Run selected text in active terminal" functionality. Additionally, #136587 offered an approach for testing using launch.json, which significantly simplified my process of reproducing this issue.

I also found the enable trace logging guide in the project’s wiki, which helped me expedite the process of identifying the cause of the problem.

Steps to Reproduce

  1. Modify ~/.zshrc. The configurations for oh-my-zshjenv, and conda can introduce delays during zsh initialization. To simulate this, add a sleep command with timestamps for tracking:

    gdate "+%Y-%m-%d %H:%M:%S.%3N"
    sleep 3
    gdate "+%Y-%m-%d %H:%M:%S.%3N"
  2. Configure settings.json. Set the terminal settings to use zsh and disable environment inheritance:

    {
    "terminal.external.osxExec": "Terminal.app",
    "terminal.integrated.defaultProfile.osx": "zsh",
    "terminal.integrated.inheritEnv": false
    }
  3. Set Log Level to Trace.

  4. Verify that all Terminal instances are closed to ensure the next session undergoes full .zshrc initialization.

  5. Create a text file containing a single line exceeding 1024 characters. Below is an example, where the space after 256marks the 1024-character boundary:

    001 002 003 004 005 006 007 008 009 010 011 012 013 014 015 016 017 018 019 020 021 022 023 024 025 026 027 028 029 030 031 032 033 034 035 036 037 038 039 040 041 042 043 044 045 046 047 048 049 050 051 052 053 054 055 056 057 058 059 060 061 062 063 064 065 066 067 068 069 070 071 072 073 074 075 076 077 078 079 080 081 082 083 084 085 086 087 088 089 090 091 092 093 094 095 096 097 098 099 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257
  6. Select the entire text and use Terminal: Run Selected Text in Active Terminal. Observe that commands beyond 1024 characters, starting from 257, are truncated.

  7. Examine the logs for details on the truncation and potential causes. Image

Cross-referencing the code and logs

In the ptyhost.log, I observed the following two log entries. The line:

2024-11-06 22:28:02.211 [trace] node-pty.IPty#write 251 252 253 254 255 256 257

is the last time the text I entered appeared in full. This log entry was generated by this._logService.trace('node-pty.IPty#write', object.data);. At this point, the input remains intact. The data is then passed through this._ptyProcess!.write(object.data); into the node-pty module, where it is further processed by this._socket.write(data);. This method facilitates communication with the C++ layer, which writes the data to the master side of the pseudo-terminal created via int ret = openpty(&master, &slave, nullptr, NULL, static_cast<winsize*>(&winp));.

The line:

2024-11-06 22:28:02.211 [trace] node-pty.IPty#onData 251 252 253 254 255 256 

marks the first instance of text truncation. In the node-pty project, when the master side of the pseudo-terminal receives data, it triggers the public get onData(): IEvent { return this._onData.event; } event, allowing subscribed listeners to capture the incoming data. In vscode, the onData event is subscribed to, and the captured data is logged via this._logService.trace('node-pty.IPty#onData', data);.

Notably, I observed two occurrences of the gdate timestamp output from .zshrc in the onData logs:

2024-11-06 22:28:02.153 [trace] node-pty.IPty#onData 2024-11-06 22:28:02.152
2024-11-06 22:28:05.175 [trace] node-pty.IPty#onData 2024-11-06 22:28:05.174

Additionally, after the shell finished loading .zshrc, there was another instance of truncated output:

2024-11-06 22:28:05.229 [trace] node-pty.IPty#onData 2
2024-11-06 22:28:05.229 [trace] node-pty.IPty#onData 5
2024-11-06 22:28:05.230 [trace] node-pty.IPty#onData 5
2024-11-06 22:28:05.230 [trace] node-pty.IPty#onData
2024-11-06 22:28:05.230 [trace] node-pty.IPty#onData 2
2024-11-06 22:28:05.230 [trace] node-pty.IPty#onData 5
2024-11-06 22:28:05.230 [trace] node-pty.IPty#onData 6
2024-11-06 22:28:05.230 [trace] node-pty.IPty#onData

Since the pseudo-terminal’s slave side in the node-pty project is configured with ECHO mode enabled (term->c_lflag = ICANON | ISIG | IEXTEN | ECHO | ECHOE | ECHOK | ECHOKE | ECHOCTL;), the echo back at 2024-11-06 22:28:02.211 corresponds to the data being written to the slave's buffer by the master. At this point, the shell on the slave side is still initializing .zshrc and has not consumed any data from the buffer.

Once the shell finishes initialization and begins consuming data from the slave's buffer, this data is echoed back to the slave and subsequently captured by the master, triggering the corresponding onData events.

Conclusion

In summary, on my macOS system, the issue of commands exceeding 1024 characters being truncated in the terminal stems from how Visual Studio Code interacts with the pseudo-terminal via node-pty. During shell initialization, which involves blocking processes, VSCode continues to write data to the slave side of the pseudo-terminal. Once the buffer reaches its maximum capacity, any additional data is discarded. When the shell resumes, it can only read as much data as fits within the buffer's limit, resulting in truncated commands.

DehanLUO commented 4 days ago

Now that the principle is clear, I can verify the slave-side buffer size of a local pseudo-terminal, which is limited to 1024 characters, through both code and direct terminal operations.

Code Verification

#include <iostream>
#include <unistd.h>
#include <util.h>  // macOS-specific header for openpty

constexpr int kTestSize = 2048;  // Test size exceeds assumed buffer size of 1024

int main() {
  int master_fd, slave_fd;

  // Open a pseudo-terminal pair
  if (openpty(&master_fd, &slave_fd, nullptr, nullptr, nullptr) == -1) {
    perror("openpty");
    return 1;
  }

  char write_buffer[kTestSize];
  char read_buffer[kTestSize];
  memset(write_buffer, 'A', sizeof(write_buffer));  // Fill buffer with 'A'

  // Write data to master end
  ssize_t bytes_written = write(master_fd, write_buffer, sizeof(write_buffer));
  if (bytes_written == -1) {
    perror("write");
    return 1;
  }

  // Read data from master end
  ssize_t bytes_read = read(master_fd, read_buffer, sizeof(read_buffer));
  if (bytes_read == -1) {
    perror("read");
    return 1;
  }

  std::cout << "Bytes written: " << bytes_written << ", Bytes read: " << bytes_read << std::endl;

  close(master_fd);
  close(slave_fd);
  return 0;
}

On my macOS system, this C++ code produces the following output:

Bytes written: 2048, Bytes read: 1024

Terminal Verification

Pre-copy a text string longer than 1024 characters. With the .zshrc configuration mentioned earlier, while sleep is blocking, paste the text into the Terminal. We can observe that only 1024 characters are pasted, and the excess is truncated. Once the shell resumes, only 1024 characters are consumed from the buffer.

Image

meganrogge commented 4 days ago

Thanks for all of the info. Looks like we'd need to investigate what happens here

https://github.com/microsoft/vscode/blob/f1210f6a715a6130b43e4aae10648cd6e7cc98fa/src/vs/platform/terminal/common/terminalProcess.ts#L84-L94