jeka
/
utun2
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity
Browse Source

Fix test files for Windows cross-platform compatibility 

- Create test_utils.h with cross-platform utility functions:
  * test_mkdtemp() - Windows uses GetTempPath + _mkdir, Linux uses mkdtemp
  * test_unlink() - Windows _unlink, Linux unlink
  * test_rmdir() - Windows _rmdir, Linux rmdir

- Update all test files to use test_utils.h
- Replace arpa/inet.h and netinet/in.h with platform_compat.h
- Replace unistd.h with conditional includes
- Replace mkdtemp(), unlink(), rmdir() with test_* versions

- Tests now build on both Linux and Windows
- Note: Some integration tests may fail on Linux due to test environment
nodeinfo-routing-update
Evgeny 2 months ago
parent
0798b149ab
commit
4d486c7017
40 changed files with 193 additions and 8925 deletions
Whitespace
Show all changes Ignore whitespace when comparing lines Ignore changes in amount of whitespace Ignore changes in whitespace at EOL
Split View
Diff Options
Show Stats Download Patch File Download Diff File
  1. 24
      tests/logs/bench_timeout_heap.log
  2. 149
      tests/logs/bench_uasync_timeouts.log
  3. 226
      tests/logs/test_bgp_route_exchange.log
  4. 16
      tests/logs/test_config_debug.log
  5. 6
      tests/logs/test_crypto.log
  6. 8
      tests/logs/test_debug_categories.log
  7. 19
      tests/logs/test_ecc_encrypt.log
  8. 3383
      tests/logs/test_etcp_100_packets.log
  9. 171
      tests/logs/test_etcp_api.log
  10. 6
      tests/logs/test_etcp_crypto.log
  11. 46
      tests/logs/test_etcp_minimal.log
  12. 548
      tests/logs/test_etcp_simple_traffic.log
  13. 528
      tests/logs/test_etcp_two_instances.log
  14. 44
      tests/logs/test_intensive_memory_pool.log
  15. 104
      tests/logs/test_ll_queue.log
  16. 26
      tests/logs/test_memory_pool_and_config.log
  17. 3
      tests/logs/test_packet_dump.log
  18. 195
      tests/logs/test_pkt_normalizer_etcp.log
  19. 29
      tests/logs/test_pkt_normalizer_standalone.log
  20. 3182
      tests/logs/test_route_lib.log
  21. 115
      tests/logs/test_u_async_comprehensive.log
  22. 59
      tests/logs/test_u_async_performance.log
  23. BIN
      tests/test_bgp_route_exchange
  24. 56
      tests/test_bgp_route_exchange.c
  25. BIN
      tests/test_config_debug
  26. 13
      tests/test_config_debug.c
  27. BIN
      tests/test_etcp_100_packets
  28. 17
      tests/test_etcp_100_packets.c
  29. BIN
      tests/test_etcp_api
  30. 17
      tests/test_etcp_api.c
  31. BIN
      tests/test_etcp_minimal
  32. BIN
      tests/test_etcp_simple_traffic
  33. 17
      tests/test_etcp_simple_traffic.c
  34. BIN
      tests/test_etcp_two_instances
  35. 18
      tests/test_etcp_two_instances.c
  36. BIN
      tests/test_memory_pool_and_config
  37. 3
      tests/test_memory_pool_and_config.c
  38. BIN
      tests/test_pkt_normalizer_etcp
  39. 17
      tests/test_pkt_normalizer_etcp.c
  40. 73
      tests/test_utils.h

24
tests/logs/bench_timeout_heap.log
Unescape View File

@ -1,24 +0,0 @@
=== timeout_heap benchmark ===
Operations: 100 each
Push 100 items:
Total time: 0.001 ms
Average per push: 0.014 us
Heap size after: 100
Cancel 50 items:
Total time: 0.001 ms
Average per cancel: 0.022 us
Heap size: 100 (deleted marked)
Pop 50 items:
Total time: 0.002 ms
Average per pop: 0.049 us
Heap size after: 0
=== Summary ===
Push: 0.001 ms total, 0.014 us/op
Cancel: 0.001 ms total, 0.022 us/op
Pop: 0.002 ms total, 0.049 us/op
Total operations: 250

149
tests/logs/bench_uasync_timeouts.log
Unescape View File

@ -1,149 +0,0 @@
=================================================
uasync timeout benchmark: with vs without sockets
=================================================
=== Test 1: Zero timeouts WITHOUT sockets ===
Set 100 zero timeouts: 0.008 ms (0.078 us/op)
Mainloop 100 iterations: 0.021 ms (0.207 us/iter)
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x5c6b4805c2b0
Timer Statistics: allocated=100, freed=100, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
=== Test 2: Zero timeouts WITH 100 sockets ===
Created 100 sockets
Set 100 zero timeouts: 0.004 ms (0.044 us/op)
Mainloop 100 iterations: 0.020 ms (0.197 us/iter)
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x5c6b4805c360
Timer Statistics: allocated=100, freed=100, active=0
Socket Statistics: allocated=100, freed=0, active=100
Active timers in heap: 0
Socket array capacity: 128, active: 100
Socket: fd=6, active=1
Socket: fd=7, active=1
Socket: fd=8, active=1
Socket: fd=9, active=1
Socket: fd=10, active=1
Socket: fd=11, active=1
Socket: fd=12, active=1
Socket: fd=13, active=1
Socket: fd=14, active=1
Socket: fd=15, active=1
Socket: fd=16, active=1
Socket: fd=17, active=1
Socket: fd=18, active=1
Socket: fd=19, active=1
Socket: fd=20, active=1
Socket: fd=21, active=1
Socket: fd=22, active=1
Socket: fd=23, active=1
Socket: fd=24, active=1
Socket: fd=25, active=1
Socket: fd=26, active=1
Socket: fd=27, active=1
Socket: fd=28, active=1
Socket: fd=29, active=1
Socket: fd=30, active=1
Socket: fd=31, active=1
Socket: fd=32, active=1
Socket: fd=33, active=1
Socket: fd=34, active=1
Socket: fd=35, active=1
Socket: fd=36, active=1
Socket: fd=37, active=1
Socket: fd=38, active=1
Socket: fd=39, active=1
Socket: fd=40, active=1
Socket: fd=41, active=1
Socket: fd=42, active=1
Socket: fd=43, active=1
Socket: fd=44, active=1
Socket: fd=45, active=1
Socket: fd=46, active=1
Socket: fd=47, active=1
Socket: fd=48, active=1
Socket: fd=49, active=1
Socket: fd=50, active=1
Socket: fd=51, active=1
Socket: fd=52, active=1
Socket: fd=53, active=1
Socket: fd=54, active=1
Socket: fd=55, active=1
Socket: fd=56, active=1
Socket: fd=57, active=1
Socket: fd=58, active=1
Socket: fd=59, active=1
Socket: fd=60, active=1
Socket: fd=61, active=1
Socket: fd=62, active=1
Socket: fd=63, active=1
Socket: fd=64, active=1
Socket: fd=65, active=1
Socket: fd=66, active=1
Socket: fd=67, active=1
Socket: fd=68, active=1
Socket: fd=69, active=1
Socket: fd=70, active=1
Socket: fd=71, active=1
Socket: fd=72, active=1
Socket: fd=73, active=1
Socket: fd=74, active=1
Socket: fd=75, active=1
Socket: fd=76, active=1
Socket: fd=77, active=1
Socket: fd=78, active=1
Socket: fd=79, active=1
Socket: fd=80, active=1
Socket: fd=81, active=1
Socket: fd=82, active=1
Socket: fd=83, active=1
Socket: fd=84, active=1
Socket: fd=85, active=1
Socket: fd=86, active=1
Socket: fd=87, active=1
Socket: fd=88, active=1
Socket: fd=89, active=1
Socket: fd=90, active=1
Socket: fd=91, active=1
Socket: fd=92, active=1
Socket: fd=93, active=1
Socket: fd=94, active=1
Socket: fd=95, active=1
Socket: fd=96, active=1
Socket: fd=97, active=1
Socket: fd=98, active=1
Socket: fd=99, active=1
Socket: fd=100, active=1
Socket: fd=101, active=1
Socket: fd=102, active=1
Socket: fd=103, active=1
Socket: fd=104, active=1
Socket: fd=105, active=1
Total active sockets: 100
🔚 BEFORE_DESTROY: End of resource report
=================================================
COMPARISON
=================================================
Set 100 timeouts:
Without sockets: 0.008 ms (0.078 us/op)
With 100 sockets: 0.004 ms (0.044 us/op)
Difference: -43.30%
Mainloop 100 iterations:
Without sockets: 0.021 ms (0.207 us/iter)
With 100 sockets: 0.020 ms (0.197 us/iter)
Difference: -4.90%
=================================================

226
tests/logs/test_bgp_route_exchange.log
Unescape View File

@ -1,226 +0,0 @@
=== BGP Route Exchange Test ===
[03:30:18-689.090] [INFO] [8] (test_bgp_route_exchange.c:321) main() Creating server instance...
[CONFIG DEBUG] Opening config file: /tmp/utun_bgp_test_bQPBmS/server.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='67b705a92b41bcaae105af2d6a17743faa7b26ccebba8b3b9b0af05e9cd1d5fb' (len=64), pub_key='1c55e4ccae7c4470707759086738b10681bf88b81f198cc2ab54a647d1556e17c65e6b1833e0c771e5a39382c03067c388915a4c732191bc130480f20f8e00b9' (len=128), node_id=1229782938247303441
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_bgp_test_bQPBmS/server.conf
[CONFIG DEBUG] Successfully opened config file
[03:30:18-689.205] [INFO] [512] (routing.c:272) routing_create() Routing module initialized for instance
[03:30:18-689.211] [INFO] [512] (utun_instance.c:91) utun_instance_create() Routing module created
[03:30:18-689.216] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.11.168.192/24 (LOCAL)
[03:30:18-689.220] [INFO] [512] (utun_instance.c:110) utun_instance_create() Added local route: 192.168.11.0/24
[03:30:18-689.223] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.10.168.192/24 (LOCAL)
[03:30:18-689.227] [INFO] [512] (utun_instance.c:110) utun_instance_create() Added local route: 192.168.10.0/24
[03:30:18-689.230] [INFO] [4096] (route_bgp.c:382) route_bgp_init() Route change callback registered
[03:30:18-689.234] [INFO] [4096] (route_bgp.c:385) route_bgp_init() BGP module initialized
[03:30:18-689.237] [INFO] [4096] (utun_instance.c:143) utun_instance_create() BGP module initialized
DEBUG: utun_instance_init() calling init_connections() for instance 0x5f1c9066ccd0
[03:30:18-689.260] [INFO] [8] (etcp_connections.c:342) etcp_socket_add() [ETCP] Successfully bound socket to local address, family=2
[03:30:18-689.266] [INFO] [8] (etcp_connections.c:366) etcp_socket_add() [ETCP] Socket 0x5f1c9066e530 registered and active
DEBUG: init_connections() returned: 0
DEBUG: Connections initialized successfully, count=0
[03:30:18-689.273] [INFO] [8] (test_bgp_route_exchange.c:335) main() Server instance ready (node_id=1111111111111111, bgp=0x5f1c9066cc90)
[03:30:18-689.276] [INFO] [8] (test_bgp_route_exchange.c:339) main() Creating client instance...
[CONFIG DEBUG] Opening config file: /tmp/utun_bgp_test_bQPBmS/client.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='4813d31d28b7e9829247f488c6be7672f2bdf61b2508333128e386d1759afed2' (len=64), pub_key='c594f33c91f3a2222795c2c110c527bf214ad1009197ce14556cb13df3c461b3c373bed8f205a8dd1fc0c364f90bf471d7c6f5db49564c33e4235d268569ac71' (len=128), node_id=2459565876494606882
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_bgp_test_bQPBmS/client.conf
[CONFIG DEBUG] Successfully opened config file
[03:30:18-689.344] [INFO] [512] (routing.c:272) routing_create() Routing module initialized for instance
[03:30:18-689.351] [INFO] [512] (utun_instance.c:91) utun_instance_create() Routing module created
[03:30:18-689.354] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.21.168.192/24 (LOCAL)
[03:30:18-689.358] [INFO] [512] (utun_instance.c:110) utun_instance_create() Added local route: 192.168.21.0/24
[03:30:18-689.361] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.20.168.192/24 (LOCAL)
[03:30:18-689.365] [INFO] [512] (utun_instance.c:110) utun_instance_create() Added local route: 192.168.20.0/24
[03:30:18-689.368] [INFO] [4096] (route_bgp.c:382) route_bgp_init() Route change callback registered
[03:30:18-689.372] [INFO] [4096] (route_bgp.c:385) route_bgp_init() BGP module initialized
[03:30:18-689.378] [INFO] [4096] (utun_instance.c:143) utun_instance_create() BGP module initialized
DEBUG: utun_instance_init() calling init_connections() for instance 0x5f1c906714f0
[03:30:18-689.395] [INFO] [8] (etcp_connections.c:342) etcp_socket_add() [ETCP] Successfully bound socket to local address, family=2
[03:30:18-689.408] [INFO] [8] (etcp_connections.c:366) etcp_socket_add() [ETCP] Socket 0x5f1c906728a0 registered and active
[03:30:18-689.823] [INFO] [8] (etcp_connections.c:90) etcp_link_send_init() [ETCP] INIT sending to 127.0.0.1:39011, link=0x5f1c9068a8f0
[03:30:18-689.830] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-693.237] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
DEBUG: init_connections() returned: 0
DEBUG: Connections initialized successfully, count=1
[03:30:18-693.628] [INFO] [8] (test_bgp_route_exchange.c:353) main() Client instance ready (node_id=2222222222222222, bgp=0x5f1c9066f060)
[03:30:18-693.636] [INFO] [8] (test_bgp_route_exchange.c:357) main() Waiting for server initialization...
[03:30:18-693.739] [INFO] [8] (etcp_connections.c:671) etcp_connections_read_callback_socket() [ETCP DEBUG] Send INIT RESPONSE
[03:30:18-693.745] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-693.751] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-693.763] [INFO] [8] (etcp_loadbalancer.c:156) loadbalancer_link_ready() loadbalancer_link_ready: link=0x5f1c906b9520 now ready, notifying ETCP_CONN
[03:30:18-693.769] [INFO] [4096] (route_bgp.c:452) route_bgp_new_conn() Added connection 0x5f1c906ba2a0 to senders_list
[03:30:18-693.773] [INFO] [4096] (route_bgp.c:338) route_bgp_send_table_to_conn_internal() Sending full routing table (2 routes) to connection
[03:30:18-693.783] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-693.789] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-693.793] [INFO] [8] (etcp_loadbalancer.c:156) loadbalancer_link_ready() loadbalancer_link_ready: link=0x5f1c9068a8f0 now ready, notifying ETCP_CONN
[03:30:18-693.797] [INFO] [4096] (route_bgp.c:452) route_bgp_new_conn() Added connection 0x5f1c90673040 to senders_list
[03:30:18-693.800] [INFO] [4096] (route_bgp.c:338) route_bgp_send_table_to_conn_internal() Sending full routing table (2 routes) to connection
[03:30:18-695.449] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-695.476] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-695.542] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-695.581] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-695.633] [INFO] [4096] (route_bgp.c:67) route_bgp_receive_cbk() Received BGP packet: subcmd=1, network=000ba8c0/24, node_id=1111111111111111
[03:30:18-695.665] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.11.168.192/24 (LEARNED)
[03:30:18-695.677] [INFO] [4096] (route_bgp.c:101) route_bgp_receive_cbk() Added learned route: 000ba8c0/24 via node 1111111111111111 (hops=1)
[03:30:18-695.686] [INFO] [4096] (route_bgp.c:67) route_bgp_receive_cbk() Received BGP packet: subcmd=1, network=000aa8c0/24, node_id=1111111111111111
[03:30:18-695.691] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.10.168.192/24 (LEARNED)
[03:30:18-695.695] [INFO] [4096] (route_bgp.c:101) route_bgp_receive_cbk() Added learned route: 000aa8c0/24 via node 1111111111111111 (hops=1)
[03:30:18-695.706] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-695.725] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-695.761] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-695.767] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-695.771] [INFO] [4096] (route_bgp.c:67) route_bgp_receive_cbk() Received BGP packet: subcmd=1, network=0015a8c0/24, node_id=2222222222222222
[03:30:18-695.776] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.21.168.192/24 (LEARNED)
[03:30:18-695.779] [INFO] [4096] (route_bgp.c:101) route_bgp_receive_cbk() Added learned route: 0015a8c0/24 via node 2222222222222222 (hops=1)
[03:30:18-695.796] [INFO] [4096] (route_bgp.c:67) route_bgp_receive_cbk() Received BGP packet: subcmd=1, network=0014a8c0/24, node_id=2222222222222222
[03:30:18-695.800] [INFO] [512] (route_lib.c:379) route_table_insert() Route inserted: 0.20.168.192/24 (LEARNED)
[03:30:18-695.803] [INFO] [4096] (route_bgp.c:101) route_bgp_receive_cbk() Added learned route: 0014a8c0/24 via node 2222222222222222 (hops=1)
[03:30:18-697.934] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-697.961] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-697.986] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-697.992] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-746.275] [INFO] [8] (test_bgp_route_exchange.c:363) main() Starting connection monitoring...
[03:30:18-746.336] [INFO] [8] (test_bgp_route_exchange.c:368) main() Running event loop...
[03:30:18-756.415] [INFO] [8] (test_bgp_route_exchange.c:245) monitor_connections() === Connection established! Waiting for BGP exchange... ===
[03:30:18-776.535] [INFO] [512] (test_bgp_route_exchange.c:255) monitor_connections() === Checking BGP route exchange ===
[03:30:18-776.576] [INFO] [512] (test_bgp_route_exchange.c:199) verify_bgp_exchange()
=== Verifying BGP Route Exchange ===
[03:30:18-776.580] [INFO] [512] (test_bgp_route_exchange.c:150) print_routing_table()
=== SERVER Routing Table (4 routes) ===
[03:30:18-776.585] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 1: 0.11.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.589] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 2: 0.10.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.593] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 3: 0.21.168.192/24 [LEARNED] node_id=2222222222222222 hops=1
[03:30:18-776.596] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 4: 0.20.168.192/24 [LEARNED] node_id=2222222222222222 hops=1
[03:30:18-776.599] [INFO] [512] (test_bgp_route_exchange.c:172) print_routing_table() =====================================
[03:30:18-776.603] [INFO] [512] (test_bgp_route_exchange.c:150) print_routing_table()
=== CLIENT Routing Table (4 routes) ===
[03:30:18-776.606] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 1: 0.21.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.616] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 2: 0.20.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.619] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 3: 0.11.168.192/24 [LEARNED] node_id=1111111111111111 hops=1
[03:30:18-776.623] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 4: 0.10.168.192/24 [LEARNED] node_id=1111111111111111 hops=1
[03:30:18-776.626] [INFO] [512] (test_bgp_route_exchange.c:172) print_routing_table() =====================================
[03:30:18-776.629] [INFO] [512] (test_bgp_route_exchange.c:206) verify_bgp_exchange() Checking server learned client's routes...
[03:30:18-776.632] [INFO] [512] (test_bgp_route_exchange.c:212) verify_bgp_exchange() PASS: Server has learned route 192.168.20.0/24
[03:30:18-776.636] [INFO] [512] (test_bgp_route_exchange.c:219) verify_bgp_exchange() PASS: Server has learned route 192.168.21.0/24
[03:30:18-776.639] [INFO] [512] (test_bgp_route_exchange.c:225) verify_bgp_exchange() Checking client learned server's routes (disabled - server->client not implemented)...
[03:30:18-776.642] [INFO] [512] (test_bgp_route_exchange.c:260) monitor_connections() === BGP ROUTE EXCHANGE SUCCESS ===
[03:30:18-776.645] [INFO] [8] (test_bgp_route_exchange.c:375) main()
Cleaning up...
[03:30:18-776.649] [INFO] [512] (test_bgp_route_exchange.c:150) print_routing_table()
=== SERVER (final) Routing Table (4 routes) ===
[03:30:18-776.664] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 1: 0.11.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.667] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 2: 0.10.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.671] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 3: 0.21.168.192/24 [LEARNED] node_id=2222222222222222 hops=1
[03:30:18-776.674] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 4: 0.20.168.192/24 [LEARNED] node_id=2222222222222222 hops=1
[03:30:18-776.677] [INFO] [512] (test_bgp_route_exchange.c:172) print_routing_table() =====================================
[03:30:18-776.680] [INFO] [512] (test_bgp_route_exchange.c:150) print_routing_table()
=== CLIENT (final) Routing Table (4 routes) ===
[03:30:18-776.684] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 1: 0.21.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.687] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 2: 0.20.168.192/24 [LOCAL] node_id=0000000000000000 hops=0
[03:30:18-776.690] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 3: 0.11.168.192/24 [LEARNED] node_id=1111111111111111 hops=1
[03:30:18-776.694] [INFO] [512] (test_bgp_route_exchange.c:167) print_routing_table() Route 4: 0.10.168.192/24 [LEARNED] node_id=1111111111111111 hops=1
[03:30:18-776.697] [INFO] [512] (test_bgp_route_exchange.c:172) print_routing_table() =====================================
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x5f1c9066ccd0
Node ID: 1229782938247303441
UA instance: 0x5f1c9066c490
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x5f1c906ba2a0
ETCP Sockets list: 0x5f1c9066e530
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-776.704] [INFO] [8] (etcp_connections.c:375) etcp_socket_remove() [ETCP] Removing socket 0x5f1c9066e530, socket_id=0x5f1c9066c540
[03:30:18-776.708] [INFO] [8] (etcp_connections.c:379) etcp_socket_remove() [ETCP] Removing socket from uasync, instance=0x5f1c9066ccd0, ua=0x5f1c9066c490
[03:30:18-776.717] [INFO] [8] (etcp_connections.c:382) etcp_socket_remove() [ETCP] Unregistered socket from uasync
[03:30:18-776.732] [INFO] [8] (etcp_connections.c:387) etcp_socket_remove() [ETCP] Closed socket
[03:30:18-776.736] [INFO] [4096] (route_bgp.c:471) route_bgp_remove_conn() Removing connection 0x5f1c906ba2a0 from senders_list
[03:30:18-776.740] [INFO] [4096] (route_bgp.c:200) route_bgp_send_withdraw_for_conn() Sending withdraw for routes via conn 0x5f1c906ba2a0 to all peers
[03:30:18-776.744] [INFO] [4096] (route_bgp.c:484) route_bgp_remove_conn() Connection 0x5f1c906ba2a0 removed from senders_list
[03:30:18-776.748] [INFO] [512] (route_lib.c:425) route_table_delete() Removed 2 routes for connection 0x5f1c906ba2a0
[03:30:18-776.754] [INFO] [512] (routing.c:281) routing_destroy() Destroying routing module
[03:30:18-776.758] [INFO] [4096] (utun_instance.c:198) utun_instance_destroy() Destroying BGP module
[03:30:18-776.761] [INFO] [4096] (route_bgp.c:418) route_bgp_destroy() BGP module destroyed
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x5f1c906714f0
Node ID: 2459565876494606882
UA instance: 0x5f1c9066c490
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x5f1c90673040
ETCP Sockets list: 0x5f1c906728a0
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-776.767] [INFO] [8] (etcp_connections.c:375) etcp_socket_remove() [ETCP] Removing socket 0x5f1c906728a0, socket_id=0x5f1c9066c588
[03:30:18-776.773] [INFO] [8] (etcp_connections.c:379) etcp_socket_remove() [ETCP] Removing socket from uasync, instance=0x5f1c906714f0, ua=0x5f1c9066c490
[03:30:18-776.778] [INFO] [8] (etcp_connections.c:382) etcp_socket_remove() [ETCP] Unregistered socket from uasync
[03:30:18-776.784] [INFO] [8] (etcp_connections.c:387) etcp_socket_remove() [ETCP] Closed socket
[03:30:18-776.788] [INFO] [4096] (route_bgp.c:471) route_bgp_remove_conn() Removing connection 0x5f1c90673040 from senders_list
[03:30:18-776.791] [INFO] [4096] (route_bgp.c:200) route_bgp_send_withdraw_for_conn() Sending withdraw for routes via conn 0x5f1c90673040 to all peers
[03:30:18-776.794] [INFO] [4096] (route_bgp.c:484) route_bgp_remove_conn() Connection 0x5f1c90673040 removed from senders_list
[03:30:18-776.797] [INFO] [512] (route_lib.c:425) route_table_delete() Removed 2 routes for connection 0x5f1c90673040
[03:30:18-776.805] [INFO] [512] (routing.c:281) routing_destroy() Destroying routing module
[03:30:18-776.810] [INFO] [4096] (utun_instance.c:198) utun_instance_destroy() Destroying BGP module
[03:30:18-776.815] [INFO] [4096] (route_bgp.c:418) route_bgp_destroy() BGP module destroyed
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x5f1c9066c490
Timer Statistics: allocated=12, freed=9, active=3
Socket Statistics: allocated=2, freed=2, active=0
Timer: node=0x5f1c906b9040, expires=1771115418796 ms, cancelled=0
Timer: node=0x5f1c906b9100, expires=1771115418796 ms, cancelled=0
Active timers in heap: 2
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
=== TEST PASSED ===
BGP route exchange working (client -> server direction)

