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

[Remote-SSH Bug]:

Open tinodj opened this issue 1 year ago • 4 comments

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

->

exactly the same.

Expected Behavior

I expect this to work.

Steps To Reproduce

When connecting to remote linux machine, some strange things are happening. This part is not open source, so it is also hard to debug.

VS Code goes in cycles and reopens and retries to remote connect.

I also read here https://github.com/microsoft/vscode/issues/129483#issuecomment-903696828 a question whether this Windows is under domain, yes, this Windows is under domain and is configured by company IT department. It is also a virtual machine.

WebSocket close with status code 1006

Remote-SSH Log

Remote-SSH Log

2024-08-07 23:23:14.597 [info] Extension host terminating: renderer closed the MessagePort
2024-08-07 23:23:14.627 [error] Canceled: Canceled
	at MessagePortMain._internalPort.emit (node:electron/js2c/utility_init:2:2285) setContext undefined
2024-08-07 23:23:14.627 [info] Extension host with pid 41460 exiting with code 0
2024-08-07 23:23:15.886 [info] Extension host with pid 56416 started
2024-08-07 23:23:15.886 [info] [resolveAuthority(ssh-remote,1)][0ms] activating remote resolvers ssh-remote+hostname
2024-08-07 23:23:15.886 [info] [resolveAuthority(ssh-remote,1)][0ms] activating resolver for ssh-remote+hostname...
2024-08-07 23:23:15.891 [info] ExtensionService#_doActivateExtension ms-vscode-remote.remote-ssh, startup: false, activationEvent: 'onResolveRemoteAuthority:ssh-remote'
2024-08-07 23:23:15.924 [info] [resolveAuthority(ssh-remote,1)][41ms] invoking final resolve()...
2024-08-07 23:23:16.925 [info] [resolveAuthority(ssh-remote,1)][1042ms] waiting...
2024-08-07 23:23:17.926 [info] [resolveAuthority(ssh-remote,1)][2043ms] waiting...
2024-08-07 23:24:35.668 [info] [resolveAuthority(ssh-remote,1)][79786ms] setting tunnel factory...
2024-08-07 23:24:35.669 [info] [resolveAuthority(ssh-remote,1)][79787ms] returned 127.0.0.1:20828
2024-08-07 23:24:36.688 [info] [resolveAuthority(ssh-remote,2)][0ms] activating remote resolvers ssh-remote+hostname
2024-08-07 23:24:36.688 [info] [resolveAuthority(ssh-remote,2)][0ms] activating resolver for ssh-remote+hostname...
2024-08-07 23:24:36.688 [info] [resolveAuthority(ssh-remote,2)][1ms] invoking final resolve()...
2024-08-07 23:24:37.698 [info] [resolveAuthority(ssh-remote,2)][1011ms] waiting...
[23:23:15.943] VS Code version: 1.92.0
[23:23:15.943] Remote-SSH version: [email protected]
[23:23:15.943] win32 x64
[23:23:15.957] SSH Resolver called for host: hostname
[23:23:15.957] Setting up SSH remote "hostname"
[23:23:15.963] Using commit id "b1c0a14de1414fcdaa400695b4db1c0799bc3124" and quality "stable" for server
[23:23:15.971] Install and start server if needed
[23:24:28.246] Remote server is listening on port 34398
[23:24:28.246] Parsed server configuration: {"serverConfiguration":{"remoteListeningOn":{"port":34398},"osReleaseId":"rhel","arch":"x86_64","webUiAccessToken":"","sshAuthSock":"","display":"","tmpDir":"/run/user/xxx","platform":"linux","connectionToken":"111a111a-11a1-11a1-11a1-1a1111aa1a1a"},"serverStartTime":76,"installUnpackCode":""}
[23:24:28.251] Starting forwarding server. local port 20828 -> socksPort 20971 -> remotePort 34398
[23:24:28.254] Forwarding server listening on port 20828
[23:24:28.254] Waiting for ssh tunnel to be ready
[23:24:35.660] Tunneled port 34398 to local port 20828
[23:24:35.661] Resolved "ssh-remote+hostname" to "port 20828"
[23:24:35.662] Updating terminal environments: {}
[23:24:35.665] TELEMETRY: {"eventName":"resolver","properties":{"osReleaseId":"rhel","arch":"x86_64","askedPw":"0","askedPassphrase":"0","asked2fa":"0","askedHostKey":"0","remoteInConfigFile":"1","gotUnrecognizedPrompt":"0","dynamicForwarding":"1","localServer":"0","didLocalDownload":"0","installUnpackCode":"0","outcome":"success"},"measures":{"resolveAttempts":1,"retries":1,"isExecServer":0,"timing.totalResolveTime":79742,"timing.preSshTime":57850,"timing.establishSshTime":14338,"timing.scriptTime":14472,"timing.serverStartTime":76}}
[23:24:35.668] ------
2024-08-07 23:23:15.071 [info] Invoking resolveAuthority(ssh-remote)...
2024-08-07 23:23:15.071 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][0ms] obtaining proxy...
2024-08-07 23:23:15.378 [info] Started local extension host with pid 56416.
2024-08-07 23:23:15.856 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][781ms] invoking...
2024-08-07 23:23:16.854 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][1783ms] waiting...
2024-08-07 23:24:35.680 [info] [LocalProcess0][resolveAuthority(ssh-remote,1)][80609ms] returned WebSocket(127.0.0.1:20828)
2024-08-07 23:24:35.681 [info] resolveAuthority(ssh-remote) returned 'WebSocket(127.0.0.1:20828)' after 80610 ms
2024-08-07 23:24:35.681 [info] Creating a socket (renderer-Management-8136a894-40e8-4ebc-94c4-5cab2e5e521f)...
2024-08-07 23:24:35.682 [info] Creating a socket (renderer-ExtensionHost-6730836b-c508-4bda-8557-16a4bcdcc793)...
2024-08-07 23:24:36.685 [info] Creating a socket (renderer-Management-8136a894-40e8-4ebc-94c4-5cab2e5e521f) returned an error after 1003 ms.
2024-08-07 23:24:36.685 [error] CodeExpectedError: WebSocket close with status code 1006
    at WebSocket.<anonymous> (vscode-file://vscode-app/c:/Users/user/AppData/Local/Programs/Microsoft%20VS%20Code/resources/app/out/vs/workbench/workbench.desktop.main.js:694:4132)
2024-08-07 23:24:36.685 [error] [remote-connection][Management   ][8136a…][initial][WebSocket(127.0.0.1:20828)] socketFactory.connect() failed or timed out. Error:
2024-08-07 23:24:36.686 [error] CodeExpectedError: WebSocket close with status code 1006

Anything else?

No response

tinodj avatar Aug 07 '24 21:08 tinodj

Something is messing with the network connection, probably from the corporate configuration, and I don't know that I'll be able to get to the bottom of it. Can you check for other error messages though?

  • F1 > Set Log Level > Trace
  • Repro the issue and check the dev tools console for errors (Help > Toggle Developer Tools)

roblourens avatar Aug 07 '24 22:08 roblourens

@roblourens thank you for engaging. I will do everything I can to get to the bottom of this.

  • I have tried trace but it add nothing :( I will try tomorrow once more.

  • I did developer tools and errors there, were the same as my last block of errors in the original message above. But will try tomorrow this part once again.

tinodj avatar Aug 07 '24 23:08 tinodj

Hmmm, I might find the issue. Starting this from command prompt:

"C:\Windows\System32\OpenSSH\ssh.exe" -T -D 20864 -F "C:\Users\user\.ssh\config" "hostname" bash

doesn't guarantee this port will be opened. For example now, I run this, and port opened was 20948 instead of 20864. So after running this port should be obtained somehow. I tried -D 0, doesn't work for me.

Do you have any suggestions/workaround, now when we know where the problem is?

Thank you!

Here is the log anyway:

 INFO [LocalProcess0][resolveAuthority(ssh-remote,1)][50362ms] waiting...
log.ts:399 TRACE CommandService#executeCommand _setContext
log.ts:419  INFO [LocalProcess0][resolveAuthority(ssh-remote,1)][50686ms] returned WebSocket(127.0.0.1:20826)
log.ts:419  INFO resolveAuthority(ssh-remote) returned 'WebSocket(127.0.0.1:20826)' after 50688 ms
log.ts:399 TRACE ForwardedPorts: Doing first restore.
log.ts:409 DEBUG Could not get workspace hash for forwarded ports storage key.
log.ts:399 TRACE [remote-connection][Management   ][6f2ad…][initial][WebSocket(127.0.0.1:20826)] 1/6. invoking socketFactory.connect().
log.ts:419  INFO Creating a socket (renderer-Management-6f2adb33-97f1-40d0-ae0e-f4103bd0b65d)...
log.ts:399 TRACE [remote-connection][ExtensionHost][7690c…][initial][WebSocket(127.0.0.1:20826)] 1/6. invoking socketFactory.connect().
log.ts:419  INFO Creating a socket (renderer-ExtensionHost-7690c0f6-5f70-43e7-8c1e-438c010a2a0a)...
browserSocketFactory.ts:80 WebSocket connection to 'ws://127.0.0.1:20826/stable-b1c0a14de1414fcdaa400695b4db1c0799bc3124?reconnectionToken=6f2adb33-97f1-40d0-ae0e-f4103bd0b65d&reconnection=false&skipWebSocketFrames=false' failed: 
v @ browserSocketFactory.ts:80
create @ browserSocketFactory.ts:204
(anonymous) @ browserSocketFactory.ts:284
connect @ browserSocketFactory.ts:282
connect @ remoteSocketFactoryService.ts:58
r @ remoteAgentConnection.ts:191
o @ remoteAgentConnection.ts:235
b @ remoteAgentConnection.ts:322
m @ remoteAgentConnection.ts:344
(anonymous) @ remoteAgentConnection.ts:418
P @ remoteAgentConnection.ts:444
log.ts:419  INFO Creating a socket (renderer-Management-6f2adb33-97f1-40d0-ae0e-f4103bd0b65d) returned an error after 1003 ms.
log.ts:439   ERR CodeExpectedError: WebSocket close with status code 1006
    at WebSocket.<anonymous> (browserSocketFactory.ts:166:20)
log.ts:439   ERR [remote-connection][Management   ][6f2ad…][initial][WebSocket(127.0.0.1:20826)] socketFactory.connect() failed or timed out. Error:
log.ts:439   ERR CodeExpectedError: WebSocket close with status code 1006
    at WebSocket.<anonymous> (browserSocketFactory.ts:166:20)
log.ts:439   ERR [remote-connection][attempt 1] An error occurred in initial connection! Will retry... Error:
log.ts:439   ERR CodeExpectedError: WebSocket close with status code 1006
    at WebSocket.<anonymous> (browserSocketFactory.ts:166:20)
log.ts:419  INFO Invoking resolveAuthority(ssh-remote)...
log.ts:419  INFO [LocalProcess0][resolveAuthority(ssh-remote,2)][0ms] obtaining proxy...
log.ts:419  INFO [LocalProcess0][resolveAuthority(ssh-remote,2)][1ms] invoking...
log.ts:399 TRACE CommandService#executeCommand _setContext
log.ts:419  INFO [LocalProcess0][resolveAuthority(ssh-remote,2)][1002ms] waiting...
browserSocketFactory.ts:80 WebSocket connection to 'ws://127.0.0.1:20826/stable-b1c0a14de1414fcdaa400695b4db1c0799bc3124?reconnectionToken=7690c0f6-5f70-43e7-8c1e-438c010a2a0a&reconnection=false&skipWebSocketFrames=false' failed: 
v @ browserSocketFactory.ts:80
create @ browserSocketFactory.ts:204
(anonymous) @ browserSocketFactory.ts:284
connect @ browserSocketFactory.ts:282
connect @ remoteSocketFactoryService.ts:58
r @ remoteAgentConnection.ts:191
o @ remoteAgentConnection.ts:235
b @ remoteAgentConnection.ts:322
w @ remoteAgentConnection.ts:362
(anonymous) @ remoteAgentConnection.ts:428
P @ remoteAgentConnection.ts:444
log.ts:419  INFO Creating a socket (renderer-ExtensionHost-7690c0f6-5f70-43e7-8c1e-438c010a2a0a) returned an error after 2030 ms.
log.ts:439   ERR CodeExpectedError: WebSocket close with status code 1006
    at WebSocket.<anonymous> (browserSocketFactory.ts:166:20)
log.ts:439   ERR [remote-connection][ExtensionHost][7690c…][initial][WebSocket(127.0.0.1:20826)] socketFactory.connect() failed or timed out. Error:
log.ts:439   ERR CodeExpectedError: WebSocket close with status code 1006
    at WebSocket.<anonymous> (browserSocketFactory.ts:166:20)
log.ts:439   ERR [remote-connection][attempt 1] An error occurred in initial connection! Will retry... Error:
log.ts:439   ERR CodeExpectedError: WebSocket close with status code 1006
    at WebSocket.<anonymous> (browserSocketFactory.ts:166:20)
log.ts:419  INFO [LocalProcess0][resolveAuthority(ssh-remote,2)][2002ms] waiting...

tinodj avatar Aug 08 '24 09:08 tinodj

was additional info any helpful @roblourens ?

tinodj avatar Aug 23 '24 14:08 tinodj

Hey @roblourens @joshspicer, this issue might need further attention.

@tinodj, you can help us out by closing this issue if the problem no longer exists, or adding more information.

Oh, I am sorry for not commenting earlier, we solved this around 6 weeks ago. The problem was Palo Alto Terminal Services or Terminal Server (TS) Palo Alto, as explained here:

https://learn.microsoft.com/en-us/answers/questions/154579/listening-port-is-being-replaced-automatically-by

Thank you for your help and the reminder!

tinodj avatar Dec 22 '24 16:12 tinodj