vscode-remote-release icon indicating copy to clipboard operation
vscode-remote-release copied to clipboard

Remote SSH Connection Fails during Server Installation on Remote

Open Andeloth opened this issue 3 years ago • 7 comments

Does this issue occur when all extensions are disabled?: N/A

  • VS Code Version: 1.71.0
  • OS Version: Windows 10 Version 10.0.19044 Build 19044

Steps to Reproduce:

  1. Update VSCode to August 2022 version.
  2. Attempt to connect to Remote SSH host.

Issue happens while VSCode is trying to install the server on the remote.

Reminder: You may only use this software with Visual Studio family products,
> * as described in the license (https://go.microsoft.com/fwlink/?linkid=2077057) 
> *
> 
[14:24:21.211] > 
> Server did not start successfully. Full server log at /home/andeloth/.vscode-ser
> ver/.784b0177c56c607789f9638da7b6bf3230d47a8c.log >>>
> node:internal/modules/cjs/loader:936
>   throw err;
>   ^
> 
> Error: Cannot find module '../product.json'
> Require stack:
> - /home/andeloth/.vscode-server/bin/784b0177c56c607789f9638da7b6bf3230d47a8c/out
> /server-main.js
>     at Function.Module._resolveFilename (node:internal/modules/cjs/loader:933:15
> )
>     at Function.Module._load (node:internal/modules/cjs/loader:778:27)
>     at Module.require (node:internal/modules/cjs/loader:1005:19)
>     at require (node:internal/modules/cjs/helpers:102:18)
>     at Object.<anonymous> (/home/andeloth/.vscode-server/bin/784b0177c56c607789f
> 9638da7b6bf3230d47a8c/out/server-main.js:1:106)
>     at Module._compile (node:internal/modules/cjs/loader:1103:14)
>     at Object.Module._extensions..js (node:internal/modules/cjs/loader:1157:10) 
>     at Module.load (node:internal/modules/cjs/loader:981:32)
>     at Function.Module._load (node:internal/modules/cjs/loader:822:12)
>     at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_ma
> in:77:12) {
>   code: 'MODULE_NOT_FOUND',
>   requireStack: [
>     '/home/andeloth/.vscode-server/bin/784b0177c56c607789f9638da7b6bf3230d47a8c/
> out/server-main.js'
[14:24:21.220] > 
>   ]
> }
> <<< End of server log
> e1c4fd8b3cc5: start
> exitCode==32==
> listeningOn====
> osReleaseId==rhel==
> arch==x86_64==
> tmpDir==/tmp==
> platform==linux==
> unpackResult====
> didLocalDownload==0==
> downloadTime====
> installTime====
> extInstallTime====
[14:24:21.226] > 
> serverStartTime==14630==
> e1c4fd8b3cc5: end
[14:24:21.227] Received install output: 
exitCode==32==
listeningOn====
osReleaseId==rhel==
arch==x86_64==
tmpDir==/tmp==
platform==linux==
unpackResult====
didLocalDownload==0==
downloadTime====
installTime====
extInstallTime====
serverStartTime==14630==

[14:24:21.228] Cannot find module '../product.json'

[14:24:21.229] Resolver error: Error: Cannot find module '../product.json'

	at g.ServerInstallError (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:585156)
	at h (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:578423)
	at t.handleInstallOutput (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:582403)
	at t.tryInstall (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:681023)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:643908
	at async t.withShowDetailsEvent (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:647224)
	at async t.resolve (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:644958)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:727082
[14:24:21.239] ------



[14:24:21.479] SSH Resolver called for "ssh-remote+ssh.rc.byu.edu", attempt 2, (Reconnection)
[14:24:21.483] SSH Resolver called for host: ssh.rc.byu.edu
[14:24:21.483] Setting up SSH remote "ssh.rc.byu.edu"
[14:24:21.490] Using commit id "784b0177c56c607789f9638da7b6bf3230d47a8c" and quality "stable" for server
[14:24:21.500] Install and start server if needed
[14:24:21.508] Running script with connection command: ssh -T -D 64677 "ssh.rc.byu.edu" bash
[14:24:21.512] Terminal shell path: C:\WINDOWS\System32\cmd.exe
[14:24:21.964] > ]0;C:\WINDOWS\System32\cmd.exe
[14:24:21.964] Got some output, clearing connection timeout
[14:24:22.009] > getsockname failed: Bad file descriptor
> channel_send_open: channel 2: unexpected internal error
> The process tried to write to a nonexistent pipe.
>     
[14:24:22.504] "install" terminal command done
[14:24:22.506] Install terminal quit with output: 
[14:24:23.281] "install" terminal command done
[14:24:23.281] Install terminal quit with output:     
[14:24:23.282] Received install output:     
[14:24:23.283] Resolver error: Error: 
	at g.Create (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:585222)
	at c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583101
	at t.handleInstallOutput (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583796)
	at t.tryInstall (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:681023)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:643908
	at async t.withShowDetailsEvent (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:647224)
	at async t.resolve (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:644958)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:727082
