Send traffic to (without edge client in server)

kashif · September 24, 2023, 9:17am

Hi,
Today I tried to send traffic to option (no tunneler on web server). So I created a service only to forward/send traffic to requested by the client (Edge Client). But not able to access web server (both https and http not working).

Do I need to do something else? Or I did not do it correctly!

Here are the snapshots

And I saw these errors in service status.

● ziti-controller.service - Ziti-Controller
     Loaded: loaded (/etc/systemd/system/ziti-controller.service; enabled; vendor preset: enabled)
     Active: active (running) since Sat 2023-09-23 10:49:16 UTC; 22h ago
   Main PID: 901 (ziti)
      Tasks: 9 (limit: 6970)
     Memory: 115.3M
        CPU: 4min 23.993s
     CGroup: /system.slice/ziti-controller.service
             └─901 /root/.ziti/quickstart/ztn/ziti-bin/ziti-v0.30.0/ziti controller run /root/.ziti/quickstart/ztn/ztn.yaml

Sep 24 09:24:38 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:38.550Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
Sep 24 09:24:38 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:38.801Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
Sep 24 09:24:39 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:39.054Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
Sep 24 09:24:39 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:39.307Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
Sep 24 09:24:39 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:39.561Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
Sep 24 09:24:39 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:39.812Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
Sep 24 09:24:40 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:40.065Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
Sep 24 09:24:40 ztn ziti[901]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{5Yxe}","error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/common.go:75","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*baseRequestHandler).returnError","level":"error","msg":"responded with error","operation":"create.circuit","routerId":"vQutsJRrHa","time":"2023-09-24T09:24:40.316Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99"}
~
~

● ziti-router.service - Ziti-Router for ztn-edge-router
     Loaded: loaded (/etc/systemd/system/ziti-router.service; enabled; vendor preset: enabled)
     Active: active (running) since Sat 2023-09-23 10:49:16 UTC; 22h ago
   Main PID: 902 (ziti)
      Tasks: 9 (limit: 6970)
     Memory: 52.1M
        CPU: 1min 5.175s
     CGroup: /system.slice/ziti-router.service
             └─902 /root/.ziti/quickstart/ztn/ziti-bin/ziti-v0.30.0/ziti router run /root/.ziti/quickstart/ztn/ztn-edge-router.yaml

Sep 24 09:24:38 ztn ziti[902]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{y8e6}","chSeq":212,"connId":183,"edgeSeq":0,"error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:171","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processConnect","level":"warning","msg":"failed to dial fabric","time":"2023-09-24T09:24:38.550Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99","type":"EdgeConnectType"}
Sep 24 09:24:38 ztn ziti[902]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{y8e6}","chSeq":213,"connId":184,"edgeSeq":0,"error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:171","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processConnect","level":"warning","msg":"failed to dial fabric","time":"2023-09-24T09:24:38.802Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99","type":"EdgeConnectType"}
Sep 24 09:24:39 ztn ziti[902]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{y8e6}","chSeq":214,"connId":185,"edgeSeq":0,"error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:171","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processConnect","level":"warning","msg":"failed to dial fabric","time":"2023-09-24T09:24:39.056Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99","type":"EdgeConnectType"}
Sep 24 09:24:39 ztn ziti[902]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{y8e6}","chSeq":215,"connId":186,"edgeSeq":0,"error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:171","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processConnect","level":"warning","msg":"failed to dial fabric","time":"2023-09-24T09:24:39.309Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99","type":"EdgeConnectType"}
Sep 24 09:24:39 ztn ziti[902]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{y8e6}","chSeq":216,"connId":187,"edgeSeq":0,"error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:171","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processConnect","level":"warning","msg":"failed to dial fabric","time":"2023-09-24T09:24:39.562Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99","type":"EdgeConnectType"}
Sep 24 09:24:39 ztn ziti[902]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{y8e6}","chSeq":217,"connId":188,"edgeSeq":0,"error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:171","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processConnect","level":"warning","msg":"failed to dial fabric","time":"2023-09-24T09:24:39.813Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99","type":"EdgeConnectType"}
Sep 24 09:24:40 ztn ziti[902]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{y8e6}","chSeq":218,"connId":189,"edgeSeq":0,"error":"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators","file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:171","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processConnect","level":"warning","msg":"failed to dial fabric","time":"2023-09-24T09:24:40.066Z","token":"8357b7db-e49d-4f16-96d1-18839de2cd99","type":"EdgeConnectType"}

