microsoft / vscode-remote-release

Visual Studio Code Remote Development: Open any folder in WSL, in a Docker container, or on a remote machine using SSH and take advantage of VS Code's full feature set.
https://aka.ms/vscode-remote
Other
3.64k stars 285 forks source link

"ExtensionHostConnection#buildUserEnvironment resolving shell environment failed Error: Unable to resolve your shell environment in a reasonable time. Please review your shell configuration." in linux remote ssh #6109

Closed SamKiley closed 2 years ago

SamKiley commented 2 years ago

Issue Type: Bug

On windows 10, using vscode remote ssh to connect to ubuntu 16.04 linux machine. I have issues with connecting to this ssh remote on the first attempt. In the log file in .vscode-server, the error "ExtensionHostConnection#buildUserEnvironment resolving shell environment failed Error: Unable to resolve your shell environment in a reasonable time. Please review your shell configuration." is encountered many times, until it eventually stops getting the error. I often have to attempt to reconnect 5 or so times before it stays connected and doesn't give an error prompt. It eventually works, but it really annoying and sometimes "connects" but there is an issue with the extension host and the search or my extensions doesn't work at all

Extension version: 0.70.0 VS Code version: Code 1.63.2 (899d46d82c4c95423fb7e10e68eba52050e30ba3, 2021-12-15T09:40:02.816Z) OS version: Windows_NT x64 10.0.19042 Restricted Mode: No Remote OS version: Linux x64 4.4.0-210-generic

System Info |Item|Value| |---|---| |CPUs|Intel(R) Core(TM) i5-8365U CPU @ 1.60GHz (8 x 1896)| |GPU Status|2d_canvas: enabled
gpu_compositing: enabled
multiple_raster_threads: enabled_on
oop_rasterization: enabled
opengl: enabled_on
rasterization: enabled
skia_renderer: enabled_on
video_decode: enabled
vulkan: disabled_off
webgl: enabled
webgl2: enabled| |Load (avg)|undefined| |Memory (System)|15.75GB (6.12GB free)| |Process Argv|--crash-reporter-id 154908ac-7c5a-4192-a580-430f627b135c| |Screen Reader|no| |VM|0%| |Item|Value| |---|---| |Remote|SSH: hu-skiley-sd| |OS|Linux x64 4.4.0-210-generic| |CPUs|AMD EPYC 7H12 64-Core Processor (8 x 2599)| |Memory (System)|15.67GB (10.07GB free)| |VM|100%|
A/B Experiments ``` vsliv368cf:30146710 vsreu685:30147344 python383cf:30185419 vspor879:30202332 vspor708:30202333 vspor363:30204092 vswsl492cf:30256860 pythontb:30283811 pythonptprofiler:30281270 vshan820:30294714 vstes263:30335439 pythondataviewer:30285071 vscod805cf:30301675 pythonvspyt200:30340761 binariesv615:30325510 bridge0708:30335490 bridge0723:30353136 vsaa593cf:30376535 pythonvs932:30410667 vscop804cf:30404767 vs360cf:30404996 vsrem710:30416614 py55gd98:30411514 vscexrecpromp3c:30407761 ```
tanhakabir commented 2 years ago

Is there anything overly time consuming in your ubuntu's shell setup/configuration?

Could I also see your Remote-SSH logs from the Output tab on a failed connection?

tanhakabir commented 2 years ago

You could look here for tips: https://code.visualstudio.com/Docs/supporting/FAQ#_resolving-shell-environment-fails

SamKiley commented 2 years ago

I have looked at that guide before and it doesn't really mention anything other than the time consuming .bashrc stuff. I timed the .bashrc execution and it takes around 0.4 seconds, so definitely not the 10 seconds that it says would be an issue. There are other issues somewhere I believe where people get this error and don't have slow .bashrc, but those issues are never resolved.

Also, my issue is potentially similar to https://github.com/microsoft/vscode-remote-release/issues/6107 that I think you are also working on. (minus the thing from waltoncade, I think they just need to delete .vscode-server and rerun)

Remote-ssh logs where I get a "Could not fetch remote environment" and "Failed to connect to remote extension host server :Error: Time limit reached" pop ups.

Output Tab:

