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.55k stars 263 forks source link

Installing VSCode Server via Remote-SSH pauses for many minutes #9917

Open LiveFreeAndRoam opened 1 month ago

LiveFreeAndRoam commented 1 month ago

When I open a Remote-SSH connection to a new Linux server, there is a ~5minute pause before the download begins.

How can I get more information on what the server is waiting for?

From the Remote-SSH log, it shows a ~5min delay between "Installing" and "Downloading" messages (see annoated log below). What's it doing during that time?

Watching the processes, I see the initial wget completes very quickly:

wget --tries=1 --connect-timeout=7 --dns-timeout=7 -nv -O vscode-cli-dc96b837cf6bb4af9cd736aa3af08cf8279f7685.tar.gz https://update.code.visualstudio.com/commit:dc96b837cf6bb4af9cd736aa3af08cf8279f7685/cli-alpine-arm64/stable

Soon after that process completes, another process is created and this is where the delay happens:

/data/.vscode-server/code-dc96b837cf6bb4af9cd736aa3af08cf8279f7685 command-shell --cli-data-dir /data/.vscode-server/cli --parent-process-id 233426 --on-port

An extract from the log file contents shows:

[11:51:52.609] [server] Checking /store/.vscode-server/cli/servers/Stable-dc96b837cf6bb4af9cd736aa3af08cf8279f7685/log.txt and /store/.vscode-server/cli/servers/Stable-dc96b837cf6bb4af9cd736aa3af08cf8279f7685/pid.txt for a running server...

### Install starts
[11:51:53.211] [server] Installing and setting up Visual Studio Code Server...

### Nothing happens for almost 5 minutes, then it continues
[11:56:16.674] [server] Downloading Visual Studio Code server -> /tmp/.tmpwJyFmY/stable
[11:56:16.676] [server] server download progress: 0/56657077 (0%)
[11:56:20.589] [server] server download progress: 2099544/56657077 (4%)

In case it helps, here is the full log, up to the point where the server begins downloading.

[11:51:42.739] Log Level: 2
[11:51:42.748] SSH Resolver called for "ssh-remote+58", attempt 1
[11:51:42.752] "remote.SSH.useLocalServer": false
[11:51:42.752] "remote.SSH.useExecServer": true
[11:51:42.752] "remote.SSH.showLoginTerminal": false
[11:51:42.753] "remote.SSH.remotePlatform": {"myhost":"linux"}
[11:51:42.753] "remote.SSH.path": undefined
[11:51:42.753] "remote.SSH.configFile": undefined
[11:51:42.753] "remote.SSH.useFlock": true
[11:51:42.753] "remote.SSH.lockfilesInTmp": false
[11:51:42.754] "remote.SSH.localServerDownload": auto
[11:51:42.754] "remote.SSH.remoteServerListenOnSocket": false
[11:51:42.754] "remote.SSH.showLoginTerminal": false
[11:51:42.754] "remote.SSH.defaultExtensions": []
[11:51:42.754] "remote.SSH.loglevel": 2
[11:51:42.754] "remote.SSH.enableDynamicForwarding": true
[11:51:42.754] "remote.SSH.enableRemoteCommand": false
[11:51:42.754] "remote.SSH.serverPickPortsFromRange": {}
[11:51:42.756] "remote.SSH.serverInstallPath": {"myhost":"/data"}
[11:51:42.759] VS Code version: 1.89.1
[11:51:42.759] Remote-SSH version: remote-ssh@0.110.1
[11:51:42.759] win32 x64
[11:51:42.777] SSH Resolver called for host: myhost
[11:51:42.777] Setting up SSH remote "myhost"
[11:51:42.781] Using commit id "dc96b837cf6bb4af9cd736aa3af08cf8279f7685" and quality "stable" for server
[11:51:42.785] Install and start server if needed
[11:51:42.796] Checking ssh with "C:\windows\system32\ssh.exe -V"
[11:51:42.799] Got error from ssh: spawn C:\windows\system32\ssh.exe ENOENT
[11:51:42.800] Checking ssh with "C:\windows\ssh.exe -V"
[11:51:42.801] Got error from ssh: spawn C:\windows\ssh.exe ENOENT
[11:51:42.801] Checking ssh with "C:\windows\System32\Wbem\ssh.exe -V"
[11:51:42.802] Got error from ssh: spawn C:\windows\System32\Wbem\ssh.exe ENOENT
[11:51:42.802] Checking ssh with "C:\windows\System32\WindowsPowerShell\v1.0\ssh.exe -V"
[11:51:42.803] Got error from ssh: spawn C:\windows\System32\WindowsPowerShell\v1.0\ssh.exe ENOENT
[11:51:42.803] Checking ssh with "C:\windows\System32\OpenSSH\ssh.exe -V"
[11:51:43.239] > OpenSSH_for_Windows_8.1p1, 
[11:51:43.239] > LibreSSL 3.0.2

