sys.stdout output with many lines is truncated on the integrated terminal with pythonTerminalEnvVarActivation

[bersbersbers]

Type: Bug

Behaviour

Expected vs. Actual

Expected: See numbers 0-4999
Actual: See fewer numbers, in my case, 0-1249

Discovered in Nuitka/Nuitka#2249

The number of lines printed actually varies with the number of lines generated:
1 -> 1
10 -> 10
100 -> 100
900 -> 900
1000 -> 1000
2000 -> 2000
2300 -> 2300
2340 -> 2340

2342 -> 1171
2344 -> 1172
3000 -> 1500
4000 -> 2000

5000 -> 1250

10000 -> 1250

So it looks like something is restricting the number of lines to <= 2340 by division by 2. If the original number if not divisible by 2, one can even end up with incomplete lines. That number does not seem to depend on the length of the lines.

Steps to reproduce:

1. Activate pythonTerminalEnvVarActivation experiment
2. Reload VS Code
3. Open integrated terminal
4. Run python -c "import sys; sys.stdout.write(''.join(f'{i:04d} \n' for i in range(5000)))"

Diagnostic data

• Python version (& distribution if applicable, e.g. Anaconda): 3.11.3
• Type of virtual environment used (e.g. conda, venv, virtualenv, etc.): Venv
• Value of the python.languageServer setting: Default

Output for Python in the Output panel (View→Output, change the drop-down the upper-right of the Output panel to Python)

2023-05-27 23:07:25.573 [info] Telemetry level is off
2023-05-27 23:07:25.573 [info] Experiments are disabled, only manually opted experiments are active.
2023-05-27 23:07:25.573 [info] Experiment 'pythonTerminalEnvVarActivation' is active
2023-05-27 23:07:25.573 [info] Test server listening.
2023-05-27 23:07:25.573 [info] Python interpreter path: ~\.pyenv-win-venv\envs\project_3.11\Scripts\python.exe
2023-05-27 23:07:25.573 [warning] Retry failed, storage update failed for key PYTHON_GLOBAL_STORAGE_KEYS
2023-05-27 23:07:25.573 [warning] Retry failed, storage update failed for key PYTHON_GLOBAL_STORAGE_KEYS
2023-05-27 23:07:25.741 [info] > ~/.pyenv-win-venv/envs/project_3.11/Scripts/activate.bat && echo 'e8b39361-0157-4923-80e1-22d70d46dee6' && python ~/.vscode/extensions/ms-python.python-2023.8.0/pythonFiles/printEnvVariables.py
2023-05-27 23:07:25.742 [info] shell: commandPrompt
2023-05-27 23:07:25.920 [warning] Retry failed, storage update failed for key PYTHON_GLOBAL_STORAGE_KEYS
2023-05-27 23:07:26.562 [info] Starting Pylance language server.
2023-05-27 23:07:26.817 [info] > ~/.pyenv-win-venv/envs/project_3.11/Scripts/activate.bat && echo 'e8b39361-0157-4923-80e1-22d70d46dee6' && python ~/.vscode/extensions/ms-python.python-2023.8.0/pythonFiles/printEnvVariables.py
2023-05-27 23:07:26.817 [info] shell: commandPrompt
2023-05-27 23:07:27.268 [info] > ~\.pyenv-win-venv\envs\project_3.11\Scripts\python.exe ~\.vscode\extensions\ms-python.python-2023.8.0\pythonFiles\linter.py -m bandit --configfile pyproject.toml .\project\bug.py
2023-05-27 23:07:27.269 [info] cwd: .
2023-05-27 23:07:27.282 [info] > ~\.pyenv-win-venv\envs\project_3.11\Scripts\python.exe ~\.vscode\extensions\ms-python.python-2023.8.0\pythonFiles\linter.py -m pycodestyle .\project\bug.py
2023-05-27 23:07:27.282 [info] cwd: .
2023-05-27 23:07:27.302 [info] > ~\.pyenv-win-venv\envs\project_3.11\Scripts\python.exe ~\.vscode\extensions\ms-python.python-2023.8.0\pythonFiles\linter.py -m pydocstyle .\project\bug.py
2023-05-27 23:07:27.302 [info] cwd: .
2023-05-27 23:07:27.329 [info] > ~\.pyenv-win-venv\envs\project_3.11\Scripts\python.exe ~\.vscode\extensions\ms-python.python-2023.8.0\pythonFiles\linter.py -m mypy --follow-imports=silent --ignore-missing-imports --show-column-numbers --no-pretty .\project\bug.py
2023-05-27 23:07:27.329 [info] cwd: .
2023-05-27 23:07:27.346 [info] > ~\.pyenv-win-venv\envs\project_3.11\Scripts\python.exe ~\.vscode\extensions\ms-python.python-2023.8.0\pythonFiles\linter.py -m pylama .\project\bug.py
2023-05-27 23:07:27.346 [info] cwd: .
2023-05-27 23:07:28.504 [info] ##########Linting Output - pycodestyle##########

