Hi there,
I've noticed that after a tunneler crash we had a couple days ago, EVERY tunneler has thousands of warning messages in the log. Full log here.
Jul 28 17:45:56 myhost ziti-edge-tunnel[104351]: (104351)[ 4827.698] WARN ziti-sdk:connect.c:1326 process_edge_message() conn[0.1575/AKzli7-z/Connected] unexpected msg_seq[0] previous[0]
The messages instantly appear after restarting any tunneler as well. Interestingly enough, on one of the hosts, any SSH connection doesn't work over a Ziti service anymore, but other services work fine.
On the trace level of another host, the log looks like the this:
Jul 28 17:49:11 myhost systemd[1]: Starting Ziti Edge Tunnel...
Jul 28 17:49:11 myhost systemd[1]: Started Ziti Edge Tunnel.
Jul 28 17:49:22 myhost systemd-journald[27259]: Suppressed 9385 messages from ziti-edge-tunnel.service
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:channel.c:879 on_channel_data() ch[1] on_data [len=164]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:channel.c:558 process_inbound() ch[1] <= ct[ED72] seq[248] len[96] hdrs[48]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:channel.c:569 process_inbound() ch[1] completing msg seq[248] body+hrds=96+48, in_offset=0, want=144, got=144
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:channel.c:580 process_inbound() ch[1] message is complete seq[248] ct[ED72]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.5/U7OBi_KF/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:connect.c:1322 process_edge_message() conn[0.5/U7OBi_KF/Connected] <= ct[ED72] uuid[3c26e917:00000054:1d74438e] edge_seq[85] len[96]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] VERBOSE ziti-sdk:connect.c:870 conn_inbound_data_msg() conn[0.5/U7OBi_KF/Connected] decrypting 96 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] VERBOSE ziti-sdk:connect.c:893 conn_inbound_data_msg() conn[0.5/U7OBi_KF/Connected] decrypted 79 bytes tag[0]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.5/U7OBi_KF/Connected] 79 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:conn_bridge.c:270 on_ziti_data() br[0.5] received 79 bytes from ziti
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:connect.c:817 flush_to_client() conn[0.5/U7OBi_KF/Connected] client consumed 79 out of 79 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.5/U7OBi_KF/Connected] flushed 0 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.167] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.5/U7OBi_KF/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:conn_bridge.c:319 bridge_alloc() br[0.7] alloc live
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:connect.c:1174 ziti_write() conn[0.7/nyAgqxZS/Connected] write 21 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.7/nyAgqxZS/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.7/nyAgqxZS/Connected] 0 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:connect.c:291 send_message() conn[0.7/nyAgqxZS/Connected] => ct[ED72] uuid[cddb7437:00000054:34d27c0a] edge_seq[84] len[38] hash[cddb7437:ed695693:88e956ae:cde0e1e4:179ab7d7:eb63c750:c872c86b:2c2aa53b]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:channel.c:384 ziti_channel_send_message() ch[1] => ct[ED72] seq[237] len[38]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:channel.c:356 on_channel_send() ch[1] write delay = 0.000d q=1 qs=106
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:connect.c:228 on_write_completed() conn[0.7/nyAgqxZS/Connected] status 0
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.7/nyAgqxZS/Connected] flushed 1 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.170] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.7/nyAgqxZS/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:channel.c:879 on_channel_data() ch[1] on_data [len=164]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:channel.c:558 process_inbound() ch[1] <= ct[ED72] seq[249] len[96] hdrs[48]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:channel.c:569 process_inbound() ch[1] completing msg seq[249] body+hrds=96+48, in_offset=0, want=144, got=144
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:channel.c:580 process_inbound() ch[1] message is complete seq[249] ct[ED72]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.7/nyAgqxZS/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:connect.c:1322 process_edge_message() conn[0.7/nyAgqxZS/Connected] <= ct[ED72] uuid[4a65b3c2:00000055:1d7443a6] edge_seq[86] len[96]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] VERBOSE ziti-sdk:connect.c:870 conn_inbound_data_msg() conn[0.7/nyAgqxZS/Connected] decrypting 96 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] VERBOSE ziti-sdk:connect.c:893 conn_inbound_data_msg() conn[0.7/nyAgqxZS/Connected] decrypted 79 bytes tag[0]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.7/nyAgqxZS/Connected] 79 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:conn_bridge.c:270 on_ziti_data() br[0.7] received 79 bytes from ziti
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:connect.c:817 flush_to_client() conn[0.7/nyAgqxZS/Connected] client consumed 79 out of 79 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.7/nyAgqxZS/Connected] flushed 0 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.221] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.7/nyAgqxZS/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:conn_bridge.c:319 bridge_alloc() br[0.5] alloc live
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:connect.c:1174 ziti_write() conn[0.5/U7OBi_KF/Connected] write 21 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.5/U7OBi_KF/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.5/U7OBi_KF/Connected] 0 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:connect.c:291 send_message() conn[0.5/U7OBi_KF/Connected] => ct[ED72] uuid[c882d987:00000054:34d27c6b] edge_seq[84] len[38] hash[c882d987:2d60e3b2:e495dba4:6b15fe58:0c383cb1:170dc827:a0eead54:ddf7bf38]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:channel.c:384 ziti_channel_send_message() ch[1] => ct[ED72] seq[238] len[38]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:channel.c:356 on_channel_send() ch[1] write delay = 0.000d q=1 qs=106
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:connect.c:228 on_write_completed() conn[0.5/U7OBi_KF/Connected] status 0
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.5/U7OBi_KF/Connected] flushed 1 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.267] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.5/U7OBi_KF/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:channel.c:879 on_channel_data() ch[1] on_data [len=164]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:channel.c:558 process_inbound() ch[1] <= ct[ED72] seq[250] len[96] hdrs[48]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:channel.c:569 process_inbound() ch[1] completing msg seq[250] body+hrds=96+48, in_offset=0, want=144, got=144
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:channel.c:580 process_inbound() ch[1] message is complete seq[250] ct[ED72]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.5/U7OBi_KF/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:connect.c:1322 process_edge_message() conn[0.5/U7OBi_KF/Connected] <= ct[ED72] uuid[bae783be:00000055:1d744408] edge_seq[86] len[96]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] VERBOSE ziti-sdk:connect.c:870 conn_inbound_data_msg() conn[0.5/U7OBi_KF/Connected] decrypting 96 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] VERBOSE ziti-sdk:connect.c:893 conn_inbound_data_msg() conn[0.5/U7OBi_KF/Connected] decrypted 79 bytes tag[0]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.5/U7OBi_KF/Connected] 79 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:conn_bridge.c:270 on_ziti_data() br[0.5] received 79 bytes from ziti
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:connect.c:817 flush_to_client() conn[0.5/U7OBi_KF/Connected] client consumed 79 out of 79 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.5/U7OBi_KF/Connected] flushed 0 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.275] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.5/U7OBi_KF/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-sdk:netif_shim.c:65 netif_shim_input() received packet UDP[100.64.0.1:41080 -> 100.64.0.2:53] len=80
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-sdk:tunnel_udp.c:194 recv_udp() received datagram src[100.64.0.1:41080] dst[100.64.0.2:53]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] DEBUG tunnel-sdk:tunnel_udp.c:269 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:41080] service[ziti:dns-resolver]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] DEBUG tunnel-cbs:ziti_dns.c:234 on_dns_client() new DNS client
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:41080] service[ziti:dns-resolver]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-sdk:tunnel_udp.c:56 to_ziti() no data to write
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] VERBOSE tunnel-sdk:tunnel_udp.c:114 on_udp_client_data() 52 bytes from 100.64.0.1:41080
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-sdk:tunnel_udp.c:63 to_ziti() writing 52 bytes to ziti src[udp:100.64.0.1:41080] dst[udp:100.64.0.2:53] service[ziti:dns-resolver]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-cbs:ziti_dns.c:758 on_dns_req() received DNS query q_len=52 id[a21a] recursive[true] type[28] name[zabbix.company.ziti]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:41080] len=80
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-cbs:ziti_dns.c:244 on_dns_close() DNS client close
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:41080] service[ziti:dns-resolver]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] DEBUG tunnel-sdk:tunnel_udp.c:126 tunneler_udp_close() closing src[udp:100.64.0.1:41080] dst[udp:100.64.0.2:53] service[ziti:dns-resolver]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.289] TRACE tunnel-sdk:netif_shim.c:69 netif_shim_input() done after reading 1 packets
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] TRACE tunnel-sdk:netif_shim.c:65 netif_shim_input() received packet TCP[100.64.0.1:60877 -> 100.64.0.3:10051] len=60
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] TRACE tunnel-sdk:tunnel_tcp.c:366 recv_tcp() received segment src[tcp:100.64.0.1:60877] dst[tcp:100.64.0.3:10051] flags[SYN]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG tunnel-sdk:tunnel_tcp.c:116 new_tcp_pcb() snd_wnd: 61690, snd_snd_max: 61690, mss: 1460
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG tunnel-sdk:tunnel_tcp.c:429 recv_tcp() intercepted address[tcp:100.64.0.3:10051] client[tcp:100.64.0.1:60877] service[zabbix_agent.svc]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:284 ziti_sdk_c_dial() ziti_dial(name=zabbix_agent.svc)
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG tunnel-cbs:ziti_tunnel_cbs.c:349 ziti_sdk_c_dial() service[zabbix_agent.svc] app_data_json[182]='{"connType":null,"dst_protocol":"tcp","dst_hostname":"zabbix.company.ziti","dst_ip":"100.64.0.3","dst_port":"10051","src_protocol":"tcp","src_ip":"100.64.0.1","src_port":"60877"}'
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] VERBOSE ziti-sdk:connect.c:105 conn_set_state() conn[0.22/h7CLVx7S/Initial] transitioning Initial => Connecting
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG ziti-sdk:connect.c:413 connect_get_service_cb() conn[0.22/h7CLVx7S/Connecting] got service[zabbix_agent.svc] id[77tfbDtj89PVPirOcMCvjy]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] VERBOSE ziti-sdk:posture.c:196 ziti_send_posture_data() ztx[0] starting to send posture data
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG ziti-sdk:posture.c:210 ziti_send_posture_data() ztx[0] posture checks must_send set to TRUE, new_session_id[FALSE], must_send_every_time[TRUE], new_controller_instance[FALSE]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] VERBOSE ziti-sdk:posture.c:238 ziti_send_posture_data() ztx[0] checking posture queries on 5 service(s)
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] VERBOSE ziti-sdk:posture.c:530 ziti_pr_send_bulk() ztx[0] no change in posture data, not sending
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG ziti-sdk:connect.c:534 process_connect() conn[0.22/h7CLVx7S/Connecting] starting Dial connection for service[zabbix_agent.svc] with session[clz5qjx3d9dhkwq7olv8sb4u1]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG ziti-sdk:connect.c:390 ziti_connect() conn[0.22/h7CLVx7S/Connecting] selected ch[zt-router-1.company.ziti@tls://zt-router-1.company.de:8442] for best latency(3 ms)
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] TRACE ziti-sdk:connect.c:1018 ziti_channel_start_connection() conn[0.22/h7CLVx7S/Connecting] ch[0] => Edge Connect request token[35a01c1c-a968-4e01-8567-7c9176543840]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] DEBUG ziti-sdk:channel.c:246 ziti_channel_add_receiver() ch[0] added receiver[22]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] TRACE ziti-sdk:channel.c:384 ziti_channel_send_message() ch[0] => ct[ED6F] seq[113] len[36]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] TRACE ziti-sdk:channel.c:356 on_channel_send() ch[0] write delay = 0.000d q=1 qs=359
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.290] TRACE tunnel-sdk:netif_shim.c:69 netif_shim_input() done after reading 1 packets
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] TRACE ziti-sdk:channel.c:879 on_channel_data() ch[0] on_data [len=125]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] TRACE ziti-sdk:channel.c:558 process_inbound() ch[0] <= ct[ED70] seq[90] len[0] hdrs[105]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] TRACE ziti-sdk:channel.c:569 process_inbound() ch[0] completing msg seq[90] body+hrds=0+105, in_offset=0, want=105, got=105
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] TRACE ziti-sdk:channel.c:580 process_inbound() ch[0] message is complete seq[90] ct[ED70]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] TRACE ziti-sdk:connect.c:973 connect_reply_cb() conn[0.22/h7CLVx7S/Connecting] connected
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.22/h7CLVx7S/Connecting] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] VERBOSE ziti-sdk:connect.c:105 conn_set_state() conn[0.22/h7CLVx7S/Connecting] transitioning Connecting => Connected
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:93 on_ziti_connect() on_ziti_connect status: 0
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[tcp:100.64.0.1:60877] service[zabbix_agent.svc]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.298] TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet TCP[100.64.0.3:10051 -> 100.64.0.1:60877] len=48
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.22/h7CLVx7S/Connected] 0 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE ziti-sdk:connect.c:291 send_message() conn[0.22/h7CLVx7S/Connected] => ct[ED72] uuid[a3b76db2:00000000:34d27c8a] edge_seq[0] len[24] hash[a3b76db2:01af1f76:abdd9ece:741320dd:0715237c:64917840:c7710abe:ebd13cc7]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE ziti-sdk:channel.c:384 ziti_channel_send_message() ch[0] => ct[ED72] seq[114] len[24]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE ziti-sdk:channel.c:356 on_channel_send() ch[0] write delay = 0.000d q=1 qs=92
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE ziti-sdk:connect.c:228 on_write_completed() conn[0.22/h7CLVx7S/Connected] status 0
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.22/h7CLVx7S/Connected] flushed 1 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.22/h7CLVx7S/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE tunnel-sdk:netif_shim.c:65 netif_shim_input() received packet TCP[100.64.0.1:60877 -> 100.64.0.3:10051] len=40
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE tunnel-sdk:tunnel_tcp.c:366 recv_tcp() received segment src[tcp:100.64.0.1:60877] dst[tcp:100.64.0.3:10051] flags[ACK]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] DEBUG tunnel-sdk:tunnel_tcp.c:66 on_accept() on_accept: 0
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.299] TRACE tunnel-sdk:netif_shim.c:69 netif_shim_input() done after reading 1 packets
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE tunnel-sdk:netif_shim.c:65 netif_shim_input() received packet TCP[100.64.0.1:60877 -> 100.64.0.3:10051] len=144
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE tunnel-sdk:tunnel_tcp.c:366 recv_tcp() received segment src[tcp:100.64.0.1:60877] dst[tcp:100.64.0.3:10051] flags[PSH,ACK]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] VERBOSE tunnel-sdk:tunnel_tcp.c:141 on_tcp_client_data() status 0 src[tcp:100.64.0.1:60877] dst[tcp:100.64.0.3:10051] state[4/ESTABLISHED] flags[0x101] service[zabbix_agent.svc]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:connect.c:1174 ziti_write() conn[0.22/h7CLVx7S/Connected] write 104 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.22/h7CLVx7S/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE tunnel-sdk:netif_shim.c:69 netif_shim_input() done after reading 1 packets
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.22/h7CLVx7S/Connected] 0 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:connect.c:291 send_message() conn[0.22/h7CLVx7S/Connected] => ct[ED72] uuid[63d2e2f9:00000001:34d27c8c] edge_seq[1] len[121] hash[63d2e2f9:c7366915:7086469a:40dc3740:616d1c34:ba764989:748a84a1:47125e7e]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:channel.c:384 ziti_channel_send_message() ch[0] => ct[ED72] seq[115] len[121]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:channel.c:356 on_channel_send() ch[0] write delay = 0.000d q=1 qs=189
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:connect.c:228 on_write_completed() conn[0.22/h7CLVx7S/Connected] status 0
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.22/h7CLVx7S/Connected] flushed 1 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.300] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.22/h7CLVx7S/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:channel.c:879 on_channel_data() ch[0] on_data [len=92]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:channel.c:558 process_inbound() ch[0] <= ct[ED72] seq[91] len[24] hdrs[48]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:channel.c:569 process_inbound() ch[0] completing msg seq[91] body+hrds=24+48, in_offset=0, want=72, got=72
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:channel.c:580 process_inbound() ch[0] message is complete seq[91] ct[ED72]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.22/h7CLVx7S/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:connect.c:1322 process_edge_message() conn[0.22/h7CLVx7S/Connected] <= ct[ED72] uuid[686af540:00000000:fc77af2a] edge_seq[1] len[24]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] WARN ziti-sdk:connect.c:1326 process_edge_message() conn[0.22/h7CLVx7S/Connected] unexpected msg_seq[0] previous[0]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] VERBOSE ziti-sdk:connect.c:859 conn_inbound_data_msg() conn[0.22/h7CLVx7S/Connected] processing crypto header(24 bytes)
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] VERBOSE ziti-sdk:connect.c:862 conn_inbound_data_msg() conn[0.22/h7CLVx7S/Connected] processed crypto header
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.22/h7CLVx7S/Connected] 0 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.22/h7CLVx7S/Connected] flushed 0 messages
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.301] TRACE ziti-sdk:connect.c:757 on_flush() conn[0.22/h7CLVx7S/Connected] stopping flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:conn_bridge.c:319 bridge_alloc() br[0.7] alloc live
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:connect.c:1174 ziti_write() conn[0.7/nyAgqxZS/Connected] write 21 bytes
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:connect.c:764 flush_connection() conn[0.7/nyAgqxZS/Connected] starting flusher
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet TCP[100.64.0.3:10051 -> 100.64.0.1:60877] len=40
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] VERBOSE ziti-sdk:connect.c:811 flush_to_client() conn[0.7/nyAgqxZS/Connected] 0 bytes available
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:connect.c:291 send_message() conn[0.7/nyAgqxZS/Connected] => ct[ED72] uuid[ef2d45e9:00000055:34d27ca1] edge_seq[85] len[38] hash[ef2d45e9:9952ed60:9675f9e4:21156897:cda95ef1:2c1476a2:3ea37610:f6283f59]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:channel.c:384 ziti_channel_send_message() ch[1] => ct[ED72] seq[239] len[38]
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:channel.c:356 on_channel_send() ch[1] write delay = 0.000d q=1 qs=106
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:connect.c:228 on_write_completed() conn[0.7/nyAgqxZS/Connected] status 0
Jul 28 17:49:22 myhost ziti-edge-tunnel[105212]: (105212)[ 11.321] TRACE ziti-sdk:connect.c:798 flush_to_service() conn[0.7/nyAgqxZS/Connected] flushed 1 messages
Since the problem affects all tunnelers, I suspect a problem with either the routers or the controller.
Any ideas?