Edge client unable to connect from WAN after reboot

Hi,
Today, client from out side LAN (from home) network are unable to connect/enroll. Clients in LAN have no issue in connecting/enrolling.

I checked DNS which is resolving to Public IP correctly, checked firewall for desired ports (DST NAT: Public IP and Port to LAN IP and Port). Everything seems fine.

Client Edge Desktop Service Logs (please visit below)

Client Edge Desktop Application Logs (please visit below)

Controller Service output on Openziti

● ziti-controller.service - Ziti-Controller
     Loaded: loaded (/etc/systemd/system/ziti-controller.service; enabled; vendor preset: enabled)
     Active: active (running) since Sun 2023-09-17 11:56:47 UTC; 14min ago
   Main PID: 2330 (ziti)
      Tasks: 8 (limit: 6970)
     Memory: 64.9M
        CPU: 8.670s
     CGroup: /system.slice/ziti-controller.service
             └─2330 /root/.ziti/quickstart/ztn/ziti-bin/ziti-v0.30.0/ziti controller run /root/.ziti/quickstart/ztn/ztn.yaml

Sep 17 11:56:52 ztn ziti[2330]: {"file":"github.com/openziti/edge@v0.24.381/controller/sync_strats/sync_instant.go:508","func":"github.com/openziti/edge/controller/sync_strats.(*InstantStrategy).synchronize.func1","level":"info","msg":"exiting synchronization, final status: SYNC_DONE","routerChannelIsOpen":true,"routerFingerprint":"6fb9e44230c9d6ab62d14b766e9ef00e4ee30cfd","routerId":"vQutsJRrHa","routerName":"ztn-edge-router","routerTxId":"Jaa55aTgK","strategy":"instant","time":"2023-09-17T11:56:52.758Z"}
Sep 17 11:56:52 ztn ziti[2330]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{69gy}","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/create_terminator.go:124","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*createTerminatorHandler).CreateTerminator","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","service":"journal2","serviceId":"5lX8uzqF5mCZWSYuyQbdnJ","terminator":"1eNvb6fgJEtKO6VMdjIzaW","time":"2023-09-17T11:56:52.901Z","token":"d39d9348-affa-46d6-92d9-8362392fab4b"}
Sep 17 11:56:52 ztn ziti[2330]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{69gy}","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/create_terminator.go:124","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*createTerminatorHandler).CreateTerminator","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","service":"connectvas2","serviceId":"3ck1IjL6IG34nu3ko6znyO","terminator":"1bKTJlZbMvTWGJYkJFXP8w","time":"2023-09-17T11:56:52.961Z","token":"947bb2bc-f67b-41fc-a3df-02928d8677c2"}
Sep 17 11:56:52 ztn ziti[2330]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{69gy}","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/create_terminator.go:124","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*createTerminatorHandler).CreateTerminator","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","service":"journal","serviceId":"18ltaoHjdFvRiOghZYuqbX","terminator":"6gRfspqAjjmp7n5aIpaKiC","time":"2023-09-17T11:56:52.962Z","token":"53121615-c9f0-41cc-b6c3-afb715857e89"}
Sep 17 11:56:52 ztn ziti[2330]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{69gy}","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/create_terminator.go:124","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*createTerminatorHandler).CreateTerminator","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","service":"connectvas","serviceId":"5I4xAjMVUOI1UkRzLkCZkG","terminator":"1uhfwXZnmEPh31YYCZjpg2","time":"2023-09-17T11:56:52.963Z","token":"8b910fb6-ceff-42ed-987f-8dccd10dfc2b"}
Sep 17 11:56:52 ztn ziti[2330]: {"file":"github.com/openziti/fabric@v0.24.2/controller/network/network.go:871","func":"github.com/openziti/fabric/controller/network.(*Network).Run","level":"info","msg":"changed router","routerId":"vQutsJRrHa","time":"2023-09-17T11:56:52.994Z"}
Sep 17 12:01:42 ztn ziti[2330]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{69gy}","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/create_terminator.go:124","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*createTerminatorHandler).CreateTerminator","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","service":"webserver","serviceId":"62D40l1tswENlw448sdPvZ","terminator":"7eUKMxVcbKIFqOw2SN0orB","time":"2023-09-17T12:01:42.890Z","token":"50788424-68b9-46e5-bedb-c521b1840c7a"}
Sep 17 12:01:43 ztn ziti[2330]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{69gy}","file":"github.com/openziti/edge@v0.24.381/controller/handler_edge_ctrl/create_terminator.go:124","func":"github.com/openziti/edge/controller/handler_edge_ctrl.(*createTerminatorHandler).CreateTerminator","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","service":"odoo-web","serviceId":"5ms9Vo7G0hm3xiLCnpxbdu","terminator":"5AKy2DkE6VaF7jopp7BUo0","time":"2023-09-17T12:01:43.247Z","token":"57f001a0-6019-4e23-ae78-017d199366ca"}
Sep 17 12:05:42 ztn ziti[2330]: {"file":"github.com/openziti/fabric@v0.24.2/controller/network/fault.go:31","func":"github.com/openziti/fabric/controller/network.(*Network).fault","level":"info","msg":"network fault processing for [1] circuits","time":"2023-09-17T12:05:42.884Z"}
Sep 17 12:05:42 ztn ziti[2330]: {"circuitId":"GeM023cbL","file":"github.com/openziti/fabric@v0.24.2/controller/network/fault.go:48","func":"github.com/openziti/fabric/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"vQutsJRrHa","time":"2023-09-17T12:05:42.884Z"}

Service Router output on Openziti

● ziti-router.service - Ziti-Router for openziti-edge-router
     Loaded: loaded (/etc/systemd/system/ziti-router.service; enabled; vendor preset: enabled)
     Active: active (running) since Sun 2023-09-17 11:56:42 UTC; 14min ago
   Main PID: 2288 (ziti)
      Tasks: 8 (limit: 6970)
     Memory: 26.4M
        CPU: 3.044s
     CGroup: /system.slice/ziti-router.service
             └─2288 /root/.ziti/quickstart/openziti/ziti-bin/ziti-v0.30.0/ziti router run /root/.ziti/quickstart/openziti/openziti-edge-router.yaml

Sep 17 11:56:52 openziti ziti[2288]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{rXZD}","chSeq":1,"connId":0,"edgeSeq":0,"file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:288","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processBind","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","sessionId":"d39d9348-affa-46d6-92d9-8362392fab4b","terminatorId":"","time":"2023-09-17T11:56:52.902Z","type":"EdgeBindType"}
Sep 17 11:56:52 openziti ziti[2288]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{rXZD}","chSeq":3,"connId":2,"edgeSeq":0,"file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:288","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processBind","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","sessionId":"947bb2bc-f67b-41fc-a3df-02928d8677c2","terminatorId":"","time":"2023-09-17T11:56:52.962Z","type":"EdgeBindType"}
Sep 17 11:56:52 openziti ziti[2288]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{rXZD}","chSeq":4,"connId":3,"edgeSeq":0,"file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:288","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processBind","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","sessionId":"53121615-c9f0-41cc-b6c3-afb715857e89","terminatorId":"","time":"2023-09-17T11:56:52.963Z","type":"EdgeBindType"}
Sep 17 11:56:52 openziti ziti[2288]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{rXZD}","chSeq":2,"connId":1,"edgeSeq":0,"file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:288","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processBind","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","sessionId":"8b910fb6-ceff-42ed-987f-8dccd10dfc2b","terminatorId":"","time":"2023-09-17T11:56:52.964Z","type":"EdgeBindType"}
Sep 17 11:56:53 openziti ziti[2288]: {"file":"github.com/openziti/edge@v0.24.381/router/handler_edge_ctrl/apiSessionAdded.go:124","func":"github.com/openziti/edge/router/handler_edge_ctrl.(*apiSessionAddedHandler).applySync","level":"info","msg":"finished sychronizing api sessions [count: 11, syncId: clmnejouq0005sqar3cs17sql, duration: 37.397µs]","time":"2023-09-17T11:56:53.760Z"}
Sep 17 12:01:42 openziti ziti[2288]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{V0Gr}","chSeq":5,"connId":0,"edgeSeq":0,"file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:288","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processBind","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","sessionId":"50788424-68b9-46e5-bedb-c521b1840c7a","terminatorId":"","time":"2023-09-17T12:01:42.892Z","type":"EdgeBindType"}
Sep 17 12:01:43 openziti ziti[2288]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{pPnV}","chSeq":5,"connId":0,"edgeSeq":0,"file":"github.com/openziti/edge@v0.24.381/router/xgress_edge/listener.go:288","func":"github.com/openziti/edge/router/xgress_edge.(*edgeClientConn).processBind","level":"info","msg":"created terminator","routerId":"vQutsJRrHa","sessionId":"57f001a0-6019-4e23-ae78-017d199366ca","terminatorId":"","time":"2023-09-17T12:01:43.248Z","type":"EdgeBindType"}
Sep 17 12:05:10 openziti ziti[2288]: {"_context":"ch{edge}-\u003eu{classic}-\u003ei{paAp}","file":"github.com/openziti/channel/v2@v2.0.91/impl.go:323","func":"github.com/openziti/channel/v2.(*channelImpl).rxer","level":"error","msg":"rx error (read tcp 192.xx.32:8442-\u003e192.xx.116:6930: read: connection reset by peer)","time":"2023-09-17T12:05:10.155Z"}
Sep 17 12:05:42 openziti ziti[2288]: {"_context":"{c/GeM023cbL|@/7kQ6}\u003cInitiator\u003e","circuitId":"GeM023cbL","error":"cannot forward payload, no destination for circuit=GeM023cbL src=7kQ6 dst=N9GM","file":"github.com/openziti/fabric@v0.24.2/router/handler_xgress/receive.go:37","func":"github.com/openziti/fabric/router/handler_xgress.(*receiveHandler).HandleXgressReceive","level":"error","msg":"unable to forward payload","origin":0,"seq":3,"time":"2023-09-17T12:05:42.083Z"}
Sep 17 12:05:42 openziti ziti[2288]: {"circuitCount":1,"ctrlId":"openziti","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/faulter.go:102","func":"github.com/openziti/fabric/router/forwarder.(*Faulter).run","level":"warning","msg":"reported forwarding faults","time":"2023-09-17T12:05:42.884Z"}

Thank you

Update: Looking around to get more information. It seems that system was rebooted and after that some services were working and some aren't in LAN.

I looked in Terminators (Manage Terminators) and some terminators went missing also. It should not happen if the system is rebooted! I added one and I was able to access the service locally. But still not able to enroll from WAN and the client already enrolled is not showing any service.

Controller Status

● ziti-controller.service - Ziti-Controller
     Loaded: loaded (/etc/systemd/system/ziti-controller.service; enabled; vendor preset: enabled)
     Active: active (running) since Mon 2023-09-18 07:11:14 UTC; 33min ago
   Main PID: 839 (ziti)
      Tasks: 9 (limit: 6970)
     Memory: 101.8M
        CPU: 16.585s
     CGroup: /system.slice/ziti-controller.service
             └─839 /root/.ziti/quickstart/ztn/ziti-bin/ziti-v0.30.0/ziti controller run /root/.ziti/quickstart/ztn/ztn.yaml

Sep 18 07:44:10 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:10.058Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:10 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:10.314Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:10 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:10.574Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:10 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:10.828Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:11 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:11.093Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:11 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:11.339Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:11 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:11.608Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:11 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:11.862Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:12 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:12.125Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}
Sep 18 07:44:12 ztn ziti[839]: {"_context":"ch{vQutsJRrHa}-\u003eu{classic}-\u003ei{O9qO}","error":"service 62D40l1tswENlw448sdPvZ 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-18T07:44:12.379Z","token":"7ad5570e-c992-47e7-b983-cd5b39751fdd"}