16
tests/logs/test_config_debug.log
Unescape View File

@ -1,16 +0,0 @@
[03:30:18-672.164] [ERROR] [128] (test_config_debug.c:77) main() 1. До загрузки конфигурации:
[03:30:18-672.192] [ERROR] [128] (test_config_debug.c:78) main() ERROR сообщение до загрузки конфигурации
[03:30:18-672.197] [ERROR] [128] (test_config_debug.c:82) main() 2. Загрузка конфигурации из файла: /tmp/utun_test_Wg6d7X/test.conf
[CONFIG DEBUG] Opening config file: /tmp/utun_test_Wg6d7X/test.conf
[CONFIG DEBUG] Successfully opened config file
[03:30:18-672.229] [ERROR] [128] (test_config_debug.c:90) main() ✅ Конфигурация загружена успешно
[03:30:18-672.233] [ERROR] [128] (test_config_debug.c:91) main() Log file: /tmp/utun_debug.log
[03:30:18-672.237] [ERROR] [128] (test_config_debug.c:92) main() Debug level: debug
[03:30:18-672.240] [ERROR] [128] (test_config_debug.c:93) main() Debug categories: 0x2A
[03:30:18-672.243] [ERROR] [128] (test_config_debug.c:94) main() Enable timestamp: 1
[03:30:18-672.246] [ERROR] [128] (test_config_debug.c:95) main() Enable colors: 1
[03:30:18-672.250] [ERROR] [128] (test_config_debug.c:98) main() 4. Тестирование после применения настроек:
[03:30:18-672.253] [ERROR] [8] (test_config_debug.c:99) main() ERROR от ETCP (должен выводиться)
[03:30:18-672.256] [ERROR] [128] (test_config_debug.c:108) main() 5. Проверка вывода в файл:
[03:30:18-672.339] [ERROR] [128] (test_config_debug.c:117) main() === Тест завершен ===
[03:30:18-672.347] [ERROR] [128] (test_config_debug.c:118) main() Проверьте файл /tmp/utun_debug.log для записанных сообщений

6
tests/logs/test_crypto.log
Unescape View File

@ -1,6 +0,0 @@
[03:30:18-140.772] [INFO] [16] (test_crypto.c:16) main() === Basic Crypto Test ===
[03:30:18-140.817] [INFO] [16] (test_crypto.c:27) main() AES key setup successful
[03:30:18-140.822] [INFO] [16] (test_crypto.c:38) main() CCM config successful
[03:30:18-140.829] [INFO] [16] (test_crypto.c:50) main() Encryption successful
[03:30:18-140.835] [INFO] [16] (test_crypto.c:58) main() Decryption successful
[03:30:18-140.838] [INFO] [16] (test_crypto.c:61) main() Crypto test PASSED

8
tests/logs/test_debug_categories.log
Unescape View File

@ -1,8 +0,0 @@
[03:30:18-670.950] [INFO] [18446744073709551615] (test_debug_categories.c:87) main() === Тестовые сообщения ===
[03:30:18-671.021] [INFO] [8] (test_debug_categories.c:90) main() Сообщение от ETCP категории
[03:30:18-671.026] [INFO] [2] (test_debug_categories.c:91) main() Сообщение от LL_QUEUE категории
[03:30:18-671.030] [INFO] [32] (test_debug_categories.c:92) main() Сообщение от MEMORY категории
[03:30:18-671.033] [INFO] [4] (test_debug_categories.c:93) main() Сообщение от CONNECTION категории
[03:30:18-671.036] [INFO] [16] (test_debug_categories.c:94) main() Сообщение от CRYPTO категории
[03:30:18-671.039] [INFO] [18446744073709551615] (test_debug_categories.c:96) main() === Информация о текущих настройках ===
[03:30:18-671.042] [INFO] [18446744073709551615] (test_debug_categories.c:107) main() Активные категории: NONE

19
tests/logs/test_ecc_encrypt.log
Unescape View File

@ -1,19 +0,0 @@
[03:30:18-627.647] [INFO] [16] (test_ecc_encrypt.c:182) main() Performing client-server key exchange and encryption test:
[03:30:18-627.740] [INFO] [16] (test_ecc_encrypt.c:90) test_key_exchange_and_encrypt() Generating client key pair...
[03:30:18-628.417] [INFO] [16] (test_ecc_encrypt.c:96) test_key_exchange_and_encrypt() Generating server key pair...
[03:30:18-629.081] [INFO] [16] (test_ecc_encrypt.c:103) test_key_exchange_and_encrypt() Computing shared secret on client side...
[03:30:18-629.765] [INFO] [16] (test_ecc_encrypt.c:110) test_key_exchange_and_encrypt() Computing shared secret on server side...
[03:30:18-630.424] [INFO] [16] (test_ecc_encrypt.c:123) test_key_exchange_and_encrypt() Shared secrets match.
[03:30:18-630.431] [INFO] [16] (test_ecc_encrypt.c:145) test_key_exchange_and_encrypt() Encrypting plaintext...
[03:30:18-630.436] [INFO] [16] (test_ecc_encrypt.c:155) test_key_exchange_and_encrypt() Decrypting ciphertext...
[03:30:18-630.440] [INFO] [16] (test_ecc_encrypt.c:169) test_key_exchange_and_encrypt() Decryption successful. Test passed.
[03:30:18-630.444] [INFO] [16] (test_ecc_encrypt.c:189) main() Result: PASS
[03:30:18-630.447] [INFO] [16] (test_ecc_encrypt.c:190) main() Test SUCCESSFUL

3383
tests/logs/test_etcp_100_packets.log
View File

File diff suppressed because it is too large Load Diff

171
tests/logs/test_etcp_api.log
Unescape View File

@ -1,171 +0,0 @@
=== ETCP API Test (etcp_send, etcp_bind) ===
Testing with 100 packets of random sizes (10-500 bytes)
Total data to transfer: 24691 bytes (0.24 KB average per packet)
Creating server...
[CONFIG DEBUG] Opening config file: /tmp/utun_test_oVJWUS/server.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='67b705a92b41bcaae105af2d6a17743faa7b26ccebba8b3b9b0af05e9cd1d5fb' (len=64), pub_key='1c55e4ccae7c4470707759086738b10681bf88b81f198cc2ab54a647d1556e17c65e6b1833e0c771e5a39382c03067c388915a4c732191bc130480f20f8e00b9' (len=128), node_id=1229782938247303441
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_oVJWUS/server.conf
[CONFIG DEBUG] Successfully opened config file
Server created, waiting for connection...
Creating client...
[CONFIG DEBUG] Opening config file: /tmp/utun_test_oVJWUS/client.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='4813d31d28b7e9829247f488c6be7672f2bdf61b2508333128e386d1759afed2' (len=64), pub_key='c594f33c91f3a2222795c2c110c527bf214ad1009197ce14556cb13df3c461b3c373bed8f205a8dd1fc0c364f90bf471d7c6f5db49564c33e4235d268569ac71' (len=128), node_id=2459565876494606882
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_oVJWUS/client.conf
[CONFIG DEBUG] Successfully opened config file
Client created
[03:30:18-447.936] [WARN] [1] (etcp_api.c:34) etcp_bind() etcp_bind: ID 0 already bound, overwriting
[03:30:18-447.965] [WARN] [1] (etcp_api.c:34) etcp_bind() etcp_bind: ID 0 already bound, overwriting
Callbacks registered for ID=0 (server=0x5a9293de2900, client=0x5a9293de2790)
Sending 100 packets in each direction via etcp_send...
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connection check: client=1, server=1
Connections ready: client=0x5a92b76d1290, server=0x5a92b7716270
Starting forward transfer (client -> server) via etcp_send...
Starting backward transfer (server -> client) via etcp_send...
Backward transfer completed: 100/100 packets in 8.68 ms
=== SUCCESS: Bidirectional transfer via etcp_api completed! ===
Forward (client->server): 100/100 packets in -26337523.18 ms
Backward (server->client): 100/100 packets in 8.68 ms
Total time: 15.85 ms
Cleaning up...
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x5a92b76c8c90
Node ID: 1229782938247303441
UA instance: 0x5a92b76c8490
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x5a92b7716270
ETCP Sockets list: 0x5a92b76ca330
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-622.347] [WARN] [1] (etcp_api.c:56) etcp_unbind() etcp_unbind: ID 0 not bound
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x5a92b76cd420
Node ID: 2459565876494606882
UA instance: 0x5a92b76c8490
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x5a92b76d1290
ETCP Sockets list: 0x5a92b76ce7d0
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-622.405] [WARN] [1] (etcp_api.c:56) etcp_unbind() etcp_unbind: ID 0 not bound
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x5a92b76c8490
Timer Statistics: allocated=281, freed=274, active=7
Socket Statistics: allocated=2, freed=2, active=0
Timer: node=0x5a92b7714f90, expires=1771115418707 ms, cancelled=0
Timer: node=0x5a92b7714f60, expires=1771115418710 ms, cancelled=0
Timer: node=0x5a92b77157d0, expires=1771115418714 ms, cancelled=0
Timer: node=0x5a92b7720ad0, expires=1771115418719 ms, cancelled=0
Timer: node=0x5a92b7722d10, expires=1771115418712 ms, cancelled=0
Timer: node=0x5a92b7714f30, expires=1771115418717 ms, cancelled=0
Active timers in heap: 6
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-622.414] [ERROR] [32] (u_async.c:1007) uasync_destroy() Memory leaks detected before cleanup: timers 281/274, sockets 2/2
[03:30:18-622.418] [ERROR] [1024] (u_async.c:1009) uasync_destroy() Timer leak: allocated=281, freed=274, diff=7
[03:30:18-622.421] [ERROR] [1024] (u_async.c:1012) uasync_destroy() Socket leak: allocated=2, freed=2, diff=0
=== TEST PASSED ===
All 100 packets transmitted in each direction via etcp_api

6
tests/logs/test_etcp_crypto.log
Unescape View File

@ -1,6 +0,0 @@
[03:30:18-138.622] [INFO] [16] (test_etcp_crypto.c:17) main() === ETCP Crypto Test ===
[03:30:18-138.906] [ERROR] [16] (secure_channel.c:211) sc_set_peer_public_key() sc_set_peer_public_key: invalid key
[03:30:18-138.925] [ERROR] [16] (secure_channel.c:211) sc_set_peer_public_key() sc_set_peer_public_key: invalid key
[03:30:18-138.929] [INFO] [16] (test_etcp_crypto.c:54) main() Crypto contexts initialized
[03:30:18-139.803] [INFO] [16] (test_etcp_crypto.c:77) main() Client->Server encryption/decryption: PASSED
[03:30:18-139.813] [INFO] [16] (test_etcp_crypto.c:78) main() ETCP crypto test PASSED

46
tests/logs/test_etcp_minimal.log
Unescape View File

@ -1,46 +0,0 @@
=== Minimal ETCP Traffic Flow Debugging ===
=== Testing Basic Packet Analysis ===
Test packet: 00 00 06 00 01 48 65 6C 6C 6F
Section type: 0x00
Section length: 6
Total packet size: 10
This is a PAYLOAD section
Packet ID: 1
Payload size: 4 bytes
Payload data: 48 65 6C 6C
Payload as text: Hell
=== Testing Multi-Section Packet ===
Multi-section packet: 06 00 02 12 34 01 00 09 02 00 01 56 78 00 02 56 79 00 00 08 00 03 48 65 6C 6C 6F 21
Section 0 at position 0:
Type: 0x06 (TIMESTAMP)
Length: 2 bytes
Timestamp: 4660
Section 1 at position 5:
Type: 0x01 (ACK)
Length: 9 bytes
ACK count: 2
ACK[0]: id=1, ts=22136
ACK[1]: id=2, ts=22137
Section 2 at position 17:
Type: 0x00 (PAYLOAD)
Length: 8 bytes
Packet ID: 3
Payload: Hello!
Total sections parsed: 3
=== Testing Connection Establishment Packets ===
INIT_REQUEST packet:
Node ID: 0x2222222222222222
MTU: 1500
Keepalive: 100
INIT_RESPONSE packet:
Node ID: 0x1111111111111111
MTU: 1500
=== Test completed ===

548
tests/logs/test_etcp_simple_traffic.log
Unescape View File

