openziti / ziti-sdk-c

A C-based sdk for delivering secure applications over a Ziti Network
https://docs.openziti.io/docs/reference/developer/sdk/ziti-sdk-c
Apache License 2.0
71 stars 14 forks source link

Crash on network change #323

Closed scareything closed 2 years ago

scareything commented 2 years ago
Screen Shot 2021-11-08 at 4 06 56 PM
[    19948.816]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19948.816] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:212 src connected status = -49
[    19948.816]   DEBUG cmake-build-debug/_deps/uv-mbed-src/src/http.c:231 failed to connect: -49(address not available)
[    19948.816] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/ziti_ctrl.c:684 ctrl_paging_req() requesting /services?limit=25&offset=0
[    19948.816] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/ziti.c:849 update_services() ztx[0] scheduling service refresh 10 seconds from now
[    19948.816]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/ziti.c:855 update_services() ztx[0] failed to get service updates err[CONTROLLER_UNAVAILABLE/address not available] from ctrl[https://3.210.34.143:443]
[    19950.477]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[5] connecting to 3.109.234.45:443
[    19950.478]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19950.478]    WARN cmake-build-debug/_deps/uv-mbed-src/src/uv_mbed.c:125 failed to connect
[    19950.478]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:856 on_channel_connect_internal() ch[5] failed to connect [-49/address not available]
[    19950.478]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:743 reconnect_channel() ch[5] reconnecting in 4686 ms (attempt = 3)
[    19950.490]   DEBUG lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:170 process_cmd() processing command[GetMetrics] with data[{"id":"/Users/scarey/.ziti/mop/mattermost.shawn.carey.pc_Enrollment.json"}]
[    19953.333]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[3] connecting to 129.159.89.151:443
[    19953.334]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19953.334]    WARN cmake-build-debug/_deps/uv-mbed-src/src/uv_mbed.c:125 failed to connect
[    19953.334]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:856 on_channel_connect_internal() ch[3] failed to connect [-49/address not available]
[    19953.334]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:743 reconnect_channel() ch[3] reconnecting in 14799 ms (attempt = 3)
[    19953.949]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[0] connecting to 129.159.71.35:443
[    19953.950]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19953.950]    WARN cmake-build-debug/_deps/uv-mbed-src/src/uv_mbed.c:125 failed to connect
[    19953.950]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:856 on_channel_connect_internal() ch[0] failed to connect [-49/address not available]
[    19953.950]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:743 reconnect_channel() ch[0] reconnecting in 56681 ms (attempt = 5)
[    19955.165]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[5] connecting to 3.109.234.45:443
[    19955.165]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19955.165]    WARN cmake-build-debug/_deps/uv-mbed-src/src/uv_mbed.c:125 failed to connect
[    19955.165]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:856 on_channel_connect_internal() ch[5] failed to connect [-49/address not available]
[    19955.165]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:743 reconnect_channel() ch[5] reconnecting in 20400 ms (attempt = 4)
[    19955.491]   DEBUG lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:170 process_cmd() processing command[GetMetrics] with data[{"id":"/Users/scarey/.ziti/mop/mattermost.shawn.carey.pc_Enrollment.json"}]
[    19956.670]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[6] connecting to 129.151.44.40:443
[    19956.672]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19956.672]    WARN cmake-build-debug/_deps/uv-mbed-src/src/uv_mbed.c:125 failed to connect
[    19956.672]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:856 on_channel_connect_internal() ch[6] failed to connect [-49/address not available]
[    19956.672]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:743 reconnect_channel() ch[6] reconnecting in 127513 ms (attempt = 5)
[    19958.225]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[2] connecting to 129.151.45.194:443
[    19958.227]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19958.227]    WARN cmake-build-debug/_deps/uv-mbed-src/src/uv_mbed.c:125 failed to connect
[    19958.227]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:856 on_channel_connect_internal() ch[2] failed to connect [-49/address not available]
[    19958.227]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:743 reconnect_channel() ch[2] reconnecting in 3217 ms (attempt = 4)
[    19958.315] VERBOSE lib/ziti-tunnel/tunnel_tcp.c:342 recv_tcp() received SYN on active connection: client=tcp:192.168.0.0:60299, service=mattermost.tools.netfoundry.io
[    19958.817] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:352 client not connected, starting connect sequence
[    19958.818]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19958.818] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:212 src connected status = -49
[    19958.818]   DEBUG cmake-build-debug/_deps/uv-mbed-src/src/http.c:231 failed to connect: -49(address not available)
[    19958.818] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/ziti_ctrl.c:684 ctrl_paging_req() requesting /services?limit=25&offset=0
[    19958.818] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/ziti.c:849 update_services() ztx[0] scheduling service refresh 10 seconds from now
[    19958.818]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/ziti.c:855 update_services() ztx[0] failed to get service updates err[CONTROLLER_UNAVAILABLE/address not available] from ctrl[https://3.210.34.143:443]
[    19960.100]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[1] connecting to 129.146.214.27:443
[    19960.101]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tcp_src.c:101 connect failed: -49(address not available)
[    19960.101]    WARN cmake-build-debug/_deps/uv-mbed-src/src/uv_mbed.c:125 failed to connect
[    19960.101]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:856 on_channel_connect_internal() ch[1] failed to connect [-49/address not available]
[    19960.101]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:743 reconnect_channel() ch[1] reconnecting in 7074 ms (attempt = 3)
[    19960.491]   DEBUG lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:170 process_cmd() processing command[GetMetrics] with data[{"id":"/Users/scarey/.ziti/mop/mattermost.shawn.carey.pc_Enrollment.json"}]
[    19960.836]   DEBUG lib/ziti-tunnel/tunnel_tcp.c:109 new_tcp_pcb() snd_wnd: 65535, snd_snd_max: 65535, mss: 32768
[    19960.836]    INFO lib/ziti-tunnel/tunnel_tcp.c:386 recv_tcp() intercepted address[tcp:192.168.0.10:443] client[tcp:192.168.0.0:60322] service[mattermost.tools.netfoundry.io]
[    19960.836] VERBOSE lib/ziti-tunnel-cbs/ziti_tunnel_cbs.c:294 ziti_sdk_c_dial() ziti_dial(name=mattermost.tools.netfoundry.io)
[    19960.836]   DEBUG lib/ziti-tunnel-cbs/ziti_tunnel_cbs.c:360 ziti_sdk_c_dial() service[mattermost.tools.netfoundry.io] app_data_json[174]='{"dst_protocol":"tcp","dst_hostname":"mattermost.tools.netfoundry.io","dst_ip":"192.168.0.10","dst_port":"443","src_protocol":"tcp","src_ip":"192.168.0.0","src_port":"60322"}'
[    19960.836] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/connect.c:94 conn_set_state() conn[0.298] transitioning Initial => Connecting
[    19960.836] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/posture.c:183 ziti_send_posture_data() ztx[0] starting to send posture data
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/posture.c:187 ziti_send_posture_data() ztx[0] posture checks either never sent or api session changed, must_send = true
[    19960.836] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/posture.c:205 ziti_send_posture_data() ztx[0] checking posture queries on 1 service(s)
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/posture.c:464 ziti_pr_send_bulk() ztx[0] no change in posture data, not sending
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/connect.c:485 ziti_connect_async() conn[0.298] starting Dial connection for service[mattermost.tools.netfoundry.io] with session[ckvr44fx70jto0fomrdcb1sfg]
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:275 ziti_channel_connect() ztx[0] existing ch[0](Disconnected) found for ingress[tls://129.159.71.35:443]
[    19960.836]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:746 reconnect_channel() ch[0] reconnecting NOW
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:275 ziti_channel_connect() ztx[0] existing ch[1](Disconnected) found for ingress[tls://129.146.214.27:443]
[    19960.836]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:746 reconnect_channel() ch[1] reconnecting NOW
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:275 ziti_channel_connect() ztx[0] existing ch[2](Disconnected) found for ingress[tls://129.151.45.194:443]
[    19960.836]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:746 reconnect_channel() ch[2] reconnecting NOW
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:275 ziti_channel_connect() ztx[0] existing ch[3](Disconnected) found for ingress[tls://129.159.89.151:443]
[    19960.836]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:746 reconnect_channel() ch[3] reconnecting NOW
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:275 ziti_channel_connect() ztx[0] existing ch[4](Disconnected) found for ingress[tls://65.2.62.54:443]
[    19960.836]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:746 reconnect_channel() ch[4] reconnecting NOW
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:275 ziti_channel_connect() ztx[0] existing ch[5](Disconnected) found for ingress[tls://3.109.234.45:443]
[    19960.836]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:746 reconnect_channel() ch[5] reconnecting NOW
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:275 ziti_channel_connect() ztx[0] existing ch[6](Disconnected) found for ingress[tls://129.151.44.40:443]
[    19960.836]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:746 reconnect_channel() ch[6] reconnecting NOW
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[0] connecting to 129.159.71.35:443
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[1] connecting to 129.146.214.27:443
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[2] connecting to 129.151.45.194:443
[    19960.836]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:717 reconnect_cb() ch[3] connecting to 129.159.89.151:443
Exception: EXC_BAD_ACCESS (code=1, address=0x38)
scareything commented 2 years ago

another crash

image

(macOS fills freed memory with 0x55 bytes, because MallocScribble is set)

[   131985.697]   DEBUG lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:170 process_cmd() processing command[GetMetrics] with data[{"id":"/Users/scarey/.ziti/mop/mattermost.shawn.carey.pc_Enrollment.json"}]
[   131987.803]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tls_link.c:115 TLS read -54(connection reset by peer)
[   131987.803]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:807 on_channel_data() ch[5] channel was closed [-54/connection reset by peer]
[   131987.803]    INFO lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:682 on_ziti_event() ztx[mattermost.shawn.carey.pc] router Mattermost-Public-Edge-aws-ap-south-1-1@tls://3.109.234.45:443 disconnected
[   131987.803]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:570 latency_reply_cb() ch[5] latency probe was canceled: -20(Connection to edge router terminated)
[   131987.803]   ERROR cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:627 hello_reply_cb() ch[5] failed to receive Hello response due to -20(Connection to edge router terminated)
[   131987.803]    INFO lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:688 on_ziti_event() ztx[mattermost.shawn.carey.pc] router Mattermost-Public-Edge-aws-ap-south-1-1@tls://3.109.234.45:443 is unavailable
[   131987.803]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:718 reconnect_channel() ch[5] not reconnecting closed channel
[   131989.718] VERBOSE lib/ziti-tunnel/tunnel_tcp.c:343 recv_tcp() received SYN on active connection: client=tcp:192.168.0.0:52969, service=mattermost.tools.netfoundry.io
[   131990.453]   ERROR cmake-build-debug/_deps/uv-mbed-src/src/tls_link.c:115 TLS read -54(connection reset by peer)
[   131990.453]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:807 on_channel_data() ch[3] channel was closed [-54/connection reset by peer]
[   131990.453]    INFO lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:682 on_ziti_event() ztx[mattermost.shawn.carey.pc] router Mattermost-Public-Edge-ocp-us-ashburn-1-1@tls://129.159.89.151:443 disconnected
[   131990.453]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:570 latency_reply_cb() ch[3] latency probe was canceled: -20(Connection to edge router terminated)
[   131990.453]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:731 reconnect_channel() ch[3] reconnecting in 6915 ms (attempt = 1)
[   131990.699]   DEBUG lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:170 process_cmd() processing command[GetMetrics] with data[{"id":"/Users/scarey/.ziti/mop/mattermost.shawn.carey.pc_Enrollment.json"}]
[   131991.460]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:705 reconnect_cb() ch[1] connecting to 129.146.214.27:443
[   131991.791]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:834 on_channel_connect_internal() ch[1] connected
[   131991.849]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:635 hello_reply_cb() ch[1] connected. EdgeRouter version: v0.22.10|258fe85a29f4|2021-11-05 18:44:47|linux|amd64
[   131991.849]    INFO lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:679 on_ziti_event() ztx[mattermost.shawn.carey.pc] router Mattermost-Public-Edge-ocp-us-phoenix-1-1@tls://129.146.214.27:443 connected
[   131993.878] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:352 client not connected, starting connect sequence
[   131993.907] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:212 src connected status = 0
[   131993.940] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:362 client connected, processing request[/current-api-session/service-updates] state[0]
[   131993.940] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:364 sending request[/current-api-session/service-updates] headers
[   131993.940] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:375 sending request[/current-api-session/service-updates] body
[   131993.940] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:246 request write completed: 0
[   131994.038] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http_req.c:196 status = 200 OK
[   131994.038] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http_req.c:206 message complete
[   131994.038] VERBOSE cmake-build-debug/_deps/ziti-sdk-c-src/library/ziti.c:1045 check_service_update() ztx[0] not updating: last_update is same previous (2021-11-20T10:44:14.276Z == 2021-11-20T10:44:14.276Z)
[   131994.038] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http_req.c:69 processed 329 out of 329
[   131994.038] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:343 no more requests, scheduling idle(0) close
[   131994.038] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:328 idle timeout triggered
[   131994.038] VERBOSE cmake-build-debug/_deps/uv-mbed-src/src/http.c:319 closing connection
[   131995.700]   DEBUG lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:170 process_cmd() processing command[GetMetrics] with data[{"id":"/Users/scarey/.ziti/mop/mattermost.shawn.carey.pc_Enrollment.json"}]
[   131997.368]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:705 reconnect_cb() ch[3] connecting to 129.159.89.151:443
[   131997.620]   DEBUG cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:834 on_channel_connect_internal() ch[3] connected
[   131997.648]    INFO cmake-build-debug/_deps/ziti-sdk-c-src/library/channel.c:635 hello_reply_cb() ch[3] connected. EdgeRouter version: v0.22.10|258fe85a29f4|2021-11-05 18:44:47|linux|amd64
[   131997.648]    INFO lib/ziti-tunnel-cbs/ziti_tunnel_ctrl.c:679 on_ziti_event() ztx[mattermost.shawn.carey.pc] router Mattermost-Public-Edge-ocp-us-ashburn-1-1@tls://129.159.89.151:443 connected
Exception: EXC_BAD_ACCESS (code=1, address=0x5555555555555575)
ekoby commented 2 years ago

fixed in [#400]