Some services unavailable right away with Windows Ziti Desktop Edge

Support
21

Oh :frowning: I suppose it's not able to force a cache clear/retry for a specific intercepted domain? The only reason I use an existing domain is so that let's encrypt can provide a valid SSL. It's not wise to tell users to blindly trust/accept cert errors in the browser :slight_smile:

22

Yeah, i understand... You should always get a wildcard cert though. Then you could add intercepts that don't actual resolve via regular DNS. or a wholly separate FQDN.

I have never been able to track down where and why and how the browser connection is cached. I just ensure no domain overlap and it will work as you want.

23

Makes sense, I suppose I could add a "z" in front of my services - I am currently using a wildcard already so could do zservice.domain.com instead of service.domain.com. Thanks for the suggestion!

24

Hey, guys.
I have the same problem. OpenZiti starts working after a minute. If the session was inactive (service turned off or the application was not connected to idenitity), I don't notice any problems.
Here is the log from my side:

[2025-05-15T22:43:42.224Z]   ERROR tlsuv:engine.c:961 openssl: write error: error:00000005:lib(0)::reason(5)
[2025-05-15T22:43:42.224Z]   ERROR ziti-sdk:channel.c:402 on_channel_send() ch[1] write failed [-4079/software caused connection abort]
[2025-05-15T22:43:42.224Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:1076 on_ziti_event() ztx[user.wj-laptop] router s1-dev-edge-router disconnected
[2025-05-15T22:43:42.224Z]    INFO ziti-sdk:channel.c:814 reconnect_channel() ch[1] reconnecting in 9257ms (attempt = 1)
[2025-05-15T22:43:42.226Z]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://example:8441] request failed: -4078(connection refused)
[2025-05-15T22:43:42.226Z]   ERROR ziti-sdk:ziti.c:1550 update_identity_data() ztx[0] failed to get identity_data: connection refused[CONTROLLER_UNAVAILABLE]
[2025-05-15T22:43:42.226Z]    WARN tunnel-cbs:ziti_tunnel_ctrl.c:1012 on_ziti_event() ziti_ctx controller connections failed: ziti controller is not available
[2025-05-15T22:43:42.226Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:456 on_event() ztx[c:\windows\system32\config\systemprofile\appdata\roaming\netfoundry\token.json] context event : status is ziti controller is not available
[2025-05-15T22:43:42.226Z]   ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:510 on_event() ztx[c:\windows\system32\config\systemprofile\appdata\roaming\netfoundry\token.json] failed to connect to controller due to ziti controller is not available
[2025-05-15T22:43:42.226Z]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://example:8441] request failed: -4078(connection refused)
[2025-05-15T22:43:42.226Z]   ERROR ziti-sdk:ziti.c:1475 edge_routers_cb() ztx[0] failed to get current edge routers: code[0] CONTROLLER_UNAVAILABLE/connection refused
[2025-05-15T22:43:42.226Z]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://example:8441] request failed: -4078(connection refused)
[2025-05-15T22:43:42.226Z]    INFO ziti-sdk:ziti_ctrl.c:180 ctrl_resp_cb() ctrl[https://example:8441] attempting to switch endpoint
[2025-05-15T22:43:42.226Z]    WARN ziti-sdk:ziti_ctrl.c:600 ctrl_next_ep() ctrl[https://example:8441] no controllers are online
[2025-05-15T22:43:42.226Z]    WARN ziti-sdk:ziti.c:1423 check_service_update() ztx[0] failed to poll service updates: code[0] err[-16/connection refused]
[2025-05-15T22:47:14.196Z]   ERROR ziti-sdk:channel.c:958 on_tls_connect() ch[1] failed to connect to ER[s1-dev-edge-router] [-4078/connection refused]
[2025-05-15T22:47:14.196Z]    INFO ziti-sdk:channel.c:814 reconnect_channel() ch[1] reconnecting in 5983ms (attempt = 2)
[2025-05-15T22:47:14.196Z]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://example:8441] request failed: -4078(connection refused)
[2025-05-15T22:47:14.196Z]   ERROR ziti-sdk:ziti.c:1550 update_identity_data() ztx[0] failed to get identity_data: connection refused[CONTROLLER_UNAVAILABLE]
[2025-05-15T22:47:14.196Z]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://example:8441] request failed: -4078(connection refused)
[2025-05-15T22:47:14.196Z]   ERROR ziti-sdk:ziti.c:1475 edge_routers_cb() ztx[0] failed to get current edge routers: code[0] CONTROLLER_UNAVAILABLE/connection refused
[2025-05-15T22:47:14.196Z]    WARN ziti-sdk:ziti_ctrl.c:177 ctrl_resp_cb() ctrl[https://example:8441] request failed: -4078(connection refused)
[2025-05-15T22:47:14.196Z]    INFO ziti-sdk:ziti_ctrl.c:180 ctrl_resp_cb() ctrl[https://example:8441] attempting to switch endpoint
[2025-05-15T22:47:14.196Z]    WARN ziti-sdk:ziti_ctrl.c:600 ctrl_next_ep() ctrl[https://example:8441] no controllers are online
[2025-05-15T22:47:14.196Z]    WARN ziti-sdk:ziti.c:1423 check_service_update() ztx[0] failed to poll service updates: code[0] err[-16/connection refused]
[2025-05-15T22:47:20.312Z]    INFO ziti-sdk:channel.c:714 hello_reply_cb() ch[1] connected. EdgeRouter version: v1.5.4|6739025d0bd6|2025-03-28T13:39:47Z|linux|amd64
[2025-05-15T22:47:20.313Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:1073 on_ziti_event() ztx[user.wj-laptop] router s1-dev-edge-router connected
[2025-05-15T22:48:38.087Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:998 on_ziti_event() ziti_ctx[user.wj-laptop] connected to controller

I can add that the controller itself but port 8441 is accessible via curl. I also set up a new connection on the PC today. I got the same errors (software caused connection abort). The problem was solved by setting the add DNS flag. Maybe it has something to do with the Ziti DNS server

25

Hi @wusikijeronii, welcome to the community and to OpenZiti!

Are you also using shadowing a legitimate DNS entry? If so, it sure seems like the app(browser?) are caching the actual IP within the app itself, so I'd recommend against shadowing a legitimate DNS entry for that reason. If it's a different scenario, please try to describe the situation?

Mmmm. I probably need to remove this flag entirely. You likely don't want to enable it. That was around from many, many years ago back before the NRPT-based approach was as solid has it has been for years. I'd really recommend you don't rely on that particular flag at this time.

If you want to send me more specific details via DM, we can keep the public stuff here and the private stuff in DM (if you don't want to share what services you're trying to access and how).

I use OpenZiti all day every day and I don't get this particular issue, but I also very, very rarely shadow a legitimate DNS entry with the services I create so I might not be testing how you are.

26

I don't think there are things we should discuss privately. I keep it as simple as possible. I don't use OpenZiti DNS from a server perspective at all. There are DNS servers on my local network. I write something like myservice.mylan in the host/intercept settings. That is, the OpenZiti servers take that entry from the local settings on the servers themselves. All BIND tunnelers run without a DNS resolver.
I have one more thing to add. Today OpenZiti stopped working abruptly. All connections ended with a timeout. I figured out that the problem was a bad entry in /etc/resolv.conf that pointed to an address on the OpenZiti subnet. This is probably an artifact of running OpenZiti with a DNS resolver. As a result, each request to get a DNS record took about 5 seconds. This is enough for OpenZiti to consider the resource unavailable. Maybe the problem was on my side. Let me test for a couple more days, and I'll let you know if this problem occurs. Honestly, I don't really want to simulate the problem, reproduce errors, etc. It's not a particularly critical problem. It's better to test with live regular use.

1 Like
27

Sounds good. If you end up hitting a problem, just let us know and we'll try to help out. Cheers!

28

@TheLumberjack Hello, again. The same issue. Curl - ok. Service - refused.
Debug logs:

[2025-05-16T18:49:29.705Z]   DEBUG tunnel-sdk:tunnel_tcp.c:438 recv_tcp() intercepted address[tcp:100.64.0.22:443] client[tcp:100.64.0.1:52474] service[dev-platform-web]
[2025-05-16T18:49:29.705Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:287 ziti_sdk_c_dial() ziti_dial(name=dev-platform-web)
[2025-05-16T18:49:29.705Z]   DEBUG tunnel-cbs:ziti_tunnel_cbs.c:354 ziti_sdk_c_dial() service[dev-platform-web] app_data_json[183]='{"connType":null,"dst_protocol":"tcp","dst_hostname":"myservice.example","dst_ip":"100.64.0.22","dst_port":"443","src_protocol":"tcp","src_ip":"100.64.0.1","src_port":"52474"}'
[2025-05-16T18:49:29.705Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.232/wZyc1H69/Initial](dev-platform-web) transitioning Initial => Connecting
[2025-05-16T18:49:29.705Z]   ERROR ziti-sdk:connect.c:508 process_connect() conn[0.232/wZyc1H69/Connecting](dev-platform-web) ziti context is not authenticated, cannot connect to service[dev-platform-web]
[2025-05-16T18:49:29.705Z]   DEBUG ziti-sdk:connect.c:323 complete_conn_req() conn[0.232/wZyc1H69/Connecting](dev-platform-web) Connecting failed: invalid state
[2025-05-16T18:49:29.705Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.232/wZyc1H69/Connecting](dev-platform-web) transitioning Connecting => Disconnected
[2025-05-16T18:49:29.705Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:93 on_ziti_connect() on_ziti_connect status: -22
[2025-05-16T18:49:29.705Z]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
[2025-05-16T18:49:29.705Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.232/wZyc1H69/Disconnected](dev-platform-web) transitioning Disconnected => Closed
[2025-05-16T18:49:29.705Z]   TRACE ziti-sdk:connect.c:814 flush_connection() conn[0.232/wZyc1H69/Closed](dev-platform-web) starting flusher
[2025-05-16T18:49:29.705Z]   TRACE tunnel-sdk:ziti_tunnel.c:516 check_lwip_timeouts() next wake in 490 millis
[2025-05-16T18:49:29.705Z]   DEBUG ziti-sdk:connect.c:897 flush_to_client() conn[0.232/wZyc1H69/Closed](dev-platform-web) no data_cb: can't flush, 0 bytes available
[2025-05-16T18:49:29.705Z]   TRACE ziti-sdk:connect.c:807 on_flush() conn[0.232/wZyc1H69/Closed](dev-platform-web) stopping flusher
[2025-05-16T18:49:29.705Z]   DEBUG ziti-sdk:connect.c:184 close_conn_internal() conn[0.232/wZyc1H69/Closed](dev-platform-web) removing
[2025-05-16T18:49:29.705Z]   TRACE tunnel-cbs:ziti_tunnel_cbs.c:602 ziti_conn_close_cb() ziti_conn[00000260ac289140] is closed
[2025-05-16T18:49:29.705Z]   DEBUG tunnel-sdk:ziti_tunnel.c:445 ziti_tunneler_close() closing connection: client[tcp:100.64.0.1:52474] service[dev-platform-web]
[2025-05-16T18:49:29.705Z]   DEBUG tunnel-sdk:tunnel_tcp.c:252 tunneler_tcp_close() closing src[tcp:100.64.0.1:52474] dst[tcp:100.64.0.22:443] state[3/SYN_RCVD] flags[0x100] service[dev-platform-web]
[2025-05-16T18:49:29.705Z]   DEBUG tunnel-sdk:tunnel_tcp.c:260 tunneler_tcp_close() closing connection before handshake complete. sending RST to client
[2025-05-16T18:49:29.705Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet TCP[100.64.0.22:443 -> 100.64.0.1:52474] len=40
[2025-05-16T18:49:29.705Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:615 ziti_conn_close_cb() nulled data for ziti_conn[00000260ac289140]
[2025-05-16T18:49:29.705Z]   TRACE ziti-sdk:connect.c:225 close_conn_internal() conn[0.232/wZyc1H69/Closed](dev-platform-web) is being free()'d
[2025-05-16T18:49:29.705Z]   DEBUG ziti-sdk:ziti.c:1683 grim_reaper() ztx[0] reaped 1 closed (out of 1 total) connections
[2025-05-16T18:49:29.959Z]   TRACE ziti-edge-tunnel:tun.c:347 tun_read() starting read
[2025-05-16T18:49:29.959Z]   TRACE tunnel-sdk:tunnel_tcp.c:372 recv_tcp() received segment src[tcp:100.64.0.1:52475] dst[tcp:100.64.0.22:443] flags[SYN]
[2025-05-16T18:49:29.959Z] VERBOSE tunnel-sdk:intercept.c:130 port_match() matching port 443 to range 80
[2025-05-16T18:49:29.959Z] VERBOSE tunnel-sdk:intercept.c:130 port_match() matching port 443 to range 443
[2025-05-16T18:49:29.959Z] VERBOSE tunnel-sdk:intercept.c:133 port_match() port 443 matches range 443 with score 0
[2025-05-16T18:49:29.959Z] VERBOSE tunnel-sdk:intercept.c:135 port_match() port 443 is best match so far
[2025-05-16T18:49:29.959Z]   DEBUG tunnel-sdk:tunnel_tcp.c:116 new_tcp_pcb() snd_wnd: 65535, snd_snd_max: 65535, mss: 16382
[2025-05-16T18:49:29.959Z]   DEBUG tunnel-sdk:tunnel_tcp.c:438 recv_tcp() intercepted address[tcp:100.64.0.22:443] client[tcp:100.64.0.1:52475] service[dev-platform-web]
[2025-05-16T18:49:29.959Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:287 ziti_sdk_c_dial() ziti_dial(name=dev-platform-web)
[2025-05-16T18:49:29.959Z]   DEBUG tunnel-cbs:ziti_tunnel_cbs.c:354 ziti_sdk_c_dial() service[dev-platform-web] app_data_json[183]='{"connType":null,"dst_protocol":"tcp","dst_hostname":"myservice.example","dst_ip":"100.64.0.22","dst_port":"443","src_protocol":"tcp","src_ip":"100.64.0.1","src_port":"52475"}'
[2025-05-16T18:49:29.959Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.233/57XT0SeH/Initial](dev-platform-web) transitioning Initial => Connecting
[2025-05-16T18:49:29.959Z]   ERROR ziti-sdk:connect.c:508 process_connect() conn[0.233/57XT0SeH/Connecting](dev-platform-web) ziti context is not authenticated, cannot connect to service[dev-platform-web]
[2025-05-16T18:49:29.959Z]   DEBUG ziti-sdk:connect.c:323 complete_conn_req() conn[0.233/57XT0SeH/Connecting](dev-platform-web) Connecting failed: invalid state
[2025-05-16T18:49:29.959Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.233/57XT0SeH/Connecting](dev-platform-web) transitioning Connecting => Disconnected
[2025-05-16T18:49:29.959Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:93 on_ziti_connect() on_ziti_connect status: -22
[2025-05-16T18:49:29.959Z]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
[2025-05-16T18:49:29.959Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.233/57XT0SeH/Disconnected](dev-platform-web) transitioning Disconnected => Closed
[2025-05-16T18:49:29.959Z]   TRACE ziti-sdk:connect.c:814 flush_connection() conn[0.233/57XT0SeH/Closed](dev-platform-web) starting flusher
[2025-05-16T18:49:29.959Z]   TRACE tunnel-sdk:ziti_tunnel.c:516 check_lwip_timeouts() next wake in 236 millis
[2025-05-16T18:49:29.959Z]   DEBUG ziti-sdk:connect.c:897 flush_to_client() conn[0.233/57XT0SeH/Closed](dev-platform-web) no data_cb: can't flush, 0 bytes available
[2025-05-16T18:49:29.959Z]   TRACE ziti-sdk:connect.c:807 on_flush() conn[0.233/57XT0SeH/Closed](dev-platform-web) stopping flusher
[2025-05-16T18:49:29.959Z]   DEBUG ziti-sdk:connect.c:184 close_conn_internal() conn[0.233/57XT0SeH/Closed](dev-platform-web) removing
[2025-05-16T18:49:29.959Z]   TRACE tunnel-cbs:ziti_tunnel_cbs.c:602 ziti_conn_close_cb() ziti_conn[00000260ac288f70] is closed
[2025-05-16T18:49:29.959Z]   DEBUG tunnel-sdk:ziti_tunnel.c:445 ziti_tunneler_close() closing connection: client[tcp:100.64.0.1:52475] service[dev-platform-web]
[2025-05-16T18:49:29.959Z]   DEBUG tunnel-sdk:tunnel_tcp.c:252 tunneler_tcp_close() closing src[tcp:100.64.0.1:52475] dst[tcp:100.64.0.22:443] state[3/SYN_RCVD] flags[0x100] service[dev-platform-web]
[2025-05-16T18:49:29.959Z]   DEBUG tunnel-sdk:tunnel_tcp.c:260 tunneler_tcp_close() closing connection before handshake complete. sending RST to client
[2025-05-16T18:49:29.959Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet TCP[100.64.0.22:443 -> 100.64.0.1:52475] len=40
[2025-05-16T18:49:29.959Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:615 ziti_conn_close_cb() nulled data for ziti_conn[00000260ac288f70]
[2025-05-16T18:49:29.959Z]   TRACE ziti-sdk:connect.c:225 close_conn_internal() conn[0.233/57XT0SeH/Closed](dev-platform-web) is being free()'d
[2025-05-16T18:49:29.959Z]   DEBUG ziti-sdk:ziti.c:1683 grim_reaper() ztx[0] reaped 1 closed (out of 1 total) connections
[2025-05-16T18:49:30.054Z] VERBOSE ziti-sdk:ziti_ctrl.c:145 start_request() ctrl[https://example:8441] starting POST[/authenticate?method=cert]
[2025-05-16T18:49:30.260Z]   TRACE ziti-edge-tunnel:tun.c:347 tun_read() starting read
[2025-05-16T18:49:30.260Z]   TRACE tunnel-sdk:tunnel_tcp.c:372 recv_tcp() received segment src[tcp:100.64.0.1:52474] dst[tcp:100.64.0.22:443] flags[SYN]
[2025-05-16T18:49:30.260Z] VERBOSE tunnel-sdk:intercept.c:130 port_match() matching port 443 to range 80
[2025-05-16T18:49:30.260Z] VERBOSE tunnel-sdk:intercept.c:130 port_match() matching port 443 to range 443
[2025-05-16T18:49:30.260Z] VERBOSE tunnel-sdk:intercept.c:133 port_match() port 443 matches range 443 with score 0
[2025-05-16T18:49:30.260Z] VERBOSE tunnel-sdk:intercept.c:135 port_match() port 443 is best match so far
[2025-05-16T18:49:30.260Z]   DEBUG tunnel-sdk:tunnel_tcp.c:116 new_tcp_pcb() snd_wnd: 65535, snd_snd_max: 65535, mss: 16382
[2025-05-16T18:49:30.260Z]   DEBUG tunnel-sdk:tunnel_tcp.c:438 recv_tcp() intercepted address[tcp:100.64.0.22:443] client[tcp:100.64.0.1:52474] service[dev-platform-web]
[2025-05-16T18:49:30.260Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:287 ziti_sdk_c_dial() ziti_dial(name=dev-platform-web)
[2025-05-16T18:49:30.260Z]   DEBUG tunnel-cbs:ziti_tunnel_cbs.c:354 ziti_sdk_c_dial() service[dev-platform-web] app_data_json[183]='{"connType":null,"dst_protocol":"tcp","dst_hostname":"myservice.example","dst_ip":"100.64.0.22","dst_port":"443","src_protocol":"tcp","src_ip":"100.64.0.1","src_port":"52474"}'
[2025-05-16T18:49:30.260Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.234/WCON7a83/Initial](dev-platform-web) transitioning Initial => Connecting
[2025-05-16T18:49:30.260Z]   ERROR ziti-sdk:connect.c:508 process_connect() conn[0.234/WCON7a83/Connecting](dev-platform-web) ziti context is not authenticated, cannot connect to service[dev-platform-web]
[2025-05-16T18:49:30.260Z]   DEBUG ziti-sdk:connect.c:323 complete_conn_req() conn[0.234/WCON7a83/Connecting](dev-platform-web) Connecting failed: invalid state
[2025-05-16T18:49:30.260Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.234/WCON7a83/Connecting](dev-platform-web) transitioning Connecting => Disconnected
[2025-05-16T18:49:30.260Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:93 on_ziti_connect() on_ziti_connect status: -22
[2025-05-16T18:49:30.260Z]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: invalid state
[2025-05-16T18:49:30.260Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.234/WCON7a83/Disconnected](dev-platform-web) transitioning Disconnected => Closed
[2025-05-16T18:49:30.260Z]   TRACE ziti-sdk:connect.c:814 flush_connection() conn[0.234/WCON7a83/Closed](dev-platform-web) starting flusher
[2025-05-16T18:49:30.260Z]   TRACE tunnel-sdk:ziti_tunnel.c:516 check_lwip_timeouts() next wake in 1000 millis
[2025-05-16T18:49:30.260Z]   DEBUG ziti-sdk:connect.c:897 flush_to_client() conn[0.234/WCON7a83/Closed](dev-platform-web) no data_cb: can't flush, 0 bytes available
[2025-05-16T18:49:30.260Z]   TRACE ziti-sdk:connect.c:807 on_flush() conn[0.234/WCON7a83/Closed](dev-platform-web) stopping flusher
[2025-05-16T18:49:30.260Z]   DEBUG ziti-sdk:connect.c:184 close_conn_internal() conn[0.234/WCON7a83/Closed](dev-platform-web) removing
[2025-05-16T18:49:30.260Z]   TRACE tunnel-cbs:ziti_tunnel_cbs.c:602 ziti_conn_close_cb() ziti_conn[00000260ac289310] is closed
[2025-05-16T18:49:30.260Z]   DEBUG tunnel-sdk:ziti_tunnel.c:445 ziti_tunneler_close() closing connection: client[tcp:100.64.0.1:52474] service[dev-platform-web]
[2025-05-16T18:49:30.260Z]   DEBUG tunnel-sdk:tunnel_tcp.c:252 tunneler_tcp_close() closing src[tcp:100.64.0.1:52474] dst[tcp:100.64.0.22:443] state[3/SYN_RCVD] flags[0x100] service[dev-platform-web]
[2025-05-16T18:49:30.260Z]   DEBUG tunnel-sdk:tunnel_tcp.c:260 tunneler_tcp_close() closing connection before handshake complete. sending RST to client
[2025-05-16T18:49:30.260Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet TCP[100.64.0.22:443 -> 100.64.0.1:52474] len=40
[2025-05-16T18:49:30.260Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:615 ziti_conn_close_cb() nulled data for ziti_conn[00000260ac289310]
[2025-05-16T18:49:30.260Z]   TRACE ziti-sdk:connect.c:225 close_conn_internal() conn[0.234/WCON7a83/Closed](dev-platform-web) is being free()'d
[2025-05-16T18:49:30.260Z]   DEBUG ziti-sdk:ziti.c:1683 grim_reaper() ztx[0] reaped 1 closed (out of 1 total) connections
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:200 ctrl_resp_cb() ctrl[https://example:8441] received headers POST[/authenticate?method=cert]
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:427 ctrl_body_cb() ctrl[https://example:8441] HTTP RESPONSE: {"data":{"_links":{"self":{"href":"./api-sessions/cmar5kfgdd1etpmfuveo7xotk"},"sessions":{"href":"./api-sessions/cmar5kfgdd1etpmfuveo7xotk/sessions"}},"createdAt":"2025-05-16T18:49:31.453Z","id":"cmar5kfgdd1etpmfuveo7xotk","tags":{},"updatedAt":"2025-05-16T18:49:31.453Z","authQueries":[],"authenticatorId":"flG-jJy7F","cachedLastActivityAt":"2025-05-16T18:49:31.453Z","configTypes":["all"],"identity":{"_links":{"auth-policies":{"href":"./auth-policies/default"},"authenticators":{"href":"./identities/XeabjlV7F/authenticators"},"edge-router-policies":{"href":"./identities/XeabjlV7F/edge-router-policies"},"edge-routers":{"href":"./identities/XeabjlV7F/edge-routers"},"enrollments":{"href":"./identities/XeabjlV7F/enrollments"},"failed-service-requests":{"href":"./identities/XeabjlV7F/failed-service-requests"},"posture-data":{"href":"./identities/XeabjlV7F/posture-data"},"self":{"href":"./identities/XeabjlV7F"},"service-configs":{"href":"./identities/XeabjlV7F/service
[2025-05-16T18:49:30.372Z]   DEBUG ziti-sdk:ziti_ctrl.c:500 ctrl_body_cb() ctrl[https://example:8441] completed POST[/authenticate?method=cert] in 0.318 s
[2025-05-16T18:49:30.372Z]   DEBUG ziti-sdk:ziti_ctrl.c:394 ctrl_login_cb() ctrl[https://example:8441] authenticated successfully session[cmar5kfgdd1etpmfuveo7xotk]
[2025-05-16T18:49:30.372Z]   DEBUG ziti-sdk:legacy_auth.c:170 login_cb() logged in successfully => api_session[cmar5kfgdd1etpmfuveo7xotk]
[2025-05-16T18:49:30.372Z]   DEBUG ziti-sdk:ziti.c:379 ziti_set_fully_authenticated() ztx[0] setting auth_state[0] to 3
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:145 start_request() ctrl[https://example:8441] starting GET[/.well-known/est/cacerts]
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:145 start_request() ctrl[https://example:8441] starting GET[/current-identity]
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti.c:1460 ziti_services_refresh() ztx[0] forcing service refresh
[2025-05-16T18:49:30.372Z]   TRACE ziti-sdk:legacy_auth.c:262 refresh_delay() API supports cached_last_activity_at
[2025-05-16T18:49:30.372Z]   DEBUG ziti-sdk:legacy_auth.c:292 refresh_delay() api session set, next refresh in 1740s
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:145 start_request() ctrl[https://example:8441] starting GET[/current-identity]
[2025-05-16T18:49:30.372Z]   DEBUG ziti-sdk:ziti_ctrl.c:1087 ctrl_paging_req() ctrl[https://example:8441] starting paging request GET[/current-identity/edge-routers]
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:1092 ctrl_paging_req() ctrl[https://example:8441] requesting /current-identity/edge-routers?limit=25&offset=0
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:145 start_request() ctrl[https://example:8441] starting GET[/current-identity/edge-routers?limit=25&offset=0]
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:ziti_ctrl.c:145 start_request() ctrl[https://example:8441] starting GET[/current-api-session/service-updates]
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:posture.c:196 ziti_send_posture_data() ztx[0] starting to send posture data
[2025-05-16T18:49:30.372Z]   DEBUG ziti-sdk:posture.c:210 ziti_send_posture_data() ztx[0] posture checks must_send set to TRUE, new_session_id[TRUE], must_send_every_time[TRUE], new_controller_instance[FALSE]
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:posture.c:239 ziti_send_posture_data() ztx[0] checking posture queries on 7 service(s)
[2025-05-16T18:49:30.372Z] VERBOSE ziti-sdk:posture.c:606 ziti_pr_send_bulk() ztx[0] no change in posture data, not sending
[2025-05-16T18:49:30.414Z] VERBOSE ziti-sdk:ziti_ctrl.c:200 ctrl_resp_cb() ctrl[https://example:8441] received headers GET[/.well-known/est/cacerts]
[2025-05-16T18:49:30.467Z]   TRACE ziti-edge-tunnel:tun.c:347 tun_read() starting read
[2025-05-16T18:49:30.467Z]   TRACE tunnel-sdk:tunnel_tcp.c:372 recv_tcp() received segment src[tcp:100.64.0.1:52475] dst[tcp:100.64.0.22:443] flags[SYN]
[2025-05-16T18:49:30.467Z] VERBOSE tunnel-sdk:intercept.c:130 port_match() matching port 443 to range 80
[2025-05-16T18:49:30.467Z] VERBOSE tunnel-sdk:intercept.c:130 port_match() matching port 443 to range 443
[2025-05-16T18:49:30.467Z] VERBOSE tunnel-sdk:intercept.c:133 port_match() port 443 matches range 443 with score 0
[2025-05-16T18:49:30.467Z] VERBOSE tunnel-sdk:intercept.c:135 port_match() port 443 is best match so far
[2025-05-16T18:49:30.467Z]   DEBUG tunnel-sdk:tunnel_tcp.c:116 new_tcp_pcb() snd_wnd: 65535, snd_snd_max: 65535, mss: 16382
[2025-05-16T18:49:30.467Z]   DEBUG tunnel-sdk:tunnel_tcp.c:438 recv_tcp() intercepted address[tcp:100.64.0.22:443] client[tcp:100.64.0.1:52475] service[dev-platform-web]
[2025-05-16T18:49:30.467Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:287 ziti_sdk_c_dial() ziti_dial(name=dev-platform-web)
[2025-05-16T18:49:30.467Z]   DEBUG tunnel-cbs:ziti_tunnel_cbs.c:354 ziti_sdk_c_dial() service[dev-platform-web] app_data_json[183]='{"connType":null,"dst_protocol":"tcp","dst_hostname":"myservice.example","dst_ip":"100.64.0.22","dst_port":"443","src_protocol":"tcp","src_ip":"100.64.0.1","src_port":"52475"}'
[2025-05-16T18:49:30.467Z] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[0.235/x9rbJj4O/Initial](dev-platform-web) transitioning Initial => Connecting
[2025-05-16T18:49:30.467Z]   DEBUG ziti-sdk:connect.c:435 connect_get_service_cb() conn[0.235/x9rbJj4O/Connecting](dev-platform-web) got service[dev-platform-web] id[8f4jPU7vSb19l9uFKnfGL]
[2025-05-16T18:49:30.467Z] VERBOSE ziti-sdk:posture.c:196 ziti_send_posture_data() ztx[0] starting to send posture data
[2025-05-16T18:49:30.467Z]   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]
[2025-05-16T18:49:30.467Z] VERBOSE ziti-sdk:posture.c:239 ziti_send_posture_data() ztx[0] checking posture queries on 7 service(s)
[2025-05-16T18:49:30.467Z] VERBOSE ziti-sdk:posture.c:606 ziti_pr_send_bulk() ztx[0] no change in posture data, not sending
[2025-05-16T18:49:30.467Z]   DEBUG ziti-sdk:connect.c:531 process_connect() conn[0.235/x9rbJj4O/Connecting](dev-platform-web) requesting 'Dial' session for service[dev-platform-web]
[2025-05-16T18:49:30.467Z] VERBOSE ziti-sdk:ziti_ctrl.c:145 start_request() ctrl[https://example:8441] starting POST[/sessions]
[2025-05-16T18:49:30.467Z]   TRACE tunnel-sdk:ziti_tunnel.c:516 check_lwip_timeouts() next wake in 794 millis
[2025-05-16T18:49:30.474Z] VERBOSE ziti-sdk:ziti_ctrl.c:200 ctrl_resp_cb() ctrl[https://example:8441] received headers GET[/current-identity]
[2025-05-16T18:49:30.474Z] VERBOSE ziti-sdk:ziti_ctrl.c:427 ctrl_body_cb() ctrl[https://example:8441] HTTP RESPONSE: {"data":{"_links":{"mfa":{"href":"./current-identity/mfa"},"self":{"href":"./current-identity"}},"createdAt":"2025-05-09T18:01:36.629Z","id":"XeabjlV7F","tags":{},"updatedAt":"2025-05-16T11:50:10.087Z","appData":{},"authPolicy":{"_links":{"self":{"href":"./auth-policies/default"}},"entity":"auth-policies","id":"default","name":"Default"},"authPolicyId":"default","authenticators":{"cert":{"fingerprint":"08476929524fea45058ad59d329ae023bbdfcdb1","id":"flG-jJy7F"}},"defaultHostingCost":0,"defaultHostingPrecedence":"default","disabled":false,"edgeRouterConnectionStatus":"offline","enrollment":{},"envInfo":{"arch":"x86_64","domain":"WORKGROUP","hostname":"LAPTOP-4PA9J0V4","os":"MINGW32_NT-10.0","osRelease":"10.0.26100","osVersion":"Windows 11 Home"},"externalId":null,"hasApiSession":true,"hasEdgeRouterConnection":false,"isAdmin":true,"isDefaultAdmin":false,"isMfaEnabled":false,"name":"user.wj-laptop","roleAttributes":["dev-scope","developer","network-admin","platfo
[2025-05-16T18:49:30.474Z]   DEBUG ziti-sdk:ziti_ctrl.c:500 ctrl_body_cb() ctrl[https://example:8441] completed GET[/current-identity] in 0.102 s
[2025-05-16T18:49:30.474Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:998 on_ziti_event() ziti_ctx[user.wj-laptop] connected to controller

I think the main cause of the problem is described in this line:

ziti context is not authenticated, cannot connect to service[dev-platform-web]

Apparently Ziti Edge Desktop saves the session. When you exit sleep mode, the session is expired. But instead of reconnecting immediately, it queues the reconnection task. I honestly haven't looked into how OpenZiti works internally, and so I could be wrong.
If more information is needed on my end, let me know. I am ready to provide everything you need.

29

Ah ok. That might make sense then. You must also be using external jwt authentication, right? I think there was a bug around this that @ekoby recently fixed. A new version of the ZDEW is likely to be rolling out in the coming days/weeks. I think it'll be worthwhile to update and find out if that solves the problem. If not, we should definitely dig deeper, if you're willing to help us find the issue.

As to 'how' it should work, here's how the flow should go:

  • Turn on ZDEW
  • Authenticate to IdP and obtain access/id/refresh tokens from IdP
  • ZDEW (technically the C SDK via ziti-edge-tunnel) caches the refresh token to refresh the session as needed
  • put machine to sleep for more than 30 minutes (30 minutes is the default timeout of an OpenZiti session)
  • wake machine from sleep, ZDEW/ziti-edge-tunnel notices the session is no longer valid and uses refresh token to obtain new access token and re-authenticate with OpenZiti

It sounds like that last bullet isn't happening immediately, based on what you're reporting. Do I have that correct?

30

To be honest, I have only recently installed the OpenZiti network. I don't really know what's going on yet. I don't really understand what external JWT authorization is. I created an identity on the server, downloaded the JWT token, and added it to ZDEW. You could say that my server is external. I don't really understand what you mean by that. But only the client and server participate in the network, and there are no external providers.
Yes, in general you have described everything correctly and understood everything correctly.
In any case, we need to first see if the fixes that will be available in the next release help to solve the problem.

31

I am having a similar issue to what is being explained here, but it is not consistent. I was wondering if it was switching between wired and wireless, or from external to internal. For me, I use Ziti for authentication etc. I cannot connect to any service until I restart the ZDEW services from within the client. It is intermittent, and are trying to understand the circumstances as to when it happens.

32

Interesting, that's definitely unexpected, yeah. If you wanted to capture a feedback log before things go bad and then just after, along with describing what happened it could help us for sure.

Changing from internal to external is interesting sounding as to what that means exactly. Do you have many routers or just a few? A topology diagram would probably help too. It definitely sounds like a problem of some kind is here, we just need to figure out how to trigger it to fix it.