@ -1,548 +0,0 @@
=== ETCP Simple Traffic Test (Queue-based) ===
[03:30:18-202.523] [TRACE] [32] (test_etcp_simple_traffic.c:361) main() *************1
Function names enabled: YES
===========================
[03:30:18-202.631] [INFO] [256] (utun_instance.c:34) utun_instance_set_tun_init_enabled() TUN initialization disabled
Creating server instance...
[03:30:18-202.658] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-202.719] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
[CONFIG DEBUG] Opening config file: /tmp/utun_test_jUbh3w/server.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='67b705a92b41bcaae105af2d6a17743faa7b26ccebba8b3b9b0af05e9cd1d5fb' (len=64), pub_key='1c55e4ccae7c4470707759086738b10681bf88b81f198cc2ab54a647d1556e17c65e6b1833e0c771e5a39382c03067c388915a4c732191bc130480f20f8e00b9' (len=128), node_id=1229782938247303441
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_jUbh3w/server.conf
[CONFIG DEBUG] Successfully opened config file
[03:30:18-202.864] [INFO] [16] (secure_channel.c:174) sc_init_local_keys() sc_init_local_keys: public_key len=128, private_key len=64
[03:30:18-203.055] [INFO] [16] (secure_channel.c:188) sc_init_local_keys() sc_init_local_keys: keys initialized successfully
[03:30:18-203.087] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 0 to callback 0x62cb2dbbf3d0 for instance 0x62cb67cd54e0
[03:30:18-203.111] [INFO] [512] (routing.c:272) routing_create() Routing module initialized for instance
[03:30:18-203.115] [INFO] [512] (utun_instance.c:91) utun_instance_create() Routing module created
[03:30:18-203.182] [INFO] [256] (utun_instance.c:133) utun_instance_create() TUN initialization disabled - skipping TUN device setup
[03:30:18-203.187] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67cd6830, hash_size=0
[03:30:18-203.210] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 1 to callback 0x62cb2dbbe480 for instance 0x62cb67cd54e0
[03:30:18-203.214] [INFO] [4096] (route_bgp.c:382) route_bgp_init() Route change callback registered
[03:30:18-203.218] [INFO] [4096] (route_bgp.c:385) route_bgp_init() BGP module initialized
[03:30:18-203.244] [INFO] [4096] (utun_instance.c:143) utun_instance_create() BGP module initialized
ℹ️ Server TUN disabled - initializing connections only
[03:30:18-203.249] [TRACE] [4] (etcp_connections.c:809) init_connections()
[03:30:18-203.253] [TRACE] [4] (etcp_connections.c:271) etcp_socket_add()
[03:30:18-203.303] [DEBUG] [8192] (socket_compat.c:97) socket_create_udp() Created UDP socket: 6
[03:30:18-203.344] [INFO] [8] (etcp_connections.c:342) etcp_socket_add() [ETCP] Successfully bound socket to local address, family=2
[03:30:18-203.372] [INFO] [4] (etcp_connections.c:364) etcp_socket_add() Registered ETCP socket with uasync
[03:30:18-203.376] [INFO] [8] (etcp_connections.c:366) etcp_socket_add() [ETCP] Socket 0x62cb67cd64d0 registered and active
[03:30:18-203.402] [INFO] [4] (etcp_connections.c:837) init_connections() Initialized server test on 127.0.0.1:9001 (links: 0)
[03:30:18-203.406] [DEBUG] [4] (etcp_connections.c:844) init_connections() init_connections called, instance=0x62cb67cd54e0, config=0x62cb67cd5db0, clients=(nil), connections_count=0
[03:30:18-203.430] [INFO] [4] (etcp_connections.c:1020) init_connections() Initialized 0 connections
Server connections initialized: sockets=0x62cb67cd64d0, connections=(nil)
✅ Server instance initialized successfully (node_id=1111111111111111)
Server instance ready (node_id=1111111111111111)
Creating client instance...
[CONFIG DEBUG] Opening config file: /tmp/utun_test_jUbh3w/client.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='4813d31d28b7e9829247f488c6be7672f2bdf61b2508333128e386d1759afed2' (len=64), pub_key='c594f33c91f3a2222795c2c110c527bf214ad1009197ce14556cb13df3c461b3c373bed8f205a8dd1fc0c364f90bf471d7c6f5db49564c33e4235d268569ac71' (len=128), node_id=2459565876494606882
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_jUbh3w/client.conf
[CONFIG DEBUG] Successfully opened config file
[03:30:18-203.549] [INFO] [16] (secure_channel.c:174) sc_init_local_keys() sc_init_local_keys: public_key len=128, private_key len=64
[03:30:18-203.643] [INFO] [16] (secure_channel.c:188) sc_init_local_keys() sc_init_local_keys: keys initialized successfully
[03:30:18-203.673] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 0 to callback 0x62cb2dbbf3d0 for instance 0x62cb67cd9490
[03:30:18-203.707] [INFO] [512] (routing.c:272) routing_create() Routing module initialized for instance
[03:30:18-203.711] [INFO] [512] (utun_instance.c:91) utun_instance_create() Routing module created
[03:30:18-203.735] [INFO] [256] (utun_instance.c:133) utun_instance_create() TUN initialization disabled - skipping TUN device setup
[03:30:18-203.739] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67cdaa20, hash_size=0
[03:30:18-203.743] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 1 to callback 0x62cb2dbbe480 for instance 0x62cb67cd9490
[03:30:18-203.765] [INFO] [4096] (route_bgp.c:382) route_bgp_init() Route change callback registered
[03:30:18-203.769] [INFO] [4096] (route_bgp.c:385) route_bgp_init() BGP module initialized
[03:30:18-203.772] [INFO] [4096] (utun_instance.c:143) utun_instance_create() BGP module initialized
ℹ️ Client TUN disabled - initializing connections only
About to call init_connections() for client instance
[03:30:18-203.796] [TRACE] [4] (etcp_connections.c:809) init_connections()
[03:30:18-203.800] [TRACE] [4] (etcp_connections.c:271) etcp_socket_add()
[03:30:18-203.827] [DEBUG] [8192] (socket_compat.c:97) socket_create_udp() Created UDP socket: 7
[03:30:18-203.856] [INFO] [8] (etcp_connections.c:342) etcp_socket_add() [ETCP] Successfully bound socket to local address, family=2
[03:30:18-203.882] [INFO] [4] (etcp_connections.c:364) etcp_socket_add() Registered ETCP socket with uasync
[03:30:18-203.886] [INFO] [8] (etcp_connections.c:366) etcp_socket_add() [ETCP] Socket 0x62cb67cda840 registered and active
[03:30:18-203.909] [INFO] [4] (etcp_connections.c:837) init_connections() Initialized server test on 127.0.0.1:9002 (links: 0)
[03:30:18-203.913] [DEBUG] [4] (etcp_connections.c:844) init_connections() init_connections called, instance=0x62cb67cd9490, config=0x62cb67cda160, clients=0x62cb67cda640, connections_count=0
[03:30:18-203.917] [INFO] [4] (etcp_connections.c:848) init_connections() Client test_client - keepalive=1, links=0x62cb67cda7a0, peer_key_len=128
[03:30:18-203.940] [TRACE] [8] (etcp.c:70) etcp_connection_create()
[03:30:18-203.944] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67cd5330, hash_size=0
[03:30:18-203.967] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67cd6a80, hash_size=0
[03:30:18-203.976] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67cdd300, hash_size=1024
[03:30:18-204.004] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67cdf3a0, hash_size=1024
[03:30:18-204.031] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67ce1440, hash_size=1024
[03:30:18-204.036] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67ce34e0, hash_size=0
[03:30:18-204.060] [DEBUG] [8] (pkt_normalizer.c:35) pn_init() pn_init:[6882→????] init 0x62cb67cd6eb0, mtu=1500
[03:30:18-204.064] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67ce3570, hash_size=0
[03:30:18-204.088] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67ce3600, hash_size=0
[03:30:18-204.092] [DEBUG] [512] (routing.c:297) routing_add_conn() routing_add_conn: deprecated, no action taken
[03:30:18-204.095] [DEBUG] [8] (etcp.c:128) etcp_connection_create() [6882→????] connection initialized. ETCP=0x62cb67cd6eb0 mtu=1500, next_tx_id=1
[03:30:18-204.119] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-204.150] [INFO] [16] (etcp_connections.c:875) init_connections() init_connections: setting peer public key for client test_client
[03:30:18-204.738] [INFO] [16] (etcp_connections.c:880) init_connections() init_connections: successfully set peer public key for client test_client
[03:30:18-204.748] [TRACE] [4] (etcp_connections.c:400) etcp_link_new()
[03:30:18-204.752] [TRACE] [4] (etcp_connections.c:236) etcp_find_free_local_link_id()
[03:30:18-204.756] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-204.760] [TRACE] [4] (etcp_connections.c:186) insert_link()
[03:30:18-204.763] [TRACE] [4] (etcp_connections.c:171) realloc_links()
[03:30:18-204.767] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-204.770] [INFO] [4] (etcp_connections.c:440) etcp_link_new() etcp_link_new: client link, calling etcp_link_send_init
[03:30:18-204.774] [TRACE] [4] (etcp_connections.c:44) etcp_link_send_init()
[03:30:18-204.777] [INFO] [4] (etcp_connections.c:45) etcp_link_send_init() etcp_link_send_init link=0x62cb67cf2780, is_server=0
[03:30:18-204.782] [INFO] [4] (etcp_connections.c:83) etcp_link_send_init() Sending INIT request to link, node_id=2459565876494606882, retry=0
[03:30:18-204.786] [INFO] [8] (etcp_connections.c:90) etcp_link_send_init() [ETCP] INIT sending to 127.0.0.1:9001, link=0x62cb67cf2780
[03:30:18-204.789] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-204.793] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-204.796] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-204.799] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-205.610] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-205.636] [INFO] [4] (etcp_connections.c:929) init_connections() Created link 0x62cb67cf2780 for client test_client, socket=0x62cb67cda840
[03:30:18-205.641] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-205.644] [INFO] [16] (etcp_connections.c:948) init_connections() init_connections: setting peer public key for client test_client
[03:30:18-205.733] [INFO] [16] (etcp_connections.c:953) init_connections() init_connections: successfully set peer public key for client test_client
[03:30:18-205.737] [INFO] [4] (etcp_connections.c:1009) init_connections() Added connection 0x62cb67cd6eb0 to instance, total count: 1
[03:30:18-205.741] [INFO] [4] (etcp_connections.c:1020) init_connections() Initialized 1 connections
init_connections() returned: 0
Client connections initialized: sockets=0x62cb67cda840, connections=0x62cb67cd6eb0, count=1
✅ Client instance initialized successfully (node_id=2222222222222222)
Client instance ready (node_id=2222222222222222)
=== Connection Debug ===
Client connection 0x62cb67cd6eb0: peer_node_id=1
Link 0x62cb67cf2780: initialized=0, is_server=0, remote_addr family=2, conn->fd=7
=== End Debug ===
Starting packet transmission test...
Running event loop...
Waiting 0.5 seconds for instances initialization...
[03:30:18-205.747] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-205.752] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-205.758] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-205.764] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-205.767] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-205.836] [TRACE] [8] (etcp.c:70) etcp_connection_create()
[03:30:18-205.840] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d22420, hash_size=0
[03:30:18-205.843] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d224b0, hash_size=0
[03:30:18-205.851] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d22540, hash_size=1024
[03:30:18-205.857] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d21160, hash_size=1024
[03:30:18-205.864] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d212d0, hash_size=1024
[03:30:18-205.867] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d20ea0, hash_size=0
[03:30:18-205.875] [DEBUG] [8] (pkt_normalizer.c:35) pn_init() pn_init:[3441→????] init 0x62cb67d222b0, mtu=1500
[03:30:18-205.878] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d21950, hash_size=0
[03:30:18-205.881] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x62cb67d219e0, hash_size=0
[03:30:18-205.885] [DEBUG] [512] (routing.c:297) routing_add_conn() routing_add_conn: deprecated, no action taken
[03:30:18-205.888] [DEBUG] [8] (etcp.c:128) etcp_connection_create() [3441→????] connection initialized. ETCP=0x62cb67d222b0 mtu=1500, next_tx_id=1
[03:30:18-205.891] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-205.895] [DEBUG] [4] (etcp_connections.c:626) etcp_connections_read_callback_socket() New connection from 127.0.0.1:9002 peer_id=2459565876494606882 etcp=0x62cb67d222b0
[03:30:18-205.899] [INFO] [4] (etcp_connections.c:631) etcp_connections_read_callback_socket() Added incoming connection 0x62cb67d222b0 to instance, total count: 1
[03:30:18-205.902] [TRACE] [4] (etcp_connections.c:400) etcp_link_new()
[03:30:18-205.905] [TRACE] [4] (etcp_connections.c:236) etcp_find_free_local_link_id()
[03:30:18-205.909] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-205.912] [TRACE] [4] (etcp_connections.c:186) insert_link()
[03:30:18-205.915] [TRACE] [4] (etcp_connections.c:171) realloc_links()
[03:30:18-205.918] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-205.921] [TRACE] [8] (etcp.c:258) etcp_conn_reset()
[03:30:18-205.924] [DEBUG] [4] (etcp_connections.c:670) etcp_connections_read_callback_socket() Sending INIT RESPONSE, link=0x62cb67d215d0, local_link_id=0, remote_link_id=0
[03:30:18-205.928] [INFO] [8] (etcp_connections.c:671) etcp_connections_read_callback_socket() [ETCP DEBUG] Send INIT RESPONSE
[03:30:18-205.931] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-205.934] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-205.937] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-205.940] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-205.945] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-205.956] [INFO] [8] (etcp_loadbalancer.c:156) loadbalancer_link_ready() loadbalancer_link_ready: link=0x62cb67d215d0 now ready, notifying ETCP_CONN
[03:30:18-205.959] [TRACE] [8] (etcp.c:637) etcp_link_ready_callback()
[03:30:18-205.963] [TRACE] [8] (etcp.c:645) etcp_conn_process_send_queue()
[03:30:18-205.966] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-205.969] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-205.972] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-205.975] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [3441→6882] resume callbacks: inflight_bytes=0, input_len=0
[03:30:18-205.979] [INFO] [4096] (route_bgp.c:452) route_bgp_new_conn() Added connection 0x62cb67d222b0 to senders_list
[03:30:18-205.983] [INFO] [4096] (route_bgp.c:338) route_bgp_send_table_to_conn_internal() Sending full routing table (0 routes) to connection
[03:30:18-205.986] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-205.990] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-205.995] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-205.998] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-206.001] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-206.004] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-206.009] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-206.012] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-206.015] [TRACE] [8] (etcp.c:258) etcp_conn_reset()
[03:30:18-206.019] [INFO] [4] (etcp_connections.c:736) etcp_connections_read_callback_socket() [6882→0001] NAT address initialized: 127.0.0.1:9002
[03:30:18-206.025] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-206.028] [INFO] [8] (etcp_loadbalancer.c:156) loadbalancer_link_ready() loadbalancer_link_ready: link=0x62cb67cf2780 now ready, notifying ETCP_CONN
[03:30:18-206.032] [TRACE] [8] (etcp.c:637) etcp_link_ready_callback()
[03:30:18-206.035] [TRACE] [8] (etcp.c:645) etcp_conn_process_send_queue()
[03:30:18-206.038] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-206.041] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-206.044] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-206.047] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [6882→3441] resume callbacks: inflight_bytes=0, input_len=0
[03:30:18-206.051] [INFO] [4096] (route_bgp.c:452) route_bgp_new_conn() Added connection 0x62cb67cd6eb0 to senders_list
[03:30:18-206.054] [INFO] [4096] (route_bgp.c:338) route_bgp_send_table_to_conn_internal() Sending full routing table (0 routes) to connection
[03:30:18-206.057] [INFO] [4] (etcp_connections.c:783) etcp_connections_read_callback_socket() etcp client: Link initialized successfully! Server node_id=1229782938247303441, mtu=0, local_link_id=0, remote_link_id=0
[03:30:18-206.061] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-208.300] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-209.390] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-210.522] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-211.595] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-212.670] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-213.747] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-215.267] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-216.350] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-217.417] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-218.484] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-219.560] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-220.636] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-221.712] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-222.788] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-223.863] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-224.942] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-226.019] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-227.094] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-228.170] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-229.246] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-230.333] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-231.437] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-232.516] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-233.593] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-234.669] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-235.752] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-236.828] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-237.904] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-238.979] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-240.054] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-241.135] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-242.213] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-243.293] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-244.370] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-245.444] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-246.525] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-247.602] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-248.682] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-249.758] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-250.833] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-251.908] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-253.005] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-254.083] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[DEBUG] monitor_and_send: ENTERING (arg=(nil))
[03:30:18-255.174] [TRACE] [8] (test_etcp_simple_traffic.c:274) monitor_and_send() monitor_and_send: ENTERING (arg=(nil))
[DEBUG] is_connection_established: Checking instance 0x62cb67cd54e0
[03:30:18-255.185] [TRACE] [8] (test_etcp_simple_traffic.c:114) is_connection_established() is_connection_established: Checking instance 0x62cb67cd54e0
[DEBUG] is_connection_established: Instance has 1 connections
[03:30:18-255.191] [DEBUG] [8] (test_etcp_simple_traffic.c:123) is_connection_established() is_connection_established: Instance has 1 connections
[DEBUG] is_connection_established: Checking connection 0x62cb67d222b0
[03:30:18-255.197] [DEBUG] [8] (test_etcp_simple_traffic.c:129) is_connection_established() is_connection_established: Checking connection 0x62cb67d222b0
[DEBUG] is_connection_established: Link 0x62cb67d215d0 - initialized=1, is_server=1
[03:30:18-255.202] [DEBUG] [8] (test_etcp_simple_traffic.c:135) is_connection_established() is_connection_established: Link 0x62cb67d215d0 - initialized=1, is_server=1
[DEBUG] is_connection_established: FOUND initialized link!
[03:30:18-255.207] [DEBUG] [8] (test_etcp_simple_traffic.c:140) is_connection_established() is_connection_established: FOUND initialized link!
[DEBUG] is_connection_established: Checking instance 0x62cb67cd9490
[03:30:18-255.212] [TRACE] [8] (test_etcp_simple_traffic.c:114) is_connection_established() is_connection_established: Checking instance 0x62cb67cd9490
[DEBUG] is_connection_established: Instance has 1 connections
[03:30:18-255.217] [DEBUG] [8] (test_etcp_simple_traffic.c:123) is_connection_established() is_connection_established: Instance has 1 connections
[DEBUG] is_connection_established: Checking connection 0x62cb67cd6eb0
[03:30:18-255.223] [DEBUG] [8] (test_etcp_simple_traffic.c:129) is_connection_established() is_connection_established: Checking connection 0x62cb67cd6eb0
[DEBUG] is_connection_established: Link 0x62cb67cf2780 - initialized=1, is_server=0
[03:30:18-255.228] [DEBUG] [8] (test_etcp_simple_traffic.c:135) is_connection_established() is_connection_established: Link 0x62cb67cf2780 - initialized=1, is_server=0
[DEBUG] is_connection_established: FOUND initialized link!
[03:30:18-255.233] [DEBUG] [8] (test_etcp_simple_traffic.c:140) is_connection_established() is_connection_established: FOUND initialized link!
[DEBUG] monitor_and_send: Connection check - server=1, client=1
[03:30:18-255.238] [DEBUG] [8] (test_etcp_simple_traffic.c:289) monitor_and_send() monitor_and_send: Connection check - server=1, client=1
[03:30:18-255.242] [INFO] [8] (test_etcp_simple_traffic.c:294) monitor_and_send() monitor_and_send: Client link initialized, ready to send packet (server=1, client=1)
[DEBUG] send_test_packet: ENTERING
[03:30:18-255.247] [TRACE] [8] (test_etcp_simple_traffic.c:156) send_test_packet() send_test_packet: ENTERING
[DEBUG] send_test_packet: Found connection 0x62cb67cd6eb0
[03:30:18-255.252] [DEBUG] [8] (test_etcp_simple_traffic.c:171) send_test_packet() send_test_packet: Found connection 0x62cb67cd6eb0
[DEBUG] send_test_packet: connection input_queue=0x62cb67cd5330
[03:30:18-255.257] [DEBUG] [8] (test_etcp_simple_traffic.c:174) send_test_packet() send_test_packet: connection input_queue=0x62cb67cd5330
[DEBUG] send_test_packet: connection output_queue=0x62cb67cd6a80
[03:30:18-255.262] [DEBUG] [8] (test_etcp_simple_traffic.c:177) send_test_packet() send_test_packet: connection output_queue=0x62cb67cd6a80
[DEBUG] send_test_packet: connection next_tx_id=1
[03:30:18-255.267] [DEBUG] [8] (test_etcp_simple_traffic.c:180) send_test_packet() send_test_packet: connection next_tx_id=1
[03:30:18-255.271] [DEBUG] [8] (test_etcp_simple_traffic.c:192) send_test_packet() send_test_packet: Created test data, first byte=00, last byte=63
[DEBUG] send_test_packet: Calling etcp_int_send with len=100
[03:30:18-255.276] [DEBUG] [8] (test_etcp_simple_traffic.c:198) send_test_packet() send_test_packet: Calling etcp_int_send with len=100
[03:30:18-255.307] [TRACE] [8] (etcp.c:283) etcp_int_send()
[03:30:18-255.319] [DEBUG] [8] (etcp.c:326) etcp_int_send() [6882→3441] created PACKET 0x62cb67d21ab0 with data 0x62cb67d28c20 (len=100)
[03:30:18-255.325] [TRACE] [8] (etcp.c:403) input_queue_cb()
[03:30:18-255.329] [DEBUG] [8] (etcp.c:434) input_queue_cb() [6882→3441] input -> inflight (seq=1, len=100)
[03:30:18-255.334] [TRACE] [8] (etcp.c:453) input_send_q_cb()
[03:30:18-255.337] [TRACE] [8] (etcp.c:645) etcp_conn_process_send_queue()
[03:30:18-255.341] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-255.346] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.350] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.354] [TRACE] [8] (etcp.c:527) wait_ack_cb()
[03:30:18-255.358] [TRACE] [8] (etcp.c:464) ack_timeout_check()
[03:30:18-255.362] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.366] [DEBUG] [8] (etcp.c:517) ack_timeout_check() [6882→3441] ack_timeout_check: retransmission timer set for 1000 units
[03:30:18-255.370] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-255.374] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.378] [DEBUG] [8] (etcp.c:616) etcp_request_pkt() [6882→3441] add DATA (seq=1, len=100), ack_size=0
[03:30:18-255.382] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-255.386] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-255.390] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.394] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-255.417] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-255.447] [TRACE] [8] (etcp_loadbalancer.c:115) etcp_loadbalancer_send() [6882→3441] unlimited bandwidth, skipping shaper update
[03:30:18-255.452] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-255.456] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.460] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-255.464] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [6882→3441] resume callbacks: inflight_bytes=100, input_len=0
[03:30:18-255.468] [TRACE] [8] (etcp.c:645) etcp_conn_process_send_queue()
[03:30:18-255.472] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-255.476] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.480] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-255.484] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [6882→3441] resume callbacks: inflight_bytes=100, input_len=0
[03:30:18-255.488] [DEBUG] [8] (etcp.c:448) input_queue_cb() [6882→3441] nextloop, input_queue size=0
[DEBUG] send_test_packet: etcp_int_send returned 0
[03:30:18-255.495] [DEBUG] [8] (test_etcp_simple_traffic.c:202) send_test_packet() send_test_packet: etcp_int_send returned 0
[03:30:18-255.500] [INFO] [8] (test_etcp_simple_traffic.c:210) send_test_packet() send_test_packet: SUCCESS - Test packet sent via etcp_int_send (100 bytes)
[03:30:18-255.504] [TRACE] [8] (test_etcp_simple_traffic.c:215) check_packet_received() check_packet_received: ENTERING
[03:30:18-255.508] [DEBUG] [8] (test_etcp_simple_traffic.c:233) check_packet_received() check_packet_received: Checking server connection 0x62cb67d222b0
[03:30:18-255.512] [DEBUG] [8] (test_etcp_simple_traffic.c:234) check_packet_received() check_packet_received: Server output_queue count: 0
[03:30:18-255.516] [TRACE] [8] (test_etcp_simple_traffic.c:266) check_packet_received() check_packet_received: No packet found in output queue
[03:30:18-255.519] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-255.525] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-255.530] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-255.533] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-255.537] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-255.540] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-255.549] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-255.552] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.556] [TRACE] [8] (etcp.c:786) etcp_conn_input()
[03:30:18-255.559] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-255.562] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-255.566] [DEBUG] [8] (etcp.c:830) etcp_conn_input() [3441→6882] set ack_timer for delayed ACK send
[03:30:18-255.569] [DEBUG] [8] (etcp.c:834) etcp_conn_input() [3441→6882] adding packet seq=1 to recv_q (last_delivered_id=0)
[03:30:18-255.573] [DEBUG] [8] (etcp.c:855) etcp_conn_input() [3441→6882] packet seq=1 added to recv_q, calling assembly (last_delivered_id=0)
[03:30:18-255.576] [TRACE] [8] (etcp.c:666) etcp_output_try_assembly()
[03:30:18-255.579] [TRACE] [8] (etcp.c:695) etcp_output_try_assembly() [3441→6882] moved packet id=1 to output_queue
[03:30:18-255.582] [DEBUG] [8] (etcp.c:710) etcp_output_try_assembly() [3441→6882] delivered 1 contiguous packets (100 bytes), last_delivered_id=1, output_queue_count=1
[03:30:18-255.586] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-256.653] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.735] [TRACE] [8] (etcp.c:654) ack_response_timer_cb()
[03:30:18-257.744] [TRACE] [8] (etcp.c:645) etcp_conn_process_send_queue()
[03:30:18-257.747] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-257.751] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-257.754] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-257.757] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [3441→6882] resume callbacks: inflight_bytes=0, input_len=0
[03:30:18-257.760] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-257.763] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-257.767] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-257.770] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-257.773] [DEBUG] [8] (etcp.c:605) etcp_request_pkt() [3441→6882] add ACK N1 dTS=22
[03:30:18-257.776] [DEBUG] [8] (etcp.c:626) etcp_request_pkt() [3441→6882] only ACK packet with 0 bytes total
[03:30:18-257.779] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-257.782] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-257.785] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-257.789] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-257.796] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-257.808] [TRACE] [8] (etcp_loadbalancer.c:115) etcp_loadbalancer_send() [3441→6882] unlimited bandwidth, skipping shaper update
[03:30:18-257.812] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-257.815] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-257.818] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-257.821] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [3441→6882] resume callbacks: inflight_bytes=0, input_len=0
[03:30:18-257.824] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.829] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-257.834] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-257.837] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-257.840] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-257.843] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-257.848] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-257.851] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-257.854] [TRACE] [8] (etcp.c:786) etcp_conn_input()
[03:30:18-257.858] [TRACE] [8] (etcp.c:716) etcp_ack_recv()
[03:30:18-257.861] [TRACE] [8] (etcp.c:61) timestamp_diff()
[03:30:18-257.864] [DEBUG] [8] (etcp.c:770) etcp_ack_recv() [6882→3441] removed packet seq=1 from wait_ack, unacked_bytes now 4294967196 total acked=1
[03:30:18-257.872] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-257.875] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [6882→3441] resume callbacks: inflight_bytes=0, input_len=0
[03:30:18-257.878] [TRACE] [8] (etcp.c:716) etcp_ack_recv()
[03:30:18-257.881] [TRACE] [8] (etcp.c:730) etcp_ack_recv() etcp_ack_recv: packet seq=1 not found in wait_ack queue
Starting connection and packet transmission...
[03:30:18-257.885] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.888] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.892] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.895] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.898] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.902] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.905] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.908] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.911] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.915] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-257.918] [TRACE] [8] (test_etcp_simple_traffic.c:215) check_packet_received() check_packet_received: ENTERING
[03:30:18-257.921] [DEBUG] [8] (test_etcp_simple_traffic.c:233) check_packet_received() check_packet_received: Checking server connection 0x62cb67d222b0
[03:30:18-257.925] [DEBUG] [8] (test_etcp_simple_traffic.c:234) check_packet_received() check_packet_received: Server output_queue count: 1
[03:30:18-257.928] [DEBUG] [8] (test_etcp_simple_traffic.c:242) check_packet_received() check_packet_received: Found packet in output queue
[03:30:18-257.931] [DEBUG] [8] (test_etcp_simple_traffic.c:248) check_packet_received() check_packet_received: Packet size=100, expected=100
[03:30:18-257.934] [DEBUG] [8] (test_etcp_simple_traffic.c:249) check_packet_received() check_packet_received: First byte received=00, expected=00
[03:30:18-257.937] [INFO] [8] (test_etcp_simple_traffic.c:255) check_packet_received() check_packet_received: SUCCESS - Packet received in server output queue (100 bytes), data matches
[TEST] Packet received, exiting early after 50 ms
Cleaning up...
[03:30:18-257.941] [INFO] [32] (utun_instance.c:153) utun_instance_destroy() [INSTANCE_DESTROY] Starting cleanup for instance 0x62cb67cd54e0
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x62cb67cd54e0
Node ID: 1229782938247303441
UA instance: 0x62cb67cd44d0
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x62cb67d222b0
ETCP Sockets list: 0x62cb67cd64d0
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-257.947] [INFO] [32] (utun_instance.c:162) utun_instance_destroy() [INSTANCE_DESTROY] Cleaning up ETCP sockets and connections
[03:30:18-257.950] [INFO] [32] (utun_instance.c:166) utun_instance_destroy() [INSTANCE_DESTROY] Removing socket 0x62cb67cd64d0, fd=6
[03:30:18-257.953] [TRACE] [4] (etcp_connections.c:372) etcp_socket_remove()
[03:30:18-257.957] [INFO] [8] (etcp_connections.c:375) etcp_socket_remove() [ETCP] Removing socket 0x62cb67cd64d0, socket_id=0x62cb67cd4580
[03:30:18-257.960] [INFO] [8] (etcp_connections.c:379) etcp_socket_remove() [ETCP] Removing socket from uasync, instance=0x62cb67cd54e0, ua=0x62cb67cd44d0
[03:30:18-257.966] [INFO] [8] (etcp_connections.c:382) etcp_socket_remove() [ETCP] Unregistered socket from uasync
[03:30:18-257.978] [INFO] [8] (etcp_connections.c:387) etcp_socket_remove() [ETCP] Closed socket
[03:30:18-257.982] [TRACE] [4] (etcp_connections.c:448) etcp_link_close()
[03:30:18-257.988] [TRACE] [4] (etcp_connections.c:210) remove_link()
[03:30:18-257.991] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-257.994] [INFO] [32] (utun_instance.c:171) utun_instance_destroy() [INSTANCE_DESTROY] ETCP sockets cleanup complete
[03:30:18-257.997] [INFO] [32] (utun_instance.c:177) utun_instance_destroy() [INSTANCE_DESTROY] Closing connection 0x62cb67d222b0
[03:30:18-258.000] [TRACE] [8] (etcp.c:136) etcp_connection_close()
[03:30:18-258.003] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-258.007] [INFO] [4096] (route_bgp.c:471) route_bgp_remove_conn() Removing connection 0x62cb67d222b0 from senders_list
[03:30:18-258.010] [INFO] [4096] (route_bgp.c:200) route_bgp_send_withdraw_for_conn() Sending withdraw for routes via conn 0x62cb67d222b0 to all peers
[03:30:18-258.014] [INFO] [4096] (route_bgp.c:484) route_bgp_remove_conn() Connection 0x62cb67d222b0 removed from senders_list
[03:30:18-258.017] [INFO] [512] (route_lib.c:425) route_table_delete() Removed 0 routes for connection 0x62cb67d222b0
[03:30:18-258.021] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-258.024] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d21950, head=(nil), tail=(nil), count=0
[03:30:18-258.028] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d219e0, head=(nil), tail=(nil), count=0
[03:30:18-258.031] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d22420, head=(nil), tail=(nil), count=0
[03:30:18-258.034] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d224b0, head=(nil), tail=(nil), count=0
[03:30:18-258.037] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d22540, head=(nil), tail=(nil), count=0
[03:30:18-258.041] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d21160, head=(nil), tail=(nil), count=0
[03:30:18-258.044] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d20ea0, head=(nil), tail=(nil), count=0
[03:30:18-258.047] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67d212d0, head=(nil), tail=(nil), count=0
[03:30:18-258.051] [INFO] [32] (utun_instance.c:184) utun_instance_destroy() [INSTANCE_DESTROY] ETCP connections cleanup complete
[03:30:18-258.054] [INFO] [512] (routing.c:281) routing_destroy() Destroying routing module
[03:30:18-258.057] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 0 for instance 0x62cb67cd54e0
[03:30:18-258.061] [INFO] [4096] (utun_instance.c:198) utun_instance_destroy() Destroying BGP module
[03:30:18-258.064] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 1 for instance 0x62cb67cd54e0
[03:30:18-258.067] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67cd6830, head=(nil), tail=(nil), count=0
[03:30:18-258.070] [INFO] [4096] (route_bgp.c:418) route_bgp_destroy() BGP module destroyed
[03:30:18-258.074] [INFO] [32] (utun_instance.c:205) utun_instance_destroy() [INSTANCE_DESTROY] Freeing configuration
[03:30:18-258.077] [INFO] [32] (utun_instance.c:212) utun_instance_destroy() [INSTANCE_DESTROY] Destroying packet pool
[03:30:18-258.080] [INFO] [32] (utun_instance.c:219) utun_instance_destroy() [INSTANCE_DESTROY] Destroying ack pool
[03:30:18-258.083] [INFO] [32] (utun_instance.c:226) utun_instance_destroy() [INSTANCE_DESTROY] Destroying data pool
[03:30:18-258.086] [INFO] [32] (utun_instance.c:241) utun_instance_destroy() [INSTANCE_DESTROY] Freeing instance memory
[03:30:18-258.090] [INFO] [32] (utun_instance.c:243) utun_instance_destroy() [INSTANCE_DESTROY] Instance destroyed completely
[03:30:18-258.093] [INFO] [32] (utun_instance.c:153) utun_instance_destroy() [INSTANCE_DESTROY] Starting cleanup for instance 0x62cb67cd9490
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x62cb67cd9490
Node ID: 2459565876494606882
UA instance: 0x62cb67cd44d0
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x62cb67cd6eb0
ETCP Sockets list: 0x62cb67cda840
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-258.097] [INFO] [32] (utun_instance.c:162) utun_instance_destroy() [INSTANCE_DESTROY] Cleaning up ETCP sockets and connections
[03:30:18-258.103] [INFO] [32] (utun_instance.c:166) utun_instance_destroy() [INSTANCE_DESTROY] Removing socket 0x62cb67cda840, fd=7
[03:30:18-258.106] [TRACE] [4] (etcp_connections.c:372) etcp_socket_remove()
[03:30:18-258.109] [INFO] [8] (etcp_connections.c:375) etcp_socket_remove() [ETCP] Removing socket 0x62cb67cda840, socket_id=0x62cb67cd45c8
[03:30:18-258.112] [INFO] [8] (etcp_connections.c:379) etcp_socket_remove() [ETCP] Removing socket from uasync, instance=0x62cb67cd9490, ua=0x62cb67cd44d0
[03:30:18-258.116] [INFO] [8] (etcp_connections.c:382) etcp_socket_remove() [ETCP] Unregistered socket from uasync
[03:30:18-258.122] [INFO] [8] (etcp_connections.c:387) etcp_socket_remove() [ETCP] Closed socket
[03:30:18-258.125] [TRACE] [4] (etcp_connections.c:448) etcp_link_close()
[03:30:18-258.128] [TRACE] [4] (etcp_connections.c:210) remove_link()
[03:30:18-258.131] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-258.134] [INFO] [32] (utun_instance.c:171) utun_instance_destroy() [INSTANCE_DESTROY] ETCP sockets cleanup complete
[03:30:18-258.137] [INFO] [32] (utun_instance.c:177) utun_instance_destroy() [INSTANCE_DESTROY] Closing connection 0x62cb67cd6eb0
[03:30:18-258.140] [TRACE] [8] (etcp.c:136) etcp_connection_close()
[03:30:18-258.144] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-258.147] [INFO] [4096] (route_bgp.c:471) route_bgp_remove_conn() Removing connection 0x62cb67cd6eb0 from senders_list
[03:30:18-258.150] [INFO] [4096] (route_bgp.c:200) route_bgp_send_withdraw_for_conn() Sending withdraw for routes via conn 0x62cb67cd6eb0 to all peers
[03:30:18-258.153] [INFO] [4096] (route_bgp.c:484) route_bgp_remove_conn() Connection 0x62cb67cd6eb0 removed from senders_list
[03:30:18-258.156] [INFO] [512] (route_lib.c:425) route_table_delete() Removed 0 routes for connection 0x62cb67cd6eb0
[03:30:18-258.159] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-258.163] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67ce3570, head=(nil), tail=(nil), count=0
[03:30:18-258.166] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67ce3600, head=(nil), tail=(nil), count=0
[03:30:18-258.169] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67cd5330, head=(nil), tail=(nil), count=0
[03:30:18-258.172] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67cd6a80, head=(nil), tail=(nil), count=0
[03:30:18-258.176] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67cdd300, head=(nil), tail=(nil), count=0
[03:30:18-258.179] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67cdf3a0, head=(nil), tail=(nil), count=0
[03:30:18-258.182] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67ce34e0, head=(nil), tail=(nil), count=0
[03:30:18-258.186] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67ce1440, head=(nil), tail=(nil), count=0
[03:30:18-258.189] [INFO] [32] (utun_instance.c:184) utun_instance_destroy() [INSTANCE_DESTROY] ETCP connections cleanup complete
[03:30:18-258.192] [INFO] [512] (routing.c:281) routing_destroy() Destroying routing module
[03:30:18-258.198] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 0 for instance 0x62cb67cd9490
[03:30:18-258.201] [INFO] [4096] (utun_instance.c:198) utun_instance_destroy() Destroying BGP module
[03:30:18-258.604] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 1 for instance 0x62cb67cd9490
[03:30:18-258.610] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x62cb67cdaa20, head=(nil), tail=(nil), count=0
[03:30:18-258.613] [INFO] [4096] (route_bgp.c:418) route_bgp_destroy() BGP module destroyed
[03:30:18-258.617] [INFO] [32] (utun_instance.c:205) utun_instance_destroy() [INSTANCE_DESTROY] Freeing configuration
[03:30:18-258.620] [INFO] [32] (utun_instance.c:212) utun_instance_destroy() [INSTANCE_DESTROY] Destroying packet pool
[03:30:18-258.624] [INFO] [32] (utun_instance.c:219) utun_instance_destroy() [INSTANCE_DESTROY] Destroying ack pool
[03:30:18-258.627] [INFO] [32] (utun_instance.c:226) utun_instance_destroy() [INSTANCE_DESTROY] Destroying data pool
[03:30:18-258.630] [INFO] [32] (utun_instance.c:241) utun_instance_destroy() [INSTANCE_DESTROY] Freeing instance memory
[03:30:18-258.634] [INFO] [32] (utun_instance.c:243) utun_instance_destroy() [INSTANCE_DESTROY] Instance destroyed completely
[03:30:18-258.637] [DEBUG] [1024] (u_async.c:1000) uasync_destroy() uasync_destroy: starting cleanup for ua=0x62cb67cd44d0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x62cb67cd44d0
Timer Statistics: allocated=6, freed=3, active=3
Socket Statistics: allocated=2, freed=2, active=0
Timer: node=0x62cb67d22220, expires=1771115418356 ms, cancelled=0
Active timers in heap: 1
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-258.641] [ERROR] [32] (u_async.c:1007) uasync_destroy() Memory leaks detected before cleanup: timers 6/3, sockets 2/2
[03:30:18-258.645] [ERROR] [1024] (u_async.c:1009) uasync_destroy() Timer leak: allocated=6, freed=3, diff=3
[03:30:18-258.648] [ERROR] [1024] (u_async.c:1012) uasync_destroy() Socket leak: allocated=2, freed=2, diff=0
[03:30:18-258.651] [DEBUG] [32] (u_async.c:1048) uasync_destroy() Freed 0 socket nodes in destroy
[03:30:18-258.666] [DEBUG] [1024] (u_async.c:1081) uasync_destroy() uasync_destroy: completed successfully for ua=0x62cb67cd44d0
[03:30:18-258.669] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
=== TEST PASSED ===
✅ Packet successfully transmitted from client input queue to server output queue
✅ ETCP connection and queue mechanisms verified

