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

chatgui: fix ERROR→WARN/DEBUG for normal situations 

- member_sync apply_items: empty payload is normal sync completion, not error
- topo_node_sqlite node_load: no addresses is normal for stub/seed nodes
- conn_mgr_core: node skipped when not in routing (normal for nodes w/o addrs)
- topo_group send_nodeinfo: downgrade ERROR→WARN in DEBUG category
- db_sync INIT_RESP: protocol details belong in DEBUG, not INFO
topo_upd
evgeny 2 months ago
parent
5feeb2c169
commit
e51d8ddda2
14 changed files with 66 additions and 49 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. 2
      src/chat/db_sync.c
  2. 2
      src/chat/member_sync.c
  3. 2
      src/routing_layer/conn_mgr_core.c
  4. 16
      src/routing_layer/topo_group.c
  5. 20
      src/routing_layer/topo_group_connect.c
  6. 8
      src/routing_layer/topo_node.c
  7. 2
      src/routing_layer/topo_node_sqlite.c
  8. 16
      src/transport_layer/etcp.c
  9. 3
      src/transport_layer/etcp.h
  10. 30
      src/transport_layer/etcp_connections.c
  11. 4
      src/transport_layer/etcp_dump.c
  12. 4
      src/transport_layer/pkt_normalizer.c
  13. 2
      tests/test_etcp_reconnect.c
  14. 4
      tests/test_pkt_normalizer_standalone.c

2
src/chat/db_sync.c
Unescape View File

@ -837,7 +837,7 @@ static void db_handle_init_resp(struct DB_SYNC_INSTANCE* si, uint64_t src, const
uint64_t my_ch8 = 0;
uint32_t mc = db_count(si);
if (mc > 0 && tp < mc) db_chain_hash8_at(si, tp, &my_ch8);
DEBUG_INFO(DEBUG_CATEGORY_CHAT_SYNC, "sync [%s:%04llX] ← INIT_RESP: tp=%u my=%u my_ch8=%016llX peer_ch8=%016llX has_tail=%u sc=%d",
DEBUG_DEBUG(DEBUG_CATEGORY_CHAT_SYNC, "sync [%s:%04llX] ← INIT_RESP: tp=%u my=%u my_ch8=%016llX peer_ch8=%016llX has_tail=%u sc=%d",
SI_SHRT(si), (unsigned long long)(src >> 16), tp, mc, my_ch8, peer_ch8, has_tail, sc);
struct SI_PEER* sp = si_peer_find(si, src);

2
src/chat/member_sync.c
Unescape View File

@ -294,7 +294,7 @@ void member_sync_remove_props_cbk(node_props_changed_fn fn, void* arg) {
static int _member_apply_items(void* ctx, const char* ns, uint64_t from_peer,
const uint8_t* data, size_t len) {
struct UTUN_INSTANCE* inst = (struct UTUN_INSTANCE*)ctx;
if (len < 2) { DEBUG_ERROR(DEBUG_CATEGORY_MEMBER_SYNC, "%s: apply_items — len=%zu < 2", MS_ID, len); return -1; }
if (len < 2) { DEBUG_DEBUG(DEBUG_CATEGORY_MEMBER_SYNC, "%s: apply_items — no items from peer=%016llx ns=%.*s (empty, sync complete)", MS_ID, (unsigned long long)from_peer, (int)strnlen(ns, 32), ns); return 0; }
uint16_t count; memcpy(&count, data, 2);
DEBUG_TRACE(DEBUG_CATEGORY_MEMBER_SYNC, "%s: apply_items ns=%s count=%u from=%016llx", MS_ID, ns, count, (unsigned long long)from_peer);

2
src/routing_layer/conn_mgr_core.c
Unescape View File

@ -396,7 +396,7 @@ int conn_mgr_open(struct CONN_MGR* mgr, uint64_t node_id, uint32_t idle_timeout_
} else DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "conn_mgr: failed to alloc TOPO_GROUP_NODE for DB node 0x%016llx", (unsigned long long)node_id);
}
}
if (!target) { DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "node 0x%016llx not found", (unsigned long long)node_id); return -1; }
if (!target) { DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "node 0x%016llx skipped — not in routing, no active connections", (unsigned long long)node_id); return -1; }
struct CONN_MGR_ENTRY* entry = cm_find_entry(mgr, node_id);

