Hello, firstly thank you for such a great product!
I am in the process of testing my POC using OpenZiti and a streaming desktop. Everything works as expected on Mac,Windows and iOS (iPad pro). The connection is super stable.
However the Android tunneller is another matter. I have tested the streaming desktop from within the Ziti Tunnel and from outside the tunnel and I can confirm that it is the Tunneler for Android that is causing issues on the Tab 8+ tablet. The Tablet browser session doesn't seem to recover unless I manually refresh the browser.
Sorry for the number of log lines in this post.
Here is the setup details:
-
Controller and the public edge router, installed via the easy setup script.
-
Docker tunneler is reaching out to the public router. I am using the latestziti-host docker container
-
Running the latest android ziti mobile edge client (v0.8.1) Android 14
-
Logs from the docker tunneler is DEBUG flag 4:
docker run --name ziti-host -d --rm --network=host --env ZITI_IDENTITY_BASENAME="test" --volume /home/user/.ziti/ids:/ziti-edge-tunnel openziti/ziti-host run-host --verbose=4
- Logs from docker container:
The issue seems to happen when I get these errors:
ziti-sdk:channel.c:490 dispatch_message() ch[0] received message without conn_id or for unknown connection ct[ED72] conn_id[36]
I get a lot of these errors with the android client and very few with all the other clients.
WARN: the identities directory is only available inside this container because /ziti-edge-tunnel is not a mounted volume. Be careful to not publish this image with identity inside or lose access to the identity by removing the image prematurely.
INFO: setting NF_REG_NAME to ${ZITI_IDENTITY_BASENAME} (test)
DEBUG: waiting 1s for /ziti-edge-tunnel/test.json (or token) to appear
INFO: found identity file /ziti-edge-tunnel/test.json
DEBUG: evaluating positionals: run-host --verbose=4
INFO: running ziti-edge-tunnel
(8)[ 0.000] INFO ziti-sdk:utils.c:200 ziti_log_set_level() set log level: root=4/DEBUG
(8)[ 0.000] INFO ziti-sdk:utils.c:171 ziti_log_init() Ziti C SDK version 0.35.12 @5acfb13(HEAD) starting at (2024-02-18T21:46:02.185)
(8)[ 0.000] INFO tunnel-sdk:ziti_tunnel.c:60 create_tunneler_ctx() Ziti Tunneler SDK (v0.22.20)
(8)[ 0.000] WARN ziti-edge-tunnel:ziti-edge-tunnel.c:1608 make_socket_path() local 'ziti' group not found.
(8)[ 0.000] WARN ziti-edge-tunnel:ziti-edge-tunnel.c:1609 make_socket_path() please create the 'ziti' group by running these commands:
(8)[ 0.000] WARN ziti-edge-tunnel:ziti-edge-tunnel.c:1611 make_socket_path() sudo groupadd --system ziti
(8)[ 0.000] WARN ziti-edge-tunnel:ziti-edge-tunnel.c:1612 make_socket_path() users can then be added to the 'ziti' group with:
(8)[ 0.000] WARN ziti-edge-tunnel:ziti-edge-tunnel.c:1613 make_socket_path() sudo usermod --append --groups ziti <USER>
(8)[ 0.000] WARN ziti-edge-tunnel:ziti-edge-tunnel.c:1712 run_tunneler_loop() One or more socket servers did not properly start.
(8)[ 0.002] DEBUG ziti-sdk:config.c:58 ziti_load_config() trying to load config from file[/ziti-edge-tunnel/test.json]
(8)[ 0.002] INFO tunnel-cbs:ziti_tunnel_ctrl.c:907 load_ziti_async() attempting to load ziti instance[/ziti-edge-tunnel/test.json]
(8)[ 0.002] INFO tunnel-cbs:ziti_tunnel_ctrl.c:914 load_ziti_async() loading ziti instance[/ziti-edge-tunnel/test.json]
(8)[ 0.002] INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1117 load_id_cb() identity[/ziti-edge-tunnel/test.json] loaded
(8)[ 0.002] WARN ziti-edge-tunnel:instance.c:40 find_tunnel_identity() Identity ztx[/ziti-edge-tunnel/test.json] is not loaded yet or already removed.
(8)[ 0.002] ERROR ziti-edge-tunnel:instance-config.c:136 save_tunnel_status_to_file() Could not copy config file [/var/lib/ziti/config.json] to backup config file, the config might not exists at the moment
(8)[ 0.002] ERROR ziti-edge-tunnel:instance-config.c:142 save_tunnel_status_to_file() Could not open config file /var/lib/ziti/config.json to store the tunnel status data
(8)[ 0.003] INFO ziti-sdk:ziti.c:449 ziti_init_async() ztx[0] using tlsuv[v0.26.1], tls[mbed TLS 2.28.1]
(8)[ 0.003] INFO ziti-sdk:ziti.c:450 ziti_init_async() ztx[0] Loading ziti context with controller[https://hosting.compute.amazonaws.com:8441/edge/client/v1]
(8)[ 0.003] DEBUG ziti-sdk:ziti_ctrl.c:412 ziti_ctrl_init() ctrl[hosting.compute.amazonaws.com] ziti controller client initialized
(8)[ 0.003] DEBUG ziti-sdk:ziti.c:472 ziti_init_async() ztx[0] using metrics interval: 0
(8)[ 0.003] DEBUG ziti-sdk:ziti.c:275 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
(8)[ 0.003] DEBUG ziti-sdk:ziti_ctrl.c:252 ziti_ctrl_clear_api_session() ctrl[hosting.compute.amazonaws.com] clearing api session token for ziti_controller
(8)[ 0.003] DEBUG ziti-sdk:ziti.c:966 ziti_re_auth() ztx[0] re-auth executing, transitioning to unauthenticated
(8)[ 0.003] DEBUG ziti-sdk:ziti.c:275 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
(8)[ 0.003] DEBUG ziti-sdk:ziti_ctrl.c:252 ziti_ctrl_clear_api_session() ctrl[hosting.compute.amazonaws.com] clearing api session token for ziti_controller
(8)[ 0.003] DEBUG ziti-sdk:ziti.c:317 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
(8)[ 0.003] INFO ziti-sdk:ziti.c:914 ziti_re_auth_with_cb() ztx[0] starting to re-auth with ctrl[https://hosting.compute.amazonaws.com:8441/edge/client/v1] api_session_status[0] api_session_expired[TRUE]
(8)[ 0.003] DEBUG ziti-sdk:ziti.c:268 ziti_set_auth_started() ztx[0] setting api_session_state[0] to 1
(8)[ 0.003] DEBUG ziti-sdk:ziti.c:352 ziti_stop_api_session_refresh() ztx[0] ziti_stop_api_session_refresh: stopping api session refresh
(8)[ 0.348] DEBUG ziti-sdk:ziti_ctrl.c:329 ctrl_body_cb() ctrl[hosting.compute.amazonaws.com] completed GET[/version] in 0.345 s
(8)[ 0.348] INFO ziti-sdk:ziti.c:1672 version_cb() ztx[0] connected to controller https://hosting.compute.amazonaws.com:8441/edge/client/v1 version v0.32.2(7c53aa006529 2024-02-10T05:53:17Z)
(8)[ 0.423] DEBUG ziti-sdk:ziti_ctrl.c:329 ctrl_body_cb() ctrl[hosting.compute.amazonaws.com] completed POST[/authenticate?method=cert] in 0.420 s
(8)[ 0.423] DEBUG ziti-sdk:ziti_ctrl.c:265 ctrl_login_cb() ctrl[hosting.compute.amazonaws.com] authenticated successfully session[clss1ejm208ipxvosgyx392uy]
(8)[ 0.423] DEBUG ziti-sdk:ziti.c:1588 api_session_cb() ztx[0] logged in successfully => api_session[clss1ejm208ipxvosgyx392uy]
(8)[ 0.423] DEBUG ziti-sdk:ziti.c:1537 ziti_set_api_session() ztx[0] ziti api session expires in 1800 seconds
(8)[ 0.423] INFO ziti-sdk:ziti.c:1561 ziti_set_api_session() ztx[0] api session set, setting api_session_timer to 1740s
(8)[ 0.423] DEBUG ziti-sdk:ziti.c:357 ziti_schedule_api_session_refresh() ztx[0] ziti_schedule_api_session_refresh: scheduling api session refresh: 1740000ms
(8)[ 0.423] DEBUG ziti-sdk:ziti.c:311 ziti_set_fully_authenticated() ztx[0] setting api_session_state[1] to 3
(8)[ 0.423] DEBUG ziti-sdk:ziti.c:311 ziti_set_fully_authenticated() ztx[0] setting api_session_state[3] to 3
(8)[ 0.423] INFO tunnel-cbs:ziti_tunnel_ctrl.c:767 on_ziti_event() ziti_ctx[test] connected to controller
(8)[ 0.423] DEBUG tunnel-sdk:ziti_tunnel.c:110 ziti_tunneler_exclude_route() No netif_driver found tun is running in host only mode and intercepts are disabled
(8)[ 0.423] INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1147 on_event() ztx[/ziti-edge-tunnel/test.json] context event : status is OK
(8)[ 0.423] DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1199 on_event() ztx[/ziti-edge-tunnel/test.json] controller connected
(8)[ 0.423] DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:764 send_events_message() Events Message => {"Op":"identity","Action":"added","Fingerprint":"/ziti-edge-tunnel/test","Id":{"Name":"test","Identifier":"/ziti-edge-tunnel/test.json","FingerPrint":"/ziti-edge-tunnel/test","Active":true,"Loaded":true,"Config":{"ztAPI":"https://hosting.compute.amazonaws.com:8441/edge/client/v1"},"ControllerVersion":"v0.32.2","IdFileStatus":true,"MfaEnabled":false,"MfaNeeded":false,"Metrics":{"Up":0,"Down":0},"MfaMinTimeout":0,"MfaMaxTimeout":0,"MfaMinTimeoutRem":0,"MfaMaxTimeoutRem":0,"MinTimeoutRemInSvcEvent":0,"MaxTimeoutRemInSvcEvent":0,"Deleted":false,"Notified":false}}
(8)[ 0.423] DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:764 send_events_message() Events Message => {"Op":"controller","Action":"connected","Identifier":"/ziti-edge-tunnel/test.json","Fingerprint":"/ziti-edge-tunnel/test"}
(8)[ 151.197] DEBUG ziti-sdk:bind.c:355 on_message() received msg ct[ed73] code[0] from ip-10-0-101-180-edge-router
(8)[ 151.197] DEBUG tunnel-cbs:ziti_hosting.c:536 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg]: received app_data_json='{"dst_hostname":"test2.ziti","dst_port":"443","dst_protocol":"tcp"}'
(8)[ 151.197] INFO tunnel-cbs:ziti_hosting.c:591 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg] dst_addr[tcp:198.18.1.12:443]: incoming connection
(8)[ 151.197] DEBUG tunnel-cbs:ziti_hosting.c:650 on_hosted_client_connect_resolved() hosted_service[test1] client[f.vUtXfOvg] initiating connection to tcp:198.18.1.12:443
(8)[ 151.198] DEBUG tunnel-cbs:ziti_hosting.c:228 on_hosted_tcp_server_connect_complete() hosted_service[test1], client[f.vUtXfOvg]: connected to server tcp:198.18.1.12:443
(8)[ 151.198] DEBUG ziti-sdk:channel.c:212 ziti_channel_add_receiver() ch[0] added receiver[41]
(8)[ 151.360] DEBUG ziti-sdk:bind.c:355 on_message() received msg ct[ed73] code[0] from ip-10-0-101-180-edge-router
(8)[ 151.360] DEBUG tunnel-cbs:ziti_hosting.c:536 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg]: received app_data_json='{"dst_hostname":"test2.ziti","dst_port":"443","dst_protocol":"tcp"}'
(8)[ 151.360] INFO tunnel-cbs:ziti_hosting.c:591 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg] dst_addr[tcp:198.18.1.12:443]: incoming connection
(8)[ 151.360] DEBUG tunnel-cbs:ziti_hosting.c:650 on_hosted_client_connect_resolved() hosted_service[test1] client[f.vUtXfOvg] initiating connection to tcp:198.18.1.12:443
(8)[ 151.361] DEBUG tunnel-cbs:ziti_hosting.c:228 on_hosted_tcp_server_connect_complete() hosted_service[test1], client[f.vUtXfOvg]: connected to server tcp:198.18.1.12:443
(8)[ 151.361] DEBUG ziti-sdk:channel.c:212 ziti_channel_add_receiver() ch[0] added receiver[42]
(8)[ 155.792] DEBUG ziti-sdk:ziti_ctrl.c:697 ctrl_paging_req() ctrl[hosting.compute.amazonaws.com] starting paging request GET[/current-identity/edge-routers]
(8)[ 156.132] DEBUG ziti-sdk:bind.c:355 on_message() received msg ct[ed73] code[0] from ip-10-0-101-180-edge-router
(8)[ 156.132] DEBUG tunnel-cbs:ziti_hosting.c:536 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg]: received app_data_json='{"dst_hostname":"test2.ziti","dst_port":"443","dst_protocol":"tcp"}'
(8)[ 156.132] INFO tunnel-cbs:ziti_hosting.c:591 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg] dst_addr[tcp:198.18.1.12:443]: incoming connection
(8)[ 156.133] DEBUG tunnel-cbs:ziti_hosting.c:650 on_hosted_client_connect_resolved() hosted_service[test1] client[f.vUtXfOvg] initiating connection to tcp:198.18.1.12:443
(8)[ 156.133] DEBUG tunnel-cbs:ziti_hosting.c:228 on_hosted_tcp_server_connect_complete() hosted_service[test1], client[f.vUtXfOvg]: connected to server tcp:198.18.1.12:443
(8)[ 156.133] DEBUG ziti-sdk:channel.c:212 ziti_channel_add_receiver() ch[0] added receiver[43]
(8)[ 156.198] DEBUG ziti-sdk:ziti_ctrl.c:329 ctrl_body_cb() ctrl[hosting.compute.amazonaws.com] completed GET[/current-identity/edge-routers?limit=25&offset=0] in 0.406 s
(8)[ 156.198] DEBUG ziti-sdk:ziti_ctrl.c:345 ctrl_body_cb() ctrl[hosting.compute.amazonaws.com] received 1/1 for paging request GET[/current-identity/edge-routers]
(8)[ 156.198] DEBUG ziti-sdk:ziti_ctrl.c:357 ctrl_body_cb() ctrl[hosting.compute.amazonaws.com] completed paging request GET[/current-identity/edge-routers] in 0.406 s
(8)[ 156.312] DEBUG ziti-sdk:bind.c:355 on_message() received msg ct[ed73] code[0] from ip-10-0-101-180-edge-router
(8)[ 156.312] DEBUG tunnel-cbs:ziti_hosting.c:536 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg]: received app_data_json='{"dst_hostname":"test2.ziti","dst_port":"443","dst_protocol":"tcp"}'
(8)[ 156.312] INFO tunnel-cbs:ziti_hosting.c:591 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg] dst_addr[tcp:198.18.1.12:443]: incoming connection
(8)[ 156.312] DEBUG tunnel-cbs:ziti_hosting.c:650 on_hosted_client_connect_resolved() hosted_service[test1] client[f.vUtXfOvg] initiating connection to tcp:198.18.1.12:443
(8)[ 156.312] DEBUG tunnel-cbs:ziti_hosting.c:228 on_hosted_tcp_server_connect_complete() hosted_service[test1], client[f.vUtXfOvg]: connected to server tcp:198.18.1.12:443
(8)[ 156.312] DEBUG ziti-sdk:channel.c:212 ziti_channel_add_receiver() ch[0] added receiver[44]
(8)[ 156.320] DEBUG ziti-sdk:ziti_ctrl.c:329 ctrl_body_cb() ctrl[hosting.compute.amazonaws.com] completed GET[/current-api-session/service-updates] in 0.527 s
(8)[ 156.966] DEBUG ziti-sdk:connect.c:1280 process_edge_message() conn[0.7/CloseWrite] connection status[ED71] conn_id[7] seq[4] err[close called]
(8)[ 156.966] DEBUG ziti-sdk:conn_bridge.c:225 close_bridge() br[0.7] closing
(8)[ 156.966] DEBUG tunnel-cbs:ziti_hosting.c:903 on_bridge_close() closing local_addr[198.18.1.12:36996] fd[14]
(8)[ 156.966] DEBUG ziti-sdk:connect.c:164 close_conn_internal() conn[0.7/Closed] removing
(8)[ 156.966] DEBUG ziti-sdk:channel.c:219 ziti_channel_rem_receiver() ch[0] removed receiver[7]
(8)[ 156.966] DEBUG ziti-sdk:ziti.c:1737 grim_reaper() ztx[0] reaped 1 closed (out of 12 total) connections
(8)[ 157.296] DEBUG tunnel-cbs:ziti_hosting.c:187 on_hosted_client_connect_complete() hosted_service[test1] client[f.vUtXfOvg] local_addr[198.18.1.12:48954] fd[18] server[tcp:198.18.1.12:443] connected 16
(8)[ 157.296] DEBUG ziti-sdk:conn_bridge.c:95 ziti_conn_bridge() br[0.43] connected
(8)[ 157.296] DEBUG tunnel-cbs:ziti_hosting.c:187 on_hosted_client_connect_complete() hosted_service[test1] client[f.vUtXfOvg] local_addr[198.18.1.12:48960] fd[19] server[tcp:198.18.1.12:443] connected 16
(8)[ 157.296] DEBUG ziti-sdk:conn_bridge.c:95 ziti_conn_bridge() br[0.44] connected
(8)[ 157.297] DEBUG ziti-sdk:connect.c:1280 process_edge_message() conn[0.43/Connected] connection status[ED71] conn_id[43] seq[1] err[close called]
(8)[ 157.297] DEBUG ziti-sdk:conn_bridge.c:225 close_bridge() br[0.43] closing
(8)[ 157.297] DEBUG tunnel-cbs:ziti_hosting.c:903 on_bridge_close() closing local_addr[198.18.1.12:48954] fd[18]
(8)[ 157.297] DEBUG ziti-sdk:connect.c:164 close_conn_internal() conn[0.43/Closed] removing
(8)[ 157.297] DEBUG ziti-sdk:channel.c:219 ziti_channel_rem_receiver() ch[0] removed receiver[43]
(8)[ 157.297] DEBUG ziti-sdk:ziti.c:1737 grim_reaper() ztx[0] reaped 1 closed (out of 11 total) connections
(8)[ 157.297] DEBUG ziti-sdk:connect.c:1280 process_edge_message() conn[0.44/Connected] connection status[ED71] conn_id[44] seq[1] err[close called]
(8)[ 157.297] DEBUG ziti-sdk:conn_bridge.c:225 close_bridge() br[0.44] closing
(8)[ 157.297] DEBUG tunnel-cbs:ziti_hosting.c:903 on_bridge_close() closing local_addr[198.18.1.12:48960] fd[19]
(8)[ 157.297] DEBUG ziti-sdk:connect.c:164 close_conn_internal() conn[0.44/Closed] removing
(8)[ 157.297] DEBUG ziti-sdk:channel.c:219 ziti_channel_rem_receiver() ch[0] removed receiver[44]
(8)[ 157.297] DEBUG ziti-sdk:ziti.c:1737 grim_reaper() ztx[0] reaped 1 closed (out of 10 total) connections
(8)[ 157.464] DEBUG ziti-sdk:connect.c:1154 send_fin_message() conn[0.36/CloseWrite] sending FIN
(8)[ 157.634] WARN ziti-sdk:conn_bridge.c:280 on_ziti_data() br[0.36] write failed: -32(broken pipe)
(8)[ 157.634] DEBUG ziti-sdk:conn_bridge.c:225 close_bridge() br[0.36] closing
(8)[ 157.634] DEBUG tunnel-cbs:ziti_hosting.c:903 on_bridge_close() closing local_addr[198.18.1.12:55314] fd[20]
(8)[ 157.634] WARN ziti-sdk:connect.c:796 flush_to_client() conn[0.36/CloseWrite] client indicated error[-32] accepting data (0 bytes buffered)
(8)[ 157.634] DEBUG ziti-sdk:connect.c:765 flush_to_service() conn[0.36/CloseWrite] got write req in invalid state[CloseWrite]
(8)[ 157.634] DEBUG ziti-sdk:channel.c:219 ziti_channel_rem_receiver() ch[0] removed receiver[36]
(8)[ 157.634] DEBUG ziti-sdk:connect.c:164 close_conn_internal() conn[0.36/Closed] removing
(8)[ 157.634] DEBUG ziti-sdk:ziti.c:1737 grim_reaper() ztx[0] reaped 1 closed (out of 9 total) connections
(8)[ 157.767] WARN ziti-sdk:channel.c:490 dispatch_message() ch[0] received message without conn_id or for unknown connection ct[ED72] conn_id[36]
(8)[ 158.234] WARN ziti-sdk:channel.c:490 dispatch_message() ch[0] received message without conn_id or for unknown connection ct[ED72] conn_id[36]
(8)[ 159.026] WARN ziti-sdk:channel.c:490 dispatch_message() ch[0] received message without conn_id or for unknown connection ct[ED72] conn_id[36]
(8)[ 160.771] WARN ziti-sdk:channel.c:490 dispatch_message() ch[0] received message without conn_id or for unknown connection ct[ED72] conn_id[36]
(8)[ 161.076] DEBUG ziti-sdk:bind.c:355 on_message() received msg ct[ed73] code[0] from ip-10-0-101-180-edge-router
(8)[ 161.076] DEBUG tunnel-cbs:ziti_hosting.c:536 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg]: received app_data_json='{"dst_hostname":"test2.ziti","dst_port":"443","dst_protocol":"tcp"}'
(8)[ 161.076] INFO tunnel-cbs:ziti_hosting.c:591 on_hosted_client_connect() hosted_service[test1] client[f.vUtXfOvg] dst_addr[tcp:198.18.1.12:443]: incoming connection
(8)[ 161.076] DEBUG tunnel-cbs:ziti_hosting.c:650 on_hosted_client_connect_resolved() hosted_service[test1] client[f.vUtXfOvg] initiating connection to tcp:198.18.1.12:443
(8)[ 161.077] DEBUG tunnel-cbs:ziti_hosting.c:228 on_hosted_tcp_server_connect_complete() hosted_service[test1], client[f.vUtXfOvg]: connected to server tcp:198.18.1.12:443
(8)[ 161.077] DEBUG ziti-sdk:channel.c:212 ziti_channel_add_receiver() ch[0] added receiver[45]
(8)[ 161.166] DEBUG tunnel-cbs:ziti_hosting.c:187 on_hosted_client_connect_complete() hosted_service[test1] client[f.vUtXfOvg] local_addr[198.18.1.12:37578] fd[14] server[tcp:198.18.1.12:443] connected 16
(8)[ 161.166] DEBUG ziti-sdk:conn_bridge.c:95 ziti_conn_bridge() br[0.45] connected
(8)[ 161.429] DEBUG ziti-sdk:posture.c:209 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]
(8)[ 164.130] WARN ziti-sdk:channel.c:490 dispatch_message() ch[0] received message without conn_id or for unknown connection ct[ED72] conn_id[36]
(8)[ 165.514] DEBUG ziti-sdk:connect.c:1154 send_fin_message() conn[0.18/CloseWrite] sending FIN
(8)[ 165.521] DEBUG ziti-sdk:connect.c:1154 send_fin_message() conn[0.19/CloseWrite] sending FIN