Controller v1.6.8 disconnects tunnelers

Ziti Overlay
1

Hi,

we’ve upgrade our controllers, routers and all ziti-edge-tunnels to the newest version yesterday.

controller: v1.6.8
router: v1.6.8
ziti-edge-tunnel: v1.7.12

This morning we got random alerts that many of our ziti-edge-tunnels couldn’t make connections to our monitoring service (Zabbix) anymore. We had similar issues before, where somehow the Zabbix connections made the ziti-edge-tunnel effectively crash. @scareything made changes to the ziti-edge-tunnel that resolved the issue back then.

I suspected the ziti-edge-tunnels being the problem again so I downgraded to v1.5.6 again, which was the version we were running for quite a while without any issues. But now the same problem occurred again which makes me think it's actually rather the controller than the tunnelers:

ziti-edge-tunnel logs

Oct 06 10:32:49 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72658.531]   ERROR tlsuv:tls_link.c:83 TLS read -4095(end of file)
Oct 06 10:32:49 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72658.531]   ERROR tlsuv:http.c:72 connection error before active request could complete -4095 (end of file)
Oct 06 10:32:49 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72658.531]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://zt.mycompany.de:8441] request failed: -4095(end of file)
Oct 06 10:32:49 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72658.531]    INFO ziti-sdk:ziti_ctrl.c:180 ctrl_resp_cb() ctrl[https://zt.mycompany.de:8441] attempting to switch endpoint
Oct 06 10:32:49 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72658.531]    WARN ziti-sdk:ziti_ctrl.c:602 ctrl_next_ep() ctrl[https://zt.mycompany.de:8441] no controllers are online
Oct 06 10:32:49 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72658.531]   ERROR ziti-sdk:ziti_ctrl.c:389 ctrl_login_cb() ctrl[https://zt.mycompany.de:8441] CONTROLLER_UNAVAILABLE(end of file)
Oct 06 10:32:49 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72658.531]    WARN ziti-sdk:legacy_auth.c:183 login_cb() failed to login to ctrl[https://zt.mycompany.de:8441] CONTROLLER_UNAVAILABLE[-16] end of file
Oct 06 10:32:50 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72659.408]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16029/043H7dLt/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:50 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72659.408]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:51 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72660.393]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16030/eQTZ3qon/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:51 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72660.393]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:52 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72661.395]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16031/Wrszijal/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:52 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72661.395]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:53 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72662.399]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16032/ELjfi3pP/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:53 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72662.399]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:54 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72663.404]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16033/5J1V4W7U/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:54 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72663.404]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:55 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72664.407]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16034/ezSa4K1F/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:55 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72664.407]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:56 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72665.394]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16035/bVpg2Bmj/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:56 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72665.394]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:57 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72666.396]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16036/-Y0nxfbe/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:57 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72666.396]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:58 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72667.399]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16037/RuG0K9_n/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:58 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72667.399]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.403]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16038/t32n_usY/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.403]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    WARN ziti-sdk:ziti_ctrl.c:815 verify_api_session() ctrl[https://zt.mycompany.de:8441] no API session
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]   ERROR ziti-sdk:ziti.c:1566 update_identity_data() ztx[1] failed to get identity_data: no api session token set for ziti_controller[UNAUTHORIZED]
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    WARN ziti-sdk:ziti.c:1568 update_identity_data() ztx[1] api session is no longer valid. Trying to re-auth
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    WARN ziti-sdk:ziti.c:223 ziti_set_unauthenticated() ztx[1] auth error: no api session token set for ziti_controller
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    WARN tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event() ziti_ctx controller connections failed: failed to authenticate
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:460 on_event() ztx[/opt/openziti/etc/identities/kbappliance.mycompany.ziti.json] context event : status is failed to authenticate
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]   ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:514 on_event() ztx[/opt/openziti/etc/identities/kbappliance.mycompany.ziti.json] failed to connect to controller due to failed to authenticate
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    WARN ziti-sdk:ziti_ctrl.c:815 verify_api_session() ctrl[https://zt.mycompany.de:8441] no API session
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]   ERROR ziti-sdk:ziti.c:1489 edge_routers_cb() ztx[1] failed to get current edge routers: code[0] UNAUTHORIZED/no api session token set for ziti_controller
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    WARN ziti-sdk:ziti_ctrl.c:815 verify_api_session() ctrl[https://zt.mycompany.de:8441] no API session
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.456]    WARN ziti-sdk:ziti.c:1437 check_service_update() ztx[1] failed to poll service updates: code[0] err[-14/no api session token set for ziti_controller]
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.536]   ERROR tlsuv:tls_link.c:83 TLS read -4095(end of file)
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.536]   ERROR tlsuv:http.c:72 connection error before active request could complete -4095 (end of file)
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.536]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://zt.mycompany.de:8441] request failed: -4095(end of file)
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.536]    INFO ziti-sdk:ziti_ctrl.c:180 ctrl_resp_cb() ctrl[https://zt.mycompany.de:8441] attempting to switch endpoint
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.536]    WARN ziti-sdk:ziti_ctrl.c:602 ctrl_next_ep() ctrl[https://zt.mycompany.de:8441] no controllers are online
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.536]   ERROR ziti-sdk:ziti_ctrl.c:389 ctrl_login_cb() ctrl[https://zt.mycompany.de:8441] CONTROLLER_UNAVAILABLE(end of file)
Oct 06 10:32:59 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72668.536]    WARN ziti-sdk:legacy_auth.c:183 login_cb() failed to login to ctrl[https://zt.mycompany.de:8441] CONTROLLER_UNAVAILABLE[-16] end of file
Oct 06 10:33:00 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72669.406]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16039/5q1Y77HM/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:00 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72669.406]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:01 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72670.399]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16040/uA1uCrBg/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:01 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72670.399]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:02 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72671.402]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16041/WryLosKX/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:02 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72671.402]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:03 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72672.405]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16042/hLGwW7dy/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:03 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72672.405]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:04 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72673.408]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16043/Q3iz6lTy/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:04 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72673.408]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:05 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72674.394]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16044/d3Jn0gPK/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:05 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72674.394]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:05 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72674.411]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16045/b5L2-P8C/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:05 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72674.411]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:06 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72675.393]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16046/xuaoArWi/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:06 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72675.393]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:07 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72676.396]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16047/zVRlzrMs/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:07 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72676.396]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:08 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72677.399]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16048/fgXZlSf_/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:08 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72677.399]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.402]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16049/SQWzp9_B/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.402]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    WARN ziti-sdk:ziti_ctrl.c:815 verify_api_session() ctrl[https://zt.mycompany.de:8441] no API session
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]   ERROR ziti-sdk:ziti.c:1566 update_identity_data() ztx[1] failed to get identity_data: no api session token set for ziti_controller[UNAUTHORIZED]
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    WARN ziti-sdk:ziti.c:1568 update_identity_data() ztx[1] api session is no longer valid. Trying to re-auth
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    WARN ziti-sdk:ziti.c:223 ziti_set_unauthenticated() ztx[1] auth error: no api session token set for ziti_controller
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    WARN tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event() ziti_ctx controller connections failed: failed to authenticate
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:460 on_event() ztx[/opt/openziti/etc/identities/kbappliance.mycompany.ziti.json] context event : status is failed to authenticate
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]   ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:514 on_event() ztx[/opt/openziti/etc/identities/kbappliance.mycompany.ziti.json] failed to connect to controller due to failed to authenticate
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    WARN ziti-sdk:ziti_ctrl.c:815 verify_api_session() ctrl[https://zt.mycompany.de:8441] no API session
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]   ERROR ziti-sdk:ziti.c:1489 edge_routers_cb() ztx[1] failed to get current edge routers: code[0] UNAUTHORIZED/no api session token set for ziti_controller
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    WARN ziti-sdk:ziti_ctrl.c:815 verify_api_session() ctrl[https://zt.mycompany.de:8441] no API session
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.456]    WARN ziti-sdk:ziti.c:1437 check_service_update() ztx[1] failed to poll service updates: code[0] err[-14/no api session token set for ziti_controller]
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.532]   ERROR tlsuv:tls_link.c:83 TLS read -4095(end of file)
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.532]   ERROR tlsuv:http.c:72 connection error before active request could complete -4095 (end of file)
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.532]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://zt.mycompany.de:8441] request failed: -4095(end of file)
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.532]    INFO ziti-sdk:ziti_ctrl.c:180 ctrl_resp_cb() ctrl[https://zt.mycompany.de:8441] attempting to switch endpoint
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.532]    WARN ziti-sdk:ziti_ctrl.c:602 ctrl_next_ep() ctrl[https://zt.mycompany.de:8441] no controllers are online
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.532]   ERROR ziti-sdk:ziti_ctrl.c:389 ctrl_login_cb() ctrl[https://zt.mycompany.de:8441] CONTROLLER_UNAVAILABLE(end of file)
Oct 06 10:33:09 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72678.532]    WARN ziti-sdk:legacy_auth.c:183 login_cb() failed to login to ctrl[https://zt.mycompany.de:8441] CONTROLLER_UNAVAILABLE[-16] end of file
Oct 06 10:33:10 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72679.405]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16050/_chNUKM3/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:10 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72679.405]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:11 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72680.394]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16051/5o0V9vmI/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:11 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72680.394]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:12 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72681.396]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16052/S2jTbgOy/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:12 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72681.396]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:13 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72682.400]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16053/rNlpgzdw/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:13 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72682.400]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:14 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72683.402]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16054/tviiR7Jh/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:14 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72683.402]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:15 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72684.406]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16055/K4X-ruHA/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:15 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72684.406]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:16 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72685.395]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16056/wPWMrB4f/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:16 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72685.395]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:17 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72686.398]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16057/ibK3jNV-/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:17 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72686.398]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:18 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72687.401]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16058/Xtu1JGfa/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]
Oct 06 10:33:18 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72687.401]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
Oct 06 10:33:19 kbappliance ziti-edge-tunnel[1478763]: (1478763)[    72688.404]   ERROR ziti-sdk:connect.c:504 process_connect() conn[1.16059/AlZytHNk/Connecting](service_ZabbixAgentToZabbix_prod) ziti context is not authenticated, cannot connect to service[service_ZabbixAgentToZabbix_prod]

