Unexpected msg_seq warn logs on EVERY tunneler

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?

I looked at the logs you linked but I only see a single WARN message, not 1000's, so I'm a bit confused tbh.

Can you look at the router/controller logs to see if there's anything interesting/useful in there? What versions are you using across the network?

1 Like

unexpected msg_seq message is a red herring -- it does not indicate an issue with the connection

for your SSH service issue -- can you get the logs from the client side?

1 Like

Sorry about the confusion. I had to cut the log because of the size. All the logs I've shared repeat every minute or so.

Nothing to see there unfortunately... I've just upgraded to all the most recent versions for the controller, routers and edge tunnels.

Sure, they are here: Pastebin.com - Locked Paste
PW: VRbEKXwvPp
The same service (wildcard.ssh) works for all other edge tunnels perfectly fine.

Hi @ekoby,

Would you be able to expand a little bit on that?
We're seeing those kind of messages suddenly on every endpoint. Do you have any idea why?