[Remote-SSH Bug]: Connection dies after a few minutes and cannot reconnect.

danlurie commented 1 year ago

Is there an existing issue for this bug?

[X] I have searched the existing issues

Required Troubleshooting Steps

[X] I have followed these troubleshooting steps
[X] I have tried both values of the remote.SSH.useLocalServer setting

Connect Locally

It connects successfully

->

No response

Expected Behavior

Remote-SSH connects to the server and remains connected unless the network connection is disrupted (e.g. the computer hibernates, the wifi drops).
If the network connection drops, Remote-SSH displays the authentication prompt and successfully re-establishes the connection.

This behavior was consistent for years until the current issue began occurring.

Steps To Reproduce

Initiate a connection to a remote host via SSH (either by selecting from the list of recent connections or via "Remote-SSH: Connect to Host").
Enter authentication key when prompted.

At first, the connection is established as expected and everything works normally (i.e. there is never an issue with the initial connection).

Proceed to work normally (e.g. navigate through the file browser, open and edit files, etc).
After a variable amount of time (often just under 5 minutes, but as short as under 2 minutes), vscode displays the authentication prompt again (and shows "Reconnecting" in the status bar at the bottom left of the window)
Enter authentication key as before.
vscode displays a dialog box which says "Cannot Reconnect: "Please reload the window"

This issue occurs every time I connect to the remote host.

Remote-SSH Log

