db_sync+chat_sync+etcp: fix conn init race, reduce keepalive log spam

- etcp_connections: keepalive SEND/RECV/DECRYPT_OK: DEBUG→TRACE; DECRYPT_FAIL: WARN→DEBUG
- db_sync_on_conn_up: skip sync if !conn->initialized, wait for next UP event
- db_sync peer_check_timer+instance_add: also check conn->initialized
- chat_sync cs_on_conn_up: ignore conn_up before initialized (cs_send fails otherwise)
- db_sync_on_conn_up log now includes init= and links=

src/db_sync.c

@@ -1207,13 +1207,14 @@ static void db_sync_on_conn_up(struct ETCP_CONN* conn, void* arg)
         if (!si->enabled)
             continue;
         struct SI_PEER* p = si_peer_add(si, pid);
-        if (p && p->synced == 0) {
+        if (p && p->synced == 0 && conn->initialized && conn->links_up) {
             p->synced = 1;
             db_sync_initiate_sync(si, pid);
         }
     }
     DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC,
-               "peer up %016llx", (unsigned long long)pid);
+               "peer up %016llx init=%d links=%d", (unsigned long long)pid,
+               conn->initialized, conn->links_up);
 }
 
 static void db_sync_on_conn_down(struct ETCP_CONN* conn, void* arg)
@@ -1309,7 +1310,7 @@ static void db_sync_peer_check_cb(void* arg)
             struct TOPO_GROUP_CONN_ITEM* item =
                 (struct TOPO_GROUP_CONN_ITEM*)e->data;
             if (item->conn && item->conn->peer_node_id != 0
-                && item->conn->links_up)
+                && item->conn->links_up && item->conn->initialized)
             {
                 uint64_t pid = item->conn->peer_node_id;
                 if (pid != db->inst->node_id) {
@@ -1583,7 +1584,7 @@ struct DB_SYNC_INSTANCE* db_sync_instance_add(struct UTUN_INSTANCE* inst,
         while (conn) {
             uint64_t pid = conn->peer_node_id;
             if (pid != 0 && pid != inst->node_id
-                && conn->links_up > 0)
+                && conn->links_up > 0 && conn->initialized)
             {
                 struct SI_PEER* p = si_peer_add(si, pid);
                 if (p && p->synced == 0) {

src/etcp_connections.c

@@ -973,7 +973,7 @@ int etcp_encrypt_send(struct ETCP_DGRAM* dgram) {
                     socket_get_error(), sockaddr_storage_to_str(addr).str, dgram->link->conn->fd);
         dgram->link->send_errors++; errcode=4; goto es_err;
     } else {
-        DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "ETCP SEND %zd bytes to %s fd=%d ne_len=%d", sent,
+            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;
@@ -1544,7 +1544,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_DEBUG(DEBUG_CATEGORY_DEBUG, "RECV %zd bytes from %s link=%p session_ready=%d",
+            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);
     
@@ -1557,10 +1557,10 @@ 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_DEBUG(DEBUG_CATEGORY_DEBUG, "DECRYPT OK link=%p log=%s", link, link->etcp->log_name);
+            DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "DECRYPT OK link=%p log=%s", link, link->etcp->log_name);
             goto process_decrypted;
         }
-        DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "DECRYPT FAIL link=%p log=%s rc=%d — trying init decrypt", link, link->etcp->log_name, dec_rc);
+            DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "DECRYPT FAIL link=%p log=%s rc=%d — trying init decrypt", link, link->etcp->log_name, dec_rc);
     } else {
         DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "SKIP normal decrypt: link=%p session_ready=%d — trying init decrypt",
                     link, link && link->etcp ? link->etcp->crypto_ctx.session_ready : -1);

tools/chatgui/transport/chat_sync.c

@@ -487,6 +487,7 @@ static void cs_on_conn_up(struct ETCP_CONN* conn, void* arg) {
     if (!conn || !g_cs) return;
     uint64_t peer = conn->peer_node_id;
     if (peer == 0 || peer == g_cs->inst->node_id) return;
+    if (!conn->initialized) return;
 
     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",