Cant connecti after update from 1.54 to 1.57

Support / Troubleshooting
1

I’m deploying using Docker in and Windows Server. We were working with 1.54 without problem. After updating from 1.54 to 1.56, the connector presented intermittent connection, and after updating to 1.57 the connector stays offline.

2

Hi Ivan,

What version of Windows Server are you running?

Is there any obvious errors in your Twingate Connector Logs that might indicate what’s going on?

If you deploy a brand new connector using 1.57 does it also fail to connect or does it work as expected?

-arthur

3

We are using Windows Server 2019 and a brand new deployment.
Where can i find the logs in Windows ?

4

You would need to set your container to Debug level Logging andpull them from the Docker container itself as per the Docker Container section of the page I linked.

5

After update Docker and Windows, for connector 1.56.0 connection is back (time offset = -6s), with version 1.57.0 nothing yet.

Log for 1.57.0

2023-08-03 15:09:48 State: Offline
2023-08-03 15:09:48 State: Authentication
2023-08-03 15:20:56 State: Offline
2023-08-03 15:20:56 State: Authentication
2023-08-03 15:20:57 State: Error
2023-08-03 15:21:32 State: Offline
2023-08-03 15:21:32 State: Authentication
2023-08-03 15:21:32 State: Error
2023-08-03 15:21:53 State: Offline
2023-08-03 15:22:34 State: Offline
2023-08-03 15:22:34 State: Authentication
2023-08-03 15:22:34 State: Error
2023-08-03 15:22:51 State: Offline
2023-08-03 15:22:51 State: Authentication
2023-08-03 15:22:51 State: Error
2023-08-03 15:23:15 State: Offline
2023-08-03 15:23:15 State: Authentication
2023-08-03 15:23:15 State: Error
2023-08-03 15:29:42 State: Offline
2023-08-03 15:29:42 State: Authentication
2023-08-03 15:29:43 State: Error
2023-08-03 15:29:45 State: Offline
2023-08-03 15:29:45 State: Authentication
2023-08-03 15:29:45 State: Error
2023-08-03 15:31:36 State: Offline
2023-08-03 15:31:36 State: Authentication
2023-08-03 15:31:37 State: Error
2023-08-03 15:31:41 State: Offline
2023-08-03 15:32:24 State: Offline
2023-08-03 15:32:24 State: Authentication
2023-08-03 15:32:24 State: Error
2023-08-03 15:32:30 State: Offline
2023-08-03 15:32:30 State: Authentication
2023-08-03 15:32:31 State: Error
2023-08-03 15:33:26 State: Offline
2023-08-03 15:33:26 State: Authentication
2023-08-03 15:33:27 State: Error
6

Hey Ivan,