528
tests/logs/test_etcp_two_instances.log
Unescape View File

@ -1,528 +0,0 @@
[03:30:18-142.174] [INFO] [8] (test_etcp_two_instances.c:253) main() === ETCP Two-Instance Connection Test ===
[03:30:18-142.196] [INFO] [256] (utun_instance.c:34) utun_instance_set_tun_init_enabled() TUN initialization disabled
[03:30:18-142.201] [INFO] [8] (test_etcp_two_instances.c:259) main() Creating server instance...
[03:30:18-142.205] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-142.223] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
[CONFIG DEBUG] Opening config file: /tmp/utun_test_ysqaNQ/server.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='67b705a92b41bcaae105af2d6a17743faa7b26ccebba8b3b9b0af05e9cd1d5fb' (len=64), pub_key='1c55e4ccae7c4470707759086738b10681bf88b81f198cc2ab54a647d1556e17c65e6b1833e0c771e5a39382c03067c388915a4c732191bc130480f20f8e00b9' (len=128), node_id=1229782938247303441
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_ysqaNQ/server.conf
[CONFIG DEBUG] Successfully opened config file
[03:30:18-142.264] [INFO] [16] (secure_channel.c:174) sc_init_local_keys() sc_init_local_keys: public_key len=128, private_key len=64
[03:30:18-142.329] [INFO] [16] (secure_channel.c:188) sc_init_local_keys() sc_init_local_keys: keys initialized successfully
[03:30:18-142.340] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 0 to callback 0x596e8f45b110 for instance 0x596ec7b6f4e0
[03:30:18-142.344] [INFO] [512] (routing.c:272) routing_create() Routing module initialized for instance
[03:30:18-142.347] [INFO] [512] (utun_instance.c:91) utun_instance_create() Routing module created
[03:30:18-142.351] [INFO] [256] (utun_instance.c:133) utun_instance_create() TUN initialization disabled - skipping TUN device setup
[03:30:18-142.354] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b70830, hash_size=0
[03:30:18-142.358] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 1 to callback 0x596e8f45a1c0 for instance 0x596ec7b6f4e0
[03:30:18-142.361] [INFO] [4096] (route_bgp.c:382) route_bgp_init() Route change callback registered
[03:30:18-142.365] [INFO] [4096] (route_bgp.c:385) route_bgp_init() BGP module initialized
[03:30:18-142.368] [INFO] [4096] (utun_instance.c:143) utun_instance_create() BGP module initialized
[03:30:18-142.371] [TRACE] [4] (etcp_connections.c:809) init_connections()
[03:30:18-142.375] [TRACE] [4] (etcp_connections.c:271) etcp_socket_add()
[03:30:18-142.387] [DEBUG] [8192] (socket_compat.c:97) socket_create_udp() Created UDP socket: 6
[03:30:18-142.401] [INFO] [8] (etcp_connections.c:342) etcp_socket_add() [ETCP] Successfully bound socket to local address, family=2
[03:30:18-142.407] [INFO] [4] (etcp_connections.c:364) etcp_socket_add() Registered ETCP socket with uasync
[03:30:18-142.411] [INFO] [8] (etcp_connections.c:366) etcp_socket_add() [ETCP] Socket 0x596ec7b704d0 registered and active
[03:30:18-142.415] [INFO] [4] (etcp_connections.c:837) init_connections() Initialized server test on 127.0.0.1:9011 (links: 0)
[03:30:18-142.418] [DEBUG] [4] (etcp_connections.c:844) init_connections() init_connections called, instance=0x596ec7b6f4e0, config=0x596ec7b6fdb0, clients=(nil), connections_count=0
[03:30:18-142.422] [INFO] [4] (etcp_connections.c:1020) init_connections() Initialized 0 connections
DEBUG: utun_instance_init() calling init_connections() for instance 0x596ec7b6f4e0
[03:30:18-142.427] [TRACE] [4] (etcp_connections.c:809) init_connections()
[03:30:18-142.430] [TRACE] [4] (etcp_connections.c:271) etcp_socket_add()
[03:30:18-142.436] [DEBUG] [8192] (socket_compat.c:97) socket_create_udp() Created UDP socket: 7
[03:30:18-142.443] [ERROR] [8] (etcp_connections.c:329) etcp_socket_add() [ETCP] Failed to bind socket to address family 2: Address already in use
[03:30:18-142.447] [ERROR] [8] (etcp_connections.c:335) etcp_socket_add() [ETCP] Failed to bind to 127.0.0.1:9011
[03:30:18-142.457] [ERROR] [8] (etcp_connections.c:820) init_connections() Failed to create socket for server test
[03:30:18-142.466] [DEBUG] [4] (etcp_connections.c:844) init_connections() init_connections called, instance=0x596ec7b6f4e0, config=0x596ec7b6fdb0, clients=(nil), connections_count=0
[03:30:18-142.470] [INFO] [4] (etcp_connections.c:1020) init_connections() Initialized 0 connections
DEBUG: init_connections() returned: 0
DEBUG: Connections initialized successfully, count=0
[03:30:18-142.475] [INFO] [8] (test_etcp_two_instances.c:280) main() Server instance ready (node_id=1111111111111111)
[03:30:18-142.478] [INFO] [8] (test_etcp_two_instances.c:283) main() Creating client instance...
[CONFIG DEBUG] Opening config file: /tmp/utun_test_ysqaNQ/client.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='4813d31d28b7e9829247f488c6be7672f2bdf61b2508333128e386d1759afed2' (len=64), pub_key='c594f33c91f3a2222795c2c110c527bf214ad1009197ce14556cb13df3c461b3c373bed8f205a8dd1fc0c364f90bf471d7c6f5db49564c33e4235d268569ac71' (len=128), node_id=2459565876494606882
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_ysqaNQ/client.conf
[CONFIG DEBUG] Successfully opened config file
[03:30:18-142.507] [INFO] [16] (secure_channel.c:174) sc_init_local_keys() sc_init_local_keys: public_key len=128, private_key len=64
[03:30:18-142.531] [INFO] [16] (secure_channel.c:188) sc_init_local_keys() sc_init_local_keys: keys initialized successfully
[03:30:18-142.537] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 0 to callback 0x596e8f45b110 for instance 0x596ec7b73560
[03:30:18-142.541] [INFO] [512] (routing.c:272) routing_create() Routing module initialized for instance
[03:30:18-142.544] [INFO] [512] (utun_instance.c:91) utun_instance_create() Routing module created
[03:30:18-142.548] [INFO] [256] (utun_instance.c:133) utun_instance_create() TUN initialization disabled - skipping TUN device setup
[03:30:18-142.551] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b74af0, hash_size=0
[03:30:18-142.554] [INFO] [1] (etcp_api.c:39) etcp_bind() etcp_bind: Bound ID 1 to callback 0x596e8f45a1c0 for instance 0x596ec7b73560
[03:30:18-142.558] [INFO] [4096] (route_bgp.c:382) route_bgp_init() Route change callback registered
[03:30:18-142.561] [INFO] [4096] (route_bgp.c:385) route_bgp_init() BGP module initialized
[03:30:18-142.564] [INFO] [4096] (utun_instance.c:143) utun_instance_create() BGP module initialized
[03:30:18-142.567] [TRACE] [4] (etcp_connections.c:809) init_connections()
[03:30:18-142.570] [TRACE] [4] (etcp_connections.c:271) etcp_socket_add()
[03:30:18-142.577] [DEBUG] [8192] (socket_compat.c:97) socket_create_udp() Created UDP socket: 7
[03:30:18-142.584] [INFO] [8] (etcp_connections.c:342) etcp_socket_add() [ETCP] Successfully bound socket to local address, family=2
[03:30:18-142.589] [INFO] [4] (etcp_connections.c:364) etcp_socket_add() Registered ETCP socket with uasync
[03:30:18-142.593] [INFO] [8] (etcp_connections.c:366) etcp_socket_add() [ETCP] Socket 0x596ec7b74910 registered and active
[03:30:18-142.596] [INFO] [4] (etcp_connections.c:837) init_connections() Initialized server test on 127.0.0.1:9012 (links: 0)
[03:30:18-142.599] [DEBUG] [4] (etcp_connections.c:844) init_connections() init_connections called, instance=0x596ec7b73560, config=0x596ec7b74230, clients=0x596ec7b74710, connections_count=0
[03:30:18-142.603] [INFO] [4] (etcp_connections.c:848) init_connections() Client test_client - keepalive=1, links=0x596ec7b74870, peer_key_len=128
[03:30:18-142.606] [TRACE] [8] (etcp.c:70) etcp_connection_create()
[03:30:18-142.610] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b6e320, hash_size=0
[03:30:18-142.613] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b70a80, hash_size=0
[03:30:18-142.621] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b773d0, hash_size=1024
[03:30:18-142.627] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b79470, hash_size=1024
[03:30:18-142.637] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b7b510, hash_size=1024
[03:30:18-142.641] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b7d5b0, hash_size=0
[03:30:18-142.644] [DEBUG] [8] (pkt_normalizer.c:35) pn_init() pn_init:[6882→????] init 0x596ec7b70eb0, mtu=1500
[03:30:18-142.648] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b7d640, hash_size=0
[03:30:18-142.651] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7b7d6d0, hash_size=0
[03:30:18-142.655] [DEBUG] [512] (routing.c:297) routing_add_conn() routing_add_conn: deprecated, no action taken
[03:30:18-142.658] [DEBUG] [8] (etcp.c:128) etcp_connection_create() [6882→????] connection initialized. ETCP=0x596ec7b70eb0 mtu=1500, next_tx_id=1
[03:30:18-142.662] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-142.665] [INFO] [16] (etcp_connections.c:875) init_connections() init_connections: setting peer public key for client test_client
[03:30:18-143.051] [INFO] [16] (etcp_connections.c:880) init_connections() init_connections: successfully set peer public key for client test_client
[03:30:18-143.058] [TRACE] [4] (etcp_connections.c:400) etcp_link_new()
[03:30:18-143.061] [TRACE] [4] (etcp_connections.c:236) etcp_find_free_local_link_id()
[03:30:18-143.065] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-143.069] [TRACE] [4] (etcp_connections.c:186) insert_link()
[03:30:18-143.072] [TRACE] [4] (etcp_connections.c:171) realloc_links()
[03:30:18-143.075] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-143.079] [INFO] [4] (etcp_connections.c:440) etcp_link_new() etcp_link_new: client link, calling etcp_link_send_init
[03:30:18-143.082] [TRACE] [4] (etcp_connections.c:44) etcp_link_send_init()
[03:30:18-143.085] [INFO] [4] (etcp_connections.c:45) etcp_link_send_init() etcp_link_send_init link=0x596ec7b8c850, is_server=0
[03:30:18-143.090] [INFO] [4] (etcp_connections.c:83) etcp_link_send_init() Sending INIT request to link, node_id=2459565876494606882, retry=0
[03:30:18-143.093] [INFO] [8] (etcp_connections.c:90) etcp_link_send_init() [ETCP] INIT sending to 127.0.0.1:9011, link=0x596ec7b8c850
[03:30:18-143.097] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-143.100] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-143.103] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-143.107] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-143.848] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-143.879] [INFO] [4] (etcp_connections.c:929) init_connections() Created link 0x596ec7b8c850 for client test_client, socket=0x596ec7b74910
[03:30:18-143.884] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-143.888] [INFO] [16] (etcp_connections.c:948) init_connections() init_connections: setting peer public key for client test_client
[03:30:18-143.966] [INFO] [16] (etcp_connections.c:953) init_connections() init_connections: successfully set peer public key for client test_client
[03:30:18-143.970] [INFO] [4] (etcp_connections.c:1009) init_connections() Added connection 0x596ec7b70eb0 to instance, total count: 1
[03:30:18-143.973] [INFO] [4] (etcp_connections.c:1020) init_connections() Initialized 1 connections
DEBUG: utun_instance_init() calling init_connections() for instance 0x596ec7b73560
[03:30:18-143.978] [TRACE] [4] (etcp_connections.c:809) init_connections()
[03:30:18-143.981] [TRACE] [4] (etcp_connections.c:271) etcp_socket_add()
[03:30:18-143.990] [DEBUG] [8192] (socket_compat.c:97) socket_create_udp() Created UDP socket: 8
[03:30:18-143.998] [ERROR] [8] (etcp_connections.c:329) etcp_socket_add() [ETCP] Failed to bind socket to address family 2: Address already in use
[03:30:18-144.002] [ERROR] [8] (etcp_connections.c:335) etcp_socket_add() [ETCP] Failed to bind to 127.0.0.1:9012
[03:30:18-144.010] [ERROR] [8] (etcp_connections.c:820) init_connections() Failed to create socket for server test
[03:30:18-144.017] [DEBUG] [4] (etcp_connections.c:844) init_connections() init_connections called, instance=0x596ec7b73560, config=0x596ec7b74230, clients=0x596ec7b74710, connections_count=1
[03:30:18-144.021] [INFO] [4] (etcp_connections.c:848) init_connections() Client test_client - keepalive=1, links=0x596ec7b74870, peer_key_len=128
[03:30:18-144.024] [TRACE] [8] (etcp.c:70) etcp_connection_create()
[03:30:18-144.028] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbbe20, hash_size=0
[03:30:18-144.031] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbbeb0, hash_size=0
[03:30:18-144.037] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbbf40, hash_size=1024
[03:30:18-144.044] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbb150, hash_size=1024
[03:30:18-144.051] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbadc0, hash_size=1024
[03:30:18-144.054] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbb4e0, hash_size=0
[03:30:18-144.058] [DEBUG] [8] (pkt_normalizer.c:35) pn_init() pn_init:[6882→????] init 0x596ec7bbbcb0, mtu=1500
[03:30:18-144.062] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbb710, hash_size=0
[03:30:18-144.065] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbb300, hash_size=0
[03:30:18-144.068] [DEBUG] [512] (routing.c:297) routing_add_conn() routing_add_conn: deprecated, no action taken
[03:30:18-144.071] [DEBUG] [8] (etcp.c:128) etcp_connection_create() [6882→????] connection initialized. ETCP=0x596ec7bbbcb0 mtu=1500, next_tx_id=1
[03:30:18-144.075] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-144.079] [INFO] [16] (etcp_connections.c:875) init_connections() init_connections: setting peer public key for client test_client
[03:30:18-144.150] [INFO] [16] (etcp_connections.c:880) init_connections() init_connections: successfully set peer public key for client test_client
[03:30:18-144.154] [TRACE] [4] (etcp_connections.c:400) etcp_link_new()
[03:30:18-144.157] [TRACE] [4] (etcp_connections.c:236) etcp_find_free_local_link_id()
[03:30:18-144.161] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-144.164] [TRACE] [4] (etcp_connections.c:186) insert_link()
[03:30:18-144.167] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-144.171] [INFO] [4] (etcp_connections.c:440) etcp_link_new() etcp_link_new: client link, calling etcp_link_send_init
[03:30:18-144.174] [TRACE] [4] (etcp_connections.c:44) etcp_link_send_init()
[03:30:18-144.177] [INFO] [4] (etcp_connections.c:45) etcp_link_send_init() etcp_link_send_init link=0x596ec7bc2520, is_server=0
[03:30:18-144.181] [INFO] [4] (etcp_connections.c:83) etcp_link_send_init() Sending INIT request to link, node_id=2459565876494606882, retry=0
[03:30:18-144.185] [INFO] [8] (etcp_connections.c:90) etcp_link_send_init() [ETCP] INIT sending to 127.0.0.1:9011, link=0x596ec7bc2520
[03:30:18-144.188] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-144.191] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-144.195] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-144.198] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-144.204] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-144.215] [INFO] [4] (etcp_connections.c:929) init_connections() Created link 0x596ec7bc2520 for client test_client, socket=0x596ec7b74910
[03:30:18-144.218] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-144.222] [INFO] [16] (etcp_connections.c:948) init_connections() init_connections: setting peer public key for client test_client
[03:30:18-144.343] [INFO] [16] (etcp_connections.c:953) init_connections() init_connections: successfully set peer public key for client test_client
[03:30:18-144.351] [INFO] [4] (etcp_connections.c:1009) init_connections() Added connection 0x596ec7bbbcb0 to instance, total count: 2
[03:30:18-144.354] [INFO] [4] (etcp_connections.c:1020) init_connections() Initialized 2 connections
DEBUG: init_connections() returned: 0
DEBUG: Connections initialized successfully, count=2
[03:30:18-144.364] [INFO] [8] (test_etcp_two_instances.c:306) main() Client instance ready (node_id=2222222222222222)
[03:30:18-144.369] [INFO] [8] (test_etcp_two_instances.c:315) main() [TEST] Client socket bound to port 9012 (expected NAT port)
[03:30:18-144.372] [INFO] [8] (test_etcp_two_instances.c:321) main() Starting connection monitoring...
[03:30:18-144.375] [INFO] [8] (test_etcp_two_instances.c:326) main() Running event loop...
[03:30:18-144.378] [INFO] [8] (test_etcp_two_instances.c:329) main() Waiting 0.5 seconds for server initialization...
[03:30:18-144.381] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-144.386] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-144.392] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-144.395] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-144.398] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-144.472] [TRACE] [8] (etcp.c:70) etcp_connection_create()
[03:30:18-144.476] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bc2e80, hash_size=0
[03:30:18-144.479] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bc2f10, hash_size=0
[03:30:18-144.487] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bc2fa0, hash_size=1024
[03:30:18-144.497] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbb9f0, hash_size=1024
[03:30:18-144.504] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bc2400, hash_size=1024
[03:30:18-144.507] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bbb390, hash_size=0
[03:30:18-144.511] [DEBUG] [8] (pkt_normalizer.c:35) pn_init() pn_init:[3441→????] init 0x596ec7bc2d10, mtu=1500
[03:30:18-144.514] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bc2120, hash_size=0
[03:30:18-144.518] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x596ec7bc21b0, hash_size=0
[03:30:18-144.521] [DEBUG] [512] (routing.c:297) routing_add_conn() routing_add_conn: deprecated, no action taken
[03:30:18-144.524] [DEBUG] [8] (etcp.c:128) etcp_connection_create() [3441→????] connection initialized. ETCP=0x596ec7bc2d10 mtu=1500, next_tx_id=1
[03:30:18-144.527] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-144.531] [DEBUG] [4] (etcp_connections.c:626) etcp_connections_read_callback_socket() New connection from 127.0.0.1:9012 peer_id=2459565876494606882 etcp=0x596ec7bc2d10
[03:30:18-144.535] [INFO] [4] (etcp_connections.c:631) etcp_connections_read_callback_socket() Added incoming connection 0x596ec7bc2d10 to instance, total count: 1
[03:30:18-144.538] [TRACE] [4] (etcp_connections.c:400) etcp_link_new()
[03:30:18-144.542] [TRACE] [4] (etcp_connections.c:236) etcp_find_free_local_link_id()
[03:30:18-144.545] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-144.548] [TRACE] [4] (etcp_connections.c:186) insert_link()
[03:30:18-144.551] [TRACE] [4] (etcp_connections.c:171) realloc_links()
[03:30:18-144.554] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-144.557] [TRACE] [8] (etcp.c:258) etcp_conn_reset()
[03:30:18-144.561] [DEBUG] [4] (etcp_connections.c:670) etcp_connections_read_callback_socket() Sending INIT RESPONSE, link=0x596ec7bc9060, local_link_id=0, remote_link_id=0
[03:30:18-144.564] [INFO] [8] (etcp_connections.c:671) etcp_connections_read_callback_socket() [ETCP DEBUG] Send INIT RESPONSE
[03:30:18-144.567] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-144.572] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-144.575] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-144.579] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-144.584] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-144.598] [INFO] [8] (etcp_loadbalancer.c:156) loadbalancer_link_ready() loadbalancer_link_ready: link=0x596ec7bc9060 now ready, notifying ETCP_CONN
[03:30:18-144.602] [TRACE] [8] (etcp.c:637) etcp_link_ready_callback()
[03:30:18-144.605] [TRACE] [8] (etcp.c:645) etcp_conn_process_send_queue()
[03:30:18-144.608] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-144.611] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-144.615] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-144.618] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [3441→6882] resume callbacks: inflight_bytes=0, input_len=0
[03:30:18-144.622] [INFO] [4096] (route_bgp.c:452) route_bgp_new_conn() Added connection 0x596ec7bc2d10 to senders_list
[03:30:18-144.625] [INFO] [4096] (route_bgp.c:338) route_bgp_send_table_to_conn_internal() Sending full routing table (0 routes) to connection
[03:30:18-144.629] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-144.633] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-144.637] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-144.640] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-144.644] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-144.647] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-144.655] [ERROR] [16] (etcp_connections.c:689) etcp_connections_read_callback_socket() etcp_connections_read_callback: failed to decrypt packet from node 1229782938247303441 len=105
[03:30:18-144.659] [ERROR] [8] (etcp_connections.c:801) etcp_connections_read_callback_socket() etcp_connections_read_callback: error 6
[03:30:18-144.662] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-144.666] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-144.670] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-144.673] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-144.676] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-144.680] [INFO] [8] (etcp_connections.c:696) etcp_connections_read_callback_socket() Decrypt end
[03:30:18-144.683] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-144.696] [TRACE] [8] (etcp.c:258) etcp_conn_reset()
[03:30:18-144.701] [INFO] [4] (etcp_connections.c:736) etcp_connections_read_callback_socket() [6882→0001] NAT address initialized: 127.0.0.1:9012
[03:30:18-144.705] [TRACE] [8] (etcp.c:268) etcp_update_log_name()
[03:30:18-144.708] [INFO] [8] (etcp_loadbalancer.c:156) loadbalancer_link_ready() loadbalancer_link_ready: link=0x596ec7b8c850 now ready, notifying ETCP_CONN
[03:30:18-144.711] [TRACE] [8] (etcp.c:637) etcp_link_ready_callback()
[03:30:18-144.715] [TRACE] [8] (etcp.c:645) etcp_conn_process_send_queue()
[03:30:18-144.718] [TRACE] [8] (etcp.c:535) etcp_request_pkt()
[03:30:18-144.721] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-144.724] [TRACE] [8] (etcp.c:342) input_queue_try_resume()
[03:30:18-144.727] [DEBUG] [8] (etcp.c:350) input_queue_try_resume() [6882→3441] resume callbacks: inflight_bytes=0, input_len=0
[03:30:18-144.731] [INFO] [4096] (route_bgp.c:452) route_bgp_new_conn() Added connection 0x596ec7b70eb0 to senders_list
[03:30:18-144.734] [INFO] [4096] (route_bgp.c:338) route_bgp_send_table_to_conn_internal() Sending full routing table (0 routes) to connection
[03:30:18-144.737] [INFO] [4] (etcp_connections.c:783) etcp_connections_read_callback_socket() etcp client: Link initialized successfully! Server node_id=1229782938247303441, mtu=0, local_link_id=0, remote_link_id=0
[03:30:18-144.741] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-145.806] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-146.876] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-147.946] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-149.034] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-150.116] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-151.183] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-152.251] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-153.313] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-154.391] [INFO] [8] (test_etcp_two_instances.c:129) monitor_connections() [SERVER] Link: peer=2222222222222222 initialized=1 type=server
[03:30:18-154.401] [INFO] [8] (test_etcp_two_instances.c:147) monitor_connections() [CLIENT] Link: peer=1 initialized=0 timer=active retry=1
[03:30:18-154.406] [INFO] [8] (test_etcp_two_instances.c:147) monitor_connections() [CLIENT] Link: peer=1111111111111111 initialized=1 timer=null retry=1
[03:30:18-154.411] [INFO] [8] (test_etcp_two_instances.c:156) monitor_connections() [CLIENT] Checking NAT fields...
[03:30:18-154.416] [INFO] [8] (test_etcp_two_instances.c:174) monitor_connections() [CLIENT] PASS: NAT address is set: 127.0.0.1:9012
[03:30:18-154.420] [INFO] [8] (test_etcp_two_instances.c:176) monitor_connections() [CLIENT] PASS: nat_changes_count=0, nat_hits_count=0
[03:30:18-154.424] [INFO] [8] (test_etcp_two_instances.c:196) monitor_connections() [CLIENT] PASS: NAT IP and port match exactly (127.0.0.1:9012)
[03:30:18-154.428] [INFO] [8] (test_etcp_two_instances.c:208) monitor_connections()
=== SUCCESS: Client connection established! ===
[03:30:18-154.432] [INFO] [8] (test_etcp_two_instances.c:212) monitor_connections() [TEST] Cancelling test timeout for immediate exit
[03:30:18-154.436] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-155.505] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-156.579] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-157.652] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-158.723] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-159.797] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-160.870] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-161.947] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-163.089] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-164.168] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-165.254] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-166.299] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-167.596] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-168.668] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-169.738] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-170.813] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-171.886] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-172.958] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-176.297] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-177.371] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-178.438] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-179.504] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-180.571] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-181.640] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-182.711] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-183.784] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-184.853] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-185.922] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-186.989] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-188.059] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-189.127] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-190.194] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-191.262] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-192.299] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-193.370] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-194.440] [TRACE] [4] (etcp_connections.c:112) etcp_link_init_timer_cbk()
[03:30:18-194.451] [TRACE] [4] (etcp_connections.c:44) etcp_link_send_init()
[03:30:18-194.465] [INFO] [4] (etcp_connections.c:45) etcp_link_send_init() etcp_link_send_init link=0x596ec7bc2520, is_server=0
[03:30:18-194.471] [INFO] [4] (etcp_connections.c:83) etcp_link_send_init() Sending INIT request to link, node_id=2459565876494606882, retry=1
[03:30:18-194.476] [INFO] [8] (etcp_connections.c:90) etcp_link_send_init() [ETCP] INIT sending to 127.0.0.1:9011, link=0x596ec7bc2520
[03:30:18-194.479] [TRACE] [4] (etcp_connections.c:473) etcp_encrypt_send()
[03:30:18-194.484] [TRACE] [8] (etcp.c:53) get_current_timestamp()
[03:30:18-194.487] [TRACE] [8] (etcp.c:43) get_current_time_units()
[03:30:18-194.491] [INFO] [8] (etcp_connections.c:487) etcp_encrypt_send() Encrypt start
[03:30:18-194.521] [INFO] [8] (etcp_connections.c:489) etcp_encrypt_send() Encrypt end
[03:30:18-194.556] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-194.562] [TRACE] [4] (etcp_connections.c:529) etcp_connections_read_callback_socket()
[03:30:18-194.568] [TRACE] [4] (etcp_connections.c:226) etcp_link_find_by_addr()
[03:30:18-194.571] [TRACE] [4] (etcp_connections.c:142) sockaddr_hash()
[03:30:18-194.575] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-194.578] [INFO] [8] (etcp_connections.c:687) etcp_connections_read_callback_socket() Decrypt start
[03:30:18-194.585] [ERROR] [16] (etcp_connections.c:689) etcp_connections_read_callback_socket() etcp_connections_read_callback: failed to decrypt packet from node 1229782938247303441 len=105
[03:30:18-194.589] [ERROR] [8] (etcp_connections.c:801) etcp_connections_read_callback_socket() etcp_connections_read_callback: error 6
[03:30:18-194.593] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-195.656] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-196.724] [DEBUG] [1024] (u_async.c:684) uasync_poll() poll
[03:30:18-197.802] [INFO] [8] (test_etcp_two_instances.c:333) main() Starting connection attempts...
[03:30:18-197.812] [INFO] [8] (test_etcp_two_instances.c:350) main()
Cleaning up...
[03:30:18-197.816] [INFO] [8] (test_etcp_two_instances.c:351) main() [CLEANUP] ua=0x596ec7b6d4c0
[03:30:18-197.819] [INFO] [8] (test_etcp_two_instances.c:352) main() [CLEANUP] server_instance=0x596ec7b6f4e0, client_instance=0x596ec7b73560
[03:30:18-197.866] [INFO] [8] (test_etcp_two_instances.c:353) main() [CLEANUP] monitor_timeout_id=0x596ec7bc2300, test_timeout_id=(nil)
[03:30:18-197.870] [INFO] [8] (test_etcp_two_instances.c:357) main() [CLEANUP] Canceling monitor timeout on valid uasync
[03:30:18-197.873] [DEBUG] [1024] (u_async.c:426) uasync_cancel_timeout() uasync_cancel_timeout: not found in heap: ua=0x596ec7b6d4c0, t_id=0x596ec7bc2300, node=0x596ec7bc2300, expires=1771115418154 ms
[03:30:18-197.877] [INFO] [8] (test_etcp_two_instances.c:366) main() [CLEANUP] Timeouts canceled
[03:30:18-197.881] [INFO] [8] (test_etcp_two_instances.c:370) main() [CLEANUP] Shared uasync resources before destroy:
🔍 SHARED: UASYNC Resource Report for 0x596ec7b6d4c0
Timer Statistics: allocated=5, freed=3, active=2
Socket Statistics: allocated=2, freed=0, active=2
Timer: node=0x596ec7bbae80, expires=1771115418244 ms, cancelled=0
Active timers in heap: 1
Socket array capacity: 16, active: 2
Socket: fd=6, active=1
Socket: fd=7, active=1
Total active sockets: 2
🔚 SHARED: End of resource report
[03:30:18-197.886] [INFO] [8] (test_etcp_two_instances.c:377) main() [CLEANUP] Destroying server instance 0x596ec7b6f4e0
[03:30:18-197.890] [INFO] [32] (utun_instance.c:153) utun_instance_destroy() [INSTANCE_DESTROY] Starting cleanup for instance 0x596ec7b6f4e0
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x596ec7b6f4e0
Node ID: 1229782938247303441
UA instance: 0x596ec7b6d4c0
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x596ec7bc2d10
ETCP Sockets list: 0x596ec7b704d0
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-197.897] [INFO] [32] (utun_instance.c:162) utun_instance_destroy() [INSTANCE_DESTROY] Cleaning up ETCP sockets and connections
[03:30:18-197.909] [INFO] [32] (utun_instance.c:166) utun_instance_destroy() [INSTANCE_DESTROY] Removing socket 0x596ec7b704d0, fd=6
[03:30:18-197.912] [TRACE] [4] (etcp_connections.c:372) etcp_socket_remove()
[03:30:18-197.916] [INFO] [8] (etcp_connections.c:375) etcp_socket_remove() [ETCP] Removing socket 0x596ec7b704d0, socket_id=0x596ec7b6d570
[03:30:18-197.919] [INFO] [8] (etcp_connections.c:379) etcp_socket_remove() [ETCP] Removing socket from uasync, instance=0x596ec7b6f4e0, ua=0x596ec7b6d4c0
[03:30:18-197.925] [INFO] [8] (etcp_connections.c:382) etcp_socket_remove() [ETCP] Unregistered socket from uasync
[03:30:18-197.934] [INFO] [8] (etcp_connections.c:387) etcp_socket_remove() [ETCP] Closed socket
[03:30:18-197.937] [TRACE] [4] (etcp_connections.c:448) etcp_link_close()
[03:30:18-197.940] [TRACE] [4] (etcp_connections.c:210) remove_link()
[03:30:18-197.976] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-197.980] [INFO] [32] (utun_instance.c:171) utun_instance_destroy() [INSTANCE_DESTROY] ETCP sockets cleanup complete
[03:30:18-197.983] [INFO] [32] (utun_instance.c:177) utun_instance_destroy() [INSTANCE_DESTROY] Closing connection 0x596ec7bc2d10
[03:30:18-197.986] [TRACE] [8] (etcp.c:136) etcp_connection_close()
[03:30:18-197.989] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-197.993] [INFO] [4096] (route_bgp.c:471) route_bgp_remove_conn() Removing connection 0x596ec7bc2d10 from senders_list
[03:30:18-197.996] [INFO] [4096] (route_bgp.c:200) route_bgp_send_withdraw_for_conn() Sending withdraw for routes via conn 0x596ec7bc2d10 to all peers
[03:30:18-198.000] [INFO] [4096] (route_bgp.c:484) route_bgp_remove_conn() Connection 0x596ec7bc2d10 removed from senders_list
[03:30:18-198.004] [INFO] [512] (route_lib.c:425) route_table_delete() Removed 0 routes for connection 0x596ec7bc2d10
[03:30:18-198.008] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-198.011] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bc2120, head=(nil), tail=(nil), count=0
[03:30:18-198.015] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bc21b0, head=(nil), tail=(nil), count=0
[03:30:18-198.019] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bc2e80, head=(nil), tail=(nil), count=0
[03:30:18-198.022] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bc2f10, head=(nil), tail=(nil), count=0
[03:30:18-198.025] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bc2fa0, head=(nil), tail=(nil), count=0
[03:30:18-198.029] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbb9f0, head=(nil), tail=(nil), count=0
[03:30:18-198.032] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbb390, head=(nil), tail=(nil), count=0
[03:30:18-198.036] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bc2400, head=(nil), tail=(nil), count=0
[03:30:18-198.039] [INFO] [32] (utun_instance.c:184) utun_instance_destroy() [INSTANCE_DESTROY] ETCP connections cleanup complete
[03:30:18-198.043] [INFO] [512] (routing.c:281) routing_destroy() Destroying routing module
[03:30:18-198.046] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 0 for instance 0x596ec7b6f4e0
[03:30:18-198.050] [INFO] [4096] (utun_instance.c:198) utun_instance_destroy() Destroying BGP module
[03:30:18-198.053] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 1 for instance 0x596ec7b6f4e0
[03:30:18-198.060] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b70830, head=(nil), tail=(nil), count=0
[03:30:18-198.063] [INFO] [4096] (route_bgp.c:418) route_bgp_destroy() BGP module destroyed
[03:30:18-198.067] [INFO] [32] (utun_instance.c:205) utun_instance_destroy() [INSTANCE_DESTROY] Freeing configuration
[03:30:18-198.070] [INFO] [32] (utun_instance.c:212) utun_instance_destroy() [INSTANCE_DESTROY] Destroying packet pool
[03:30:18-198.074] [INFO] [32] (utun_instance.c:219) utun_instance_destroy() [INSTANCE_DESTROY] Destroying ack pool
[03:30:18-198.077] [INFO] [32] (utun_instance.c:226) utun_instance_destroy() [INSTANCE_DESTROY] Destroying data pool
[03:30:18-198.080] [INFO] [32] (utun_instance.c:241) utun_instance_destroy() [INSTANCE_DESTROY] Freeing instance memory
[03:30:18-198.083] [INFO] [32] (utun_instance.c:243) utun_instance_destroy() [INSTANCE_DESTROY] Instance destroyed completely
[03:30:18-198.087] [INFO] [8] (test_etcp_two_instances.c:382) main() [CLEANUP] Destroying client instance 0x596ec7b73560
[03:30:18-198.090] [INFO] [32] (utun_instance.c:153) utun_instance_destroy() [INSTANCE_DESTROY] Starting cleanup for instance 0x596ec7b73560
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x596ec7b73560
Node ID: 2459565876494606882
UA instance: 0x596ec7b6d4c0
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 2 active
ETCP Links: 3 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x596ec7bbbcb0
ETCP Sockets list: 0x596ec7b74910
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 2 ETCP connections still allocated
❌ 3 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
[03:30:18-198.095] [INFO] [32] (utun_instance.c:162) utun_instance_destroy() [INSTANCE_DESTROY] Cleaning up ETCP sockets and connections
[03:30:18-198.098] [INFO] [32] (utun_instance.c:166) utun_instance_destroy() [INSTANCE_DESTROY] Removing socket 0x596ec7b74910, fd=7
[03:30:18-198.101] [TRACE] [4] (etcp_connections.c:372) etcp_socket_remove()
[03:30:18-198.105] [INFO] [8] (etcp_connections.c:375) etcp_socket_remove() [ETCP] Removing socket 0x596ec7b74910, socket_id=0x596ec7b6d5b8
[03:30:18-198.108] [INFO] [8] (etcp_connections.c:379) etcp_socket_remove() [ETCP] Removing socket from uasync, instance=0x596ec7b73560, ua=0x596ec7b6d4c0
[03:30:18-198.112] [INFO] [8] (etcp_connections.c:382) etcp_socket_remove() [ETCP] Unregistered socket from uasync
[03:30:18-198.119] [INFO] [8] (etcp_connections.c:387) etcp_socket_remove() [ETCP] Closed socket
[03:30:18-198.122] [TRACE] [4] (etcp_connections.c:448) etcp_link_close()
[03:30:18-198.125] [TRACE] [4] (etcp_connections.c:210) remove_link()
[03:30:18-198.128] [TRACE] [4] (etcp_connections.c:149) find_link_index()
[03:30:18-198.131] [INFO] [32] (utun_instance.c:171) utun_instance_destroy() [INSTANCE_DESTROY] ETCP sockets cleanup complete
[03:30:18-198.134] [INFO] [32] (utun_instance.c:177) utun_instance_destroy() [INSTANCE_DESTROY] Closing connection 0x596ec7bbbcb0
[03:30:18-198.137] [TRACE] [8] (etcp.c:136) etcp_connection_close()
[03:30:18-198.140] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-198.144] [INFO] [4096] (route_bgp.c:471) route_bgp_remove_conn() Removing connection 0x596ec7bbbcb0 from senders_list
[03:30:18-198.147] [INFO] [4096] (route_bgp.c:200) route_bgp_send_withdraw_for_conn() Sending withdraw for routes via conn 0x596ec7bbbcb0 to all peers
[03:30:18-198.150] [INFO] [512] (route_lib.c:425) route_table_delete() Removed 0 routes for connection 0x596ec7bbbcb0
[03:30:18-198.153] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-198.157] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbb710, head=(nil), tail=(nil), count=0
[03:30:18-198.162] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbb300, head=(nil), tail=(nil), count=0
[03:30:18-198.166] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbbe20, head=(nil), tail=(nil), count=0
[03:30:18-198.169] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbbeb0, head=(nil), tail=(nil), count=0
[03:30:18-198.173] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbbf40, head=(nil), tail=(nil), count=0
[03:30:18-198.182] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbb150, head=(nil), tail=(nil), count=0
[03:30:18-198.185] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbb4e0, head=(nil), tail=(nil), count=0
[03:30:18-198.189] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7bbadc0, head=(nil), tail=(nil), count=0
[03:30:18-198.192] [TRACE] [4] (etcp_connections.c:448) etcp_link_close()
[03:30:18-198.195] [TRACE] [4] (etcp_connections.c:210) remove_link()
[03:30:18-198.198] [INFO] [32] (utun_instance.c:177) utun_instance_destroy() [INSTANCE_DESTROY] Closing connection 0x596ec7b70eb0
[03:30:18-198.202] [TRACE] [8] (etcp.c:136) etcp_connection_close()
[03:30:18-198.205] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-198.208] [INFO] [4096] (route_bgp.c:471) route_bgp_remove_conn() Removing connection 0x596ec7b70eb0 from senders_list
[03:30:18-198.211] [INFO] [4096] (route_bgp.c:200) route_bgp_send_withdraw_for_conn() Sending withdraw for routes via conn 0x596ec7b70eb0 to all peers
[03:30:18-198.214] [INFO] [4096] (route_bgp.c:484) route_bgp_remove_conn() Connection 0x596ec7b70eb0 removed from senders_list
[03:30:18-198.217] [INFO] [512] (route_lib.c:425) route_table_delete() Removed 0 routes for connection 0x596ec7b70eb0
[03:30:18-198.221] [DEBUG] [512] (routing.c:304) routing_del_conn() routing_del_conn: deprecated, no action taken
[03:30:18-198.224] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b7d640, head=(nil), tail=(nil), count=0
[03:30:18-198.227] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b7d6d0, head=(nil), tail=(nil), count=0
[03:30:18-198.231] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b6e320, head=(nil), tail=(nil), count=0
[03:30:18-198.234] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b70a80, head=(nil), tail=(nil), count=0
[03:30:18-198.237] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b773d0, head=(nil), tail=(nil), count=0
[03:30:18-198.241] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b79470, head=(nil), tail=(nil), count=0
[03:30:18-198.244] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b7d5b0, head=(nil), tail=(nil), count=0
[03:30:18-198.247] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b7b510, head=(nil), tail=(nil), count=0
[03:30:18-198.251] [INFO] [32] (utun_instance.c:184) utun_instance_destroy() [INSTANCE_DESTROY] ETCP connections cleanup complete
[03:30:18-198.254] [INFO] [512] (routing.c:281) routing_destroy() Destroying routing module
[03:30:18-198.257] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 0 for instance 0x596ec7b73560
[03:30:18-198.261] [INFO] [4096] (utun_instance.c:198) utun_instance_destroy() Destroying BGP module
[03:30:18-198.264] [INFO] [1] (etcp_api.c:62) etcp_unbind() etcp_unbind: Unbound ID 1 for instance 0x596ec7b73560
[03:30:18-198.267] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x596ec7b74af0, head=(nil), tail=(nil), count=0
[03:30:18-198.270] [INFO] [4096] (route_bgp.c:418) route_bgp_destroy() BGP module destroyed
[03:30:18-198.273] [INFO] [32] (utun_instance.c:205) utun_instance_destroy() [INSTANCE_DESTROY] Freeing configuration
[03:30:18-198.279] [INFO] [32] (utun_instance.c:212) utun_instance_destroy() [INSTANCE_DESTROY] Destroying packet pool
[03:30:18-198.303] [INFO] [32] (utun_instance.c:219) utun_instance_destroy() [INSTANCE_DESTROY] Destroying ack pool
[03:30:18-198.622] [INFO] [32] (utun_instance.c:226) utun_instance_destroy() [INSTANCE_DESTROY] Destroying data pool
[03:30:18-198.626] [INFO] [32] (utun_instance.c:241) utun_instance_destroy() [INSTANCE_DESTROY] Freeing instance memory
[03:30:18-198.630] [INFO] [32] (utun_instance.c:243) utun_instance_destroy() [INSTANCE_DESTROY] Instance destroyed completely
[03:30:18-198.633] [DEBUG] [1024] (u_async.c:1000) uasync_destroy() uasync_destroy: starting cleanup for ua=0x596ec7b6d4c0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x596ec7b6d4c0
Timer Statistics: allocated=5, freed=3, active=2
Socket Statistics: allocated=2, freed=2, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-198.637] [ERROR] [32] (u_async.c:1007) uasync_destroy() Memory leaks detected before cleanup: timers 5/3, sockets 2/2
[03:30:18-198.641] [ERROR] [1024] (u_async.c:1009) uasync_destroy() Timer leak: allocated=5, freed=3, diff=2
[03:30:18-198.644] [ERROR] [1024] (u_async.c:1012) uasync_destroy() Socket leak: allocated=2, freed=2, diff=0
[03:30:18-198.647] [DEBUG] [32] (u_async.c:1048) uasync_destroy() Freed 0 socket nodes in destroy
[03:30:18-198.660] [DEBUG] [1024] (u_async.c:1081) uasync_destroy() uasync_destroy: completed successfully for ua=0x596ec7b6d4c0
[03:30:18-198.664] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-198.904] [INFO] [8] (test_etcp_two_instances.c:396) main()
=== TEST PASSED ===

