Убрал спам-логи ETCP SEND/RECV/DECRYPT OK + добавил диагностику синхронизации мемберов (DEBUG_CATEGORY_DEBUG) в ключевые точки topo_group, merkle_sync, member_sync, chat_sync

src/etcp_connections.c

@@ -971,9 +971,6 @@ int etcp_encrypt_send(struct ETCP_DGRAM* dgram) {
         DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "sendto failed, sock_err=%d dst=%s fd=%d",
                     socket_get_error(), sockaddr_storage_to_str(addr).str, dgram->link->conn->fd);
         dgram->link->send_errors++; errcode=4; goto es_err;
-    } else {
-            DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "ETCP SEND %zd bytes to %s fd=%d ne_len=%d", sent,
-                    sockaddr_storage_to_str(addr).str, dgram->link->conn->fd, dgram->noencrypt_len);
     }
     return (int)sent;
 es_err:
@@ -1542,10 +1539,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
     int errorcode=0;
 
     struct ETCP_LINK* link=etcp_link_find_by_addr(e_sock, &addr);
-            DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "RECV %zd bytes from %s link=%p session_ready=%d",
-                recv_len, sockaddr_storage_to_str(&addr).str, link,
-                link && link->etcp ? link->etcp->crypto_ctx.session_ready : -1);
-    
+
     // Try normal decryption first if we have an established link with session keys
     // This is the common case for data packets and responses
 //    if (link) {
@@ -1555,7 +1549,6 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
     if (link!=NULL && link->etcp!=NULL && link->etcp->crypto_ctx.session_ready) {
         sc_status_t dec_rc = sc_decrypt(&link->etcp->crypto_ctx, data, recv_len, (uint8_t*)&pkt->timestamp, &pkt_len);
         if (!dec_rc) {
-            DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "DECRYPT OK link=%p log=%s", link, link->etcp->log_name);
             goto process_decrypted;
         }
             DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "etcp: DECRYPT FAIL rc=%d link=%p log=%s session_ready=%d my_pub=%016llx peer_pub=%016llx", dec_rc, link, link->etcp->log_name, link->etcp->crypto_ctx.session_ready, *(uint64_t*)link->etcp->crypto_ctx.pk->public_key, *(uint64_t*)link->etcp->crypto_ctx.peer_public_key);

src/topo_group.c

@@ -364,7 +364,9 @@ void topo_group_new_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn) {
 
     struct TOPO_NODEQ* peer_nq = topo_node_find_by_id(group, conn->peer_node_id);
     topo_group_add_to_senders(group, conn);
-    if (peer_nq && peer_nq->alien) { DEBUG_INFO(DEBUG_CATEGORY_BGP, "peer 0x%016llx is alien, skipping route exchange", (unsigned long long)conn->peer_node_id); return; }
+    if (peer_nq && peer_nq->alien) { DEBUG_INFO(DEBUG_CATEGORY_BGP, "peer 0x%016llx is alien, skipping route exchange", (unsigned long long)conn->peer_node_id); DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "topo_group_new_conn: peer=%016llx group=%016llx type=%d ch=%s ALIEN=1 — SKIP", (unsigned long long)conn->peer_node_id, (unsigned long long)group->group_id, group->group_type, group->channel_id); return; }
+
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "topo_group_new_conn: peer=%016llx group=%016llx type=%d ch=%s alien=%d", (unsigned long long)conn->peer_node_id, (unsigned long long)group->group_id, group->group_type, group->channel_id, peer_nq ? peer_nq->alien : -1);
 
     struct ll_entry* entry = conn->instance->connections->head;
     while (entry) { struct conn_queue_entry* ce = (struct conn_queue_entry*)entry->data; struct ETCP_LINK* l = ce->conn->links; while (l) { if (l->initialized && l->conn && l->nat_check_status < NAT_CHECK_IN_PROGRESS) topo_group_start_link_nat_check(group, l); l = l->next; } entry = entry->next; }
@@ -558,6 +560,7 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from
     uint8_t new_ver = ni->ver;
 
     if (nodeinfo1 && (int8_t)(nodeinfo1->last_ver - new_ver) >= 0) {
+        DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "NODEINFO skip (stale ver): node=%016llx cur_ver=%d new_ver=%d from=%s", (unsigned long long)node_id, nodeinfo1->last_ver, new_ver, from->log_name);
         int new_hops = ni->hop_count + 1;
         if (new_hops <= MAX_HOPS) {
             uint64_t hop_list[MAX_HOPS];
@@ -639,12 +642,15 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from
         sqlite3* sdb = group->instance->topo_groups->topo_sqlite_db;
         if (sdb) {
             topo_node_sqlite_node_put(sdb, nodeinfo1);
-            if (group->group_type == TOPO_GROUP_TYPE_CHAT && group->channel_id[0])
+            if (group->group_type == TOPO_GROUP_TYPE_CHAT && group->channel_id[0]) {
                 topo_node_sqlite_member_put(sdb, group->channel_id, node_id, NULL, NULL);
+                DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "SQLite member_put: ch=%s node=%016llx", group->channel_id, (unsigned long long)node_id);
+            }
         }
     }
     if (group->instance->control_srv) control_server_notify_node_change(group->instance->control_srv, nodeinfo1);
 
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "node_updated_cb: node=%016llx has_cb=%d ch=%s type=%d", (unsigned long long)node_id, group->instance->topo_groups->node_updated_cb ? 1 : 0, group->channel_id, group->group_type);
     if (group->instance->topo_groups->node_updated_cb)
         group->instance->topo_groups->node_updated_cb(group->instance, node_id, ni->public_key, ni->ed25519_public_key);
 