[10:09:58.140] Log Level: 2 [10:09:58.149] remote-ssh@0.70.0 [10:09:58.150] win32 x64 [10:09:58.166] SSH Resolver called for "ssh-remote+hu-skiley-sd", attempt 1 [10:09:58.167] "remote.SSH.useLocalServer": false [10:09:58.167] "remote.SSH.showLoginTerminal": true [10:09:58.167] "remote.SSH.remotePlatform": {"hu-skiley-sd":"linux"} [10:09:58.167] "remote.SSH.path": undefined [10:09:58.167] "remote.SSH.configFile": undefined [10:09:58.167] "remote.SSH.useFlock": true [10:09:58.167] "remote.SSH.lockfilesInTmp": false [10:09:58.168] "remote.SSH.localServerDownload": auto [10:09:58.168] "remote.SSH.remoteServerListenOnSocket": false [10:09:58.168] "remote.SSH.showLoginTerminal": true [10:09:58.168] "remote.SSH.defaultExtensions": [] [10:09:58.168] "remote.SSH.loglevel": 2 [10:09:58.168] "remote.SSH.serverPickPortsFromRange": {} [10:09:58.168] "remote.SSH.enableDynamicForwarding": true [10:09:58.168] "remote.SSH.serverInstallPath": {} [10:09:58.169] SSH Resolver called for host: hu-skiley-sd [10:09:58.169] Setting up SSH remote "hu-skiley-sd" [10:09:58.184] Using commit id "899d46d82c4c95423fb7e10e68eba52050e30ba3" and quality "stable" for server [10:09:58.188] Install and start server if needed [10:09:58.207] Checking ssh with "ssh -V" [10:09:58.317] > OpenSSH_for_Windows_8.1p1, LibreSSL 3.0.2

[10:09:58.324] Running script with connection command: ssh -T -D 62131 "hu-skiley-sd" bash [10:09:58.329] Terminal shell path: C:\WINDOWS\System32\cmd.exe [10:09:58.856] > ]0;C:\WINDOWS\System32\cmd.exe [10:09:58.856] Got some output, clearing connection timeout [10:09:58.869] >

[10:09:59.958] > b8325f57a8d0: running [10:10:00.531] > Acquiring lock on /usr2/skiley/.vscode-server/bin/899d46d82c4c95423fb7e10e68eba52050e30ba3/vscode-remote-lock.skiley.899d46d82c4c95423fb7e10e68eba52050e30ba3 [10:10:00.914] > Found existing installation at /usr2/skiley/.vscode-server/bin/899d46d82c4c95423fb7e10e68eba52050e30ba3... [10:10:00.937] > Checking /usr2/skiley/.vscode-server/.899d46d82c4c95423fb7e10e68eba52050e30ba3.log and /usr2/skiley/.vscode-server/.899d46d82c4c95423fb7e10e68eba52050e30ba3.pid for a running server [10:10:01.061] > Looking for server with pid: 16033 [10:10:01.101] > Starting server with command... /usr2/skiley/.vscode-server/bin/899d46d82c4c95423fb7e10e68eba52050e30ba3/server.sh --start-server --host=127.0.0.1 --enable-remote-aut o-shutdown --port=0 &> "/usr2/skiley/.vscode-server/.899d46d82c4c95423fb7e10e68eba52050e30ba3.log" < /dev/null printenv: SHELL=/bin/bash LANGUAGE=en_US: P4CONFIG=.p4config PWD=/usr2/skiley LOGNAME=skiley HOME=/usr2/skiley LANG=en_US.UTF-8 P4PORT=qctp401:1666 VSCODE_AGENT_FOLDER=/usr2/skiley/.vscode-server SSH_CONNECTION=10.110.36.166 62133 10.56.228.143 22 P4USER=skiley USER=skiley SHLVL=0 XDG_SESSION_ID=3105 ARMLMD_LICENSE_FILE=8224@redcloud:7117@license-wan-arm1 XDG_RUNTIME_DIR=/run/user/2377461 SSHCLIENT=10.110.36.166 62133 22 PATH=/pkg/qct/software/perforce/2017.1:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/prj/qct/asw/qctss/linux /bin:/pkg/qct/software/collaborator/8.5.8502:.:/pkg/ice/sysadmin/ossi/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/sn ap/bin:/pkg/qct/software/perforce/current:/pkg/qct/software/gnu/tree/1.7.0/bin:/pkg/qct/software/hexagon/trace32/run/latest:/prj/qct/asw/SABin/Linux/Parasoft/cpptest standard:/prj/qct/asw/SABin/Linux/Parasoft/cpptest_standard/bin:/pkg/qct/software/hexagon/earlyaccess/volume2/8.6-beta1/Tools/bin:pkg/icetools/bin:/usr2/skiley/.local /bin:/pkg/qct/virtualplatforms/tools/bin:/pkg/qct/software/hexagon/trace32/run/latest/bin/pc_linux64:/prj/qct/asw/qctss/linux/bin/vce FINDBUILD_OVERRIDESITE=http://crmbuild.qualcomm.com/crmbuild.svc?wsdl MAIL=/var/mail/skiley =/usr/bin/printenv [10:10:02.144] > Spawned remote server: 31321 [10:10:02.212] > Waiting for server log... [10:10:02.320] > Waiting for server log... [10:10:02.428] > Waiting for server log... [10:10:02.573] > Waiting for server log... [10:10:02.644] > Waiting for server log... [10:10:02.746] > Waiting for server log... [10:10:02.856] > Waiting for server log... [10:10:02.962] > Waiting for server log... [10:10:03.071] > Waiting for server log... [10:10:03.174] > Waiting for server log... [10:10:03.282] > Waiting for server log... [10:10:03.466] > Waiting for server log... [10:10:03.579] > Waiting for server log... [10:10:03.680] > Waiting for server log... [10:10:03.791] > Waiting for server log... [10:10:04.358] > Waiting for server log... [10:10:04.741] >
*