44
tests/logs/test_intensive_memory_pool.log
Unescape View File

@ -1,44 +0,0 @@
[03:30:18-631.960] [INFO] [32] (test_intensive_memory_pool.c:127) main() === Интенсивный тест пулов памяти ===
[03:30:18-632.033] [INFO] [32] (test_intensive_memory_pool.c:128) main() Тестируется производительность с пулами vs без пулов
[03:30:18-632.040] [INFO] [32] (test_intensive_memory_pool.c:132) main() Запуск теста без пулов памяти...
[03:30:18-632.047] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-632.064] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
[03:30:18-632.072] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63a5cc7c0cc0, hash_size=0
[03:30:18-632.437] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63a5cc7c0cc0, head=(nil), tail=(nil), count=0
[03:30:18-632.443] [DEBUG] [1024] (u_async.c:1000) uasync_destroy() uasync_destroy: starting cleanup for ua=0x63a5cc7c04c0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63a5cc7c04c0
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-632.448] [DEBUG] [32] (u_async.c:1048) uasync_destroy() Freed 0 socket nodes in destroy
[03:30:18-632.460] [DEBUG] [1024] (u_async.c:1081) uasync_destroy() uasync_destroy: completed successfully for ua=0x63a5cc7c04c0
[03:30:18-632.464] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-632.468] [INFO] [32] (test_intensive_memory_pool.c:134) main() Время без пулов: 0.000 сек
[03:30:18-632.479] [INFO] [32] (test_intensive_memory_pool.c:135) main() Waiter callbacks: 32000
[03:30:18-632.483] [INFO] [32] (test_intensive_memory_pool.c:139) main() Запуск теста с пулами памяти...
[03:30:18-632.487] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-632.495] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
[03:30:18-632.500] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63a5cc7c1230, hash_size=0
[03:30:18-632.794] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63a5cc7c1230, head=(nil), tail=(nil), count=0
[03:30:18-632.799] [DEBUG] [1024] (u_async.c:1000) uasync_destroy() uasync_destroy: starting cleanup for ua=0x63a5cc7c0cc0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63a5cc7c0cc0
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-632.803] [DEBUG] [32] (u_async.c:1048) uasync_destroy() Freed 0 socket nodes in destroy
[03:30:18-632.812] [DEBUG] [1024] (u_async.c:1081) uasync_destroy() uasync_destroy: completed successfully for ua=0x63a5cc7c0cc0
[03:30:18-632.815] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-632.819] [INFO] [32] (test_intensive_memory_pool.c:141) main() Время с пулами: 0.000 сек
[03:30:18-632.823] [INFO] [32] (test_intensive_memory_pool.c:142) main() Waiter callbacks: 32000
[03:30:18-632.826] [INFO] [32] (test_intensive_memory_pool.c:146) main() Результат: пулы памяти дали 1.30x ускорение
[03:30:18-632.830] [INFO] [32] (test_intensive_memory_pool.c:148) main() ✅ Пулы памяти эффективны!