16
src/routing_layer/topo_group.c
Unescape View File

@ -35,7 +35,7 @@
static void topo_group_send_table_request(struct TOPO_GROUP* group, struct ETCP_CONN* conn) {
if (!group || !conn) return;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "Sending table request to %s", conn->log_name);
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "Sending table request to %s grp=%016llx", conn->log_name, (unsigned long long)group->group_id);
struct TOPOMSG_TABLE_REQ* req = u_calloc(1, sizeof(struct TOPOMSG_TABLE_REQ));
if (!req) return;
req->cmd = ETCP_ID_TOPO_ENTRY;
@ -167,17 +167,17 @@ static void topo_group_receive_cbk(struct ETCP_CONN* from_conn, struct ll_entry*
struct TOPO_GROUP* group = topo_groups_find(instance->topo_groups, pkt_group_id);
if (!group) {
DEBUG_WARN(DEBUG_CATEGORY_BGP, "BGP recv %s from %s: group %016llx not found, dropping", group_subcmd_name(subcmd), from_conn->log_name, (unsigned long long)pkt_group_id);
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "BGP recv %s from %s: group %016llx not found, dropping", group_subcmd_name(subcmd), from_conn->log_name, (unsigned long long)pkt_group_id);
queue_dgram_free(entry); queue_entry_free(entry); return;
}
DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP recv %s from %s len=%zu group=%016llx", group_subcmd_name(subcmd), from_conn->log_name, entry->len, (unsigned long long)pkt_group_id);
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "BGP recv %s from %s len=%zu group=%016llx", group_subcmd_name(subcmd), from_conn->log_name, entry->len, (unsigned long long)pkt_group_id);
if (subcmd == TOPO_SUBCMD_NODEINFO) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "BGP recv NODEINFO from=%s nid=%016llx ver=%d grp=%016llx", from_conn->log_name, (unsigned long long)((struct TOPOMSG_NODEINFO_PKT*)data)->node.node_id, ((struct TOPOMSG_NODEINFO_PKT*)data)->node.ver, (unsigned long long)((struct TOPOMSG_NODEINFO_PKT*)data)->node.group_id); }
if (subcmd == TOPO_SUBCMD_NODEINFO) { nodeinfo_dump_log(data, entry->len); topo_group_process_nodeinfo(group, from_conn, data, entry->len); }
else if (subcmd == TOPO_SUBCMD_WITHDRAW) topo_group_process_withdraw(group, from_conn, data, entry->len);
else if (subcmd == TOPO_SUBCMD_REQUEST_TABLE) topo_group_handle_request_table(group, from_conn);
else if (subcmd == TOPO_SUBCMD_TABLE_COMPLETE) { etcp_set_routing_exchange_state(from_conn, 3); DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP initial sync complete with %s", from_conn->log_name); }
else if (subcmd == TOPO_SUBCMD_TABLE_COMPLETE) { etcp_set_routing_exchange_state(from_conn, 3); DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP sync complete with %s: %d nodes grp=%016llx", from_conn->log_name, queue_entry_count(group->nodes), (unsigned long long)group->group_id); }
else if (subcmd == TOPO_SUBCMD_ERR_GROUP_MISMATCH) {
if (entry->len >= sizeof(struct TOPOMSG_ERR_GROUP_MISMATCH)) {
struct TOPOMSG_ERR_GROUP_MISMATCH* err = (struct TOPOMSG_ERR_GROUP_MISMATCH*)data;
@ -482,7 +482,7 @@ void topo_group_remove_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn) {
topo_group_connect_on_down(group, conn);
DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP peer removed: %s nodes=%d", conn->log_name, nodes_removed);
DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP peer removed: %s nodes=%d grp=%016llx", conn->log_name, nodes_removed, (unsigned long long)group->group_id);
}
@ -607,7 +607,7 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from
return 0;
}
DEBUG_INFO(DEBUG_CATEGORY_BGP, "NODEINFO: node=%016llx ver=%d v4s=%d v4a=%d v6s=%d v6a=%d hops=%d from=%s",
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "NODEINFO: node=%016llx ver=%d v4s=%d v4a=%d v6s=%d v6a=%d hops=%d from=%s",
(unsigned long long)node_id, new_ver, ni->local_v4_sockets, ni->local_v4_addrs,
ni->local_v6_sockets, ni->local_v6_addrs, ni->hop_count, from->log_name);
@ -631,7 +631,7 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from
}
{ int v4c = topo_list_count((struct _topo_head*)new_ni->v4_addrs);
int v6c = topo_list_count((struct _topo_head*)new_ni->v6_addrs);
DEBUG_INFO(DEBUG_CATEGORY_BGP, "NODEINFO deser: nid=%016llx v4a=%d v6a=%d from=%s",
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "NODEINFO deser: nid=%016llx v4a=%d v6a=%d from=%s",
(unsigned long long)node_id, v4c, v6c, from->log_name); }
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "NODEINFO deserialized: nid=%016llx new_ver=%d flags=0x%02x ed=%016llx",
(unsigned long long)node_id, new_ni->ver, new_ni->flags, *(uint64_t*)new_ni->ed25519_public_key);
@ -794,7 +794,7 @@ void topo_group_send_nodeinfo(struct TOPO_GROUP* group, struct TOPO_GROUP_NODE*
p[0] = ETCP_ID_TOPO_ENTRY; p[1] = TOPO_SUBCMD_NODEINFO;
struct TOPO_NODE* sni = topo_node_registry_find(group->instance->topo_groups, node->node_id);
if (!sni) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "send_nodeinfo: node %016llx NOT in registry — skip forward to %s", (unsigned long long)node->node_id, conn->log_name); u_free(p); return; }
if (!sni) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "send_nodeinfo: node %016llx NOT in registry — skip forward to %s", (unsigned long long)node->node_id, conn->log_name); u_free(p); return; }
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "send_nodeinfo: node %016llx ver=%d grp=%016llx to conn=%s", (unsigned long long)node->node_id, sni->ver, (unsigned long long)sni->group_id, conn->log_name);
int ser_len = topo_node_serialize(sni, node, p + 2, max_sz - 2, cumulative_rtt);
if (ser_len < 0) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "send_nodeinfo: serialize failed for node %016llx", (unsigned long long)node->node_id); u_free(p); return; }