b8325f57a8d0: start [10:10:04.748] > SSH_AUTH_SOCK==== DISPLAY==== webUiAccessToken==== listeningOn==36551== osReleaseId==ubuntu== arch==x86_64== tmpDir==/run/user/2377461== platform==linux== unpackResult==== didLocalDownload==0== downloadTime==== installTime==== extInstallTime==== serverStartTime==3581== connectionToken==a111a11a-111a-11a1-a1a1-11a111aaa1a1== b8325f57a8d0: end [10:10:04.748] Received install output: SSH_AUTH_SOCK==== DISPLAY==== webUiAccessToken==== listeningOn==36551== osReleaseId==ubuntu== arch==x86_64== tmpDir==/run/user/2377461== platform==linux== unpackResult==== didLocalDownload==0== downloadTime==== installTime==== extInstallTime==== serverStartTime==3581== connectionToken==a111a11a-111a-11a1-a1a1-11a111aaa1a1==

[10:10:04.748] Remote server is listening on 36551 [10:10:04.748] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":36551},"osReleaseId":"ubuntu","arch":"x86_64","webUiAccessToken":"","sshAuthSock":"","display":"","tmpDir":"/run/user/2377461","platform":"linux","connectionToken":"a111a11a-111a-11a1-a1a1-11a111aaa1a1"},"serverStartTime":3581,"installUnpackCode":""} [10:10:04.763] Starting forwarding server. localPort 63808 -> socksPort 62131 -> remotePort 36551 [10:10:04.775] Forwarding server listening on 63808 [10:10:04.776] Waiting for ssh tunnel to be ready [10:10:04.777] > [10:10:04.778] Tunneled 36551 to local port 63808 [10:10:04.778] Resolved "ssh-remote+hu-skiley-sd" to "127.0.0.1:63808" [10:10:04.779] [Forwarding server 63808] Got connection 0 [10:10:04.788] ------

[10:10:04.822] [Forwarding server 63808] Got connection 1 [10:10:18.019] [Forwarding server 63808] Got connection 2

Terminal Tab:

b8325f57a8d0: running Acquiring lock on /usr2/skiley/.vscode-server/bin/899d46d82c4c95423fb7e10e68eba52050e30ba3/vscode-remote-lock.skiley.899d46d82c4c95423fb7e10e68eba52050e30ba3 Found existing installation at /usr2/skiley/.vscode-server/bin/899d46d82c4c95423fb7e10e68eba52050e30ba3... Checking /usr2/skiley/.vscode-server/.899d46d82c4c95423fb7e10e68eba52050e30ba3.log and /usr2/skiley/.vscode-server/.899d46d82c4c95423fb7e10e68eba52050e30ba3.pid for a running server Looking for server with pid: 16033 Starting server with command... /usr2/skiley/.vscode-server/bin/899d46d82c4c95423fb7e10e68eba52050e30ba3/server.sh --start-server --host=127.0.0.1 --enable-remote-auto-shutdown --port=0 &> "/usr2/skiley/.vscode-server/.899d46d82c4c95423fb7e10e68eba52050e30ba3.log" < /dev/null printenv: SHELL=/bin/bash LANGUAGE=en_US: P4CONFIG=.p4config PWD=/usr2/skiley LOGNAME=skiley HOME=/usr2/skiley LANG=en_US.UTF-8 P4PORT=qctp401:1666 VSCODE_AGENT_FOLDER=/usr2/skiley/.vscode-server SSH_CONNECTION=10.110.36.166 62133 10.56.228.143 22 P4USER=skiley USER=skiley SHLVL=0 XDG_SESSION_ID=3105 ARMLMD_LICENSE_FILE=8224@redcloud:7117@license-wan-arm1 XDG_RUNTIME_DIR=/run/user/2377461 SSH_CLIENT=10.110.36.166 62133 22 PATH=/pkg/qct/software/perforce/2017.1:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/prj/qct/asw/qctss/linux/bin:/pkg/qct/software/collaborator/8.5.8502:.:/pkg/ice/sysadmin/ossi/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/pkg/qct/software/perforce/current:/pkg/qct/software/gnu/tree/1.7.0/bin:/pkg/qct/software/hexagon/trace32/run/latest:/prj/qct/asw/SABin/Linux/Parasoft/cpptest_standard:/prj/qct/asw/SABin/Linux/Parasoft/cpptest_standard/bin:/pkg/qct/software/hexagon/earlyaccess/volume2/8.6-beta1/Tools/bin:pkg/icetools/bin:/usr2/skiley/.local/bin:/pkg/qct/virtualplatforms/tools/bin:/pkg/qct/software/hexagon/trace32/run/latest/bin/pc_linux64:/prj/qct/asw/qctss/linux/bin/vce FINDBUILD_OVERRIDESITE=http://crmbuild.qualcomm.com/crmbuild.svc?wsdl MAIL=/var/mail/skiley =/usr/bin/printenv Spawned remote server: 31321 Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log... Waiting for server log...