Thank you

TheLumberjack · September 24, 2023, 3:44pm

Did you actually use: 192.168.x.x or are you just editing that for posting on the internet? (fwiw, I wouldn't worry about exposing those IPs if that's the case)

"service 1Pc3gjgaVnzOQaxmZVfgob has no terminators" is an indication that there's a problem. Generally, it's because the service is not authorized to be bound by any particular identity or the identity that's binding it is not online.

I use the ziti cli for this:

ziti edge policy-advisor services myweb -q

If you run that command, what are the results? Do you see an identity able to bind and another that can dial?

For example:

ziti edge policy-advisor services hosted-svc -q
OKAY : hosted-svc.server (1) -> hosted-svc (1) Common Routers: (1/1) Dial: N Bind: Y
OKAY : hosted-svc.client (1) -> hosted-svc (1) Common Routers: (1/1) Dial: Y Bind: N

kashif · September 25, 2023, 7:14am

Hi,
Thank you again for your reply

Okay

The below command gave same output as you mentioned.

ziti edge policy-advisor services myweb -q

root@ztn# source $HOME/.ziti/quickstart/$(hostname -s)/$(hostname -s).env

adding /root/.ziti/quickstart/ztn/ziti-bin/ziti-v0.30.0 to the path

root@ztn# zitiLogin
Token: 0f4f0a04-7bcd-4bad-8847-9b05ef44a7fc
Saving identity 'default' to /root/.config/ziti/ziti-cli.json

root@ztn# ziti edge policy-advisor services myweb -q
OKAY : ztn-edge-router (1) -> myweb (1) Common Routers: (1/1) Dial: N Bind: Y

OKAY : kashif-pc (1) -> myweb (1) Common Routers: (1/1) Dial: Y Bind: N

I noticed no green indicators for the edge-router in identities section

But in routers section, both are green

TheLumberjack · September 25, 2023, 10:05am

When it seems traffic isn't working, it's important to look to the logs on the client to make sure the client is intercepting traffic, then look at the far identity to see if it's receiving the traffic but it has a problem and then if neither of those help, look at the router logs, then finally the controller logs.

You shared the "no terminators" error which is a common error when a policy is not setup properly. If you look at the terminators with the ziti cli (ziti edge list terminators) do you see any terminators? Can you share the output from that command?

kashif · September 25, 2023, 10:31am

Hi,
Thank you for explanation. Here's the output. I don't see any terminator for myweb.ziti

root@ztn# ziti edge list terminators
╭────────────────────────┬─────────────────────┬─────────────────┬─────────┬─────────────────────────────────────────────┬──────────┬──────┬────────────┬──────────────╮
│ ID                     │ SERVICE             │ ROUTER          │ BINDING │ ADDRESS                                     │ IDENTITY │ COST │ PRECEDENCE │ DYNAMIC COST │
├────────────────────────┼─────────────────────┼─────────────────┼─────────┼─────────────────────────────────────────────┼──────────┼──────┼────────────┼──────────────┤
│ 2K77T3kN6gRvu1fQ71zTKd │ covas-test          │ ztn-edge-router │ edge    │ hosted:893bdb6b-6e29-43a6-ae19-d2bf5455089b │          │    0 │ default    │            0 │
│ 2jNbPJZR13Oycosq2mRyUI │ journal_test_srv    │ ztn-edge-router │ edge    │ hosted:1c9a0545-e268-46c4-a4be-353bee52665f │          │    0 │ default    │            0 │
│ 3iDiT3clEekSRybpWZYicQ │ odoo-test           │ ztn-edge-router │ edge    │ hosted:0e8372c0-0ba4-4119-b6eb-aa9e4599edf2 │          │    0 │ default    │            0 │
│ 7UPLrCAwYHlL220uFVOQns │ odoo-web            │ ztn-edge-router │ edge    │ hosted:f096042c-9a99-49ce-ad34-baae1a3a95f0 │          │    0 │ default    │            0 │
│ EevfI8BKAX4py80OxUtPu  │ journal-test        │ ztn-edge-router │ edge    │ hosted:0c0cdaf1-fcd0-40c6-993d-62c5d02289eb │          │    0 │ default    │            0 │
╰────────────────────────┴─────────────────────┴─────────────────┴─────────┴─────────────────────────────────────────────┴──────────┴──────┴────────────┴──────────────╯