[14:24:23.286] ------

Andeloth avatar Sep 07 '22 14:09 Andeloth

Thanks for creating this issue! It looks like you may be using an old version of VS Code, the latest stable release is 1.71.0. Please try upgrading to the latest version and checking whether this issue remains.

Happy Coding!

vscodenpa avatar Sep 07 '22 14:09 vscodenpa

Hello! There are a few different ideas I have on a fix. First can you send the full log files? It looks like you included only those after the connection and installation of the vs code server which in those previous logs there might be some warning messages or errors which could help debug this issue. On that same note, can you see if you have any antivirus software which interfered? That can sometimes be the cause of a missing file. Additionally can you run the command kill vscode server on host from the command palette then try setup again? This might reset the situation to allow the install to go smoothly. Thanks!

eleanorjboyd avatar Sep 09 '22 20:09 eleanorjboyd

Here is the log file.

784b0177c56c607789f9638da7b6bf3230d47a8c.log

I checked and my antivirus (Windows Defender) hasn't detected anything on my side, and I don't know what antivirus my organization's server has.

I also ran kill vscode server on host and the same issue happened. This is the log file after running the kill command.

784b0177c56c607789f9638da7b6bf3230d47a8c-2.log

I have reverted to version 1.70 and I've been able to connect to the remote with that.

Andeloth avatar Sep 12 '22 15:09 Andeloth

Hello again! My apologies I forgot to specify the log file which gives output for our extension. If you could instead send over the output from the remote ssh output channel those are the logs I can look through for detailed information on our extension's execution. Thanks!

eleanorjboyd avatar Sep 12 '22 22:09 eleanorjboyd

Hello I'm new into this thread, but today I've got into the same issue Can you, please, explain, where can I find "remote ssh output channel" and get output from it? Thanks!

Hello again! My apologies I forgot to specify the log file which gives output for our extension. If you could instead send over the output from the remote ssh output channel those are the logs I can look through for detailed information on our extension's execution. Thanks!

andsh avatar Sep 17 '22 05:09 andsh

Interestingly, I updated my VSCode to 1.71 today to try to reproduce the issue and I haven't been able to so far. It seems like the 1.71.2 update fixed the issue somehow?

Well, anyway, here is the current output

[09:23:09.161] Log Level: 2
[09:23:09.163] [email protected]
[09:23:09.163] win32 x64
[09:23:09.189] SSH Resolver called for "ssh-remote+ssh.rc.byu.edu", attempt 1
[09:23:09.190] "remote.SSH.useLocalServer": false
[09:23:09.190] "remote.SSH.showLoginTerminal": false
[09:23:09.190] "remote.SSH.remotePlatform": {"ssh.rc.byu.edu":"linux"}
[09:23:09.190] "remote.SSH.path": undefined
[09:23:09.190] "remote.SSH.configFile": undefined
[09:23:09.191] "remote.SSH.useFlock": true
[09:23:09.191] "remote.SSH.lockfilesInTmp": false
[09:23:09.191] "remote.SSH.localServerDownload": auto
[09:23:09.191] "remote.SSH.remoteServerListenOnSocket": false
[09:23:09.191] "remote.SSH.showLoginTerminal": false
[09:23:09.191] "remote.SSH.defaultExtensions": []
[09:23:09.191] "remote.SSH.loglevel": 2
[09:23:09.191] "remote.SSH.enableDynamicForwarding": true
[09:23:09.192] "remote.SSH.enableRemoteCommand": false
[09:23:09.192] "remote.SSH.serverPickPortsFromRange": {}
[09:23:09.192] "remote.SSH.serverInstallPath": {}
[09:23:09.196] SSH Resolver called for host: ssh.rc.byu.edu
[09:23:09.196] Setting up SSH remote "ssh.rc.byu.edu"
[09:23:09.201] Using commit id "74b1f979648cc44d385a2286793c226e611f59e7" and quality "stable" for server
[09:23:09.206] Install and start server if needed
[09:23:09.233] Checking ssh with "ssh -V"
[09:23:09.311] > OpenSSH_for_Windows_8.1p1, LibreSSL 3.0.2