20
src/routing_layer/topo_group_connect.c
Unescape View File

@ -82,7 +82,7 @@ int topo_group_connect_init(struct TOPO_GROUP* group) {
}
gc->phase = TGC_PHASE_ONE; gc->pending = count;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: ch=%s Phase 1 launching %d connects", TGC_ID, group->channel_id, count);
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase 1 launching %d connects ch=%s grp=%016llx", TGC_ID, count, group->channel_id, (unsigned long long)group->group_id);
for (int i = 0; i < count && gc->handle_count < TGC_MAX_HANDLES; i++) {
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "%s: Phase1 connect to 0x%016llx (%d/%d)", TGC_ID, (unsigned long long)ids[i], i + 1, count);
conn_mgr_open_invite(group->instance, group->group_id, NULL, ids[i], tgc_callback, gc,
@ -144,8 +144,8 @@ void topo_group_connect_on_up(struct TOPO_GROUP* group, struct ETCP_CONN* conn)
gc->active_conn_count++;
sqlite3* db = group->instance->topo_sqlite_db;
if (db) topo_node_sqlite_set_connected(db, group->channel_id, peer, 1);
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: UP peer=0x%016llx ch=%s active=%d",
TGC_ID, (unsigned long long)peer, group->channel_id, gc->active_conn_count);
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: UP peer=0x%016llx ch=%s grp=%016llx active=%d",
TGC_ID, (unsigned long long)peer, group->channel_id, (unsigned long long)group->group_id, gc->active_conn_count);
}
void topo_group_connect_on_down(struct TOPO_GROUP* group, struct ETCP_CONN* conn) {
@ -213,7 +213,7 @@ static void tgc_callback(struct CONN_MGR_HANDLE* h, uint64_t node_id, uint64_t g
case TGC_PHASE_ONE:
gc->pending--;
if (ok) gc->connected_count++;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase1 result node=0x%016llx %s pending=%d connected=%d",
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "%s: Phase1 result node=0x%016llx %s pending=%d connected=%d",
TGC_ID, (unsigned long long)node_id, ok ? "OK" : "FAIL", gc->pending, gc->connected_count);
break;
case TGC_PHASE_TWO:
@ -245,8 +245,6 @@ static void tgc_phase1_timeout(void* arg) {
struct TOPO_GROUP_CONNECT* gc = (struct TOPO_GROUP_CONNECT*)arg;
gc->phase_timer = NULL;
if (gc->phase != TGC_PHASE_ONE) return;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase1 timeout connected=%d pending=%d ch=%s",
TGC_ID, gc->connected_count, gc->pending, gc->group->channel_id);
sqlite3* db = gc->group->instance->topo_sqlite_db;
uint64_t* ids = NULL; int count = 0;
@ -284,17 +282,17 @@ static void tgc_phase2_try_next(struct TOPO_GROUP_CONNECT* gc) {
topo_node_sqlite_get_public_peers(db, gc->group->channel_id, &gc->candidate_ids, &gc->candidate_count,
gc->group->instance->node_id);
gc->cursor = 0;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase2 loaded %d public peers for ch=%s",
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "%s: Phase2 loaded %d public peers for ch=%s",
TGC_ID, gc->candidate_count, gc->group->channel_id);
}
while (gc->cursor < gc->candidate_count) {
uint64_t nid = gc->candidate_ids[gc->cursor++];
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase2 trying 0x%016llx (%d/%d)", TGC_ID,
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "%s: Phase2 trying 0x%016llx (%d/%d)", TGC_ID,
(unsigned long long)nid, gc->cursor, gc->candidate_count);
conn_mgr_open_invite(gc->group->instance, gc->group->group_id, NULL, nid, tgc_callback, gc, NULL);
return;
}
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase2 exhausted — no connections, ch=%s", TGC_ID, gc->group->channel_id);
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "%s: Phase2 exhausted — no connections, ch=%s", TGC_ID, gc->group->channel_id);
gc->phase = TGC_PHASE_THREE; gc->candidate_count = 0;
tgc_phase3_try_next(gc);
}
@ -310,12 +308,12 @@ static void tgc_phase3_try_next(struct TOPO_GROUP_CONNECT* gc) {
topo_node_sqlite_get_local_peers(db, gc->group->channel_id, &gc->candidate_ids, &gc->candidate_count,
gc->group->instance->node_id);
gc->cursor = 0;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase3 loaded %d local peers for ch=%s",
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "%s: Phase3 loaded %d local peers for ch=%s",
TGC_ID, gc->candidate_count, gc->group->channel_id);
}
while (gc->cursor < gc->candidate_count) {
uint64_t nid = gc->candidate_ids[gc->cursor++];
DEBUG_INFO(DEBUG_CATEGORY_BGP, "%s: Phase3 trying 0x%016llx (%d/%d)", TGC_ID,
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "%s: Phase3 trying 0x%016llx (%d/%d)", TGC_ID,
(unsigned long long)nid, gc->cursor, gc->candidate_count);
conn_mgr_open_invite(gc->group->instance, gc->group->group_id, NULL, nid, tgc_callback, gc, NULL);
return;

8
src/routing_layer/topo_node.c
Unescape View File

@ -760,8 +760,12 @@ int topo_group_update_my_nodeinfo(struct UTUN_INSTANCE* instance, struct TOPO_GR
lq->subnets = r;
}
DEBUG_INFO(DEBUG_CATEGORY_BGP, "my_nodeinfo updated: v4s=%d v4a=%d v6s=%d v6a=%d tcp4=%d tcp6=%d v4sub=%d v6sub=%d ver=%d",
sock_count, addr_count, sock6_count, addr6_count, tcp4_count, tcp6_count, vc, vc6, ni->ver);
if (group->group_type == TOPO_GROUP_TYPE_CHAT)
DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "my_nodeinfo updated: v4s=%d v4a=%d v6s=%d v6a=%d tcp4=%d tcp6=%d v4sub=%d v6sub=%d ver=%d grp=%016llx",
sock_count, addr_count, sock6_count, addr6_count, tcp4_count, tcp6_count, vc, vc6, ni->ver, (unsigned long long)group->group_id);
else
DEBUG_INFO(DEBUG_CATEGORY_BGP, "my_nodeinfo updated: v4s=%d v4a=%d v6s=%d v6a=%d tcp4=%d tcp6=%d v4sub=%d v6sub=%d ver=%d grp=%016llx",
sock_count, addr_count, sock6_count, addr6_count, tcp4_count, tcp6_count, vc, vc6, ni->ver, (unsigned long long)group->group_id);
if (group->group_type != TOPO_GROUP_TYPE_CHAT && instance->rt && !route_insert(instance->rt, lq))
DEBUG_WARN(DEBUG_CATEGORY_ROUTING, "failed to insert local routes");
} else {

2
src/routing_layer/topo_node_sqlite.c
Unescape View File

@ -674,7 +674,7 @@ struct TOPO_NODE* topo_node_sqlite_node_load(sqlite3* db, struct TOPO_GROUPS* gr
sqlite3_finalize(s);
}
}
if (!v4_head && !v6_head) { u_free(name); DEBUG_ERROR(DEBUG_CATEGORY_BGP, "node_load: node 0x%016llx has no addresses", (unsigned long long)node_id); return NULL; }
if (!v4_head && !v6_head) { u_free(name); DEBUG_WARN(DEBUG_CATEGORY_BGP, "node_load: node 0x%016llx has no addresses (may be stub/seed — will retry when addresses arrive)", (unsigned long long)node_id); return NULL; }
struct TOPO_NODE* ni = u_calloc(1, sizeof(struct TOPO_NODE));
if (!ni) { u_free(name); return NULL; }