``` [15:38:08.454] Log Level: 1 [15:38:08.465] VS Code version: 1.76.2 [15:38:08.465] Remote-SSH version: remote-ssh@0.98.0 [15:38:08.465] darwin x64 [15:38:08.474] SSH Resolver called for "ssh-remote+nx3.neuro.berkeley.edu", attempt 1 [15:38:08.474] "remote.SSH.useLocalServer": false [15:38:08.475] "remote.SSH.showLoginTerminal": false [15:38:08.475] "remote.SSH.remotePlatform": {"nx3.neuro.berkeley.edu":"linux"} [15:38:08.475] "remote.SSH.path": undefined [15:38:08.475] "remote.SSH.configFile": undefined [15:38:08.476] "remote.SSH.useFlock": true [15:38:08.476] "remote.SSH.lockfilesInTmp": false [15:38:08.476] "remote.SSH.localServerDownload": auto [15:38:08.476] "remote.SSH.remoteServerListenOnSocket": false [15:38:08.476] "remote.SSH.showLoginTerminal": false [15:38:08.476] "remote.SSH.defaultExtensions": [] [15:38:08.476] "remote.SSH.loglevel": 1 [15:38:08.477] "remote.SSH.enableDynamicForwarding": true [15:38:08.477] "remote.SSH.enableRemoteCommand": false [15:38:08.477] "remote.SSH.serverPickPortsFromRange": {} [15:38:08.477] "remote.SSH.serverInstallPath": {} [15:38:08.480] SSH Resolver called for host: nx3.neuro.berkeley.edu [15:38:08.481] Setting up SSH remote "nx3.neuro.berkeley.edu" [15:38:08.484] Using commit id "ee2b180d582a7f601fa6ecfdad8d9fd269ab1884" and quality "stable" for server [15:38:08.488] Install and start server if needed [15:38:08.492] PATH: /Users/dlurie/anaconda3/bin:/Users/dlurie/anaconda3/condabin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/opt/X11/bin [15:38:08.492] Checking ssh with "ssh -V" [15:38:08.499] > OpenSSH_8.6p1, LibreSSL 3.3.6 [15:38:08.503] Running script with connection command: ssh -T -D 51430 -o ConnectTimeout=15 'nx3.neuro.berkeley.edu' bash [15:38:10.060] "install" terminal received data: " Enter passphrase for key '/Users/dlurie/.ssh/id_rsa': " [15:38:10.060] Got some output, clearing connection timeout [15:38:10.061] Detected passphrase message [15:38:13.337] Got passphrase response [15:38:13.338] "install" wrote data to terminal: "**********" [15:38:13.356] "install" terminal received data: "" [15:38:13.722] "install" terminal received data: "ae2d6071b821: running" [15:38:13.744] "install" terminal received data: "Acquiring lock on /home/despo/dlurie/.vscode-server/bin/ee2b180d582a7f601fa6ecfdad8d9fd269ab1884/vscode-remote-lock.dlurie.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884" [15:38:13.753] "install" terminal received data: "Found existing installation at /home/despo/dlurie/.vscode-server/bin/ee2b180d582a7f601fa6ecfdad8d9fd269ab1884..." [15:38:13.764] "install" terminal received data: "Checking /home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.log and /home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.pid for a running server Looking for server with pid: 2983875" [15:38:13.820] "install" terminal received data: "Running ssh connection command... /home/despo/dlurie/.vscode-server/bin/ee2b180d582a7f601fa6ecfdad8d9fd269ab1884/bin/code-server --start-server --host=127.0.0.1 --accept-server-license-terms --enable-remote-auto-shutdown --port=0 --telemetry-level all &> "/home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.log" < /dev/null printenv: SSH_CONNECTION=135.180.118.238 51431 169.229.248.250 22 LANG=en_US.UTF-8 ITK_GLOBAL_DEFAULT_NUMBER_OF_THREADS=3 SGE_CELL=hwni which_declare=declare -f XDG_SESSION_ID=483144 USER=dlurie PWD=/home/despo/dlurie SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass HOME=/home/despo/dlurie SSH_CLIENT=135.180.118.238 51431 22 XDG_DATA_DIRS=/home/despo/dlurie/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share:/usr/share SGE_ROOT=/usr/local/sge-8.1.9 SHELL=/bin/bash SHLVL=2 MANPATH=/usr/local/sge-8.1.9/man:/usr/share/man:/usr/local/share/man VSCODE_AGENT_FOLDER=/home/despo/dlurie/.vscode-server LOGNAME=dlurie DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1186/bus XDG_RUNTIME_DIR=/run/user/1186 PATH=/home/despo/dlurie/anaconda3/bin:/home/despoB/dlurie/Software/globusconnectpersonal-2.3.4/:/home/despoB/dlurie/Software/libwebp-0.6.1-linux-x86-32/bin:/home/despoB/dlurie/Software/jre1.8.0_152/bin:/home/despoB/dlurie/Software/dcm2niix:/home/despoB/dlurie/Software/itksnap-3.8.0-beta-20181028-Linux-gcc64-qt4/bin:/home/despoB/dlurie/Software/DicomBrowser-1.5.2/bin:/home/despoB/dlurie/Software/cmake_3.5.0/bin:/home/despoB/dlurie/Software/c3d-1.0.0/bin:/home/despoB/dlurie/Software/ants-2.2.0/bin/:/usr/local/sge-8.1.9/bin:/usr/local/sge-8.1.9/bin/lx-amd64:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/home/despo/dlurie/.local/bin DEBUGINFOD_URLS=https://debuginfod.centos.org/ SGE_ARCH=lx-amd64 LESSOPEN=||/usr/bin/lesspipe.sh %s SGE_CLUSTER_NAME=p6444 BASH_FUNC_which%%=() { ( alias; eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ } _=/usr/bin/printenv" [15:38:13.846] "install" terminal received data: "Removing old logfile at /home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.log Spawned remote server: 3014545" [15:38:13.858] "install" terminal received data: "Waiting for server log..." [15:38:13.881] "install" terminal received data: "Waiting for server log..." [15:38:13.920] "install" terminal received data: " * * Visual Studio Code Server * * By using the software, you agree to * the Visual Studio Code Server License Terms (https://aka.ms/vscode-server-license) and * the Microsoft Privacy Statement (https://privacy.microsoft.com/en-US/privacystatement). * ae2d6071b821: start SSH_AUTH_SOCK==== DISPLAY==== webUiAccessToken==== listeningOn==45601== osReleaseId==rocky== arch==x86_64== tmpDir==/run/user/1186== platform==linux== unpackResult==== didLocalDownload==0== downloadTime==== installTime==== extInstallTime==== serverStartTime==94== connectionToken==111aa1aa-1111-11a1-1111-1111111aaa11== ae2d6071b821: end" [15:38:13.921] Received install output: SSH_AUTH_SOCK==== DISPLAY==== webUiAccessToken==== listeningOn==45601== osReleaseId==rocky== arch==x86_64== tmpDir==/run/user/1186== platform==linux== unpackResult==== didLocalDownload==0== downloadTime==== installTime==== extInstallTime==== serverStartTime==94== connectionToken==111aa1aa-1111-11a1-1111-1111111aaa11== [15:38:13.922] Remote server is listening on 45601 [15:38:13.922] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":45601},"osReleaseId":"rocky","arch":"x86_64","webUiAccessToken":"","sshAuthSock":"","display":"","tmpDir":"/run/user/1186","platform":"linux","connectionToken":"111aa1aa-1111-11a1-1111-1111111aaa11"},"serverStartTime":94,"installUnpackCode":""} [15:38:13.924] Starting forwarding server. localPort 51434 -> socksPort 51430 -> remotePort 45601 [15:38:13.924] Forwarding server listening on 51434 [15:38:13.925] Waiting for ssh tunnel to be ready [15:38:13.926] [Forwarding server 51434] Got connection 0 [15:38:13.928] Tunneled 45601 to local port 51434 [15:38:13.928] Resolved "ssh-remote+nx3.neuro.berkeley.edu" to "127.0.0.1:51434" [15:38:13.928] Updating terminal environments: {} [15:38:13.937] TELEMETRY: {"eventName":"resolver","properties":{"osReleaseId":"rocky","arch":"x86_64","askedPw":"0","askedPassphrase":"1","asked2fa":"0","askedHostKey":"0","remoteInConfigFile":"1","gotUnrecognizedPrompt":"0","dynamicForwarding":"1","localServer":"0","didLocalDownload":"0","installUnpackCode":"0","outcome":"success"},"measures":{"resolveAttempts":1,"retries":1,"timing.totalResolveTime":5462,"timing.preSshTime":30,"timing.establishSshTime":5218,"timing.scriptTime":5417,"timing.serverStartTime":94}} [15:38:13.941] ------ [15:38:13.961] [Forwarding server 51434] Got connection 1 [15:38:14.158] [Forwarding server 51434] Got connection 2 [15:38:22.847] TELEMETRY: {"eventName":"extraInfo","properties":{"remoteCloud":""},"measures":{}} [15:40:01.447] [Forwarding server 51434] Got connection 3 [15:40:01.451] ------ [15:40:01.451] SSH Resolver called for "ssh-remote+nx3.neuro.berkeley.edu", attempt 2, (Reconnection) [15:40:01.452] SSH Resolver called for host: nx3.neuro.berkeley.edu [15:40:01.452] Setting up SSH remote "nx3.neuro.berkeley.edu" [15:40:01.455] Using commit id "ee2b180d582a7f601fa6ecfdad8d9fd269ab1884" and quality "stable" for server [15:40:01.460] Install and start server if needed [15:40:01.463] Failed to set up socket for dynamic port forward to remote port 45601: Socket closed. Is the remote port correct? [15:40:01.468] Running script with connection command: ssh -T -D 51457 -o ConnectTimeout=15 'nx3.neuro.berkeley.edu' bash [15:40:01.546] "install" terminal received data: "channel 3: open failed: connect failed: Connection refused " [15:40:01.786] "install" terminal received data: " Enter passphrase for key '/Users/dlurie/.ssh/id_rsa': " [15:40:01.787] Got some output, clearing connection timeout [15:40:01.787] Detected passphrase message [15:40:06.717] Got passphrase response [15:40:06.719] "install" wrote data to terminal: "**********" [15:40:06.765] "install" terminal received data: "" [15:40:07.111] "install" terminal received data: "cebf27f78e23: running" [15:40:07.132] "install" terminal received data: "Acquiring lock on /home/despo/dlurie/.vscode-server/bin/ee2b180d582a7f601fa6ecfdad8d9fd269ab1884/vscode-remote-lock.dlurie.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884" [15:40:07.142] "install" terminal received data: "Found existing installation at /home/despo/dlurie/.vscode-server/bin/ee2b180d582a7f601fa6ecfdad8d9fd269ab1884... Checking /home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.log and /home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.pid for a running server Looking for server with pid: 3014545" [15:40:07.208] "install" terminal received data: "Running ssh connection command... /home/despo/dlurie/.vscode-server/bin/ee2b180d582a7f601fa6ecfdad8d9fd269ab1884/bin/code-server --start-server --host=127.0.0.1 --accept-server-license-terms --enable-remote-auto-shutdown --port=0 --telemetry-level all &> "/home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.log" < /dev/null printenv: SSH_CONNECTION=135.180.118.238 51458 169.229.248.250 22 LANG=en_US.UTF-8 ITK_GLOBAL_DEFAULT_NUMBER_OF_THREADS=3 SGE_CELL=hwni which_declare=declare -f XDG_SESSION_ID=483147 USER=dlurie PWD=/home/despo/dlurie SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass HOME=/home/despo/dlurie SSH_CLIENT=135.180.118.238 51458 22 XDG_DATA_DIRS=/home/despo/dlurie/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share:/usr/share SGE_ROOT=/usr/local/sge-8.1.9 SHELL=/bin/bash SHLVL=2 MANPATH=/usr/local/sge-8.1.9/man:/usr/share/man:/usr/local/share/man VSCODE_AGENT_FOLDER=/home/despo/dlurie/.vscode-server LOGNAME=dlurie DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1186/bus XDG_RUNTIME_DIR=/run/user/1186 PATH=/home/despo/dlurie/anaconda3/bin:/home/despoB/dlurie/Software/globusconnectpersonal-2.3.4/:/home/despoB/dlurie/Software/libwebp-0.6.1-linux-x86-32/bin:/home/despoB/dlurie/Software/jre1.8.0_152/bin:/home/despoB/dlurie/Software/dcm2niix:/home/despoB/dlurie/Software/itksnap-3.8.0-beta-20181028-Linux-gcc64-qt4/bin:/home/despoB/dlurie/Software/DicomBrowser-1.5.2/bin:/home/despoB/dlurie/Software/cmake_3.5.0/bin:/home/despoB/dlurie/Software/c3d-1.0.0/bin:/home/despoB/dlurie/Software/ants-2.2.0/bin/:/usr/local/sge-8.1.9/bin:/usr/local/sge-8.1.9/bin/lx-amd64:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/home/despo/dlurie/.local/bin DEBUGINFOD_URLS=https://debuginfod.centos.org/ SGE_ARCH=lx-amd64 LESSOPEN=||/usr/bin/lesspipe.sh %s SGE_CLUSTER_NAME=p6444 BASH_FUNC_which%%=() { ( alias; eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ } _=/usr/bin/printenv" [15:40:07.237] "install" terminal received data: "Removing old logfile at /home/despo/dlurie/.vscode-server/.ee2b180d582a7f601fa6ecfdad8d9fd269ab1884.log Spawned remote server: 3019613 Waiting for server log..." [15:40:07.266] "install" terminal received data: "Waiting for server log..." [15:40:07.305] "install" terminal received data: " * * Visual Studio Code Server * * By using the software, you agree to * the Visual Studio Code Server License Terms (https://aka.ms/vscode-server-license) and * the Microsoft Privacy Statement (https://privacy.microsoft.com/en-US/privacystatement). * " [15:40:07.314] "install" terminal received data: "cebf27f78e23: start SSH_AUTH_SOCK==== DISPLAY==== webUiAccessToken==== listeningOn==36075== osReleaseId==rocky== arch==x86_64== tmpDir==/run/user/1186== platform==linux== unpackResult==== didLocalDownload==0== downloadTime==== installTime==== extInstallTime==== serverStartTime==91== connectionToken==1111111a-11a1-1aaa-a1a1-11a111aa1111== cebf27f78e23: end" [15:40:07.315] Received install output: SSH_AUTH_SOCK==== DISPLAY==== webUiAccessToken==== listeningOn==36075== osReleaseId==rocky== arch==x86_64== tmpDir==/run/user/1186== platform==linux== unpackResult==== didLocalDownload==0== downloadTime==== installTime==== extInstallTime==== serverStartTime==91== connectionToken==1111111a-11a1-1aaa-a1a1-11a111aa1111== [15:40:07.315] Remote server is listening on 36075 [15:40:07.315] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":36075},"osReleaseId":"rocky","arch":"x86_64","webUiAccessToken":"","sshAuthSock":"","display":"","tmpDir":"/run/user/1186","platform":"linux","connectionToken":"1111111a-11a1-1aaa-a1a1-11a111aa1111"},"serverStartTime":91,"installUnpackCode":""} [15:40:07.317] Starting forwarding server. localPort 51460 -> socksPort 51457 -> remotePort 36075 [15:40:07.317] Forwarding server listening on 51460 [15:40:07.317] Waiting for ssh tunnel to be ready [15:40:07.318] Tunneled 36075 to local port 51460 [15:40:07.319] Resolved "ssh-remote+nx3.neuro.berkeley.edu" to "127.0.0.1:51460" [15:40:07.319] Updating terminal environments: {} [15:40:07.320] [Forwarding server 51460] Got connection 0 [15:40:07.322] TELEMETRY: {"eventName":"resolver","properties":{"osReleaseId":"rocky","arch":"x86_64","askedPw":"0","askedPassphrase":"1","asked2fa":"0","askedHostKey":"0","remoteInConfigFile":"1","gotUnrecognizedPrompt":"0","dynamicForwarding":"1","localServer":"0","didLocalDownload":"0","installUnpackCode":"0","outcome":"success"},"measures":{"resolveAttempts":2,"retries":1,"timing.totalResolveTime":5870,"timing.preSshTime":18,"timing.establishSshTime":5642,"timing.scriptTime":5846,"timing.serverStartTime":91}} [15:40:07.323] ------ [15:40:07.345] [Forwarding server 51460] Got connection 1 ```