104
tests/logs/test_ll_queue.log
Unescape View File

@ -1,104 +0,0 @@
TEST: basic creation / free [03:30:18-624.701] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb920ab0, hash_size=0
[03:30:18-624.724] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb920d60, hash_size=16
[03:30:18-624.728] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb920ab0, head=(nil), tail=(nil), count=0
[03:30:18-624.732] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb920d60, head=(nil), tail=(nil), count=0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb9202b0
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
TEST: FIFO ordering [03:30:18-624.750] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb9204c0, hash_size=0
[03:30:18-624.755] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb9204c0, head=(nil), tail=(nil), count=0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb920360
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
TEST: put_first (LIFO priority) [03:30:18-624.769] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb921bd0, hash_size=0
[03:30:18-624.773] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb921bd0, head=(nil), tail=(nil), count=0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb920e80
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
TEST: callback serial processing [03:30:18-624.787] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb920ef0, hash_size=0
[03:30:18-624.791] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb920ef0, head=(nil), tail=(nil), count=0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb921c60
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
TEST: wait_threshold + cancel [03:30:18-624.804] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb920ff0, hash_size=0
[03:30:18-624.808] [DEBUG] [2] (ll_queue.c:216) check_waiters() check_waiters: condition met, calling callback, count=2<=2, bytes=0<=0 (max_bytes_check=disabled)
[03:30:18-624.815] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb920ff0, head=0x63defb921310, tail=0x63defb9206f0, count=2
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb920f80
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
TEST: size limit + hash find/remove [03:30:18-624.829] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb9210f0, hash_size=16
[03:30:18-624.832] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb9210f0, head=(nil), tail=(nil), count=0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb921080
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
TEST: memory_pool integration + reuse [03:30:18-624.846] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb921160, hash_size=0
[03:30:18-624.854] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb921160, head=(nil), tail=(nil), count=0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb9210f0
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
TEST: stress 10k ops [03:30:18-624.870] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x63defb921d70, hash_size=64
[03:30:18-625.236] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x63defb921d70, head=(nil), tail=(nil), count=0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x63defb921160
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
PASS
=== SUMMARY ===
run=8 passed=8 failed=0
callbacks: queue=5 waiter=2
ops=10000 time=0.59 ms

