services cannot be dialed after dial permission is removed and restored #905
Description
ziti-prox-c startup
ziti-prox-c run -i /Users/scarey/.ziti/shawns-m1-mbp/zet.shawns-m1-mbp.json -d6 ssh:2222
[ 0.000] INFO ziti-sdk:utils.c:196 ziti_log_set_level() set log level: root=6/TRACE
[ 0.000] INFO ziti-sdk:utils.c:167 ziti_log_init() Ziti C SDK version 1.8.1 @g3104fe4(main) starting at (2025-08-20T13:41:39.213)
[ 0.000] INFO ziti-prox-c:proxy.c:854 run_proxy() built with SDK version 1.8.1(g3104fe4)[Aug 20 2025
[ 0.000] INFO ziti-prox-c:proxy.c:862 run_proxy() starting event loop
[ 0.001] INFO ziti-sdk:ziti.c:512 ziti_start_internal() ztx[1] enabling Ziti Context
[ 0.001] INFO ziti-sdk:ziti.c:529 ziti_start_internal() ztx[1] using tlsuv[v0.37.4/OpenSSL 3.5.0 8 Apr 2025]
...
[ 0.101] VERBOSE ziti-sdk:ziti.c:1310 update_services() ztx[1] processing service updates
[ 0.101] DEBUG ziti-sdk:ziti.c:1388 update_services() ztx[1] sending service event initial[true] 1 added, 0 removed, 0 changed
[ 0.101] DEBUG ziti-prox-c:proxy.c:426 service_check_cb() service[ssh]: OK
[ 0.101] INFO ziti-prox-c:proxy.c:314 update_listener() starting listener for service[ssh] on port[2222]
successful ssh connection, then dial policy removed
% ssh -p 2222 127.0.0.1
Last login: Wed Aug 20 09:41:31 2025 from 10.211.55.2
scarey@fedora-42-vm:~$
logout
% ziti edge update identity zet.shawns-m1-mbp -a ssh-binders
ziti-prox-c handles the policy update
[ 60.167] VERBOSE ziti-sdk:ziti.c:1310 update_services() ztx[1] processing service updates
[ 60.167] VERBOSE ziti-sdk:ziti.c:1276 is_service_updated() ztx[1] service [ssh] is updated, new service lost a policy [5qEuLtiw8dXm8yMKpTGbtf]
[ 60.167] DEBUG ziti-sdk:ziti.c:1388 update_services() ztx[1] sending service event initial[false] 0 added, 0 removed, 1 changed
[ 60.167] DEBUG ziti-prox-c:proxy.c:426 service_check_cb() service[ssh]: OK
[ 60.167] WARN ziti-prox-c:proxy.c:323 update_listener() service ssh is not available. stopping listener[2222]
dial policy restored
% ziti edge update identity zet.shawns-m1-mbp -a ssh-binders,ssh-dialers
ziti-prox-c handles the policy update
[ 120.219] VERBOSE ziti-sdk:ziti.c:1310 update_services() ztx[1] processing service updates
[ 120.219] VERBOSE ziti-sdk:ziti.c:1253 is_service_updated() ztx[1] service [ssh] is updated, new service gained a policy [5qEuLtiw8dXm8yMKpTGbtf]
[ 120.219] DEBUG ziti-sdk:ziti.c:1388 update_services() ztx[1] sending service event initial[false] 0 added, 0 removed, 1 changed
[ 120.219] DEBUG ziti-prox-c:proxy.c:426 service_check_cb() service[ssh]: OK
[ 120.219] INFO ziti-prox-c:proxy.c:314 update_listener() starting listener for service[ssh] on port[2222]
dial fails
[ 137.954] DEBUG ziti-prox-c:proxy.c:281 on_client() client connection accepted from 127.0.0.1:56836 (ssh:2222)
[ 137.954] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[1.1/7XVs5B7k/Initial](ssh) transitioning Initial => Connecting
[ 137.954] DEBUG ziti-sdk:connect.c:431 connect_get_service_cb() conn[1.1/7XVs5B7k/Connecting](ssh) got service[ssh] id[6JsvS8ujoG5YU4ylDXsaPu]
[ 137.954] VERBOSE ziti-sdk:posture.c:196 ziti_send_posture_data() ztx[1] starting to send posture data
[ 137.954] DEBUG ziti-sdk:posture.c:213 ziti_send_posture_data() ztx[1] posture checks must_send set to TRUE, new_session_id[FALSE], must_send_every_time[TRUE], new_controller_instance[FALSE]
[ 137.954] VERBOSE ziti-sdk:posture.c:239 ziti_send_posture_data() ztx[1] checking posture queries on 1 service(s)
[ 137.954] VERBOSE ziti-sdk:posture.c:606 ziti_pr_send_bulk() ztx[1] no change in posture data, not sending
[ 137.954] DEBUG ziti-sdk:connect.c:550 process_connect() conn[1.1/7XVs5B7k/Connecting](ssh) starting Dial connection for service[ssh] with session[cmek0ul51mjldhtx56i0vuk9x]
[ 137.954] DEBUG ziti-sdk:connect.c:409 ziti_connect() conn[1.1/7XVs5B7k/Connecting](ssh) selected ch[er.shawns-m1-mbp@tls://shawns-m1-mbp.localdomain:3022] for best latency(1 ms)
[ 137.954] TRACE ziti-sdk:connect.c:1123 ziti_channel_start_connection() conn[1.1/7XVs5B7k/Connecting](ssh) ch[0] => Edge Connect request token[d57ae59b-da60-4e36-b5ba-20846f8622e4]
[ 137.954] DEBUG ziti-sdk:channel.c:238 ziti_channel_add_receiver() ch[0] added receiver[1]
[ 137.954] TRACE ziti-sdk:channel.c:435 ziti_channel_send_message() ch[0] => ct[ConnectType] seq[19] len[36]
[ 137.954] TRACE ziti-sdk:channel.c:405 on_channel_send() ch[0] write delay = 0.000d q=1 qs=162
[ 137.955] TRACE ziti-sdk:ziti.c:1761 ztx_prep_deadlines() ztx[1] processing deadlines in 2148
[ 137.956] TRACE ziti-sdk:channel.c:937 on_channel_data() ch[0] on_data [len=58]
[ 137.956] TRACE ziti-sdk:channel.c:615 process_inbound() ch[0] <= ct[StateClosedType] seq[20] len[14] hdrs[24]
[ 137.956] TRACE ziti-sdk:channel.c:625 process_inbound() ch[0] completing msg seq[20] body+hrds=14+24, in_offset=0, want=38, got=38
[ 137.956] TRACE ziti-sdk:channel.c:639 process_inbound() ch[0] message is complete seq[20] ct[StateClosedType]
[ 137.956] TRACE ziti-sdk:message.c:91 parse_hdrs() parsing headers len[24]
[ 137.956] TRACE ziti-sdk:message.c:104 parse_hdrs() hdr[0] id[1000] len[4]
[ 137.956] TRACE ziti-sdk:message.c:104 parse_hdrs() hdr[1] id[1001] len[4]
[ 137.956] TRACE ziti-sdk:connect.c:810 flush_connection() conn[1.1/7XVs5B7k/Connecting](ssh) starting flusher
[ 137.956] TRACE ziti-sdk:channel.c:932 on_channel_data() ch[0] read no data
[ 137.956] TRACE ziti-sdk:connect.c:1449 process_edge_message() conn[1.1/7XVs5B7k/Connecting](ssh) <= ct[StateClosedType] edge_seq[1] len[14]
[ 137.956] DEBUG ziti-sdk:connect.c:1456 process_edge_message() conn[1.1/7XVs5B7k/Connecting](ssh) connection status[StateClosedType] seq[1] err[session closed]
[ 137.956] ERROR ziti-sdk:connect.c:1474 process_edge_message() conn[1.1/7XVs5B7k/Connecting](ssh) failed to connect, reason=session closed
[ 137.956] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[1.1/7XVs5B7k/Connecting](ssh) transitioning Connecting => Disconnected
[ 137.956] DEBUG ziti-sdk:connect.c:323 complete_conn_req() conn[1.1/7XVs5B7k/Disconnected](ssh) Disconnected failed: connection is closed
[ 137.956] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[1.1/7XVs5B7k/Disconnected](ssh) transitioning Disconnected => Disconnected
[ 137.956] TRACE ziti-sdk:channel.c:461 ziti_channel_send() ch[0] => ct[StateClosedType] seq[20] len[0]
[ 137.956] TRACE ziti-sdk:channel.c:435 ziti_channel_send_message() ch[0] => ct[StateClosedType] seq[20] len[0]
[ 137.956] TRACE ziti-sdk:channel.c:405 on_channel_send() ch[0] write delay = 0.000d q=1 qs=32
[ 137.956] ERROR ziti-prox-c:proxy.c:258 on_ziti_connect() ziti connect failed: connection is closed(-24)
[ 137.956] VERBOSE ziti-sdk:connect.c:129 conn_set_state() conn[1.1/7XVs5B7k/Disconnected](ssh) transitioning Disconnected => Closed
[ 137.956] DEBUG ziti-sdk:connect.c:893 flush_to_client() conn[1.1/7XVs5B7k/Closed](ssh) no data_cb: can't flush, 0 bytes available
[ 137.956] TRACE ziti-sdk:connect.c:879 flush_to_service() conn[1.1/7XVs5B7k/Closed](ssh) flushed 0 messages
[ 137.956] TRACE ziti-sdk:connect.c:803 on_flush() conn[1.1/7XVs5B7k/Closed](ssh) stopping flusher
[ 137.956] DEBUG ziti-sdk:connect.c:184 close_conn_internal() conn[1.1/7XVs5B7k/Closed](ssh) removing
[ 137.956] DEBUG ziti-prox-c:proxy.c:240 on_ziti_close() ziti connection closed for clt[127.0.0.1:56836]