[09:23:09.318] Running script with connection command: ssh -T -D 63668 "ssh.rc.byu.edu" bash
[09:23:09.323] Terminal shell path: C:\WINDOWS\System32\cmd.exe
[09:23:12.733] > ]0;C:\WINDOWS\System32\cmd.exegetsockname failed: Bad file descriptor
> channel_send_open: channel 2: unexpected internal error
> The process tried to write to a nonexistent pipe.
>     
[09:23:12.735] Got some output, clearing connection timeout
[09:23:13.816] "install" terminal command done
[09:23:13.818] Install terminal quit with output:     
[09:23:13.818] Received install output:     
[09:23:13.821] Resolver error: Error: 
	at g.Create (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:585222)
	at c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583101
	at t.handleInstallOutput (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583796)
	at t.tryInstall (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:681023)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:643908
	at async t.withShowDetailsEvent (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:647224)
	at async t.resolve (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:644958)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:727082
[09:23:13.834] ------




[09:23:13.880] ------




[09:23:13.881] SSH Resolver called for "ssh-remote+ssh.rc.byu.edu", attempt 2, (Reconnection)
[09:23:13.884] SSH Resolver called for host: ssh.rc.byu.edu
[09:23:13.885] Setting up SSH remote "ssh.rc.byu.edu"
[09:23:13.892] Using commit id "74b1f979648cc44d385a2286793c226e611f59e7" and quality "stable" for server
[09:23:13.896] Install and start server if needed
[09:23:13.909] Running script with connection command: ssh -T -D 63673 "ssh.rc.byu.edu" bash
[09:23:13.913] Terminal shell path: C:\WINDOWS\System32\cmd.exe
[09:23:14.302] > ]0;C:\WINDOWS\System32\cmd.exe
[09:23:14.304] Got some output, clearing connection timeout
[09:23:14.334] > getsockname failed: Bad file descriptor
[09:23:14.341] > channel_send_open: channel 2: unexpected internal error
> The process tried to write to a nonexistent pipe.
>     
[09:23:15.621] "install" terminal command done
[09:23:15.622] Install terminal quit with output:     
[09:23:15.622] Received install output:     
[09:23:15.623] Resolver error: Error: 
	at g.Create (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:585222)
	at c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583101
	at t.handleInstallOutput (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583796)
	at t.tryInstall (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:681023)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:643908
	at async t.withShowDetailsEvent (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:647224)
	at async t.resolve (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:644958)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:727082
[09:23:15.628] ------




[09:23:15.635] ------




[09:23:15.636] SSH Resolver called for "ssh-remote+ssh.rc.byu.edu", attempt 3, (Reconnection)
[09:23:15.639] SSH Resolver called for host: ssh.rc.byu.edu
[09:23:15.639] Setting up SSH remote "ssh.rc.byu.edu"
[09:23:15.642] Using commit id "74b1f979648cc44d385a2286793c226e611f59e7" and quality "stable" for server
[09:23:15.645] Install and start server if needed
[09:23:15.652] Running script with connection command: ssh -T -D 63674 "ssh.rc.byu.edu" bash
[09:23:15.656] Terminal shell path: C:\WINDOWS\System32\cmd.exe
[09:23:16.101] > ]0;C:\WINDOWS\System32\cmd.exe
[09:23:16.101] Got some output, clearing connection timeout
[09:23:16.129] > getsockname failed: Bad file descriptor
> channel_send_open: channel 2: unexpected internal error
> The process tried to write to a nonexistent pipe.
>     
[09:23:17.392] "install" terminal command done
[09:23:17.394] Install terminal quit with output:     
[09:23:17.395] Received install output:     
[09:23:17.396] Resolver error: Error: 
	at g.Create (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:585222)
	at c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583101
	at t.handleInstallOutput (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:583796)
	at t.tryInstall (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:681023)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:643908
	at async t.withShowDetailsEvent (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:647224)
	at async t.resolve (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:644958)
	at async c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:727082
[09:23:17.402] ------




[09:23:17.423] ------




