search

microsoft / vscode

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

export DEBUG in ~/.bashrc file causes "Cannot reconnect. Please reload the window." / "Disconnected from SSH: <remote>" #130072

Closed JeffReeves closed 3 years ago

JeffReeves commented 3 years ago

VSCode 1.57.0:

[16:22:00.993] Log Level: 2
[16:22:00.996] remote-ssh@0.65.7
[16:22:00.996] win32 x64
[16:22:00.997] SSH Resolver called for "ssh-remote+bridges", attempt 1
[16:22:00.997] "remote.SSH.useLocalServer": false
[16:22:00.997] "remote.SSH.showLoginTerminal": false
[16:22:00.997] "remote.SSH.remotePlatform": {"bridges":"linux"}
[16:22:00.997] "remote.SSH.path": undefined
[16:22:00.997] "remote.SSH.configFile": undefined
[16:22:00.998] "remote.SSH.useFlock": true
[16:22:00.998] "remote.SSH.lockfilesInTmp": false
[16:22:00.998] "remote.SSH.localServerDownload": auto
[16:22:00.998] "remote.SSH.remoteServerListenOnSocket": false
[16:22:00.998] "remote.SSH.showLoginTerminal": false
[16:22:00.998] "remote.SSH.defaultExtensions": []
[16:22:00.998] "remote.SSH.loglevel": 2
[16:22:00.998] SSH Resolver called for host: bridges
[16:22:00.998] Setting up SSH remote "bridges"
[16:22:01.009] Using commit id "b4c1bd0a9b03c749ea011b06c6d2676c8091a70c" and quality "stable" for server
[16:22:01.011] Install and start server if needed
[16:22:01.017] Checking ssh with "ssh -V"
[16:22:01.035] > OpenSSH_for_Windows_8.
[16:22:01.035] > 1p1, LibreSSL 3.0.2