*

b8325f57a8d0: start SSH_AUTH_SOCK==== DISPLAY==== webUiAccessToken==== listeningOn==36551== osReleaseId==ubuntu== arch==x86_64== tmpDir==/run/user/2377461== platform==linux== unpackResult==== didLocalDownload==0== downloadTime==== installTime==== extInstallTime==== serverStartTime==3581== connectionToken==a934a06d-231c-45e2-b0a4-52f334ccf2a2== b8325f57a8d0: end

SamKiley commented 2 years ago

Even more confusing, when I just tried to open vscode to provide those logs, the .vscode-server log file did not have that original error about not resolving the shell. After it failed and provided the errors above I simple closed vscode and tried again. Like typical, it opened fine then. Below is the .vscode-server log for the failure and the successful connection: (Usually this is where the resolving failure error shows up)

*

Extension host agent listening on 36551

[10:10:17] Extension host agent started. [10:10:33] No ptyHost heartbeat after 6 seconds [10:10:34] [127.0.0.1][8ff45a2a][ExtensionHostConnection] New connection established. [10:10:35] [127.0.0.1][8ff45a2a][ExtensionHostConnection] <31936> Launched Extension Host Process. [10:22:40] [127.0.0.1][bed266d2][ManagementConnection] New connection established. [10:22:40] [127.0.0.1][d02754bc][ExtensionHostConnection] New connection established. [10:22:41] [127.0.0.1][d02754bc][ExtensionHostConnection] <10757> Launched Extension Host Process.

tanhakabir commented 2 years ago

Sorry about the delayed response. @Tyriar I'm not sure how we resolve shells in remote windows. Do you have an idea why there'd be a discrepancy between opening a shell in vscode in a remote window and the actual time it takes to resolve .bashrc?

SamKiley commented 2 years ago

Also I did have a "bash" in my .profile.local. I removed it, but that did not end up helping at all. And to reiterate, I am using windows 10 vscode and remote ssh into a linux machine with a .vscode server. Your statement of "resolve shells in remote windows" confused me. Sometimes when I try to open the remote ssh it fails, but does not give the resolving shell error, others times it does.

tanhakabir commented 2 years ago

"remote windows" I mean remote vscode windows. Not Windows as in the OS.

I'm sorry I don't know what could be the issue here but @Tyriar or @meganrogge might know?

meganrogge commented 2 years ago

when VS Code launches, we source a "dev environment" by running your default shell. When this fails we show the error message that your shell returned. Thus, you have some issue in your shell init files that's causing that error. You need to investigate on your end as it's a problem with your environment, not with VS Code.

We do this before showing that error:

https://github.com/microsoft/vscode/blob/87b365f433427f0b936b02382b177abebc7c6369/src/vs/platform/environment/node/shellEnv.ts#L126-L151

Tyriar commented 2 years ago

The remote case is a little different, but it still does essentially the same thing:

https://github.com/microsoft/vscode/blob/ef8700e85e8bacf471a60a44fcd72a0781258569/src/vs/server/node/extensionHostConnection.ts#L28-L35

That error displays when your shell takes over 10 seconds to start up:

https://github.com/microsoft/vscode/blob/1ab07c536abfb7ac05e57728ab1fb1e1d40190e8/src/vs/platform/environment/node/shellEnv.ts#L75-L79

I agree the issue is with your environment.