[09:23:17.423] SSH Resolver called for "ssh-remote+ssh.rc.byu.edu", attempt 4, (Reconnection)
[09:23:17.425] SSH Resolver called for host: ssh.rc.byu.edu
[09:23:17.425] Setting up SSH remote "ssh.rc.byu.edu"
[09:23:17.430] Using commit id "74b1f979648cc44d385a2286793c226e611f59e7" and quality "stable" for server
[09:23:17.438] Install and start server if needed
[09:23:17.445] Running script with connection command: ssh -T -D 63676 "ssh.rc.byu.edu" bash
[09:23:17.450] Terminal shell path: C:\WINDOWS\System32\cmd.exe
[09:23:17.891] > ]0;C:\WINDOWS\System32\cmd.exe
[09:23:17.891] Got some output, clearing connection timeout
[09:23:18.039] > 
[09:23:18.055] > All network and system usage is subject to monitoring and recording in order to
> maintain confidentiality, data integrity, and system availability. Any improper
> or unlawful use may be disclosed to organization and law enforcement officials,
[09:23:18.072] > and appropriate action may be taken.
> 
> Password:
[09:23:18.072] Showing password prompt
[09:23:36.114] Password dialog canceled
[09:23:36.114] "install" terminal command canceled
[09:23:36.116] Resolver error: Error: Connecting was canceled
	at g.Canceled (c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:585418)
	at c:\Users\benji\.vscode\extensions\ms-vscode-remote.remote-ssh-0.84.0\out\extension.js:1:680337
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
[09:23:36.122] ------




[09:23:36.146] ------




