Browse Source

log_dump: level+category, memory_pool: дамп user_data через log_dump при коррапшне

tmo
Evgeny 4 months ago
parent
commit
677a5cdcf5
  1. 25
      lib/debug_config.c
  2. 2
      lib/debug_config.h
  3. 30
      lib/memory_pool.c
  4. 6
      src/etcp_connections.c
  5. 8
      src/pkt_normalizer.c

25
lib/debug_config.c

@ -13,30 +13,29 @@
#include <stdio.h> #include <stdio.h>
#include <time.h> #include <time.h>
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'}; char hex_buf[513] = {'\0'};
size_t hex_len = 0; size_t hex_len = 0;
size_t show_len = (len > 128) ? 128 : len; size_t show_len = (len > 128) ? 128 : len;
for (size_t i = 0; i < show_len && hex_len < 512 - 3; i++) { 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]); 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, " "); 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, "..."); hex_len += snprintf(hex_buf + hex_len, sizeof(hex_buf) - hex_len, "...");
}
// Single-line debug output with packet info switch (level) {
DEBUG_INFO(DEBUG_CATEGORY_DUMP, "%s: len=%zu hex=%s", prefix, len, hex_buf); 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;
// Additional debug info for first few bytes case DEBUG_LEVEL_INFO: DEBUG_INFO(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break;
// if (len >= 2) { case DEBUG_LEVEL_DEBUG: DEBUG_DEBUG(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break;
// DEBUG_DEBUG(DEBUG_CATEGORY_ETCP, "%s: first_bytes=%02x%02x last_bytes=%02x%02x", case DEBUG_LEVEL_TRACE: DEBUG_TRACE(category, "%s: len=%zu hex=%s", prefix, len, hex_buf); break;
// prefix, data[0], data[1], data[len-2], data[len-1]); }
// }
} }

2
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 ip_str_t sockaddr_storage_to_str(const struct sockaddr_storage *addr);// автоопределение v4 или v6
// hex dump в лог // 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 */ /* 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); int debug_should_output(debug_level_t level, debug_category_t category_idx);

30
lib/memory_pool.c

@ -22,17 +22,6 @@ static void pool_init_tags(struct memory_pool* pool, void* obj, const char* loca
*counter = 1; *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) 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); 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; uint8_t* counter = (uint8_t*)obj + POOL_COUNTER_OFF;
if (*canary != POOL_CANARY_VAL) { 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", DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "pool_free BUFFER OVERFLOW pool=%p sz=%zu allocs=%zu reuse=%zu free=%d",
obj, pool->object_size, *loc ? *loc : "(null)", location, *canary, POOL_CANARY_VAL); pool, pool->object_size, pool->allocations, pool->reuse_count, pool->free_count);
pool_dump_object(obj, pool->object_size, "head"); DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, " obj=%p alloc=%s free=%s canary=0x%08x expected=0x%08x",
pool_dump_object((uint8_t*)obj + (pool->object_size > 32 ? pool->object_size - 32 : 0), obj, *loc ? *loc : "(null)", location, *canary, POOL_CANARY_VAL);
pool->object_size < 32 ? pool->object_size : 32, "tail"); if (pool->object_size)
// dump raw canary area log_dump(DEBUG_LEVEL_ERROR, DEBUG_CATEGORY_MEMORY, " user_data", obj, pool->object_size);
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);
volatile int _halt = 1; volatile int _halt = 1;
while (_halt) {} while (_halt) {}
} }
if (*counter == 0) { if (*counter == 0) {
DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "pool_free DOUBLE FREE obj=%p alloc=%s free=%s! halting", DEBUG_ERROR(DEBUG_CATEGORY_MEMORY, "pool_free DOUBLE FREE pool=%p sz=%zu allocs=%zu reuse=%zu alloc=%s free=%s",
obj, *loc ? *loc : "(null)", location); pool, pool->object_size, pool->allocations, pool->reuse_count,
*loc ? *loc : "(null)", location);
volatile int _halt = 1; volatile int _halt = 1;
while (_halt) {} while (_halt) {}
} }

6
src/etcp_connections.c

@ -940,7 +940,7 @@ int etcp_encrypt_send(struct ETCP_DGRAM* dgram) {
dgram->timestamp=get_current_timestamp(); dgram->timestamp=get_current_timestamp();
dgram->link->total_encrypted += dgram->data_len; 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); sc_encrypt(sc, (uint8_t*)&dgram->timestamp, 3 + len, enc_buf, &enc_buf_len);
if (enc_buf_len == 0) { if (enc_buf_len == 0) {
DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "eencryption failed for node %016llx", (unsigned long long)dgram->link->etcp->instance->node_id); DEBUG_ERROR(DEBUG_CATEGORY_CONNECTION, "eencryption failed for node %016llx", (unsigned long long)dgram->link->etcp->instance->node_id);
@ -950,7 +950,7 @@ int etcp_encrypt_send(struct ETCP_DGRAM* dgram) {
dgram->link->send_errors++; errcode=3; goto es_err; } dgram->link->send_errors++; errcode=3; goto es_err; }
memcpy(enc_buf+enc_buf_len, dgram->data+len, dgram->noencrypt_len); 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; 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); socklen_t addr_len = (addr->ss_family == AF_INET) ? sizeof(struct sockaddr_in) : sizeof(struct sockaddr_in6);
@ -1180,7 +1180,7 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) {
} }
// DUMP: Show received packet content // 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); struct ETCP_DGRAM* pkt = memory_pool_alloc(e_sock->instance->pkt_pool);
if (!pkt) return; if (!pkt) return;

8
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; 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); 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); queue_data_put(pn->etcp->input_queue, (struct ll_entry*)frag);
// Сбросить структуру (dgram передан во фрагмент, не освобождаем) // Сбросить структуру (dgram передан во фрагмент, не освобождаем)
@ -286,7 +286,7 @@ static void etcp_input_ready_cb(struct ll_queue* q, void* arg) {
return; 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); pn_buf_renew(pn);
// DEBUG_INFO(DEBUG_CATEGORY_NORMALIZER, "pn_packer: new pkt hdrpos=%d",pn->data_ptr); // 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; uint8_t* payload = frag->ll.dgram;
uint16_t len = frag->ll.len; uint16_t len = frag->ll.len;
uint16_t ptr = 0; 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); 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) { if (pn->recvpart->len == pn->recvpart->memlen) {
DEBUG_DEBUG(DEBUG_CATEGORY_NORMALIZER, "unpacked dgram (size=%d)", pn->recvpart->len); 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); queue_data_put(pn->output, pn->recvpart);
pn->out_total_pkts++; pn->out_total_pkts++;
pn->out_total_bytes += pn->recvpart->len; pn->out_total_bytes += pn->recvpart->len;

Loading…
Cancel
Save