microsoft / microsoft/vscode-remote-release

[Remote-SSH Bug]: AFS - 2nd connection always fails - Failed to parse remote port from server output

Open
#10,445 15 comments 2 reactions 1 assignee View on GitHub

Nobody has claimed this yet.

bug ssh
Dominant language
Dockerfile
Stars
4.2k
Forks
469
Avg merge
1d 1h
Merged PRs (30d)
1

Description

Is there an existing issue for this bug?
  • I have searched the existing issues
Required Troubleshooting Steps
  • I have followed these troubleshooting steps
  • I have tried both values of the remote.SSH.useLocalServer setting (more info here)
Connect Locally

It connects successfully

->

Connecting vscode to our servers works reliably.

However after exiting vscode and confirming the remote vscode has stopped on re-connection.

[21:13:44.822] Failed to parse remote port from server output
[21:13:44.823] Terminating local server
[21:13:44.827] Resolver error: Error:

The second connection remote end starts up okay

202598 /afs/example.ch/user/me/.vscode-server/code-65edc4939843c90c34d61f4ce11704f09d3e5cb6 command-shell --cli-data-dir /afs/example.ch/user/me/.vscode-server/cli --parent-process-id 202580 --on-host=127.0.0.1 --on-port

$ cat .cli.65edc4939843c90c34d61f4ce11704f09d3e5cb6.log 
Listening on 127.0.0.1:44915

is the correct port and the server is listening on that.

The situation can be fixed with a "rm -rf ~/.vscode-server" on the server side and again you can connect once but never a second time.

Only setting I have is keep lockfiles in /tmp though similar behaviour is seen with out that setting.

Expected Behavior

The on disk remote server should be started and connected to.

Steps To Reproduce
  1. SSH remote connect to our SSH service.
  2. Exit
  3. SSH remote connect to our SSH service

It fails as above.

Remote-SSH Log
Remote-SSH Log 