Just reminding, no Identity is created for the webserver 192.168.17.95:80 (myweb.ziti) since it has no tunneler, so I used this "send traffic to" option in service to forward client's tracffic to the webserver.

Here's the output as well of Edge client.

[2023-09-25T11:08:29.370Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:706 on_events_client() Received events client connection request, count: 2
[2023-09-25T11:08:29.370Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:755 send_events_message() Events Message => 
{"Bind":false,"Dial":true}},{"Id":"5XtcCgqYlldG4XMZ0qG2NQ","Name":"myweb","Protocols":["tcp","udp"],"Addresses":[{"IsHost":true,"HostName":"myweb.ziti","Prefix":0}],"Ports":[{"High":80,"Low":80}],"OwnsIntercept":true,"IsAccessible":true,"Timeout":-1,"TimeoutRemaining":-1,"Permissions":
[2023-09-25T11:08:29.370Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:29.370Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:29.382Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:662 on_cmd_client() Received IPC client connection request, count: 2
[2023-09-25T11:08:32.110Z]   TRACE tunnel-cbs:ziti_tunnel_ctrl.c:198 process_cmd() processing command[GetMetrics] with data[{"Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/kashif-pc.json"}]
[2023-09-25T11:08:32.110Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:32.110Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:839 api_session_refresh() ztx[0] api_session_refresh running
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:288 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:845 api_session_refresh() ztx[0] api_session_refresh re-auth due to no active api session[TRUE] or session expiration[TRUE]
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:918 ziti_re_auth() ztx[0] re-auth executing, transitioning to unauthenticated
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:288 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2023-09-25T11:08:32.161Z]    INFO ziti-sdk:ziti.c:865 ziti_re_auth_with_cb() ztx[0] starting to re-auth with ctlr[https://openziti:8441] api_session_status[0] api_session_expired[TRUE]
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:250 ziti_set_auth_started() ztx[0] setting api_session_state[0] to 1
[2023-09-25T11:08:32.161Z]   DEBUG ziti-sdk:ziti.c:322 ziti_stop_api_session_refresh() ztx[0] ziti_stop_api_session_refresh: stopping api session refresh
[2023-09-25T11:08:32.161Z] VERBOSE ziti-sdk:ziti_ctrl.c:134 start_request() ctrl[openziti] starting POST[/authenticate?method=cert]
[2023-09-25T11:08:37.111Z]   TRACE tunnel-cbs:ziti_tunnel_ctrl.c:198 process_cmd() processing command[GetMetrics] with data[{"Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/kashif-pc.json"}]
[2023-09-25T11:08:37.111Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:37.111Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:42.112Z]   TRACE tunnel-cbs:ziti_tunnel_ctrl.c:198 process_cmd() processing command[GetMetrics] with data[{"Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/kashif-pc.json"}]
[2023-09-25T11:08:42.112Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:42.112Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:47.112Z]   TRACE tunnel-cbs:ziti_tunnel_ctrl.c:198 process_cmd() processing command[GetMetrics] with data[{"Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/kashif-pc.json"}]
[2023-09-25T11:08:47.112Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:47.112Z]   TRACE ziti-edge-tunnel:ziti-edge-tunnel.c:739 on_write_event() Events message is sent.
[2023-09-25T11:08:47.161Z]   ERROR ziti-sdk:ziti_ctrl.c:155 ctrl_resp_cb() ctrl[openziti] request failed: -4039(connection timed out)
[2023-09-25T11:08:47.161Z]    WARN ziti-sdk:ziti.c:1457 api_session_cb() ztx[0] failed to get api session from ctrl[https://openziti:8441] api_session_state[1] CONTROLLER_UNAVAILABLE[-15] connection timed out
[2023-09-25T11:08:47.161Z]   DEBUG ziti-sdk:ziti.c:1499 api_session_cb() ztx[0] unhandled error, setting api_session_timer to 5s
[2023-09-25T11:08:47.161Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[1] to 0
[2023-09-25T11:08:47.161Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-25T11:08:47.161Z]   DEBUG ziti-sdk:ziti.c:327 ziti_schedule_api_session_refresh() ztx[0] ziti_schedule_api_session_refresh: scheduling api session refresh: 5000ms
[2023-09-25T11:08:50.488Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:50.488Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:64925->100.64.0.1:53
[2023-09-25T11:08:50.488Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:64925] service[ziti:dns-resolver]
[2023-09-25T11:08:50.488Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:50.488Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:64925] service[ziti:dns-resolver]
[2023-09-25T11:08:50.488Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:50.488Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 31 bytes from 100.64.0.1:64925
[2023-09-25T11:08:50.488Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 31 bytes to ziti
[2023-09-25T11:08:50.488Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=31 id[c34f] recursive[false] type[1] name[journal.ziti]
[2023-09-25T11:08:50.488Z]    INFO tunnel-cbs:ziti_dns.c:500 format_resp() found record[100.64.0.9] for query[1:journal.ziti]
[2023-09-25T11:08:50.488Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:64925] len=86
[2023-09-25T11:08:50.488Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:50.488Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:64925] service[ziti:dns-resolver]
[2023-09-25T11:08:50.488Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:50.489Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:61716->100.64.0.1:53
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:61716] service[ziti:dns-resolver]
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:61716] service[ziti:dns-resolver]
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:50.489Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 31 bytes from 100.64.0.1:61716
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 31 bytes to ziti
[2023-09-25T11:08:50.489Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=31 id[b35b] recursive[false] type[1] name[journal.ziti]
[2023-09-25T11:08:50.489Z]    INFO tunnel-cbs:ziti_dns.c:500 format_resp() found record[100.64.0.9] for query[1:journal.ziti]
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:61716] len=86
[2023-09-25T11:08:50.489Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:61716] service[ziti:dns-resolver]
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:50.489Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:50784->100.64.0.1:53
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:50784] service[ziti:dns-resolver]
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:50784] service[ziti:dns-resolver]
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:50.489Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 31 bytes from 100.64.0.1:50784
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 31 bytes to ziti
[2023-09-25T11:08:50.489Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=31 id[225d] recursive[false] type[28] name[journal.ziti]
[2023-09-25T11:08:50.489Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:50784] len=70
[2023-09-25T11:08:50.489Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:50784] service[ziti:dns-resolver]
[2023-09-25T11:08:50.489Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:50.688Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:57676->100.64.0.1:53
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:57676] service[ziti:dns-resolver]
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:57676] service[ziti:dns-resolver]
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:50.689Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 41 bytes from 100.64.0.1:57676
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 41 bytes to ziti
[2023-09-25T11:08:50.689Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=41 id[f6d8] recursive[false] type[1] name[connectvastestsrv.ziti]
[2023-09-25T11:08:50.689Z]    INFO tunnel-cbs:ziti_dns.c:500 format_resp() found record[100.64.0.4] for query[1:connectvastestsrv.ziti]
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:57676] len=96
[2023-09-25T11:08:50.689Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:57676] service[ziti:dns-resolver]
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:50.689Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:64731->100.64.0.1:53
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:64731] service[ziti:dns-resolver]
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:64731] service[ziti:dns-resolver]
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:50.689Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 41 bytes from 100.64.0.1:64731
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 41 bytes to ziti
[2023-09-25T11:08:50.689Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=41 id[1159] recursive[false] type[1] name[connectvastestsrv.ziti]
[2023-09-25T11:08:50.689Z]    INFO tunnel-cbs:ziti_dns.c:500 format_resp() found record[100.64.0.4] for query[1:connectvastestsrv.ziti]
[2023-09-25T11:08:50.689Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:64731] len=96
[2023-09-25T11:08:50.689Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:64731] service[ziti:dns-resolver]
[2023-09-25T11:08:50.689Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:50.690Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:50.690Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:49159->100.64.0.1:53
[2023-09-25T11:08:50.690Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:49159] service[ziti:dns-resolver]
[2023-09-25T11:08:50.690Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:50.690Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:49159] service[ziti:dns-resolver]
[2023-09-25T11:08:50.690Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:50.690Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 41 bytes from 100.64.0.1:49159
[2023-09-25T11:08:50.690Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 41 bytes to ziti
[2023-09-25T11:08:50.690Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=41 id[b747] recursive[false] type[28] name[connectvastestsrv.ziti]
[2023-09-25T11:08:50.690Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:49159] len=80
[2023-09-25T11:08:50.690Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:50.690Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:49159] service[ziti:dns-resolver]
[2023-09-25T11:08:50.690Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:51.759Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:51.759Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:56615->100.64.0.1:53
[2023-09-25T11:08:51.759Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:56615] service[ziti:dns-resolver]
[2023-09-25T11:08:51.759Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:51.759Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:56615] service[ziti:dns-resolver]
[2023-09-25T11:08:51.759Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:51.759Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 28 bytes from 100.64.0.1:56615
[2023-09-25T11:08:51.759Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 28 bytes to ziti
[2023-09-25T11:08:51.759Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=28 id[c303] recursive[false] type[1] name[myweb.ziti]
[2023-09-25T11:08:51.759Z]    INFO tunnel-cbs:ziti_dns.c:500 format_resp() found record[100.64.0.6] for query[1:myweb.ziti]
[2023-09-25T11:08:51.759Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:56615] len=83
[2023-09-25T11:08:51.759Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:51.759Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:56615] service[ziti:dns-resolver]
[2023-09-25T11:08:51.759Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:51.760Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:51.760Z]   TRACE tunnel-sdk:tunnel_tcp.c:344 recv_tcp() received segment 100.64.0.1:1699->100.64.0.6:80
[2023-09-25T11:08:51.760Z]   DEBUG tunnel-sdk:tunnel_tcp.c:109 new_tcp_pcb() snd_wnd: 55295, snd_snd_max: 55295, mss: 32768
[2023-09-25T11:08:51.760Z]   DEBUG tunnel-sdk:tunnel_tcp.c:409 recv_tcp() intercepted address[tcp:100.64.0.6:80] client[tcp:100.64.0.1:1699] service[myweb]
[2023-09-25T11:08:51.760Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:286 ziti_sdk_c_dial() ziti_dial(name=myweb)
[2023-09-25T11:08:51.760Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:312 ziti_sdk_c_dial() not setting ziti dial options for 'ziti-tunneler-client.v1' config
[2023-09-25T11:08:51.760Z]   DEBUG tunnel-cbs:ziti_tunnel_cbs.c:357 ziti_sdk_c_dial() service[myweb] app_data_json[165]='{"connType":null,"dst_protocol":"tcp","dst_hostname":"myweb.ziti","dst_ip":"100.64.0.6","dst_port":"80","src_protocol":"tcp","src_ip":"100.64.0.1","src_port":"1699"}'
[2023-09-25T11:08:51.760Z] VERBOSE ziti-sdk:connect.c:101 conn_set_state() conn[0.135/Initial] transitioning Initial => Connecting
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:posture.c:189 ziti_send_posture_data() ztx[0] no api_session, can't submit posture responses
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:connect.c:520 process_connect() conn[0.135/Connecting] requesting 'Dial' session for service[myweb]
[2023-09-25T11:08:51.760Z]    WARN ziti-sdk:ziti_ctrl.c:499 verify_api_session() ctrl[openziti] no API session
[2023-09-25T11:08:51.760Z]    WARN ziti-sdk:connect.c:457 connect_get_net_session_cb() conn[0.135/Connecting] failed to get 'Dial' session for service[myweb]: UNAUTHORIZED(no api session token set for ziti_controller)
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:ziti.c:332 ziti_force_api_session_refresh() ztx[0] forcing session refresh
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:ziti.c:327 ziti_schedule_api_session_refresh() ztx[0] ziti_schedule_api_session_refresh: scheduling api session refresh: 0ms
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:connect.c:918 restart_connect() conn[0.135/Connecting] restarting connect sequence
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:posture.c:189 ziti_send_posture_data() ztx[0] no api_session, can't submit posture responses
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:connect.c:520 process_connect() conn[0.135/Connecting] requesting 'Dial' session for service[myweb]
[2023-09-25T11:08:51.760Z]    WARN ziti-sdk:ziti_ctrl.c:499 verify_api_session() ctrl[openziti] no API session
[2023-09-25T11:08:51.760Z]    WARN ziti-sdk:connect.c:457 connect_get_net_session_cb() conn[0.135/Connecting] failed to get 'Dial' session for service[myweb]: UNAUTHORIZED(no api session token set for ziti_controller)
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:ziti.c:332 ziti_force_api_session_refresh() ztx[0] forcing session refresh
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:ziti.c:327 ziti_schedule_api_session_refresh() ztx[0] ziti_schedule_api_session_refresh: scheduling api session refresh: 0ms
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:connect.c:918 restart_connect() conn[0.135/Connecting] restarting connect sequence
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:posture.c:189 ziti_send_posture_data() ztx[0] no api_session, can't submit posture responses
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:connect.c:520 process_connect() conn[0.135/Connecting] requesting 'Dial' session for service[myweb]
[2023-09-25T11:08:51.760Z]    WARN ziti-sdk:ziti_ctrl.c:499 verify_api_session() ctrl[openziti] no API session
[2023-09-25T11:08:51.760Z]    WARN ziti-sdk:connect.c:457 connect_get_net_session_cb() conn[0.135/Connecting] failed to get 'Dial' session for service[myweb]: UNAUTHORIZED(no api session token set for ziti_controller)
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:ziti.c:332 ziti_force_api_session_refresh() ztx[0] forcing session refresh
[2023-09-25T11:08:51.760Z]   DEBUG ziti-sdk:ziti.c:327 ziti_schedule_api_session_refresh() ztx[0] ziti_schedule_api_session_refresh: scheduling api session refresh: 0ms
[2023-09-25T11:08:51.760Z]   ERROR ziti-sdk:connect.c:913 restart_connect() conn[0.135/Connecting] failed to connect after 3 retries
[2023-09-25T11:08:51.760Z] VERBOSE ziti-sdk:connect.c:101 conn_set_state() conn[0.135/Connecting] transitioning Connecting => Disconnected
[2023-09-25T11:08:51.760Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:93 on_ziti_connect() on_ziti_connect status: -17
[2023-09-25T11:08:51.760Z]   ERROR tunnel-cbs:ziti_tunnel_cbs.c:103 on_ziti_connect() ziti dial failed: Service not available
[2023-09-25T11:08:51.760Z] VERBOSE ziti-sdk:connect.c:101 conn_set_state() conn[0.135/Disconnected] transitioning Disconnected => Closed
[2023-09-25T11:08:51.760Z]   TRACE ziti-sdk:connect.c:775 flush_connection() conn[0.135/Closed] starting flusher
[2023-09-25T11:08:51.760Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:53952->100.64.0.1:53
[2023-09-25T11:08:51.760Z]   DEBUG tunnel-sdk:tunnel_udp.c:259 recv_udp() intercepted address[udp:100.64.0.2:53] client[udp:100.64.0.1:53952] service[ziti:dns-resolver]
[2023-09-25T11:08:51.760Z]   DEBUG tunnel-cbs:ziti_dns.c:238 on_dns_client() new DNS client
[2023-09-25T11:08:51.760Z]   DEBUG tunnel-sdk:ziti_tunnel.c:221 ziti_tunneler_dial_completed() ziti dial succeeded: client[udp:100.64.0.1:53952] service[ziti:dns-resolver]
[2023-09-25T11:08:51.760Z]   TRACE tunnel-sdk:tunnel_udp.c:51 to_ziti() no data to write
[2023-09-25T11:08:51.760Z] VERBOSE tunnel-sdk:tunnel_udp.c:107 on_udp_client_data() 28 bytes from 100.64.0.1:53952
[2023-09-25T11:08:51.760Z]   TRACE tunnel-sdk:tunnel_udp.c:58 to_ziti() writing 28 bytes to ziti
[2023-09-25T11:08:51.760Z]   TRACE tunnel-cbs:ziti_dns.c:675 on_dns_req() received DNS query q_len=28 id[7659] recursive[false] type[1] name[myweb.ziti]
[2023-09-25T11:08:51.760Z]    INFO tunnel-cbs:ziti_dns.c:500 format_resp() found record[100.64.0.6] for query[1:myweb.ziti]
[2023-09-25T11:08:51.760Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet UDP[100.64.0.2:53 -> 100.64.0.1:53952] len=83
[2023-09-25T11:08:51.760Z]   TRACE tunnel-cbs:ziti_dns.c:248 on_dns_close() DNS client close
[2023-09-25T11:08:51.761Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[udp:100.64.0.1:53952] service[ziti:dns-resolver]
[2023-09-25T11:08:51.761Z]   DEBUG tunnel-sdk:tunnel_udp.c:119 tunneler_udp_close() closing ziti:dns-resolver session
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:839 api_session_refresh() ztx[0] api_session_refresh running
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:288 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:845 api_session_refresh() ztx[0] api_session_refresh re-auth due to no active api session[TRUE] or session expiration[TRUE]
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:918 ziti_re_auth() ztx[0] re-auth executing, transitioning to unauthenticated
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:288 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2023-09-25T11:08:51.761Z]    INFO ziti-sdk:ziti.c:865 ziti_re_auth_with_cb() ztx[0] starting to re-auth with ctlr[https://openziti:8441] api_session_status[0] api_session_expired[TRUE]
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:250 ziti_set_auth_started() ztx[0] setting api_session_state[0] to 1
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:322 ziti_stop_api_session_refresh() ztx[0] ziti_stop_api_session_refresh: stopping api session refresh
[2023-09-25T11:08:51.761Z] VERBOSE ziti-sdk:ziti_ctrl.c:134 start_request() ctrl[openziti] starting POST[/authenticate?method=cert]
[2023-09-25T11:08:51.761Z] VERBOSE ziti-sdk:connect.c:818 flush_to_client() conn[0.135/Closed] 0 bytes available
[2023-09-25T11:08:51.761Z]   TRACE ziti-sdk:connect.c:768 on_flush() conn[0.135/Closed] stopping flusher
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:connect.c:169 close_conn_internal() conn[0.135/Closed] removing
[2023-09-25T11:08:51.761Z]   TRACE tunnel-cbs:ziti_tunnel_cbs.c:602 ziti_conn_close_cb() ziti_conn[00000269a743c4a0] is closed
[2023-09-25T11:08:51.761Z]   DEBUG tunnel-sdk:ziti_tunnel.c:434 ziti_tunneler_close() closing connection: client[tcp:100.64.0.1:1699] service[myweb]
[2023-09-25T11:08:51.761Z]   DEBUG tunnel-sdk:tunnel_tcp.c:244 tunneler_tcp_close() closing 00007ff6a8cc2230, state=3(SYN_RCVD) flags=0
[2023-09-25T11:08:51.761Z]   DEBUG tunnel-sdk:tunnel_tcp.c:251 tunneler_tcp_close() closing connection before handshake complete. sending RST to client
[2023-09-25T11:08:51.761Z]   TRACE tunnel-sdk:netif_shim.c:34 netif_shim_output() writing packet TCP[100.64.0.6:80 -> 100.64.0.1:1699] len=40
[2023-09-25T11:08:51.761Z] VERBOSE tunnel-cbs:ziti_tunnel_cbs.c:614 ziti_conn_close_cb() nulled data for ziti_conn[00000269a743c4a0]
[2023-09-25T11:08:51.761Z]   TRACE ziti-sdk:connect.c:144 free_ziti_listen_opts() refuse to free NULL listen_opts
[2023-09-25T11:08:51.761Z]   TRACE ziti-sdk:connect.c:212 close_conn_internal() conn[0.135/Closed] is being free()'d
[2023-09-25T11:08:51.761Z]   DEBUG ziti-sdk:ziti.c:1597 grim_reaper() ztx[0] reaped 1 closed (out of 1 total) connections
[2023-09-25T11:08:51.761Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:51.762Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-25T11:08:51.762Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:59982->100.64.0.1:53

TheLumberjack · September 25, 2023, 11:53am

Hmmmm. If you restart the edge router, then list the terminators, do you see one created? In the router logs you should see:

"msg":"attempting to establish terminator","service":"weather-svc"

and

"msg":"received terminator created notification"

Do you see those in the logs for "myweb"?

kashif · September 25, 2023, 1:35pm

I restarted the ziti-router-service. And tried to access myweb.ziti. It worked.

This happened because of abnormal server shutdown? Or something else.

root@ztn:/home/user# ziti edge list terminators
╭──────────────────────────────────────┬─────────────────────┬─────────────────┬─────────┬─────────────────────────────────────────────┬──────────┬──────┬────────────┬──────────────╮
│ ID                                   │ SERVICE             │ ROUTER          │ BINDING │ ADDRESS                                     │ IDENTITY │ COST │ PRECEDENCE │ DYNAMIC COST │
├──────────────────────────────────────┼─────────────────────┼─────────────────┼─────────┼─────────────────────────────────────────────┼──────────┼──────┼────────────┼──────────────┤
│ 310db6fa-e834-4b12-8bbb-17b057c05ed0 │ myweb               │ ztn-edge-router │ tunnel  │ 310db6fa-e834-4b12-8bbb-17b057c05ed0        │          │    0 │ default    │            0 │
╰──────────────────────────────────────┴─────────────────────┴─────────────────┴─────────┴─────────────────────────────────────────────┴──────────┴──────┴────────────┴──────────────╯

Can you please tell where to see these below logs?

> "msg":"attempting to establish terminator","service":"weather-svc"
> ```
> 
> and
> 
> ```
> "msg":"received terminator created notification"
> ```

TheLumberjack · September 25, 2023, 1:41pm

To be honest, I don't think we'll be able to figure that out now. It might have been related, or it might be a hard to reproduce bug.

You can/should find those messages in the hosting edge router logs.

kashif · September 26, 2023, 11:13am

Thank you very much.

That's okay at least it is clear that if the service is not reachable then the first remedy is to restart router service before looking to other things.

The logs can be found by this command?

journalctl -u ziti-router

TheLumberjack · September 26, 2023, 11:57am

It's really only a very special situation that honestly, doesn't happen very often and seems to only happen when the controller/router are brand new (just installed) and it only happens one time as far as I can tell so far.

If you are using systemd (by following the quickstart) and using systemctl, then yes you find the logs using journald and journalctl -u ziti-router --since "1 days ago" or journalctl -u ziti-controller --since "1 days ago" (I added the 'since' on there, but you should just read up on journalctl usage)

Topic		Replies	Views
Terminators and service issue	3	175	October 17, 2023
Failed to connect, reason=encryption required on service, terminator did not send public header Ziti Overlay	4	191	June 19, 2023
Service still can be accessed either IP or testpage.ziti	15	179	August 21, 2023
Service fails in Ziti Edge Tunnels Gw setup Ziti Edge Tunnel	15	112	February 29, 2024
Quickstart(ish): Can see service but can't access it General Questions	22	434	May 1, 2023

Send traffic to (without edge client in server)

Related Topics