[09:23:36.146] SSH Resolver called for "ssh-remote+ssh.rc.byu.edu", attempt 5, (Reconnection)
[09:23:36.149] SSH Resolver called for host: ssh.rc.byu.edu
[09:23:36.149] Setting up SSH remote "ssh.rc.byu.edu"
[09:23:36.153] Using commit id "74b1f979648cc44d385a2286793c226e611f59e7" and quality "stable" for server
[09:23:36.162] Install and start server if needed
[09:23:36.170] Running script with connection command: ssh -T -D 63680 "ssh.rc.byu.edu" bash
[09:23:36.176] Terminal shell path: C:\WINDOWS\System32\cmd.exe
[09:23:36.589] > ]0;C:\WINDOWS\System32\cmd.exe
[09:23:36.590] Got some output, clearing connection timeout
[09:23:36.755] > 
[09:23:36.790] > All network and system usage is subject to monitoring and recording in order to
> maintain confidentiality, data integrity, and system availability. Any improper
> or unlawful use may be disclosed to organization and law enforcement officials,
> and appropriate action may be taken.
[09:23:36.806] > Password: 
[09:23:36.808] Showing password prompt
[09:23:59.210] Got password response
[09:23:59.211] "install" wrote data to terminal: "******************"
[09:23:59.250] > 
[09:23:59.304] > Verification code: 
[09:23:59.304] Detected verification code prompt
[09:24:07.893] Got verification code response
[09:24:07.894] "install" wrote data to terminal: "******"
[09:24:07.950] > 
[09:24:09.589] > 7dcc45dc54ad: running
[09:24:09.628] > Acquiring lock on /home/andeloth/.vscode-server/bin/74b1f979648cc44d385a2286793c
> 226e611f59e7/vscode-remote-lock.andeloth.74b1f979648cc44d385a2286793c226e611f59e
> 7
[09:24:09.665] > Found old VS Code install 7f6ab5485bbc008386c4386d08766667e155244e, attempting t
> o clean up
[09:24:09.799] > Deleting old install from /home/andeloth/.vscode-server/bin/7f6ab5485bbc008386c4
> 386d08766667e155244e
[09:24:09.815] > rm: cannot remove '/home/andeloth/.vscode-server/bin/7f6ab5485bbc008386c4386d087
> 66667e155244e': Directory not empty
> Deleting old log file from /home/andeloth/.vscode-server/.7f6ab5485bbc008386c438
> 6d08766667e155244e.log
> rm: cannot remove '/home/andeloth/.vscode-server/.7f6ab5485bbc008386c4386d087666
> 67e155244e.log': No such file or directory
> Found old VS Code install dfd34e8260c270da74b5c2d86d61aee4b6d56977, attempting t
> o clean up
[09:24:09.946] > Deleting old install from /home/andeloth/.vscode-server/bin/dfd34e8260c270da74b5
> c2d86d61aee4b6d56977
> rm: cannot remove '/home/andeloth/.vscode-server/bin/dfd34e8260c270da74b5c2d86d6
> 1aee4b6d56977': Directory not empty
> Deleting old log file from /home/andeloth/.vscode-server/.dfd34e8260c270da74b5c2
> d86d61aee4b6d56977.log
[09:24:09.949] > 
> rm: cannot remove '/home/andeloth/.vscode-server/.dfd34e8260c270da74b5c2d86d61ae
> e4b6d56977.log': No such file or directory
> Found old VS Code install 74b1f979648cc44d385a2286793c226e611f59e7, attempting t
> o clean up
> Failed to acquire lock for install, not deleting: 74b1f979648cc44d385a2286793c22
> 6e611f59e7
[09:24:09.957] > 
> Found old VS Code install e18005f0f1b33c29e81d732535d8c0e47cafb0b5, attempting t
> o clean up
[09:24:10.100] > Deleting old install from /home/andeloth/.vscode-server/bin/e18005f0f1b33c29e81d
> 732535d8c0e47cafb0b5
> rm: cannot remove '/home/andeloth/.vscode-server/bin/e18005f0f1b33c29e81d732535d
> 8c0e47cafb0b5': Directory not empty
[09:24:10.107] > 
> Deleting old log file from /home/andeloth/.vscode-server/.e18005f0f1b33c29e81d73
> 2535d8c0e47cafb0b5.log
> rm: cannot remove '/home/andeloth/.vscode-server/.e18005f0f1b33c29e81d732535d8c0
> e47cafb0b5.log': No such file or directory
> Found old VS Code install c3f126316369cd610563c75b1b1725e0679adfb3, attempting t
> o clean up
[09:24:10.122] > 
[09:24:10.259] > Deleting old install from /home/andeloth/.vscode-server/bin/c3f126316369cd610563
> c75b1b1725e0679adfb3
[09:24:10.266] > rm: cannot remove '/home/andeloth/.vscode-server/bin/c3f126316369cd610563c75b1b1
> 725e0679adfb3': Directory not empty
> Deleting old log file from /home/andeloth/.vscode-server/.c3f126316369cd610563c7
> 5b1b1725e0679adfb3.log
> rm: cannot remove '/home/andeloth/.vscode-server/.c3f126316369cd610563c75b1b1725
> e0679adfb3.log': No such file or directory
> Found old VS Code install 83bd43bc519d15e50c4272c6cf5c1479df196a4d, attempting t
> o clean up
[09:24:10.283] > 
[09:24:10.419] > Deleting old install from /home/andeloth/.vscode-server/bin/83bd43bc519d15e50c42
> 72c6cf5c1479df196a4d
[09:24:10.424] > rm: cannot remove '/home/andeloth/.vscode-server/bin/83bd43bc519d15e50c4272c6cf5
> c1479df196a4d': Directory not empty
> Deleting old log file from /home/andeloth/.vscode-server/.83bd43bc519d15e50c4272
> c6cf5c1479df196a4d.log
> rm: cannot remove '/home/andeloth/.vscode-server/.83bd43bc519d15e50c4272c6cf5c14
> 79df196a4d.log': No such file or directory
> Found old VS Code install 784b0177c56c607789f9638da7b6bf3230d47a8c, attempting t
> o clean up
[09:24:10.446] > 
[09:24:10.569] > Install still has running processes, not deleting: 784b0177c56c607789f9638da7b6b
> f3230d47a8c
> Found old VS Code install e4503b30fc78200f846c62cf8091b76ff5547662, attempting t
> o clean up
[09:24:10.712] > Install still has running processes, not deleting: e4503b30fc78200f846c62cf8091b
> 76ff5547662
> Found existing installation at /home/andeloth/.vscode-server/bin/74b1f979648cc44
> d385a2286793c226e611f59e7...
> Checking /home/andeloth/.vscode-server/.74b1f979648cc44d385a2286793c226e611f59e7
> .log and /home/andeloth/.vscode-server/.74b1f979648cc44d385a2286793c226e611f59e7
[09:24:10.723] > 
> .pid for a running server
> Looking for server with pid: 7785
[09:24:10.744] > 
[09:24:10.863] > Starting server with command... /home/andeloth/.vscode-server/bin/74b1f979648cc4
> 4d385a2286793c226e611f59e7/bin/code-server --start-server --host=127.0.0.1 --acc
> ept-server-license-terms --enable-remote-auto-shutdown --port=0 --telemetry-leve
> l all   &> "/home/andeloth/.vscode-server/.74b1f979648cc44d385a2286793c226e611f5
> 9e7.log" < /dev/null
> printenv:
>     SHELL=/usr/local/bin/bash
>     SSH_CLIENT=10.2.118.180 63681 22
>     OPENBLAS_NUM_THREADS=1
>     CONDA_SHLVL=1
>     CONDA_PROMPT_MODIFIER=(base)
>     USER=andeloth
>     CONDA_EXE=/fslhome/andeloth/miniconda3/bin/conda
>     OMPI_MCA_btl_tcp_if_exclude=lo,ib0
>     VSCODE_AGENT_FOLDER=/home/andeloth/.vscode-server
[09:24:10.868] > 
>     _CE_CONDA=
>     PATH=/fslhome/andeloth/bin:/fslhome/andeloth/.local/bin:/fslhome/andeloth/de
> v/scicomp_class/scicomp/projecthelp/bin:/fslhome/andeloth/miniconda3/bin:/fslhom
> e/andeloth/miniconda3/condabin:/usr/local/bin:/bin:/usr/bin
>     MAIL=/var/mail/andeloth
>     MKL_NUM_THREADS=1
>     CONDA_PREFIX=/fslhome/andeloth/miniconda3
>     PWD=/home/andeloth
>     _CE_M=
>     HOME=/home/andeloth
>     SHLVL=2
>     OMPI_MCA_btl_base_warn_component_unused=0
>     LOGNAME=andeloth
>     CONDA_PYTHON_EXE=/fslhome/andeloth/miniconda3/bin/python
>     SSH_CONNECTION=10.2.118.180 63681 128.187.49.40 22
>     OMP_NUM_THREADS=1
>     CONDA_DEFAULT_ENV=base
>     _=/bin/printenv
[09:24:10.909] > 
[09:24:10.916] > Removing old logfile at /home/andeloth/.vscode-server/.74b1f979648cc44d385a22867
> 93c226e611f59e7.log
> Spawned remote server: 173901
> Waiting for server log...
[09:24:10.943] > Waiting for server log...
[09:24:10.976] > Waiting for server log...
[09:24:11.011] > Waiting for server log...
[09:24:11.045] > Waiting for server log...
[09:24:11.084] > Waiting for server log...
[09:24:11.120] > Waiting for server log...
[09:24:11.161] > Waiting for server log...
[09:24:11.199] > Waiting for server log...
[09:24:11.237] > Waiting for server log...
[09:24:11.274] > Waiting for server log...
[09:24:11.312] > Waiting for server log...
[09:24:11.350] > Waiting for server log...
[09:24:11.386] > Waiting for server log...
[09:24:11.425] > Waiting for server log...
[09:24:11.467] >  
> *
> * Reminder: You may only use this software with Visual Studio family products,
> * as described in the license (https://go.microsoft.com/fwlink/?linkid=2077057) 
> *
> 
[09:24:11.479] > 
> 7dcc45dc54ad: start
> SSH_AUTH_SOCK====
> DISPLAY====
> webUiAccessToken====
> listeningOn==43921==
> osReleaseId==rhel==
> arch==x86_64==
> tmpDir==/tmp==
> platform==linux==
> unpackResult====
> didLocalDownload==0==
> downloadTime====
> installTime====
> extInstallTime====
> serverStartTime==596==
> connectionToken==111a111a-1a11-111a-111a-11111a11a1a1==
> 7dcc45dc54ad: end
[09:24:11.480] Received install output: 
SSH_AUTH_SOCK====
DISPLAY====
webUiAccessToken====
listeningOn==43921==
osReleaseId==rhel==
arch==x86_64==
tmpDir==/tmp==
platform==linux==
unpackResult====
didLocalDownload==0==
downloadTime====
installTime====
extInstallTime====
serverStartTime==596==
connectionToken==111a111a-1a11-111a-111a-11111a11a1a1==

[09:24:11.480] Remote server is listening on 43921
[09:24:11.481] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":43921},"osReleaseId":"rhel","arch":"x86_64","webUiAccessToken":"","sshAuthSock":"","display":"","tmpDir":"/tmp","platform":"linux","connectionToken":"111a111a-1a11-111a-111a-11111a11a1a1"},"serverStartTime":596,"installUnpackCode":""}
[09:24:11.487] Starting forwarding server. localPort 63698 -> socksPort 63680 -> remotePort 43921
[09:24:11.490] Forwarding server listening on 63698
[09:24:11.490] Waiting for ssh tunnel to be ready
[09:24:11.492] [Forwarding server 63698] Got connection 0
[09:24:11.495] Tunneled 43921 to local port 63698
[09:24:11.496] Resolved "ssh-remote+ssh.rc.byu.edu" to "127.0.0.1:63698"
[09:24:11.513] ------




[09:24:11.532] > 
[09:24:11.576] [Forwarding server 63698] Got connection 1
[09:24:11.684] [Forwarding server 63698] Got connection 2
[09:24:18.419] [Forwarding server 63698] Got connection 3

Andeloth avatar Sep 19 '22 15:09 Andeloth

Interestingly, I updated my VSCode to 1.71 today to try to reproduce the issue and I haven't been able to so far. It seems like the 1.71.2 update fixed the issue somehow?

I confirm, the issue is resolved in version 1.71.2

andsh avatar Sep 19 '22 15:09 andsh

The error does not involve the client trying to connect or reconnect, but rather it shows a corrupt installation directory of the vscode server.

[14:24:21.211] > 
> Server did not start successfully. Full server log at /home/andeloth/.vscode-ser
> ver/.784b0177c56c607789f9638da7b6bf3230d47a8c.log >>>
> node:internal/modules/cjs/loader:936
>   throw err;
>   ^
> 
> Error: Cannot find module '../product.json'
> Require stack:
> - /home/andeloth/.vscode-server/bin/784b0177c56c607789f9638da7b6bf3230d47a8c/out
> /server-main.js
>     at Function.Module._resolveFilename (node:internal/modules/cjs/loader:933:15
> )
>     at Function.Module._load (node:internal/modules/cjs/loader:778:27)
>     at Module.require (node:internal/modules/cjs/loader:1005:19)
>     at require (node:internal/modules/cjs/helpers:102:18)
>     at Object.<anonymous> (/home/andeloth/.vscode-server/bin/784b0177c56c607789f
> 9638da7b6bf3230d47a8c/out/server-main.js:1:106)
>     at Module._compile (node:internal/modules/cjs/loader:1103:14)
>     at Object.Module._extensions..js (node:internal/modules/cjs/loader:1157:10) 
>     at Module.load (node:internal/modules/cjs/loader:981:32)
>     at Function.Module._load (node:internal/modules/cjs/loader:822:12)
>     at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_ma
> in:77:12) {
>   code: 'MODULE_NOT_FOUND',
>   requireStack: [
>     '/home/andeloth/.vscode-server/bin/784b0177c56c607789f9638da7b6bf3230d47a8c/
> out/server-main.js'
[14:24:21.220] > 
>   ]
> }
> <<< End of server log