[16:22:01.037] Running script with connection command: ssh -T -D 62593 bridges bash
[16:22:01.038] Terminal shell path: C:\Windows\System32\cmd.exe
[16:22:01.196] > ]0;C:\Windows\System32\cmd.exe
[16:22:01.197] Got some output, clearing connection timeout
[16:22:01.418] > 23d37ed021ed: running
[16:22:01.447] > Acquiring lock on /home/jeff/.vscode-server/bin/b4c1bd0a9b03c749ea011b06c6d2676c
> 8091a70c/vscode-remote-lock.jeff.b4c1bd0a9b03c749ea011b06c6d2676c8091a70c       
> Installing to /home/jeff/.vscode-server/bin/b4c1bd0a9b03c749ea011b06c6d2676c8091
> a70c...
> 23d37ed021ed%%1%%
> Downloading with wget
[16:22:04.411] > Download complete
[16:22:04.423] > 23d37ed021ed%%2%%
> tar --version:
> tar (GNU tar) 1.30
> Copyright (C) 2017 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later <https://gnu.org/licenses/gpl.html>.
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law.
> 
> Written by John Gilmore and Jay Fenlason.
[16:22:05.256] > Checking /home/jeff/.vscode-server/.b4c1bd0a9b03c749ea011b06c6d2676c8091a70c.log
>  and /home/jeff/.vscode-server/.b4c1bd0a9b03c749ea011b06c6d2676c8091a70c.pid for
>  a running server
[16:22:05.271] > WARNING: VS Code Server is running but its logfile is missing. Don't delete the 
> VS Code Server manually, run the command 'Uninstall VS Code Server'.
> Starting server with command... /home/jeff/.vscode-server/bin/b4c1bd0a9b03c749ea
> 011b06c6d2676c8091a70c/server.sh --start-server --host=127.0.0.1 --enable-remote
> -auto-shutdown  --port=0  &> "/home/jeff/.vscode-server/.b4c1bd0a9b03c749ea011b0
> 6c6d2676c8091a70c.log" < /dev/null
> printenv:
>     SHELL=/bin/bash
>     PWD=/home/jeff
>     LOGNAME=jeff
>     XDG_SESSION_TYPE=tty
>     MOTD_SHOWN=pam
>     HOME=/home/jeff
>     LANG=en_US.UTF-8
>     VSCODE_AGENT_FOLDER=/home/jeff/.vscode-server
>     SSH_CONNECTION=192.168.1.20 62595 192.168.1.3 22
>     XDG_SESSION_CLASS=user
>     USER=jeff
>     SHLVL=0
>     XDG_SESSION_ID=11
>     XDG_RUNTIME_DIR=/run/user/1000
>     SSH_CLIENT=192.168.1.20 62595 22
>     PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games
> :/usr/local/games:/snap/bin
>     DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
>     OLDPWD=/home/jeff/.vscode-server/bin/b4c1bd0a9b03c749ea011b06c6d2676c8091a70
> c
>     _=/usr/bin/printenv
> rm: cannot remove '/home/jeff/.vscode-server/.b4c1bd0a9b03c749ea011b06c6d2676c80
> 91a70c.token': No such file or directory
> Spawned remote server: 2450
[16:22:05.277] > 
> Waiting for server log...
[16:22:05.287] > 
[16:22:05.309] > Waiting for server log...
[16:22:05.346] >  
> *
> * Reminder: You may only use this software with Visual Studio family products,
> * as described in the license (https://go.microsoft.com/fwlink/?linkid=2077057) 
> *
> 
[16:22:05.353] > 
> Checking server status on port 44815 with wget
[16:22:05.367] > 
[16:22:05.432] > 23d37ed021ed: start
> SSH_AUTH_SOCK====
> DISPLAY====
> webUiAccessToken====
> listeningOn==44815==
> osReleaseId==ubuntu==
> arch==x86_64==
> tmpDir==/run/user/1000==
> platform==linux==
> unpackResult==success==
> didLocalDownload==0==
> downloadTime==2975==
> installTime==836==
> extInstallTime====
> serverStartTime==73==
> connectionToken==aa1aaaa1-1a1a-1aaa-aa11-aa1a11a1aaaa==
> 23d37ed021ed: end
[16:22:05.432] Received install output: 
SSH_AUTH_SOCK====
DISPLAY====
webUiAccessToken====
listeningOn==44815==
osReleaseId==ubuntu==
arch==x86_64==
tmpDir==/run/user/1000==
platform==linux==
unpackResult==success==
didLocalDownload==0==
downloadTime==2975==
installTime==836==
extInstallTime====
serverStartTime==73==
connectionToken==aa1aaaa1-1a1a-1aaa-aa11-aa1a11a1aaaa==

[16:22:05.432] Remote server is listening on 44815
[16:22:05.432] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":44815},"osReleaseId":"ubuntu","arch":"x86_64","webUiAccessToken":"","sshAuthSock":"","display":"","tmpDir":"/run/user/1000","platform":"linux","connectionToken":"aa1aaaa1-1a1a-1aaa-aa11-aa1a11a1aaaa"},"downloadTime":2975,"installTime":836,"serverStartTime":73,"installUnpackCode":"success"}
[16:22:05.433] Starting forwarding server. localPort 62596 -> socksPort 62593 -> remotePort 44815
[16:22:05.434] Forwarding server listening on 62596
[16:22:05.434] Waiting for ssh tunnel to be ready
[16:22:05.435] [Forwarding server 62596] Got connection 0
[16:22:05.435] Tunneled 44815 to local port 62596
[16:22:05.435] Resolved "ssh-remote+bridges" to "127.0.0.1:62596"
[16:22:05.438] ------

[16:22:05.485] [Forwarding server 62596] Got connection 1
[16:22:05.495] > 
[16:22:05.500] [Forwarding server 62596] Got connection 2
[16:22:05.927] [Forwarding server 62596] Got connection 3

VSCode 1.58.0-insiders:

[16:31:30.446] Log Level: 2
[16:31:30.449] remote-ssh@0.65.7
[16:31:30.449] win32 x64
[16:31:30.450] SSH Resolver called for "ssh-remote+bridges", attempt 1
[16:31:30.450] "remote.SSH.useLocalServer": false
[16:31:30.450] "remote.SSH.showLoginTerminal": false
[16:31:30.450] "remote.SSH.remotePlatform": {"bridges":"linux"}
[16:31:30.450] "remote.SSH.path": undefined
[16:31:30.450] "remote.SSH.configFile": undefined
[16:31:30.450] "remote.SSH.useFlock": true
[16:31:30.451] "remote.SSH.lockfilesInTmp": false
[16:31:30.451] "remote.SSH.localServerDownload": auto
[16:31:30.451] "remote.SSH.remoteServerListenOnSocket": false
[16:31:30.451] "remote.SSH.showLoginTerminal": false
[16:31:30.451] "remote.SSH.defaultExtensions": []
[16:31:30.451] "remote.SSH.loglevel": 2
[16:31:30.451] SSH Resolver called for host: bridges
[16:31:30.451] Setting up SSH remote "bridges"
[16:31:30.462] Using commit id "012b14606f75ec4fed90d7ab4154f63dffab9503" and quality "insider" for server
[16:31:30.464] Install and start server if needed
[16:31:30.468] Checking ssh with "ssh -V"
[16:31:30.488] > OpenSSH_for_Win
[16:31:30.489] > dows_8.1p1, LibreSSL 3.0.2

[16:31:30.490] Running script with connection command: ssh -T -D 62408 bridges bash
[16:31:30.492] Terminal shell path: C:\Windows\System32\cmd.exe
[16:31:30.672] > ]0;C:\Windows\System32\cmd.exe
[16:31:30.672] Got some output, clearing connection timeout
[16:31:30.895] > f9b74f511a85: running
[16:31:30.924] > Acquiring lock on /home/jeff/.vscode-server-insiders/bin/012b14606f75ec4fed90d7a
> b4154f63dffab9503/vscode-remote-lock.jeff.012b14606f75ec4fed90d7ab4154f63dffab95
> 03
> Installing to /home/jeff/.vscode-server-insiders/bin/012b14606f75ec4fed90d7ab415
> 4f63dffab9503...
> f9b74f511a85%%1%%
> Downloading with wget
[16:31:33.794] > Download complete
[16:31:33.802] > f9b74f511a85%%2%%
> tar --version:
> tar (GNU tar) 1.30
> Copyright (C) 2017 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later <https://gnu.org/licenses/gpl.html>.
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law.
> 
> Written by John Gilmore and Jay Fenlason.
[16:31:34.635] > Checking /home/jeff/.vscode-server-insiders/.012b14606f75ec4fed90d7ab4154f63dffa
> b9503.log and /home/jeff/.vscode-server-insiders/.012b14606f75ec4fed90d7ab4154f6
> 3dffab9503.pid for a running server
[16:31:34.651] > Starting server with command... /home/jeff/.vscode-server-insiders/bin/012b14606
> f75ec4fed90d7ab4154f63dffab9503/server.sh --start-server --host=127.0.0.1 --enab
> le-remote-auto-shutdown  --port=0  &> "/home/jeff/.vscode-server-insiders/.012b1
> 4606f75ec4fed90d7ab4154f63dffab9503.log" < /dev/null
> printenv:
>     SHELL=/bin/bash
>     PWD=/home/jeff
>     LOGNAME=jeff
>     XDG_SESSION_TYPE=tty
>     MOTD_SHOWN=pam
>     HOME=/home/jeff
>     LANG=en_US.UTF-8
>     VSCODE_AGENT_FOLDER=/home/jeff/.vscode-server-insiders
>     SSH_CONNECTION=192.168.1.20 62410 192.168.1.3 22
>     XDG_SESSION_CLASS=user
>     USER=jeff
>     SHLVL=0
>     XDG_SESSION_ID=14
>     XDG_RUNTIME_DIR=/run/user/1000
>     SSH_CLIENT=192.168.1.20 62410 22
>     PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games
> :/usr/local/games:/snap/bin
>     DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
>     OLDPWD=/home/jeff/.vscode-server-insiders/bin/012b14606f75ec4fed90d7ab4154f6
> 3dffab9503
>     _=/usr/bin/printenv
> rm: cannot remove '/home/jeff/.vscode-server-insiders/.012b14606f75ec4fed90d7ab4
> 154f63dffab9503.token': No such file or directory
> Spawned remote server: 2830
[16:31:34.657] > 
> Waiting for server log...
[16:31:34.663] > 
[16:31:34.694] >  
> *
> * Reminder: You may only use this software with Visual Studio family products,
> * as described in the license (https://go.microsoft.com/fwlink/?linkid=2077057) 
> *
> 
> f9b74f511a85: start
> SSH_AUTH_SOCK====
> DISPLAY====
> webUiAccessToken====
> listeningOn==43969==
> osReleaseId==ubuntu==
> arch==x86_64==
> tmpDir==/run/user/1000==
> platform==linux==
> unpackResult==success==
> didLocalDownload==0==
> downloadTime==2881==
> installTime==832==
> extInstallTime====
> serverStartTime==39==
> connectionToken==aaa11111-111a-1a1a-11aa-111aaa111a11==
> f9b74f511a85: end
[16:31:34.694] Received install output: 
SSH_AUTH_SOCK====
DISPLAY====
webUiAccessToken====
listeningOn==43969==
osReleaseId==ubuntu==
arch==x86_64==
tmpDir==/run/user/1000==
platform==linux==
unpackResult==success==
didLocalDownload==0==
downloadTime==2881==
installTime==832==
extInstallTime====
serverStartTime==39==
connectionToken==aaa11111-111a-1a1a-11aa-111aaa111a11==

[16:31:34.694] Remote server is listening on 43969
[16:31:34.695] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":43969},"osReleaseId":"ubuntu","arch":"x86_64","webUiAccessToken":"","sshAuthSock":"","display":"","tmpDir":"/run/user/1000","platform":"linux","connectionToken":"aaa11111-111a-1a1a-11aa-111aaa111a11"},"downloadTime":2881,"installTime":832,"serverStartTime":39,"installUnpackCode":"success"}
[16:31:34.695] Starting forwarding server. localPort 62411 -> socksPort 62408 -> remotePort 43969
[16:31:34.696] Forwarding server listening on 62411
[16:31:34.696] Waiting for ssh tunnel to be ready
[16:31:34.697] Tunneled 43969 to local port 62411
[16:31:34.697] Resolved "ssh-remote+bridges" to "127.0.0.1:62411"
[16:31:34.698] [Forwarding server 62411] Got connection 0
[16:31:34.701] ------

[16:31:34.741] [Forwarding server 62411] Got connection 1
[16:31:34.752] > 
[16:31:34.810] [Forwarding server 62411] Got connection 2
[16:31:35.248] [Forwarding server 62411] Got connection 3

Steps to Reproduce:

  1. Install VSCode v1.57.0 or v1.58.0-insiders.
  2. Install Remote Development extension (which includes Remote SSH).
  3. Connect to new SSH host (ex. ssh jeff@bridges).
  4. Watch the terminal show vscode server get downloaded and installed, and then the connection fails with a pop-up saying: "Cannot reconnect. Please reload the window.", and in the bottom left there is a green bar that reads: "Disconnected from SSH:".

Does this issue occur when you try this locally?: Yes Does this issue occur when you try this locally and all extensions are disabled?: Yes

Troubleshooting Attempts:

I've tried running the "Remote-SSH: Kill VS Code Server on Host" option, deleting the ~/.vscode-server* directories manually, killing all processes related to vscode on the remote server, etc. but nothing seems to resolve the issue.

I'm able to connect using SSH in Windows Terminal and git bash just fine, so I don't see why the connection fails after it appears to be established to download vscode-server.

Oddly enough, this issue only happens on my local home lab server ("bridges") and not on one of my production servers running on Digital Ocean ("uca").

Additional Details on Failing Home Lab Connection

Host Client /.ssh/config:

Host bridges
  HostName 192.168.1.3
  User jeff
  Port 22
  IdentityFile ~/.ssh/id_rsa

Remote Server details:

# sshd version
jeff@bridges:~$ ssh -V
OpenSSH_8.2p1 Ubuntu-4ubuntu0.2, OpenSSL 1.1.1f  31 Mar 2020

# kernel details
jeff@bridges:~$ uname -a
Linux bridges 5.8.0-55-generic microsoft/vscode-remote-release#62~20.04.1-Ubuntu SMP Wed Jun 2 08:55:04 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

# my sshd configuration (sans commented out lines)
jeff@bridges:~$ grep -Ev '^#' /etc/ssh/sshd_config | grep -v '^$'
Include /etc/ssh/sshd_config.d/*.conf
PermitRootLogin no
MaxAuthTries 2
AuthorizedKeysFile      .ssh/authorized_keys .ssh/authorized_keys2
PasswordAuthentication yes
ChallengeResponseAuthentication no
UsePAM yes
AllowTcpForwarding yes
X11Forwarding yes
PrintMotd no
AcceptEnv LANG LC_*
Subsystem       sftp    /usr/lib/openssh/sftp-server

# I have added my SSH key from my Windows machine to the authorized_keys
jeff@bridges:~$ ll ~/.ssh/authorized_keys
-rw-------  1 jeff jeff  721 Jun 11 15:00 authorized_keys

# vscode directories show up in home directory
jeff@bridges:~$ ll ~ | grep -i vscode
drwxrwxr-x  5 jeff jeff 4.0K Jun 11 16:22 .vscode-server
drwxrwxr-x  5 jeff jeff 4.0K Jun 11 16:31 .vscode-server-insiders

Additional Details on Working Digital Ocean Connection

Remote Server Details:

# sshd version
jeff@uca:~$ ssh -V
OpenSSH_8.2p1 Ubuntu-4ubuntu0.2, OpenSSL 1.1.1f  31 Mar 2020

# kernel details
jeff@uca:~$ uname -a
Linux uca 5.4.0-74-generic microsoft/vscode-remote-release#83-Ubuntu SMP Sat May 8 02:35:39 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
JeffReeves commented 3 years ago

After a fair bit of troubleshooting, I managed to get connections to work.

It appears that an additional set of files I source in my ~/.bashrc file is causing the connection to fail after vscode is installed. I've commented them out for now, and will re-introduce them one at a time until I find which thing is at fault.

JeffReeves commented 3 years ago

Narrowed it down to exporting a variable called DEBUG ...

I have a set of colored text variables I export for use in other scripts, such as:

export DEBUG="\033[1;30m[DEBUG]\033[0m"

Apparently I can use these variables but not DEBUG: 

INFO
TASK
COMMAND
PROMPT
HELP
SUCCESS
WARNING
ERROR

If I comment out the DEBUG export, source ~/.bashrc, and then kill and reload the remote SSH connection in VSCode, it works fine.

If I uncomment and re-enable the DEBUG export, source ~/.bashrc, kill and reload the SSH connection in VSCode, it fails with the error I put in the original post.

This is a really odd thing to encounter. I'm guessing there's some sort of build process where the DEBUG env variable carries some special meaning, and my export is causing a conflict. Could anyone tell me why the exporting a DEBUG variable is causing this issue?

I'll work on changing my approach to making those variables available to my bash scripts in the meantime.

bamurtaugh commented 3 years ago

cc @roblourens @Chuxel Is it a known experience/limitation that a DEBUG env variable carries special meaning and would cause the user's connection to fail?

If this is expected, I looked through our docs and didn't see anything about it, and it feels like we should mention something about it?

Chuxel commented 3 years ago

@roblourens Does DEBUG this have special meaning to anything for Remote - SSH? I could certainly see it getting picked up by something and processed like it should be 0 or 1 or true or false rather than a color.

@JeffReeves How is DEBUG being processed? Normally I'd recommend using something with a prefix rather than just DEBUG given how likely it is that this could be picked up by some tool other than the one you are wanting - but don't know if that's an option.

JeffReeves commented 3 years ago

@Chuxel - The DEBUG env variable is being exported in a ~/.bashrc file like this:

export DEBUG="\033[1;30m[DEBUG]\033[0m"

I was using it for colored output in my shell scripts, like: echo "${DEBUG} This is a debug statement" --> [DEBUG] This is a debug statement

I've since rethought how I was including these macros for colored output in messages and have opted to just create a function called messages that I can pass parameters to, such as: message DEBUG "This is a debug statement" --> [DEBUG] This is a debug statement.

It took me a little while to figure out that exporting a DEBUG env variable of any value was causing my VSCode Remote connectivity issue. I've had this little script for years without issues (at least none that I noticed) and this was the first time it truly broke something.

roblourens commented 3 years ago

Interesting, I can repro. We spawn an EH and it shuts down immediately

[15:40:12] [127.0.0.1][cd572682][ExtensionHostConnection] <27672> Launched Extension Host Process.
[15:40:12] [127.0.0.1][cd572682][ExtensionHostConnection] <27672> Extension Host Process exited with code: 0, signal: null.

I don't know of anywhere that we read this, but DEBUG is commonly used by npm modules and I can imagine that some dependency is either crashing or producing too much output and causing a crash. cc @alexdima

roblourens commented 3 years ago

Easy repro in local vscode: 

[81595:0803/160931.596946:INFO:CONSOLE(104)] "%c[Extension Host] %cSyntaxError: Invalid regular expression: /^[$/: Unterminated character class
    at new RegExp (<anonymous>)
    at Function.enable (/Users/roblou/code/vscode/node_modules/get-uri/node_modules/debug/src/common.js:179:28)
    at setup (/Users/roblou/code/vscode/node_modules/get-uri/node_modules/debug/src/common.js:261:14)
    at Object.<anonymous> (/Users/roblou/code/vscode/node_modules/get-uri/node_modules/debug/src/node.js:236:37)
    at Module._compile (internal/modules/cjs/loader.js:1078:30)
    at Object..js (internal/modules/cjs/loader.js:1108:10)
    at Module.load (internal/modules/cjs/loader.js:935:32)
    at internal/modules/cjs/loader.js:776:14
    at Function._load (electron/js2c/asar_bundle.js:5:12913)
    at Module.require (internal/modules/cjs/loader.js:959:19)
    at require (internal/modules/cjs/helpers.js:88:18)
    at Object.<anonymous> (/Users/roblou/code/vscode/node_modules/get-uri/node_modules/debug/src/index.js:9:19)
    at Module._compile (internal/modules/cjs/loader.js:1078:30)
    at Object..js (internal/modules/cjs/loader.js:1108:10)
    at Module.load (internal/modules/cjs/loader.js:935:32)
    at internal/modules/cjs/loader.js:776:14
    at Function._load (electron/js2c/asar_bundle.js:5:12913)
    at Module.require (internal/modules/cjs/loader.js:959:19)
    at require (internal/modules/cjs/helpers.js:88:18)
    at Object.<anonymous> (/Users/roblou/code/vscode/node_modules/get-uri/dist/index.js:5:33)
    at Module._compile (internal/modules/cjs/loader.js:1078:30)
    at Object..js (internal/modules/cjs/loader.js:1108:10)
    at Module.load (internal/modules/cjs/loader.js:935:32)
    at internal/modules/cjs/loader.js:776:14
    at Function._load (electron/js2c/asar_bundle.js:5:12913)
roblourens commented 3 years ago

Relevant: https://github.com/visionmedia/debug/issues/288, https://github.com/visionmedia/debug/pull/250,

I think the right fix is to just strip the DEBUG environment variable at the line I pointed at above. I don't think this would change anything for us because I'm not aware of us relying on this in any debugging workflow. But I will leave it for @alexdima

Thanks for the narrowing this down @JeffReeves!

JeffReeves commented 3 years ago

@roblourens Thank you for getting attention to this! I seem to have a magic touch for breaking things in very unexpected ways lol.

roblourens commented 3 years ago

Verification steps:

JeffReeves commented 3 years ago

/verified on my end. Thank you all for this fix!