From b48d3b4a77223a2ed9901a6d3a7f509893a22c80 Mon Sep 17 00:00:00 2001 From: Evgeny Date: Thu, 23 Jul 2026 16:47:22 +0300 Subject: [PATCH] db_sync: add diagnostic logs for message sync debugging during join MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - db_handle_init_sync: TRACE→INFO with peer_cnt/my_cnt/tp_offset - db_handle_send_data: detailed batch info (range, remaining count) - db_sync_initiate_sync: add table name to log - db_sync_on_conn_up: add first table name to summary log --- src/db_sync.c | 20 ++++++++++++-------- 1 file changed, 12 insertions(+), 8 deletions(-) diff --git a/src/db_sync.c b/src/db_sync.c index b3f524db..beae8525 100644 --- a/src/db_sync.c +++ b/src/db_sync.c @@ -604,7 +604,7 @@ static void db_handle_init_sync(struct DB_SYNC_INSTANCE* si, uint64_t src, const if (len < 4) { DEBUG_ERROR(DEBUG_CATEGORY_DB_SYNC, "INIT_SYNC too short %zu from %016llx", len, (unsigned long long)src); return; } uint32_t pc = *(uint32_t*)p; uint32_t mc = db_count(si); - DEBUG_TRACE(DEBUG_CATEGORY_DB_SYNC, "from=%016llx peer_cnt=%u my=%u tbl=%s", (unsigned long long)src, pc, mc, SI_TBL(si)); + DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "INIT_SYNC from=%016llx peer_cnt=%u my_cnt=%u tbl=%s → tp_offset=%u", (unsigned long long)src, pc, mc, SI_TBL(si), (pc < mc ? pc : mc)); uint32_t tp = (pc < mc ? pc : mc); if (tp > 0) tp--; @@ -943,12 +943,15 @@ static void db_handle_send_data(struct DB_SYNC_INSTANCE* si, uint64_t src, const if (mc > pk && sp && sp->sync_state == 1) { uint32_t scnt = mc - pk; if (scnt > DB_SEND_DATA_MAX) scnt = DB_SEND_DATA_MAX; - DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "send_data continue to %016llx from=%u cnt=%u mc=%u", - (unsigned long long)src, pk, scnt, mc); + DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "db_sync SEND_DATA batch: %u records [%u..%u/%u] → still %u remaining", + received, from, from + received - 1, mc, mc - pk); si_send_data_batch(si, src, pk, scnt, 1); } else if (mc > pk) { - DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "send_data stopping to %016llx — mc=%u pk=%u state=%d", - (unsigned long long)src, mc, pk, sp ? sp->sync_state : -1); + DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "db_sync SEND_DATA batch: %u records [%u..%u/%u] — stopping (state=%d)", + received, from, from + received - 1, mc, sp ? sp->sync_state : -1); + } else { + DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "db_sync SEND_DATA batch: %u records [%u..%u/%u] — all caught up (state=%d)", + received, from, from + received - 1, mc, sp ? sp->sync_state : -1); } uint32_t nc = db_count(si); @@ -1162,9 +1165,10 @@ static void db_sync_on_conn_up(struct ETCP_CONN* conn, void* arg) synced++; } DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, - "conn_up peer=%016llx init=%d links=%d instances=%d synced=%d skipped_state=%d skipped_not_ready=%d", + "conn_up peer=%016llx init=%d links=%d instances=%d synced=%d skipped_state=%d skipped_not_ready=%d tbls=[%s]", (unsigned long long)pid, conn->initialized, conn->links_up, - db->instance_count, synced, skipped_state, skipped_not_ready); + db->instance_count, synced, skipped_state, skipped_not_ready, + (synced > 0 && db->instance_count > 0) ? db->instances[0].table_name : "none"); } static void db_sync_on_conn_down(struct ETCP_CONN* conn, void* arg) @@ -1208,7 +1212,7 @@ static void db_sync_initiate_sync(struct DB_SYNC_INSTANCE* si, uint64_t pid) msg[0] = DB_MSG_INIT_SYNC; memcpy(msg + 1, &mc, 4); db_sync_send(si, pid, msg, 5); - DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "INIT_SYNC -> %016llx my=%u", (unsigned long long)pid, mc); + DEBUG_INFO(DEBUG_CATEGORY_DB_SYNC, "INIT_SYNC → %016llx my=%u tbl=%s", (unsigned long long)pid, mc, SI_TBL(si)); } static void db_verify_chain(struct DB_SYNC_INSTANCE* si)