You’ll need to put the container in Debug mode (with the ENV Var TWINGATE_LOG_LEVEL=7 set on the container for the logs to have the debug messages which should hopefully tell us more than the basic logs.

Thanks!

7

In a new connector with 1.57.0 adding –env TWINGATE_LOG_LEVEL=7, the state goes to online, but did’t last long.

This is the log with the debug messages.


2023-08-03 16:49:17 [INFO] [connector] starting crash reporting service
2023-08-03 16:49:17 [INFO] [connector] initializing sdwan
2023-08-03 16:49:17 [DEBUG] [libsdwan] sdwan_new() config: {"controller":{"mode":"access","url":"https://dautom.twingate.com","type":"enterprise","app_version":"1.57.0"},"modules":{"viper":{"nat":{"log-level":"DEBUG"},"dns-proxy":{"enable-netbios":1,"proxy-rules":[{"type":"bypass","route_id":0,"default":1}]},"generic-proxy":{"session-table-size":"1024","proxy-rules":[{"type":"bypass","route_id":0,"default":1}],"plugin-chain":[{"name":"gnrprx"}]}},"tranceport":{"ssl":{"ciphers":"ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384","curves":"P-256:P-384:P-521","sigalgs":"ECDSA+SHA256:ECDSA+SHA384:ECDSA+SHA512:RSA+SHA256:RSA+SHA384:RSA+SHA512:RSA-PSS+SHA256:RSA-PSS+SHA384:RSA-PSS+SHA512","server_auth":0,"client_auth":0},"dequeue":1,"dequeue_r":0,"enqueue":3,"enqueue_r":0,"reorder_stats":100,"vlink_idle_time":10,"frontend":{"flush":1,"flush_type":1,"max_queue":65536,"pools":[{"impl":"local","id":3,"link":"bev_http","connect_str":1},{"impl":"local","id":5,"link":"bev_tcp"},{"impl":"local","id":6,"link":"bev_udp"}]},"backend":{"flush":1,"flush_type":1,"max_queue":65536,"pools":[{"impl":"local","id":6,"link":"udp_proxy"},{"id":10,"impl":"local","link":"tcp_proxy","https_skipencrypt":1},{"impl":"local","id":8,"link":"packet"}]}}},"sdwan":{"loglevel":7,"loglevel_console":-1,"ca_path":null,"timestamp_fmt":0,"log_analytics":"v2"},"afvpn":{"dns":null}}
2023-08-03 16:49:17 [DEBUG] [libsdwan] crypto_module_load_ca: loaded 2 trusted certificates from "default"
2023-08-03 16:49:17 [DEBUG] [libsdwan] crypto_module_new: available cipher suites:"ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384", curves: "P-256:P-384:P-521"
2023-08-03 16:49:17 [DEBUG] [libsdwan] forced expiration of the access tokens
2023-08-03 16:49:17 [DEBUG] [libsdwan] operator(): twingate_label_hostname=WIN-C9J1U8PLJ5O
2023-08-03 16:49:17 [DEBUG] [libsdwan] [quic] init: new instance
2023-08-03 16:49:17 [DEBUG] [libsdwan] [quic] on_accept: enabling server
2023-08-03 16:49:17 [DEBUG] [libsdwan] reconfigure_direct_connect_socket: set the size of UDP socket buffers to 4194304 bytes
2023-08-03 16:49:17 [DEBUG] [libsdwan] reconfigure_direct_connect_socket: reconfigured direct connect socket
2023-08-03 16:49:17 [INFO] [libsdwan] sdwan_new: libsdwan_version=0.146.0, app_version=1.57.0, platform=Linux-x86_64
2023-08-03 16:49:17 [INFO] [libsdwan] sdwan_state: Offline
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] run_state_machine: Offline
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] set_state: switching from "Offline" to "Getting public keys"
2023-08-03 16:49:17 [INFO] [libsdwan] sdwan_state: Authenticating
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] get_controller_keys: fetching controller public keys...
2023-08-03 16:49:17 [DEBUG] [libsdwan] send: sending HTTP request 13094937367510418538
2023-08-03 16:49:17 [DEBUG] [libsdwan] http::request::send_request: GET "https://dautom.twingate.com/api/v1/public_keys" text/plain
2023-08-03 16:49:17 [INFO] [connector] started server on /connector.sock
2023-08-03 16:49:17 [DEBUG] [libsdwan] http::response::from: certificate 3452c42ec6bef8f100225c8c21b31fec4dabe9dec8d0a5f4e45a4302a4108c16, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=*.twingate.com
2023-08-03 16:49:17 [DEBUG] [libsdwan] http::request::handle_response: GET "https://dautom.twingate.com/api/v1/public_keys" 200 OK (duration 0 sec)
2023-08-03 16:49:17 [DEBUG] [libsdwan] operator(): got HTTP request 13094937367510418538 successful response
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] set_state: switching from "Getting public keys" to "Got public keys"
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] run_state_machine: Got public keys
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] set_state: switching from "Got public keys" to "Authenticating"
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] set_state: switching from "Authenticating" to "Authenticated"
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] run_state_machine: Authenticated
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] set_state: switching from "Authenticated" to "Getting SD"
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] get_sd: getting SD
2023-08-03 16:49:17 [DEBUG] [libsdwan] [controller] require_access_token: dat.expired
2023-08-03 16:49:17 [DEBUG] [libsdwan] send: sending HTTP request 11795832307097519680
2023-08-03 16:49:17 [DEBUG] [libsdwan] http::request::send_request: POST "https://dautom.twingate.com/api/v5/connector/refresh" application/json
2023-08-03 16:49:18 [DEBUG] [libsdwan] http::response::from: certificate 3452c42ec6bef8f100225c8c21b31fec4dabe9dec8d0a5f4e45a4302a4108c16, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=*.twingate.com
2023-08-03 16:49:18 [DEBUG] [libsdwan] http::request::handle_response: POST "https://dautom.twingate.com/api/v5/connector/refresh" 200 OK (duration 1 sec)
2023-08-03 16:49:18 [DEBUG] [libsdwan] operator(): got HTTP request 11795832307097519680 successful response
2023-08-03 16:49:18 [DEBUG] [libsdwan] [controller] verify_token: {"alg":"ES256","kid":"Uo1vPcMAp9s0SiznE1mDc6WoWZc00Axy1xTCPHAfysM","typ":"DAT"} {"nt":"AN","aid":"126278","did":"841386","jti":"e013b50b-bc62-45e4-93a4-0849297784de","iss":"twingate","aud":"dautom","exp":1691102964,"iat":1691099364,"ver":"4","tid":"27960","rnw":1691099664,"rnetid":"35054"}
2023-08-03 16:49:18 [WARNING] [libsdwan] [controller] parse_verify_token: token verification failed: token expired
2023-08-03 16:49:18 [WARNING] [libsdwan] [controller] operator(): failed to get SD: Invalid token, err code 1
2023-08-03 16:49:19 [DEBUG] [libsdwan] [controller] get_sd: getting SD
2023-08-03 16:49:19 [DEBUG] [libsdwan] [controller] require_access_token: dat.expired
2023-08-03 16:49:19 [DEBUG] [libsdwan] send: sending HTTP request 11795832307097519680
2023-08-03 16:49:19 [DEBUG] [libsdwan] http::request::send_request: POST "https://dautom.twingate.com/api/v5/connector/refresh" application/json
2023-08-03 16:49:20 [DEBUG] [libsdwan] http::response::from: certificate 3452c42ec6bef8f100225c8c21b31fec4dabe9dec8d0a5f4e45a4302a4108c16, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=*.twingate.com
2023-08-03 16:49:20 [DEBUG] [libsdwan] http::request::handle_response: POST "https://dautom.twingate.com/api/v5/connector/refresh" 200 OK (duration 1 sec)
2023-08-03 16:49:20 [DEBUG] [libsdwan] operator(): got HTTP request 11795832307097519680 successful response
2023-08-03 16:49:20 [DEBUG] [libsdwan] [controller] verify_token: {"alg":"ES256","kid":"Uo1vPcMAp9s0SiznE1mDc6WoWZc00Axy1xTCPHAfysM","typ":"DAT"} {"nt":"AN","aid":"126278","did":"841386","jti":"b7a570f4-2390-41cb-b915-20df1aa82245","iss":"twingate","aud":"dautom","exp":1691102965,"iat":1691099365,"ver":"4","tid":"27960","rnw":1691099665,"rnetid":"35054"}
2023-08-03 16:49:20 [DEBUG] [libsdwan] [controller] process_access_tokens: scheduling DAT update in 298 seconds
2023-08-03 16:49:20 [DEBUG] [libsdwan] send: sending HTTP request 3805263700693825276
2023-08-03 16:49:20 [DEBUG] [libsdwan] http::request::send_request: POST "https://dautom.twingate.com/api/v4/connector/sd" text/plain
2023-08-03 16:49:20 [DEBUG] [libsdwan] http::response::from: certificate 3452c42ec6bef8f100225c8c21b31fec4dabe9dec8d0a5f4e45a4302a4108c16, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=*.twingate.com
2023-08-03 16:49:20 [DEBUG] [libsdwan] http::request::handle_response: POST "https://dautom.twingate.com/api/v4/connector/sd" 200 OK (duration 0 sec)
2023-08-03 16:49:20 [DEBUG] [libsdwan] operator(): got HTTP request 3805263700693825276 successful response
2023-08-03 16:49:20 [DEBUG] [libsdwan] [controller] verify_token: {"alg":"ES256","kid":"Uo1vPcMAp9s0SiznE1mDc6WoWZc00Axy1xTCPHAfysM","typ":"SD"} {"nt":"AN","aid":"126278","did":"841386","jti":"dcaf8811-3a34-4e7d-84cd-2c5878a99eb3","iss":"twingate","aud":"dautom","exp":1691358566,"iat":1691099366,"ver":"4","tid":"27960","rnw":1691099666,"rnetid":"35054","sd":{"last_updated_at":1691099230688,"authz_version":"0.1.743354","network":{"id":"27960","name":"Dautom","slug":"dautom","admin_url":"https://dautom.twingate.com","stun_discovery_url":"https://relays.twingate.com","analytics_url":"https://analytics.twingate.com","feature_flags":{"wildcard_matching_v2":false,"local_direct_connect":false},"templates":{"admin_resource":"{{admin_url}}/resources/{{global_id}}"}},"logging":{"allow_analytics":true},"resources":[{"id":"2246330","name":"CPW PASS","global_id":"UmVzb3VyY2U6MjI0NjMzMA==","type":"ip","address":"10.10.2.200","aliases":[{"name":"cpw.pass","url":"http://cpw.pass"}],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":"http://10.10.2.200","is_range":false,"is_visible_in_client":true,"can_open_in_browser":true,"is_favorite":false},{"id":"2255110","name":"CPW Deif","global_id":"UmVzb3VyY2U6MjI1NTExMA==","type":"ip","address":"10.10.2.100","aliases":[{"name":"cpw.deif","url":"http://cpw.deif"}],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":"http://10.10.2.100","is_range":false,"is_visible_in_client":true,"can_open_in_browser":false,"is_favorite":false},{"id":"__local1","name":"Local 1","global_id":"","type":"ip","address":"192.168.0.0/16","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local2","name":"Local 2","global_id":"","type":"ip","address":"127.0.0.0/8","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local3","name":"Local 3","global_id":"","type":"ip","address":"10.0.0.0/8","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local4","name":"Local 4","global_id":"","type":"ip","address":"172.16.0.0/12","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false}],"device":{"id":"126278","name":"scarlet-rhino","type":"Device"},"timeouts":{"max_idle_timeout_seconds":60},"connector":{"name":"scarlet-rhino","relay":{"address":"relaybalancer+https://relays.twingate.com","max_endpoints":4},"remote_network":{"id":"35054","name":"Dautom HQ","connection_mode":"ANY"},"matches":["2246330","2255110","__local1","__local2","__local3","__local4"],"heartbeat_interval_seconds":60}}}
2023-08-03 16:49:20 [WARNING] [libsdwan] [controller] parse_verify_token: token verification failed: token expired
2023-08-03 16:49:20 [WARNING] [libsdwan] [controller] operator(): failed to get SD: Invalid token, err code 5
2023-08-03 16:49:23 [DEBUG] [libsdwan] [controller] get_sd: getting SD
2023-08-03 16:49:23 [DEBUG] [libsdwan] send: sending HTTP request 3805263700693825276
2023-08-03 16:49:23 [DEBUG] [libsdwan] http::request::send_request: POST "https://dautom.twingate.com/api/v4/connector/sd" text/plain
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::response::from: certificate 3452c42ec6bef8f100225c8c21b31fec4dabe9dec8d0a5f4e45a4302a4108c16, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=*.twingate.com
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::handle_response: POST "https://dautom.twingate.com/api/v4/connector/sd" 200 OK (duration 1 sec)
2023-08-03 16:49:24 [DEBUG] [libsdwan] operator(): got HTTP request 3805263700693825276 successful response
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] verify_token: {"alg":"ES256","kid":"Uo1vPcMAp9s0SiznE1mDc6WoWZc00Axy1xTCPHAfysM","typ":"SD"} {"nt":"AN","aid":"126278","did":"841386","jti":"1ffac552-5cc8-41b9-9867-e5efb2e9aeff","iss":"twingate","aud":"dautom","exp":1691358569,"iat":1691099369,"ver":"4","tid":"27960","rnw":1691099669,"rnetid":"35054","sd":{"last_updated_at":1691099230688,"authz_version":"0.1.743354","network":{"id":"27960","name":"Dautom","slug":"dautom","admin_url":"https://dautom.twingate.com","stun_discovery_url":"https://relays.twingate.com","analytics_url":"https://analytics.twingate.com","feature_flags":{"wildcard_matching_v2":false,"local_direct_connect":false},"templates":{"admin_resource":"{{admin_url}}/resources/{{global_id}}"}},"logging":{"allow_analytics":true},"resources":[{"id":"2246330","name":"CPW PASS","global_id":"UmVzb3VyY2U6MjI0NjMzMA==","type":"ip","address":"10.10.2.200","aliases":[{"name":"cpw.pass","url":"http://cpw.pass"}],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":"http://10.10.2.200","is_range":false,"is_visible_in_client":true,"can_open_in_browser":true,"is_favorite":false},{"id":"2255110","name":"CPW Deif","global_id":"UmVzb3VyY2U6MjI1NTExMA==","type":"ip","address":"10.10.2.100","aliases":[{"name":"cpw.deif","url":"http://cpw.deif"}],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":"http://10.10.2.100","is_range":false,"is_visible_in_client":true,"can_open_in_browser":false,"is_favorite":false},{"id":"__local1","name":"Local 1","global_id":"","type":"ip","address":"192.168.0.0/16","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local2","name":"Local 2","global_id":"","type":"ip","address":"127.0.0.0/8","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local3","name":"Local 3","global_id":"","type":"ip","address":"10.0.0.0/8","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local4","name":"Local 4","global_id":"","type":"ip","address":"172.16.0.0/12","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false}],"device":{"id":"126278","name":"scarlet-rhino","type":"Device"},"timeouts":{"max_idle_timeout_seconds":60},"connector":{"name":"scarlet-rhino","relay":{"address":"relaybalancer+https://relays.twingate.com","max_endpoints":4},"remote_network":{"id":"35054","name":"Dautom HQ","connection_mode":"ANY"},"matches":["2246330","2255110","__local1","__local2","__local3","__local4"],"heartbeat_interval_seconds":60}}}
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] set_state: switching from "Getting SD" to "Applying SD"
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] process_sd_token: applying a new heartbeat interval: 60 seconds
2023-08-03 16:49:24 [INFO] [libsdwan] sd: {"nt":"AN","aid":"126278","did":"841386","jti":"1ffac552-5cc8-41b9-9867-e5efb2e9aeff","iss":"twingate","aud":"dautom","exp":1691358569,"iat":1691099369,"ver":"4","tid":"27960","rnw":1691099669,"rnetid":"35054","sd":{"last_updated_at":1691099230688,"authz_version":"0.1.743354","network":{"id":"27960","name":"Dautom","slug":"dautom","admin_url":"https://dautom.twingate.com","stun_discovery_url":"https://relays.twingate.com","analytics_url":"https://analytics.twingate.com","feature_flags":{"wildcard_matching_v2":false,"local_direct_connect":false},"templates":{"admin_resource":"{{admin_url}}/resources/{{global_id}}"}},"logging":{"allow_analytics":true},"resources":[{"id":"2246330","name":"CPW PASS","global_id":"UmVzb3VyY2U6MjI0NjMzMA==","type":"ip","address":"10.10.2.200","aliases":[{"name":"cpw.pass","url":"http://cpw.pass"}],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":"http://10.10.2.200","is_range":false,"is_visible_in_client":true,"can_open_in_browser":true,"is_favorite":false},{"id":"2255110","name":"CPW Deif","global_id":"UmVzb3VyY2U6MjI1NTExMA==","type":"ip","address":"10.10.2.100","aliases":[{"name":"cpw.deif","url":"http://cpw.deif"}],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":"http://10.10.2.100","is_range":false,"is_visible_in_client":true,"can_open_in_browser":false,"is_favorite":false},{"id":"__local1","name":"Local 1","global_id":"","type":"ip","address":"192.168.0.0/16","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local2","name":"Local 2","global_id":"","type":"ip","address":"127.0.0.0/8","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local3","name":"Local 3","global_id":"","type":"ip","address":"10.0.0.0/8","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false},{"id":"__local4","name":"Local 4","global_id":"","type":"ip","address":"172.16.0.0/12","aliases":[],"tcp_ports":null,"udp_ports":null,"icmp":true,"open_url":null,"is_range":true,"is_visible_in_client":false,"can_open_in_browser":false,"is_favorite":false}],"device":{"id":"126278","name":"scarlet-rhino","type":"Device"},"timeouts":{"max_idle_timeout_seconds":60},"connector":{"name":"scarlet-rhino","relay":{"address":"relaybalancer+https://relays.twingate.com","max_endpoints":4},"remote_network":{"id":"35054","name":"Dautom HQ","connection_mode":"ANY"},"matches":["2246330","2255110","__local1","__local2","__local3","__local4"],"heartbeat_interval_seconds":60}}}
2023-08-03 16:49:24 [DEBUG] [libsdwan] creating hydra pool "ice://any"
2023-08-03 16:49:24 [DEBUG] [libsdwan] relaybalancer::get_instance: "relaybalancer+https://relays.twingate.com"
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::send_request: GET "https://relays.twingate.com/api/v2/metadata" text/plain
2023-08-03 16:49:24 [DEBUG] [libsdwan] [relay] get_all_listen_addrs: listeners_ size 1
2023-08-03 16:49:24 [DEBUG] [libsdwan] [relay] sdwan_async_listen: listening on "ice://any"
2023-08-03 16:49:24 [DEBUG] [libsdwan] [stun] get_stun_addresses: asking load balancer https://relays.twingate.com for the addresses of STUN server instances
2023-08-03 16:49:24 [DEBUG] [libsdwan] relaybalancer::get_instance: "https://relays.twingate.com"
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::send_request: GET "https://relays.twingate.com/api/v2/metadata" text/plain
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] set_state: switching from "Applying SD" to "Got SD"
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] run_state_machine: Got SD
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] set_state: switching from "Got SD" to "Ready"
2023-08-03 16:49:24 [INFO] [libsdwan] sdwan_state: Online
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] update_realtime_token: updating realtime token
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] get_realtime: requesting realtime_t()
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] get_token: enqueuing a request for realtime_t()
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] get_realtime: getting realtime token
2023-08-03 16:49:24 [DEBUG] [libsdwan] send: sending HTTP request 15070106400832805080
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::send_request: POST "https://dautom.twingate.com/api/v4/connector/realtime" text/plain
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] process_send: sending a request for realtime_t()
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] update_presence_state: presence state check
2023-08-03 16:49:24 [DEBUG] [libsdwan] [relay] get_all_listen_addrs: listeners_ size 1
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] set_state_machine_locked: 0x55abc0e49360 not allowing state change from no auth (NO_AUTH_WAIT) to start transaction (START_TRANS)
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] operator(): starting pubnub subscribe thread with context 0x7ffabf7fd9d0
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] update_presence_state: presence state changed
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] set_state_machine_locked: 0x55abc0e492c0 allow state change from create pubnub context (CREATE_CONTEXT) to no auth (NO_AUTH_WAIT)
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] run_state_machine: Ready
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] run_state_machine: scheduling SD update in 298 seconds
2023-08-03 16:49:24 [DEBUG] [libsdwan] send: sending HTTP request 10041283876197965739
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::send_request: POST "https://dautom.twingate.com/api/v4/connector/label" application/json
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] operator(): starting pubnub presence thread with context 0x7ffabeffc9d0
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] set_state_machine_locked: 0x55abc0e49360 allow state change from create pubnub context (CREATE_CONTEXT) to no auth (NO_AUTH_WAIT)
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::response::from: certificate f45cd393edfe2dc83c39cbade4c105321384f486256409fb21d63b34cba5d168, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=relays.twingate.com
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::handle_response: GET "https://relays.twingate.com/api/v2/metadata" 200 OK (duration 0 sec)
2023-08-03 16:49:24 [DEBUG] [libsdwan] relaybalancer::operator(): relay info: {"ip":"34.23.101.100","port":"30009","stun":"stun.us-east1-d.twingate.com:3478","stuns":["stun.us-east1-d.twingate.com:3478","stun-alt.us-east1-d.twingate.com:3478"],"zone":"us-east1-d"}
2023-08-03 16:49:24 [DEBUG] [libsdwan] [relay] operator(): new relay instance: zone us-east1-d, addr 34.23.101.100:30009
2023-08-03 16:49:24 [DEBUG] [libsdwan] [relay] get_needed_conns_count: relay 34.23.101.100:30009, needed_conns_count 16
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] get_ct: requesting ct_key_t(network: any)
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] get_token: enqueuing a request for ct_key_t(network: any)
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] get_ct: getting CT for "any"
2023-08-03 16:49:24 [DEBUG] [libsdwan] send: sending HTTP request 16665341424011541358
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::send_request: POST "https://dautom.twingate.com/api/v4/connector/ct" application/json
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] process_send: sending a request for ct_key_t(network: any)
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::response::from: certificate f45cd393edfe2dc83c39cbade4c105321384f486256409fb21d63b34cba5d168, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=relays.twingate.com
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::handle_response: GET "https://relays.twingate.com/api/v2/metadata" 200 OK (duration 0 sec)
2023-08-03 16:49:24 [DEBUG] [libsdwan] relaybalancer::operator(): relay info: {"ip":"34.23.101.100","port":"30009","stun":"stun.us-east1-d.twingate.com:3478","stuns":["stun.us-east1-d.twingate.com:3478","stun-alt.us-east1-d.twingate.com:3478"],"zone":"us-east1-d"}
2023-08-03 16:49:24 [DEBUG] [libsdwan] [stun] operator(): resolving STUN address: stun.us-east1-d.twingate.com:3478
2023-08-03 16:49:24 [DEBUG] [libsdwan] dns_getaddrinfo(stun.us-east1-d.twingate.com:3478)
2023-08-03 16:49:24 [DEBUG] [libsdwan] [stun] operator(): resolving STUN address: stun-alt.us-east1-d.twingate.com:3478
2023-08-03 16:49:24 [DEBUG] [libsdwan] dns_getaddrinfo(stun-alt.us-east1-d.twingate.com:3478)
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::response::from: certificate 3452c42ec6bef8f100225c8c21b31fec4dabe9dec8d0a5f4e45a4302a4108c16, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=*.twingate.com
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::handle_response: POST "https://dautom.twingate.com/api/v4/connector/realtime" 200 OK (duration 0 sec)
2023-08-03 16:49:24 [DEBUG] [libsdwan] operator(): got HTTP request 15070106400832805080 successful response
2023-08-03 16:49:17 State: Offline
2023-08-03 16:49:17 State: Authentication
2023-08-03 16:49:24 State: Online
2023-08-03 16:49:24 [DEBUG] [libsdwan] [controller] verify_token: {"alg":"ES256","kid":"Uo1vPcMAp9s0SiznE1mDc6WoWZc00Axy1xTCPHAfysM","typ":"RTMT"} {"nt":"AN","aid":"126278","did":"841386","jti":"4877247c-36df-422c-8858-e80107b2296e","iss":"twingate","aud":"dautom","exp":1691120970,"iat":1691099370,"ver":"4","tid":"27960","rnw":1691104770,"sk":"sub-c-908c8358-4469-4917-a1ca-72a9cf6d6da8","suid":"126278","ak":"d258467b97268df253151739992e46677da9228f68159aa44e453af389d71e5a","cn":["27960","27960_heartbeat"],"scn":["27960_heartbeat"]}
2023-08-03 16:49:24 [WARNING] [libsdwan] [controller] parse_verify_token: token verification failed: token expired
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] operator(): failed to get a token for realtime_t()
2023-08-03 16:49:24 [WARNING] [libsdwan] [pubnub] operator(): failed to get realtime token: Invalid token, err code 5
2023-08-03 16:49:24 [DEBUG] [libsdwan] [pubnub] operator(): scheduling the next attempt in 30 seconds
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] retry: retrying realtime_t()
2023-08-03 16:49:24 [DEBUG] [libsdwan] [token_fetcher] schedule_retry_timer: next retry attempt in 1000000µs
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::response::from: certificate 3452c42ec6bef8f100225c8c21b31fec4dabe9dec8d0a5f4e45a4302a4108c16, issuer: C=US, O=Let's Encrypt, CN=R3, subject: CN=*.twingate.com
2023-08-03 16:49:24 [DEBUG] [libsdwan] http::request::handle_response: POST "https://dautom.twingate.com/api/v4/connector/label" 200 OK (duration 0 sec)
2023-08-03 16:49:24 [DEBUG] [libsdwan] operator(): got HTTP request 10041283876197965739 successful response
2023-08-03 16:49:24 [DEBUG] [libsdwan] [stun] operator(): cached STUN address: 34.148.205.131:3478
8

Hey Ivan,

I see the parse_verify_token: token verification failed: token expired message which means something is very likely up with the timezone settings on your host machine or within docker itself.

If we convert the values in the token from Epoch to Human Readable that it is Issued At (iat) Thursday, August 3, 2023 9:49:24 PM GMT and Expires at (exp) Thursday, August 3, 2023 10:49:24 PM GMT, yet is saying the token is expired.

The timestamp in your log file is 2023-08-03 16:49:18 - so if the offset of your timezone really is -5, means we just have a variance of about 6 seconds.

But what this means, is that the connector thinks it’s 16:49:18 and is being given a token that was issued at 16:49:24 (aka from the Fuuuuuuutuureeeeeeee), and because the connector isn’t there yet, it’s saying “this token is no good we still have 6 seconds before it matters” and promptly crashing.

The TL;DR of it all is you’ll need to ensure that the BIOS on your host machine as well as the OS/Docker are set to the correct time, preferably sync’d to an NTP server of some sort, rather than managed manually, and once the variance between what time the connector thinks it is and what time it “really” is gets eliminated, the container will likely start just fine.

Please let me know if you have any further questions!

Thanks,

-arthur