Anything else?

This issue occurs even if I continuously engage with the remote host by browsing remote directories, typing into remote files, etc. That is to say, it does not appear that the connection gets dropped because it is idle. Similarly, connections to the same remote host established via SSH in the terminal can remain active at idle for hours without issue (even when the connection drops in vscode).

If I inspect the "Window" log from vscode, it looks like the issue starts with "received socket close event" at 15:40:01

Window Log

``` 2023-03-20 15:33:18.040 [info] [perf] Render performance baseline is 35ms 2023-03-20 15:38:08.473 [info] Invoking resolveAuthority(ssh-remote)... 2023-03-20 15:38:08.473 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][0ms] obtaining proxy... 2023-03-20 15:38:08.474 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][0ms] invoking... 2023-03-20 15:38:09.474 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][1001ms] waiting... 2023-03-20 15:38:10.520 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][2003ms] waiting... 2023-03-20 15:38:11.474 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][3001ms] waiting... 2023-03-20 15:38:12.487 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][4013ms] waiting... 2023-03-20 15:38:13.476 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][5003ms] waiting... 2023-03-20 15:38:13.942 [error] [Extension Host] (node:6853) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. (Use `Code Helper (Plugin) --trace-deprecation ...` to show where the warning was created) 2023-03-20 15:38:13.958 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][5484ms] returned 127.0.0.1:51434 2023-03-20 15:38:13.958 [info] resolveAuthority(ssh-remote) returned '127.0.0.1:51434' after 5484 ms 2023-03-20 15:38:13.959 [info] Creating a socket (renderer-Management-84f7f845-a40a-45de-b55a-de9ceffd087e)... 2023-03-20 15:38:13.960 [info] Creating a socket (renderer-ExtensionHost-af076d52-6658-4bd4-9cc4-8cd9809d1bb7)... 2023-03-20 15:38:14.149 [info] Creating a socket (renderer-Management-84f7f845-a40a-45de-b55a-de9ceffd087e) was successful after 189 ms. 2023-03-20 15:38:14.245 [info] Creating a socket (renderer-ExtensionHost-af076d52-6658-4bd4-9cc4-8cd9809d1bb7) was successful after 284 ms. 2023-03-20 15:38:14.935 [warning] No search provider registered for scheme: vscode-remote, waiting 2023-03-20 15:38:15.722 [info] [perf] Render performance baseline is 38ms 2023-03-20 15:40:01.443 [info] [remote-connection][ExtensionHost][af076…][reconnect] received socket close event (wasClean: false, code: 1006, reason: ). 2023-03-20 15:40:01.443 [error] {"isTrusted":true} 2023-03-20 15:40:01.444 [info] [remote-connection][ExtensionHost][af076…][reconnect] starting reconnecting loop. You can get more information with the trace log level. 2023-03-20 15:40:01.444 [info] [remote-connection][ExtensionHost][af076…][reconnect] resolving connection... 2023-03-20 15:40:01.444 [info] [remote-connection][ExtensionHost][af076…][reconnect] connecting to 127.0.0.1:51434... 2023-03-20 15:40:01.445 [info] Creating a socket (renderer-ExtensionHost-af076d52-6658-4bd4-9cc4-8cd9809d1bb7)... 2023-03-20 15:40:01.446 [info] [remote-connection][Management ][84f7f…][reconnect] received socket close event (wasClean: false, code: 1006, reason: ). 2023-03-20 15:40:01.446 [error] {"isTrusted":true} 2023-03-20 15:40:01.447 [info] [remote-connection][Management ][84f7f…][reconnect] starting reconnecting loop. You can get more information with the trace log level. 2023-03-20 15:40:01.448 [info] [remote-connection][Management ][84f7f…][reconnect] resolving connection... 2023-03-20 15:40:01.449 [info] Invoking resolveAuthority(ssh-remote)... 2023-03-20 15:40:01.449 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][0ms] obtaining proxy... 2023-03-20 15:40:01.450 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][1ms] invoking... 2023-03-20 15:40:02.453 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][1003ms] waiting... 2023-03-20 15:40:03.452 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][2003ms] waiting... 2023-03-20 15:40:04.453 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][3003ms] waiting... 2023-03-20 15:40:05.453 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][4003ms] waiting... 2023-03-20 15:40:06.451 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][5002ms] waiting... 2023-03-20 15:40:07.342 [info] [LocalProcess0][resolveAuthority(ssh-remote,2)][5893ms] returned 127.0.0.1:51460 2023-03-20 15:40:07.343 [info] resolveAuthority(ssh-remote) returned '127.0.0.1:51460' after 5893 ms 2023-03-20 15:40:07.343 [info] [remote-connection][Management ][84f7f…][reconnect] connecting to 127.0.0.1:51460... 2023-03-20 15:40:07.344 [info] Creating a socket (renderer-Management-84f7f845-a40a-45de-b55a-de9ceffd087e)... 2023-03-20 15:40:07.533 [info] Creating a socket (renderer-Management-84f7f845-a40a-45de-b55a-de9ceffd087e) was successful after 189 ms. 2023-03-20 15:40:07.696 [info] [remote-connection][Management ][84f7f…][reconnect] received socket close event (wasClean: false, code: 1006, reason: ). 2023-03-20 15:40:07.696 [error] {"isTrusted":true} 2023-03-20 15:40:07.697 [error] [remote-connection][Management ][84f7f…][reconnect][127.0.0.1:51460] received error control message when negotiating connection. Error: 2023-03-20 15:40:07.698 [error] Error: Connection error: Unknown reconnection token (never seen) at $ (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:58150) at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:48775 at g.invoke (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:145) at n.deliver (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:2066) at h.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:1704) at a.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:15221) at E (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:19321) at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:18466 at g.invoke (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:145) at n.deliver (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:2066) at h.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:1704) at f.acceptChunk (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:12952) at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:12239 at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:38972 at g.invoke (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:145) at n.deliver (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:2066) at h.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:1704) at i.onload (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:37239) 2023-03-20 15:40:07.698 [error] [remote-connection][Management ][84f7f…][reconnect] A permanent error occurred in the reconnecting loop! Will give up now! Error: 2023-03-20 15:40:07.699 [error] Error: Connection error: Unknown reconnection token (never seen) at $ (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:58150) at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:48775 at g.invoke (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:145) at n.deliver (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:2066) at h.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:1704) at a.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:15221) at E (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:19321) at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:18466 at g.invoke (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:145) at n.deliver (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:2066) at h.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:1704) at f.acceptChunk (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:12952) at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:553:12239 at vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:38972 at g.invoke (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:145) at n.deliver (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:2066) at h.fire (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:86:1704) at i.onload (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:642:37239) 2023-03-20 15:40:07.996 [error] Error: Unable to read file 'vscode-remote://ssh-remote+nx3.neuro.berkeley.edu/home/despo/dlurie/Projects/timescale_hierarchy/.vscode/settings.json' (Canceled: Canceled) at o.w (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:17298) at o.v (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16960) at async o.u (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16242) at async vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7303 at async Promise.all (index 0) at async Promise.all (index 0) at async u.resolveContents (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7548) at async S.n (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:19157) 2023-03-20 15:40:07.996 [error] Error: Unable to read file 'vscode-remote://ssh-remote+nx3.neuro.berkeley.edu/home/despo/dlurie/Projects/timescale_hierarchy/.vscode/tasks.json' (Canceled: Canceled) at o.w (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:17298) at o.v (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16960) at async o.u (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16242) at async vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7303 at async Promise.all (index 0) at async Promise.all (index 1) at async u.resolveContents (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7548) at async S.n (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:19157) 2023-03-20 15:40:07.997 [error] Error: Unable to read file 'vscode-remote://ssh-remote+nx3.neuro.berkeley.edu/home/despo/dlurie/Projects/timescale_hierarchy/.vscode/launch.json' (Canceled: Canceled) at o.w (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:17298) at o.v (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16960) at async o.u (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16242) at async vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7303 at async Promise.all (index 1) at async Promise.all (index 1) at async u.resolveContents (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7548) at async S.n (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:19157) 2023-03-20 15:40:07.997 [error] Error: Unable to read file 'vscode-remote://ssh-remote+nx3.neuro.berkeley.edu/home/despo/dlurie/Projects/timescale_hierarchy/.vscode/settings.json' (Canceled: Canceled) at o.w (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:17298) at o.v (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16960) at async o.u (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16242) at async vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7303 at async Promise.all (index 0) at async Promise.all (index 0) at async u.resolveContents (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7548) at async S.n (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:19157) 2023-03-20 15:40:07.998 [error] Error: Unable to read file 'vscode-remote://ssh-remote+nx3.neuro.berkeley.edu/home/despo/dlurie/Projects/timescale_hierarchy/.vscode/tasks.json' (Canceled: Canceled) at o.w (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:17298) at o.v (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16960) at async o.u (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16242) at async vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7303 at async Promise.all (index 0) at async Promise.all (index 1) at async u.resolveContents (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7548) at async S.n (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:19157) 2023-03-20 15:40:07.998 [error] Error: Unable to read file 'vscode-remote://ssh-remote+nx3.neuro.berkeley.edu/home/despo/dlurie/Projects/timescale_hierarchy/.vscode/launch.json' (Canceled: Canceled) at o.w (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:17298) at o.v (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16960) at async o.u (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:615:16242) at async vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7303 at async Promise.all (index 1) at async Promise.all (index 1) at async u.resolveContents (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:7548) at async S.n (vscode-file://vscode-app/Applications/Visual%20Studio%20Code.app/Contents/Resources/app/out/vs/workbench/workbench.desktop.main.js:1192:19157) ```

