cloudflare / cloudflare/cloudflared
🐛 Better handling of orphaned lock files -- delay of auth when using cloudflared access
- Dominant language
- Go
- Stars
- 15.6k
- Forks
- 1.4k
- PR merge metrics
- No merged PRs in 30d
Description
## **Describe the bug**
When using VS Code to Remote SSH to a server behind Cloudflared, I sometimes get an extra ordinarily long delay between initiating the remote tunnel and then the Access approval page being popped in the default browser. Sometimes, this delay is so long, it happens minutes (i.e 15 minutes) after the connection was initiated, long after VS Code has failed.
The failure message is "The operation timed out." because the tunnel never gets established.
Obviously there's a lot of variables/components in the chain, but I've added the debug/trace output below if that reveals anything.
I've turned on Trace for the OpenSSH component and the Cloudflared log-level, however haven't found anything conclusive. It's like ProxyCommand is not sending any sort of packets which means Cloudflared doesn't trigger the browser? It also seems like a cascading failure in that subsequent attempts will also fail while the first is attempting to connect?
Unsure what else to gather in this scenario to help diagnosis.
## **To Reproduce**
Remote SSH using ProxyCommand as per Cloudflared documentation.
If it's an issue with Cloudflare Tunnel:
4. Tunnel ID :
5. cloudflared config:
## **Expected behavior**
No delay in popping Access approval page.
## **Environment and versions**
Occurs on both MacOS and Windows.
Multiple versions up to 2024.1.1.
## **Logs and errors**
VS Code:
```
[12:41:10.910] > local-server-1> Running ssh connection command: ssh -v -T -D 59269 -o ConnectTimeout=500 sshtest bash
[12:41:10.917] > local-server-1> Spawned ssh, pid=27413
[12:41:10.935] stderr> OpenSSH_9.6p1, OpenSSL 3.2.1 30 Jan 2024
[12:41:10.935] stderr> debug1: Reading configuration data /Users/jake/.ssh/config
[12:41:10.935] stderr> debug1: /Users/jake/.ssh/config line 7: Applying options for sshtest
[12:41:10.936] stderr> debug1: Reading configuration data /usr/local/etc/ssh/ssh_config
[12:41:10.937] stderr> debug1: Executing proxy command: exec /usr/local/bin/cloudflared access ssh --log-level debug --logfile ~/vscode-cloudflared.log --hostname mydomain.com
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_rsa type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_rsa-cert type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ecdsa type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ecdsa-cert type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ecdsa_sk type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ecdsa_sk-cert type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ed25519 type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ed25519-cert type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ed25519_sk type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_ed25519_sk-cert type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_xmss type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_xmss-cert type -1
[12:41:10.939] stderr> debug1: identity file /Users/jake/.ssh/id_dsa type -1
[12:41:10.940] stderr> debug1: identity file /Users/jake/.ssh/id_dsa-cert type -1
[12:41:10.940] stderr> debug1: Local version string SSH-2.0-OpenSSH_9.6
[12:44:56.677] stderr> A browser window should have opened at the following URL:
[12:44:56.678] stderr>
[12:44:56.678] stderr> https://mydomain.com/cloudflaredauthurl
[12:44:56.678] stderr>
[12:44:56.678] stderr> If the browser failed to open, please visit the URL above directly in your browser.
[12:45:00.671] stderr> debug1: Remote protocol version 2.0, remote software version OpenSSH_8.2p1 Ubuntu-4ubuntu0.11
[12:45:00.671] stderr> debug1: compat_banner: match: OpenSSH_8.2p1 Ubuntu-4ubuntu0.11 pat OpenSSH* compat 0x04000000
...
```
Cloudflared:
```
{"level":"debug","time":"2024-02-18T01:41:10Z","message":"Websocket request: GET / HTTP/1.1\r\nHost: mydomain.com\r\nUser-Agent: cloudflared/2024.1.1\r\n\r\n"}
{"level":"debug","time":"2024-02-18T01:45:00Z","message":"Access Websocket request: GET / HTTP/1.1\r\nHost: mydomain.com\r\nCf-Access-Token: token\r\nUser-Agent: cloudflared/2024.1.1\r\n\r\n"}
{"level":"debug","time":"2024-02-18T01:45:00Z","message":"Websocket response: \"HTTP/1.1 101 Switching Protocols\\r\\nAlt-Svc: h3=\\\":443\\\"; ma=86400\\r\\nCf-Cache-Status: DYNAMIC\\r\\nCf-Ray: rayid\\r\\nConnection: upgrade\\r\\nDate: Sun, 18 Feb 2024 01:45:00 GMT\\r\\nNel: {\\\"success_fraction\\\":0,\\\"report_to\\\":\\\"cf-nel\\\",\\\"max_age\\\":604800}\\r\\nReport-To: {\\\"endpoints\\\":[{\\\"url\\\":\\\"https:\\\\/\\\\/a.nel.cloudflare.com\\\\/report\\\\/v3?s=\\\"}],\\\"group\\\":\\\"cf-nel\\\",\\\"max_age\\\":604800}\\r\\nSec-Websocket-Accept: \\r\\nServer: cloudflare\\r\\nUpgrade: websocket\\r\\n\\r\\n\""}
{"level":"debug","time":"2024-02-18T01:45:34Z","message":"Websocket request: GET / HTTP/1.1\r\nHost: mydomain.com\r\nUser-Agent: cloudflared/2024.1.1\r\n\r\n"}
{"level":"debug","time":"2024-02-18T01:45:35Z","message":"Access Websocket request: GET / HTTP/1.1\r\nHost: mydomain.com\r\nCf-Access-Token: token\r\nUser-Agent: cloudflared/2024.1.1\r\n\r\n"}
{"level":"debug","time":"2024-02-18T01:45:35Z","message":"Websocket response: \"HTTP/1.1 101 Switching Protocols\\r\\nAlt-Svc: h3=\\\":443\\\"; ma=86400\\r\\nCf-Cache-Status: DYNAMIC\\r\\nCf-Ray: rayid\\r\\nConnection: upgrade\\r\\nDate: Sun, 18 Feb 2024 01:45:35 GMT\\r\\nNel: {\\\"success_fraction\\\":0,\\\"report_to\\\":\\\"cf-nel\\\",\\\"max_age\\\":604800}\\r\\nReport-To: {\\\"endpoints\\\":[{\\\"url\\\":\\\"https:\\\\/\\\\/a.nel.cloudflare.com\\\\/report\\\\/v3?s=\\\"}],\\\"group\\\":\\\"cf-nel\\\",\\\"max_age\\\":604800}\\r\\nSec-Websocket-Accept: \\r\\nServer: cloudflare\\r\\nUpgrade: websocket\\r\\n\\r\\n\""}
{"level":"debug","time":"2024-02-18T01:45:40Z","message":"Websocket request: GET / HTTP/1.1\r\nHost: mydomain.com\r\nUser-Agent: cloudflared/2024.1.1\r\n\r\n"}
{"level":"debug","time":"2024-02-18T01:45:40Z","message":"Access Websocket request: GET / HTTP/1.1\r\nHost: mydomain.com\r\nCf-Access-Token: token\r\nUser-Agent: cloudflared/2024.1.1\r\n\r\n"}
{"level":"debug","time":"2024-02-18T01:45:40Z","message":"Websocket response: \"HTTP/1.1 101 Switching Protocols\\r\\nAlt-Svc: h3=\\\":443\\\"; ma=86400\\r\\nCf-Cache-Status: DYNAMIC\\r\\nCf-Ray: rayid\\r\\nConnection: upgrade\\r\\nDate: Sun, 18 Feb 2024 01:45:40 GMT\\r\\nNel: {\\\"success_fraction\\\":0,\\\"report_to\\\":\\\"cf-nel\\\",\\\"max_age\\\":604800}\\r\\nReport-To: {\\\"endpoints\\\":[{\\\"url\\\":\\\"https:\\\\/\\\\/a.nel.cloudflare.com\\\\/report\\\\/v3?s=\\\"}],\\\"group\\\":\\\"cf-nel\\\",\\\"max_age\\\":604800}\\r\\nSec-Websocket-Accept: \\r\\nServer: cloudflare\\r\\nUpgrade: websocket\\r\\n\\r\\n\""}
```
## **Additional context**
Setting a ConnectTimeout=500 doesn't really do much except sometimes allow the unusual delay to finish though it's often longer than this up to 15 minutes.
Contributor guide
Assessment
This issue has not been assessed yet.