It looks to me like the server installation directory is corrupt. The server zip file contains (amongst others) the following files:

.
├── out
│   ├── server-main.js
│   └── ...
├── product.json
├── ...

The code in out/server-main.js has a require call like require('../product.json') and that should be able to find the product.json file. The exception indicates that product.json is not on disk at the expected location. This indicates to me a corrupt installation, maybe caused by a bug in the unzipping code or by some other process on the target machine deleting the product.json file after it was written. Is the unzipping code safe from interruptions? i.e. if the remote machine reboots during an installation, would it resume safely with the next connection?

Updating to 1.71.2 did not fix anything per se, it just installed the server at version 1.71.2, which seems to have been installed correctly. Since the previous installation directory is no longer in use, the installation corruption no longer impacts anything.

@eleanorjboyd TL;DR: in this case, the SSH extension installed a vscode server and the outcome was a corrupt installation. It is not clear if there is a bug in the SSH code that installs the vscode server (more likely) or if there was another process running on the target machine (like an antivirus) which decided to delete the product.json file (less likely). How is the installation code looking like? Is the unzipping done to a temporary folder and then renamed to the right name (to simulate an atomic fs operation?).

alexdima avatar Sep 27 '22 07:09 alexdima

We have opened issue https://github.com/microsoft/vscode/issues/162590 to investigate the retry further. With this issue created I am closing this issue as resolved.

eleanorjboyd avatar Oct 04 '22 15:10 eleanorjboyd