Dial logs

[deansheather]

Adds optional debug logging to Dial

$ CODER_TUNNEL_DEBUG=true go run ./cmd/coder tunnel dean-c 8081 8081
2021-07-24 06:34:31.617 [INFO]  <tunnel.go:39>  debug logging enabled
2021-07-24 06:34:34.346 [DEBUG] <tunnel.go:110> Connecting to workspace...
2021-07-24 06:34:34.346 [DEBUG] (wsnet) <dial.go:57>    connecting to broker    {"broker": "wss://master.cdr.dev/api/private/envagent/xxx/connect?session_token=xxx"}
2021-07-24 06:34:34.927 [DEBUG] (wsnet) <dial.go:68>    connected to broker
2021-07-24 06:34:34.927 [DEBUG] (wsnet) <dial.go:101>   creating peer connection        {"options": "\u0026{Log:0xc0003c22a0 ICEServers:[{URLs:[turn:127.0.0.1:3478?transport=tcp] Username:~magicalusername~ Credential:~magicalusername~ CredentialType:password}] TURNProxyAuthToken:xxx TURNProxyURL:https://master.cdr.dev}", "turn_proxy": "\u0026{baseURL:xxx token:xxx}"}
2021-07-24 06:34:34.929 [DEBUG] (wsnet) <dial.go:106>   created peer connection
2021-07-24 06:34:34.929 [DEBUG] (wsnet) <dial.go:113>   creating control channel        {"proto": "control"}
2021-07-24 06:34:34.930 [DEBUG] (wsnet) <dial.go:126>   created offer   {"offer": {"type": "offer", "sdp": "xxx"}}
2021-07-24 06:34:34.930 [DEBUG] (wsnet) <dial.go:142>   sending offer message   {"msg": {"offer": {"type": "offer", "sdp": "xxx"}, "servers": [{"urls": ["turn:127.0.0.1:3478?transport=tcp"], "username": "~magicalusername~", "credential": "~magicalusername~"}], "turn_proxy_url": "https://master.cdr.dev", "ports": null, "error": "", "answer": null, "candidate": ""}}
2021-07-24 06:34:34.932 [DEBUG] (wsnet) <dial.go:221>   beginning negotiation
2021-07-24 06:34:35.308 [DEBUG] (wsnet) <dial.go:231>   got message from handshake conn {"msg": {"offer": null, "servers": null, "turn_proxy_url": "", "ports": null, "error": "", "answer": {"type": "answer", "sdp": "xxx"}, "candidate": ""}}
2021-07-24 06:34:35.308 [DEBUG] (wsnet) <dial.go:251>   received answer {"a": {"type": "answer", "sdp": "xxx"}}
2021-07-24 06:34:36.261 [DEBUG] (wsnet) <dial.go:231>   got message from handshake conn {"msg": {"offer": null, "servers": null, "turn_proxy_url": "", "ports": null, "error": "", "answer": null, "candidate": "xxx"}}
2021-07-24 06:34:36.262 [DEBUG] (wsnet) <dial.go:242>   adding remote ICE candidate     {"c": {"candidate": "xxx", "sdpMid": null, "sdpMLineIndex": null, "usernameFragment": null}}
2021-07-24 06:34:38.121 [DEBUG] (wsnet) <dial.go:344>   opening data channel    {"proto": "tcp:localhost:8081"}
2021-07-24 06:34:38.678 [DEBUG] (wsnet) <dial.go:363>   data channel opened     {"proto": "tcp:localhost:8081", "dc_id": 3}
2021-07-24 06:34:38.678 [DEBUG] (wsnet) <dial.go:369>   data channel detached   {"proto": "tcp:localhost:8081", "dc_id": 3}
2021-07-24 06:34:39.050 [DEBUG] (wsnet) <dial.go:382>   dial response   {"proto": "tcp:localhost:8081", "dc_id": 3, "res": "{Code:dial_error Err:dial tcp 127.0.0.1:8081: connect: connection refused Net:tcp Op:dial}"}
fatal: running tunnel: dial tcp: dial tcp 127.0.0.1:8081: connect: connection refused

exit status 1

[CH-15414]

[shortcut-integration]

This pull request has been linked to Clubhouse Story #15414: Add logging to wsnet dial.

[kylecarbs]

I'm good with this being internal, but I'd prefer if we implemented a LOG_LEVEL environment variable in slog longer-term.