16
src/transport_layer/etcp.c
Unescape View File

@ -218,6 +218,7 @@ struct ETCP_CONN* etcp_connection_create(struct UTUN_INSTANCE* instance, char* n
etcp->optimal_inflight=100000;
etcp->initialized=0;
etcp->links_up=0;
etcp->setup_start_tb = get_time_tb();
etcp->reset_done=0;
etcp->callbacks_running=0;
etcp->ref_count=0;
@ -306,7 +307,10 @@ void etcp_cbk_fire(struct ETCP_CONN* conn, int event) {
}
static void etcp_on_up(struct ETCP_CONN* etcp) {
DEBUG_INFO(DEBUG_CATEGORY_CONNECTION, "[%s] Connection UP (links_up=%d initialized=%d)", etcp->log_name, etcp->links_up, etcp->initialized);
int total_links = 0; for (struct ETCP_LINK* l = etcp->links; l; l = l->next) total_links++;
uint64_t elapsed_ms = (get_time_tb() - etcp->setup_start_tb) / 10;
DEBUG_INFO(DEBUG_CATEGORY_CONNECTION, "[%s] Connection UP (%d/%d links up, mtu=%d, setup=%llums, reinit=%u)",
etcp->log_name, etcp->links_up, total_links, etcp->mtu, (unsigned long long)elapsed_ms, etcp->reinit_count);
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_ON_UP_BEFORE: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x",
etcp->log_name,
etcp->crypto_ctx.session_key[0], etcp->crypto_ctx.session_key[1],
@ -549,7 +553,8 @@ void etcp_conn_reset(struct ETCP_CONN* etcp) {
} else {
DEBUG_TRACE(DEBUG_CATEGORY_ETCP, "links not up - skip on_down/on_up");
if (etcp->links_up) {
etcp->links_up=0;
etcp->links_up=0;
etcp->setup_start_tb = get_time_tb();
etcp_on_down(etcp);
}
}
@ -571,10 +576,11 @@ void etcp_links_reset(struct ETCP_CONN* etcp) {// Если сбой в обме
}
}
void etcp_conn_reinit(struct ETCP_CONN* etcp) {// Если сбой в обмене или ребутнулась одна из сторон -> необходимо заново переинициализировать соединение
DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] REINIT: initialized=%d links_up=%d reinit_count=%u tx_state=%d",
etcp->log_name, etcp->initialized, etcp->links_up, etcp->reinit_count, etcp->tx_state);
void etcp_conn_reinit(struct ETCP_CONN* etcp, const char* reason) {// Если сбой в обмене или ребутнулась одна из сторон -> необходимо заново переинициализировать соединение
DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] REINIT: %s (init=%d links=%d reinit=%u tx=%d)",
etcp->log_name, reason, etcp->initialized, etcp->links_up, etcp->reinit_count, etcp->tx_state);
etcp->setup_start_tb = get_time_tb();
etcp->reinit_count++;
etcp->reinit_pending = 1;
etcp->reset_done = 0;