controller logs:

Okt 06 10:33:17 zt ziti[946173]: {"_context":"tls:0.0.0.0:8441","error":"cryptobyte: pending child length 65908 exceeds 2-byte length prefix","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"152.53.179.4:35458","time":"2025-10-06T10:33:17.942Z"}
Okt 06 10:33:17 zt ziti[946173]: {"_context":"tls:0.0.0.0:8441","error":"cryptobyte: pending child length 65908 exceeds 2-byte length prefix","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"152.53.179.4:35468","time":"2025-10-06T10:33:17.966Z"}
Okt 06 10:33:17 zt ziti[946173]: {"_context":"tls:0.0.0.0:8441","error":"cryptobyte: pending child length 65908 exceeds 2-byte length prefix","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"152.53.179.4:35470","time":"2025-10-06T10:33:17.988Z"}
Okt 06 10:33:19 zt ziti[946173]: {"_context":"tls:0.0.0.0:8441","error":"cryptobyte: pending child length 65909 exceeds 2-byte length prefix","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"62.156.152.18:51942","time":"2025-10-06T10:33:19.132Z"}
Okt 06 10:33:19 zt ziti[946173]: {"_context":"tls:0.0.0.0:8441","error":"cryptobyte: pending child length 66368 exceeds 2-byte length prefix","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"46.38.242.110:50720","time":"2025-10-06T10:33:19.261Z"}
Okt 06 10:33:19 zt ziti[946173]: {"_context":"tls:0.0.0.0:8441","error":"cryptobyte: pending child length 66368 exceeds 2-byte length prefix","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"46.38.242.110:50728","time":"2025-10-06T10:33:19.290Z"}
Okt 06 10:33:19 zt ziti[946173]: {"_context":"tls:0.0.0.0:8441","error":"cryptobyte: pending child length 66368 exceeds 2-byte length prefix","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"46.38.242.110:50734","time":"2025-10-06T10:33:19.317Z"}
Okt 06 10:33:20 zt ziti[946173]: {"_context":"tls:127.0.0.1:18441","error":"remote error: tls: bad certificate","file":"github.com/openziti/transport/v2@v2.0.188/tls/listener.go:260","func":"github.com/openziti/transport/v2/tls.(*sharedListener).processConn","level":"error","msg":"handshake failed","remote":"127.0.0.1:37580","time":"2025-10-06T10:33:20.424Z"}
Okt 06 10:33:20 zt ziti[946173]: {"file":"github.com/openziti/ziti/controller/network/fault.go:32","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"network fault processing for [31] circuits","time":"2025-10-06T10:33:20.976Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"64poL3xbzytYOsWf9Kzn2x","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.976Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"1cj1mJXylEaPm4dqWtbtWq","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.976Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"4OlE7ywQ1v9rGINFZb9HDj","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.976Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"2Gx0E9wIXo4vQH191vEKl0","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.976Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"5reylE7Ef45lnsoz9jaRPW","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.976Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"5Afr6s7fkKu4QVNOifieL2","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.977Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"1QfceiikS9Gpl5R9LJFVEw","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.977Z"}
Okt 06 10:33:20 zt ziti[946173]: {"circuitId":"4HQYEQjsjX9CfcQ8PxczVx","file":"github.com/openziti/ziti/controller/network/fault.go:49","func":"github.com/openziti/ziti/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"YZanu3dvYy","time":"2025-10-06T10:33:20.977Z"}
2

Hello Dominik,

You’re right, it isn’t clear exactly where the problem is here. I’d like to see more detailed logs from a ziti-edge-tunnel that’s having this issue. Enabling the logs that I’m interested in requires setting an environment variable before ziti-edge-tunnel starts. The important thing is to set the log level for the “tlsuv” module - it is not set with the global level and must be set explicitly as below.

If you’re using the standard ziti-edge-tunnel package then you should set this in the environment file "/opt/openziti/etc/ziti-edge-tunnel.env".

ZITI_LOG='6;tlsuv=6'
1 Like
3

I’ve updated the servers with the updated log level, will report asap when the problem occurs again.

4

Ok, thanks!

I was originally thinking this problem was persistent and not intermittent for a given tunneler. That’s really interesting if it is intermittent.

1 Like
5

Hi, so I think I caught the issue in the logs.
Excited to hear your opinion on the issue!

ziti-edge-tunnel-fail-08.10.2025.txt (721.3 KB)

6

this part here makes me think it is the controller terminating connection after receiving /authenticate request

Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.069]   TRACE tlsuv:tls_link.c:222 flushing 245 bytes
Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.069] VERBOSE tlsuv:http.c:439 sending request[/authenticate?method=cert] body
Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.069] VERBOSE tlsuv:http.c:324 sending body chunk 393 bytes
Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.069]   TRACE tlsuv:tls_link.c:242 io buffering 415 bytes
Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.069]   TRACE tlsuv:tls_link.c:222 flushing 415 bytes
Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.069] VERBOSE tlsuv:http.c:295 request write completed: 0
Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.069] VERBOSE tlsuv:http.c:300 request body write completed: 0
Okt 08 05:26:56 splnds01-bo ziti-edge-tunnel[3645153]: (3645153)[    73551.123]   TRACE tlsuv:tls_link.c:75 TLS(0x55d7f32c62c0)[2]: -4095

can you see anything in controller log in that timeframe? you may need to bump log level on the controller

7

Yeah, might be. I set the log level to debug but tbh I don’t see what the problem is.

ziti-controller-logs.txt (66.2 KB)

8

I do have one of the servers in this “never reconnecting“ state right now. Let me know what to test!

9

Can you try replacing the ziti-edge-tunnel binary with the latest pre-release v1.7.14?

10

Hi Shawn,

unfortunately we’re still experiencing the same behavior with Tunnelers v1.9.5.

Is there anything I can provide to help fix the issue? Did you manage to understand what kind of traffic/connections cause this? Then I could try raising an issue for the software making the request as well (Zabbix)

- Dominik

11

Hi Dominik,

I think the issue you’re having was fixed with ziti-sdk-c #965, which was included in (pre-release) ziti-edge-tunnel v1.9.8. There have been a number of other fixes since then, so my recommendation is to try ziti-edge-tunnel v1.10.1. btw I plan to promote 1.10.1 to stable in a few days.

1 Like
12

Ah gotcha! I was assuming the fix was already in the newest release. Will try, thanks!

13

Hi Shawn,

sorry to report back that 1.10.0 still causes the same disconnects with messages that the context is not authenticated. Will record some TRACE logs for you

14

Ok, thanks for letting me know. I’ll look at your logs as soon as I have them. Please let me know if you’ve already sent them and I somehow lost track.

Also do you know which controller version were you running before the upgrade, and is the “edge-oidc” api binding present in the controller’s config file?

apis:
...
      - binding: edge-oidc
        options: { }
1 Like
15

Hi Shawn,

The issue remains intermittent and hard to reproduce consistently. Previously we ran controller v1.5.6 (no issues), and yes, the edge-oidc binding is present in the controller config.

My key findings:

  • Controller upgrade to v1.6.8 alone causes no problems, issues only start after upgrading ziti-edge-tunnel.
  • ziti-edge-tunnel v1.5.4 runs flawlessly, indefinitely. So in my opinion it has to be a commit in a version > 1.5.4
  • Newer versions (e.g., v1.10.1) disconnect randomly, enter a "never reconnects" state, and require systemctl restart ziti-edge-tunnel to recover, only for the issue to recur within hours.

I have observed a pattern: When multiple v1.10.1 tunnelers are running, one drops first, followed by others within minutes. I'm uncertain if this is a domino effect or simultaneous traffic triggering the same failure across all.

I've sent you the logs via a private message.

Thanks
Dominik

1 Like
16

This is really interesting. What I see in the zet log looks like there’s some kind of i/o failure like EOF with the oidc endpoint when attempting to reauthenticate:

Dec 23 09:20:15 ... iteration[0]: tls read error: unexpected eof while reading

Is there any chance you can get the controller logs from this time period?

1 Like
17

I'm afraid I don't have those logs in the journal anymore as they were already rotated...
But I can wait until the issue happens next time and then save them.

18

Could you please try ziti-edge-tunnel v1.10.2 when you get a chance? This release handles i/o errors differently. Previously an unexpected end of file during OIDC authentication would cause the tunneler to retry the read operation instead of giving up entirely on the authentication attempt and starting over.

19

Thanks for the updated release. I've deployed v1.10.2 to 5 testing servers, we should pretty quickly see if the issue recurs :slight_smile: Will report back

Happy Christmas!

1 Like
20

Thought it would be a good idea to attach the TRACE zet to our centralized logging.
Welp :smiley: 22k Logs/sec from a single tunneler

image