[11:51:43.250] Running script with connection command: "C:\windows\System32\OpenSSH\ssh.exe" -T -D 55744 myhost bash
[11:51:43.253] Terminal shell path: C:\windows\System32\cmd.exe
[11:51:43.815] > ]0;C:\windows\System32\cmd.exe
[11:51:43.816] Got some output, clearing connection timeout
[11:51:44.048] > load pubkey "C:\\Users\\myusername/.ssh/id_ed25519": invalid format
[11:51:44.932] > Warning: Permanently added 'myhost.mydomain.net' (ECDSA) to the l
> ist of known hosts.
[11:51:45.745] > ##----------------------------------------------------------------------------
> # WARNING: This is a private system.  Do not attempt to login unless you are 
> # an authorized user.  Any access and use may be monitored and can result in 
> # criminal or civil prosecution under applicable law.
> #----------------------------------------------------------------------------
> #
> #
[11:51:47.252] > a654ebc89e1e: running
[11:51:47.385] > Installing to /data/.vscode-server...
[11:51:47.415] > a654ebc89e1e%%1%%
[11:51:47.432] > Downloading with wget
[11:51:49.836] > Download complete
[11:51:49.868] > a654ebc89e1e%%2%%
> tar --version:   
[11:51:49.905] > tar (GNU tar) 1.34
> Copyright (C) 2021 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.
[11:51:50.870] > code 1.89.1 (commit dc96b837cf6bb4af9cd736aa3af08cf8279f7685)
[11:51:50.906] > Starting VS Code CLI... "/data/.vscode-server/code-dc96b837cf6bb4af9cd736aa3af0
> 8cf8279f7685" command-shell --cli-data-dir "/data/.vscode-server/cli" --on-port
>  --parent-process-id 342488 &> "/data/.vscode-server/.cli.dc96b837cf6bb4af9cd73
> 6aa3af08cf8279f7685.log" < /dev/null
> printenv:
[11:51:50.915] > 
>     SHELL=/bin/sh
>     PWD=/home/root
>     LOGNAME=root
>     HOME=/home/root
>     VSCODE_AGENT_FOLDER=/data/.vscode-server
>     SSH_CONNECTION=10.207.137.211 55745 10.229.130.226 22
>     USER=root
>     SHLVL=0
>     SSH_CLIENT=10.207.137.211 55745 22
[11:51:50.923] > 
>     PATH=/usr/bin:/bin:/usr/sbin:/sbin
>     OLDPWD=/data/.vscode-server
>     _=/usr/bin/printenv
[11:51:50.949] > 
> Spawned remote CLI: 342552
[11:51:50.970] > 
[11:51:51.078] > Waiting for server log...
[11:51:51.255] > Waiting for server log...
[11:51:51.422] > Waiting for server log...
[11:51:51.503] > a654ebc89e1e: start
> SSH_AUTH_SOCK====
> DISPLAY====
> listeningOn==127.0.0.1:41839==
> osReleaseId==custom-linux==
> arch==aarch64==
> vscodeArch==arm64==
> bitness==64==
> tmpDir==/tmp==
> platform==linux==
> unpackResult==success==
[11:51:51.517] > 
> didLocalDownload==0==
> downloadTime==2458==
> installTime==956==
> serverStartTime==579==
[11:51:51.543] > 
> execServerToken==a1a11a11-1a1a-111a-a1a1-11111111a11a==
> a654ebc89e1e: end
[11:51:51.544] Received install output: 
SSH_AUTH_SOCK====
DISPLAY====
listeningOn==127.0.0.1:41839==
osReleaseId==custom-linux==
arch==aarch64==
vscodeArch==arm64==
bitness==64==
tmpDir==/tmp==
platform==linux==
unpackResult==success==
didLocalDownload==0==
downloadTime==2458==
installTime==956==
serverStartTime==579==
execServerToken==a1a11a11-1a1a-111a-a1a1-11111111a11a==

[11:51:51.545] Remote server is listening on port 41839
[11:51:51.546] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":41839},"osReleaseId":"custom-linux","arch":"aarch64","sshAuthSock":"","display":"","tmpDir":"/tmp","platform":"linux","execServerToken":"a1a11a11-1a1a-111a-a1a1-11111111a11a"},"downloadTime":2458,"installTime":956,"serverStartTime":579,"installUnpackCode":"success"}
[11:51:51.546] ** Note: Support for architecture "aarch64" is in preview **
[11:51:51.569] Starting forwarding server. local port 55751 -> socksPort 55744 -> remotePort 41839
[11:51:51.570] Forwarding server listening on port 55751
[11:51:51.570] Waiting for ssh tunnel to be ready
[11:51:51.572] [Forwarding server port 55751] Got connection 0
[11:51:51.573] Tunneled port 41839 to local port 55751
[11:51:51.574] Resolved "ssh-remote+myhost" to "port 55751"
[11:51:51.576] Initizing new exec server for ssh-remote+myhost
[11:51:51.576] Resolving exec server at port 55751
[11:51:51.599] [Forwarding server port 55751] Got connection 1
[11:51:52.356] Exec server for ssh-remote+myhost created and cached
[11:51:52.360] ------

[11:51:52.609] [server] Checking /data/.vscode-server/cli/servers/Stable-dc96b837cf6bb4af9cd736aa3af08cf8279f7685/log.txt and /data/.vscode-server/cli/servers/Stable-dc96b837cf6bb4af9cd736aa3af08cf8279f7685/pid.txt for a running server...
[11:51:53.211] [server] Installing and setting up Visual Studio Code Server...
[11:56:16.674] [server] Downloading Visual Studio Code server -> /tmp/.tmpwJyFmY/stable
[11:56:16.676] [server] server download progress: 0/56657077 (0%)
[11:56:20.589] [server] server download progress: 2099544/56657077 (4%)
connor4312 commented 1 month ago

It seems like your connection to our update service is very slow, or the service experienced some slowness. The time between the two log messages is the time to query the service for the relevant release information.

LiveFreeAndRoam commented 1 month ago

What is the URL of the update server? I'd like to test my access to it.

It would help if the URL and download method were shown in the log file. Then, I'd have a chance of troubleshooting myself.

Also, note that it successfully downloaded some initial code with wget. It's only the 2nd download that's affected.

connor4312 commented 1 month ago

https://update.code.visualstudio.com/api/update/win32-x64-archive/insider/latest is one URL that it'll hit, followed by an access of the URL in that response, e.g. https://vscode.download.prss.microsoft.com/dbazure/download/insider/bc15ede705b9168324a3440b7c80c80644743306/VSCode-win32-x64-1.90.0-insider.zip