[21:13:40.431] Log Level: 2
[21:13:40.444] SSH Resolver called for "ssh-remote+host.example.ch", attempt 1
[21:13:40.444] "remote.SSH.useLocalServer": true
[21:13:40.444] "remote.SSH.useExecServer": true
[21:13:40.444] "remote.SSH.path": undefined
[21:13:40.444] "remote.SSH.configFile": undefined
[21:13:40.445] "remote.SSH.useFlock": true
[21:13:40.445] "remote.SSH.lockfilesInTmp": true
[21:13:40.445] "remote.SSH.localServerDownload": auto
[21:13:40.445] "remote.SSH.remoteServerListenOnSocket": false
[21:13:40.445] "remote.SSH.showLoginTerminal": false
[21:13:40.445] "remote.SSH.defaultExtensions": []
[21:13:40.445] "remote.SSH.loglevel": 2
[21:13:40.445] "remote.SSH.enableDynamicForwarding": true
[21:13:40.445] "remote.SSH.enableRemoteCommand": false
[21:13:40.445] "remote.SSH.serverPickPortsFromRange": {}
[21:13:40.445] "remote.SSH.serverInstallPath": {}
[21:13:40.445] "remote.SSH.permitPtyAllocation": false
[21:13:40.445] "remote.SSH.preferredLocalPortRange: undefined
[21:13:40.445] "remote.SSH.useCurlAndWgetConfigurationFiles: false
[21:13:40.450] VS Code version: 1.95.1
[21:13:40.450] Remote-SSH version: remote-ssh@0.115.0
[21:13:40.450] linux x64
[21:13:40.458] SSH Resolver called for host: host.example.ch
[21:13:40.458] Setting up SSH remote "host.example.ch"
[21:13:40.461] Acquiring local install lock: /tmp/vscode-remote-ssh-47bf8c66-install.lock
[21:13:40.462] Looking for existing server data file at /home/me/.config/Code/User/globalStorage/ms-vscode-remote.remote-ssh/vscode-ssh-host-47bf8c66-65edc4939843c90c34d61f4ce11704f09d3e5cb6-0.115.0-es/data.json
[21:13:40.462] No existing data file
[21:13:40.462] Using commit id "65edc4939843c90c34d61f4ce11704f09d3e5cb6" and quality "stable" for server
[21:13:40.464] Script variables:
 {
  "InstallExitCode.24": "AlreadyInProgress",
  "InstallExitCode.25": "ServerDownloadFailed",
  "InstallExitCode.26": "NoDownloaderAvailable",
  "InstallExitCode.27": "UnsupportedArch",
  "InstallExitCode.28": "StatusCheckFailed",
  "InstallExitCode.29": "NeedInsidersArch",
  "InstallExitCode.30": "NoDownloaderAvailableForStatusCheck",
  "InstallExitCode.31": "ServerTransferFailed",
  "InstallExitCode.32": "ServerFailedToStart",
  "InstallExitCode.33": "NeedInsidersWindows",
  "InstallExitCode.34": "CreateInstallDirFailed",
  "InstallExitCode.35": "UnsupportedPlatform",
  "InstallExitCode.36": "ServerTerminatedCVE20201416",
  "InstallExitCode.37": "UnpackFailed",
  "InstallExitCode.38": "ChangeDirFailed",
  "InstallExitCode.AlreadyInProgress": "24",
  "InstallExitCode.ServerDownloadFailed": "25",
  "InstallExitCode.NoDownloaderAvailable": "26",
  "InstallExitCode.NoDownloaderAvailableForStatusCheck": "30",
  "InstallExitCode.UnsupportedArch": "27",
  "InstallExitCode.StatusCheckFailed": "28",
  "InstallExitCode.NeedInsidersArch": "29",
  "InstallExitCode.ServerTransferFailed": "31",
  "InstallExitCode.ServerFailedToStart": "32",
  "InstallExitCode.NeedInsidersWindows": "33",
  "InstallExitCode.CreateInstallDirFailed": "34",
  "InstallExitCode.UnsupportedPlatform": "35",
  "InstallExitCode.ServerTerminatedCVE20201416": "36",
  "InstallExitCode.UnpackFailed": "37",
  "InstallExitCode.ChangeDirFailed": "38",
  "InstallUnpackCode.Success": "success",
  "InstallUnpackCode.Error": "error",
  "InstallUnpackCode.MissingFiles": "missingFiles",
  "uuid": "0b7124c7dc85",
  "startMarker": "0b7124c7dc85: running",
  "commitId": "65edc4939843c90c34d61f4ce11704f09d3e5cb6",
  "quality": "stable",
  "token": "11aaa11a-aa1a-1111-aa11-1111111a11a1",
  "vscodeAgentFolder": "$HOME/.vscode-server",
  "allowClientDownload": "1",
  "forceClientDownload": "0",
  "cliNameInArchive": "code",
  "ignoreWgetConfigFlag": " --no-config ",
  "ignoreCurlConfigFlag": " --disable ",
  "wgetTriesSegment": "--tries=1",
  "listenArgs": "--on-host=127.0.0.1 --on-port",
  "getDownloadServerStartTrigger": "0b7124c7dc85:trigger_server_download",
  "getDownloadServerEndTrigger": "0b7124c7dc85:trigger_server_download_end",
  "getProgressDownloading": "0b7124c7dc85%%1%%",
  "getProgressInstalling": "0b7124c7dc85%%2%%"
}
[21:13:40.465] Install and start server if needed
[21:13:40.468] PATH: /home/me/.rbenv/shims:/home/steve/bin:/home/steve/.fzf/bin:/home/steve/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/local/games:/usr/games
[21:13:40.469] Checking ssh with "ssh -V"
[21:13:40.474] > OpenSSH_9.2p1 Debian-2+deb12u3, OpenSSL 3.0.14 4 Jun 2024