26
tests/logs/test_memory_pool_and_config.log
Unescape View File

@ -1,26 +0,0 @@
[03:30:18-636.022] [INFO] [32] (test_memory_pool_and_config.c:33) main() === Memory Pool and Config File Test ===
[03:30:18-636.114] [INFO] [32] (test_memory_pool_and_config.c:36) main() Test 1: Memory pool optimization...
[03:30:18-636.119] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-636.140] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
[03:30:18-636.148] [DEBUG] [2] (ll_queue.c:37) queue_new() queue_new: created queue 0x64909f863cc0, hash_size=0
[03:30:18-636.153] [INFO] [32] (test_memory_pool_and_config.c:82) main() Pool statistics: allocations=0, reuse_count=0
[03:30:18-636.156] [INFO] [32] (test_memory_pool_and_config.c:83) main() Pool efficiency: 0.0%
[03:30:18-636.168] [DEBUG] [2] (ll_queue.c:62) queue_free() queue_free: freeing queue 0x64909f863cc0, head=(nil), tail=(nil), count=0
[03:30:18-636.172] [DEBUG] [1024] (u_async.c:1000) uasync_destroy() uasync_destroy: starting cleanup for ua=0x64909f8634c0
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x64909f8634c0
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-636.177] [DEBUG] [32] (u_async.c:1048) uasync_destroy() Freed 0 socket nodes in destroy
[03:30:18-636.190] [DEBUG] [1024] (u_async.c:1081) uasync_destroy() uasync_destroy: completed successfully for ua=0x64909f8634c0
[03:30:18-636.194] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-636.198] [INFO] [32] (test_memory_pool_and_config.c:89) main() Memory pool test: PASS
[03:30:18-636.201] [INFO] [128] (test_memory_pool_and_config.c:92) main() Test 2: Configuration file support...
[03:30:18-636.321] [ERROR] [128] (test_memory_pool_and_config.c:125) main() Failed to parse configuration
[03:30:18-636.371] [INFO] [128] (test_memory_pool_and_config.c:133) main() Configuration file test: PASS
[03:30:18-636.376] [INFO] [32] (test_memory_pool_and_config.c:135) main() === All tests completed successfully ===

3
tests/logs/test_packet_dump.log
Unescape View File

@ -1,3 +0,0 @@
[03:30:18-640.198] [INFO] [8] (test_packet_dump.c:23) main() === Testing single-line packet dump ===
[03:30:18-640.267] [INFO] [8] (test_packet_dump.c:14) test_packet_dump() TEST_SEND: len=6 hex=021122334455
[03:30:18-640.271] [INFO] [8] (test_packet_dump.c:15) test_packet_dump() TEST_COMPACT: link=NULL type=0x02 ts=0 len=6

195
tests/logs/test_pkt_normalizer_etcp.log
Unescape View File

@ -1,195 +0,0 @@
=== PKT Normalizer + ETCP Test ===
Testing with 100 packets of random sizes (10-2000 bytes)
Total data to transfer: 104431 bytes (1.02 KB average per packet)
Creating server...
[CONFIG DEBUG] Opening config file: /tmp/utun_test_5DpiUN/server.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='67b705a92b41bcaae105af2d6a17743faa7b26ccebba8b3b9b0af05e9cd1d5fb' (len=64), pub_key='1c55e4ccae7c4470707759086738b10681bf88b81f198cc2ab54a647d1556e17c65e6b1833e0c771e5a39382c03067c388915a4c732191bc130480f20f8e00b9' (len=128), node_id=1229782938247303441
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_5DpiUN/server.conf
[CONFIG DEBUG] Successfully opened config file
Server created, waiting for connection...
Creating client...
[CONFIG DEBUG] Opening config file: /tmp/utun_test_5DpiUN/client.conf
[CONFIG DEBUG] Successfully opened config file
[CONFIG DEBUG] Checking config - priv_key='4813d31d28b7e9829247f488c6be7672f2bdf61b2508333128e386d1759afed2' (len=64), pub_key='c594f33c91f3a2222795c2c110c527bf214ad1009197ce14556cb13df3c461b3c373bed8f205a8dd1fc0c364f90bf471d7c6f5db49564c33e4235d268569ac71' (len=128), node_id=2459565876494606882
[CONFIG DEBUG] Validation results - need_priv_key=0, need_pub_key=0, need_node_id=0
[CONFIG DEBUG] Opening config file: /tmp/utun_test_5DpiUN/client.conf
[CONFIG DEBUG] Successfully opened config file
Client created
Sending 100 packets in each direction via normalizer...
Connection check: client=1, server=1
Connections: client=0x5b22583e4290, server=0x5b22584292d0
DEBUG: client_pn=(nil), client_instance->connections=0x5b22583e4290
Creating client normalizer...
Client normalizer created (frag_size=1400)
DEBUG: server_pn=(nil), server_instance->connections=0x5b22584292d0
Creating server normalizer...
Server normalizer created (frag_size=1400)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=0/100
Starting forward transfer (client -> server) via normalizer...
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
DEBUG send_packets_fwd: client_instance=0x5b22583e0420, client_pn=0x5b2258428250, packets_sent_fwd=100/100
DEBUG send_packets_fwd: early return (instance=0x5b22583e0420, pn=0x5b2258428250, sent=100)
Forward transfer completed: 100/100 packets in 22.74 ms
Starting backward transfer (server -> client) via normalizer...
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
DEBUG check_received_packets_back: client_instance=0x5b22583e0420, client_pn=0x5b2258428250
Backward transfer completed: 100/100 packets in 27.06 ms
=== SUCCESS: Bidirectional transfer via normalizer completed! ===
Forward (client->server): 100/100 packets in 22.74 ms
Backward (server->client): 100/100 packets in 27.06 ms
Total time: 50.86 ms
Cleaning up...
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x5b22583dbc90
Node ID: 1229782938247303441
UA instance: 0x5b22583db490
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x5b22584292d0
ETCP Sockets list: 0x5b22583dd330
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
🔍 [UTUN_INSTANCE LEAK DIAGNOSIS] Phase: BEFORE_CLEANUP
Instance: 0x5b22583e0420
Node ID: 2459565876494606882
UA instance: 0x5b22583db490
Running: 0
📊 STRUCTURE COUNTS:
ETCP Sockets: 1 active
ETCP Connections: 1 active
ETCP Links: 2 total
🔧 RESOURCE STATUS:
Memory Pool: ALLOCATED
TUN Interface: NULL
TUN FD: -1
Connections list: 0x5b22583e4290
ETCP Sockets list: 0x5b22583e17d0
⚠️ POTENTIAL LEAKS:
❌ Memory Pool not freed
❌ 1 ETCP sockets still allocated
❌ 1 ETCP connections still allocated
❌ 2 ETCP links still allocated
📋 RECOMMENDATIONS:
→ Call memory_pool_destroy() before freeing instance
→ Iterate and call etcp_socket_remove() for each socket
→ Iterate and call etcp_connection_close() for each connection
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x5b22583db490
Timer Statistics: allocated=331, freed=310, active=21
Socket Statistics: allocated=2, freed=2, active=0
Timer: node=0x5b2258429240, expires=1771115418489 ms, cancelled=0
Timer: node=0x5b225844be20, expires=1771115418494 ms, cancelled=0
Timer: node=0x5b2258428940, expires=1771115418492 ms, cancelled=0
Timer: node=0x5b2258442020, expires=1771115418498 ms, cancelled=0
Timer: node=0x5b2258429210, expires=1771115418502 ms, cancelled=0
Timer: node=0x5b2258404e40, expires=1771115418506 ms, cancelled=0
Timer: node=0x5b2258448a10, expires=1771115418496 ms, cancelled=0
Timer: node=0x5b2258438e60, expires=1771115418518 ms, cancelled=0
Timer: node=0x5b2258427fa0, expires=1771115418504 ms, cancelled=0
Timer: node=0x5b225843c0c0, expires=1771115418508 ms, cancelled=0
Timer: node=0x5b2258429150, expires=1771115418513 ms, cancelled=0
Timer: node=0x5b225844bbd0, expires=1771115418533 ms, cancelled=0
Timer: node=0x5b2258427d60, expires=1771115418536 ms, cancelled=0
Timer: node=0x5b2258444600, expires=1771115418500 ms, cancelled=0
Timer: node=0x5b225843bf20, expires=1771115418516 ms, cancelled=0
Timer: node=0x5b22584284a0, expires=1771115418520 ms, cancelled=0
Timer: node=0x5b22584280c0, expires=1771115418524 ms, cancelled=0
Timer: node=0x5b22584501f0, expires=1771115418526 ms, cancelled=0
Timer: node=0x5b2258439780, expires=1771115418530 ms, cancelled=0
Timer: node=0x5b225843be00, expires=1771115418528 ms, cancelled=0
Active timers in heap: 20
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-439.537] [ERROR] [32] (u_async.c:1007) uasync_destroy() Memory leaks detected before cleanup: timers 331/310, sockets 2/2
[03:30:18-439.592] [ERROR] [1024] (u_async.c:1009) uasync_destroy() Timer leak: allocated=331, freed=310, diff=21
[03:30:18-439.597] [ERROR] [1024] (u_async.c:1012) uasync_destroy() Socket leak: allocated=2, freed=2, diff=0
=== TEST PASSED ===
All 100 packets transmitted in each direction via normalizer

29
tests/logs/test_pkt_normalizer_standalone.log
Unescape View File

@ -1,29 +0,0 @@
=== PKT Normalizer Standalone Test (Loopback) ===
MTU: 1500, Frag size: 1400
Testing with 100 packets of random sizes (10-3000 bytes)
Total data to transfer: 147167 bytes (1.44 KB average per packet)
Normalizer created (frag_size=1400)
Sending 100 packets...
All 100 packets queued to normalizer
=== SUCCESS: All packets received! ===
Sent: 100, Received: 100
Fragments: sent=106, received=100
Duration: 3.59 ms
Cleaning up...
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x631764e2f2b0
Timer Statistics: allocated=103, freed=102, active=1
Socket Statistics: allocated=0, freed=0, active=0
Timer: node=0x631764e2fdf0, expires=1771115419441 ms, cancelled=0
Active timers in heap: 1
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
=== TEST PASSED ===

3182
tests/logs/test_route_lib.log
View File

File diff suppressed because it is too large Load Diff

115
tests/logs/test_u_async_comprehensive.log
Unescape View File

@ -1,115 +0,0 @@
[03:30:18-641.696] [INFO] [1] (test_u_async_comprehensive.c:474) main() === lib Comprehensive Unit Tests ===
[03:30:18-641.758] [INFO] [1] (test_u_async_comprehensive.c:475) main() Testing race conditions, memory management, and error handling
[03:30:18-641.763] [INFO] [1] (test_u_async_comprehensive.c:144) test_basic_timers() TEST: Basic timer functionality...
[03:30:18-641.767] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-641.787] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x55561d8ff4c0
Timer Statistics: allocated=3, freed=3, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-644.321] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-644.343] [INFO] [1] (test_u_async_comprehensive.c:172) test_basic_timers() PASS
[03:30:18-644.347] [INFO] [1] (test_u_async_comprehensive.c:177) test_timer_cancellation_races() TEST: Timer cancellation race conditions...
[03:30:18-644.350] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-644.365] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x55561d8ff570
Timer Statistics: allocated=3, freed=3, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-654.664] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-654.691] [INFO] [1] (test_u_async_comprehensive.c:224) test_timer_cancellation_races() PASS
[03:30:18-654.695] [INFO] [1] (test_u_async_comprehensive.c:229) test_immediate_timeouts() TEST: Immediate timeout handling...
[03:30:18-654.699] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-654.713] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x55561d9002d0
Timer Statistics: allocated=5, freed=5, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-654.726] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-654.729] [INFO] [1] (test_u_async_comprehensive.c:261) test_immediate_timeouts() PASS
[03:30:18-654.733] [INFO] [1] (test_u_async_comprehensive.c:266) test_memory_leak_detection() TEST: Memory leak detection...
[03:30:18-654.736] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-654.743] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x55561d8ff5e0
Timer Statistics: allocated=10, freed=10, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-665.337] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-665.384] [INFO] [1] (test_u_async_comprehensive.c:293) test_memory_leak_detection() PASS
[03:30:18-665.389] [INFO] [1] (test_u_async_comprehensive.c:298) test_socket_management() TEST: Socket management efficiency...
[03:30:18-665.392] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-665.414] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x55561d8ff790
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=10, freed=10, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-665.512] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-665.534] [INFO] [1] (test_u_async_comprehensive.c:340) test_socket_management() PASS
[03:30:18-665.538] [INFO] [1] (test_u_async_comprehensive.c:345) test_error_handling() TEST: Error injection and handling...
[03:30:18-665.541] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-665.549] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
[03:30:18-665.553] [ERROR] [1024] (u_async.c:410) uasync_cancel_timeout() uasync_cancel_timeout: invalid parameters ua=(nil), t_id=(nil), heap=(nil)
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x55561d900430
Timer Statistics: allocated=1, freed=1, active=0
Socket Statistics: allocated=0, freed=0, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-666.638] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-666.652] [INFO] [1] (test_u_async_comprehensive.c:375) test_error_handling() PASS
[03:30:18-666.656] [INFO] [1] (test_u_async_comprehensive.c:380) test_concurrent_operations() TEST: Concurrent operations stress test...
[03:30:18-666.659] [INFO] [8192] (socket_compat.c:54) socket_platform_init() POSIX socket subsystem ready
[03:30:18-666.669] [INFO] [1] (u_async.c:930) uasync_create() Using epoll for socket monitoring
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x55561d8ff800
Timer Statistics: allocated=10, freed=2, active=8
Socket Statistics: allocated=2, freed=2, active=0
Active timers in heap: 0
Socket array capacity: 16, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
[03:30:18-666.786] [ERROR] [32] (u_async.c:1007) uasync_destroy() Memory leaks detected before cleanup: timers 10/2, sockets 2/2
[03:30:18-666.790] [ERROR] [1024] (u_async.c:1009) uasync_destroy() Timer leak: allocated=10, freed=2, diff=8
[03:30:18-666.793] [ERROR] [1024] (u_async.c:1012) uasync_destroy() Socket leak: allocated=2, freed=2, diff=0
[03:30:18-666.801] [INFO] [8192] (socket_compat.c:60) socket_platform_cleanup() POSIX socket cleanup completed
[03:30:18-666.804] [INFO] [1] (test_u_async_comprehensive.c:465) test_concurrent_operations() PASS
[03:30:18-666.807] [INFO] [1] (test_u_async_comprehensive.c:487) main() === Test Statistics ===
[03:30:18-666.810] [INFO] [1] (test_u_async_comprehensive.c:488) main() Tests run: 7
[03:30:18-666.813] [INFO] [1] (test_u_async_comprehensive.c:489) main() Tests passed: 7
[03:30:18-666.816] [INFO] [1] (test_u_async_comprehensive.c:490) main() Tests failed: 0
[03:30:18-666.819] [INFO] [1] (test_u_async_comprehensive.c:491) main() Timer callbacks: 14
[03:30:18-666.822] [INFO] [1] (test_u_async_comprehensive.c:492) main() Timer cancellations: 1
[03:30:18-666.826] [INFO] [1] (test_u_async_comprehensive.c:493) main() Immediate timeouts: 9
[03:30:18-666.829] [INFO] [1] (test_u_async_comprehensive.c:494) main() Socket events: 17
[03:30:18-666.832] [INFO] [1] (test_u_async_comprehensive.c:495) main() Race condition errors: 1
[03:30:18-666.835] [INFO] [1] (test_u_async_comprehensive.c:498) main() === Memory Leak Detection ===
[03:30:18-666.838] [INFO] [1] (test_u_async_comprehensive.c:499) main() No memory leaks detected during testing