If I then go look for that close event in the Dev Tools Console, it shows:

15:40:01.442 log.ts:392  INFO [remote-connection][ExtensionHost][af076…][reconnect] received socket close event (wasClean: false, code: 1006, reason: ).
15:40:01.443 log.ts:404   ERR CloseEvent {isTrusted: true, wasClean: false, code: 1006, reason: '', type: 'close', …}isTrusted: truebubbles: falsecancelBubble: falsecancelable: falsecode: 1006composed: falsecurrentTarget: WebSocket {url: 'ws://127.0.0.1:51434/stable-ee2b180d582a7f601fa6ec…1bb7&reconnection=false&skipWebSocketFrames=false', readyState: 3, bufferedAmount: 0, onopen: null, onerror: null, …}defaultPrevented: falseeventPhase: 0path: []reason: ""returnValue: truesrcElement: WebSocket {url: 'ws://127.0.0.1:51434/stable-ee2b180d582a7f601fa6ec…1bb7&reconnection=false&skipWebSocketFrames=false', readyState: 3, bufferedAmount: 0, onopen: null, onerror: null, …}target: WebSocket {url: 'ws://127.0.0.1:51434/stable-ee2b180d582a7f601fa6ec…1bb7&reconnection=false&skipWebSocketFrames=false', readyState: 3, bufferedAmount: 0, onopen: null, onerror: null, …}timeStamp: 114140.80000000447type: "close"wasClean: false[[Prototype]]: CloseEvent
15:40:01.443 log.ts:392  INFO [remote-connection][ExtensionHost][af076…][reconnect] starting reconnecting loop. You can get more information with the trace log level.

