diff --git a/lib/debug_config.c b/lib/debug_config.c index ab1e5dac..95e88f1b 100644 --- a/lib/debug_config.c +++ b/lib/debug_config.c @@ -114,6 +114,7 @@ static const struct { {"routing", DEBUG_CATEGORY_ROUTING}, {"timers", DEBUG_CATEGORY_TIMERS}, {"bgp", DEBUG_CATEGORY_BGP}, + {"chat", DEBUG_CATEGORY_CHAT}, {"socket", DEBUG_CATEGORY_SOCKET}, {"control", DEBUG_CATEGORY_CONTROL}, {"dump", DEBUG_CATEGORY_DUMP}, @@ -122,6 +123,7 @@ static const struct { {"general", DEBUG_CATEGORY_GENERAL}, {"nat", DEBUG_CATEGORY_NAT}, {"keepalive", DEBUG_CATEGORY_KEEPALIVE}, + {"media", DEBUG_CATEGORY_MEDIA}, {"etcp_route", DEBUG_CATEGORY_ETCPROUTE}, {"etcp_dump", DEBUG_CATEGORY_ETCP_DUMP}, {"chat_sync", DEBUG_CATEGORY_CHAT_SYNC}, diff --git a/lib/debug_config.h b/lib/debug_config.h index 31f3560d..e0baa12d 100644 --- a/lib/debug_config.h +++ b/lib/debug_config.h @@ -61,9 +61,9 @@ typedef int debug_category_t; #define DEBUG_CATEGORY_NAT 20 // EIM NAT module #define DEBUG_CATEGORY_KEEPALIVE 21 // Keepalive periodic monitoring only #define DEBUG_CATEGORY_ETCPROUTE 22 // ETCP routing -// #define DEBUG_CATEGORY_BBR 23 (merged into ETCP) +#define DEBUG_CATEGORY_MEDIA 23 // Media delivery + media async #define DEBUG_CATEGORY_ETCP_DUMP 24 // ETCP packet dump -// #define DEBUG_CATEGORY_CONNECTIVITY 25 (unused, removed) +#define DEBUG_CATEGORY_CHAT 25 // Chat modules (chat_core, whisper, etc.) #define DEBUG_CATEGORY_CHAT_SYNC 26 // Message DB sync (INIT_SYNC, PUSH, chain hash, recalc) #define DEBUG_CATEGORY_MEMBER_SYNC 27 // Member + address + merkle sync #define DEBUG_CATEGORY_PROXY 28 // Proxy modules (SOCKS5, TCP, UDP, ICMP) diff --git a/lib/u_async.c b/lib/u_async.c index ad966594..b87b99d7 100644 --- a/lib/u_async.c +++ b/lib/u_async.c @@ -560,7 +560,7 @@ void* uasync_set_timeout(struct UASYNC* ua, int timeout_tb, void* arg, timeout_c node->expiration_ms = timeval_to_ms(&now); if (name && strncmp(name, "ncd_connect", 11) == 0) { uint64_t exp_tb = (uint64_t)now.tv_sec * 10000ULL + (uint64_t)now.tv_usec / 100ULL; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[uasync] set_timeout: name=%s tb=%d now_tb=%llu exp_tb=%llu exp_ms=%llu delta_tb=%llu", + DEBUG_DEBUG(DEBUG_CATEGORY_TIMERS, "[uasync] set_timeout: name=%s tb=%d now_tb=%llu exp_tb=%llu exp_ms=%llu delta_tb=%llu", name, timeout_tb, (unsigned long long)now_tb, (unsigned long long)exp_tb, (unsigned long long)node->expiration_ms, (unsigned long long)(exp_tb - now_tb)); } diff --git a/src/chat/chat_event.c b/src/chat/chat_event.c index e92d678a..b246eaab 100644 --- a/src/chat/chat_event.c +++ b/src/chat/chat_event.c @@ -39,6 +39,6 @@ void chat_event_post(int type, const uint8_t* data, int len) { [24]="MEMBER_UPDATED", [25]="MEMBER_REMOVED", }; const char* n = (type >= 1 && type <= 25) ? names[type] : "?"; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "chat_event: %s(%d) data=%d bytes", n, type, len); - if (data && len > 0) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DEBUG, " ", data, len); + DEBUG_DEBUG(DEBUG_CATEGORY_CHAT, "chat_event: %s(%d) data=%d bytes", n, type, len); + if (data && len > 0) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CHAT, " ", data, len); } diff --git a/src/chat/chat_whisper.c b/src/chat/chat_whisper.c index 63084ddc..d5ca26db 100644 --- a/src/chat/chat_whisper.c +++ b/src/chat/chat_whisper.c @@ -64,12 +64,12 @@ static int read_u32_le(FILE* f, uint32_t* v) { return fread(v, 4, 1, f) == 1; } static struct wav_pcm* wav_read(const char* path) { FILE* f = fopen(path, "rb"); - if (!f) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: cannot open %s", CW_ID, path); return NULL; } + if (!f) { DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: cannot open %s", CW_ID, path); return NULL; } char riff[4], wave[4]; - if (fread(riff, 1, 4, f) != 4 || memcmp(riff, "RIFF", 4) != 0) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: no RIFF header", CW_ID); return NULL; } + if (fread(riff, 1, 4, f) != 4 || memcmp(riff, "RIFF", 4) != 0) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: no RIFF header", CW_ID); return NULL; } uint32_t file_size; read_u32_le(f, &file_size); - if (fread(wave, 1, 4, f) != 4 || memcmp(wave, "WAVE", 4) != 0) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: no WAVE", CW_ID); return NULL; } + if (fread(wave, 1, 4, f) != 4 || memcmp(wave, "WAVE", 4) != 0) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: no WAVE", CW_ID); return NULL; } uint16_t audio_format = 0, channels = 0; uint32_t sample_rate = 0, byte_rate = 0, data_size = 0; @@ -93,10 +93,10 @@ static struct wav_pcm* wav_read(const char* path) { } } - if (audio_format != 1) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: not PCM (fmt=%u)", CW_ID, audio_format); return NULL; } - if (channels < 1 || channels > 2) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: bad channels %u", CW_ID, channels); return NULL; } - if (bits_per_sample != 16) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: not 16-bit PCM", CW_ID); return NULL; } - if (sample_rate < 8000 || sample_rate > 48000) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: bad sample_rate %u", CW_ID, sample_rate); return NULL; } + if (audio_format != 1) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: not PCM (fmt=%u)", CW_ID, audio_format); return NULL; } + if (channels < 1 || channels > 2) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: bad channels %u", CW_ID, channels); return NULL; } + if (bits_per_sample != 16) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: not 16-bit PCM", CW_ID); return NULL; } + if (sample_rate < 8000 || sample_rate > 48000) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: bad sample_rate %u", CW_ID, sample_rate); return NULL; } int frame_size = (int)(bits_per_sample / 8) * channels; int total_frames = (int)(data_size / frame_size); @@ -117,7 +117,7 @@ static struct wav_pcm* wav_read(const char* path) { } fclose(f); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: wav_read %s: %d samples %dHz mono", CW_ID, path, pcm->n_samples, pcm->sample_rate); + DEBUG_DEBUG(DEBUG_CATEGORY_CHAT, "%s: wav_read %s: %d samples %dHz mono", CW_ID, path, pcm->n_samples, pcm->sample_rate); return pcm; } @@ -139,16 +139,16 @@ struct opus_pcm { static struct opus_pcm* opus_read(const char* path) { FILE* f = fopen(path, "rb"); - if (!f) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: cannot open %s", CW_ID, path); return NULL; } + if (!f) { DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: cannot open %s", CW_ID, path); return NULL; } char magic[4]; if (fread(magic, 1, 4, f) != 4 || memcmp(magic, "OPUS", 4) != 0) { fclose(f); return NULL; } uint32_t sr, ch; - if (fread(&sr, 4, 1, f) != 1 || fread(&ch, 4, 1, f) != 1) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: bad opus header", CW_ID); return NULL; } + if (fread(&sr, 4, 1, f) != 1 || fread(&ch, 4, 1, f) != 1) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: bad opus header", CW_ID); return NULL; } opus_codec_decoder_t* dec = opus_codec_decoder_create((int)sr, (int)ch); - if (!dec) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: opus decoder create failed", CW_ID); return NULL; } + if (!dec) { fclose(f); DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: opus decoder create failed", CW_ID); return NULL; } int frame_samples = (int)sr * 20 / 1000; size_t alloc_samples = 0; @@ -190,7 +190,7 @@ static struct opus_pcm* opus_read(const char* path) { pcm->samples = buffer; pcm->n_samples = total_samples; pcm->sample_rate = (int)sr; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: opus_read %s: %d samples %dHz", CW_ID, path, total_samples, (int)sr); + DEBUG_DEBUG(DEBUG_CATEGORY_CHAT, "%s: opus_read %s: %d samples %dHz", CW_ID, path, total_samples, (int)sr); return pcm; } @@ -253,12 +253,12 @@ static void wh_work_fn(void* raw) { struct wh_work_ctx* w = (struct wh_work_ctx*)raw; #ifndef HAVE_WHISPER - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: whisper not compiled in", CW_ID); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: whisper not compiled in", CW_ID); w->err = -1; return; #else if (!g_whisper_ctx) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: whisper not initialized", CW_ID); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: whisper not initialized", CW_ID); w->err = -1; return; } @@ -282,7 +282,7 @@ static void wh_work_fn(void* raw) { } if (!pcm_samples || pcm_n <= 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: cannot decode %s", CW_ID, w->job.audio_path); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: cannot decode %s", CW_ID, w->job.audio_path); w->err = -1; return; } @@ -292,12 +292,12 @@ static void wh_work_fn(void* raw) { float* samples_16k = resample_16k(pcm_samples, pcm_n, pcm_rate, &n_16k); u_free(pcm_samples); if (!samples_16k || n_16k <= 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: resample failed", CW_ID); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: resample failed", CW_ID); w->err = -1; return; } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: %d samples @ 16kHz, running whisper_full", CW_ID, n_16k); + DEBUG_DEBUG(DEBUG_CATEGORY_CHAT, "%s: %d samples @ 16kHz, running whisper_full", CW_ID, n_16k); /* 3. Whisper */ struct whisper_full_params wparams = whisper_full_default_params(WHISPER_SAMPLING_GREEDY); @@ -310,7 +310,7 @@ static void wh_work_fn(void* raw) { u_free(samples_16k); if (ret != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: whisper_full failed ret=%d", CW_ID, ret); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: whisper_full failed ret=%d", CW_ID, ret); w->err = -1; return; } @@ -318,7 +318,7 @@ static void wh_work_fn(void* raw) { /* 4. Collect text */ int n_seg = whisper_full_n_segments(g_whisper_ctx); if (n_seg <= 0) { - DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: whisper returned no segments", CW_ID); + DEBUG_WARN(DEBUG_CATEGORY_CHAT, "%s: whisper returned no segments", CW_ID); w->text = u_strdup(""); } else { size_t total = 0; @@ -333,7 +333,7 @@ static void wh_work_fn(void* raw) { const char* seg = whisper_full_get_segment_text(g_whisper_ctx, i); if (seg) strcat(w->text, seg); } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: transcribed [%s]", CW_ID, w->text); + DEBUG_INFO(DEBUG_CATEGORY_CHAT, "%s: transcribed [%s]", CW_ID, w->text); } } @@ -375,7 +375,7 @@ static int find_model_path(char* out, size_t out_sz) { /* если путь относительный, не проверяем доступ — вернём как есть */ if (access(setting, R_OK) == 0) { snprintf(out, out_sz, "%s", setting); return 0; } /* если задан явно но не доступен — ошибка */ - DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: model_path from setting not accessible: %s", CW_ID, setting); + DEBUG_WARN(DEBUG_CATEGORY_CHAT, "%s: model_path from setting not accessible: %s", CW_ID, setting); } const char* search_paths[] = { @@ -402,31 +402,31 @@ int chat_whisper_init(void) { g_initialized = 1; #ifndef HAVE_WHISPER - DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: compiled without whisper support", CW_ID); + DEBUG_WARN(DEBUG_CATEGORY_CHAT, "%s: compiled without whisper support", CW_ID); return -1; #else if (!chat_setting_get_int("whisper_enabled", 0)) { - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: whisper disabled in settings", CW_ID); + DEBUG_INFO(DEBUG_CATEGORY_CHAT, "%s: whisper disabled in settings", CW_ID); return -1; } char model_path[512]; if (find_model_path(model_path, sizeof(model_path)) != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: model not found (set whisper_model_path)", CW_ID); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: model not found (set whisper_model_path)", CW_ID); return -1; } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: loading model %s..." , CW_ID, model_path); + DEBUG_INFO(DEBUG_CATEGORY_CHAT, "%s: loading model %s..." , CW_ID, model_path); struct whisper_context_params cparams = whisper_context_default_params(); cparams.use_gpu = 0; g_whisper_ctx = whisper_init_from_file_with_params(model_path, cparams); if (!g_whisper_ctx) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: whisper_init_from_file failed for %s", CW_ID, model_path); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: whisper_init_from_file failed for %s", CW_ID, model_path); return -1; } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: model loaded successfully", CW_ID); + DEBUG_INFO(DEBUG_CATEGORY_CHAT, "%s: model loaded successfully", CW_ID); g_chat_whisper_trigger = chat_whisper_transcribe_async; return 0; #endif /* HAVE_WHISPER */ @@ -445,7 +445,7 @@ void chat_whisper_destroy(void) { if (g_whisper_ctx) { whisper_free(g_whisper_ctx); g_whisper_ctx = NULL; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: model unloaded", CW_ID); + DEBUG_INFO(DEBUG_CATEGORY_CHAT, "%s: model unloaded", CW_ID); } #endif /* отменяем ожидающие задачи */ @@ -472,7 +472,7 @@ static void chat_whisper_transcribe_async_impl( chat_whisper_done_fn done_cb, void* done_arg) { if (!audio_path || !channel_id || !done_cb || !ma || !ua) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "%s: invalid args", CW_ID); + DEBUG_ERROR(DEBUG_CATEGORY_CHAT, "%s: invalid args", CW_ID); if (done_cb) done_cb(done_arg, channel_id ? channel_id : "", NULL, -1, reply_to_ts, reply_to_node); return; } @@ -480,7 +480,7 @@ static void chat_whisper_transcribe_async_impl( if (!chat_whisper_available()) { int rc = chat_whisper_init(); if (rc != 0) { - DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: whisper not available, skip transcription", CW_ID); + DEBUG_WARN(DEBUG_CATEGORY_CHAT, "%s: whisper not available, skip transcription", CW_ID); done_cb(done_arg, channel_id, NULL, -1, reply_to_ts, reply_to_node); return; } @@ -499,7 +499,7 @@ static void chat_whisper_transcribe_async_impl( g_pending_job->done_arg = done_arg; g_pending_job->ma = ma; g_pending_job->ua = ua; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: queued transcription for ch=%s", CW_ID, channel_id); + DEBUG_DEBUG(DEBUG_CATEGORY_CHAT, "%s: queued transcription for ch=%s", CW_ID, channel_id); return; } @@ -519,6 +519,6 @@ static void chat_whisper_transcribe_async_impl( w->ua = ua; w->err = 0; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: starting transcription ch=%s file=%s", CW_ID, channel_id, audio_path); + DEBUG_INFO(DEBUG_CATEGORY_CHAT, "%s: starting transcription ch=%s file=%s", CW_ID, channel_id, audio_path); media_async_submit(ma, ua, wh_work_fn, w, wh_done_fn, w); } diff --git a/src/media_async/media_async.c b/src/media_async/media_async.c index ce4cad75..0e7336e9 100644 --- a/src/media_async/media_async.c +++ b/src/media_async/media_async.c @@ -42,7 +42,7 @@ struct media_async* media_async_create(void) { struct media_async* ma = u_malloc(sizeof(*ma)); if (!ma) return NULL; ma->initialized = 1; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "media_async: created"); + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "media_async: created"); return ma; } @@ -50,7 +50,7 @@ void media_async_destroy(struct media_async* ma) { if (!ma) return; ma->initialized = 0; u_free(ma); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "media_async: destroyed"); + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "media_async: destroyed"); } void media_async_submit(struct media_async* ma, struct UASYNC* ua, @@ -71,7 +71,7 @@ void media_async_submit(struct media_async* ma, struct UASYNC* ua, pthread_t tid; int rc = pthread_create(&tid, NULL, ma_thread_entry, ctx); if (rc != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_async: pthread_create failed rc=%d", rc); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_async: pthread_create failed rc=%d", rc); u_free(ctx); done(arg, -1); return; @@ -83,7 +83,7 @@ void media_async_submit(struct media_async* ma, struct UASYNC* ua, int ma_sha256_file(const char* path, uint8_t hash_out[32]) { FILE* f = fopen(path, "rb"); - if (!f) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "ma_sha256_file: cannot open %s", path); return -1; } + if (!f) { DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "ma_sha256_file: cannot open %s", path); return -1; } SHA256_CTX ctx; SHA256_Init(&ctx); @@ -99,13 +99,13 @@ int ma_sha256_file(const char* path, uint8_t hash_out[32]) { int ma_sign_block(const uint8_t* ed25519_privkey, const uint8_t* data, size_t len, uint8_t sig_out[64]) { EVP_PKEY* pkey = EVP_PKEY_new_raw_private_key(EVP_PKEY_ED25519, NULL, ed25519_privkey, 32); - if (!pkey) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "ma_sign_block: EVP_PKEY_new_raw_private_key failed"); return -1; } + if (!pkey) { DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "ma_sign_block: EVP_PKEY_new_raw_private_key failed"); return -1; } EVP_MD_CTX* mdctx = EVP_MD_CTX_new(); if (!mdctx) { EVP_PKEY_free(pkey); return -1; } if (EVP_DigestSignInit(mdctx, NULL, NULL, NULL, pkey) != 1) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "ma_sign_block: EVP_DigestSignInit failed"); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "ma_sign_block: EVP_DigestSignInit failed"); EVP_MD_CTX_free(mdctx); EVP_PKEY_free(pkey); return -1; } @@ -115,7 +115,7 @@ int ma_sign_block(const uint8_t* ed25519_privkey, const uint8_t* data, size_t le EVP_PKEY_free(pkey); if (rc != 1 || siglen != 64) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "ma_sign_block: EVP_DigestSign failed rc=%d len=%zu", rc, siglen); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "ma_sign_block: EVP_DigestSign failed rc=%d len=%zu", rc, siglen); return -1; } return 0; @@ -126,16 +126,16 @@ int ma_copy_file(const char* src, const char* dst) { if (strcmp(src, dst) == 0) return 0; FILE* s = fopen(src, "rb"); - if (!s) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "ma_copy_file: cannot open src %s", src); return -1; } + if (!s) { DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "ma_copy_file: cannot open src %s", src); return -1; } FILE* d = fopen(dst, "wb"); - if (!d) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "ma_copy_file: cannot create dst %s", dst); fclose(s); return -1; } + if (!d) { DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "ma_copy_file: cannot create dst %s", dst); fclose(s); return -1; } uint8_t buf[65536]; size_t rd; while ((rd = fread(buf, 1, sizeof(buf), s)) > 0) { if (fwrite(buf, 1, rd, d) != rd) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "ma_copy_file: write error at %s", dst); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "ma_copy_file: write error at %s", dst); fclose(s); fclose(d); return -1; } } diff --git a/src/media_delivery/media_delivery.c b/src/media_delivery/media_delivery.c index 1e0b6eaf..75eb5c10 100644 --- a/src/media_delivery/media_delivery.c +++ b/src/media_delivery/media_delivery.c @@ -106,7 +106,7 @@ static int md_ba_complete_block(sqlite3* db, const uint8_t* block_uuid, int exists = (sqlite3_step(st) == SQLITE_ROW); sqlite3_finalize(st); if (exists) { - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: ba_complete_block: completed already exists for node=0x%016llx, skipping", + DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "%s: ba_complete_block: completed already exists for node=0x%016llx, skipping", MD_ID, (unsigned long long)node_id); return 0; } @@ -293,7 +293,7 @@ int md_file_load_inc(struct media_delivery_ctx* md, const uint8_t* media_id, uin if (fl->active_downloads < 10) fl->downloader_ids[fl->active_downloads] = node_id; fl->active_downloads++; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: file_load inc media=%02x%02x... node=0x%016llx count=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "%s: file_load inc media=%02x%02x... node=0x%016llx count=%d", MD_ID, media_id[0], media_id[1], (unsigned long long)node_id, fl->active_downloads); return fl->active_downloads; } @@ -311,7 +311,7 @@ void md_file_load_dec(struct media_delivery_ctx* md, const uint8_t* media_id, ui break; } } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: file_load dec media=%02x%02x... node=0x%016llx count=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "%s: file_load dec media=%02x%02x... node=0x%016llx count=%d", MD_ID, media_id[0], media_id[1], (unsigned long long)node_id, fl->active_downloads); /* remove entry when count reaches 0 */ if (fl->active_downloads == 0 && md->file_loads) { @@ -386,7 +386,7 @@ static void md_super_repl_send(struct media_delivery_ctx* md, struct media_super if (md_send(md->inst, TOPO_GROUP_UTUN, peer->peer_node_id, pkt, (size_t)off) == 0) { peer->inflight_count++; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: SUPER_REPL sent to 0x%016llx seq=%u entries=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "%s: SUPER_REPL sent to 0x%016llx seq=%u entries=%d", MD_ID, (unsigned long long)peer->peer_node_id, seq, num_entries); } else { DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "%s: SUPER_REPL send failed to 0x%016llx", @@ -442,7 +442,7 @@ static void md_handle_serve_reg(struct media_delivery_ctx* md, uint64_t from_nod uint8_t ack[9] = { MEDIA_SUBCMD_SERVE_ACK, 0, 0 }; memcpy(ack + 1, &pkt->group_id, 8); (void)from_node; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: SERVE_REG node=0x%016llx group=%016llx", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: SERVE_REG node=0x%016llx group=%016llx", MD_ID, (unsigned long long)from_node, (unsigned long long)pkt->group_id); } @@ -492,7 +492,7 @@ static void md_handle_query(struct media_delivery_ctx* md, uint64_t from_node, uint16_t nc = (uint16_t)count; memcpy(resp + num_pos, &nc, 2); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: QUERY from 0x%016llx → %d entries (super=%d)", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: QUERY from 0x%016llx → %d entries (super=%d)", MD_ID, (unsigned long long)from_node, count, md->is_supernode); md_send(md->inst, TOPO_GROUP_UTUN, from_node, resp, (size_t)off); } @@ -515,7 +515,7 @@ static void md_handle_have_block(struct media_delivery_ctx* md, uint64_t from_no md_send(md->inst, TOPO_GROUP_UTUN, from_node, ack, sizeof(ack)); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: HAVE_BLOCK from 0x%016llx rc=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: HAVE_BLOCK from 0x%016llx rc=%d", MD_ID, (unsigned long long)from_node, rc); if (rc == 0) { @@ -541,11 +541,11 @@ static void md_handle_block_processing(struct media_delivery_ctx* md, uint64_t f /* INSERT processing (status=0) with new id */ int rc = md_ba_insert(md->db, hb->block_id, hb->group_id, from_node, hb->chunk, hb->timestamp, 0); if (rc != 0) { - DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_PROCESSING insert failed for node=0x%016llx (duplicate/constraint?)", + DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_PROCESSING insert failed for node=0x%016llx (duplicate/constraint?)", MD_ID, (unsigned long long)from_node); } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_PROCESSING from 0x%016llx block=%02x%02x...", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_PROCESSING from 0x%016llx block=%02x%02x...", MD_ID, (unsigned long long)from_node, hb->block_id[0], hb->block_id[1]); /* replicate to connected super-peers */ @@ -602,7 +602,7 @@ static void md_handle_super_repl(struct media_delivery_ctx* md, uint64_t from_no sa->ack_seq = (uint32_t)max_id; md_send(md->inst, TOPO_GROUP_UTUN, from_node, ack, sizeof(ack)); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: SUPER_REPL from 0x%016llx entries=%d max_id=%lld", + DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "%s: SUPER_REPL from 0x%016llx entries=%d max_id=%lld", MD_ID, (unsigned long long)from_node, num, (long long)max_id); } @@ -612,13 +612,13 @@ static void md_handle_super_ack(struct media_delivery_ctx* md, uint64_t from_nod struct media_pkt_super_ack* sa = (struct media_pkt_super_ack*)data; struct media_super_peer* peer = md_super_peer_find(md, from_node); - if (!peer) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: SUPER_ACK from unknown peer 0x%016llx", MD_ID, (unsigned long long)from_node); return; } + if (!peer) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: SUPER_ACK from unknown peer 0x%016llx", MD_ID, (unsigned long long)from_node); return; } peer->peer_last_recv_id = sa->ack_seq; peer->inflight_count--; peer->timeout_tb = MEDIA_REPL_TIMEOUT_TB; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: SUPER_ACK from 0x%016llx seq=%u inflight=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "%s: SUPER_ACK from 0x%016llx seq=%u inflight=%d", MD_ID, (unsigned long long)from_node, sa->ack_seq, peer->inflight_count); md_super_repl_send(md, peer); @@ -644,7 +644,7 @@ static void md_handle_super_hello(struct media_delivery_ctx* md, uint64_t from_n resp.last_recv_id = my_last_recv; md_send(md->inst, TOPO_GROUP_UTUN, from_node, (const uint8_t*)&resp, sizeof(resp)); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: SUPER_HELLO from 0x%016llx (peer_last_recv=%lld, my_last_recv=%lld)", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: SUPER_HELLO from 0x%016llx (peer_last_recv=%lld, my_last_recv=%lld)", MD_ID, (unsigned long long)from_node, (long long)sh->last_recv_id, (long long)my_last_recv); /* start replication */ @@ -677,7 +677,7 @@ static void md_super_conn_cb(struct CONN_MGR_HANDLE* h, uint64_t node_id, uint64 hello.last_recv_id = my_last; if (md_send(md->inst, TOPO_GROUP_UTUN, node_id, (const uint8_t*)&hello, sizeof(hello)) == 0) { - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: SUPER_HELLO sent to 0x%016llx last_recv=%lld", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: SUPER_HELLO sent to 0x%016llx last_recv=%lld", MD_ID, (unsigned long long)node_id, (long long)my_last); } else { DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "%s: SUPER_HELLO send failed to 0x%016llx", @@ -755,7 +755,7 @@ static void stream_send_chunk_cb(struct ll_queue* q, void* arg) { media_delivery_stream_done(md->inst); fclose(sc->file); u_free(sc); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_DONE sent chunk=%d total=%u", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_DONE sent chunk=%d total=%u", MD_ID, sc->chunk, bd->total_size); } else { /* continue streaming — register waiter for backpressure */ @@ -839,7 +839,7 @@ static void md_handle_block_req(struct media_delivery_ctx* md, uint64_t from_nod struct media_pkt_block_req* req = (struct media_pkt_block_req*)data; uint64_t group_id = req->group_id ? req->group_id : TOPO_GROUP_UTUN; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_REQ from 0x%016llx group=%016llx block=%02x%02x... active_streams=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_REQ from 0x%016llx group=%016llx block=%02x%02x... active_streams=%d", MD_ID, (unsigned long long)from_node, (unsigned long long)group_id, req->block_id[0], req->block_id[1], md->active_streams); int limit_reached = md->active_streams >= MD_MAX_STREAMS; @@ -864,7 +864,7 @@ static void md_handle_block_req(struct media_delivery_ctx* md, uint64_t from_nod struct TOPO_GROUP* grp = topo_groups_find(md->inst->topo_groups, group_id); if (!grp) grp = topo_groups_get_default(md->inst->topo_groups); if (grp && grp->conn_mgr) { - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: no direct conn to 0x%016llx — connecting via conn_mgr", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: no direct conn to 0x%016llx — connecting via conn_mgr", MD_ID, (unsigned long long)from_node); conn_mgr_open_invite(grp->instance, grp->group_id, NULL, from_node, NULL, NULL, NULL); } @@ -889,7 +889,7 @@ static void md_handle_block_req(struct media_delivery_ctx* md, uint64_t from_nod rc->downstream[dsi].group_id = group_id; rc->downstream[dsi].sent_offset = 0; memset(&rc->downstream[dsi].waiter, 0, sizeof(rc->downstream[dsi].waiter)); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: relay downstream[%d] added node=0x%016llx file_offset=%llu", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: relay downstream[%d] added node=0x%016llx file_offset=%llu", MD_ID, dsi, (unsigned long long)from_node, (unsigned long long)rc->file_offset); md_relay_catchup(md, rc, from_node, group_id, dsi); md->active_streams--; return; @@ -907,7 +907,7 @@ static void md_handle_block_req(struct media_delivery_ctx* md, uint64_t from_nod memcpy(rfp + roff, &rc->downstream[i].node_id, 8); roff += 8; } md_send(md->inst, group_id, from_node, rfp, (size_t)roff); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: relay full for block=%02x%02x..., sent %d downstream nodes to 0x%016llx", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: relay full for block=%02x%02x..., sent %d downstream nodes to 0x%016llx", MD_ID, req->block_id[0], req->block_id[1], rc->downstream_count, (unsigned long long)from_node); } else { DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "%s: BLOCK_REQ block_id=%02x%02x... not found in media_files", @@ -968,7 +968,7 @@ static void md_handle_block_req(struct media_delivery_ctx* md, uint64_t from_nod memcpy(rfp + roff, &fl->downloader_ids[i], 8); roff += 8; } md_send(md->inst, group_id, from_node, rfp, (size_t)roff); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: source at capacity (%d/%d) for media=%02x%02x..., redirecting to %d nodes", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: source at capacity (%d/%d) for media=%02x%02x..., redirecting to %d nodes", MD_ID, fl->active_downloads, md->max_downloads_per_file, req->media_id[0], req->media_id[1], fl->active_downloads); fclose(f); @@ -991,7 +991,7 @@ static void md_handle_block_req(struct media_delivery_ctx* md, uint64_t from_nod sc->block_start = (uint64_t)block_start; sc->block_data_len = (size_t)block_length; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: streaming file=%s chunk=%d start=%lld len=%lld group=%016llx to 0x%016llx", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: streaming file=%s chunk=%d start=%lld len=%lld group=%016llx to 0x%016llx", MD_ID, path, chunk, (long long)block_start, (long long)block_length, (unsigned long long)group_id, (unsigned long long)from_node); md->streams_started++; /* monotonic — for test admission checks */ @@ -1009,7 +1009,7 @@ static void md_handle_block_relay_full(struct media_delivery_ctx* md, uint64_t f uint16_t nrn = rf->num_relay_nodes; if (nrn > MD_MAX_RELAY_DOWNSTREAM) nrn = MD_MAX_RELAY_DOWNSTREAM; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: RELAY_FULL from 0x%016llx block=%02x%02x... nodes=%u", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: RELAY_FULL from 0x%016llx block=%02x%02x... nodes=%u", MD_ID, (unsigned long long)from_node, rf->block_id[0], rf->block_id[1], nrn); /* forward to media_download layer to retry from one of the listed nodes */ @@ -1045,7 +1045,7 @@ static void md_super_connect(struct media_delivery_ctx* md, uint64_t peer_node_i return; } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: connecting to supernode 0x%016llx", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: connecting to supernode 0x%016llx", MD_ID, (unsigned long long)peer_node_id); conn_mgr_open_invite(grp->instance, grp->group_id, NULL, peer_node_id, md_super_conn_cb, md, NULL); } @@ -1189,7 +1189,7 @@ static void md_etcp_recv(struct ETCP_CONN* conn, struct ll_entry* entry) { struct UTUN_INSTANCE* inst = conn->instance; if (!inst) return; struct media_delivery_ctx* md = &inst->md; - if (!md->initialized) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: recv before init", MD_ID); return; } + if (!md->initialized) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: recv before init", MD_ID); return; } const uint8_t* data = entry->dgram; size_t len = entry->len; @@ -1200,7 +1200,7 @@ static void md_etcp_recv(struct ETCP_CONN* conn, struct ll_entry* entry) { data += 1; len -= 1; uint64_t from_node = conn->peer_node_id; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "%s: recv %s(%02x) from 0x%016llx len=%zu", + DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "%s: recv %s(%02x) from 0x%016llx len=%zu", MD_ID, md_subcmd_name(subcmd), subcmd, (unsigned long long)from_node, len); switch (subcmd) { @@ -1208,7 +1208,7 @@ static void md_etcp_recv(struct ETCP_CONN* conn, struct ll_entry* entry) { md_handle_serve_reg(md, from_node, data, len); break; case MEDIA_SUBCMD_SERVE_LEAVE: - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: SERVE_LEAVE from 0x%016llx", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: SERVE_LEAVE from 0x%016llx", MD_ID, (unsigned long long)from_node); if (md->served_nodes) { struct ll_entry* e = queue_find_data_by_index(md->served_nodes, &from_node); @@ -1223,19 +1223,19 @@ static void md_etcp_recv(struct ETCP_CONN* conn, struct ll_entry* entry) { break; case MEDIA_SUBCMD_BLOCK_PROCESSING: if (md->is_supernode) md_handle_block_processing(md, from_node, data, len); - else DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_PROCESSING ignored — not supernode", MD_ID); + else DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_PROCESSING ignored — not supernode", MD_ID); break; case MEDIA_SUBCMD_SUPER_REPL: if (md->is_supernode) md_handle_super_repl(md, from_node, data, len); - else DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: SUPER_REPL ignored — not supernode", MD_ID); + else DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: SUPER_REPL ignored — not supernode", MD_ID); break; case MEDIA_SUBCMD_SUPER_ACK: if (md->is_supernode) md_handle_super_ack(md, from_node, data, len); - else DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: SUPER_ACK ignored — not supernode", MD_ID); + else DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: SUPER_ACK ignored — not supernode", MD_ID); break; case MEDIA_SUBCMD_SUPER_HELLO: if (md->is_supernode) md_handle_super_hello(md, from_node, data, len); - else DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: SUPER_HELLO ignored — not supernode", MD_ID); + else DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: SUPER_HELLO ignored — not supernode", MD_ID); break; case MEDIA_SUBCMD_QUERY_RESP: media_download_handle_query_resp(inst, data, len); @@ -1264,7 +1264,7 @@ static void md_etcp_recv(struct ETCP_CONN* conn, struct ll_entry* entry) { /* TODO: handle cancel from remote */ break; default: - DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: unknown subcmd 0x%02x from 0x%016llx", + DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: unknown subcmd 0x%02x from 0x%016llx", MD_ID, subcmd, (unsigned long long)from_node); } } diff --git a/src/media_delivery/media_download.c b/src/media_delivery/media_download.c index cbf3e266..c213e7b9 100644 --- a/src/media_delivery/media_download.c +++ b/src/media_delivery/media_download.c @@ -86,7 +86,7 @@ static int md_dl_send_block_req(struct UTUN_INSTANCE* inst, uint64_t dst, req.chunk = (uint32_t)chunk_idx; req.offset = 0; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_REQ to 0x%016llx group=%016llx bi=%d dl->num_blocks=%d block_id=%02x%02x%02x%02x...", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_REQ to 0x%016llx group=%016llx bi=%d dl->num_blocks=%d block_id=%02x%02x%02x%02x...", MDL_ID, (unsigned long long)dst, (unsigned long long)dl->group_id, peer_local_bi, dl->num_blocks, block_id[0], block_id[1], block_id[2], block_id[3]); return md_dl_send(inst, dst, (const uint8_t*)&req, sizeof(req)); @@ -142,7 +142,7 @@ static void md_dl_send_have_block(struct UTUN_INSTANCE* inst, struct media_downl return; } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: HAVE_BLOCK to super 0x%016llx block=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: HAVE_BLOCK to super 0x%016llx block=%d", MDL_ID, (unsigned long long)super, bi); md_dl_send(inst, super, (const uint8_t*)&hb, sizeof(hb)); } @@ -172,7 +172,7 @@ static void md_dl_send_block_processing(struct UTUN_INSTANCE* inst, struct media return; } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_PROCESSING to super 0x%016llx block=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_PROCESSING to super 0x%016llx block=%d", MDL_ID, (unsigned long long)super, bi); md_dl_send(inst, super, (const uint8_t*)&hb, sizeof(hb)); } @@ -182,7 +182,7 @@ static void md_dl_send_block_processing(struct UTUN_INSTANCE* inst, struct media void md_dl_conn_cb(struct CONN_MGR_HANDLE* h, uint64_t node_id, uint64_t group_id, enum conn_mgr_event event, void* arg) { struct media_download* dl = (struct media_download*)arg; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: conn_cb event=%d node=0x%016llx dl=%p active=%d num_peers=%d num_blocks=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: conn_cb event=%d node=0x%016llx dl=%p active=%d num_peers=%d num_blocks=%d", MDL_ID, event, (unsigned long long)node_id, (void*)dl, dl->active, dl->num_peers, dl->num_blocks); if (event != CONN_EVENT_UP) { DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "%s: connect to 0x%016llx failed rc=%d", @@ -194,12 +194,12 @@ void md_dl_conn_cb(struct CONN_MGR_HANDLE* h, uint64_t node_id, uint64_t group_i if (dl->peers[pi].node_id == node_id) { dl->peers[pi].connected = 1; dl->peers[pi].cm_handle = h; /* store for close on completion */ - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: matched peer[%d] num_blocks=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: matched peer[%d] num_blocks=%d", MDL_ID, pi, dl->peers[pi].num_blocks); for (int bi = 0; bi < dl->peers[pi].num_blocks; bi++) { if (!dl->peers[pi].blocks[bi].started) { dl->peers[pi].blocks[bi].started = 1; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: conn_cb BLOCK_REQ: peer-local bi=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: conn_cb BLOCK_REQ: peer-local bi=%d", MDL_ID, bi); md_dl_start_block(dl->inst, node_id, dl, dl->peers[pi].blocks[bi].block_id, bi, bi); break; @@ -264,7 +264,7 @@ static void md_dl_send_query(struct UTUN_INSTANCE* inst, struct media_download* q->num_blocks = (uint16_t)dl->num_blocks; memcpy(pkt + MEDIA_QUERY_HDR_SIZE, dl->block_ids, (size_t)dl->num_blocks * 16); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: QUERY to super 0x%016llx blocks=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: QUERY to super 0x%016llx blocks=%d", MDL_ID, (unsigned long long)super, dl->num_blocks); md_dl_send(inst, super, pkt, pkt_len); u_free(pkt); @@ -295,7 +295,7 @@ void media_download_handle_query_resp(struct UTUN_INSTANCE* inst, qe = qe->next; } } - if (!dl) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: QUERY_RESP — no matching download", MDL_ID); return; } + if (!dl) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: QUERY_RESP — no matching download", MDL_ID); return; } dl->num_peers = 0; @@ -320,16 +320,16 @@ void media_download_handle_query_resp(struct UTUN_INSTANCE* inst, } } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: QUERY_RESP entries=%d peers=%d dl=%p num_blocks=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: QUERY_RESP entries=%d peers=%d dl=%p num_blocks=%d", MDL_ID, ne, dl->num_peers, (void*)dl, dl->num_blocks); for (int pi = 0; pi < dl->num_peers; pi++) { - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: peer[%d] node=0x%016llx num_blocks=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: peer[%d] node=0x%016llx num_blocks=%d", MDL_ID, pi, (unsigned long long)dl->peers[pi].node_id, dl->peers[pi].num_blocks); } /* if no peers found, try querying the author directly */ if (dl->num_peers == 0 && dl->author_node_id && dl->author_node_id != inst->node_id) { - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: no holders from supernode, querying author 0x%016llx", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: no holders from supernode, querying author 0x%016llx", MDL_ID, (unsigned long long)dl->author_node_id); dl->super_nodes[0] = dl->author_node_id; dl->super_count = 1; @@ -349,14 +349,14 @@ void media_download_handle_query_resp(struct UTUN_INSTANCE* inst, for (int pi = 0; pi < dl->num_peers; pi++) { dl->peers[pi].connected = 1; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: peer[%d] route: grp=%p conn_mgr=%p", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: peer[%d] route: grp=%p conn_mgr=%p", MDL_ID, pi, (void*)grp, grp ? (void*)grp->conn_mgr : NULL); if (grp && grp->conn_mgr) { int cm_rc = conn_mgr_open_invite(inst, grp->group_id, NULL, dl->peers[pi].node_id, md_dl_conn_cb, dl, NULL); if (cm_rc != 0) DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "%s: conn_mgr_open_invite failed rc=%d for 0x%016llx", MDL_ID, cm_rc, (unsigned long long)dl->peers[pi].node_id); } else for (int bi = 0; bi < dl->peers[pi].num_blocks; bi++) { - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: direct BLOCK_REQ: peer-local bi=%d peer_num_blocks=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: direct BLOCK_REQ: peer-local bi=%d peer_num_blocks=%d", MDL_ID, bi, dl->peers[pi].num_blocks); md_dl_start_block(inst, dl->peers[pi].node_id, dl, dl->peers[pi].blocks[bi].block_id, bi, bi); } @@ -372,14 +372,14 @@ void media_download_handle_chunk(struct UTUN_INSTANCE* inst, const uint8_t* d = data; struct media_pkt_block_chunk* ch = (struct media_pkt_block_chunk*)data; struct media_download* dl = md_dl_find(inst, ch->media_id); - if (!dl) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: CHUNK for unknown media %02x%02x...", MDL_ID, ch->media_id[0], ch->media_id[1]); return; } - if (!dl->active) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: CHUNK for inactive download", MDL_ID); return; } + if (!dl) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: CHUNK for unknown media %02x%02x...", MDL_ID, ch->media_id[0], ch->media_id[1]); return; } + if (!dl->active) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: CHUNK for inactive download", MDL_ID); return; } int bi = -1; for (int i = 0; i < dl->num_blocks; i++) { if (memcmp(dl->block_ids + i * 16, ch->block_id, 16) == 0) { bi = i; break; } } - if (bi < 0) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: CHUNK for unknown block %02x%02x...", MDL_ID, ch->block_id[0], ch->block_id[1]); return; } + if (bi < 0) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: CHUNK for unknown block %02x%02x...", MDL_ID, ch->block_id[0], ch->block_id[1]); return; } char tmp[2048]; snprintf(tmp, sizeof(tmp), "%s.chunk_%d", dl->dest_path, bi); @@ -389,7 +389,7 @@ void media_download_handle_chunk(struct UTUN_INSTANCE* inst, if (len >= MEDIA_BLOCK_CHUNK_HDR_SIZE + wlen) { fwrite(d + MEDIA_BLOCK_CHUNK_HDR_SIZE, 1, wlen, f); } else { - DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: CHUNK truncated: len=%zu need=%zu+%zu", + DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: CHUNK truncated: len=%zu need=%zu+%zu", MDL_ID, len, (size_t)MEDIA_BLOCK_CHUNK_HDR_SIZE, (size_t)wlen); } fclose(f); @@ -439,14 +439,14 @@ void media_download_handle_done(struct UTUN_INSTANCE* inst, const uint8_t* d = data; struct media_pkt_block_done* bd = (struct media_pkt_block_done*)data; struct media_download* dl = md_dl_find(inst, bd->media_id); - if (!dl) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_DONE for unknown media", MDL_ID); return; } - if (!dl->active) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_DONE for inactive download", MDL_ID); return; } + if (!dl) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_DONE for unknown media", MDL_ID); return; } + if (!dl->active) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_DONE for inactive download", MDL_ID); return; } int bi = -1; for (int i = 0; i < dl->num_blocks; i++) { if (memcmp(dl->block_ids + i * 16, bd->block_id, 16) == 0) { bi = i; break; } } - if (bi < 0) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_DONE for unknown block", MDL_ID); return; } + if (bi < 0) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_DONE for unknown block", MDL_ID); return; } /* verify block data: Ed25519 signature from author, or size-only fallback */ int sig_ok = 0; @@ -492,7 +492,7 @@ void media_download_handle_done(struct UTUN_INSTANCE* inst, if (sig_ok) { dl->blocks_received++; dl->blocks_validated++; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_DONE block=%d total=%d/%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_DONE block=%d total=%d/%d", MDL_ID, bi, dl->blocks_validated, dl->num_blocks); if (dl->progress_cb) dl->progress_cb(dl->progress_arg, dl->blocks_validated, dl->num_blocks); @@ -513,7 +513,7 @@ void media_download_handle_done(struct UTUN_INSTANCE* inst, rd.chunk = (uint32_t)bi; rd.total_size = (uint32_t)rc->file_offset; md_dl_send(inst, rc->downstream[i].node_id, (const uint8_t*)&rd, sizeof(rd)); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: relay BLOCK_DONE forwarded to 0x%016llx block=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: relay BLOCK_DONE forwarded to 0x%016llx block=%d", MDL_ID, (unsigned long long)rc->downstream[i].node_id, bi); } md_relay_remove(&inst->md, dl->block_ids + bi * 16); @@ -527,7 +527,7 @@ void media_download_handle_done(struct UTUN_INSTANCE* inst, for (int bk = 0; bk < dl->peers[pi].num_blocks; bk++) { if (!dl->peers[pi].blocks[bk].started) { dl->peers[pi].blocks[bk].started = 1; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: BLOCK_DONE → next req: peer[%d] bi=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: BLOCK_DONE → next req: peer[%d] bi=%d", MDL_ID, pi, bk); md_dl_start_block(inst, dl->peers[pi].node_id, dl, dl->peers[pi].blocks[bk].block_id, bk, bk); @@ -712,13 +712,13 @@ void media_download_handle_relay_full(struct UTUN_INSTANCE* inst, const uint8_t* media_id, const uint8_t* block_id, uint32_t chunk, const uint64_t* node_ids, int num_nodes) { struct media_download* dl = md_dl_find(inst, media_id); - if (!dl || !dl->active) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: RELAY_FULL — no active download", MDL_ID); return; } + if (!dl || !dl->active) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: RELAY_FULL — no active download", MDL_ID); return; } int bi = -1; for (int i = 0; i < dl->num_blocks; i++) { if (memcmp(dl->block_ids + i * 16, block_id, 16) == 0) { bi = i; break; } } - if (bi < 0) { DEBUG_WARN(DEBUG_CATEGORY_DEBUG, "%s: RELAY_FULL — unknown block", MDL_ID); return; } + if (bi < 0) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "%s: RELAY_FULL — unknown block", MDL_ID); return; } /* try each listed node — if already a peer, retry block; otherwise add new */ for (int ni = 0; ni < num_nodes && ni < MD_MAX_RELAY_DOWNSTREAM; ni++) { @@ -732,7 +732,7 @@ void media_download_handle_relay_full(struct UTUN_INSTANCE* inst, if (memcmp(dl->peers[found_pi].blocks[bj].block_id, block_id, 16) == 0) { dl->peers[found_pi].blocks[bj].started = 0; dl->peers[found_pi].blocks[bj].received = 0; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: RELAY_FULL → retry existing peer[%d] node=0x%016llx bi=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: RELAY_FULL → retry existing peer[%d] node=0x%016llx bi=%d", MDL_ID, found_pi, (unsigned long long)node_ids[ni], bj); md_dl_start_block(inst, node_ids[ni], dl, block_id, (int)chunk, bj); return; @@ -746,7 +746,7 @@ void media_download_handle_relay_full(struct UTUN_INSTANCE* inst, dl->peers[found_pi].blocks[nb].received = 0; dl->peers[found_pi].blocks[nb].validated = 0; dl->peers[found_pi].num_blocks++; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: RELAY_FULL → add block to existing peer[%d] bi=%d", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: RELAY_FULL → add block to existing peer[%d] bi=%d", MDL_ID, found_pi, nb); md_dl_start_block(inst, node_ids[ni], dl, block_id, (int)chunk, nb); return; @@ -762,7 +762,7 @@ void media_download_handle_relay_full(struct UTUN_INSTANCE* inst, dl->peers[pi].blocks[0].received = 0; dl->peers[pi].blocks[0].validated = 0; dl->num_peers++; - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "%s: RELAY_FULL → new peer[%d] node=0x%016llx", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "%s: RELAY_FULL → new peer[%d] node=0x%016llx", MDL_ID, pi, (unsigned long long)node_ids[ni]); md_dl_start_block(inst, node_ids[ni], dl, block_id, (int)chunk, 0); break; diff --git a/src/media_delivery/media_index.c b/src/media_delivery/media_index.c index 2b09266b..ac635c6f 100644 --- a/src/media_delivery/media_index.c +++ b/src/media_delivery/media_index.c @@ -30,7 +30,7 @@ static int mi_insert(sqlite3* db, sqlite3_stmt* stmt = NULL; if (sqlite3_prepare_v2(db, sql, -1, &stmt, NULL) != SQLITE_OK) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_index: insert prep fail: %s", sqlite3_errmsg(db)); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_index: insert prep fail: %s", sqlite3_errmsg(db)); return -1; } sqlite3_bind_blob(stmt, 1, media_id, 16, SQLITE_STATIC); @@ -50,7 +50,7 @@ static int mi_insert(sqlite3* db, sqlite3_finalize(stmt); if (rc != SQLITE_DONE) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_index: insert fail rc=%d: %s", rc, sqlite3_errmsg(db)); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_index: insert fail rc=%d: %s", rc, sqlite3_errmsg(db)); return -1; } return 0; @@ -78,7 +78,7 @@ int media_index_init(sqlite3* db) { char* err = NULL; int rc = sqlite3_exec(db, sql, NULL, NULL, &err); if (rc != SQLITE_OK) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_index: CREATE TABLE failed: %s", err ? err : "?"); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_index: CREATE TABLE failed: %s", err ? err : "?"); sqlite3_free(err); return -1; } @@ -99,7 +99,7 @@ int media_index_init(sqlite3* db) { "CREATE INDEX IF NOT EXISTS idx_media_files_content_hash ON media_files(content_hash);", NULL, NULL, NULL); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "media_index: table+indices created"); + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "media_index: table+indices created"); return 0; } @@ -157,19 +157,19 @@ int media_index_commit(sqlite3* db, const struct media_index_result* result, uint8_t node_sign[64]; if (ma_sign_block(ed25519_privkey, sig_msg, soff, node_sign) != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_index: node_sign failed chunk=%d", n); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_index: node_sign failed chunk=%d", n); return -1; } if (mi_insert(db, result->media_id, result->block_ids + n * 16, result->content_hash, chat_id, location, node_id, node_sign, ts, fs, cs, n, off) != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_index: insert failed chunk=%d", n); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_index: insert failed chunk=%d", n); return -1; } } - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "media_index: committed %d chunks for chat=%s path=%s", + DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "media_index: committed %d chunks for chat=%s path=%s", nb, chat_id, rel); return 0; } @@ -199,7 +199,7 @@ static void mi_reg_work(void* data) { struct mi_reg_ctx* ctx = (struct mi_reg_ctx*)data; if (ctx->copy_file && ma_copy_file(ctx->src_path, ctx->dest_path) != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_index: copy failed %s -> %s", ctx->src_path, ctx->dest_path); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_index: copy failed %s -> %s", ctx->src_path, ctx->dest_path); ctx->err = -10; return; } @@ -272,7 +272,7 @@ void media_index_register_async( void* cb_arg) { if (!ma || !ua || !db || !ed25519_privkey || !chat_id || !src_path || !dest_path || !media_base || !cb) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "media_index: register_async invalid args"); + DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "media_index: register_async invalid args"); if (cb) cb(cb_arg, -1, NULL); return; } diff --git a/src/routing_layer/conn_mgr_core.c b/src/routing_layer/conn_mgr_core.c index 2fafcc43..a2cb6111 100644 --- a/src/routing_layer/conn_mgr_core.c +++ b/src/routing_layer/conn_mgr_core.c @@ -1052,7 +1052,7 @@ inv_cancel_free: void cm_invite_fail(struct cm_invite_pending* inv) { if (!inv) return; if (inv->cancelled) { DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "cm_invite_fail: IGNORED — already cancelled node=0x%016llx", (unsigned long long)inv->node_id); return; } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "cm_invite_fail: node=0x%016llx state=%d conn=%p", + DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "cm_invite_fail: node=0x%016llx state=%d conn=%p", (unsigned long long)inv->node_id, (int)inv->state, (void*)inv->invite_conn); conn_mgr_cb_t cb = inv->cb; diff --git a/src/routing_layer/topo_group.c b/src/routing_layer/topo_group.c index b1ac4529..daf724a2 100644 --- a/src/routing_layer/topo_group.c +++ b/src/routing_layer/topo_group.c @@ -172,8 +172,7 @@ static void topo_group_receive_cbk(struct ETCP_CONN* from_conn, struct ll_entry* queue_dgram_free(entry); queue_entry_free(entry); return; } - 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); } + DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "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); @@ -312,7 +311,7 @@ struct TOPO_GROUPS* topo_groups_init(struct UTUN_INSTANCE* instance) { sqlite3_exec(instance->topo_sqlite_db, "PRAGMA mmap_size=134217728", NULL, NULL, NULL); sqlite3_exec(instance->topo_sqlite_db, "PRAGMA temp_store=MEMORY", NULL, NULL, NULL); topo_node_sqlite_init(instance->topo_sqlite_db); - DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "SQLite opened: %s rc=%d db=%p", db_file, rc, (void*)instance->topo_sqlite_db); + DEBUG_INFO(DEBUG_CATEGORY_GENERAL, "SQLite opened: %s rc=%d db=%p", db_file, rc, (void*)instance->topo_sqlite_db); } else { DEBUG_ERROR(DEBUG_CATEGORY_BGP, "sqlite3_open(%s) failed: %s", db_file, instance->topo_sqlite_db ? sqlite3_errmsg(instance->topo_sqlite_db) : "null db"); @@ -457,7 +456,7 @@ void topo_group_new_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn) { } topo_group_add_to_senders(group, conn); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "topo_group_new_conn: peer=%016llx group=%016llx type=%d ch=%s", (unsigned long long)conn->peer_node_id, (unsigned long long)group->group_id, group->group_type, group->channel_id); + DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "topo_group_new_conn: peer=%016llx group=%016llx type=%d ch=%s", (unsigned long long)conn->peer_node_id, (unsigned long long)group->group_id, group->group_type, group->channel_id); topo_group_send_table_request(group, conn); topo_group_connect_on_up(group, conn); @@ -602,7 +601,7 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from struct TOPOMSG_NODE* ni = &pkt->node; if (ni->group_id != group->group_id) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "NODEINFO group_id mismatch from %s: expected=%016llx got=%016llx nid=%016llx", + DEBUG_ERROR(DEBUG_CATEGORY_BGP, "NODEINFO group_id mismatch from %s: expected=%016llx got=%016llx nid=%016llx", from->log_name, (unsigned long long)group->group_id, (unsigned long long)ni->group_id, (unsigned long long)ni->node_id); return -1; } @@ -625,11 +624,9 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from struct TOPO_GROUP_NODE* nodeinfo1 = topo_node_find_by_id(group, node_id); uint8_t new_ver = ni->ver; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "process_nodeinfo: nid=%016llx ver=%d hops=%d nodeinfo1=%p from=%s", - (unsigned long long)node_id, new_ver, ni->hop_count, (void*)nodeinfo1, from->log_name); 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); + DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "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]; @@ -661,7 +658,7 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from uint64_t* new_hop_list = NULL; uint8_t new_hop_count = 0; uint16_t incoming_cumulative_rtt = 0; if (topo_node_deserialize(group, ser_data, ser_len, &new_ni, &new_subnets, &new_hop_list, &new_hop_count, &incoming_cumulative_rtt) != 0) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "NODEINFO deserialize failed from %s nid=%016llx", from->log_name, (unsigned long long)node_id); + DEBUG_ERROR(DEBUG_CATEGORY_BGP, "NODEINFO deserialize failed from %s nid=%016llx", from->log_name, (unsigned long long)node_id); if (nodeinfo1) { queue_remove_data(group->nodes, &nodeinfo1->ll); queue_free(paths); queue_entry_free(&nodeinfo1->ll); } return -1; } @@ -669,8 +666,6 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from int v6c = topo_list_count((struct _topo_head*)new_ni->v6_addrs); 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); /* verify Ed25519 self-signature over canonical message */ { @@ -696,8 +691,6 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from if (nodeinfo1) { { struct TOPO_NODE* stored = topo_node_registry_store(group->instance->topo_groups, new_ni); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "NODEINFO update: stored=%p new_ni=%p same=%d nid=%016llx", - (void*)stored, (void*)new_ni, stored == new_ni, (unsigned long long)(stored ? stored->node_id : 0)); if (stored != new_ni) new_ni = stored; } new_ni->group_id = group->group_id; new_ni->flags = pkt->node.flags; @@ -709,8 +702,6 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from nodeinfo1 = (struct TOPO_GROUP_NODE*)qe; memset((uint8_t*)nodeinfo1 + sizeof(struct ll_entry), 0, sizeof(*nodeinfo1) - sizeof(struct ll_entry)); { struct TOPO_NODE* stored = topo_node_registry_store(group->instance->topo_groups, new_ni); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "NODEINFO new: stored=%p new_ni=%p same=%d nid=%016llx", - (void*)stored, (void*)new_ni, stored == new_ni, (unsigned long long)(stored ? stored->node_id : 0)); if (stored != new_ni) new_ni = stored; } new_ni->group_id = group->group_id; new_ni->flags = pkt->node.flags; @@ -746,14 +737,13 @@ int topo_group_process_nodeinfo(struct TOPO_GROUP* group, struct ETCP_CONN* from topo_node_sqlite_node_put(sdb, group->instance->topo_groups, nodeinfo1, ntp_time_get_seconds(group->instance)); if (group->group_type == TOPO_GROUP_TYPE_CHAT && group->channel_id[0]) { topo_node_sqlite_member_put(sdb, group->channel_id, node_id, NULL, 0, NULL, 0, NULL, NULL, NULL, NULL, NULL, NULL, 0); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "SQLite member_put: ch=%s node=%016llx", group->channel_id, (unsigned long long)node_id); } topo_node_sqlite_nodeinfo_updated(sdb, 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); + DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "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); @@ -833,16 +823,16 @@ 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_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); + if (!sni) { DEBUG_WARN(DEBUG_CATEGORY_BGP, "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_BGP, "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; } + if (ser_len < 0) { DEBUG_ERROR(DEBUG_CATEGORY_BGP, "send_nodeinfo: serialize failed for node %016llx", (unsigned long long)node->node_id); u_free(p); return; } struct ll_entry* e = queue_entry_new(0); if (!e) { u_free(p); return; } e->dgram = p; e->len = (size_t)ser_len + 2; - if (etcp_send(conn, e) != 0) { DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "send_nodeinfo: etcp_send FAILED for node %016llx to %s", (unsigned long long)node->node_id, conn->log_name); u_free(p); queue_entry_free(e); } + if (etcp_send(conn, e) != 0) { DEBUG_ERROR(DEBUG_CATEGORY_BGP, "send_nodeinfo: etcp_send FAILED for node %016llx to %s", (unsigned long long)node->node_id, conn->log_name); u_free(p); queue_entry_free(e); } } static void topo_group_add_to_senders(struct TOPO_GROUP* group, struct ETCP_CONN* conn) { diff --git a/src/transport_layer/etcp.c b/src/transport_layer/etcp.c index c1883b48..82dd9769 100644 --- a/src/transport_layer/etcp.c +++ b/src/transport_layer/etcp.c @@ -320,20 +320,8 @@ static void etcp_on_up(struct ETCP_CONN* etcp) { etcp->log_name, etcp->links_up, total_links, etcp->mtu, etcp->reinit_count, pp > 0 ? " — up: " : "", links_str); (void)elapsed_ms; - 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], - etcp->crypto_ctx.session_key[2], etcp->crypto_ctx.session_key[3], - etcp->crypto_ctx.peer_public_key[0], etcp->crypto_ctx.peer_public_key[1], - etcp->crypto_ctx.peer_public_key[2], etcp->crypto_ctx.peer_public_key[3]); etcp_cbk_fire(etcp, ETCP_CBK_EVENT_UP); etcp_fire_conn_status(etcp, ETCP_CONN_STATUS_UP); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_ON_UP_AFTER: 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], - etcp->crypto_ctx.session_key[2], etcp->crypto_ctx.session_key[3], - etcp->crypto_ctx.peer_public_key[0], etcp->crypto_ctx.peer_public_key[1], - etcp->crypto_ctx.peer_public_key[2], etcp->crypto_ctx.peer_public_key[3]); } static void etcp_on_down(struct ETCP_CONN* etcp, struct ETCP_LINK* down_link) { @@ -397,7 +385,7 @@ void etcp_connection_close(struct ETCP_CONN* etcp) { if (etcp->state == 2) { DEBUG_WARN(DEBUG_CATEGORY_ETCP, "[%s] already deleted", etcp->log_name); return; } if (etcp->callbacks_running) { - DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, "[%s] FATAL: etcp_connection_close called from inside callback chain — SEGFAULTING to show backtrace", + DEBUG_ERROR(DEBUG_CATEGORY_ETCP, "[%s] FATAL: etcp_connection_close called from inside callback chain — SEGFAULTING to show backtrace", etcp->log_name); *(volatile int*)0 = 0; } @@ -645,17 +633,6 @@ void etcp_conn_ready(struct ETCP_CONN* conn) { conn->reset_done = 1; if (conn->tx_state == 0) { conn->tx_state = ETCP_TX_STATE_DATA_WAIT; } DEBUG_INFO(DEBUG_CATEGORY_ETCP, "[%s] Connection ready", conn->log_name); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_CONN_READY: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x my_pub=%02x%02x%02x%02x links=%p", - conn->log_name, - conn->crypto_ctx.session_key[0], conn->crypto_ctx.session_key[1], - conn->crypto_ctx.session_key[2], conn->crypto_ctx.session_key[3], - conn->crypto_ctx.peer_public_key[0], conn->crypto_ctx.peer_public_key[1], - conn->crypto_ctx.peer_public_key[2], conn->crypto_ctx.peer_public_key[3], - conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[0] : 0, - conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[1] : 0, - conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[2] : 0, - conn->crypto_ctx.pk ? conn->crypto_ctx.pk->public_key[3] : 0, - (void*)conn->links); etcp_conn_queue_set_ready(conn); } @@ -1042,7 +1019,7 @@ static void etcp_link_ready_callback(struct ETCP_CONN* etcp) { DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "[%s] etcp_link_ready_callback: links_up 0→1, calling etcp_on_up (initialized=%d tx_state=%d)", etcp->log_name, etcp->initialized, etcp->tx_state); etcp->links_up=1; etcp_on_up(etcp); - } else DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[%s] etcp_link_ready_callback: links_up=%d already up", etcp->log_name, etcp->links_up); + } if (etcp->tx_state!=ETCP_TX_STATE_LINK_WAIT) return; diff --git a/src/transport_layer/etcp_api.c b/src/transport_layer/etcp_api.c index 10467812..5e8bfdb1 100644 --- a/src/transport_layer/etcp_api.c +++ b/src/transport_layer/etcp_api.c @@ -182,11 +182,11 @@ void etcp_int_recv(struct ll_queue* queue, void* arg) { struct UTUN_INSTANCE* inst = conn->instance; if (!inst) { queue_dgram_free(e); queue_entry_free(e); queue_resume_callback(queue); return; } if (inst->api_bindings.callbacks[id]) { - DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "dispatch id=0x%02x conn=%s len=%zu", id, conn->log_name, e->len); + DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "dispatch id=0x%02x conn=%s len=%zu", id, conn->log_name, e->len); inst->api_bindings.callbacks[id](conn, e); } else if (inst->api_bindings.callbacks[0]) { - DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "dispatch id=0x%02x (fallback) conn=%s len=%zu", id, conn->log_name, e->len); + DEBUG_TRACE(DEBUG_CATEGORY_TRAFFIC, "dispatch id=0x%02x (fallback) conn=%s len=%zu", id, conn->log_name, e->len); inst->api_bindings.callbacks[0](conn, e); - } else { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "dispatch id=0x%02x NO CB conn=%s len=%zu — DROPPED", id, conn->log_name, e->len); queue_dgram_free(e); queue_entry_free(e); } + } else { queue_dgram_free(e); queue_entry_free(e); } queue_resume_callback(queue); } diff --git a/src/transport_layer/etcp_connect.c b/src/transport_layer/etcp_connect.c index 4c3644ad..1f783679 100644 --- a/src/transport_layer/etcp_connect.c +++ b/src/transport_layer/etcp_connect.c @@ -68,7 +68,7 @@ static void connect_cancel(struct ETCP_CONNECT* ctx) { static void connect_create_links_v4(struct ETCP_CONNECT* ctx, struct TOPO_GROUP_NODE* node) { if (!node) return; struct TOPO_NODE* ni = topo_node_registry_find(ctx->instance->topo_groups, node->node_id); - if (!ni) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[etcp_connect] links_v4: ni NOT in registry for node=%016llx", (unsigned long long)node->node_id); return; } + if (!ni) { DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "[etcp_connect] links_v4: ni NOT in registry for node=%016llx", (unsigned long long)node->node_id); return; } int addr_count = 0, sock_count = 0, link_count = 0; { struct ETCP_SOCKET* s = ctx->instance->etcp_sockets; while (s) { sock_count++; s = s->next; } } for (const struct TOPO_ADDR4* a = ni->v4_addrs; a; a = a->next) { @@ -87,7 +87,7 @@ static void connect_create_links_v4(struct ETCP_CONNECT* ctx, struct TOPO_GROUP_ if (tlink) { tlink->is_tcp = 1; etcp_tcp_link_start_connect(tlink, &sa, a->port); link_count++; } } } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[etcp_connect] links_v4: addrs=%d socks=%d links=%d for node=%016llx", + DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "[etcp_connect] links_v4: addrs=%d socks=%d links=%d for node=%016llx", addr_count, sock_count, link_count, (unsigned long long)node->node_id); } @@ -123,7 +123,7 @@ static void connect_create_links_v6(struct ETCP_CONNECT* ctx, struct TOPO_GROUP_ static void connect_bgp_ready_cb(struct ETCP_CONN* conn) { struct ETCP_CONNECT* ctx = connect_find(conn->instance, conn->peer_node_id); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[etcp_connect] bgp_ready_cb: node=%016llx ctx=%p ctx_done=%d ra=%d", + DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "[etcp_connect] bgp_ready_cb: node=%016llx ctx=%p ctx_done=%d ra=%d", (unsigned long long)conn->peer_node_id, (void*)ctx, ctx ? ctx->done : -1, conn->routing_exchange_active); if (!ctx || ctx->done) return; connect_deliver(ctx, ETCP_CONNECT_BGP_READY, 1); @@ -212,7 +212,7 @@ int etcp_connect(struct UTUN_INSTANCE* inst, struct TOPO_GROUP_NODE* node, struct TOPO_NODE* ni = topo_node_registry_find(inst->topo_groups, node->node_id); if (!ni) { DEBUG_ERROR(DEBUG_CATEGORY_ETCP_CONNECT, "[etcp_connect] node not in registry"); return -1; } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[etcp_connect] registry OK node=%016llx pub=%016llx v4addrs=%p v4socks=%p", + DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "[etcp_connect] registry OK node=%016llx pub=%016llx v4addrs=%p v4socks=%p", (unsigned long long)node->node_id, *(uint64_t*)ni->public_key, (void*)ni->v4_addrs, (void*)ni->v4_sock_meta); uint64_t node_id = ni->node_id; diff --git a/src/transport_layer/etcp_connections.c b/src/transport_layer/etcp_connections.c index 53b01425..2fd8ae5c 100644 --- a/src/transport_layer/etcp_connections.c +++ b/src/transport_layer/etcp_connections.c @@ -1210,7 +1210,7 @@ int etcp_encrypt_send(struct ETCP_DGRAM* dgram) { socklen_t addr_len = (addr->ss_family == AF_INET) ? sizeof(struct sockaddr_in) : sizeof(struct sockaddr_in6); if (addr->ss_family == AF_INET6) { struct sockaddr_in6* sin6 = (struct sockaddr_in6*)addr; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[v6_send] fd=%d dst=%-39s scope=%u", dgram->link->conn->fd, + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "[v6_send] fd=%d dst=%-39s scope=%u", dgram->link->conn->fd, sockaddr_storage_to_str(addr).str, sin6->sin6_scope_id); } @@ -1813,7 +1813,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { ssize_t recv_len = socket_recvfrom(sock, data, PACKET_DATA_SIZE, (struct sockaddr*)&addr, &addr_len); if (recv_len > 0 && addr.ss_family == AF_INET6) { struct sockaddr_in6* sin6 = (struct sockaddr_in6*)&addr; - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[v6_recv] sock=%s fd=%d src=[%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x]:%d len=%zd scope=%u", + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "[v6_recv] sock=%s fd=%d src=[%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x:%02x%02x]:%d len=%zd scope=%u", e_sock->name, (int)sock, sin6->sin6_addr.s6_addr[0],sin6->sin6_addr.s6_addr[1],sin6->sin6_addr.s6_addr[2],sin6->sin6_addr.s6_addr[3], sin6->sin6_addr.s6_addr[4],sin6->sin6_addr.s6_addr[5],sin6->sin6_addr.s6_addr[6],sin6->sin6_addr.s6_addr[7], @@ -1859,7 +1859,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { link->etcp->crypto_ctx.session_key[0], link->etcp->crypto_ctx.session_key[1], link->etcp->crypto_ctx.session_key[2], link->etcp->crypto_ctx.session_key[3]); } else { - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "SKIP normal decrypt: link=%p session_ready=%d — trying init decrypt", + DEBUG_DEBUG(DEBUG_CATEGORY_CRYPTO, "SKIP normal decrypt: link=%p session_ready=%d — trying init decrypt", link, link && link->etcp ? link->etcp->crypto_ctx.session_ready : -1); } @@ -2017,7 +2017,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { conn=etcp_connection_create(e_sock->instance,""); if (!conn) { errorcode=55; DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "failed to create connection"); goto ec_fr; } memcpy(&conn->crypto_ctx, &sc, sizeof(sc)); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "CRYPTO_CTX_INIT: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x my_priv=%02x%02x%02x%02x", + DEBUG_DEBUG(DEBUG_CATEGORY_CRYPTO, "CRYPTO_CTX_INIT: log=%s seskey=%02x%02x%02x%02x peer_pub=%02x%02x%02x%02x my_priv=%02x%02x%02x%02x", conn->log_name, conn->crypto_ctx.session_key[0], conn->crypto_ctx.session_key[1], conn->crypto_ctx.session_key[2], conn->crypto_ctx.session_key[3], @@ -2054,7 +2054,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { if (conn->fin_wait_clear_cb) { conn->fin_wait_clear_cb(conn, conn->fin_wait_clear_arg); conn->fin_wait_clear_cb = NULL; conn->fin_wait_clear_arg = NULL; } } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "INIT conn=%s new_conn=%d peer=0x%016llx state=%d links_up=%d links=%p", conn->log_name, new_conn, (unsigned long long)peer_id, conn->state, conn->links_up, (void*)conn->links); + DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "INIT conn=%s new_conn=%d peer=0x%016llx state=%d links_up=%d links=%p", conn->log_name, new_conn, (unsigned long long)peer_id, conn->state, conn->links_up, (void*)conn->links); // Check if link already exists (for CHANNEL_INIT recovery) diff --git a/src/transport_layer/etcp_loadbalancer.c b/src/transport_layer/etcp_loadbalancer.c index 8cdb0fe0..27ca8a95 100644 --- a/src/transport_layer/etcp_loadbalancer.c +++ b/src/transport_layer/etcp_loadbalancer.c @@ -194,7 +194,7 @@ void loadbalancer_link_ready(struct ETCP_LINK* link) { DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "link still blocked by shaper"); return; } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[%s] loadbalancer_link_ready: link=%p links_up=%d initialized=%d tx_state=%d", link->etcp->log_name, (void*)link, link->etcp->links_up, link->etcp->initialized, link->etcp->tx_state); + DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "[%s] loadbalancer_link_ready: link=%p links_up=%d initialized=%d tx_state=%d", link->etcp->log_name, (void*)link, link->etcp->links_up, link->etcp->initialized, link->etcp->tx_state); if (link->etcp->link_ready_for_send_fn) { link->etcp->link_ready_for_send_fn(link->etcp); } else { diff --git a/src/transport_layer/node_conn_direct.c b/src/transport_layer/node_conn_direct.c index 2b9662e2..6aefa23a 100644 --- a/src/transport_layer/node_conn_direct.c +++ b/src/transport_layer/node_conn_direct.c @@ -143,14 +143,14 @@ static int ncd_create_links(struct ncd_entry* entry, struct TOPO_NODE* ni, if (s->local_addr.ss_family == AF_INET && s->type != CFG_SERVER_TYPE_PRIVATE) socks[sock_count++] = s; } - if (sock_count == 0) DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] v4 sock_count=0 node=0x%016llx", (unsigned long long)nid); + if (sock_count == 0) DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[ncd] v4 sock_count=0 node=0x%016llx", (unsigned long long)nid); if (sock_count > 0) { int rr = 0; for (const struct TOPO_ADDR4* a = ni->v4_addrs; a; a = a->next) { - if (a->port == 0 || !(a->protocol & TOPO_PROTO_UDP)) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] v4 skip proto=%02x port=%d node=0x%016llx", a->protocol, (int)a->port, (unsigned long long)nid); continue; } + if (a->port == 0 || !(a->protocol & TOPO_PROTO_UDP)) { DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[ncd] v4 skip proto=%02x port=%d node=0x%016llx", a->protocol, (int)a->port, (unsigned long long)nid); continue; } int zero = 1; for (int j = 0; j < 4; j++) if (a->addr[j] != 0) { zero = 0; break; } - if (zero) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] v4 skip zero-addr node=0x%016llx", (unsigned long long)nid); continue; } + if (zero) { DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[ncd] v4 skip zero-addr node=0x%016llx", (unsigned long long)nid); continue; } struct sockaddr_in sin; memset(&sin, 0, sizeof(sin)); sin.sin_family = AF_INET; memcpy(&sin.sin_addr.s_addr, a->addr, 4); sin.sin_port = htons(a->port); struct sockaddr_storage sa; memcpy(&sa, &sin, sizeof(sin)); @@ -193,14 +193,14 @@ static int ncd_create_links(struct ncd_entry* entry, struct TOPO_NODE* ni, socks[sock_count++] = s; } - if (sock_count == 0) DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] v6 sock_count=0 node=0x%016llx", (unsigned long long)nid); + if (sock_count == 0) DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[ncd] v6 sock_count=0 node=0x%016llx", (unsigned long long)nid); if (sock_count > 0) { int rr = 0; for (const struct TOPO_ADDR6* a = ni->v6_addrs; a; a = a->next) { - if (a->port == 0 || !(a->protocol & TOPO_PROTO_UDP)) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] v6 skip proto=%02x port=%d node=0x%016llx", a->protocol, (int)a->port, (unsigned long long)nid); continue; } + if (a->port == 0 || !(a->protocol & TOPO_PROTO_UDP)) { DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[ncd] v6 skip proto=%02x port=%d node=0x%016llx", a->protocol, (int)a->port, (unsigned long long)nid); continue; } int zero = 1; for (int j = 0; j < 16; j++) if (a->addr[j] != 0) { zero = 0; break; } - if (zero) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] v6 skip zero-addr node=0x%016llx", (unsigned long long)nid); continue; } + if (zero) { DEBUG_DEBUG(DEBUG_CATEGORY_CONNECTION, "[ncd] v6 skip zero-addr node=0x%016llx", (unsigned long long)nid); continue; } struct sockaddr_in6 sin6; memset(&sin6, 0, sizeof(sin6)); sin6.sin6_family = AF_INET6; memcpy(&sin6.sin6_addr, a->addr, 16); sin6.sin6_port = htons(a->port); struct ETCP_SOCKET* use_sock = socks[rr++ % sock_count]; @@ -559,7 +559,7 @@ int node_conn_direct_open(struct UTUN_INSTANCE* inst, uint64_t node_id, { struct TOPO_NODE* ni = ncd_lookup_node(inst, node_id); if (ni) { ncd_create_links(entry, ni, specific_sock); topo_node_registry_unref(inst->topo_groups, ni->node_id); } } - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=REUSED_entry_pending", + DEBUG_DEBUG(DEBUG_CATEGORY_TIMERS, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=REUSED_entry_pending", (unsigned long long)node_id, inst->etcp_connect_timeout_tb, (unsigned long long)get_time_tb()); entry->connect_timer = uasync_set_timeout(inst->ua, (int)inst->etcp_connect_timeout_tb, entry, ncd_connect_timeout_cb, "ncd_connect"); DEBUG_INFO(DEBUG_CATEGORY_NCD, "[ncd] open REUSED new-entry (pending) node=0x%016llx conn=%p", (unsigned long long)node_id, (void*)conn); @@ -633,7 +633,7 @@ int node_conn_direct_open(struct UTUN_INSTANCE* inst, uint64_t node_id, if (link_count == 0) DEBUG_WARN(DEBUG_CATEGORY_NCD, "[ncd] no links created for node=0x%016llx", (unsigned long long)node_id); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=NEW_node_conn_direct_open", + DEBUG_DEBUG(DEBUG_CATEGORY_TIMERS, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=NEW_node_conn_direct_open", (unsigned long long)node_id, inst->etcp_connect_timeout_tb, (unsigned long long)get_time_tb()); entry->connect_timer = uasync_set_timeout(inst->ua, (int)inst->etcp_connect_timeout_tb, entry, ncd_connect_timeout_cb, "ncd_connect"); DEBUG_INFO(DEBUG_CATEGORY_NCD, "[ncd] open NEW node=0x%016llx conn=%p links=%d handles=%d", @@ -710,7 +710,7 @@ int node_conn_direct_open_node(struct UTUN_INSTANCE* inst, uint64_t node_id, DEBUG_INFO(DEBUG_CATEGORY_NCD, "[ncd] open_node REUSED new-entry (ready) node=0x%016llx conn=%p", (unsigned long long)node_id, (void*)conn); } else { ncd_create_links(entry, ni, specific_sock); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=REUSED_conn_pending", + DEBUG_DEBUG(DEBUG_CATEGORY_TIMERS, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=REUSED_conn_pending", (unsigned long long)node_id, inst->etcp_connect_timeout_tb, (unsigned long long)get_time_tb()); entry->connect_timer = uasync_set_timeout(inst->ua, (int)inst->etcp_connect_timeout_tb, entry, ncd_connect_timeout_cb, "ncd_connect_node"); DEBUG_INFO(DEBUG_CATEGORY_NCD, "[ncd] open_node REUSED new-entry (pending) node=0x%016llx conn=%p", (unsigned long long)node_id, (void*)conn); @@ -775,7 +775,7 @@ int node_conn_direct_open_node(struct UTUN_INSTANCE* inst, uint64_t node_id, if (link_count == 0) DEBUG_WARN(DEBUG_CATEGORY_NCD, "[ncd] open_node no links created for node=0x%016llx", (unsigned long long)node_id); - DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=NEW_node_conn_direct_open_node", + DEBUG_DEBUG(DEBUG_CATEGORY_TIMERS, "[ncd] connect timer SET: node=0x%016llx value_tb=%u now_tb=%llu path=NEW_node_conn_direct_open_node", (unsigned long long)node_id, inst->etcp_connect_timeout_tb, (unsigned long long)get_time_tb()); entry->connect_timer = uasync_set_timeout(inst->ua, (int)inst->etcp_connect_timeout_tb, entry, ncd_connect_timeout_cb, "ncd_connect_node"); DEBUG_INFO(DEBUG_CATEGORY_NCD, "[ncd] open_node NEW node=0x%016llx conn=%p links=%d handles=%d", diff --git a/tools/chatgui/src/debug_ui.h b/tools/chatgui/src/debug_ui.h index 8ec0108b..153f7201 100644 --- a/tools/chatgui/src/debug_ui.h +++ b/tools/chatgui/src/debug_ui.h @@ -4,7 +4,7 @@ extern "C" { #include "../../lib/debug_config.h" } -#define GUI_ERROR(fmt, ...) DEBUG_ERROR(DEBUG_CATEGORY_DEBUG, fmt, ##__VA_ARGS__) -#define GUI_WARN(fmt, ...) DEBUG_WARN(DEBUG_CATEGORY_DEBUG, fmt, ##__VA_ARGS__) -#define GUI_INFO(fmt, ...) DEBUG_INFO(DEBUG_CATEGORY_DEBUG, fmt, ##__VA_ARGS__) -#define GUI_DEBUG(fmt, ...) DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, fmt, ##__VA_ARGS__) +#define GUI_ERROR(fmt, ...) DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, fmt, ##__VA_ARGS__) +#define GUI_WARN(fmt, ...) DEBUG_WARN(DEBUG_CATEGORY_GENERAL, fmt, ##__VA_ARGS__) +#define GUI_INFO(fmt, ...) DEBUG_INFO(DEBUG_CATEGORY_GENERAL, fmt, ##__VA_ARGS__) +#define GUI_DEBUG(fmt, ...) DEBUG_DEBUG(DEBUG_CATEGORY_GENERAL, fmt, ##__VA_ARGS__)