59
tests/logs/test_u_async_performance.log
Unescape View File

@ -1,59 +0,0 @@
lib Socket Management Performance Benchmark
================================================
=== Socket Management Benchmark ===
Testing with 25 sockets
DEBUG: Socket 0 has fd=6
Created 25 sockets
DEBUG: Total sockets added: 25
Add 25 sockets: 26 us (1.04 us per socket)
SKIPPING POLLING to test corruption
DEBUG: Removing sockets using lookup by FD
DEBUG: Attempting to remove socket 0 (fd=6, id=0x575a04a9bb90)
DEBUG: Attempting to remove socket 1 (fd=7, id=0x575a04a9bbd8)
DEBUG: Attempting to remove socket 2 (fd=8, id=0x575a04a9bc20)
DEBUG: Attempting to remove socket 3 (fd=9, id=0x575a04a9bc68)
DEBUG: Attempting to remove socket 4 (fd=10, id=0x575a04a9bcb0)
DEBUG: Attempting to remove socket 5 (fd=11, id=0x575a04a9bcf8)
DEBUG: Attempting to remove socket 6 (fd=12, id=0x575a04a9bd40)
DEBUG: Attempting to remove socket 7 (fd=13, id=0x575a04a9bd88)
DEBUG: Attempting to remove socket 8 (fd=14, id=0x575a04a9bdd0)
DEBUG: Attempting to remove socket 9 (fd=15, id=0x575a04a9be18)
DEBUG: Attempting to remove socket 10 (fd=16, id=0x575a04a9be60)
DEBUG: Attempting to remove socket 11 (fd=17, id=0x575a04a9bea8)
DEBUG: Attempting to remove socket 12 (fd=18, id=0x575a04a9bef0)
DEBUG: Attempting to remove socket 13 (fd=19, id=0x575a04a9bf38)
DEBUG: Attempting to remove socket 14 (fd=20, id=0x575a04a9bf80)
DEBUG: Attempting to remove socket 15 (fd=21, id=0x575a04a9bfc8)
DEBUG: Attempting to remove socket 16 (fd=22, id=0x575a04a9c010)
DEBUG: Attempting to remove socket 17 (fd=23, id=0x575a04a9c058)
DEBUG: Attempting to remove socket 18 (fd=24, id=0x575a04a9c0a0)
DEBUG: Attempting to remove socket 19 (fd=25, id=0x575a04a9c0e8)
DEBUG: Attempting to remove socket 20 (fd=26, id=0x575a04a9c130)
DEBUG: Attempting to remove socket 21 (fd=27, id=0x575a04a9c178)
DEBUG: Attempting to remove socket 22 (fd=28, id=0x575a04a9c1c0)
DEBUG: Attempting to remove socket 23 (fd=29, id=0x575a04a9c208)
DEBUG: Attempting to remove socket 24 (fd=30, id=0x575a04a9c250)
DEBUG: Actually removed 25 sockets, failed 0
Remove 25 sockets: 19 us (0.76 us per socket)
Total time: 45 us
Average per operation: 0.90 us
SKIPPING memory stats for corruption testing
🔍 BEFORE_DESTROY: UASYNC Resource Report for 0x575a04a9b2b0
Timer Statistics: allocated=0, freed=0, active=0
Socket Statistics: allocated=25, freed=25, active=0
Active timers in heap: 0
Socket array capacity: 32, active: 0
Total active sockets: 0
🔚 BEFORE_DESTROY: End of resource report
=== Benchmark Complete ===
Array-based socket management provides:
- O(1) add/remove operations (vs O(n) for linked list)
- Better cache locality for sequential socket processing
- Direct FD-to-index mapping for fast lookups
- Reduced memory allocations per operation

BIN
tests/test_bgp_route_exchange
View File

Binary file not shown.

56
tests/test_bgp_route_exchange.c
Unescape View File

@ -12,11 +12,18 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <time.h>
#include <sys/stat.h>
#include <arpa/inet.h>
#include <sys/socket.h>
#include "../lib/platform_compat.h"
#include "test_utils.h"
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
#define _mkdir(path) _mkdir(path)
#else
#include <unistd.h>
#endif
#include "../src/etcp.h"
#include "../src/etcp_connections.h"
@ -42,10 +49,37 @@ static void* monitor_timeout_id = NULL;
static void* test_timeout_id = NULL;
// Temp config file paths
#ifdef _WIN32
static char temp_dir[MAX_PATH];
#else
static char temp_dir[] = "/tmp/utun_bgp_test_XXXXXX";
#endif
static char server_config_path[256];
static char client_config_path[256];
// Cross-platform mkdtemp replacement
static int create_temp_directory(void) {
#ifdef _WIN32
char tmp_path[MAX_PATH];
GetTempPathA(MAX_PATH, tmp_path);
// Generate unique directory name
srand((unsigned int)GetTickCount());
int attempts = 0;
while (attempts < 100) {
snprintf(temp_dir, sizeof(temp_dir), "%s\\utun_bgp_test_%08x",
tmp_path, (unsigned int)rand());
if (_mkdir(temp_dir) == 0) {
return 0; // Success
}
attempts++;
}
return -1; // Failed after 100 attempts
#else
return (test_mkdtemp(temp_dir) == NULL) ? -1 : 0;
#endif
}
// Server config: 2 subnets - 192.168.10.0/24 and 192.168.11.0/24
static const char* server_config_content =
"[global]\n"
@ -87,7 +121,7 @@ static const char* client_config_content =
// Create temp config files
static int create_temp_configs(void) {
if (mkdtemp(temp_dir) == NULL) {
if (create_temp_directory() != 0) {
fprintf(stderr, "Failed to create temp directory\n");
return -1;
}
@ -106,7 +140,7 @@ static int create_temp_configs(void) {
f = fopen(client_config_path, "w");
if (!f) {
fprintf(stderr, "Failed to create client config file\n");
unlink(server_config_path);
test_unlink(server_config_path);
return -1;
}
fprintf(f, "%s", client_config_content);
@ -117,9 +151,15 @@ static int create_temp_configs(void) {
// Cleanup temp config files
static void cleanup_temp_configs(void) {
if (server_config_path[0]) unlink(server_config_path);
if (client_config_path[0]) unlink(client_config_path);
if (temp_dir[0]) rmdir(temp_dir);
#ifdef _WIN32
if (server_config_path[0]) _unlink(server_config_path);
if (client_config_path[0]) _unlink(client_config_path);
if (temp_dir[0]) _rmdir(temp_dir);
#else
if (server_config_path[0]) test_unlink(server_config_path);
if (client_config_path[0]) test_unlink(client_config_path);
if (temp_dir[0]) test_rmdir(temp_dir);
#endif
}
// Check if connection is established (link initialized)

BIN
tests/test_config_debug
View File

Binary file not shown.

13
tests/test_config_debug.c
Unescape View File

@ -5,7 +5,14 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "../lib/platform_compat.h"
#include "test_utils.h"
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
#else
#include <unistd.h>
#endif
#include <sys/stat.h>
#include "../lib/debug_config.h"
#include "../src/config_parser.h"
@ -37,7 +44,7 @@ static const char* config_content =
// Create temp config file
static int create_temp_config(void) {
if (mkdtemp(temp_dir) == NULL) {
if (test_mkdtemp(temp_dir) == NULL) {
fprintf(stderr, "Failed to create temp directory\n");
return -1;
}
@ -57,8 +64,8 @@ static int create_temp_config(void) {
// Cleanup temp config file
static void cleanup_temp_config(void) {
if (config_path[0]) unlink(config_path);
if (temp_dir[0]) rmdir(temp_dir);
if (config_path[0]) test_unlink(config_path);
if (temp_dir[0]) test_rmdir(temp_dir);
}
int main() {

BIN
tests/test_etcp_100_packets
View File

Binary file not shown.

17
tests/test_etcp_100_packets.c
Unescape View File

@ -1,7 +1,14 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "../lib/platform_compat.h"
#include "test_utils.h"
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
#else
#include <unistd.h>
#endif
#include <time.h>
#include <sys/stat.h>
@ -63,7 +70,7 @@ static const char* client_config_content =
// Create temp config files
static int create_temp_configs(void) {
if (mkdtemp(temp_dir) == NULL) {
if (test_mkdtemp(temp_dir) == NULL) {
fprintf(stderr, "Failed to create temp directory\n");
return -1;
}
@ -82,7 +89,7 @@ static int create_temp_configs(void) {
f = fopen(client_config_path, "w");
if (!f) {
fprintf(stderr, "Failed to create client config file\n");
unlink(server_config_path);
test_unlink(server_config_path);
return -1;
}
fprintf(f, "%s", client_config_content);
@ -93,9 +100,9 @@ static int create_temp_configs(void) {
// Cleanup temp config files
static void cleanup_temp_configs(void) {
if (server_config_path[0]) unlink(server_config_path);
if (client_config_path[0]) unlink(client_config_path);
if (temp_dir[0]) rmdir(temp_dir);
if (server_config_path[0]) test_unlink(server_config_path);
if (client_config_path[0]) test_unlink(client_config_path);
if (temp_dir[0]) test_rmdir(temp_dir);
}
static int test_completed = 0;
static void* packet_timeout_id = NULL;

BIN
tests/test_etcp_api
View File

Binary file not shown.

17
tests/test_etcp_api.c
Unescape View File

@ -10,7 +10,14 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "../lib/platform_compat.h"
#include "test_utils.h"
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
#else
#include <unistd.h>
#endif
#include <time.h>
#include <sys/stat.h>
@ -70,7 +77,7 @@ static const char* client_config_content =
// Create temp config files
static int create_temp_configs(void) {
if (mkdtemp(temp_dir) == NULL) {
if (test_mkdtemp(temp_dir) == NULL) {
fprintf(stderr, "Failed to create temp directory\n");
return -1;
}
@ -89,7 +96,7 @@ static int create_temp_configs(void) {
f = fopen(client_config_path, "w");
if (!f) {
fprintf(stderr, "Failed to create client config file\n");
unlink(server_config_path);
test_unlink(server_config_path);
return -1;
}
fprintf(f, "%s", client_config_content);
@ -100,9 +107,9 @@ static int create_temp_configs(void) {
// Cleanup temp config files
static void cleanup_temp_configs(void) {
if (server_config_path[0]) unlink(server_config_path);
if (client_config_path[0]) unlink(client_config_path);
if (temp_dir[0]) rmdir(temp_dir);
if (server_config_path[0]) test_unlink(server_config_path);
if (client_config_path[0]) test_unlink(client_config_path);
if (temp_dir[0]) test_rmdir(temp_dir);
}
// Packet header size: seq(2) + size(2) + checksum(2) = 6 bytes

BIN
tests/test_etcp_minimal
View File

Binary file not shown.

BIN
tests/test_etcp_simple_traffic
View File

Binary file not shown.

17
tests/test_etcp_simple_traffic.c
Unescape View File

@ -1,7 +1,14 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "../lib/platform_compat.h"
#include "test_utils.h"
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
#else
#include <unistd.h>
#endif
#include <time.h>
#include <sys/stat.h>
@ -61,7 +68,7 @@ static const char* client_config_content =
// Create temp config files
static int create_temp_configs(void) {
if (mkdtemp(temp_dir) == NULL) {
if (test_mkdtemp(temp_dir) == NULL) {
fprintf(stderr, "Failed to create temp directory\n");
return -1;
}
@ -80,7 +87,7 @@ static int create_temp_configs(void) {
f = fopen(client_config_path, "w");
if (!f) {
fprintf(stderr, "Failed to create client config file\n");
unlink(server_config_path);
test_unlink(server_config_path);
return -1;
}
fprintf(f, "%s", client_config_content);
@ -91,9 +98,9 @@ static int create_temp_configs(void) {
// Cleanup temp config files
static void cleanup_temp_configs(void) {
if (server_config_path[0]) unlink(server_config_path);
if (client_config_path[0]) unlink(client_config_path);
if (temp_dir[0]) rmdir(temp_dir);
if (server_config_path[0]) test_unlink(server_config_path);
if (client_config_path[0]) test_unlink(client_config_path);
if (temp_dir[0]) test_rmdir(temp_dir);
}
static int test_completed = 0; // 0 = running, 1 = success, 2 = timeout/failure
static void* packet_timeout_id = NULL;

BIN
tests/test_etcp_two_instances
View File

Binary file not shown.

18
tests/test_etcp_two_instances.c
Unescape View File

@ -1,10 +1,16 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "../lib/platform_compat.h"
#include "test_utils.h"
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
#else
#include <unistd.h>
#endif
#include <time.h>
#include <sys/stat.h>
#include <arpa/inet.h>
#include <sys/socket.h>
#include "../src/etcp.h"
@ -65,7 +71,7 @@ static const char* client_config_content =
// Create temp config files
static int create_temp_configs(void) {
if (mkdtemp(temp_dir) == NULL) {
if (test_mkdtemp(temp_dir) == NULL) {
fprintf(stderr, "Failed to create temp directory\n");
return -1;
}
@ -84,7 +90,7 @@ static int create_temp_configs(void) {
f = fopen(client_config_path, "w");
if (!f) {
fprintf(stderr, "Failed to create client config file\n");
unlink(server_config_path);
test_unlink(server_config_path);
return -1;
}
fprintf(f, "%s", client_config_content);
@ -95,9 +101,9 @@ static int create_temp_configs(void) {
// Cleanup temp config files
static void cleanup_temp_configs(void) {
if (server_config_path[0]) unlink(server_config_path);
if (client_config_path[0]) unlink(client_config_path);
if (temp_dir[0]) rmdir(temp_dir);
if (server_config_path[0]) test_unlink(server_config_path);
if (client_config_path[0]) test_unlink(client_config_path);
if (temp_dir[0]) test_rmdir(temp_dir);
}
// For debug: enable in etcp_connections.c

BIN
tests/test_memory_pool_and_config
View File

Binary file not shown.

3
tests/test_memory_pool_and_config.c
Unescape View File

@ -2,6 +2,7 @@
* Test for memory pool optimization and configuration file support
*/
#include "test_utils.h"
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
@ -125,7 +126,7 @@ int main() {
DEBUG_ERROR(DEBUG_CATEGORY_CONFIG, "Failed to parse configuration");
}
unlink(config_file);
test_unlink(config_file);
} else {
DEBUG_ERROR(DEBUG_CATEGORY_CONFIG, "Failed to create test configuration file");
}

BIN
tests/test_pkt_normalizer_etcp
View File

Binary file not shown.

17
tests/test_pkt_normalizer_etcp.c
Unescape View File

@ -1,7 +1,14 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "../lib/platform_compat.h"
#include "test_utils.h"
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
#else
#include <unistd.h>
#endif
#include <time.h>
#include <sys/stat.h>
@ -64,7 +71,7 @@ static const char* client_config_content =
// Create temp config files
static int create_temp_configs(void) {
if (mkdtemp(temp_dir) == NULL) {
if (test_mkdtemp(temp_dir) == NULL) {
fprintf(stderr, "Failed to create temp directory\n");
return -1;
}
@ -83,7 +90,7 @@ static int create_temp_configs(void) {
f = fopen(client_config_path, "w");
if (!f) {
fprintf(stderr, "Failed to create client config file\n");
unlink(server_config_path);
test_unlink(server_config_path);
return -1;
}
fprintf(f, "%s", client_config_content);
@ -94,9 +101,9 @@ static int create_temp_configs(void) {
// Cleanup temp config files
static void cleanup_temp_configs(void) {
if (server_config_path[0]) unlink(server_config_path);
if (client_config_path[0]) unlink(client_config_path);
if (temp_dir[0]) rmdir(temp_dir);
if (server_config_path[0]) test_unlink(server_config_path);
if (client_config_path[0]) test_unlink(client_config_path);
if (temp_dir[0]) test_rmdir(temp_dir);
}
static struct UTUN_INSTANCE* server_instance = NULL;

73
tests/test_utils.h
Unescape View File

@ -0,0 +1,73 @@
/**
* @file test_utils.h
* @brief Utility functions for cross-platform tests
*/
#ifndef TEST_UTILS_H
#define TEST_UTILS_H
#include "../lib/platform_compat.h"
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#ifdef _WIN32
#include <windows.h>
#include <direct.h>
// Windows temp directory buffer
static char test_temp_dir[MAX_PATH];
// Cross-platform mkdtemp for Windows
static inline int test_mkdtemp(char *template_str) {
(void)template_str; // Not used on Windows, we generate our own path
char tmp_path[MAX_PATH];
GetTempPathA(MAX_PATH, tmp_path);
// Generate unique directory name
srand((unsigned int)GetTickCount());
int attempts = 0;
while (attempts < 100) {
snprintf(test_temp_dir, sizeof(test_temp_dir), "%s\\utun_test_%08x",
tmp_path, (unsigned int)rand());
if (_mkdir(test_temp_dir) == 0) {
// Copy path back to caller's buffer
if (template_str) {
strncpy(template_str, test_temp_dir, MAX_PATH);
}
return 0; // Success
}
attempts++;
}
return -1; // Failed after 100 attempts
}
// Cross-platform unlink for Windows
static inline int test_unlink(const char *path) {
return _unlink(path);
}
// Cross-platform rmdir for Windows
static inline int test_rmdir(const char *path) {
return _rmdir(path);
}
#else
// Linux/macOS - use standard functions
#include <unistd.h>
static inline int test_mkdtemp(char *template_str) {
return (mkdtemp(template_str) == NULL) ? -1 : 0;
}
static inline int test_unlink(const char *path) {
return unlink(path);
}
static inline int test_rmdir(const char *path) {
return rmdir(path);
}
#endif
#endif // TEST_UTILS_H
Write Preview
Loading…
Cancel
Save