diff --git a/lib/debug_config.c b/lib/debug_config.c index 3f5d2171..ad1b1c4a 100644 --- a/lib/debug_config.c +++ b/lib/debug_config.c @@ -13,30 +13,29 @@ #include #include -void log_dump(const char* prefix, const uint8_t* data, size_t len) { +void log_dump(int level, int category, const char* prefix, const uint8_t* data, size_t len) { + if (!debug_should_output(level, category)) return; + char hex_buf[513] = {'\0'}; size_t hex_len = 0; size_t show_len = (len > 128) ? 128 : len; - + for (size_t i = 0; i < show_len && hex_len < 512 - 3; i++) { hex_len += snprintf(hex_buf + hex_len, sizeof(hex_buf) - hex_len, "%02x", data[i]); - if (i < show_len - 1 && (i + 1) % 32 == 0) { // Add space every 32 bytes + if (i < show_len - 1 && (i + 1) % 32 == 0) hex_len += snprintf(hex_buf + hex_len, sizeof(hex_buf) - hex_len, " "); - } } - - if (len > 128) { + + if (len > 128) hex_len += snprintf(hex_buf + hex_len, sizeof(hex_buf) - hex_len, "..."); + + switch (level) { + case DEBUG_LEVEL_ERROR: DEBUG_ERROR(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break; + case DEBUG_LEVEL_WARN: DEBUG_WARN(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break; + case DEBUG_LEVEL_INFO: DEBUG_INFO(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break; + case DEBUG_LEVEL_DEBUG: DEBUG_DEBUG(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break; + case DEBUG_LEVEL_TRACE: DEBUG_TRACE(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break; } - - // Single-line debug output with packet info - DEBUG_INFO(DEBUG_CATEGORY_DUMP, "%s: len=%zu hex=%s", prefix, len, hex_buf); - - // Additional debug info for first few bytes -// if (len >= 2) { -// DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "%s: first_bytes=%02x%02x last_bytes=%02x%02x", -// prefix, data[0], data[1], data[len-2], data[len-1]); -// } } diff --git a/lib/debug_config.h b/lib/debug_config.h index 9b98e5b4..6fb6c748 100644 --- a/lib/debug_config.h +++ b/lib/debug_config.h @@ -123,7 +123,7 @@ ip_str_t ip_to_str(const void *addr, int family);// big endian addr ip_str_t sockaddr_storage_to_str(const struct sockaddr_storage *addr);// автоопределение v4 или v6 // hex dump в лог -void log_dump(const char* prefix, const uint8_t* data, size_t len); +void log_dump(int level, int category, const char* prefix, const uint8_t* data, size_t len); /* Check if debug output should be shown for given level and category */ int debug_should_output(debug_level_t level, debug_category_t category_idx); diff --git a/lib/memory_pool.c b/lib/memory_pool.c index 8593b5bd..53c52421 100644 --- a/lib/memory_pool.c +++ b/lib/memory_pool.c @@ -22,17 +22,6 @@ static void pool_init_tags(struct memory_pool* pool, void* obj, const char* loca *counter = 1; } -static void pool_dump_object(void* obj, size_t len, const char* prefix) -{ - unsigned char* p = (unsigned char*)obj; - char line[128]; - int pos; - size_t cnt = len < 32 ? len : 32; - pos = snprintf(line, sizeof(line), " %s [%zu]:", prefix, len); - for (size_t i = 0; i < cnt; i++) pos += snprintf(line + pos, sizeof(line) - pos, " %02x", p[i]); - DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "%s", line); -} - static void pool_check_and_clear_tags(struct memory_pool* pool, void* obj, const char* location) { uint32_t* canary = (uint32_t*)((uint8_t*)obj + POOL_CANARY_OFF); @@ -40,20 +29,19 @@ static void pool_check_and_clear_tags(struct memory_pool* pool, void* obj, const uint8_t* counter = (uint8_t*)obj + POOL_COUNTER_OFF; if (*canary != POOL_CANARY_VAL) { - DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "pool_free BUFFER OVERFLOW obj=%p sz=%zu alloc=%s free=%s canary=0x%08x expected=0x%08x", - obj, pool->object_size, *loc ? *loc : "(null)", location, *canary, POOL_CANARY_VAL); - pool_dump_object(obj, pool->object_size, "head"); - pool_dump_object((uint8_t*)obj + (pool->object_size > 32 ? pool->object_size - 32 : 0), - pool->object_size < 32 ? pool->object_size : 32, "tail"); - // dump raw canary area - DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, " canary_raw: %02x %02x %02x %02x loc=%p", - ((uint8_t*)canary)[0], ((uint8_t*)canary)[1], ((uint8_t*)canary)[2], ((uint8_t*)canary)[3], (void*)*loc); + DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "pool_free BUFFER OVERFLOW pool=%p sz=%zu allocs=%zu reuse=%zu free=%d", + pool, pool->object_size, pool->allocations, pool->reuse_count, pool->free_count); + DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, " obj=%p alloc=%s free=%s canary=0x%08x expected=0x%08x", + obj, *loc ? *loc : "(null)", location, *canary, POOL_CANARY_VAL); + if (pool->object_size) + log_dump(DEBUG_LEVEL_ERROR, DEBUG_CATEGORY_MEMORY, " user_data", obj, pool->object_size); volatile int _halt = 1; while (_halt) {} } if (*counter == 0) { - DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "pool_free DOUBLE FREE obj=%p alloc=%s free=%s! halting", - obj, *loc ? *loc : "(null)", location); + DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "pool_free DOUBLE FREE pool=%p sz=%zu allocs=%zu reuse=%zu alloc=%s free=%s", + pool, pool->object_size, pool->allocations, pool->reuse_count, + *loc ? *loc : "(null)", location); volatile int _halt = 1; while (_halt) {} } diff --git a/src/etcp_connections.c b/src/etcp_connections.c index 1b6a437d..b19e0bc7 100644 --- a/src/etcp_connections.c +++ b/src/etcp_connections.c @@ -944,7 +944,7 @@ int etcp_encrypt_send(struct ETCP_DGRAM* dgram) { dgram->timestamp=get_current_timestamp(); dgram->link->total_encrypted += dgram->data_len; - if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO)) log_dump("Before encryption", dgram->data, dgram->data_len); + if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO)) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO, "Before encryption", dgram->data, dgram->data_len); sc_encrypt(sc, (uint8_t*)&dgram->timestamp, 3 + len, enc_buf, &enc_buf_len); if (enc_buf_len == 0) { DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "eencryption failed for node %016llx", (unsigned long long)dgram->link->etcp->instance->node_id); @@ -954,7 +954,7 @@ int etcp_encrypt_send(struct ETCP_DGRAM* dgram) { dgram->link->send_errors++; errcode=3; goto es_err; } memcpy(enc_buf+enc_buf_len, dgram->data+len, dgram->noencrypt_len); - if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO)) log_dump("Encrypted", enc_buf, enc_buf_len + dgram->noencrypt_len); + if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO)) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO, "Encrypted", enc_buf, enc_buf_len + dgram->noencrypt_len); struct sockaddr_storage* addr=&dgram->link->remote_addr; socklen_t addr_len = (addr->ss_family == AF_INET) ? sizeof(struct sockaddr_in) : sizeof(struct sockaddr_in6); @@ -1184,7 +1184,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { } // DUMP: Show received packet content - if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO)) log_dump("RECV in:", data, recv_len); // link unknown at this point + if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO)) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_CRYPTO, "RECV in:", data, recv_len); struct ETCP_DGRAM* pkt = memory_pool_alloc(e_sock->instance->pkt_pool); if (!pkt) return; diff --git a/src/pkt_normalizer.c b/src/pkt_normalizer.c index 88d6df73..2917ae4a 100644 --- a/src/pkt_normalizer.c +++ b/src/pkt_normalizer.c @@ -241,7 +241,7 @@ static void pn_send_to_etcp(struct PKTNORM* pn) { frag->ll.memlen = pn->etcp->instance->data_pool->object_size; DEBUG_INFO(DEBUG_CATEGORY_NORMALIZER, "pn->etcp: size=%d memlen=%d frag_size=%d", frag->ll.len, frag->ll.memlen, pn->frag_size); - if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump("NORM->ETCP", pn->data, frag->ll.len); + if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP, "NORM->ETCP", pn->data, frag->ll.len); queue_data_put(pn->etcp->input_queue, (struct ll_entry*)frag); // Сбросить структуру (dgram передан во фрагмент, не освобождаем) @@ -286,7 +286,7 @@ static void etcp_input_ready_cb(struct ll_queue* q, void* arg) { return; } - if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump("->NORM", in_dgram->dgram, in_dgram->len); + if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP, "->NORM", in_dgram->dgram, in_dgram->len); pn_buf_renew(pn); // DEBUG_INFO(DEBUG_CATEGORY_NORMALIZER, "pn_packer: new pkt hdrpos=%d",pn->data_ptr); @@ -350,7 +350,7 @@ static void pn_unpacker_cb(struct ll_queue* q, void* arg) { uint8_t* payload = frag->ll.dgram; uint16_t len = frag->ll.len; uint16_t ptr = 0; - if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump("ETCP->NORM", payload, len); + if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP, "ETCP->NORM", payload, len); DEBUG_DEBUG(DEBUG_CATEGORY_NORMALIZER, "unpacking fragment len=%d", len); @@ -395,7 +395,7 @@ static void pn_unpacker_cb(struct ll_queue* q, void* arg) { if (pn->recvpart->len == pn->recvpart->memlen) { DEBUG_DEBUG(DEBUG_CATEGORY_NORMALIZER, "unpacked dgram (size=%d)", pn->recvpart->len); - if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump("NORM->", pn->recvpart->dgram, pn->recvpart->len); + if (debug_should_output(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP)) log_dump(DEBUG_LEVEL_DEBUG, DEBUG_CATEGORY_DUMP, "NORM->", pn->recvpart->dgram, pn->recvpart->len); queue_data_put(pn->output, pn->recvpart); pn->out_total_pkts++; pn->out_total_bytes += pn->recvpart->len;