tools/chatgui/transport/chat_sync.c

@@ -494,6 +494,8 @@ static void cs_on_conn_up(struct ETCP_CONN* conn, void* arg) {
     if (peer == 0 || peer == g_cs->inst->node_id) return;
     if (!conn->initialized) { DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: conn_up SKIP — not initialized peer=%016llx", CS_ID, (unsigned long long)peer); return; }
 
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: conn_up peer=%016llx pending_invite=%llu links_up=%d", CS_ID, (unsigned long long)peer, (unsigned long long)g_cs->pending_invite_ch_id, conn->links_up);
+
     if (g_cs->pending_invite_ch_id != 0 && !g_cs->info_req_timer) {
         DEBUG_INFO(DEBUG_CATEGORY_CONNECTIVITY, "%s: conn_up invite path peer=%016llx ch=%llu",
                    CS_ID, (unsigned long long)peer, (unsigned long long)g_cs->pending_invite_ch_id);

tools/chatgui/transport/member_sync.c

@@ -228,6 +228,7 @@ static void _on_node_updated(struct UTUN_INSTANCE* inst, uint64_t node_id,
     (void)x25519; (void)ed25519;
     if (!inst) return;
     sqlite3* db = _db(inst); if (!db) return;
+    int rc = 0;
     sqlite3_stmt* cs = NULL;
     if (sqlite3_prepare_v2(db, "SELECT channel_id FROM channels", -1, &cs, NULL) != SQLITE_OK) return;
     while (sqlite3_step(cs) == SQLITE_ROW) {
@@ -238,12 +239,15 @@ static void _on_node_updated(struct UTUN_INSTANCE* inst, uint64_t node_id,
         sqlite3_stmt* ps = NULL;
         if (sqlite3_prepare_v2(db, buf, -1, &ps, NULL) == SQLITE_OK) {
             sqlite3_bind_int64(ps, 1, (sqlite3_int64)node_id);
-            if (sqlite3_step(ps) == SQLITE_ROW)
+            if (sqlite3_step(ps) == SQLITE_ROW) {
                 merkle_sync_recompute_path(inst, ch, node_id);
+                rc++;
+            }
             sqlite3_finalize(ps);
         }
     }
     sqlite3_finalize(cs);
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: _on_node_updated node=%016llx channels_recomputed=%d", MS_ID, (unsigned long long)node_id, rc);
 }
 
 /* ──  Public API ── */
@@ -253,7 +257,7 @@ int member_sync_init(struct UTUN_INSTANCE* inst) {
     int rc = merkle_sync_init(inst, 0x31, &g_member_ops, inst);
     if (rc != 0) return rc;
     topo_groups_set_node_updated_cb(inst->topo_groups, _on_node_updated);
-    DEBUG_INFO(DEBUG_CATEGORY_CONNECTIVITY, "%s: initialized", MS_ID);
+    DEBUG_INFO(DEBUG_CATEGORY_CONNECTIVITY, "%s: initialized, merkle_rc=%d cb_registered=%d", MS_ID, rc, inst->topo_groups && inst->topo_groups->node_updated_cb ? 1 : 0);
     return 0;
 }
 

tools/chatgui/transport/merkle_sync.c

@@ -174,12 +174,12 @@ static int _get_level_hashes(struct merkle_sync* ms, const char* ns,
 /* ── Send helpers ── */
 
 static struct ETCP_CONN* ms_find_conn_for_node(struct UTUN_INSTANCE* inst, uint64_t node_id) {
-    if (!inst->connections) return NULL;
+    if (!inst->connections) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: find_conn — inst->connections is NULL", MS_ID); return NULL; }
     struct ll_entry* e = queue_find_data_by_index(inst->connections, (const uint8_t*)&node_id);
-    if (e) {
-        struct conn_queue_entry* ce = (struct conn_queue_entry*)e->data;
-        if (ce->conn->initialized && ce->conn->links_up) return ce->conn;
-    }
+    if (!e) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: find_conn — node=%016llx NOT FOUND in connections", MS_ID, (unsigned long long)node_id); return NULL; }
+    struct conn_queue_entry* ce = (struct conn_queue_entry*)e->data;
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: find_conn — node=%016llx found=%d initialized=%d links_up=%d", MS_ID, (unsigned long long)node_id, 1, ce->conn->initialized, ce->conn->links_up);
+    if (ce->conn->initialized && ce->conn->links_up) return ce->conn;
     return NULL;
 }
 
@@ -197,6 +197,7 @@ static int _send_msg(struct merkle_sync* ms, uint64_t peer,
     if (!conn) { DEBUG_ERROR(DEBUG_CATEGORY_CONNECTIVITY, "%s: no conn for node %016llx", MS_ID, (unsigned long long)peer); u_free(buf); queue_entry_free(entry); return -1; }
     int r = etcp_send(conn, entry);
     if (r != 0) { u_free(buf); queue_entry_free(entry); }
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: send OK peer=%016llx len=%zu rc=%d", MS_ID, (unsigned long long)peer, len, r);
     return r;
 }
 
@@ -601,6 +602,7 @@ int merkle_sync_start(struct UTUN_INSTANCE* inst, uint64_t peer,
     _ensure_table(ms);
 
     struct ms_session* s = _session_find(ms, peer, ns);
+    DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: start peer=%016llx ns=%s new=%d initialized=%d", MS_ID, (unsigned long long)peer, ns, s ? 0 : 1, ms->initialized);
     if (!s) {
         s = u_calloc(1, sizeof(*s));
         if (!s) return -1;