2023-05-27 23:07:28.504 [info] 
2023-05-27 23:07:28.763 [info] ##########Linting Output - pydocstyle##########

2023-05-27 23:07:28.763 [info] 
2023-05-27 23:07:29.125 [info] ##########Linting Output - mypy##########

2023-05-27 23:07:29.125 [info] Success: no issues found in 1 source file

2023-05-27 23:07:29.247 [info] ##########Linting Output - bandit##########

2023-05-27 23:07:29.247 [info] 
2023-05-27 23:07:30.348 [info] ##########Linting Output - pylama##########

2023-05-27 23:07:30.348 [info] 

User Settings

venvPath: "<placeholder>"

languageServer: "Pylance"

linting
• banditArgs: "<placeholder>"
• banditEnabled: true
• mypyEnabled: true
• pycodestyleEnabled: true
• pydocstyleEnabled: true
• pylamaEnabled: true

formatting
• provider: "none"

testing
• pytestEnabled: true

experiments
• optInto: ["pythonTerminalEnvVarActivation"]

Extension version: 2023.8.0
VS Code version: Code 1.78.2 (b3e4e68a0bc097f0ae7907b217c1119af9e03435, 2023-05-10T14:39:26.248Z)
OS version: Windows_NT x64 10.0.19044
Modes:
Sandboxed: No

[karrtikr]

Can you demonstrate that opting out of pythonTerminalEnvVarActivation experiment solves the issue in integrated terminal?

[bersbersbers]

Can you demonstrate that opting out of pythonTerminalEnvVarActivation experiment solves the issue in integrated terminal?

Yes:

On:

Off:

If that helps, toggling pythonTerminalEnvVarActivation and then using "Developer: Reload Window" does not change the behavior immediately. The bug seems to stick with an open terminal. Closing the terminal and opening a new one then shows the behavior if pythonTerminalEnvVarActivation was on when reloading VS Code, and does not show it if pythonTerminalEnvVarActivation was off when reloading VS Code.

By the way, this is in the integrated terminal with cmd - I cannot reproduce this with PowerShell or bash in WSL.

[karrtikr]

@Tyriar Any idea why this might be happening when using env collection, is a restriction imposed for sys.stdout?

[Tyriar]

No restriction, I don't know how this could happen.

[karrtikr]

@bersbersbers It's likely because of some environment variables which are being set due to experiment. Try the following:

• Try pre-release version:

• Run Show environment contributions command and paste the list of env vars here
• Try unsetting the env vars under ms.python-python extension one by one and running the command to see which env is the problematic one.

[bersbersbers]

• Try pre-release version:

Done - installed v2023.13.12071009.

• Run Show environment contributions command and paste the list of env vars here

This is before opening a .py file:

# Terminal Environment Changes

## Extension: vscode.git

- `GIT_ASKPASS=c:\Users\bers\AppData\Local\Programs\Microsoft VS Code\resources\app\extensions\git\dist\askpass.sh`
- `VSCODE_GIT_ASKPASS_NODE=C:\Users\bers\AppData\Local\Programs\Microsoft VS Code\Code.exe`
- `VSCODE_GIT_ASKPASS_EXTRA_ARGS=--ms-enable-electron-run-as-node`
- `VSCODE_GIT_ASKPASS_MAIN=c:\Users\bers\AppData\Local\Programs\Microsoft VS Code\resources\app\extensions\git\dist\askpass-main.js`
- `VSCODE_GIT_IPC_HANDLE=\\.\pipe\vscode-git-e394b530ca-sock`