[21:13:40.481] askpass server listening on /run/user/1000/vscode-ssh-askpass-0c17c20945af07060453eedad762d15ebf76f1f2.sock
[21:13:40.481] Spawning local server with {"serverId":1,"ipcHandlePath":"/run/user/1000/vscode-ssh-askpass-d9c1a4d60babaded85d184ca76cfbc38c257e41f.sock","sshCommand":"ssh","sshArgs":["-v","-T","-D","34569","-o","ConnectTimeout=15","host.example.ch"],"serverDataFolderName":".vscode-server","dataFilePath":"/home/me/.config/Code/User/globalStorage/ms-vscode-remote.remote-ssh/vscode-ssh-host-47bf8c66-65edc4939843c90c34d61f4ce11704f09d3e5cb6-0.115.0-es/data.json"}
[21:13:40.481] Local server env: {"SSH_AUTH_SOCK":"/run/user/1000/ssh-agent.socket","SHELL":"/usr/bin/fish","DISPLAY":":0","ELECTRON_RUN_AS_NODE":"1","SSH_ASKPASS":"/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/local-server/askpass.sh","VSCODE_SSH_ASKPASS_NODE":"/usr/share/code/code","VSCODE_SSH_ASKPASS_EXTRA_ARGS":"","VSCODE_SSH_ASKPASS_MAIN":"/home/steve/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/askpass-main.js","VSCODE_SSH_ASKPASS_HANDLE":"/run/user/1000/vscode-ssh-askpass-0c17c20945af07060453eedad762d15ebf76f1f2.sock"}
[21:13:40.484] Spawned 12401
[21:13:40.485] Using connect timeout of 17 seconds
[21:13:40.544] > local-server-1> Running ssh connection command: ssh -v -T -D 34569 -o ConnectTimeout=15 host.example.ch
[21:13:40.547] > local-server-1> Spawned ssh, pid=12409
[21:13:40.549] stderr> OpenSSH_9.2p1 Debian-2+deb12u3, OpenSSL 3.0.14 4 Jun 2024
[21:13:40.609] stderr> debug1: Server host key: ecdsa-sha2-nistp256 SHA256:q+xzK9deJ9K3kVSpV0a/w6vUnLErqGEYAUB1OkxR+uk
[21:13:41.107] stderr> Authenticated to host.example.ch ([2001:1458:d00:61::100:c6]:22) using "gssapi-with-mic".
[21:13:42.682] > /usr/bin/eosfusebind failed: exit code 8
> * ********************************************************************
> * Welcome to host9121.example.ch, Red Hat Enterprise Linux release 9.4 (Plow)
> * October 10th: host will switch to requiring 2fa during 2025
> *  Test your access from now https://example.ch/otg0152605
[21:13:44.127] > ready: 0b7124c7dc85
[21:13:44.136] > Linux 5.14.0-427.40.1.el9_4.x86_64 #1 SMP PREEMPT_DYNAMIC Fri Oct 4 15:22:45 EDT 2024
[21:13:44.136] Platform: linux
[21:13:44.143] > /bin/bash
[21:13:44.144] Parent Shell: bash
[21:13:44.144] Parent Shell pid: 12401
[21:13:44.153] > 202580
[21:13:44.154] Waiting for pid of spawned 'sh' subshell: '202580'...
[21:13:44.170] > 0b7124c7dc85: running
> Script executing under PID: 202580
[21:13:44.182] > Found existing installation at /afs/example.ch/user/s/me/.vscode-server...
> Starting VS Code CLI...
> printenv:
[21:13:44.184] >     SHELL=/bin/bash
>     LCG_GFAL_INFOSYS=lcg-bdii.example.ch:2170
>     HISTCONTROL=ignoredups
>     rvm_prefix=/afs/example.ch/user/s/me
>     HOSTNAME=host9121.example.ch
>     HISTSIZE=1000
>     OS_REGION_NAME=cern
>     OS_PROJECT_DOMAIN_ID=default
>     GUESTFISH_OUTPUT=\e[0m
>     SSH_AUTH_SOCK=/tmp/ssh-XXXXy2mdZW/agent.202456
>     RBENV_SHELL=bash
>     EDITOR=vim
>     _HPX_SEEN_HEPIX_SH=1
>     PWD=/afs/example.ch/user/s/me
>     LOGNAME=me
>     XDG_SESSION_TYPE=tty
>     MODULESHOME=/usr/share/Modules
>     rvm_version=1.29.12 (latest)
>     MANPATH=/usr/share/man::/opt/puppetlabs/puppet/share/man
>     MESA_GLSL_CACHE_DIR=/run/user/16568
>     MYPROXY_SERVER=myproxy.example.ch
>     OS_AUTH_URL=https://keystone.example.ch/v3
>     GUESTFISH_RESTORE=\e[0m
>     MOTD_SHOWN=pam
>     __MODULES_SHARE_MANPATH=:1
>     HOME=/afs/example.ch/user/s/me
>     SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass
>     LANG=en_US.UTF-8
>     HISTFILE=/afs/example.ch/user/s/me/.history.host9121.example.ch
>     GUESTFISH_PS1=\[\e[1;32m\]><fs>\[\e[0;31m\] 
>     SSH_CONNECTION=2a0e:e701:121f:0:7f:fe4f:71aa:87d4 52928 2001:1458:d00:61::100:c6 22
>     MCOLLECTIVE_CERTNAME=me
>     KUBECACHEDIR=/run/user/16568/kubecache
>     rvm_bin_path=/afs/example.ch/user/s/me/.rvm/bin
>     XDG_SESSION_CLASS=user
>     SELINUX_ROLE_REQUESTED=
>     LESSOPEN=||/usr/bin/lesspipe.sh %s
>     USER=me
>     CONDA_SHLVL=0
>     MODULES_RUN_QUARANTINE=LD_LIBRARY_PATH LD_PRELOAD
>     OS_VOLUME_API_VERSION=3
>     LOADEDMODULES=
>     VISUAL=vim
>     SELINUX_USE_CURRENT_RANGE=
>     OS_IDENTITY_PROVIDER=sssd
>     SHLVL=2
>     GUESTFISH_INIT=\e[1;34m
>     CVS_RSH=ssh
>     XDG_SESSION_ID=17597
>     GPGKEY=2348427F
>     OS_AUTH_TYPE=v3fedkerb
>     XDG_RUNTIME_DIR=/run/user/16568
>     OS_MUTUAL_AUTH=disabled
>     S_COLORS=auto
>     SSH_CLIENT=2a0e:e701:121f:0:7f:fe4f:71aa:87d4 52928 22
>     __MODULES_LMINIT=module use --append /usr/share/Modules/modulefiles:module use --append /etc/modulefiles:module use --append /usr/share/modulefiles
>     OS_PROJECT_NAME=Personal me
>     which_declare=declare -f
>     KDEDIRS=/usr
>     OS_PROTOCOL=kerberos
>     PATH=/afs/example.ch/user/s/me/.rbenv/shims:/afs/example.ch/user/s/me/.rbenv/bin:/usr/sue/bin:/usr/share/Modules/bin:/usr/condabin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/opt/puppetlabs/bin:/afs/example.ch/user/s/me/.fzf/bin:/afs/example.ch/user/s/me/.rvm/bin:/afs/example.ch/user/s/me/bin
>     SELINUX_LEVEL_REQUESTED=
>     MODULEPATH=/etc/scl/modulefiles:/usr/share/Modules/modulefiles:/etc/modulefiles:/usr/share/modulefiles
>     DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/16568/bus
>     MAIL=/var/spool/mail/me
>     MESA_SHADER_CACHE_DIR=/run/user/16568
>     OS_COMPUTE_API_VERSION=2.72
>     CVSEDITOR=vim
>     rvm_path=/afs/example.ch/user/s/me/.rvm
>     OS_IDENTITY_API_VERSION=3
>     MODULES_CMD=/usr/share/Modules/libexec/modulecmd.tcl
>     BASH_FUNC_ml%%=() {  module ml "$@"
>     }
>     BASH_FUNC_which%%=() {  ( alias;
>      eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
>     }
>     BASH_FUNC_module%%=() {  local _mlredir=0;
>      if [ -n "${MODULES_REDIRECT_OUTPUT+x}" ]; then
>      if [ "$MODULES_REDIRECT_OUTPUT" = '0' ]; then
>      _mlredir=0;
>      else
>      if [ "$MODULES_REDIRECT_OUTPUT" = '1' ]; then
>      _mlredir=1;
>      fi;
>      fi;
>      fi;
>      case " $@ " in 
>      *' --no-redirect '*)
>      _mlredir=0
>      ;;
>      *' --redirect '*)
>      _mlredir=1
>      ;;
>      esac;
>      if [ $_mlredir -eq 0 ]; then
>      _module_raw "$@";
>      else
>      _module_raw "$@" 2>&1;
>      fi
>     }
>     BASH_FUNC_scl%%=() {  if [ "$1" = "load" -o "$1" = "unload" ]; then
>      eval "module $@";
>      else
>      /usr/bin/scl "$@";
>      fi
>     }
>     BASH_FUNC__module_raw%%=() {  eval "$(/usr/bin/tclsh '/usr/share/Modules/libexec/modulecmd.tcl' bash "$@")";
>      _mlstatus=$?;
>      return $_mlstatus
>     }
>     _=/usr/bin/printenv
[21:13:44.186] > Removing old logfile at /afs/example.ch/user/s/me/.vscode-server/.cli.65edc4939843c90c34d61f4ce11704f09d3e5cb6.log
[21:13:44.304] > Spawned remote CLI: 202598
[21:13:44.306] stderr> cat: /afs/example.ch/user/s/me/.vscode-server/.cli.65edc4939843c90c34d61f4ce11704f09d3e5cb6.log: No such file or directory
[21:13:44.307] > Waiting for server log...
[21:13:44.339] stderr> cat: /afs/example.ch/user/s/me/.vscode-server/.cli.65edc4939843c90c34d61f4ce11704f09d3e5cb6.log: No such file or directory
[21:13:44.341] > Waiting for server log...
[21:13:44.374] stderr> cat: /afs/example.ch/user/s/me/.vscode-server/.cli.65edc4939843c90c34d61f4ce11704f09d3e5cb6.log: No such file or directory
[21:13:44.375] > Waiting for server log...
[21:13:44.410] > Waiting for server log...
[21:13:44.443] > Waiting for server log...
[21:13:44.477] > Waiting for server log...
[21:13:44.511] > Waiting for server log...
[21:13:44.545] > Waiting for server log...
[21:13:44.580] > Waiting for server log...
[21:13:44.614] > Waiting for server log...
[21:13:44.648] > Waiting for server log...
[21:13:44.682] > Waiting for server log...
[21:13:44.715] > Waiting for server log...
[21:13:44.749] > Waiting for server log...
[21:13:44.784] > Waiting for server log...
[21:13:44.818] > 0b7124c7dc85: start
> listeningOn====
> osReleaseId==rhel==
> arch==x86_64==
> vscodeArch==x64==
> bitness==64==
> tmpDir==/run/user/16568==
> platform==linux==
> unpackResult====
> didLocalDownload==0==
> downloadTime====
> installTime====
> serverStartTime==632==
> execServerToken==11aaa11a-aa1a-1111-aa11-1111111a11a1==
> platformDownloadPath==cli-alpine-x64==
> 0b7124c7dc85: end
[21:13:44.819] Received install output: 
listeningOn====
osReleaseId==rhel==
arch==x86_64==
vscodeArch==x64==
bitness==64==
tmpDir==/run/user/16568==
platform==linux==
unpackResult====
didLocalDownload==0==
downloadTime====
installTime====
serverStartTime==632==
execServerToken==11aaa11a-aa1a-1111-aa11-1111111a11a1==
platformDownloadPath==cli-alpine-x64==

[21:13:44.822] Failed to parse remote port from server output
[21:13:44.823] Terminating local server
[21:13:44.827] Resolver error: Error: 
	at v.Create (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:493431)
	at t.handleInstallOutput (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:490753)
	at e (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:545236)
	at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
	at async /home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:567561
	at async t.withShowDetailsEvent (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:571256)
	at async /home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:541941
	at async T (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:539992)
	at async t.resolveWithLocalServer (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:541481)
	at async P (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:564693)
	at async t.resolve (/home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:568667)
	at async /home/me/.vscode/extensions/ms-vscode-remote.remote-ssh-0.115.0/out/extension.js:2:839059
[21:13:44.829] Local server exit: 15
[21:13:44.834] ------

Anything else?

Definitely worth mentioning that this with kerberos login and ~/.vscode-server on AFS file system.

What output we are failing to parse ?

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.