Installing the server fails

[gothicVI]

This is somewhat decoupled from #16 and from #17 which aims to close the former.

The error I'm getting when trying to install the server on the remote machine behind the 2FA jump host is:

[Info  - 06:07:09.675] Resolving ssh remote authority 'ssh-remote+REMOVE' (attemp #1)
[Trace  - 06:07:09.686] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Trace  - 06:07:09.688] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Info  - 06:07:09.718] Trying no-auth authentication
[Info  - 06:07:09.726] Trying publickey authentication: /home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Info  - 06:07:09.742] Trying keyboard-interactive authentication
[Info  - 06:07:12.297] Trying no-auth authentication
[Info  - 06:07:12.353] Trying publickey authentication: /home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Trace  - 06:07:12.419] Server install command:

###skipped to save space

[Trace  - 06:07:17.820] Server install command stderr:
ps: bad -o argument 'command', supported arguments: user,group,comm,args,pid,ppid,pgid,etime,nice,rgroup,ruser,time,tty,vsz,sid,stat,rss

[Trace  - 06:07:17.821] Server install command stdout:
Error server did not start sucessfully
1e676c7df18a6c2a568a1284: start
exitCode==1==
listeningOn====
connectionToken==822c5ba2-3af4-4c3c-ac96-6bc604bdf215==
logFile==/home/YYY/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log==
osReleaseId==alpine==
arch==x86_64==
platform==Linux==
tmpDir==/tmp==
1e676c7df18a6c2a568a1284: end

[Error  - 06:07:17.821] Error resolving authority
Error: Couldn't install vscode server on remote server, install script returned non-zero exit status
	at t.installCodeServer (/home/XXX/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:405397)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async /home/XXX/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:375641
[Info  - 06:07:28.856] Resolving ssh remote authority 'ssh-remote+REMOTE' (attemp #2)
[Trace  - 06:07:28.860] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Trace  - 06:07:28.862] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:G5Xju3fAbNvv5y0pxtjEuAYfHWXpE9HdjnUlasj9eDA=
[Info  - 06:07:28.882] Trying no-auth authentication
[Info  - 06:07:28.889] Trying publickey authentication: /home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Info  - 06:07:28.906] Trying keyboard-interactive authentication
[Error  - 06:08:58.863] Error resolving authority
Error: Timed out while waiting for handshake
	at Timeout.<anonymous> (/home/XXX/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:143942)
	at listOnTimeout (node:internal/timers:559:17)
	at process.processTimers (node:internal/timers:502:7)
[Info  - 06:08:58.907] Resolving ssh remote authority 'ssh-remote+REMOTE' (attemp #3)
[Trace  - 06:08:58.909] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Trace  - 06:08:58.910] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Info  - 06:08:58.927] Trying no-auth authentication
[Info  - 06:08:58.935] Trying publickey authentication: /home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Info  - 06:08:58.952] Trying keyboard-interactive authentication
[Error  - 06:10:28.911] Error resolving authority
Error: Timed out while waiting for handshake
	at Timeout.<anonymous> (/home/XXX/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:143942)
	at listOnTimeout (node:internal/timers:559:17)
	at process.processTimers (node:internal/timers:502:7)
[Info  - 06:10:28.943] Resolving ssh remote authority 'ssh-remote+RMOTE' (attemp #4)
[Trace  - 06:10:28.946] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Trace  - 06:10:28.947] Identity keys:
/home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Info  - 06:10:28.966] Trying no-auth authentication
[Info  - 06:10:28.973] Trying publickey authentication: /home/XXX/.ssh/id_rsa ssh-rsa SHA256:YYY=
[Info  - 06:10:28.988] Trying keyboard-interactive authentication

On the remote machine the content of the .vscodium-server is:

$ ls -a .vscodium-server/
.   .cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log    .cea9d1a4b17966719d8c5f3cdd914480f7cec47c.token
..  .cea9d1a4b17966719d8c5f3cdd914480f7cec47c.pid    bin
$ ls .vscodium-server/bin/
cea9d1a4b17966719d8c5f3cdd914480f7cec47c
$ ls .vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c/
bin           extensions    node          node_modules  out           package.json  product.json  server.sh

Initially I thought that a firewall rule might prevent the download, but:

$ ping -c 3 www.github.com
PING www.github.com (140.82.121.3): 56 data bytes
64 bytes from 140.82.121.3: seq=0 ttl=42 time=9.392 ms
64 bytes from 140.82.121.3: seq=1 ttl=42 time=9.377 ms
64 bytes from 140.82.121.3: seq=2 ttl=42 time=9.444 ms