(Setting log level to trace doesn't actually provide any additional information.)

In addition to the recommended troubleshooting steps, I have also tried manually deleting the .vscode-server directory on the remote host. I do not have access to a different remote machine, so I can't test if the issue is specific to this host.

eleanorjboyd commented 1 year ago

Hello! It seems your remote extension host crashed. What extensions do you have enabled on your remote?

danlurie commented 1 year ago

I have no extensions installed on the remote host (nothing is listed for that host in the extensions tab, and there is nothing in ~/.vscode-server/extensions on the remote other than an empty extensions.json file).

The only extensions I have installed and enabled on my local are those included in the Microsoft Remote Development Extension Pack (WSL, Dev Containers, Remote-SSH, and Remote-Tunnels).

In case it is useful, here is the Remote Extension Host log from a recent session.

2023-03-26 16:10:54.971 [info] Extension host with pid 2885227 started
2023-03-26 16:10:54.976 [error] Error: EEXIST: file already exists, open '/home/despo/dlurie/.vscode-server/data/User/workspaceStorage/71789f6b438f421c761a8da7fd0dd4b6/vscode.lock'
2023-03-26 16:10:54.983 [info] Lock '/home/despo/dlurie/.vscode-server/data/User/workspaceStorage/71789f6b438f421c761a8da7fd0dd4b6/vscode.lock': Could not acquire lock, checking if the file is stale.
2023-03-26 16:10:54.994 [info] Lock '/home/despo/dlurie/.vscode-server/data/User/workspaceStorage/71789f6b438f421c761a8da7fd0dd4b6/vscode.lock': The pid 2879936 appears to be gone.
2023-03-26 16:10:54.994 [info] Lock '/home/despo/dlurie/.vscode-server/data/User/workspaceStorage/71789f6b438f421c761a8da7fd0dd4b6/vscode.lock': Deleting a stale lock.
2023-03-26 16:10:54.999 [info] Lock '/home/despo/dlurie/.vscode-server/data/User/workspaceStorage/71789f6b438f421c761a8da7fd0dd4b6/vscode.lock': Lock acquired.
2023-03-26 16:10:55.053 [info] ExtensionService#_doActivateExtension vscode.emmet, startup: false, activationEvent: 'onLanguage'
2023-03-26 16:10:55.055 [info] ExtensionService#_doActivateExtension vscode.git-base, startup: true, activationEvent: '*', root cause: vscode.git
2023-03-26 16:10:55.259 [info] ExtensionService#_doActivateExtension vscode.git, startup: true, activationEvent: '*'
2023-03-26 16:10:55.259 [info] ExtensionService#_doActivateExtension vscode.github, startup: true, activationEvent: '*'
2023-03-26 16:10:55.425 [info] Eager extensions activated
2023-03-26 16:10:55.425 [info] ExtensionService#_doActivateExtension vscode.debug-auto-launch, startup: false, activationEvent: 'onStartupFinished'
2023-03-26 16:10:55.426 [info] ExtensionService#_doActivateExtension vscode.merge-conflict, startup: false, activationEvent: 'onStartupFinished'

danlurie commented 1 year ago

Still experiencing this on 1.78.2; any suggestions or updates?

danlurie commented 1 year ago

Managed to fix this by completely uninstalling vscode (including hidden directories) from my local, then re-installing. Had previously tried deleting vscode directories on the remote with no success. Closing this issue as it's not clear how it could be further diagnosed at this point.

microsoft / vscode-remote-release