3
src/transport_layer/etcp.h
Unescape View File

@ -198,6 +198,7 @@ struct ETCP_CONN {
// uint32_t bytes_received_total; // Not used
uint32_t retransmissions_count;
uint32_t reinit_count;
uint64_t setup_start_tb; // время начала/рестарта подключения (0.1ms)
uint32_t reset_count;
// uint32_t bytes_sent_norx; // сколько отправили байт без единого ответного пакета (для детекции запроса реконнекта)
@ -286,7 +287,7 @@ void etcp_conn_ref_free(struct ETCP_CONN* conn);
void etcp_conn_reset(struct ETCP_CONN* etcp);
void etcp_links_reset(struct ETCP_CONN* etcp);
void etcp_conn_reinit(struct ETCP_CONN* etcp);
void etcp_conn_reinit(struct ETCP_CONN* etcp, const char* reason);
void etcp_connection_ready(struct ETCP_CONN* etcp);// вызывается когда подключение инициализировано

30
src/transport_layer/etcp_connections.c
Unescape View File

@ -177,7 +177,10 @@ static void etcp_link_send_init(struct ETCP_LINK* link, uint8_t reset, uint8_t c
dgram->data_len = offset;
DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] INIT sent to %s (link=%d, retry=%d, reset=%d)", link->etcp->log_name, sockaddr_storage_to_str(&link->remote_addr).str, link->local_link_id, link->init_retry_count, reset);
if (link->init_retry_count == 0)
DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] INIT sent to %s (link=%d, retry=%d, reset=%d)", link->etcp->log_name, sockaddr_storage_to_str(&link->remote_addr).str, link->local_link_id, link->init_retry_count, reset);
else
DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "[%s] INIT sent to %s (link=%d, retry=%d, reset=%d)", link->etcp->log_name, sockaddr_storage_to_str(&link->remote_addr).str, link->local_link_id, link->init_retry_count, reset);
etcp_encrypt_send(dgram);
u_free(dgram);
@ -229,7 +232,7 @@ void etcp_link_enter_reinit(struct ETCP_LINK* link) {
etcp_fire_link_status_cbk(link, old_state, link->link_status);
etcp_on_link_down(link->etcp);
if (link->is_server != 0) return;
etcp_conn_reinit(link->etcp);
etcp_conn_reinit(link->etcp, "link recovery");
etcp_link_send_init(link,1,0);
if (link->keepalive_timer) {// keepalive заменяяется reinit запросами
@ -1005,6 +1008,9 @@ void etcp_link_close(struct ETCP_LINK* link) {
remove_link_from_queue(link);
etcp_conn_on_inflight_lim_changed(link->etcp);
DEBUG_INFO(DEBUG_CATEGORY_CONNECTION, "[%s] Link %d closed: rcvd=%zub ack=%llub infl=%ub/%upkt",
link->etcp->log_name, link->local_link_id, link->total_decrypted,
(unsigned long long)link->acked_bytes, link->inflight_bytes, link->inflight_packets);
u_free(link->bbr);
u_free(link);
}
@ -1596,7 +1602,7 @@ static int handle_init_response_client(struct ETCP_SOCKET* e_sock, struct ETCP_D
if (pkt_code == ETCP_INIT_RESPONSE && link->etcp->got_initial_pkt) {
DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] REINIT from client: INIT_RESPONSE(0x03) received, reinit conn=%p",
link->etcp->log_name, (void*)link->etcp);
etcp_conn_reinit(link->etcp);
etcp_conn_reinit(link->etcp, "server requested");
}
if (link->etcp->initialized == 0) {
@ -1699,7 +1705,8 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
// Try INIT decryption (for incoming connection requests)
// This handles: no link found, or link without session, or normal decrypt failed
if (recv_len <= SC_PUBKEY_ENC_SIZE + UDP_SC_HDR_SIZE) {
DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "packet too small for init, size=%zd from %s", recv_len, sockaddr_storage_to_str(&addr).str);
if (e_sock->pkt_format_errors < 2)
DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "packet too small for init, size=%zd from %s", recv_len, sockaddr_storage_to_str(&addr).str);
errorcode=1;
goto ec_fr;
}
@ -1732,8 +1739,8 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
link->etcp ? link->etcp->log_name : "null",
link->link_state,
link->etcp ? link->etcp->crypto_ctx.session_ready : -1);
} else {
DEBUG_ERROR(DEBUG_CATEGORY_CRYPTO,
} else if (e_sock->pkt_format_errors < 2) {
DEBUG_WARN(DEBUG_CATEGORY_CRYPTO,
"packet undecryptable (normal+init fail) from=%s — no link for this address",
sockaddr_storage_to_str(&addr).str);
}
@ -1952,7 +1959,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[%s] INIT collision=1 from peer=%016llx — remote is master, becoming slave",
conn->log_name, (unsigned long long)peer_id);
conn->session_id = session_id;
etcp_conn_reinit(conn);
etcp_conn_reinit(conn, "collision yield");
send_reset = 1;
} else {
// Check if WE have an outbound (master) link on this conn
@ -1976,7 +1983,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
/* Sync session_id; reset if remote is clean and we're dirty, or request reset if we're clean and remote is dirty */
conn->session_id = session_id;
if (req->code == ETCP_INIT_REQUEST) {
if (conn->got_initial_pkt) etcp_conn_reinit(conn);
if (conn->got_initial_pkt) etcp_conn_reinit(conn, "duplicate INIT");
send_reset = 0;
} else {
if (conn->got_initial_pkt == 0) send_reset = 1;
@ -2003,7 +2010,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[%s] INIT collision=1 from peer=%016llx — remote is master, becoming slave",
conn->log_name, (unsigned long long)peer_id);
conn->session_id = session_id;
etcp_conn_reinit(conn);
etcp_conn_reinit(conn, "collision yield");
send_reset = 1;
} else {
// Check if WE have an outbound (master) link
@ -2024,7 +2031,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
send_reset = 1;
DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] REINIT new link: code=0x%02x sess=%08x→%08x got_init=%d initialized=%d links_up=%d",
conn->log_name, code, conn->session_id, session_id, conn->got_initial_pkt, conn->initialized, conn->links_up);
etcp_conn_reinit(conn);
etcp_conn_reinit(conn, "session changed");
} }
}
link->keepalive_interval=(req->keepalive[0]<<8) | req->keepalive[1];
@ -2117,8 +2124,9 @@ process_decrypted:
return;
ec_fr:
DEBUG_ERROR(DEBUG_CATEGORY_ETCP, "error %d, from %s", errorcode, sockaddr_storage_to_str(&addr).str);
e_sock->pkt_format_errors++;
if (e_sock->pkt_format_errors < 3 || (e_sock->pkt_format_errors % 500 == 0))
DEBUG_WARN(DEBUG_CATEGORY_ETCP, "error %d, from %s (count=%zu)", errorcode, sockaddr_storage_to_str(&addr).str, e_sock->pkt_format_errors);
e_sock->errorcode=errorcode;
memory_pool_free(e_sock->instance->pkt_pool, pkt);
return;