Problem does not reproduce.

After opening a .py file:

# Terminal Environment Changes

## Extension: ms-python.python


## Extension: vscode.git

- `GIT_ASKPASS=c:\Users\bers\AppData\Local\Programs\Microsoft VS Code\resources\app\extensions\git\dist\askpass.sh`
- `VSCODE_GIT_ASKPASS_NODE=C:\Users\bers\AppData\Local\Programs\Microsoft VS Code\Code.exe`
- `VSCODE_GIT_ASKPASS_EXTRA_ARGS=--ms-enable-electron-run-as-node`
- `VSCODE_GIT_ASKPASS_MAIN=c:\Users\bers\AppData\Local\Programs\Microsoft VS Code\resources\app\extensions\git\dist\askpass-main.js`
- `VSCODE_GIT_IPC_HANDLE=\\.\pipe\vscode-git-c32f3db32b-sock`

Problem appears again.

• Try unsetting the env vars under ms.python-python extension one by one and running the command to see which env is the problematic one.

Nothing for me to do here, I fear :(

[karrtikr]

That's weird, Python section ideally shouldn't even appear when empty. Can you send a screenshot of the lower right portion after hovering over the terminal? Make sure to include the Python text in the status bar.

[bersbersbers]

Sure!

I also verified this:

2023-07-27 22:14:58.747 [info] Telemetry level is off
2023-07-27 22:14:58.747 [info] Experiments are disabled, only manually opted experiments are active.
2023-07-27 22:14:58.747 [info] Experiment 'pythonTerminalEnvVarActivation' is active
2023-07-27 22:14:58.747 [info] Experiment 'pythonTestAdapter' is active

[karrtikr]

Make sure to include the Python text in the status bar.

This appears to be missing.

[karrtikr]

Also, please send the result of the command below when run outside VS Code in command prompt:

%USERPROFILE%/.pyenv-win-venv/envs/project_3.11/Scripts/activate.bat && echo 'e8b39361-0157-4923-80e1-22d70d46dee6' && python ~/.vscode/extensions/ms-python.python-2023.8.0/pythonFiles/printEnvVariables.py

Make sure to replace ms-python.python-2023.8.0 with the current version of Python extension that exists.

[karrtikr]

Lastly, I may need the debug logs based on above information:

• Run Developer: Set log level command

• Select Python -> Select Trace

• Run Developer: Reload Window command

• Provide the output:

  Output for Python in the Output panel (View→Output, change the drop-down the upper-right of the Output panel to Python)

  XXX
  

[bersbersbers]

This appears to be missing.

Sorry for that:

The other commands contain quite a bit of to-be-redacted information, so unless you absolutely need this, I'd like to proceed without first. To help in that: I was able to reproduce the problem outside of VS Code, looking at the difference between environments at different times:

        "PYTHONWARNINGS": "ignore",
        "PYTHONUNBUFFERED": "1",
        "PYTHONIOENCODING": "utf-8"

So this creates the same problem in cmd.exe:

rem Pass
python -c "import sys; sys.stdout.write(''.join(f'{i:04d} \n' for i in range(5000)))"

set PYTHONUNBUFFERED=1

rem Fail
python -c "import sys; sys.stdout.write(''.join(f'{i:04d} \n' for i in range(5000)))"

[bersbersbers]

This seems to be a duplicate of python/cpython#86210

[karrtikr]

Yup, seems like it. I have modified our code to not PYTHONUNBUFFERED, can you try https://github.com/microsoft/vscode-python/suites/14805705609/artifacts/842641932? Use Extension: Install from VSIX command to install the extension and reload window. Make sure you're using the latest stable version of VSCode (1.81.0).

Thanks for helping diagnose this btw~

[bersbersbers]

I have tried v2023.15.5755506229-dev and it seems to do the trick (took me a couple of tries, but once I closed all terminals and installed the VSIX every time I reloaded VS Code, it worked). Thanks!

[karrtikr]

Awesome, reopening terminals is generally required to reapply env variables so that's fine.

Fix should be officially out in the pre-release version of the extension in a day, use the following to try it out: