TLS First Record Does Not Look like a Handshake

[jasonmerc]

When attempting to connect to the server from the client, I get the following message for every TCP port that I'm trying to forward:

Agent error "tls: first record does not look like a TLS handshake" - recovering...

I am running Debian 11 on the client and Debian 10 on the server. Both using the latest go 1.17 downloaded from the Go website.

Below are the config yml files for each

Server:

control_address: 0.0.0.0:16969 agents:

• auth_key: [hidden] ports: [80/tcp, 443/tcp, 43029/tcp, 10000/udp]

Client:

gateway_url: wss://server.ip.address:16969

auth_key: [hidden, but the EXACT same from the server as a copy/paste]

forwards:

• port: 80/tcp destination: 127.0.0.1:80

• port: 443/tcp destination: 127.0.0.1:443

• port: 43029/tcp destination: 127.0.0.1:22

Any guidance on how to fix this would be appreciated... or if it's a bug, take this as a bug report.

[jasonmerc]

I should mention too, if I try to mark the gateway_url as ws:// instead of wss:// I get the following on repeat on the client side:

2021/09/27 13:46:47 Listening on remote port: 43029/tcp 2021/09/27 13:46:47 Listening on remote port: 80/tcp 2021/09/27 13:46:47 Listening on remote port: 443/tcp 2021/09/27 13:46:53 Agent error "websocket: close 1008 (policy violation): error: accept tcp [::]:43029: use of closed network connection" - recovering... 2021/09/27 13:46:53 Agent error "websocket: close 1008 (policy violation): error: accept tcp [::]:80: use of closed network connection" - recovering... 2021/09/27 13:46:53 Agent error "websocket: close 1008 (policy violation): error: accept tcp [::]:443: use of closed network connection" - recovering... 2021/09/27 13:46:57 Listening on remote port: 443/tcp 2021/09/27 13:46:57 Listening on remote port: 43029/tcp 2021/09/27 13:46:58 Listening on remote port: 80/tcp

....and so on

The server side log looks like this on repeat:

{"time":"2021-09-27T17:48:27.175114514Z","level":"ERROR","prefix":"echo","file":"responder.go","line":"44","message":"accept tcp [::]:443: use of closed network connection"} {"time":"2021-09-27T17:48:27.314540036Z","level":"ERROR","prefix":"echo","file":"responder.go","line":"44","message":"accept tcp [::]:43029: use of closed network connection"} {"time":"2021-09-27T17:48:27.366915771Z","level":"ERROR","prefix":"echo","file":"responder.go","line":"44","message":"accept tcp [::]:80: use of closed network connection"} {"time":"2021-09-27T17:48:27.890365411Z","id":"","remote_ip":"104.38.56.28","host":"40.88.26.102:16969","method":"GET","uri":"/tcp/443","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":73101,"latency_human":"73.101µs","bytes_in":0,"bytes_out":0} {"time":"2021-09-27T17:48:28.077928324Z","id":"","remote_ip":"104.38.56.28","host":"40.88.26.102:16969","method":"GET","uri":"/tcp/80","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":77501,"latency_human":"77.501µs","bytes_in":0,"bytes_out":0} {"time":"2021-09-27T17:48:28.07851313Z","id":"","remote_ip":"104.38.56.28","host":"40.88.26.102:16969","method":"GET","uri":"/tcp/43029","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":41000,"latency_human":"41µs","bytes_in":0,"bytes_out":0}

....and so on

[snsinfu]

Currently I don't have enough free time to investigate this, but it looks like agent-to-server connections are broken due to timeout.

A technical note for future reference: The errors come from use of closed listener here. The listener could be closed due to websocket timeout caught here.