Controller is unavailable!

============================================================================
[2023-09-18T07:27:34.991Z]    INFO ziti-sdk:utils.c:173 ziti_log_set_level() set log level: root=4/DEBUG
[2023-09-18T07:27:35.000Z]    INFO ziti-edge-tunnel:tun.c:171 tun_open() Wintun v0.13 loaded
[2023-09-18T07:27:35.000Z]    INFO ziti-edge-tunnel:tun.c:522 cleanup_adapters() Cleaning up orphan wintun adapters
[2023-09-18T07:27:35.289Z]    INFO ziti-edge-tunnel:tun.c:513 tun_delete_cb() Deleted wintun adapter ziti-tun0
[2023-09-18T07:27:35.290Z]    INFO ziti-edge-tunnel:tun.c:153 flush_dns() DnsFlushResolverCache succeeded
[2023-09-18T07:27:36.001Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 0, change = 3
[2023-09-18T07:27:36.001Z]    INFO ziti-edge-tunnel:tun.c:405 if_change_cb() default route is now via if_idx[20]
[2023-09-18T07:27:36.001Z]    INFO ziti-edge-tunnel:tun.c:411 if_change_cb() updating excluded routes
[2023-09-18T07:27:36.009Z]   DEBUG ziti-edge-tunnel:tun.c:377 tun_add_route() adding route: 100.64.0.0/10
[2023-09-18T07:27:36.009Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:444 is_nrpt_policies_effective() Executing add test nrpt rule. powershell -Command "Add-DnsClientNrptRule -Namespace '.ziti.test' -NameServers '100.64.0.2' -Comment 'Added by ziti-edge-tunnel' -DisplayName 'ziti-edge-tunnel:.ziti.test'"
[2023-09-18T07:27:36.013Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 4, change = 0
[2023-09-18T07:27:36.139Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 4, change = 0
[2023-09-18T07:27:36.147Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 4, change = 0
[2023-09-18T07:27:37.663Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:461 is_nrpt_policies_effective() test nrpt rule query returned 1 items
[2023-09-18T07:27:37.663Z]    INFO ziti-edge-tunnel:windows-scripts.c:469 is_nrpt_policies_effective() NRPT policies are effective in this system
[2023-09-18T07:27:37.663Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:430 remove_single_nrpt_rule() Executing Remove nrpt rule: powershell -Command "Get-DnsClientNrptRule | where Namespace -eq '.ziti.test' | Remove-DnsClientNrptRule -Force -ErrorAction SilentlyContinue"
[2023-09-18T07:27:38.373Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:435 remove_single_nrpt_rule() Removed nrpt rules
[2023-09-18T07:27:38.373Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1553 run_tunnel() Setting interface metric to 255
[2023-09-18T07:27:38.373Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:492 update_interface_metric() Executing Update Interface metric script :
[2023-09-18T07:27:38.373Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:493 update_interface_metric() powershell -Command "$i=Get-NetIPInterface | Where -FilterScript {$_.InterfaceAlias -Eq "ziti-tun0"}
Set-NetIPInterface -InterfaceIndex $i.ifIndex -InterfaceMetric 255"
[2023-09-18T07:27:38.384Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:499 update_interface_metric() Updated Interface metric
[2023-09-18T07:27:38.384Z]    INFO tunnel-sdk:ziti_tunnel.c:60 create_tunneler_ctx() Ziti Tunneler SDK (2.1.16)
[2023-09-18T07:27:38.389Z]   DEBUG ziti-edge-tunnel:tun.c:327 tun_setup_read() tun=00000230876f9490, adapter=0000023087b20860, session=0000023087b20cc0
[2023-09-18T07:27:38.389Z]    INFO tunnel-cbs:ziti_dns.c:168 seed_dns() DNS configured with range 100.64.0.0 - 100.127.255.255 (4194302 ips)
[2023-09-18T07:27:38.389Z]   DEBUG tunnel-sdk:ziti_tunnel.c:320 ziti_tunneler_intercept() intercepting address[udp:100.64.0.2/32:53] service[ziti:dns-resolver]
[2023-09-18T07:27:38.390Z]   DEBUG ziti-edge-tunnel:tun.c:377 tun_add_route() adding route: 100.64.0.2/32
[2023-09-18T07:27:38.390Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1599 run_tunneler_loop() Loading identity files from C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry
[2023-09-18T07:27:38.390Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1078 load_identities() skipping the configuration file: config.json
[2023-09-18T07:27:38.390Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1081 load_identities() skipping the backup configuration file: config.json.backup
[2023-09-18T07:27:38.390Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1093 load_identities() loading identity file: web-pc.json
[2023-09-18T07:27:38.390Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:1073 load_identities() skipping file in config dir as it's not the proper type. type: 2. file: ZitiUpdateService
[2023-09-18T07:27:38.392Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:515 update_symlink() Executing update symlink script :
[2023-09-18T07:27:38.392Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:516 update_symlink() powershell -Command "Get-Item -Path "C:\Program Files (x86)\NetFoundry Inc\Ziti Desktop Edge\/logs/service/ziti-tunneler.log" | Remove-Item
New-Item -Itemtype SymbolicLink -Path "C:\Program Files (x86)\NetFoundry Inc\Ziti Desktop Edge\/logs/service/ziti-tunneler.log" -Target "C:\Program Files (x86)\NetFoundry Inc\Ziti Desktop Edge\/logs/service/ziti-tunneler.log.202309180000.log""
[2023-09-18T07:27:38.405Z]   DEBUG ziti-edge-tunnel:windows-scripts.c:522 update_symlink() Updated symlink script
[2023-09-18T07:27:38.405Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:864 load_ziti_async() attempting to load ziti instance from file[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/web-pc.json]
[2023-09-18T07:27:38.405Z]    INFO tunnel-cbs:ziti_tunnel_ctrl.c:871 load_ziti_async() loading ziti instance from C:\Windows\system32\config\systemprofile\AppData\Roaming\NetFoundry\web-pc.json
[2023-09-18T07:27:38.405Z]    INFO ziti-sdk:utils.c:173 ziti_log_set_level() set log level: root=4/DEBUG
[2023-09-18T07:27:38.405Z]   DEBUG ziti-sdk:config.c:73 load_config() trying to load config from file
[2023-09-18T07:27:38.407Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1108 load_id_cb() identity[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/web-pc.json] loaded
[2023-09-18T07:27:38.410Z]   DEBUG ziti-edge-tunnel:instance-config.c:131 save_tunnel_status_to_file() Deleted backup config file C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/config.json.backup
[2023-09-18T07:27:38.410Z]   DEBUG ziti-edge-tunnel:instance-config.c:134 save_tunnel_status_to_file() Copied config file to backup config file C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/config.json.backup
[2023-09-18T07:27:38.411Z]   DEBUG ziti-edge-tunnel:instance-config.c:156 save_tunnel_status_to_file() Saved current tunnel status into Config file C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/config.json
[2023-09-18T07:27:38.411Z]    INFO ziti-sdk:ziti.c:424 ziti_init_async() ztx[0] Ziti C SDK version 0.31.4 @68c3a76(HEAD) starting at (2023-09-18T07:27:38.411)
[2023-09-18T07:27:38.411Z]    INFO ziti-sdk:ziti.c:427 ziti_init_async() ztx[0] using tlsuv[<unknown>], tls[mbed TLS 3.2.1]
[2023-09-18T07:27:38.411Z]    INFO ziti-sdk:ziti.c:429 ziti_init_async() ztx[0] Loading ziti context with controller[https://openziti:8441]
[2023-09-18T07:27:38.411Z]    INFO ziti-sdk:ziti_ctrl.c:409 ziti_ctrl_init() ctrl[openziti] ziti controller client initialized
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti.c:451 ziti_init_async() ztx[0] using metrics interval: 0
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti.c:918 ziti_re_auth() ztx[0] re-auth executing, transitioning to unauthenticated
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti.c:288 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2023-09-18T07:27:38.411Z]    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-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti.c:250 ziti_set_auth_started() ztx[0] setting api_session_state[0] to 1
[2023-09-18T07:27:38.411Z]   DEBUG ziti-sdk:ziti.c:322 ziti_stop_api_session_refresh() ztx[0] ziti_stop_api_session_refresh: stopping api session refresh
[2023-09-18T07:27:38.997Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:706 on_events_client() Received events client connection request, count: 1
[2023-09-18T07:27:38.997Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:755 send_events_message() Events Message => {"Op":"status","Status":{"Active":true,"Duration":4007,"StartTime":"2023-09-18T07:27:34.990631Z","Identities":[{"Name":"web-pc","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/web-pc.json","FingerPrint":"web-pc","Active":false,"Loaded":true,"Config":{"ztAPI":"https://openziti:8441"},"ControllerVersion":"v0.30.0","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}],"IpInfo":{"Ip":"100.64.0.1","Subnet":"255.192.0.0","MTU":65535,"DNS":"100.64.0.2"},"LogLevel":"debug","ServiceVersion":{"Version":"2.1.16","BuildDate":"Tue-03/14/2023-20:18:12-+00"},"TunIpv4":"100.64.0.1","TunIpv4Mask":10,"AddDns":false,"ApiPageSize":25}}
[2023-09-18T07:27:38.997Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:662 on_cmd_client() Received IPC client connection request, count: 1
[2023-09-18T07:27:39.004Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:706 on_events_client() Received events client connection request, count: 2
[2023-09-18T07:27:39.004Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:755 send_events_message() Events Message => {"Op":"status","Status":{"Active":true,"Duration":4014,"StartTime":"2023-09-18T07:27:34.990631Z","Identities":[{"Name":"web-pc","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/web-pc.json","FingerPrint":"web-pc","Active":false,"Loaded":true,"Config":{"ztAPI":"https://openziti:8441"},"ControllerVersion":"v0.30.0","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}],"IpInfo":{"Ip":"100.64.0.1","Subnet":"255.192.0.0","MTU":65535,"DNS":"100.64.0.2"},"LogLevel":"debug","ServiceVersion":{"Version":"2.1.16","BuildDate":"Tue-03/14/2023-20:18:12-+00"},"TunIpv4":"100.64.0.1","TunIpv4Mask":10,"AddDns":false,"ApiPageSize":25}}
[2023-09-18T07:27:39.004Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:662 on_cmd_client() Received IPC client connection request, count: 2
[2023-09-18T07:27:39.636Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 4, change = 0
[2023-09-18T07:27:40.106Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:635 on_cmd() received cmd <{"Data":{"OnOff":true,"Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/web-pc.json"},"Command":"IdentityOnOff"}
>
[2023-09-18T07:27:40.106Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:221 on_command_resp() resp[0,len=65] = {"Success":false,"Error":"ziti context is not loaded","Code":500}
[2023-09-18T07:27:47.737Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 3, change = 0
[2023-09-18T07:27:53.418Z]   ERROR ziti-sdk:ziti_ctrl.c:155 ctrl_resp_cb() ctrl[openziti] request failed: -4039(connection timed out)
[2023-09-18T07:27:53.418Z]   ERROR ziti-sdk:ziti.c:1528 version_cb() ztx[0] failed to get controller version from https://openziti:8441 CONTROLLER_UNAVAILABLE(connection timed out)
[2023-09-18T07:27:53.418Z]   ERROR ziti-sdk:ziti_ctrl.c:155 ctrl_resp_cb() ctrl[openziti] request failed: -4039(connection timed out)
[2023-09-18T07:27:53.418Z]    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-18T07:27:53.418Z]   DEBUG ziti-sdk:ziti.c:1499 api_session_cb() ztx[0] unhandled error, setting api_session_timer to 5s
[2023-09-18T07:27:53.418Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[1] to 0
[2023-09-18T07:27:53.418Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-18T07:27:53.418Z]   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-18T07:27:53.418Z]    WARN tunnel-cbs:ziti_tunnel_ctrl.c:739 on_ziti_event() ziti_ctx controller connections failed: Ziti Controller is not available
[2023-09-18T07:27:53.418Z]    INFO ziti-edge-tunnel:ziti-edge-tunnel.c:1138 on_event() ztx[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/web-pc.json] context event : status is Ziti Controller is not available
[2023-09-18T07:27:53.418Z]   ERROR ziti-edge-tunnel:ziti-edge-tunnel.c:1193 on_event() ztx[C:\Windows\system32\config\systemprofile\AppData\Roaming/NetFoundry/web-pc.json] failed to connect to controller due to Ziti Controller is not available
[2023-09-18T07:27:53.418Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:755 send_events_message() Events Message => {"Op":"identity","Action":"added","Fingerprint":"web-pc","Id":{"Name":"web-pc","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/web-pc.json","FingerPrint":"web-pc","Active":false,"Loaded":true,"Config":{"ztAPI":"https://openziti:8441"},"ControllerVersion":"v0.30.0","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}}
[2023-09-18T07:27:53.418Z]   DEBUG ziti-edge-tunnel:ziti-edge-tunnel.c:755 send_events_message() Events Message => {"Op":"controller","Action":"disconnected","Identifier":"C:\\Windows\\system32\\config\\systemprofile\\AppData\\Roaming/NetFoundry/web-pc.json","Fingerprint":"web-pc"}
[2023-09-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti.c:839 api_session_refresh() ztx[0] api_session_refresh running
[2023-09-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti.c:288 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2023-09-18T07:27:58.432Z]   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-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti.c:918 ziti_re_auth() ztx[0] re-auth executing, transitioning to unauthenticated
[2023-09-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[0] to 0
[2023-09-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti.c:288 is_api_session_expired() ztx[0] is_api_session_expired[TRUE] - api_session is null
[2023-09-18T07:27:58.432Z]    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-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti.c:250 ziti_set_auth_started() ztx[0] setting api_session_state[0] to 1
[2023-09-18T07:27:58.432Z]   DEBUG ziti-sdk:ziti.c:322 ziti_stop_api_session_refresh() ztx[0] ziti_stop_api_session_refresh: stopping api session refresh
[2023-09-18T07:27:58.800Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 3, change = 0
[2023-09-18T07:28:00.635Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 3, change = 0
[2023-09-18T07:28:03.944Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 20, change = 0
[2023-09-18T07:28:03.944Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 20, change = 0
[2023-09-18T07:28:03.944Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 20, change = 0
[2023-09-18T07:28:03.959Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 20, change = 0
[2023-09-18T07:28:04.060Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 20, change = 0
[2023-09-18T07:28:04.060Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 20, change = 0
[2023-09-18T07:28:04.462Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 7, change = 0
[2023-09-18T07:28:04.726Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 7, change = 0
[2023-09-18T07:28:04.848Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 20, change = 0
[2023-09-18T07:28:05.885Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 3, change = 0
[2023-09-18T07:28:06.155Z]   DEBUG ziti-edge-tunnel:tun.c:401 if_change_cb() interface change: if_idx = 3, change = 0
[2023-09-18T07:28:07.272Z]   ERROR ziti-sdk:ziti_ctrl.c:155 ctrl_resp_cb() ctrl[openziti] request failed: -4079(software caused connection abort)
[2023-09-18T07:28:07.272Z]    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] software caused connection abort
[2023-09-18T07:28:07.272Z]   DEBUG ziti-sdk:ziti.c:1499 api_session_cb() ztx[0] unhandled error, setting api_session_timer to 5s
[2023-09-18T07:28:07.272Z]   DEBUG ziti-sdk:ziti.c:257 ziti_set_unauthenticated() ztx[0] setting api_session_state[1] to 0
[2023-09-18T07:28:07.272Z]   DEBUG ziti-sdk:ziti_ctrl.c:245 ziti_ctrl_clear_api_session() ctrl[openziti] clearing api session token for ziti_controller
[2023-09-18T07:28:07.272Z]   DEBUG ziti-sdk:ziti.c:327 ziti_schedule_api_session_refresh() ztx[0] ziti_schedule_api_session_refresh: scheduling api session refresh: 5000ms

Trace Log

[2023-09-18T07:40:52.335Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-18T07:40:52.335Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-18T07:40:52.335Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:57143->100.64.0.1:5355
[2023-09-18T07:40:52.335Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:224.0.0.252:5355
[2023-09-18T07:40:52.335Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-18T07:40:52.335Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram FE80::D5A1:7544:4315:CEAD:56984->FE80::D5A1:7544:4315:CEAD:5355
[2023-09-18T07:40:52.335Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:FF02::1:3:5355
[2023-09-18T07:40:52.335Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-18T07:40:52.335Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:56984->100.64.0.1:5355
[2023-09-18T07:40:52.335Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:224.0.0.252:5355
[2023-09-18T07:40:52.693Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-18T07:40:52.693Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram FE80::D5A1:7544:4315:CEAD:53912->FE80::D5A1:7544:4315:CEAD:3702
[2023-09-18T07:40:52.693Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:FF02::C:3702
[2023-09-18T07:40:52.753Z]   TRACE ziti-edge-tunnel:tun.c:303 tun_read() starting read
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram FE80::D5A1:7544:4315:CEAD:57143->FE80::D5A1:7544:4315:CEAD:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:FF02::1:3:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram FE80::D5A1:7544:4315:CEAD:56811->FE80::D5A1:7544:4315:CEAD:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:FF02::1:3:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram FE80::D5A1:7544:4315:CEAD:52533->FE80::D5A1:7544:4315:CEAD:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:FF02::1:3:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:52533->100.64.0.1:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:224.0.0.252:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:57143->100.64.0.1:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:224.0.0.252:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:56811->100.64.0.1:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:224.0.0.252:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram FE80::D5A1:7544:4315:CEAD:56984->FE80::D5A1:7544:4315:CEAD:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:FF02::1:3:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:183 recv_udp() received datagram 100.64.0.1:56984->100.64.0.1:5355
[2023-09-18T07:40:52.753Z]   TRACE tunnel-sdk:tunnel_udp.c:208 recv_udp() no intercepted addresses match udp:224.0.0.252:5355


Do you mean the controller was rebooted? If so, that will be a problem if the IP and DNS change. Can you confirm that's the situation here? Let's start by confirming if that's what happened here. Did your controller reboot and did you get a new IP/DNS?

If this is what happened, I think we need to make a "note" or "caution" around this and make sure people understand that the quickstart will use these values in the PKI it generates. When/if the IP (or DNS) changes, it will invalidate your PKI, and that causes edge clients (and routers and everything really) to not be able to reconnect...

Thank you so much
Yes that was the case, after reboot system IP configuration was changed... I don't why it happened.
Thank you

It happens in aws if the vm reboots, as one example. You definitely should assign a standard IP, or best yet, use a domain name that you own and you know won't change.

I'll add an issue to make this more prominent in the doc

Thank you for your reply. I have set permanent IP and Gateway. DNS is already set and is permanent.

But I am seeing some warn log in service status. Sometimes on android phone, using another internet it delays. This is all happening after rebooting the system.

P.S. Accessing from LAN is fine but sometimes service is unreachable from WAN.

Thank you

Controller

 ziti-controller.service - Ziti-Controller
     Loaded: loaded (/etc/systemd/system/ziti-controller.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2023-09-19 11:29:40 UTC; 1h 18min ago
   Main PID: 3034 (ziti)
      Tasks: 9 (limit: 6970)
     Memory: 68.5M
        CPU: 41.706s
     CGroup: /system.slice/ziti-controller.service
             └─3034 /root/.ziti/quickstart/ztn/ziti-bin/ziti-v0.30.0/ziti controller run /root/.ziti/quickstart/ztn/ztn.yaml

Sep 19 12:40:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:40:36.802Z"}
Sep 19 12:41:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:41:36.805Z"}
Sep 19 12:42:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:42:36.809Z"}
Sep 19 12:43:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:43:36.811Z"}
Sep 19 12:43:36 ztn ziti[3034]: {"file":"github.com/openziti/fabric@v0.24.2/controller/network/fault.go:31","func":"github.com/openziti/fabric/controller/network.(*Network).fault","level":"info","msg":"network fault processing for [1] circuits","time":"2023-09-19T12:43:36.914Z"}
Sep 19 12:43:36 ztn ziti[3034]: {"circuitId":"22RWfEwBb","file":"github.com/openziti/fabric@v0.24.2/controller/network/fault.go:48","func":"github.com/openziti/fabric/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"vQutsJRrHa","time":"2023-09-19T12:43:36.914Z"}
Sep 19 12:44:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:44:36.814Z"}
Sep 19 12:45:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:45:36.818Z"}
Sep 19 12:46:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:46:36.819Z"}

Sep 19 12:43:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:43:36.811Z"}
Sep 19 12:43:36 ztn ziti[3034]: {"file":"github.com/openziti/fabric@v0.24.2/controller/network/fault.go:31","func":"github.com/openziti/fabric/controller/network.(*Network).fault","level":"info","msg":"network fault processing for [1] circuits","time":"2023-09-19T12:43:36.914Z"}
Sep 19 12:43:36 ztn ziti[3034]: {"circuitId":"22RWfEwBb","file":"github.com/openziti/fabric@v0.24.2/controller/network/fault.go:48","func":"github.com/openziti/fabric/controller/network.(*Network).fault","level":"info","msg":"sent unroute for circuit to router in response to forwarding fault","routerId":"vQutsJRrHa","time":"2023-09-19T12:43:36.914Z"}
Sep 19 12:44:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:44:36.814Z"}
Sep 19 12:45:36 ztn ziti[3034]: {"circuitCount":13,"file":"github.com/openziti/fabric@v0.24.2/controller/handler_ctrl/circuit_confirmation.go:45","func":"github.com/openziti/fabric/controller/handler_ctrl.(*circuitConfirmationHandler).HandleReceive","level":"info","msg":"received circuit confirmation request","routerId":"vQutsJRrHa","time":"2023-09-19T12:45:36.818Z"}

Router

● 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 Tue 2023-09-19 11:29:36 UTC; 1h 18min ago
   Main PID: 2992 (ziti)
      Tasks: 8 (limit: 6970)
     Memory: 31.2M
        CPU: 35.257s
     CGroup: /system.slice/ziti-router.service
             └─2992 /root/.ziti/quickstart/ztn/ziti-bin/ziti-v0.30.0/ziti router run /root/.ziti/quickstart/ztn/ztn-edge-router.yaml

Sep 19 12:47:36 ztn ziti[2992]: {"circuitId":"wQYUfAwBb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":813078000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:47:36.822Z"}
Sep 19 12:47:36 ztn ziti[2992]: {"circuitId":"EHJKTAwXb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":1029931000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:47:36.822Z"}
Sep 19 12:47:36 ztn ziti[2992]: {"circuitId":"4zlKTErXZ","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":1029808000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:47:36.822Z"}

Sep 19 12:47:36 ztn ziti[2992]: {"circuitId":"0rliTArBb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":1030141000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:47:36.822Z"}
Sep 19 12:47:36 ztn ziti[2992]: {"circuitId":"q-YUfEwBb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":813125000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:47:36.823Z"}
Sep 19 12:47:36 ztn ziti[2992]: {"circuitId":"3FQphErBb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":813125000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:47:36.823Z"}
Sep 19 12:47:36 ztn ziti[2992]: {"circuitId":"OYUUhEwBZ","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":812010000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:47:36.823Z"}
Sep 19 12:47:36 ztn ziti[2992]: {"circuitCount":13,"ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:97","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","level":"warning","msg":"sent confirmation for circuits","time":"2023-09-19T12:47:36.823Z"}

Sep 19 12:50:36 ztn ziti[2992]: {"circuitId":"OYUUhEwBZ","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":992018000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:50:36.830Z"}
Sep 19 12:50:36 ztn ziti[2992]: {"circuitId":"wQYUfAwBb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":993086000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:50:36.830Z"}
Sep 19 12:50:36 ztn ziti[2992]: {"circuitId":"EHJKTAwXb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":1209939000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:50:36.830Z"}
Sep 19 12:50:36 ztn ziti[2992]: {"circuitId":"0rliTArBb","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":1210149000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:50:36.831Z"}
Sep 19 12:50:36 ztn ziti[2992]: {"circuitId":"M6lKoArBZ","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":1209869000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:50:36.831Z"}
Sep 19 12:50:36 ztn ziti[2992]: {"circuitId":"b6lKoArXZ","ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:85","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","idleThreshold":60000000000,"idleTime":1209708000000,"level":"warning","msg":"circuit exceeds idle threshold","time":"2023-09-19T12:50:36.831Z"}
Sep 19 12:50:36 ztn ziti[2992]: {"circuitCount":13,"ctrlId":"ztn","file":"github.com/openziti/fabric@v0.24.2/router/forwarder/scanner.go:97","func":"github.com/openziti/fabric/router/forwarder.(*Scanner).scan","level":"warning","msg":"sent confirmation for circuits","time":"2023-09-19T12:50:36.831Z"}

@mike.gorman or maybe @plorenz what does "circuit exceeds idle threshold" indicate? Other than those, things seem ok here.

@kashif, getting the logs from the android device will be useful too, along with a more clear description of what you're doing? A diagram might be needed to help more.

"circuit exceeds idle threshold" indicates an open circuit that has had no data pass over it in more than 1 minute. It can be perfectly normal, if it is orphaned at any point, it will be cleaned up with the Edge Routers confirm their circuits with the Controller.

Hi
Thank your for reply. Now i checked and it is not showing any delays. I will keep monitor.

Here are the logs, no packet logs

Service

--------- beginning of main
09-19 16:31:02.822  5663  5714 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:02.822  5663  5714 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.009  5663  5714 V C.s.com:8442]: got m = ct: Data, seq: 172, repTo: -1, connId: 47, body 32785 bytes
09-19 16:31:03.010  5663  5714 V ziti-conn[CgjM1860B/47]: conn[47] received message[Data] with seq[33]
09-19 16:31:03.010  5663  5714 V ziti-conn[CgjM1860B/47]: received data(32785 bytes) for conn[47]
09-19 16:31:03.011  5663  5714 V ziti-conn[CgjM1860B/47]: saving 16384 for later
09-19 16:31:03.011  5663  5714 V ziti-conn[CgjM1860B/47]: transferred 16384
09-19 16:31:03.011  5663  5714 V ziti-conn[CgjM1860B/47]: read completed null
09-19 16:31:03.012  5663  5714 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.012  5663  5714 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[950684] ack[2772971560] data[16384]
09-19 16:31:03.012  5663  5714 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.013  5663  5714 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.013  5663  5711 V C.s.com:8442]: got m = ct: StateConnected, seq: 173, repTo: 234, connId: 48, body 0 bytes
09-19 16:31:03.013  5663  5714 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.013  5663  5714 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[967068] ack[2772971560] data[16384]
09-19 16:31:03.014  5663  5714 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.014  5663  5714 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.015  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.015  5663  5711 D ziti-conn[CgjM1860B/48]: network connection established clmqcikzt05bdcaarrp3a46cw/48
09-19 16:31:03.015  5663  5716 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.015  5663  5714 V C.s.com:8442]: sending m = ct: Data, seq: 235, repTo: -1, connId: 48, body 24 bytes
09-19 16:31:03.015  5663  5711 D ziti-conn[CgjM1860B/48]: connected
09-19 16:31:03.015  5663  5716 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.017  5663  5708 D tcp:/100.64.0.0:52152 -> /100.64.1.3:8069: sending to peer packet_size[60]
09-19 16:31:03.017  5663  5714 V tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069: received flags[SYN] seq[3635527988] ack[0] ws[65456 (1072431104)]
09-19 16:31:03.017  5663  5714 V tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069: state[SYN_RCVD] <- SYN data[0]
09-19 16:31:03.018  5663  5708 V ziti-conn[CgjM1860B/48]: reading
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069: invalid packet for state[SYN_RCVD]: [TCP Header (40 bytes)]
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Source port: 52152 (unknown)
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Destination port: 8069 (unknown)
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Sequence Number: 3635527988
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Acknowledgment Number: 0
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Data Offset: 10 (40 [bytes])
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Reserved: 0
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   URG: false
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   ACK: false
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   PSH: false
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   RST: false
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   SYN: true
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   FIN: false
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Window: 65456
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Checksum: 0xe73e
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Urgent Pointer: 0
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Option: [Kind: 2 (Maximum Segment Size)] [Length: 4 bytes] [Maximum Segment Size: 32728 bytes]
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Option: [Kind: 4 (SACK Permitted)] [Length: 2 bytes]
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Option: [Kind: 8 (Timestamps)] [Length: 10 bytes] [TS Value: 759864] [TS Echo Reply: 0]
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Option: [Kind: 1 (No Operation)]
09-19 16:31:03.018  5663  5714 E tcp:/100.64.0.0:52152 -> odooprod.ziti/100.64.1.3:8069:   Option: [Kind: 3 (Window Scale)] [Length: 3 bytes] [Shift Count: 8]
09-19 16:31:03.019  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.019  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.020  5663  5710 V C.s.com:8442]: got m = ct: Data, seq: 174, repTo: -1, connId: 48, body 24 bytes
09-19 16:31:03.020  5663  5710 V ziti-conn[CgjM1860B/48]: conn[48] received message[Data] with seq[1]
09-19 16:31:03.020  5663  5710 V ziti-conn[CgjM1860B/48]: received data(24 bytes) for conn[48]
09-19 16:31:03.020  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.020  5663  5710 D ziti-conn[CgjM1860B/48]: crypto init finished conn[48]
09-19 16:31:03.024  5663 13524 W routing : dropping unhandled packet [IPv4 Header (20 bytes)]
09-19 16:31:03.024  5663 13524 W routing :   Version: 4 (IPv4)
09-19 16:31:03.024  5663 13524 W routing :   IHL: 5 (20 [bytes])
09-19 16:31:03.024  5663 13524 W routing :   TOS: [precedence: 6 (Internetwork Control/ECP)] [tos: 0 (Default)] [mbz: 0]
09-19 16:31:03.024  5663 13524 W routing :   Total length: 88 [bytes]
09-19 16:31:03.024  5663 13524 W routing :   Identification: 38774
09-19 16:31:03.024  5663 13524 W routing :   Flags: (Reserved, Don't Fragment, More Fragment) = (false, false, false)
09-19 16:31:03.024  5663 13524 W routing :   Fragment offset: 0 (0 [bytes])
09-19 16:31:03.024  5663 13524 W routing :   TTL: 64
09-19 16:31:03.024  5663 13524 W routing :   Protocol: 1 (ICMPv4)
09-19 16:31:03.024  5663 13524 W routing :   Header checksum: 0x18ec
09-19 16:31:03.024  5663 13524 W routing :   Source address: /100.64.0.0
09-19 16:31:03.024  5663 13524 W routing :   Destination address: /100.64.1.3
09-19 16:31:03.074  5663  5710 V C.s.com:8442]: got m = ct: Data, seq: 175, repTo: -1, connId: 47, body 32785 bytes
09-19 16:31:03.074  5663  5710 V ziti-conn[CgjM1860B/47]: conn[47] received message[Data] with seq[34]
09-19 16:31:03.075  5663  5710 V ziti-conn[CgjM1860B/47]: received data(32785 bytes) for conn[47]
09-19 16:31:03.075  5663 14012 V ziti-conn[CgjM1860B/47]: saving 16384 for later
09-19 16:31:03.076  5663 14012 V ziti-conn[CgjM1860B/47]: transferred 16384
09-19 16:31:03.076  5663 14012 V ziti-conn[CgjM1860B/47]: read completed null
09-19 16:31:03.076  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.077  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[983452] ack[2772971560] data[16384]
09-19 16:31:03.077  5663 14012 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.077  5663 14012 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.077  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.078  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[999836] ack[2772971560] data[16384]
09-19 16:31:03.078  5663 14012 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.078  5663 14012 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.079  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.079  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.080  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.080  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.081  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.081  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.191  5663  5710 V C.s.com:8442]: got m = ct: Data, seq: 176, repTo: -1, connId: 47, body 32785 bytes
09-19 16:31:03.192  5663  5710 V ziti-conn[CgjM1860B/47]: conn[47] received message[Data] with seq[35]
09-19 16:31:03.192  5663  5710 V ziti-conn[CgjM1860B/47]: received data(32785 bytes) for conn[47]
09-19 16:31:03.193  5663  5710 V ziti-conn[CgjM1860B/47]: saving 16384 for later
09-19 16:31:03.193  5663  5710 V ziti-conn[CgjM1860B/47]: transferred 16384
09-19 16:31:03.193  5663  5710 V ziti-conn[CgjM1860B/47]: read completed null
09-19 16:31:03.194  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.195  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[1016220] ack[2772971560] data[16384]
09-19 16:31:03.195  5663  5708 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.195  5663  5708 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.196  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.196  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[1032604] ack[2772971560] data[16384]
09-19 16:31:03.196  5663  5708 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.197  5663  5708 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.199  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.201  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.202  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.202  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.202  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.202  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.310  5663  5708 V C.s.com:8442]: got m = ct: Data, seq: 177, repTo: -1, connId: 47, body 32785 bytes
09-19 16:31:03.311  5663  5708 V ziti-conn[CgjM1860B/47]: conn[47] received message[Data] with seq[36]
09-19 16:31:03.311  5663  5708 V ziti-conn[CgjM1860B/47]: received data(32785 bytes) for conn[47]
09-19 16:31:03.315  5663 14012 V ziti-conn[CgjM1860B/47]: saving 16384 for later
09-19 16:31:03.315  5663 14012 V ziti-conn[CgjM1860B/47]: transferred 16384
09-19 16:31:03.316  5663 14012 V ziti-conn[CgjM1860B/47]: read completed null
09-19 16:31:03.317  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.319  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[1048988] ack[2772971560] data[16384]
09-19 16:31:03.320  5663 14012 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.321  5663 14012 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.325  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 16384 from ziti
09-19 16:31:03.325  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.327  5663  5710 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.327  5663 14012 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[16416] flags[ACK] seq[1065372] ack[2772971560] data[16384]
09-19 16:31:03.327  5663  5710 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.328  5663 14012 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[16436]
09-19 16:31:03.329  5663 14012 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.335  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.337  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.337  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.388  5663  5708 V C.s.com:8442]: got m = ct: Data, seq: 178, repTo: -1, connId: 47, body 10661 bytes
09-19 16:31:03.388  5663  5708 V ziti-conn[CgjM1860B/47]: conn[47] received message[Data] with seq[37]
09-19 16:31:03.388  5663  5708 V ziti-conn[CgjM1860B/47]: received data(10661 bytes) for conn[47]
09-19 16:31:03.390  5663  5708 V ziti-conn[CgjM1860B/47]: transferred 10644
09-19 16:31:03.390  5663  5708 V ziti-conn[CgjM1860B/47]: read completed null
09-19 16:31:03.390  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got from 10644 from ziti
09-19 16:31:03.391  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[10676] flags[ACK] seq[1081756] ack[2772971560] data[10644]
09-19 16:31:03.391  5663  5708 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[10696]
09-19 16:31:03.391  5663  5708 V ziti-conn[CgjM1860B/47]: reading
09-19 16:31:03.398  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.401  5663 13964 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.401  5663 13964 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[CLOSE_WAIT] <- ACK data[0]
09-19 16:31:03.473  5663 13964 V C.s.com:8442]: got m = ct: Data, seq: 179, repTo: -1, connId: 47, body 0 bytes
09-19 16:31:03.473  5663 13964 V ziti-conn[CgjM1860B/47]: conn[47] received message[Data] with seq[38]
09-19 16:31:03.473  5663 13964 V ziti-conn[CgjM1860B/47]: received data(0 bytes) for conn[47]
09-19 16:31:03.474  5663 13964 D ziti-conn[CgjM1860B/47]: received FIN
09-19 16:31:03.476  5663  5708 V ziti-conn[CgjM1860B/47]: read completed kotlinx.coroutines.channels.ClosedReceiveChannelException: Channel was closed
09-19 16:31:03.477  5663  5708 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: ziti conn is closed
09-19 16:31:03.478  5663  5708 D tcp-conn: tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069/CLOSE_WAIT transitioning to LAST_ACK
09-19 16:31:03.478  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: made packet[32] flags[SYN,ACK,FIN] seq[1092400] ack[2772971560] data[null]
09-19 16:31:03.479  5663  5708 D tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: sending to peer packet_size[52]
09-19 16:31:03.480  5663  5708 D tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: got close() in LAST_ACK
09-19 16:31:03.480  5663  5708 I tcp:/100.64.0.0:52150 -> /100.64.1.3:8069: readZitiConn() is finished
09-19 16:31:03.484  5663 13524 V routing : got msg[(/100.64.0.0:52150, /100.64.1.3:8069)]: 52 bytes
09-19 16:31:03.487  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: received flags[ACK] seq[2772971560] ack[459164] ws[3844 (62980096)]
09-19 16:31:03.488  5663  5708 V tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069: state[LAST_ACK] <- ACK data[0]
09-19 16:31:03.488  5663  5708 D tcp-conn: tcp:/100.64.0.0:52150 -> odooprod.ziti/100.64.1.3:8069/LAST_ACK transitioning to Closed
09-19 16:31:03.489  5663  5708 D ziti-conn[CgjM1860B/47]: sending FIN
09-19 16:31:03.491  5663  5710 V C.s.com:8442]: sending m = ct: Data, seq: 236, repTo: -1, connId: 47, body 0 bytes
09-19 16:31:03.493  5663  5708 D ziti-conn[CgjM1860B/47]: closing conn = 47
09-19 16:31:03.497  5663 14012 V C.s.com:8442]: sending m = ct: StateClosed, seq: 237, repTo: -1, connId: 47, body 0 bytes
09-19 16:31:06.750  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,720,1480) new=(0,0,720,1480) req=(720,1480)4 dur=19 res=0x1 s={false 0} ch=false
09-19 16:31:06.750  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: stopped(false) old=true
09-19 16:31:06.754  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: stopped(false) old=false
09-19 16:31:06.772  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,720,1480) new=(0,0,720,1480) req=(720,1480)0 dur=6 res=0x7 s={true 491549351936} ch=true
09-19 16:31:06.773  5663 13415 I mali_winsys: new_window_surface() [720x1480] return: 0x3000
09-19 16:31:06.775  5663  5663 D ScrollView:  onsize change changed 
09-19 16:31:06.777  5663  5663 D ScrollView:  onsize change changed 
09-19 16:31:06.804  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: MSG_WINDOW_FOCUS_CHANGED 1 1
09-19 16:31:06.804  5663  5663 D InputMethodManager: prepareNavigationBarInfo() DecorView@2c932e2[ZitiMobileEdgeActivity]
09-19 16:31:06.804  5663  5663 D InputMethodManager: getNavigationBarColor() -855310
09-19 16:31:06.805  5663  5663 D InputMethodManager: prepareNavigationBarInfo() DecorView@2c932e2[ZitiMobileEdgeActivity]
09-19 16:31:06.805  5663  5663 D InputMethodManager: getNavigationBarColor() -855310
09-19 16:31:06.805  5663  5663 V InputMethodManager: Starting input: tba=org.openziti.mobile ic=null mNaviBarColor -855310 mIsGetNaviBarColorSuccess true , NavVisible : true , NavTrans : false
09-19 16:31:06.805  5663  5663 D InputMethodManager: startInputInner - Id : 0
09-19 16:31:06.805  5663  5663 I InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
09-19 16:31:06.856  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: MSG_RESIZED: frame=(0,0,720,1480) ci=(0,42,0,84) vi=(0,42,0,84) or=1
09-19 16:31:06.878  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,720,1480) new=(0,0,720,1480) req=(720,1480)0 dur=4 res=0x1 s={true 491549351936} ch=false
09-19 16:31:06.888  5663  5663 D ScrollView:  onsize change changed 
09-19 16:31:06.889  5663  5663 D ScrollView:  onsize change changed 
09-19 16:31:07.654  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:07.688  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:07.764  5663 13524 W routing : not handling [IPv6 Header (40 bytes)]
09-19 16:31:07.764  5663 13524 W routing :   Version: 6 (IPv6)
09-19 16:31:07.764  5663 13524 W routing :   Traffic Class: 0x00
09-19 16:31:07.764  5663 13524 W routing :   Flow Label: 0x00000
09-19 16:31:07.764  5663 13524 W routing :   Payload length: 8 [bytes]
09-19 16:31:07.764  5663 13524 W routing :   Next Header: 58 (ICMPv6)
09-19 16:31:07.764  5663 13524 W routing :   Hop Limit: 255
09-19 16:31:07.764  5663 13524 W routing :   Source address: /fe80::cdab:a8f2:acde:d210
09-19 16:31:07.764  5663 13524 W routing :   Destination address: /ff02::2
09-19 16:31:07.764  5663 13524 W routing :  at this time
09-19 16:31:08.522  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:08.572  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:10.050  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:10.098  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:11.190  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:11.224  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:13.042  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:13.075  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:16.711  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme key 0
09-19 16:31:16.791  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: ViewPostIme key 1
09-19 16:31:16.812  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: MSG_WINDOW_FOCUS_CHANGED 0 1
09-19 16:31:16.812  5663  5663 D InputMethodManager: prepareNavigationBarInfo() DecorView@2c932e2[ZitiMobileEdgeActivity]
09-19 16:31:16.812  5663  5663 D InputMethodManager: getNavigationBarColor() -855310
09-19 16:31:16.874  5663 13415 I mali_egl: eglDestroySurface() in
09-19 16:31:16.875  5663 13415 I mali_winsys: delete_surface() [720x1480] return
09-19 16:31:16.876  5663 13415 I mali_egl: eglDestroySurface() out
09-19 16:31:16.876  5663 13415 W libEGL  : EGLNativeWindowType 0x727fc0c750 disconnect failed
09-19 16:31:16.880  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,720,1480) new=(0,0,720,1480) req=(720,1480)8 dur=4 res=0x5 s={false 0} ch=true
09-19 16:31:16.881  5663  5663 D InputTransport: Input channel destroyed: 'ClientS', fd=86
09-19 16:31:16.885  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: stopped(true) old=false
09-19 16:31:16.888  5663  5663 I ViewRootImpl@e84ea16[ZitiMobileEdgeActivity]: dispatchDetachedFromWindow
09-19 16:31:16.892  5663  5663 D InputTransport: Input channel destroyed: 'd85a1b2', fd=69
09-19 16:31:17.740  5663  5663 W ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@8746d97
09-19 16:31:17.788  5663  5663 D ScrollView: initGoToTop
09-19 16:31:17.876  5663  5663 D ScrollView: initGoToTop
09-19 16:31:17.878  5663  5663 D PhoneWindow: forceLight changed to true [] from com.android.internal.policy.PhoneWindow.updateForceLightNavigationBar:4274 com.android.internal.policy.DecorView.updateColorViews:1547 com.android.internal.policy.PhoneWindow.dispatchWindowAttributesChanged:3252 android.view.Window.setFlags:1153 com.android.internal.policy.PhoneWindow.generateLayout:2474 
09-19 16:31:17.878  5663  5663 I MultiWindowDecorSupport: [INFO] isPopOver = false
09-19 16:31:17.878  5663  5663 I MultiWindowDecorSupport: updateCaptionType >> DecorView@f4ae07b[], isFloating: false, isApplication: true, hasWindowDecorCaption: false, hasWindowControllerCallback: true
09-19 16:31:17.878  5663  5663 D MultiWindowDecorSupport: setCaptionType = 0, DecorView = DecorView@f4ae07b[]
09-19 16:31:17.903  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: setView = com.android.internal.policy.DecorView@f4ae07b TM=true MM=false
09-19 16:31:17.924  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,720,1480) new=(0,0,720,1480) req=(720,1480)0 dur=6 res=0x7 s={true 491549384704} ch=true
09-19 16:31:17.925  5663 13415 I mali_winsys: new_window_surface() [720x1480] return: 0x3000
09-19 16:31:17.931  5663  5663 D ScrollView:  onsize change changed 
09-19 16:31:17.932  5663  5663 D ScrollView:  onsize change changed 
09-19 16:31:17.947  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: MSG_WINDOW_FOCUS_CHANGED 1 1
09-19 16:31:17.947  5663  5663 D InputMethodManager: prepareNavigationBarInfo() DecorView@f4ae07b[ZitiMobileEdgeActivity]
09-19 16:31:17.947  5663  5663 D InputMethodManager: getNavigationBarColor() -855310
09-19 16:31:17.948  5663  5663 D InputMethodManager: prepareNavigationBarInfo() DecorView@f4ae07b[ZitiMobileEdgeActivity]
09-19 16:31:17.948  5663  5663 D InputMethodManager: getNavigationBarColor() -855310
09-19 16:31:17.948  5663  5663 V InputMethodManager: Starting input: tba=org.openziti.mobile ic=null mNaviBarColor -855310 mIsGetNaviBarColorSuccess true , NavVisible : true , NavTrans : false
09-19 16:31:17.948  5663  5663 D InputMethodManager: startInputInner - Id : 0
09-19 16:31:17.948  5663  5663 I InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
09-19 16:31:17.954  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: MSG_RESIZED: frame=(0,0,720,1480) ci=(0,42,0,84) vi=(0,42,0,84) or=1
09-19 16:31:18.664  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:18.714  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:19.675  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:19.724  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:20.643  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:20.699  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
09-19 16:31:21.678  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
09-19 16:31:21.717  5663  5663 I ViewRootImpl@d056c12[ZitiMobileEdgeActivity]: ViewPostIme pointer 1