--- www.github.com ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 9.377/9.404/9.444 ms

Maybe some form of manual install instructions or a local download and push to remote via rsync or similar could solve this.

[jeanp413]

See #17 (comment)

@gothicVI if you have the vsix version installed, uninstall it first as the published version has the same version

[gothicVI]

Hi @jeanp413,
the change introduced in ec8d7c8 uncovered a follow up bug:

[Trace  - 07:39:27.112] Server install command stderr:
ps: unrecognized option: p
BusyBox v1.34.1 (2022-07-19 20:11:24 UTC) multi-call binary.

Usage: ps [-o COL1,COL2=HEADER] [-T]

Show list of processes

	-o COL1,COL2=HEADER	Select columns for display
	-T			Show threads

[Trace  - 07:39:27.112] Server install command stdout:
Server script already installed in /home/XXX/.vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c/bin/codium-server
Error server did not start sucessfully
06b2176810b8a00076daafce: start
exitCode==1==
listeningOn====
connectionToken==31c59e4b-308c-4219-9f16-b662fc5ce69a==
logFile==/home/XXX/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log==
osReleaseId==alpine==
arch==x86_64==
platform==Linux==
tmpDir==/tmp==
06b2176810b8a00076daafce: end

I can provide the full log file if needed.
This machine sadly is quite different from the others and remains the only one to not work successfully ;)

[jeanp413]

From the logs as you are using alpine it seems the ps command is kinda limited, found this comment , that says installing procps package would help, could you try that?

[gothicVI]

I did install procps. The error message now no longer mentions a specific thing failing:

[Trace  - 05:37:05.975] Server install command stdout:
Error server did not start sucessfully
1d46a61140d880c0efdce66f: start
exitCode==1==
listeningOn====
connectionToken==4a435a3f-4f91-481a-baf1-dc828d0a2806==
logFile==/home/REMOTEUSER/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log==
osReleaseId==alpine==
arch==x86_64==
platform==Linux==
tmpDir==/tmp==
1d46a61140d880c0efdce66f: end

[Error  - 05:37:05.976] Error resolving authority
Error: Couldn't install vscode server on remote server, install script returned non-zero exit status
	at t.installCodeServer (/home/YYY/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:405391)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async /home/YYY/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:375641