4
src/transport_layer/etcp_dump.c
Unescape View File

@ -9,8 +9,8 @@
#include <stdio.h>
#include <string.h>
#define DLOG(fmt, ...) DEBUG_INFO(DEBUG_CATEGORY_DEBUG, " " fmt, ##__VA_ARGS__)
#define DHDR(fmt, ...) DEBUG_INFO(DEBUG_CATEGORY_DEBUG, fmt, ##__VA_ARGS__)
#define DLOG(fmt, ...) DEBUG_DEBUG(DEBUG_CATEGORY_ETCP_DUMP, " " fmt, ##__VA_ARGS__)
#define DHDR(fmt, ...) DEBUG_DEBUG(DEBUG_CATEGORY_ETCP_DUMP, fmt, ##__VA_ARGS__)
static void dump_queue(const char* name, struct ll_queue* q) {
if (!q) { DLOG("%-14s NULL", name); return; }

4
src/transport_layer/pkt_normalizer.c
Unescape View File

@ -364,7 +364,7 @@ static void pn_unpacker_cb(struct ll_queue* q, void* arg) {
// Incomplete header, reset
DEBUG_ERROR(DEBUG_CATEGORY_ETCP, "reset state");
// pn_unpacker_reset_state(pn);
etcp_conn_reinit(pn->etcp);
etcp_conn_reinit(pn->etcp, "normalizer desync");
break;
}
uint16_t part_size = payload[ptr] | (payload[ptr + 1] << 8);
@ -374,7 +374,7 @@ static void pn_unpacker_cb(struct ll_queue* q, void* arg) {
if (part_size<1 || part_size>16384) {
pn->logic_errors++;
DEBUG_ERROR(DEBUG_CATEGORY_ETCP, "PART_SIZE ERROR!!! %d", part_size);
etcp_conn_reinit(pn->etcp);
etcp_conn_reinit(pn->etcp, "bad fragment size");
break;
}

2
tests/test_etcp_reconnect.c
Unescape View File

@ -212,7 +212,7 @@ static void monitor(void* arg) {
printf("Server recreated (node_id=%llx)\n", (unsigned long long)server_instance->node_id);
// Force client to reinit — otherwise conn_ok stays true on old initialized=1
{ struct ll_entry* e = client_instance->connections->head;
while (e) { struct conn_queue_entry* ce = (struct conn_queue_entry*)e->data; etcp_conn_reinit(ce->conn); e = e->next; } }
while (e) { struct conn_queue_entry* ce = (struct conn_queue_entry*)e->data; etcp_conn_reinit(ce->conn, "test force reinit"); e = e->next; } }
restart_action_done = 1;
}
drain_received(0);

4
tests/test_pkt_normalizer_standalone.c
Unescape View File

@ -14,8 +14,8 @@
// Weak stub for etcp_conn_reinit — overridden if real ETCP is linked
// Weak stub for etcp_conn_reinit - can be overridden by real ETCP implementation
__attribute__((weak)) void etcp_conn_reinit(struct ETCP_CONN* etcp) {
(void)etcp;
__attribute__((weak)) void etcp_conn_reinit(struct ETCP_CONN* etcp, const char* reason) {
(void)etcp; (void)reason;
fprintf(stderr, "FAIL: etcp_conn_reinit called - ETCP not initialized in standalone test!\n");
exit(1);
}

Write Preview
Loading…
Cancel
Save