[Info  - 05:37:09.604] Resolving ssh remote authority 'ssh-remote+REMOTEHOST' (attemp #2)
[Trace  - 05:37:09.607] Identity keys:
/home/YYY/.ssh/id_rsa ssh-rsa SHA256:XXX
[Trace  - 05:37:09.610] Identity keys:
/home/YYY/.ssh/id_rsa ssh-rsa SHA256:XXX
[Info  - 05:37:09.640] Trying no-auth authentication
[Info  - 05:37:09.659] Trying publickey authentication: /home/YYY/.ssh/id_rsa ssh-rsa SHA256:XXX
[Info  - 05:37:09.676] Trying keyboard-interactive authentication

The logfile contains a single line

/home/REMOTEUSER/.vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c/bin/codium-server: line 12: /home/REMOTEUSER/.vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c/node: not found

however:

~/.vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c$ ls -l
total 78476
drwxr-sr-x    4 REMOTEUSER    REMOTEGROUP       4096 Sep 29 05:37 bin
drwxr-sr-x   33 REMOTEUSER    REMOTEGROUP       4096 Sep 29 05:37 extensions
-rwxr-xr-x    1 REMOTEUSER    REMOTEGROUP   80316256 Sep 15 18:20 node
drwxr-sr-x  103 REMOTEUSER    REMOTEGROUP       4096 Sep 29 05:37 node_modules
drwxr-sr-x    3 REMOTEUSER    REMOTEGROUP       4096 Sep 29 05:37 out
-rw-r--r--    1 REMOTEUSER    REMOTEGROUP         88 Sep 15 18:05 package.json
-rw-r--r--    1 REMOTEUSER    REMOTEGROUP      12109 Sep 15 18:10 product.json
-rwxr-xr-x    1 REMOTEUSER    REMOTEGROUP        240 Sep 15 18:05 server.sh

[jeanp413]

Can you follow this https://johnsiu.com/blog/alpine-vscode/#busybox, basically installing apk add gcompat libstdc++
Forgot that alpine is not even officially supported in the MS remote-ssh extension.

[gothicVI]

Sadly did not seem to do the trick:

[Trace  - 07:49:33.611] Server install command stdout:
Server script already installed in /home/XXX/.vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c/bin/codium-server
Error server did not start sucessfully
fb35fb0406be17c041c3edd5: start
exitCode==1==
listeningOn====
connectionToken==c654596f-e259-4f37-a719-66c7223d3ed2==
logFile==/home/XXX/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log==
osReleaseId==alpine==
arch==x86_64==
platform==Linux==
tmpDir==/tmp==
fb35fb0406be17c041c3edd5: end

[Error  - 07:49:33.611] Error resolving authority
Error: Couldn't install vscode server on remote server, install script returned non-zero exit status
	at t.installCodeServer (/home/YYY/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:405391)
	at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
	at async /home/di75faw/.vscode-oss/extensions/jeanp413.open-remote-ssh-0.0.15/out/extension.js:1:375641

with

$ cat ~/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log
Server bound to 127.0.0.1:45307 (IPv4)
Extension host agent listening on 45307

[07:49:36] Extension host agent started.

which somewhat indicate it should be working though...

[jeanp413]

Yeah so that means the server is running, could be that the time waiting for parsing the output is too short, right now is 2.5s, but then I expect if you try to reconnect again after failing the first time it should work as server is already running and the log file contains the listening port. Could you confirm that or reconnecting always fails?
Also can you test if this command from the script cat $SERVER_LOGFILE | grep -E 'Extension host agent listening on .+' | sed 's/Extension host agent listening on //' runs successfully or does it throw an error

[gothicVI]

Hi,
so now I get

[Trace  - 06:13:33.911] Server install command stdout:
Server script already installed in /home/XXX/.vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c/bin/codium-server
Server script is already running /home/XXX/.vscodium-server/bin/cea9d1a4b17966719d8c5f3cdd914480f7cec47c/bin/codium-server
633866061edccfea1c2a6668: start
exitCode==0==
listeningOn==40393==
connectionToken==a23e0418-385d-471a-9532-00a266e305ff==
logFile==/home/XXX/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log==
osReleaseId==alpine==
arch==x86_64==
platform==Linux==
tmpDir==/tmp==
633866061edccfea1c2a6668: end

[Trace  - 06:13:33.913] Creating forwarding server 46339(local) => 42419(socks) => 40393(remote)

which is new. This, i.e., the Creating forwarding server, persists after a retry.
The log contains:

Server bound to 127.0.0.1:40393 (IPv4)
Extension host agent listening on 40393

[05:56:35] Extension host agent started.

The command you suggested does not return but keeps on running.
echo $SERVER_LOGFILE returns nothing.

[jeanp413]

You need to replace $SERVER_LOGFILE with the actual file ~/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log as the env var is set in the whole script.

But from your logs I see it's now working successfully right? I see the port being detected and the tunnel created so you should see your files in vscode

633866061edccfea1c2a6668: start
exitCode==0==
listeningOn==40393==
connectionToken==a23e0418-385d-471a-9532-00a266e305ff==
logFile==/home/XXX/.vscodium-server/.cea9d1a4b17966719d8c5f3cdd914480f7cec47c.log==
osReleaseId==alpine==
arch==x86_64==
platform==Linux==
tmpDir==/tmp==
633866061edccfea1c2a6668: end

[Trace  - 06:13:33.913] Creating forwarding server 46339(local) => 42419(socks) => 40393(remote)

[gothicVI]

Oh I'm dumb lol - but yeah it wasn't working.
However, I couldn't see any files and continuously got asked for the 2FA.
I'll check again tomorrow after a reboot ;)

[jeanp413]

2FA logic runs before running the installation script so if the script run successfully exitCode==0== and tunnel got created then you shouldn't see any auth request afterwards.

[gothicVI]

I have a horrible suspicion...
Is the connection always taking place via a random port? It might be our firewall blocking the connection to be finally established as that specific machine is in another vlan than the other ones where things work fine by now...
Do you see a way to diagnose this quickly from within the extension?
SSHing onto the jumphost I can ping the remote and can also run telnet IP 22, i.e., ssh works as expected.
However, when replacing 22 with the port I get from the log, i.e., 44963 I'm getting a Connection timed out after some time.

In vscodium I'm continuously getting asked for 2FA authentication, then get the message that connection could not be established, the bottom left green indicator shows connected but opening a folder shows my local files.

I'll check with our networking team but this could be an issue on my end...
Anyhow, I'll write a pull request w.r.t. the necessary alpine packages...